feat: better logging

apps/api/package.json

@@ -40,12 +40,15 @@
         "drizzle-orm": "^0.33.0",
         "express-session": "^1.18.0",
         "graphql": "^16.9.0",
+        "nest-winston": "^1.9.7",
         "passport": "^0.7.0",
         "passport-local": "^1.0.0",
         "pg": "^8.13.0",
         "redis": "^4.7.0",
         "reflect-metadata": "^0.2.0",
-        "rxjs": "^7.8.1"
+        "rxjs": "^7.8.1",
+        "winston": "^3.15.0",
+        "winston-daily-rotate-file": "^5.0.0"
     },
     "devDependencies": {
         "@nestjs/cli": "^10.0.0",

apps/api/src/app.module.ts

@@ -11,6 +11,7 @@ import { AuthenticatedGuard } from "./common/guards/auth.guard";
 import { DrizzleModule } from "./drizzle/drizzle.module";
 import { AuthModule } from "./modules/auth/auth.module";
 import { validate } from "./utils/env.validate";
+import { ApolloLogger } from "./utils/graphql.logger";
 
 @Module({
     imports: [
@@ -48,6 +49,7 @@ import { validate } from "./utils/env.validate";
             provide: APP_GUARD,
             useClass: AuthenticatedGuard,
         },
+        ApolloLogger,
     ],
 })
 export class AppModule {}

apps/api/src/app.resolver.ts

@@ -12,6 +12,7 @@ export class AppResolver {
         return this.appService.getHello();
     }
 
+    @Public()
     @Query(() => String)
     async db(): Promise<string> {
         return this.appService.testDb();

apps/api/src/drizzle/drizzle.logger.ts

@@ -0,0 +1,11 @@
+import { Injectable, Logger, LoggerService } from "@nestjs/common";
+import { Logger as DrizzleLoggerInterface } from "drizzle-orm";
+
+@Injectable()
+export class DrizzleLogger implements DrizzleLoggerInterface {
+    constructor(private readonly logger: LoggerService) {}
+
+    logQuery(query: string, params: unknown[]): void {
+        if (query && params) this.logger.log(`Query: ${query} ${params}`);
+    }
+}

apps/api/src/drizzle/drizzle.service.ts

@@ -1,21 +1,28 @@
-import { Inject, Injectable, Scope } from "@nestjs/common";
+import { Inject, Injectable, Logger, Scope } from "@nestjs/common";
 import { CONTEXT } from "@nestjs/graphql";
 import { NodePgDatabase, drizzle } from "drizzle-orm/node-postgres";
 import { Pool } from "pg";
+import { DrizzleLogger } from "./drizzle.logger";
 import { CONNECTION_POOL } from "./drizzle.module-definition";
 import * as schema from "./schema";
 import { DRIZZLE_DATABASE_KEY } from "./transaction.interceptor";
 
 @Injectable({ scope: Scope.REQUEST })
 export class DrizzleService {
+    private readonly logger = new Logger("Drizzle:Service");
+
     constructor(
         @Inject(CONNECTION_POOL) private readonly pool: Pool,
         @Inject(CONTEXT) private readonly context: any,
     ) {}
 
     public get db(): NodePgDatabase<typeof schema> {
         return (
-            this.context[DRIZZLE_DATABASE_KEY] ?? drizzle(this.pool, { schema })
+            this.context[DRIZZLE_DATABASE_KEY] ??
+            drizzle(this.pool, {
+                schema,
+                logger: new DrizzleLogger(this.logger),
+            })
         );
     }
 }

apps/api/src/drizzle/transaction.interceptor.ts

@@ -3,20 +3,24 @@
     ExecutionContext,
     Inject,
     Injectable,
+    Logger,
     NestInterceptor,
 } from "@nestjs/common";
 import { GqlExecutionContext } from "@nestjs/graphql";
 import { drizzle } from "drizzle-orm/node-postgres";
 import { Pool } from "pg";
 import { Observable, from, throwError } from "rxjs";
 import { catchError, switchMap } from "rxjs/operators";
+import { DrizzleLogger } from "./drizzle.logger";
 import { CONNECTION_POOL } from "./drizzle.module-definition";
 import * as schema from "./schema";
 
 export const DRIZZLE_DATABASE_KEY = "DRIZZLE_DATABASE";
 
 @Injectable()
 export class TransactionInterceptor implements NestInterceptor {
+    private readonly logger = new Logger("Drizzle:TransactionInterceptor");
+
     constructor(@Inject(CONNECTION_POOL) private readonly pool: Pool) {}
 
     intercept(
@@ -26,7 +30,10 @@
         const gqlContext = GqlExecutionContext.create(context);
         const ctx = gqlContext.getContext();
 
-        const db = drizzle(this.pool, { schema });
+        const db = drizzle(this.pool, {
+            schema,
+            logger: new DrizzleLogger(this.logger),
+        });
 
         return from(
             db.transaction(async (tx) => {

apps/api/src/main.ts

@@ -3,12 +3,19 @@
 import { NestFactory } from "@nestjs/core";
 import RedisStore from "connect-redis";
 import * as session from "express-session";
+import { WinstonModule } from "nest-winston";
 import * as passport from "passport";
 import { createClient } from "redis";
+import { createLogger } from "winston";
 import { AppModule } from "./app.module";
+import { winstonConfig } from "./utils/winston.config";
 
 async function bootstrap() {
-    const app = await NestFactory.create(AppModule);
+    const loggerInstance = createLogger(winstonConfig);
+
+    const app = await NestFactory.create(AppModule, {
+        logger: WinstonModule.createLogger({ instance: loggerInstance }),
+    });
     const configService = app.get(ConfigService);
 
     app.useGlobalPipes(

apps/api/src/utils/graphql.logger.ts

@@ -0,0 +1,61 @@
+import {
+    ApolloServerPlugin,
+    BaseContext,
+    GraphQLRequestContext,
+    GraphQLRequestContextWillSendResponse,
+    GraphQLRequestListener,
+} from "@apollo/server";
+import { Plugin } from "@nestjs/apollo";
+import { Logger } from "@nestjs/common";
+import { performance } from "perf_hooks";
+
+@Plugin()
+export class ApolloLogger implements ApolloServerPlugin {
+    private readonly logger = new Logger("GraphQL");
+
+    async requestDidStart(requestContext: GraphQLRequestContext<BaseContext>) {
+        const thatLogger = this.logger;
+        if (requestContext.request.operationName === "IntrospectionQuery") {
+            return;
+        }
+
+        requestContext.request.http?.headers.set(
+            "x-request-id",
+            crypto.randomUUID(),
+        );
+        if (!requestContext.request.http?.headers.get("x-session-id")) {
+            requestContext.request.http?.headers.set(
+                "x-session-id",
+                crypto.randomUUID(),
+            );
+        }
+        const now = performance.now();
+        return {
+            async willSendResponse(
+                responseContext: GraphQLRequestContextWillSendResponse<BaseContext>,
+            ) {
+                if (
+                    requestContext.request.operationName ===
+                    "IntrospectionQuery"
+                ) {
+                    return;
+                }
+                thatLogger.log({
+                    sessionId:
+                        requestContext.request.http?.headers.get(
+                            "x-session-id",
+                        ),
+                    requestId:
+                        requestContext.request.http?.headers.get(
+                            "x-request-id",
+                        ),
+                    query: requestContext.request.query,
+                    variables: requestContext.request.variables,
+                    resposneTime: performance.now() - now,
+                    responseDate: new Date().toISOString(),
+                    error: responseContext.errors,
+                });
+            },
+        };
+    }
+}

apps/api/src/utils/winston.config.ts

@@ -0,0 +1,74 @@
+import * as winston from "winston";
+import "winston-daily-rotate-file";
+import { utilities as nestWinstonModuleUtilities } from "nest-winston";
+
+const dbRotateTransport = new winston.transports.DailyRotateFile({
+    filename: "logs/db-%DATE%.log",
+    datePattern: "YYYY-MM-DD",
+    zippedArchive: true,
+    maxSize: "20m",
+    maxFiles: "14d",
+    format: winston.format.combine(
+        winston.format((info) => {
+            if (
+                info.context === "Drizzle:Service" ||
+                info.context === "Drizzle:TransactionInterceptor"
+            )
+                return info;
+            else return false;
+        })(),
+        winston.format.json(),
+    ),
+});
+
+const httpRotateTransport = new winston.transports.DailyRotateFile({
+    filename: "logs/graphql-%DATE%.log",
+    datePattern: "YYYY-MM-DD",
+    zippedArchive: true,
+    maxSize: "20m",
+    maxFiles: "14d",
+    format: winston.format.combine(
+        winston.format((info) => {
+            if (info.context === "GraphQL") return info;
+            else return false;
+        })(),
+        winston.format.json(),
+    ),
+});
+
+const errorRotateTransport = new winston.transports.DailyRotateFile({
+    filename: "logs/error-%DATE%.log",
+    datePattern: "YYYY-MM-DD",
+    zippedArchive: true,
+    maxSize: "20m",
+    maxFiles: "14d",
+    level: "error",
+    format: winston.format.combine(
+        winston.format.timestamp(),
+        winston.format.json(),
+    ),
+});
+
+export const winstonConfig = {
+    level: process.env.LOG_LEVEL || "info",
+    format: winston.format.combine(
+        winston.format.timestamp(),
+        winston.format.json(),
+    ),
+    handleExceptions: true,
+    handleRejections: true,
+    exitOnError: false,
+    transports: [
+        errorRotateTransport,
+        dbRotateTransport,
+        httpRotateTransport,
+        new winston.transports.Console({
+            format: winston.format.combine(
+                nestWinstonModuleUtilities.format.nestLike("NestWinston", {
+                    colors: true,
+                    prettyPrint: true,
+                }),
+            ),
+        }),
+    ],
+};