基于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

好了，整个项目就完成了。

基于nestjs 的一种log traceId 的实现方案

前言

项目开始

requestId 设置

logger 设置

使用范例

相关文章

发布评论取消回复

大猫

开启3389端口命令，要怎么开启3389端口命令

win10优化驱动器怎么启动

MySQL DNS查找和主机缓存解读

基于nestjs 的一种log traceId 的实现方案

前言

项目开始

requestId 设置

logger 设置

使用范例

相关文章

发布评论 取消回复

大猫

开启3389端口命令，要怎么开启3389端口命令

win10优化驱动器怎么启动

MySQL DNS查找和主机缓存解读

发布评论取消回复