基于nestjs 的一种log traceId 的实现方案
前言
开发中经常需要根据日志排查问题,看一次调用中经过了哪些系统,以及每个系统打印出的数据有那些,这就需要业务日志中关联调用链的TraceId信息,在没有TraceId 日志混杂,没办法区分当前日志属于哪一次请求,能把同一个请求链上的日志串连起来就会对排查问题有很大的帮助。本文提供一种简单的方式实现 log traceId。
项目开始
requestId 设置
使用中间件设置requestId
src/middleware/requestId.middleware.ts
import { Injectable, NestMiddleware } from '@nestjs/common'; import { Request, Response, NextFunction } from 'express'; import { v4 as uuidv4 } from 'uuid'; @Injectable() export class RequestIdMiddleware implements NestMiddleware { use(req: Request, res: Response, next: NextFunction) { console.log("init req") const headerName = "X-Request-Id"; const headerId = req.get(headerName) const requestId = headerId ? headerId : uuidv4() req.requestId = requestId res.set(headerName, requestId); next(); } }
在app.module.ts
里引用
import { Module, NestModule, MiddlewareConsumer } from '@nestjs/common'; import { RequestIdMiddleware } from './middleware/requestId.middleware.ts'; export class AppModule implements NestModule { configure(consumer: MiddlewareConsumer) { consumer .apply(RequestIdMiddleware) .forRoutes('*'); } }
logger 设置
自己扩展Nestjs 自带的 LoggerService
扩展 LoggerService 只需要按照以下格式就可以了,前3个是必选,后3 可选
export interface LoggerService { log(message: any, ...optionalParams: any[]): any; error(message: any, ...optionalParams: any[]): any; warn(message: any, ...optionalParams: any[]): any; debug?(message: any, ...optionalParams: any[]): any; verbose?(message: any, ...optionalParams: any[]): any; setLogLevels?(levels: LogLevel[]): any; }
在 src/logger/logger.service.ts
以下使用 winston
来输出和管理日志。当前文件自定义了输出格式,以及输出到文件的一系列设置
import { Logger, createLogger, format, transports } from 'winston'; import 'winston-daily-rotate-file'; import { Injectable, LoggerService } from '@nestjs/common'; @Injectable() export class MyLogger implements LoggerService { private logger: Logger; constructor() { const myFormat = format.printf(({ level, message, context, requestId, timestamp, meta }) => { return `${timestamp} - ${level} - ${context} - ${requestId ? requestId : " "} : ${message} - ${JSON.stringify(meta)}`; }); this.logger = createLogger({ format: format.combine( format.timestamp({ format: 'YYYY-MM-DD HH:mm:ss' }), myFormat ), transports: [ new transports.Console(), new transports.DailyRotateFile({ dirname: 'src/logs', filename: 'application-%DATE%.info.log', datePattern: 'YYYY-MM-DD', zippedArchive: true, maxSize: '20m', maxFiles: '7d', format: format.combine( format.timestamp({ format: 'YYYY-MM-DD HH:mm:ss', }), myFormat ), level: 'info', }), new transports.DailyRotateFile({ dirname: 'src/logs', filename: 'application-%DATE%.error.log', datePattern: 'YYYY-MM-DD', zippedArchive: true, maxSize: '20m', maxFiles: '14d', format: format.combine( format.timestamp({ }), myFormat ), level: 'error', }), ], }); } warpParams(params: any) { let context: string, ctx: any, meta: any; if (!Array.isArray(params)) { context = params } else { [context, ctx, meta] = params } const requestId = ctx?.requestId || " " return { requestId, context, meta } } log(message: string, params: any[]) { const paramMessage = this.warpParams(params) const logMsg = Object.assign({ message }, paramMessage) this.logger.info(logMsg); } error(message: string, params: any[]) { const paramMessage = this.warpParams(params) const logMsg = Object.assign({ message }, paramMessage) this.logger.error(logMsg); } warn(message: string, params: any[]) { const paramMessage = this.warpParams(params) const logMsg = Object.assign({ message }, paramMessage) this.logger.warn(logMsg); } debug(message: string, params: any[]) { const paramMessage = this.warpParams(params) const logMsg = Object.assign({ message }, paramMessage) this.logger.debug(logMsg); } }
在main.ts
里替换实现
import { NestFactory } from '@nestjs/core'; import { AppModule } from './app.module'; import { NestExpressApplication } from '@nestjs/platform-express'; import { MyLogger } from './logger/logger.service.ts'; async function bootstrap() { const app = await NestFactory.create(AppModule,{ logger: new MyLogger() }); await app.listen(3000); } bootstrap();
使用范例
截至当前,准备工作已经做好了,现在找地方去使用它
做个一个全局的ExceptionFilter
src/filters/http-execption.filter.ts
可以看到这里 Logger 是从nestjs/common 中导入,但是由于我们的扩展,所以他现在走的是我们自己实现。
import { ExceptionFilter, Catch, ArgumentsHost, HttpException } from '@nestjs/common'; import { Request, Response } from 'express'; import { Logger } from '@nestjs/common'; @Catch(HttpException) export class HttpExceptionFilter implements ExceptionFilter { private readonly logger = new Logger("HttpExceptionFilter"); catch(exception: HttpException, host: ArgumentsHost) { const ctx = host.switchToHttp(); const response = ctx.getResponse(); const status = exception.getStatus(); const message = exception.message const request = ctx.getRequest(); const requestId = request.requestId;// 这个是我们之前在中间件设置的requestId const exceptionResponse: any = exception.getResponse() let validatorMessage = exceptionResponse; let validatorCode = "" if (typeof validatorMessage == "object") { if (Array.isArray(exceptionResponse.message)) { validatorMessage = exceptionResponse.message[0] validatorCode = exceptionResponse.statusCode // console.log(exceptionResponse) } else { validatorMessage = exceptionResponse.message validatorCode = exceptionResponse.code } } const resMessage = validatorMessage || message const logMsg = { validatorCode, validatorMessage } this.logger.error(JSON.stringify(logMsg), ["HttpExceptionFilter",{ requestId }]); response .status(status) .json({ code: validatorCode || status, message: resMessage, data: {}, path: request.url }); } }
上述打印的结果是
2023-10-04 17:54:51 - error - HttpExceptionFilter - 4aa2e054-592c-49f0-b56a-662662b60575 : {"validator Code":10011,"validatorMessage":"密码错误"} - undefined
我们再写一个 Interceptor 捕获一下接收到的请求和返回值
import { CallHandler, ExecutionContext, Injectable, NestInterceptor, Logger } from '@nestjs/common'; import { Response } from 'express'; import { Request } from 'express'; import { Observable, tap } from 'rxjs'; @Injectable() export class RecordInterceptor implements NestInterceptor { // constructor(private readonly logger: LoggerService){} private readonly logger = new Logger(); intercept( context: ExecutionContext, next: CallHandler, ): Observable | Promise { const request = context.switchToHttp().getRequest(); const response = context.switchToHttp().getResponse(); const requestId = request.requestId; const userAgent = request.headers['user-agent']; const { ip, method, path } = request; const message = `${method} - ${path} - ${ip} - ${userAgent} : ${context.getClass().name} - ${context.getHandler().name} invoked...`; this.logger.log(message, [ "RecordInterceptor", { requestId }, { userId: request.user?.userId, userName: request.user?.userName }]); const now = Date.now(); return next.handle().pipe( tap((res) => { const resMessege = `${response.statusCode} - ${Date.now() - now}ms - Response: ${JSON.stringify(res)}` this.logger.log(resMessege, ["RecordInterceptor", { requestId }]) }), ); } }
把这两个文件打印出来的log 综合起来看一下
2023-10-04 17:54:51 - info - RecordInterceptor - 4aa2e054-592c-49f0-b56a-662662b60575 : POST - / auth/login - ::1 - PostmanRuntime/7.33.0 : AuthController - login invoked... - {} 2023-10-04 17:54:51 - error - HttpExceptionFilter - 4aa2e054-592c-49f0-b56a-662662b60575 : {"validator Code":10011,"validatorMessage":"密码错误"} - undefined
这个样子是不是就可以把通过 requestId
4aa2e054-592c-49f0-b56a-662662b60575 把两行log日志 从茫茫日志之海中找出来了,
同样我们还可以在service 里调用,这里主要是 注入了REQUEST
,通过它可以拿到请求的上下文。
import { Injectable, Logger, Inject } from '@nestjs/common'; import { UserService } from '../user/user.service'; import { BusinessException, encryptPassword } from '@app/common'; import { REQUEST } from '@nestjs/core'; import { Request } from 'express'; @Injectable() export class AuthService { private readonly logger = new Logger(); constructor(private userService: UserService, private jwtService: JwtService, @Inject(REQUEST) private readonly request: Request, ) { } async validateUser(username: string, password: string): Promise { const user = await this.userService.findOneByMobile(username) const requestId = this.request.requestId; if (!user) { throw new BusinessException("USER_LOGIN_NOT_EXISTS") } this.logger.log("user exists", ["AuthService", { requestId }]) if (user.isDelete) { throw new BusinessException("USER_DISABLED") } let { password: dbPassword, salt } = user const encryptPostPassword = encryptPassword(password, salt) if (encryptPostPassword !== dbPassword) { this.logger.log("passwor error", ["AuthService", { requestId }]) throw new BusinessException("USER_LOGIN_PASSWORD_ERROR") } return { userId: user.userId, userName: user.nickname } } }
综上,我们把4条 log 放一起看看
2023-10-04 21:36:06 - info - InvokeRecordInterceptor - 3e377415-f596-423c-819b-8a0f429b2b21 : POST - / auth/login - ::1 - PostmanRuntime/7.33.0 : AuthController - login invoked... - {} 2023-10-04 21:36:07 - info - AuthService - 3e377415-f596-423c-819b-8a0f429b2b21 : user exists - undefined 2023-10-04 21:36:07 - info - AuthService - 3e377415-f596-423c-819b-8a0f429b2b21 : password error - undefined 2023-10-04 21:36:07 - error - HttpExceptionFilter - 3e377415-f596-423c-819b-8a0f429b2b21 : {"validator Code":10011,"validatorMessage":"密码错误"} - undefined
好了,整个项目就完成了。