diff --git a/src/admin/system-log/system-log.service.ts b/src/admin/system-log/system-log.service.ts index a0dfff3..c46c9bb 100644 --- a/src/admin/system-log/system-log.service.ts +++ b/src/admin/system-log/system-log.service.ts @@ -226,9 +226,25 @@ export class SystemLogService { this.normalizeLevel(parsed.level) || 'info'; const requestId = - this.pickText(params.metadata?.requestId, meta.requestId, req.id) || - undefined; - const path = this.pickText(parsed.path, req.url, req.originalUrl) || undefined; + this.pickText( + params.metadata?.requestId, + parsed.requestId, + meta.requestId, + req.id, + ) || undefined; + const path = + this.toolsService.normalizeRequestPathValue( + this.pickText( + parsed.path, + parsed.url, + parsed.originalUrl, + req.path, + req.url, + req.originalUrl, + ), + ) || undefined; + const method = + this.pickText(parsed.method, req.method)?.toUpperCase() || undefined; return formatDateTimeFields( Object.assign(new SystemLogDto(), { @@ -244,7 +260,7 @@ export class SystemLogService { message: this.pickText(parsed.msg, parsed.message, parsed.err?.message) || params.line, - method: this.pickText(parsed.method, req.method) || undefined, + method, path, raw: params.line, requestId, diff --git a/src/app.module.ts b/src/app.module.ts index 5a97df5..f49e7e1 100644 --- a/src/app.module.ts +++ b/src/app.module.ts @@ -8,6 +8,7 @@ import { TypeOrmModule } from '@nestjs/typeorm'; import { MinioModule } from 'nestjs-minio-client'; import { MinioClientModule } from './minio/minio.module'; import { + ApiRequestLogInterceptor, ApiExceptionFilter, CommonModule, createPinoLoggerParams, @@ -69,6 +70,10 @@ import { QqbotModule } from './qqbot/qqbot.module'; providers: [ AppService, ConfigService, + { + provide: APP_INTERCEPTOR, + useClass: ApiRequestLogInterceptor, + }, { provide: APP_INTERCEPTOR, useClass: SaveBodyInterceptor, diff --git a/src/common/index.ts b/src/common/index.ts index 23e0934..ca2d381 100644 --- a/src/common/index.ts +++ b/src/common/index.ts @@ -4,6 +4,7 @@ export * from './decorators/decode-dict.decorator'; export * from './decorators/format-date-time.decorator'; export * from './decorators/public.decorator'; export * from './filters/api-exception.filter'; +export * from './interceptors/api-request-log.interceptor'; export * from './interceptors/save-body.interceptor'; export * from './logger/pino-logger.config'; export * from './response/vben-response'; diff --git a/src/common/interceptors/api-request-log.interceptor.ts b/src/common/interceptors/api-request-log.interceptor.ts new file mode 100644 index 0000000..d49c155 --- /dev/null +++ b/src/common/interceptors/api-request-log.interceptor.ts @@ -0,0 +1,114 @@ +import { randomUUID } from 'node:crypto'; +import { + CallHandler, + ExecutionContext, + HttpException, + Injectable, + NestInterceptor, +} from '@nestjs/common'; +import type { Request, Response } from 'express'; +import { PinoLogger } from 'nestjs-pino'; +import { catchError, Observable, tap, throwError } from 'rxjs'; +import { ToolsService } from '../services/tool.service'; + +type RequestWithId = Request & { + id?: string; +}; + +@Injectable() +export class ApiRequestLogInterceptor implements NestInterceptor { + constructor( + private readonly logger: PinoLogger, + private readonly toolsService: ToolsService, + ) { + this.logger.setContext(ApiRequestLogInterceptor.name); + } + + intercept(context: ExecutionContext, next: CallHandler): Observable { + if (context.getType() !== 'http') { + return next.handle(); + } + + const httpContext = context.switchToHttp(); + const request = httpContext.getRequest(); + const response = httpContext.getResponse(); + const startedAt = Date.now(); + const requestId = this.ensureRequestId(request, response); + + return next.handle().pipe( + tap(() => { + this.logRequest({ + request, + requestId, + response, + startedAt, + }); + }), + catchError((error) => { + this.logRequest({ + error, + request, + requestId, + response, + startedAt, + }); + return throwError(() => error); + }), + ); + } + + private ensureRequestId(request: RequestWithId, response: Response) { + const requestId = this.toolsService.getRequestId(request) || randomUUID(); + request.id = requestId; + + if (!response.getHeader('x-request-id')) { + response.setHeader('x-request-id', requestId); + } + + return requestId; + } + + private logRequest(params: { + error?: unknown; + request: RequestWithId; + requestId: string; + response: Response; + startedAt: number; + }) { + const statusCode = this.getStatusCode(params.error, params.response); + const payload = { + durationMs: Date.now() - params.startedAt, + method: params.request.method, + path: this.toolsService.getRequestPath(params.request), + requestId: params.requestId, + statusCode, + }; + + if (statusCode >= 500) { + this.logger.error( + { + ...payload, + err: params.error, + }, + 'HTTP request failed', + ); + return; + } + + if (statusCode >= 400) { + this.logger.warn(payload, 'HTTP request completed'); + return; + } + + this.logger.info(payload, 'HTTP request completed'); + } + + private getStatusCode(error: unknown, response: Response) { + if (error instanceof HttpException) { + return error.getStatus(); + } + + if (error) return 500; + return response.statusCode || 200; + } +} diff --git a/src/common/logger/pino-logger.config.ts b/src/common/logger/pino-logger.config.ts index 9463a6c..8756e11 100644 --- a/src/common/logger/pino-logger.config.ts +++ b/src/common/logger/pino-logger.config.ts @@ -39,10 +39,7 @@ export function createPinoLoggerParams( return { pinoHttp: { - autoLogging: { - ignore: (req: Request) => - ['/favicon.ico'].includes(req.url) || req.url.startsWith('/api-json'), - }, + autoLogging: false, base: { app: appName, env: nodeEnv, diff --git a/src/common/services/tool.service.ts b/src/common/services/tool.service.ts index db8cc0b..343349e 100644 --- a/src/common/services/tool.service.ts +++ b/src/common/services/tool.service.ts @@ -211,6 +211,39 @@ export class ToolsService { return Array.isArray(value) ? value[0] : value; } + getRequestId(request: { headers?: Record; id?: unknown }) { + return this.pickFirstText( + request?.id, + this.readHeader(request, 'x-request-id'), + this.readHeader(request, 'x-correlation-id'), + ); + } + + getRequestPath( + request: + | { + originalUrl?: unknown; + path?: unknown; + url?: unknown; + } + | undefined, + ) { + return this.normalizeRequestPathValue( + this.pickFirstText(request?.path, request?.originalUrl, request?.url), + ); + } + + normalizeRequestPathValue(value: unknown) { + const text = this.toTrimmedString(value); + if (!text) return ''; + + try { + return new URL(text, 'http://localhost').pathname; + } catch { + return text.split('?')[0] || text; + } + } + readCookie( request: { headers?: Record } | undefined, cookieName: string, diff --git a/test/admin/system-log/system-log.service.spec.ts b/test/admin/system-log/system-log.service.spec.ts new file mode 100644 index 0000000..16d756f --- /dev/null +++ b/test/admin/system-log/system-log.service.spec.ts @@ -0,0 +1,82 @@ +import { ConfigService } from '@nestjs/config'; +import { SystemLogService } from '../../../src/admin/system-log/system-log.service'; +import { ToolsService } from '../../../src/common'; + +function createService() { + const configService = { + get: jest.fn((key: string) => { + const values: Record = { + LOKI_QUERY_HOST: 'http://kt-loki:3100', + NODE_ENV: 'production', + }; + return values[key]; + }), + } as unknown as ConfigService; + + return new SystemLogService(configService, new ToolsService()); +} + +describe('SystemLogService', () => { + it('parses structured HTTP request fields from top-level Loki log lines', () => { + const service = createService(); + const result = (service as any).serializeLog({ + line: JSON.stringify({ + durationMs: 18, + level: 30, + method: 'get', + msg: 'HTTP request completed', + path: '/system/logs?pageNo=1', + requestId: 'req-1', + statusCode: 200, + }), + rowIndex: 0, + stream: { + hostname: 'api-pod', + }, + streamIndex: 0, + timestampNs: '1760000000000000000', + }); + + expect(result).toEqual( + expect.objectContaining({ + durationMs: 18, + method: 'GET', + path: '/system/logs', + requestId: 'req-1', + statusCode: 200, + }), + ); + }); + + it('keeps compatibility with pino-http nested request logs', () => { + const service = createService(); + const result = (service as any).serializeLog({ + line: JSON.stringify({ + durationMs: 6, + level: 30, + msg: 'request completed', + req: { + id: 'req-2', + method: 'POST', + url: '/dict/save?debug=true', + }, + res: { + statusCode: 201, + }, + }), + rowIndex: 0, + stream: {}, + streamIndex: 0, + timestampNs: '1760000000000000000', + }); + + expect(result).toEqual( + expect.objectContaining({ + method: 'POST', + path: '/dict/save', + requestId: 'req-2', + statusCode: 201, + }), + ); + }); +}); diff --git a/test/common/api-request-log.interceptor.spec.ts b/test/common/api-request-log.interceptor.spec.ts new file mode 100644 index 0000000..3bb0045 --- /dev/null +++ b/test/common/api-request-log.interceptor.spec.ts @@ -0,0 +1,166 @@ +import { + Controller, + Get, + HttpException, + HttpStatus, + INestApplication, +} from '@nestjs/common'; +import { APP_INTERCEPTOR } from '@nestjs/core'; +import { Test } from '@nestjs/testing'; +import { PinoLogger } from 'nestjs-pino'; +import * as request from 'supertest'; +import { lastValueFrom, of, throwError } from 'rxjs'; +import { ApiRequestLogInterceptor, ToolsService } from '../../src/common'; + +@Controller('probe') +class ProbeController { + @Get() + probe() { + return { ok: true }; + } +} + +function createHttpContext(request: Record, response: Record) { + return { + getType: () => 'http', + switchToHttp: () => ({ + getRequest: () => request, + getResponse: () => response, + }), + } as any; +} + +function createResponse(statusCode = 200) { + return { + getHeader: jest.fn(), + setHeader: jest.fn(), + statusCode, + }; +} + +describe('ApiRequestLogInterceptor', () => { + it('writes structured HTTP request fields for successful controller calls', async () => { + const logger = { + error: jest.fn(), + info: jest.fn(), + setContext: jest.fn(), + warn: jest.fn(), + }; + const interceptor = new ApiRequestLogInterceptor( + logger as any, + new ToolsService(), + ); + const request: Record = { + headers: { + 'x-request-id': 'req-1', + }, + method: 'GET', + originalUrl: '/system/logs?pageNo=1', + }; + const response = createResponse(200); + + await lastValueFrom( + interceptor.intercept(createHttpContext(request, response), { + handle: () => of({ ok: true }), + }), + ); + + expect(response.setHeader).toHaveBeenCalledWith('x-request-id', 'req-1'); + expect(request.id).toBe('req-1'); + expect(logger.info).toHaveBeenCalledWith( + expect.objectContaining({ + method: 'GET', + path: '/system/logs', + requestId: 'req-1', + statusCode: 200, + }), + 'HTTP request completed', + ); + }); + + it('writes warning logs with HTTP status for controller errors', async () => { + const logger = { + error: jest.fn(), + info: jest.fn(), + setContext: jest.fn(), + warn: jest.fn(), + }; + const interceptor = new ApiRequestLogInterceptor( + logger as any, + new ToolsService(), + ); + const request: Record = { + headers: {}, + method: 'POST', + path: '/dict/save', + }; + const response = createResponse(200); + const error = new HttpException('not found', HttpStatus.NOT_FOUND); + + await expect( + lastValueFrom( + interceptor.intercept(createHttpContext(request, response), { + handle: () => throwError(() => error), + }), + ), + ).rejects.toBe(error); + + expect(request.id).toEqual(expect.any(String)); + expect(logger.warn).toHaveBeenCalledWith( + expect.objectContaining({ + method: 'POST', + path: '/dict/save', + requestId: request.id, + statusCode: 404, + }), + 'HTTP request completed', + ); + }); + + it('captures a real local HTTP request in a Nest application', async () => { + const logger = { + error: jest.fn(), + info: jest.fn(), + setContext: jest.fn(), + warn: jest.fn(), + }; + let app: INestApplication | undefined; + + try { + const moduleRef = await Test.createTestingModule({ + controllers: [ProbeController], + providers: [ + ToolsService, + { + provide: PinoLogger, + useValue: logger, + }, + { + provide: APP_INTERCEPTOR, + useClass: ApiRequestLogInterceptor, + }, + ], + }).compile(); + + app = moduleRef.createNestApplication(); + await app.init(); + + await request(app.getHttpServer()) + .get('/probe?source=test') + .set('x-request-id', 'req-real') + .expect(200); + + expect(logger.info).toHaveBeenCalledWith( + expect.objectContaining({ + method: 'GET', + path: '/probe', + requestId: 'req-real', + statusCode: 200, + }), + 'HTTP request completed', + ); + } finally { + await app?.close(); + } + }); +});