impr(server): store some logs forever (@miodec) (#5708)

!nuf

backend/src/api/controllers/quote.ts

@@ -9,6 +9,7 @@ import { verify } from "../../utils/captcha";
 import Logger from "../../utils/logger";
 import { MonkeyResponse } from "../../utils/monkey-response";
 import { ObjectId } from "mongodb";
+import { addLog } from "../../dal/logs";
 
 async function verifyCaptcha(captcha: string): Promise<void> {
   if (!(await verify(captcha))) {
@@ -70,7 +71,7 @@ export async function approveQuote(
   }
 
   const data = await NewQuotesDAL.approve(quoteId, editText, editSource, name);
-  void Logger.logToDb("system_quote_approved", data, uid);
+  void addLog("system_quote_approved", data, uid);
 
   return new MonkeyResponse(data.message, data.quote);
 }

backend/src/api/controllers/result.ts

@@ -41,6 +41,7 @@ import {
   Configuration,
   PostResultResponse,
 } from "@monkeytype/shared-types";
+import { addLog } from "../../dal/logs";
 
 try {
   if (!anticheatImplemented()) throw new Error("undefined");
@@ -103,7 +104,7 @@ export async function getResults(
     limit,
     offset,
   });
-  void Logger.logToDb(
+  void addLog(
     "user_results_requested",
     {
       limit,
@@ -130,7 +131,7 @@ export async function deleteAll(
   const { uid } = req.ctx.decodedToken;
 
   await ResultDAL.deleteAll(uid);
-  void Logger.logToDb("user_results_deleted", "", uid);
+  void addLog("user_results_deleted", "", uid);
   return new MonkeyResponse("All results deleted");
 }
 
@@ -205,7 +206,7 @@ export async function addResult(
   if (req.ctx.configuration.results.objectHashCheckEnabled) {
     const serverhash = objectHash(completedEvent);
     if (serverhash !== resulthash) {
-      void Logger.logToDb(
+      void addLog(
         "incorrect_result_hash",
         {
           serverhash,
@@ -306,7 +307,7 @@ export async function addResult(
   const earliestPossible = (lastResultTimestamp ?? 0) + testDurationMilis;
   const nowNoMilis = Math.floor(Date.now() / 1000) * 1000;
   if (lastResultTimestamp && nowNoMilis < earliestPossible - 1000) {
-    void Logger.logToDb(
+    void addLog(
       "invalid_result_spacing",
       {
         lastTimestamp: lastResultTimestamp,
@@ -376,7 +377,7 @@ export async function addResult(
   if (req.ctx.configuration.users.lastHashesCheck.enabled) {
     let lastHashes = user.lastReultHashes ?? [];
     if (lastHashes.includes(resulthash)) {
-      void Logger.logToDb(
+      void addLog(
         "duplicate_result",
         {
           lastHashes,
@@ -591,7 +592,7 @@ export async function addResult(
   await UserDAL.incrementTestActivity(user, completedEvent.timestamp);
 
   if (isPb) {
-    void Logger.logToDb(
+    void addLog(
       "user_new_pb",
       `${completedEvent.mode + " " + completedEvent.mode2} ${
         completedEvent.wpm

backend/src/api/controllers/user.ts

@@ -37,6 +37,7 @@ import {
   UserProfile,
   UserProfileDetails,
 } from "@monkeytype/shared-types";
+import { addImportantLog, addLog, deleteUserLogs } from "../../dal/logs";
 
 async function verifyCaptcha(captcha: string): Promise<void> {
   if (!(await verify(captcha))) {
@@ -68,7 +69,7 @@ export async function createNewUser(
     }
 
     await UserDAL.addUser(name, email, uid);
-    void Logger.logToDb("user_created", `${name} ${email}`, uid);
+    void addImportantLog("user_created", `${name} ${email}`, uid);
 
     return new MonkeyResponse("User created");
   } catch (e) {
@@ -206,6 +207,7 @@ export async function deleteUser(
   //cleanup database
   await Promise.all([
     UserDAL.deleteUser(uid),
+    deleteUserLogs(uid),
     deleteAllApeKeys(uid),
     deleteAllPresets(uid),
     deleteConfig(uid),
@@ -219,7 +221,7 @@ export async function deleteUser(
   //delete user from
   await AuthUtil.deleteUser(uid);
 
-  void Logger.logToDb(
+  void addImportantLog(
     "user_deleted",
     `${userInfo.email} ${userInfo.name}`,
     uid
@@ -259,7 +261,7 @@ export async function resetUser(
     promises.push(GeorgeQueue.unlinkDiscord(userInfo.discordId, uid));
   }
   await Promise.all(promises);
-  void Logger.logToDb("user_reset", `${userInfo.email} ${userInfo.name}`, uid);
+  void addImportantLog("user_reset", `${userInfo.email} ${userInfo.name}`, uid);
 
   return new MonkeyResponse("User reset");
 }
@@ -289,7 +291,7 @@ export async function updateName(
   }
 
   await UserDAL.updateName(uid, name, user.name);
-  void Logger.logToDb(
+  void addImportantLog(
     "user_name_updated",
     `changed name from ${user.name} to ${name}`,
     uid
@@ -308,7 +310,7 @@ export async function clearPb(
     uid,
     req.ctx.configuration.dailyLeaderboards
   );
-  void Logger.logToDb("user_cleared_pbs", "", uid);
+  void addImportantLog("user_cleared_pbs", "", uid);
 
   return new MonkeyResponse("User's PB cleared");
 }
@@ -323,7 +325,7 @@ export async function optOutOfLeaderboards(
     uid,
     req.ctx.configuration.dailyLeaderboards
   );
-  void Logger.logToDb("user_opted_out_of_leaderboards", "", uid);
+  void addImportantLog("user_opted_out_of_leaderboards", "", uid);
 
   return new MonkeyResponse("User opted out of leaderboards");
 }
@@ -377,7 +379,7 @@ export async function updateEmail(
     }
   }
 
-  void Logger.logToDb(
+  void addImportantLog(
     "user_email_updated",
     `changed email to ${newEmail}`,
     uid
@@ -461,7 +463,7 @@ export async function getUser(
   };
 
   const agentLog = buildAgentLog(req);
-  void Logger.logToDb("user_data_requested", agentLog, uid);
+  void addLog("user_data_requested", agentLog, uid);
   void UserDAL.logIpAddress(uid, agentLog.ip, userInfo);
 
   let inboxUnreadSize = 0;
@@ -556,7 +558,7 @@ export async function linkDiscord(
   await UserDAL.linkDiscord(uid, discordId, discordAvatar);
 
   await GeorgeQueue.linkDiscord(discordId, uid);
-  void Logger.logToDb("user_discord_link", `linked to ${discordId}`, uid);
+  void addImportantLog("user_discord_link", `linked to ${discordId}`, uid);
 
   return new MonkeyResponse("Discord account linked", {
     discordId,
@@ -585,7 +587,7 @@ export async function unlinkDiscord(
 
   await GeorgeQueue.unlinkDiscord(discordId, uid);
   await UserDAL.unlinkDiscord(uid);
-  void Logger.logToDb("user_discord_unlinked", discordId, uid);
+  void addImportantLog("user_discord_unlinked", discordId, uid);
 
   return new MonkeyResponse("Discord account unlinked");
 }
@@ -957,6 +959,8 @@ export async function setStreakHourOffset(
 
   await UserDAL.setStreakHourOffset(uid, hourOffset);
 
+  void addImportantLog("user_streak_hour_offset_set", { hourOffset }, uid);
+
   return new MonkeyResponse("Streak hour offset set");
 }
 
@@ -980,6 +984,8 @@ export async function toggleBan(
     if (discordIdIsValid) await GeorgeQueue.userBanned(discordId, true);
   }
 
+  void addImportantLog("user_ban_toggled", { banned: !user.banned }, uid);
+
   return new MonkeyResponse(`Ban toggled`, {
     banned: !user.banned,
   });
@@ -990,6 +996,7 @@ export async function revokeAllTokens(
 ): Promise<MonkeyResponse> {
   const { uid } = req.ctx.decodedToken;
   await AuthUtil.revokeTokensByUid(uid);
+  void addImportantLog("user_tokens_revoked", "", uid);
   return new MonkeyResponse("All tokens revoked");
 }
 

backend/src/dal/leaderboards.ts

@@ -5,6 +5,7 @@ import { setLeaderboard } from "../utils/prometheus";
 import { isDevEnvironment } from "../utils/misc";
 import { getCachedConfiguration } from "../init/configuration";
 import { LeaderboardEntry } from "@monkeytype/shared-types";
+import { addLog } from "./logs";
 
 export async function get(
   mode: string,
@@ -235,7 +236,7 @@ export async function update(
   const timeToRunIndex = (end2 - start2) / 1000;
   const timeToSaveHistogram = (end3 - start3) / 1000; // not sent to prometheus yet
 
-  void Logger.logToDb(
+  void addLog(
     `system_lb_update_${language}_${mode}_${mode2}`,
     `Aggregate ${timeToRunAggregate}s, loop 0s, insert 0s, index ${timeToRunIndex}s, histogram ${timeToSaveHistogram}`
   );

backend/src/dal/logs.ts

@@ -0,0 +1,58 @@
+import { Collection, ObjectId } from "mongodb";
+import * as db from "../init/db";
+import Logger from "../utils/logger";
+
+type DbLog = {
+  _id: ObjectId;
+  type?: string;
+  timestamp: number;
+  uid: string;
+  important?: boolean;
+  event: string;
+  message: string | Record<string, unknown>;
+};
+
+export const getLogsCollection = (): Collection<DbLog> =>
+  db.collection<DbLog>("logs");
+
+async function insertIntoDb(
+  event: string,
+  message: string | Record<string, unknown>,
+  uid = "",
+  important = false
+): Promise<void> {
+  const dbLog: DbLog = {
+    _id: new ObjectId(),
+    timestamp: Date.now(),
+    uid: uid ?? "",
+    event: event,
+    message: message,
+    important: important,
+  };
+
+  if (!important) delete dbLog.important;
+
+  Logger.info(`${event}\t${uid}\t${JSON.stringify(message)}`);
+
+  await getLogsCollection().insertOne(dbLog);
+}
+
+export async function addLog(
+  event: string,
+  message: string | Record<string, unknown>,
+  uid = ""
+): Promise<void> {
+  await insertIntoDb(event, message, uid);
+}
+
+export async function addImportantLog(
+  event: string,
+  message: string | Record<string, unknown>,
+  uid = ""
+): Promise<void> {
+  await insertIntoDb(event, message, uid, true);
+}
+
+export async function deleteUserLogs(uid: string): Promise<void> {
+  await getLogsCollection().deleteMany({ uid });
+}

backend/src/dal/user.ts

@@ -33,6 +33,7 @@ import {
   Mode2,
   PersonalBest,
 } from "@monkeytype/contracts/schemas/shared";
+import { addImportantLog } from "./logs";
 
 const SECONDS_PER_HOUR = 3600;
 
@@ -859,7 +860,7 @@ export async function recordAutoBanEvent(
   }
 
   await getUsersCollection().updateOne({ uid }, { $set: updateObj });
-  void Logger.logToDb(
+  void addImportantLog(
     "user_auto_banned",
     { autoBanTimestamps, banningUser },
     uid
@@ -1077,7 +1078,11 @@ export async function updateStreak(
   if (isYesterday(streak.lastResultTimestamp, streak.hourOffset ?? 0)) {
     streak.length += 1;
   } else if (!isToday(streak.lastResultTimestamp, streak.hourOffset ?? 0)) {
-    void Logger.logToDb("streak_lost", JSON.parse(JSON.stringify(streak)), uid);
+    void addImportantLog(
+      "streak_lost",
+      JSON.parse(JSON.stringify(streak)),
+      uid
+    );
     streak.length = 1;
   }
 

backend/src/init/configuration.ts

@@ -5,6 +5,7 @@ import Logger from "../utils/logger";
 import { identity } from "../utils/misc";
 import { BASE_CONFIGURATION } from "../constants/base-configuration";
 import { Configuration } from "@monkeytype/shared-types";
+import { addLog } from "../dal/logs";
 
 const CONFIG_UPDATE_INTERVAL = 10 * 60 * 1000; // 10 Minutes
 
@@ -84,7 +85,7 @@ export async function getLiveConfiguration(): Promise<Configuration> {
       }); // Seed the base configuration.
     }
   } catch (error) {
-    void Logger.logToDb(
+    void addLog(
       "fetch_configuration_failure",
       `Could not fetch configuration: ${error.message}`
     );
@@ -102,7 +103,7 @@ async function pushConfiguration(configuration: Configuration): Promise<void> {
     await db.collection("configuration").replaceOne({}, configuration);
     serverConfigurationUpdated = true;
   } catch (error) {
-    void Logger.logToDb(
+    void addLog(
       "push_configuration_failure",
       `Could not push configuration: ${error.message}`
     );
@@ -122,7 +123,7 @@ export async function patchConfiguration(
 
     await getLiveConfiguration();
   } catch (error) {
-    void Logger.logToDb(
+    void addLog(
       "patch_configuration_failure",
       `Could not patch configuration: ${error.message}`
     );

backend/src/jobs/delete-old-logs.ts

@@ -1,7 +1,7 @@
 import { CronJob } from "cron";
 import * as db from "../init/db";
-import Logger from "../utils/logger";
 import { getCachedConfiguration } from "../init/configuration";
+import { addLog } from "../dal/logs";
 
 const CRON_SCHEDULE = "0 0 0 * * *";
 const LOG_MAX_AGE_DAYS = 30;
@@ -13,11 +13,12 @@ async function deleteOldLogs(): Promise<void> {
     return;
   }
 
-  const data = await db
-    .collection("logs")
-    .deleteMany({ timestamp: { $lt: Date.now() - LOG_MAX_AGE_MILLISECONDS } });
+  const data = await db.collection("logs").deleteMany({
+    timestamp: { $lt: Date.now() - LOG_MAX_AGE_MILLISECONDS },
+    $or: [{ important: false }, { important: { $exists: false } }],
+  });
 
-  void Logger.logToDb(
+  void addLog(
     "system_logs_deleted",
     `${data.deletedCount} logs deleted older than ${LOG_MAX_AGE_DAYS} day(s)`,
     undefined

backend/src/middlewares/error.ts

@@ -12,6 +12,7 @@ import {
 import { isDevEnvironment } from "../utils/misc";
 import { ObjectId } from "mongodb";
 import { version } from "../version";
+import { addLog } from "../dal/logs";
 
 type DBError = {
   _id: ObjectId;
@@ -70,7 +71,7 @@ async function errorHandlingMiddleware(
       const { uid, errorId } = monkeyResponse.data;
 
       try {
-        await Logger.logToDb(
+        await addLog(
           "system_error",
           `${monkeyResponse.status} ${errorId} ${error.message} ${error.stack}`,
           uid

backend/src/utils/logger.ts

@@ -17,14 +17,6 @@ const infoColor = chalk.white;
 const logFolderPath = process.env["LOG_FOLDER_PATH"] ?? "./logs";
 const maxLogSize = parseInt(process.env["LOG_FILE_MAX_SIZE"] ?? "10485760");
 
-type Log = {
-  type?: string;
-  timestamp: number;
-  uid: string;
-  event: string;
-  message: string | Record<string, unknown>;
-};
-
 const customLevels = {
   error: 0,
   warning: 1,
@@ -90,33 +82,11 @@ const logger = createLogger({
   ],
 });
 
-const logToDb = async (
-  event: string,
-  message: string | Record<string, unknown>,
-  uid?: string
-): Promise<void> => {
-  const logsCollection = db.collection<Log>("logs");
-
-  logger.info(`${event}\t${uid}\t${JSON.stringify(message)}`);
-  logsCollection
-    .insertOne({
-      _id: new ObjectId(),
-      timestamp: Date.now(),
-      uid: uid ?? "",
-      event,
-      message,
-    })
-    .catch((error) => {
-      logger.error(`Could not log to db: ${error.message}`);
-    });
-};
-
 const Logger = {
   error: (message: string): LoggerType => logger.error(message),
   warning: (message: string): LoggerType => logger.warning(message),
   info: (message: string): LoggerType => logger.info(message),
   success: (message: string): LoggerType => logger.log("success", message),
-  logToDb,
 };
 
 export default Logger;

backend/src/workers/email-worker.ts

@@ -8,6 +8,7 @@ import EmailQueue, {
 } from "../queues/email-queue";
 import { sendEmail } from "../init/email-client";
 import { recordTimeToCompleteJob } from "../utils/prometheus";
+import { addLog } from "../dal/logs";
 
 async function jobHandler(job: Job): Promise<void> {
   const type: EmailType = job.data.type;
@@ -21,7 +22,7 @@ async function jobHandler(job: Job): Promise<void> {
   const result = await sendEmail(type, email, ctx);
 
   if (!result.success) {
-    void Logger.logToDb("error_sending_email", {
+    void addLog("error_sending_email", {
       type,
       email,
       ctx: JSON.stringify(ctx),