Merge pull request #323 from shoaib050326/codex/issue-165-request-logging

backend: add request logging interceptor for method/url/status/duration

Author: Otaiki1

backend/src/main.ts

@@ -7,6 +7,7 @@ import multipart from "@fastify/multipart";
 import { AppModule } from "./app.module";
 import { configureSecurity } from "./bootstrap";
 import { MAX_UPLOAD_BYTES } from "./config/upload.config";
+import { RequestLoggingInterceptor } from "./middleware/request-logging.interceptor";
 
 async function bootstrap() {
   const app = await NestFactory.create<NestFastifyApplication>(
@@ -24,6 +25,8 @@ async function bootstrap() {
     },
   });
 
+  app.useGlobalInterceptors(new RequestLoggingInterceptor());
+
   await app.listen(process.env.PORT ?? 3001, "0.0.0.0");
 }
 bootstrap();

backend/src/middleware/request-logging.interceptor.spec.ts

@@ -0,0 +1,75 @@
+import {
+  CallHandler,
+  ExecutionContext,
+  Logger,
+} from '@nestjs/common';
+import { lastValueFrom, of } from 'rxjs';
+import { RequestLoggingInterceptor } from './request-logging.interceptor';
+
+function createExecutionContext(
+  request: Record<string, unknown>,
+  response: Record<string, unknown>,
+): ExecutionContext {
+  return {
+    switchToHttp: () => ({
+      getRequest: () => request,
+      getResponse: () => response,
+    }),
+  } as ExecutionContext;
+}
+
+describe('RequestLoggingInterceptor', () => {
+  afterEach(() => {
+    jest.restoreAllMocks();
+  });
+
+  it('logs method, url, status code, and duration', async () => {
+    const interceptor = new RequestLoggingInterceptor();
+    const context = createExecutionContext(
+      { method: 'GET', url: '/health' },
+      { statusCode: 200 },
+    );
+    const next: CallHandler = { handle: () => of('ok') };
+
+    jest.spyOn(Date, 'now').mockReturnValueOnce(100).mockReturnValueOnce(115);
+    const logSpy = jest
+      .spyOn(Logger.prototype, 'log')
+      .mockImplementation(() => undefined);
+
+    await expect(lastValueFrom(interceptor.intercept(context, next))).resolves.toBe(
+      'ok',
+    );
+
+    expect(logSpy).toHaveBeenCalledWith('GET /health 200 15ms');
+  });
+
+  it('does not log sensitive request data', async () => {
+    const interceptor = new RequestLoggingInterceptor();
+    const context = createExecutionContext(
+      {
+        method: 'POST',
+        url: '/auth/verify?token=sensitive-query-token',
+        headers: { authorization: 'Bearer secret-token' },
+        body: { password: 'super-secret', email: 'user@example.com' },
+        query: { token: 'sensitive-query-token' },
+      },
+      { statusCode: 401 },
+    );
+    const next: CallHandler = { handle: () => of('denied') };
+
+    jest.spyOn(Date, 'now').mockReturnValueOnce(200).mockReturnValueOnce(240);
+    const logSpy = jest
+      .spyOn(Logger.prototype, 'log')
+      .mockImplementation(() => undefined);
+
+    await lastValueFrom(interceptor.intercept(context, next));
+
+    const [message] = logSpy.mock.calls.at(-1) ?? [];
+
+    expect(message).toBe('POST /auth/verify 401 40ms');
+    expect(message).not.toContain('secret-token');
+    expect(message).not.toContain('super-secret');
+    expect(message).not.toContain('user@example.com');
+    expect(message).not.toContain('sensitive-query-token');
+  });
+});

backend/src/middleware/request-logging.interceptor.ts

@@ -0,0 +1,48 @@
+import {
+  CallHandler,
+  ExecutionContext,
+  Injectable,
+  Logger,
+  NestInterceptor,
+} from '@nestjs/common';
+import { Observable, finalize } from 'rxjs';
+
+interface HttpRequestLike {
+  method?: string;
+  originalUrl?: string;
+  url?: string;
+}
+
+interface HttpResponseLike {
+  statusCode?: number;
+}
+
+@Injectable()
+export class RequestLoggingInterceptor implements NestInterceptor {
+  private readonly logger = new Logger(RequestLoggingInterceptor.name);
+
+  intercept(context: ExecutionContext, next: CallHandler): Observable<unknown> {
+    const request = context.switchToHttp().getRequest<HttpRequestLike>();
+    const response = context.switchToHttp().getResponse<HttpResponseLike>();
+    const startedAt = Date.now();
+
+    return next.handle().pipe(
+      finalize(() => {
+        const method = request.method ?? 'UNKNOWN';
+        const url = this.sanitizeUrl(request.originalUrl ?? request.url);
+        const statusCode = response.statusCode ?? 500;
+        const durationMs = Date.now() - startedAt;
+
+        this.logger.log(`${method} ${url} ${statusCode} ${durationMs}ms`);
+      }),
+    );
+  }
+
+  private sanitizeUrl(url: string | undefined): string {
+    if (!url) {
+      return 'UNKNOWN';
+    }
+
+    return url.split('?')[0] || '/';
+  }
+}