From c1a930032dda5c4b513be51df0cffd105c2ec53a Mon Sep 17 00:00:00 2001 From: Justin Gasper Date: Mon, 9 Feb 2026 15:11:41 +1100 Subject: [PATCH] Better logging of requests / reasons for 400 errors to help LPU --- .../filters/validation-exception.filter.ts | 68 +++++++++++++++++-- .../middleware/request-logger.middleware.ts | 24 ++++++- src/shared/util/log-sanitizer.util.ts | 67 ++++++++++++++++++ 3 files changed, 153 insertions(+), 6 deletions(-) create mode 100644 src/shared/util/log-sanitizer.util.ts diff --git a/src/shared/filters/validation-exception.filter.ts b/src/shared/filters/validation-exception.filter.ts index e829eae..0cdb1bb 100644 --- a/src/shared/filters/validation-exception.filter.ts +++ b/src/shared/filters/validation-exception.filter.ts @@ -6,8 +6,9 @@ import { HttpStatus, Logger, } from '@nestjs/common'; -import { Response } from 'express'; +import { Request, Response } from 'express'; import { ValidationError } from 'class-validator'; +import { sanitizeForLogging } from '../util/log-sanitizer.util'; @Catch(HttpException) export class ValidationExceptionFilter implements ExceptionFilter { @@ -15,12 +16,13 @@ export class ValidationExceptionFilter implements ExceptionFilter { catch(exception: HttpException, host: ArgumentsHost) { const ctx = host.switchToHttp(); + const request = ctx.getRequest(); const response = ctx.getResponse(); const status = exception.getStatus(); const exceptionResponse = exception.getResponse(); let message = exception.message; - let errors: any = null; + let errors: Record | null = null; // Handle class-validator ValidationPipe errors specifically if ( @@ -57,17 +59,36 @@ export class ValidationExceptionFilter implements ExceptionFilter { message = (exceptionResponse as { message?: string }).message || message; } + if (status === HttpStatus.BAD_REQUEST) { + const reason = this.extractBadRequestReason( + exceptionResponse, + message, + errors, + ); + this.logger.warn( + `400 Bad Request: ${request.method} ${request.originalUrl} - Reason: ${reason}`, + ); + + if (this.isCreateUserRequest(request.method, request.originalUrl)) { + this.logger.warn( + `400 Request Body: ${JSON.stringify(sanitizeForLogging(request.body))}`, + ); + } + } + response.status(status).json({ statusCode: status, message: message, errors: errors, // Include formatted validation errors if present timestamp: new Date().toISOString(), - path: ctx.getRequest().url, + path: request.url, }); } - private formatValidationErrors(validationErrors: ValidationError[]) { - const formattedErrors = {}; + private formatValidationErrors( + validationErrors: ValidationError[], + ): Record { + const formattedErrors: Record = {}; validationErrors.forEach((err) => { formattedErrors[err.property] = Object.values(err.constraints || {}).join( ', ', @@ -81,4 +102,41 @@ export class ValidationExceptionFilter implements ExceptionFilter { }); return formattedErrors; } + + private extractBadRequestReason( + exceptionResponse: unknown, + fallbackMessage: string, + errors: Record | null, + ): string { + if (typeof exceptionResponse === 'string') { + return exceptionResponse; + } + + if ( + typeof exceptionResponse === 'object' && + exceptionResponse !== null && + 'message' in exceptionResponse + ) { + const responseMessage = (exceptionResponse as { message?: unknown }) + .message; + if (Array.isArray(responseMessage)) { + return responseMessage.map((entry) => String(entry)).join('; '); + } + if (typeof responseMessage === 'string') { + return responseMessage; + } + return JSON.stringify(sanitizeForLogging(responseMessage)); + } + + if (errors && Object.keys(errors).length > 0) { + return JSON.stringify(sanitizeForLogging(errors)); + } + + return fallbackMessage; + } + + private isCreateUserRequest(method: string, originalUrl: string): boolean { + const pathOnly = originalUrl.split('?')[0]; + return method.toUpperCase() === 'POST' && /\/v6\/users\/?$/.test(pathOnly); + } } diff --git a/src/shared/middleware/request-logger.middleware.ts b/src/shared/middleware/request-logger.middleware.ts index 3f773a6..dc015f0 100644 --- a/src/shared/middleware/request-logger.middleware.ts +++ b/src/shared/middleware/request-logger.middleware.ts @@ -1,5 +1,6 @@ import { Injectable, NestMiddleware, Logger } from '@nestjs/common'; import { Request, Response, NextFunction } from 'express'; +import { sanitizeForLogging } from '../util/log-sanitizer.util'; @Injectable() export class RequestLoggerMiddleware implements NestMiddleware { @@ -12,7 +13,15 @@ export class RequestLoggerMiddleware implements NestMiddleware { this.logger.log( `---> ${method} ${originalUrl} - User-Agent: ${userAgent} - IP: ${req.ip}`, ); - this.logger.debug(`---> Request Headers: ${JSON.stringify(headers)}`); + this.logger.debug( + `---> Request Headers: ${JSON.stringify(sanitizeForLogging(headers))}`, + ); + + if (this.shouldLogCreateUserBody(method, originalUrl)) { + this.logger.debug( + `---> Request Body: ${JSON.stringify(sanitizeForLogging(req.body))}`, + ); + } // Optionally log when the request finishes res.on('finish', () => { @@ -24,4 +33,17 @@ export class RequestLoggerMiddleware implements NestMiddleware { next(); } + + private shouldLogCreateUserBody( + method: string, + originalUrl: string, + ): boolean { + const normalizedMethod = method.toUpperCase(); + if (normalizedMethod !== 'POST') { + return false; + } + + const pathOnly = originalUrl.split('?')[0]; + return /\/v6\/users\/?$/.test(pathOnly); + } } diff --git a/src/shared/util/log-sanitizer.util.ts b/src/shared/util/log-sanitizer.util.ts new file mode 100644 index 0000000..5e7971a --- /dev/null +++ b/src/shared/util/log-sanitizer.util.ts @@ -0,0 +1,67 @@ +const CIRCULAR_REFERENCE = '[Circular]'; +const REDACTED = '[REDACTED]'; + +function normalizeKey(key: string): string { + return key.toLowerCase().replace(/[^a-z0-9]/g, ''); +} + +function isSensitiveKey(key: string): boolean { + const normalizedKey = normalizeKey(key); + return ( + normalizedKey.includes('password') || + normalizedKey.includes('token') || + normalizedKey.includes('secret') || + normalizedKey.includes('authorization') || + normalizedKey.includes('cookie') || + normalizedKey === 'otp' || + normalizedKey.endsWith('otp') || + normalizedKey === 'apikey' || + normalizedKey.endsWith('apikey') + ); +} + +function sanitizeValue(value: unknown, seen: WeakSet): unknown { + if (value === null || value === undefined) { + return value; + } + + if (Array.isArray(value)) { + return value.map((item) => sanitizeValue(item, seen)); + } + + if (value instanceof Date) { + return value.toISOString(); + } + + if (typeof value !== 'object') { + return value; + } + + if (Buffer.isBuffer(value)) { + return `[Buffer:${value.length}]`; + } + + if (seen.has(value)) { + return CIRCULAR_REFERENCE; + } + + seen.add(value); + + const source = value as Record; + const sanitized: Record = {}; + + for (const [key, nestedValue] of Object.entries(source)) { + if (isSensitiveKey(key)) { + sanitized[key] = REDACTED; + continue; + } + + sanitized[key] = sanitizeValue(nestedValue, seen); + } + + return sanitized; +} + +export function sanitizeForLogging(value: unknown): unknown { + return sanitizeValue(value, new WeakSet()); +}