feat(api): protected settings logs (#59063)

api/src/routes/protected/settings.ts

@@ -97,7 +97,9 @@ export const settingRoutes: FastifyPluginCallbackTypebox = (
   done
 ) => {
   fastify.setErrorHandler((error, request, reply) => {
+    const logger = fastify.log.child({ req: request });
     if (error.validation) {
+      logger.warn({ validationError: error.validation });
       void reply.code(400);
       void reply.send({ message: 'flash.wrong-updating', type: 'danger' });
     } else {
@@ -111,6 +113,7 @@ export const settingRoutes: FastifyPluginCallbackTypebox = (
       schema: schemas.updateMyProfileUI
     },
     async (req, reply) => {
+      const logger = fastify.log.child({ req });
       try {
         await fastify.prisma.user.update({
           where: { id: req.user?.id },
@@ -135,7 +138,8 @@ export const settingRoutes: FastifyPluginCallbackTypebox = (
           type: 'success'
         } as const;
       } catch (err) {
-        fastify.log.error(err);
+        logger.error('Error updating profileUI');
+        logger.error(err);
         fastify.Sentry.captureException(err);
         void reply.code(500);
         return { message: 'flash.wrong-updating', type: 'danger' } as const;
@@ -163,7 +167,9 @@ Happy coding!
       attachValidation: true
     },
     async (req, reply) => {
+      const logger = fastify.log.child({ req });
       if (req.validationError) {
+        logger.warn(`Invalid email ${req.body.email}`);
         void reply.code(400);
         return { message: 'Email format is invalid', type: 'danger' } as const;
       }
@@ -184,6 +190,9 @@ Happy coding!
       const isVerifiedEmail = user.emailVerified;
       const isOwnEmail = newEmail === currentEmailFormatted;
       if (isOwnEmail && isVerifiedEmail) {
+        logger.warn(
+          'New email address is already associated with this account'
+        );
         void reply.code(400);
         return reply.send({
           type: 'info',
@@ -199,6 +208,9 @@ You can update a new email address instead.`
       });
 
       if (isResendUpdateToSameEmail && isLinkSentWithinLimitTTL) {
+        logger.warn(
+          'Email confirmation link has been sent within the last 5 minutes'
+        );
         void reply.code(429);
         return reply.send({
           type: 'info',
@@ -211,6 +223,9 @@ ${isLinkSentWithinLimitTTL}`
         (await fastify.prisma.user.count({ where: { email: newEmail } })) > 0;
 
       if (isEmailAlreadyTaken && !isOwnEmail) {
+        logger.warn(
+          'New email address is already associated with another account'
+        );
         void reply.code(400);
         return reply.send({
           type: 'info',
@@ -238,6 +253,9 @@ ${isLinkSentWithinLimitTTL}`
         });
 
         if (tooManyRequestsMessage) {
+          logger.warn(
+            'Email confirmation link has been sent within the last 5 minutes'
+          );
           void reply.code(429);
           return reply.send({
             type: 'info',
@@ -275,7 +293,8 @@ ${isLinkSentWithinLimitTTL}`
           type: 'info'
         });
       } catch (err) {
-        fastify.log.error(err);
+        logger.error(`Error updating user ${user.id}'s email address`);
+        logger.error(err);
         fastify.Sentry.captureException(err);
         void reply.code(500);
         await reply.send({ message: 'flash.wrong-updating', type: 'danger' });
@@ -289,6 +308,7 @@ ${isLinkSentWithinLimitTTL}`
       schema: schemas.updateMyTheme
     },
     async (req, reply) => {
+      const logger = fastify.log.child({ req });
       try {
         await fastify.prisma.user.update({
           where: { id: req.user?.id },
@@ -302,7 +322,8 @@ ${isLinkSentWithinLimitTTL}`
           type: 'success'
         } as const;
       } catch (err) {
-        fastify.log.error(err);
+        logger.error(`Error updating user ${req.user?.id}'s theme`);
+        logger.error(err);
         fastify.Sentry.captureException(err);
         void reply.code(500);
         return { message: 'flash.wrong-updating', type: 'danger' } as const;
@@ -316,11 +337,21 @@ ${isLinkSentWithinLimitTTL}`
       schema: schemas.updateMySocials
     },
     async (req, reply) => {
+      const logger = fastify.log.child({ req });
+
+      const socials = {
+        twitter: req.body.twitter,
+        githubProfile: req.body.githubProfile,
+        linkedin: req.body.linkedin,
+        website: req.body.website
+      };
+
       const valid = (['twitter', 'githubProfile', 'linkedin'] as const).every(
-        key => validateSocialUrl(req.body[key], key)
+        key => validateSocialUrl(socials[key], key)
       );
 
       if (!valid) {
+        logger.warn({ socials }, `Invalid social URL`);
         void reply.code(400);
         return reply.send({
           message: 'flash.wrong-updating',
@@ -332,10 +363,10 @@ ${isLinkSentWithinLimitTTL}`
         await fastify.prisma.user.update({
           where: { id: req.user?.id },
           data: {
-            website: req.body.website,
+            website: socials.website,
-            twitter: req.body.twitter,
+            twitter: socials.twitter,
-            githubProfile: req.body.githubProfile,
+            githubProfile: socials.githubProfile,
-            linkedin: req.body.linkedin
+            linkedin: socials.linkedin
           }
         });
 
@@ -344,7 +375,8 @@ ${isLinkSentWithinLimitTTL}`
           type: 'success'
         } as const;
       } catch (err) {
-        fastify.log.error(err);
+        logger.error(`Error updating user ${req.user?.id}'s socials`);
+        logger.error(err);
         fastify.Sentry.captureException(err);
         void reply.code(500);
         return { message: 'flash.wrong-updating', type: 'danger' } as const;
@@ -359,6 +391,8 @@ ${isLinkSentWithinLimitTTL}`
       attachValidation: true
     },
     async (req, reply) => {
+      const logger = fastify.log.child({ req });
+
       try {
         const user = await fastify.prisma.user.findFirstOrThrow({
           where: { id: req.user?.id }
@@ -375,6 +409,7 @@ ${isLinkSentWithinLimitTTL}`
           newUsernameDisplay === oldUsernameDisplay;
 
         if (usernameUnchanged) {
+          logger.warn('Username is unchanged');
           void reply.code(400);
           return {
             message: 'flash.username-used',
@@ -383,6 +418,7 @@ ${isLinkSentWithinLimitTTL}`
         }
 
         if (req.validationError) {
+          logger.warn(`Bad request. Supplied username: ${req.body.username}`);
           void reply.code(400);
           return {
             message: req.validationError.message,
@@ -393,6 +429,7 @@ ${isLinkSentWithinLimitTTL}`
         const validation = isValidUsername(newUsername);
 
         if (!validation.valid) {
+          logger.warn(`Invalid username ${newUsername}. ${validation.error}`);
           void reply.code(400);
           return reply.send({
             // TODO(Post-MVP): custom validation errors.
@@ -409,6 +446,7 @@ ${isLinkSentWithinLimitTTL}`
               });
 
         if (usernameTaken || isRestricted(newUsername)) {
+          logger.warn(`Username ${newUsername} is taken or restricted`);
           void reply.code(400);
           return reply.send({
             message: 'flash.username-taken',
@@ -430,7 +468,7 @@ ${isLinkSentWithinLimitTTL}`
           variables: { username: newUsernameDisplay }
         });
       } catch (err) {
-        fastify.log.error(err);
+        logger.error(err);
         fastify.Sentry.captureException(err);
         void reply.code(500);
         await reply.send({ message: 'flash.wrong-updating', type: 'danger' });
@@ -444,6 +482,7 @@ ${isLinkSentWithinLimitTTL}`
       schema: schemas.updateMyAbout
     },
     async (req, reply) => {
+      const logger = fastify.log.child({ req });
       const hasProtocol = isPictureWithProtocol(req.body.picture);
 
       try {
@@ -462,7 +501,7 @@ ${isLinkSentWithinLimitTTL}`
           type: 'success'
         } as const;
       } catch (err) {
-        fastify.log.error(err);
+        logger.error(err);
         fastify.Sentry.captureException(err);
         void reply.code(500);
         return { message: 'flash.wrong-updating', type: 'danger' } as const;
@@ -476,6 +515,7 @@ ${isLinkSentWithinLimitTTL}`
       schema: schemas.updateMyKeyboardShortcuts
     },
     async (req, reply) => {
+      const logger = fastify.log.child({ req });
       try {
         await fastify.prisma.user.update({
           where: { id: req.user?.id },
@@ -489,7 +529,7 @@ ${isLinkSentWithinLimitTTL}`
           type: 'success'
         } as const;
       } catch (err) {
-        fastify.log.error(err);
+        logger.error(err);
         fastify.Sentry.captureException(err);
         void reply.code(500);
         return { message: 'flash.wrong-updating', type: 'danger' } as const;
@@ -503,6 +543,7 @@ ${isLinkSentWithinLimitTTL}`
       schema: schemas.updateMyQuincyEmail
     },
     async (req, reply) => {
+      const logger = fastify.log.child({ req });
       try {
         await fastify.prisma.user.update({
           where: { id: req.user?.id },
@@ -516,7 +557,7 @@ ${isLinkSentWithinLimitTTL}`
           type: 'success'
         } as const;
       } catch (err) {
-        fastify.log.error(err);
+        logger.error(err);
         fastify.Sentry.captureException(err);
         void reply.code(500);
         return { message: 'flash.wrong-updating', type: 'danger' } as const;
@@ -530,6 +571,7 @@ ${isLinkSentWithinLimitTTL}`
       schema: schemas.updateMyHonesty
     },
     async (req, reply) => {
+      const logger = fastify.log.child({ req });
       try {
         await fastify.prisma.user.update({
           where: { id: req.user?.id },
@@ -543,7 +585,7 @@ ${isLinkSentWithinLimitTTL}`
           type: 'success'
         } as const;
       } catch (err) {
-        fastify.log.error(err);
+        logger.error(err);
         fastify.Sentry.captureException(err);
         void reply.code(500);
         return { message: 'flash.wrong-updating', type: 'danger' } as const;
@@ -557,6 +599,7 @@ ${isLinkSentWithinLimitTTL}`
       schema: schemas.updateMyPrivacyTerms
     },
     async (req, reply) => {
+      const logger = fastify.log.child({ req });
       try {
         await fastify.prisma.user.update({
           where: { id: req.user?.id },
@@ -571,7 +614,7 @@ ${isLinkSentWithinLimitTTL}`
           type: 'success'
         } as const;
       } catch (err) {
-        fastify.log.error(err);
+        logger.error(err);
         fastify.Sentry.captureException(err);
         void reply.code(500);
         return { message: 'flash.wrong-updating', type: 'danger' } as const;
@@ -585,6 +628,7 @@ ${isLinkSentWithinLimitTTL}`
       schema: schemas.updateMyPortfolio
     },
     async (req, reply) => {
+      const logger = fastify.log.child({ req });
       try {
         // TODO(Post-MVP): make all properties required in the schema and use
         // req.body.portfolio directly.
@@ -609,7 +653,7 @@ ${isLinkSentWithinLimitTTL}`
           type: 'success'
         } as const;
       } catch (err) {
-        fastify.log.error(err);
+        logger.error(err);
         fastify.Sentry.captureException(err);
         void reply.code(500);
         return { message: 'flash.wrong-updating', type: 'danger' } as const;
@@ -623,6 +667,7 @@ ${isLinkSentWithinLimitTTL}`
       schema: schemas.updateMyClassroomMode
     },
     async (req, reply) => {
+      const logger = fastify.log.child({ req });
       try {
         const classroomMode = req.body.isClassroomAccount;
 
@@ -638,7 +683,7 @@ ${isLinkSentWithinLimitTTL}`
           type: 'success'
         } as const;
       } catch (err) {
-        fastify.log.error(err);
+        logger.error(err);
         fastify.Sentry.captureException(err);
         void reply.code(403);
         return { message: 'flash.wrong-updating', type: 'danger' } as const;
@@ -708,7 +753,9 @@ export const settingRedirectRoutes: FastifyPluginCallbackTypebox = (
     {
       schema: schemas.confirmEmail,
       errorHandler(error, request, reply) {
+        const logger = fastify.log.child({ req: request });
         if (error.validation) {
+          logger.warn({ validationError: error.validation });
           const { origin } = getRedirectParams(request);
           void reply.redirectWithMessage(origin, redirectMessage);
         } else {
@@ -717,10 +764,12 @@ export const settingRedirectRoutes: FastifyPluginCallbackTypebox = (
       }
     },
     async (req, reply) => {
+      const logger = fastify.log.child({ req });
       const email = Buffer.from(req.query.email, 'base64').toString();
 
       const { origin } = getRedirectParams(req);
       if (!isEmail(email)) {
+        logger.warn(`Invalid email ${email}`);
         return reply.redirectWithMessage(origin, redirectMessage);
       }
 
@@ -729,11 +778,13 @@ export const settingRedirectRoutes: FastifyPluginCallbackTypebox = (
       });
 
       if (!authToken) {
+        logger.warn('No token found');
         return reply.redirectWithMessage(origin, redirectMessage);
       }
 
       // TODO(Post-MVP): clean up expired auth tokens.
       if (isExpired(authToken)) {
+        logger.info('Token expired');
         return reply.redirectWithMessage(origin, expirationMessage);
       }