feat: add proper logging with winston

.gitignore

@@ -1,6 +1,7 @@
 dist/
 node_modules/
-generated/prisma
+generated/
+logs/
 package-lock.json
 .env
 

README.md

@@ -16,3 +16,5 @@
 |`CLIENT_ID`|Discord application client ID.|✔||
 |`CLIENT_SECRET`|Discord application client secret.|✔||
 |`DISCORD_USER_IDS`|CSV of Discord User IDs allowed to access the web ui.|✔||
+|`LOG_LEVEL`|Manually set the log level (not recommended).||`info`|
+|`LOG_DIR`|Override the default output directory for log files.|||

package.json

@@ -60,6 +60,7 @@
     "@floating-ui/dom": "^1.6.13",
     "@prisma/client": "^6.6.0",
     "@tailwindcss/forms": "^0.5.10",
+    "chalk": "^5.4.1",
     "datatables.net-dt": "^2.2.2",
     "datatables.net-select": "^3.0.0",
     "datatables.net-select-dt": "^3.0.0",

src/app.ts

@@ -11,6 +11,10 @@ import homeRouter from "@server/routers/home.router";
 import guildRouter from "@server/routers/guild.router";
 import { attachGuilds } from "@server/middleware/attachGuilds";
 import { guildTabHelper } from "@server/middleware/guildTabHelper";
+import { requestLog } from "@server/middleware/requestLog";
+import { getLogger } from "./log";
+
+const logger = getLogger(__filename);
 
 const app = express();
 
@@ -19,6 +23,7 @@ app.set("view engine", "ejs");
 app.set("views", path.resolve(__dirname, "client/views"));
 app.use(express.urlencoded({ extended: true }));
 app.use(express.json());
+app.use(requestLog);
 
 app.use("/public", express.static(path.resolve(__dirname, "client/public")));
 
@@ -29,11 +34,11 @@ const HOST = process.env.HOST || "localhost";
 const PORT = process.env.PORT || 3000;
 
 const server = app.listen(PORT, () => {
-    console.log(`Server is listening on port http://${HOST}:${PORT}`);
+    logger.info(`Server is listening on port http://${HOST}:${PORT}`);
 });
 
 process.on("SIGINT", () => {
-    console.log("\nShutdown signal received...");
+    logger.info("Shutdown signal received...");
 
     prisma.$disconnect();
     server.close(error => {

src/bot/events/ready.ts

@@ -1,6 +1,9 @@
 import { ActivityType } from "discord.js";
 import Event from "@bot/components/event";
 import DiscordBot from "@bot/bot";
+import { getLogger } from "src/log";
+
+const logger = getLogger(__filename);
 
 export default class Ready extends Event {
     name = "ready";
@@ -14,6 +17,6 @@ export default class Ready extends Event {
         await client.interactions.deploy();
 
         client.user.setActivity("new sources", {type: ActivityType.Watching});
-        console.log(`Discord Bot ${client.user.displayName} is online!`);
+        logger.info(`Discord Bot ${client.user.displayName} is online!`)
     }
 }

src/bot/task.ts

@@ -4,6 +4,9 @@ import { parse as HtmlParser } from "node-html-parser";
 import { Feed, Filter, MessageStyle, Channel, MatchingAlgorithms } from "../../generated/prisma";
 import * as filters from "@bot/filter";
 import prisma from "@server/prisma";
+import { getLogger } from "src/log";
+
+const logger = getLogger(__filename);
 
 export const triggerTask = async (client: Client) => {
     for (const [_, guild] of client.guilds.cache) {
@@ -42,7 +45,7 @@ const processFeed = async (feed: ExpandedFeed, client: Client) => {
     const parsed = await getParsedUrl(feed.url);
     if (!parsed) return;
 
-    console.log(`Processing feed: ${feed.name}`);
+    logger.debug(`Processing feed: ${feed.name}`);
 
     for (const channelId of feed.channels.map(channel => channel.channel_id)) {
         const channel = client.channels.cache.get(channelId);
@@ -51,11 +54,11 @@ const processFeed = async (feed: ExpandedFeed, client: Client) => {
 };
 
 const processItems = async (items: RssParser.Item[], feed: ExpandedFeed, channel: DiscordChannel) => {
-    console.log(`Processing ${items.length} items`);
+    logger.debug(`Processing ${items.length} items`);
 
     for (let i = items.length; i--;) {
         if (new Date(items[i].pubDate!) < feed.published_threshold) {
-            console.log(`skipping outdated item: ${items[i].title}`)
+            logger.debug(`skipping outdated item: ${items[i].title}`)
             items.splice(i, 1);
             continue;
         }
@@ -65,15 +68,15 @@ const processItems = async (items: RssParser.Item[], feed: ExpandedFeed, channel
         }
     }
 
-    console.log(`Processing ${items.length} items (post-filter)`)
+    logger.debug(`Processing ${items.length} items (post-filter)`)
 
     const batchSize = 4;
     const totalBatches = Math.floor((items.length + batchSize - 1) / batchSize);
 
-    console.log(`batchSize: ${batchSize}, totalBatches: ${totalBatches}`)
+    logger.debug(`batchSize: ${batchSize}, totalBatches: ${totalBatches}`)
 
     for (let batchNumber = 0; batchNumber * batchSize < items.length; batchNumber++) {
-        console.log(`Processing items batch [${batchNumber+1}/${totalBatches}]`);
+        logger.debug(`Processing items batch [${batchNumber+1}/${totalBatches}]`);
 
         const i = batchNumber * batchSize;
         const batch = items.slice(i, i + batchSize);
@@ -142,7 +145,7 @@ const passesFilter = async (filter: Filter, item: RssParser.Item) => {
         );
     }
 
-    console.log(`Filter result: matchFound=${matchFound}, is_whitelist=${filter.is_whitelist}, willSend=${filter.is_whitelist ? matchFound : !matchFound}`);
+    logger.debug(`Filter result: matchFound=${matchFound}, is_whitelist=${filter.is_whitelist}, willSend=${filter.is_whitelist ? matchFound : !matchFound}`);
 
     return filter.is_whitelist ? matchFound : !matchFound;
 };

src/log.ts

@@ -1,18 +1,101 @@
 import winston from "winston";
+import chalk from "chalk";
+import path from "path";
+import fs from "fs";
 
-const { combine, timestamp, json, printf } = winston.format;
+const logFileDirectory = process.env.LOG_DIR || path.join(__dirname, "..", "logs");
+if (!fs.existsSync(logFileDirectory)) {
+    fs.mkdirSync(logFileDirectory);
+}
+
+const deleteLogFile =(filePath: string) => {
+    try {
+        fs.unlinkSync(filePath);
+        logger.info("Deleted expired log file", { filename: __filename });
+    } catch (error) {
+        logger.error("Failed to expired log file:", error);
+    }
+}
+
+const cleanExpiredLogFiles = () => {
+    const files = fs.readdirSync(logFileDirectory);
+    const now = Date.now();
+    const maxAgeMs = 7 * 24 * 60 * 60 * 1000;
+
+    for (const file of files) {
+        const filePath = path.join(logFileDirectory, file);
+        const stats = fs.statSync(filePath);
+
+        if (stats.isFile() && now - stats.mtimeMs > maxAgeMs) {
+            deleteLogFile(filePath);
+        }
+    }
+};
+
+const { combine, timestamp, errors, printf } = winston.format;
 const timestampFormat = "YYYY-MM-DD HH:mm:ss";
+const levelColours: Record<string, any> = {
+    info: chalk.green,
+    warn: chalk.yellow,
+    error: chalk.red,
+    debug: chalk.magenta,
+}
+
+const consoleFormat = combine(
+    errors({ stack: true }),
+    timestamp({ format: timestampFormat }),
+    printf(({ timestamp, level, message, filename }) => {
+        const levelColour = levelColours[level] || chalk.white;
+    
+        level = levelColour(level);
+        timestamp = chalk.cyan(timestamp);
+        message = chalk.white(message);
+        filename = chalk.white(filename || "unknown")
+    
+        return `[${level}] (${filename}) ${timestamp}: ${message}`;
+    })
+);
+
+const consoleFormatHttp = combine(
+    errors({ stack: true }),
+    timestamp({ format: timestampFormat }),
+    printf(({ timestamp, level, method, path, status, duration }) => {    
+        return `[${level}] ${timestamp} [${method}] (${status}) ${path} ${duration}ms`;
+    })    
+);
+
+const fileFormat = combine(
+    errors({ stack: true }),
+    timestamp({ format: timestampFormat }),
+    printf(({ timestamp, level, message, filename }) => {    
+        return `[${level}] (${filename || "unknown"}) ${timestamp}: ${message}`;
+    })
+);
+
+const sessionTimestamp = new Date().toISOString()
+    .replace(/T/, "_")
+    .replace(/:/g, "-")
+    .replace(/\..+/, "");
+const sessionLogFile = path.join(logFileDirectory, `${sessionTimestamp}.log`);
 
 export const logger = winston.createLogger({
-    format: combine(
+    level: process.env.LOG_LEVEL || "info",
-        timestamp({ format: timestampFormat }),
+    levels: winston.config.syslog.levels,
-        json(),
-        printf(({ _timestamp, level, message, ...data }) => {
-            const response = { level, message, data };
-            return JSON.stringify(response);
-        })
-    ),
     transports: [
-        new winston.transports.Console()
+        new winston.transports.Console({
+            level: "debug",
+            format: consoleFormat
+        }),
+        new winston.transports.File({
+            filename: sessionLogFile,
+            level: "info",
+            format: fileFormat
+        })
     ]
-});
+});
+
+cleanExpiredLogFiles();
+
+export const getLogger = (file: string) => {
+    return logger.child({ filename: path.relative(__dirname, file).replace(/\\/g, "/") });
+}

src/server/middleware/requestLog.ts

@@ -0,0 +1,18 @@
+import { Request, Response, NextFunction } from "express";
+import { logger } from "src/log";
+
+// const logger = getLogger(__filename);
+
+export const requestLog = (request: Request, response: Response, next: NextFunction) => {
+    // const start = Date.now();
+    // response.on("finish", () => {
+    //     const duration = Date.now() - start;
+    //     httpLogger.info({
+    //         method: request.method,
+    //         path: request.path,
+    //         status: response.statusCode,
+    //         duration: duration
+    //     });
+    // });
+    next();
+};