Improve Winston logging

.gitignore

@@ -6,7 +6,8 @@ yarn-debug.log*
 yarn-error.log*
 lerna-debug.log*
 .pnpm-debug.log*
-Logging
+logging
+logs.json
 
 # Diagnostic reports (https://nodejs.org/api/report.html)
 report.[0-9]*.[0-9]*.[0-9]*.[0-9]*.json

src/api/controllers/info.controller.ts

@@ -75,6 +75,7 @@ export const infoController = new Elysia({
     );
 
 function readLogFile() {
-    const logPath = path.join(srcFolder, "Logging", "logs.json");
-    return JSON.parse(fs.readFileSync(logPath, "utf-8"));
+    const logPath = path.join(srcFolder, "logging", "logs.json");
+    const lines = fs.readFileSync(logPath, "utf-8").split("\n").filter(Boolean);
+    return lines.map((line) => JSON.parse(line));
 }

src/api/controllers/trigger.controller.ts

@@ -27,7 +27,7 @@ export const triggerController = new Elysia({
   .post(
     "/wipe-logs",
     async () => {
-      const logPath = path.join(import.meta.dir, "..", "..", "Logging", "logs.json");
+      const logPath = path.join(import.meta.dir, "..", "..", "logging", "logs.json");
       fs.writeFileSync(logPath, JSON.stringify([]), "utf8");
       return { message: "Wiped all logs!" };
     },

src/app.ts

@@ -4,8 +4,6 @@ import { Client } from "#structures/index";
 import { GatewayIntentBits } from "discord.js";
 import { registerEvents, RSA, updateBotStats } from "#utils/index";
 import { runChecks } from "#checks/run";
-import path from "path";
-import fs from "fs";
 import { syncAnilistUsers, type WorkerResponseUnion } from "#workers/index";
 import { env } from "#env";
 import { eq, sql } from "drizzle-orm";
@@ -29,20 +27,6 @@ async function start(token: string | undefined) {
   client.login(token);
   await updateBotStats(client);
 
-  const logPath = path.join(import.meta.dir, 'Logging/logs.json')
-  const currentDate = new Date().toISOString().replace(/T/, ' ').replace(/\..+/, '')
-
-  if (!fs.existsSync(path.join(import.meta.dir, 'Logging')))
-    fs.mkdirSync(path.join(import.meta.dir, 'Logging'))
-
-  if (!fs.existsSync(logPath))
-    fs.writeFileSync(logPath, JSON.stringify(
-      [{
-        date: currentDate,
-        user: "SYSTEM_LOGGER",
-        info: "Initialized log!"
-      }]));
-
   env().UPTIME = Date.now();
 }
 
@@ -72,7 +56,7 @@ workerManager.onmessage = async (e) => {
 
   switch (data.type) {
     case 'LOG': {
-      client.log(data.text, data.category);
+      client.logger.log(data.level, data.text);
       break;
     }
     case "SYNC": {
@@ -84,4 +68,4 @@ workerManager.onmessage = async (e) => {
       break;
     }
   }
-};
+};

src/caching/redis.ts

@@ -1,5 +1,5 @@
 import { createClient } from "redis";
-import { client } from "app";
+import { client } from "#src/app";
 import { env } from "#env";
 
 const host = env().NODE_ENV === "docker" ? "dragonfly" : "localhost";
@@ -16,7 +16,7 @@ redis.on("error", (err) => {
 });
 
 redis.on("connect", () => {
-  client.log(`Connected to ${host}!`, "info");
+  client.logger.info(`Connected to ${host}!`);
   redis.set("test", "test");
 });
 

src/checks/run.ts

@@ -15,28 +15,41 @@ export async function runChecks(client: Client) {
         }),
     )
   ).flat()
-  client.log(`Running ${checks.length} checks...`, "info")
+  client.logger.info("Running checks", { type: "check", total: checks.length });
 
   for (const check of checks) {
     try {
       check.run()
-      client.log(`[✅] Check "${check.name}" passed.`, "info")
+      client.logger.info("Check passed", { type: "check", name: check.name, optional: check.optional });
     }
     catch (e) {
       if (check.optional === true) {
-        client.log(`[⚠️] Optional check "${check.name}" failed. This may or may not cause problems in the future.
-              > Purpose: ${check.description}
-              > Why: ${e}
-              `, "warn")
+        client.logger.log("warn", "Optional check failed", {
+          type: "check",
+          name: check.name,
+          purpose: check.description,
+          why: serializeError(e),
+        });
       }
       else {
-        throw new Error(`[❌] FATAL: Critical check "${check.name}" failed. Cannot continue.
+        throw new Error(`Critical check "${check.name}" failed
               > Purpose: ${check.description}
               > Why: ${e}
               `)
       }
     }
   }
 
-  client.log(`Checks passed!`, "info")
+  client.logger.info("Checks passed!");
 }
+
+function serializeError(e: unknown) {
+  if (e instanceof Error) {
+    return {
+      message: e.message,
+      stack: e.stack,
+      name: e.name,
+    };
+  }
+  return e;
+}

src/checks/verifyEnv.ts

@@ -22,8 +22,7 @@ const clientIDCheck = new Check({
 
 const guildIDCheck = new Check({
   name: 'Guild ID Check',
-  description: `Check if process.env.GUILD_ID is present and valid.
-    This is required for slash commands to be instantly visible in a guild when developing.`,
+  description: `Check if process.env.GUILD_ID is present and valid. This is required for slash commands to be instantly visible in a guild when developing.`,
   optional: true,
   run: () => {
     if (!process.env.GUILD_ID)

src/commands/activity.ts

@@ -38,7 +38,7 @@ export default {
         }, interaction.ALtoken)
       ).data.User;
 
-      if (!uData?.id) throw new YuukoError("Couldn't find user id.", vars);
+      if (!uData?.id) throw new YuukoError("Couldn't find user id.", { vars });
       vars.userid = uData?.id;
 
     }
@@ -48,7 +48,7 @@ export default {
     } = await graphQLRequest("Activity", vars, interaction.ALtoken);
 
     if (!data) {
-      throw new YuukoError("Couldn't find any data.", vars);
+      throw new YuukoError("Couldn't find any data.", { vars });
     }
 
     const embed = new EmbedBuilder().setTimestamp(data?.createdAt * 1000);
@@ -161,4 +161,4 @@ function replaceUrls(input: string): string {
   }
 
   return newString;
-}
+}

src/commands/airing.ts

@@ -37,7 +37,7 @@ export default {
     if (period) {
       // @ts-ignore can't think of any other way to get around this
       airingIn = ms(period);
-      if (!airingIn) throw new YuukoError("Invalid time format. See `/help` for more information.", { period });
+      if (!airingIn) throw new YuukoError("Invalid time format. See `/help` for more information.", { vars: { period } });
     }
 
     // ^ Get current day and time in UTC
@@ -75,7 +75,7 @@ export default {
       data: { Page: data },
       headers,
     } = await graphQLRequest("Airing", vars);
-    if (!data || !data.airingSchedules) throw new YuukoError("No airing anime found.", vars);
+    if (!data || !data.airingSchedules) throw new YuukoError("No airing anime found.", { vars });
     const { airingSchedules } = data;
 
     const chunkSize = 5;

src/commands/anime.ts

@@ -34,16 +34,13 @@ export default {
       if (cachedId) {
         animeIdFound = true;
         vars.aID = parseInt(cachedId);
-        client.log(`Found cached data for ${normalizedQuery}, ID ${vars.aID}`, "debug");
+        client.logger.debug("Series cache hit", { type: "commandDebug", command: name, query: normalizedQuery, seriesId: vars.aID, mediaType: "ANIME" })
       }
 
     } else {
       vars.aID = hookData.id;
     }
 
-    client.log(`Anime ID: ${vars.aID}`, "debug");
-
-    client.log(`Querying Redis with hook animeId ${vars.aID}`, "debug");
     const cacheData = (await redis.json.get(`_anime-${vars.aID}`)) as AnimeQuery["Media"] | null;
 
     if (cacheData) {
@@ -55,19 +52,18 @@ export default {
         if (mediaListEntry) cacheData.mediaListEntry = mediaListEntry;
       }
 
-      client.log("Found cache data, returning data...", "debug");
+      client.logger.debug("User cache hit", { type: "commandDebug", command: name, seriesId: vars.aID, anilistId: interaction.alID })
 
-      return void handleData({ media: cacheData }, interaction, "ANIME");
+      return void handleData({ media: cacheData }, interaction, client, "ANIME");
     }
 
-    client.log("No cache found, fetching from CringeQL", "debug");
     const {
       data: { Media: data },
       headers,
     } = await graphQLRequest("Anime", vars, interaction.ALtoken);
 
     if (!data) {
-      throw new YuukoError("No anime found.", vars);
+      throw new YuukoError("No anime found.", { vars });
     }
 
     if (!animeIdFound) redis.set(`_animeId-${vars.query}`, data.id);
@@ -79,9 +75,9 @@ export default {
       redis.set(`_animeId-${normalize(synonym)}`, data.id);
     }
     if (redisData.nextAiringEpisode?.airingAt) {
-      client.log(`Expiring anime-${redisData.id} at ${redisData.nextAiringEpisode.airingAt}`, "debug");
+      client.logger.debug("Adding expiration date", { type: "commandDebug", command: name, seriesId: redisData.id, airingAt: redisData.nextAiringEpisode.airingAt })
       redis.expireAt(`_anime-${data.id}`, redisData.nextAiringEpisode.airingAt);
     }
-    return void await handleData({ media: data, headers: headers }, interaction, "ANIME", hookData);
+    return void await handleData({ media: data, headers: headers }, interaction, client, "ANIME", hookData);
   },
 } satisfies Command<{ id?: number, anime?: string }>;

src/commands/auth.ts

@@ -42,7 +42,7 @@ export default {
         const user = (await db.select().from(anilistUser).where(eq(anilistUser.discordId, interaction.user.id)).limit(1))[0];
 
         if (subcommandType === "wipe") {
-            if (!user) throw new YuukoError("You don't have an AniList account bound to your Discord account.", null, true)
+            if (!user) throw new YuukoError("You don't have an AniList account bound to your Discord account.", { ephemeral: true })
             await db.delete(anilistUser).where(eq(anilistUser.discordId, interaction.user.id));
 
             await updateBotStats(client);

src/commands/character.ts

@@ -24,7 +24,7 @@ export default {
       headers,
     } = await graphQLRequest("Character", { charName });
 
-    if (!data) throw new YuukoError("Couldn't find this character.", { charName });
+    if (!data) throw new YuukoError("Couldn't find this character.", { vars: { charName } });
 
     const embeds = [];
     const description =

src/commands/makeactivity.ts

@@ -93,7 +93,7 @@ export default {
       const statusData = hookData?.subcommandType === "status" ? hookData : undefined;
       const statusText = statusData?.text ?? interaction.options.getString("text", true);
       const vars = { text: getEmojis(statusText), asHtml: true };
-      if (!interaction.ALtoken) throw new YuukoError("No Anilist token found.", null, true);
+      if (!interaction.ALtoken) throw new YuukoError("No Anilist token found.", { ephemeral: true });
 
       const {
         data: { SaveTextActivity: data },
@@ -126,13 +126,13 @@ export default {
         }
       }
 
-      if (!interaction.ALtoken) throw new YuukoError("No Anilist token found.", null, true);
+      if (!interaction.ALtoken) throw new YuukoError("No Anilist token found.", { ephemeral: true });
 
       const {
         data: { SaveMediaListEntry: data },
         headers,
       } = await graphQLRequest("SaveMediaList", vars, interaction.ALtoken);
-      if (!data) throw new YuukoError("Something went wrong while making the activity.", null, true);
+      if (!data) throw new YuukoError("Something went wrong while making the activity.", { ephemeral: true });
       const mediaListActivity = new EmbedBuilder()
         .setURL(`https://anilist.co/${data?.media?.type || ""}/${data?.mediaId || ""}`)
         .setTitle(`${data.user?.name || "Unknown"} added ${data?.media?.title?.userPreferred || "Unknown"} to ${data?.status || "Unknown"}!`)

src/commands/manga.ts

@@ -38,7 +38,7 @@ export default {
       if (cachedId) {
         mangaIdFound = true;
         vars.mID = parseInt(cachedId);
-        client.log(`Found cached data for ${normalizedQuery}, ID ${vars.mID}`, "debug");
+        client.logger.debug("Series cache hit", { query: normalizedQuery, seriesId: vars.mID, type: "generic", mediaType: "MANGA" })
       }
 
     } else {
@@ -50,33 +50,36 @@ export default {
     if (cacheData) {
       if (interaction.alID) {
         const _mediaListEntry = await redis.json.get(`_user${interaction.alID}-MANGA`) as Record<number, CacheEntry>;
-        if (!vars.mID) throw new YuukoError("No mID found in cache data.", vars);
+        if (!vars.mID) throw new YuukoError("No mID found in cache data.", { vars });
         const mediaListEntry = _mediaListEntry ? _mediaListEntry[vars.mID] : null;
         if (mediaListEntry) cacheData.mediaListEntry = mediaListEntry;
       }
-      client.log("[MangaCmd] Found cache data, returning data...", "debug");
-      return void handleData({ media: cacheData }, interaction, "MANGA");
-    }
 
-    client.log("[MangaCmd] No cache found, fetching from CringeQL", "debug");
+      client.logger.debug("User cache hit", { seriesId: vars.mID, anilistId: interaction.alID, type: "generic" })
+
+      return void handleData({ media: cacheData }, interaction, client, "MANGA");
+    }
 
     const {
       data: { Media: data },
       headers,
     } = await graphQLRequest("Manga", vars, interaction.ALtoken);
 
     if (!data) {
-      throw new YuukoError("Couldn't find any data.", vars);
+      throw new YuukoError("Couldn't find any data.", { vars });
     }
 
     if (!mangaIdFound) redis.set(`_mangaId-${vars.query}`, data.id);
+
     const { mediaListEntry, ...redisData } = data;
     redis.json.set(`_manga-${data.id}`, "$", redisData);
     redis.expireAt(`_manga-${redisData.id}`, new Date(Date.now() + 604800000))
+
     for (const synonym of redisData.synonyms || []) {
       if (!synonym) continue;
       redis.set(`_mangaId-${normalize(synonym)}`, data.id.toString());
     }
-    return void handleData({ media: data, headers: headers }, interaction, "MANGA", hookData);
+
+    return void handleData({ media: data, headers: headers }, interaction, client, "MANGA", hookData);
   },
-} satisfies Command<{ id?: number, manga?: string }>;
+} satisfies Command<{ id?: number, manga?: string }>;

src/commands/pixel_jumble.ts

@@ -50,7 +50,7 @@ export default {
         const vars = { type, userId: interaction.alID, chunk: Math.floor(Math.random() * totalSize) };
         const { data: { MediaListCollection: data } } = await graphQLRequest("PixelJumble", vars);
 
-        if (!data || !data.lists || data.lists.length < 1) throw new YuukoError("Couldn't find any data from the user specified.", vars);
+        if (!data || !data.lists || data.lists.length < 1) throw new YuukoError("Couldn't find any data from the user specified.", { vars });
 
         const allMediaItems = data.lists
             .flatMap(list => list?.entries);

src/commands/recent.ts

@@ -32,7 +32,7 @@ export default {
 
     if (!userName) {
       // We try to use the one the user set
-      if (!interaction.alID) throw new YuukoError("You have yet to set an AniList token.", null, true)
+      if (!interaction.alID) throw new YuukoError("You have yet to set an AniList token.", { ephemeral: true })
       vars.userId = interaction.alID;
     } else {
       vars.user = userName;
@@ -41,7 +41,7 @@ export default {
     const {
       data: { Page: data },
     } = await graphQLRequest("RecentChart", vars, interaction.ALtoken);
-    if (!data?.mediaList) throw new YuukoError("Unable to find specified user.", vars, true);
+    if (!data?.mediaList) throw new YuukoError("Unable to find specified user.", { vars, ephemeral: true });
     await interaction.deferReply();
 
     const parsedData = [];
@@ -56,6 +56,8 @@ export default {
       parsedData.push({ status: `${status}\n${title}`, imageUrl: cover });
     }
 
+    client.logger.debug("Recent command", { type: "generic", total: parsedData.length, userName: vars.user });
+
     const lib = client.modules.getModule("modules");
 
     const enc = new TextEncoder();