fix: 修复系统日志运行时请求捕获

This commit is contained in:
sunlei 2026-06-04 13:53:45 +08:00
parent 3d22913869
commit a85db5e045
8 changed files with 422 additions and 8 deletions

View File

@ -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,

View File

@ -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,

View File

@ -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';

View File

@ -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<any> {
if (context.getType() !== 'http') {
return next.handle();
}
const httpContext = context.switchToHttp();
const request = httpContext.getRequest<RequestWithId>();
const response = httpContext.getResponse<Response>();
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;
}
}

View File

@ -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,

View File

@ -211,6 +211,39 @@ export class ToolsService {
return Array.isArray(value) ? value[0] : value;
}
getRequestId(request: { headers?: Record<string, any>; 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<string, any> } | undefined,
cookieName: string,

View File

@ -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<string, string> = {
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,
}),
);
});
});

View File

@ -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<string, any>, response: Record<string, any>) {
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<string, any> = {
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<string, any> = {
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();
}
});
});