NestJS 日志进阶：集成 Winston/Pino，玩转请求上下文与链路追踪

NestJS 日志进阶：集成 Winston/Pino，玩转请求上下文与链路追踪

大家好，我是你们的“老伙计”码农小助手。今天咱们来聊聊 NestJS 开发中一个非常重要，但又经常被忽视的环节——日志系统。相信不少开发者在日常开发中，都遇到过线上问题难以排查的窘境，而一个完善的日志系统，正是解决这一问题的关键。

你是不是也遇到过这样的情况：

• 线上出现了一个偶发性 bug，但日志里除了报错信息，啥也没有，完全不知道这个请求经历了什么。
• 多个请求同时发生，日志混杂在一起，根本分不清哪个是哪个，排查起来像大海捞针。
• 想做全链路追踪，却不知道从何下手，每次都要手动在各个服务里加一堆追踪 ID。

别担心，今天我就带你一起，用 NestJS 结合流行的日志库 Winston 和 Pino，打造一个强大的日志系统，彻底解决这些烦恼！

为什么我们需要一个强大的日志系统？

在传统的开发模式下，console.log 大法或许还能勉强应付。但是，随着微服务架构的兴起，以及系统复杂度的不断提升，console.log 已经远远不够用了。一个好的日志系统，至少应该具备以下几个特点：

1. 分级记录： 能够根据日志的严重程度（DEBUG、INFO、WARN、ERROR 等）进行分类，方便开发者快速筛选。
2. 结构化输出： 日志信息以结构化的方式（如 JSON）输出，方便机器解析和后续处理。
3. 持久化存储： 日志能够被持久化存储到文件、数据库或专业的日志服务中，方便长期保存和分析。
4. 上下文信息： 能够记录请求的上下文信息，如请求 ID、用户 ID、请求参数等，方便问题定位。
5. 链路追踪： 在微服务架构下，能够追踪一个请求在各个服务之间的调用链，快速定位问题源头。

Winston 和 Pino：两大日志库的对比

Winston 和 Pino 都是 Node.js 社区中非常流行的日志库，它们各有千秋，我们先来简单对比一下：

总的来说，Winston 更灵活，功能更丰富，但配置也更复杂；Pino 则更注重性能，配置更简单。在实际项目中，你可以根据自己的需求进行选择。不过，无论选择哪个，NestJS 都能够很好地与它们集成。

NestJS 日志系统的核心：LoggerService

NestJS 提供了一个内置的 LoggerService 接口，它定义了日志记录的基本方法（log、error、warn、debug、verbose）。NestJS 默认的 Logger 类实现了这个接口，但它只是简单地将日志输出到控制台。在实际项目中，我们通常需要自定义一个 LoggerService，来实现更强大的日志功能。

实战：集成 Winston

1. 安装依赖

npm install winston @nestjs/common

2. 创建自定义 Logger

// src/logger/winston.logger.ts
import { LoggerService } from '@nestjs/common';
import * as winston from 'winston';

export class WinstonLogger implements LoggerService {
  private readonly logger: winston.Logger;

  constructor(private readonly context?: string) {
    this.logger = winston.createLogger({
      level: 'info', // 设置日志级别
      format: winston.format.combine(
        winston.format.timestamp(), // 添加时间戳
        winston.format.json() // 使用 JSON 格式
      ),
      transports: [
        new winston.transports.Console(), // 输出到控制台
        new winston.transports.File({ filename: 'logs/combined.log' }), // 输出到文件
        new winston.transports.File({ filename: 'logs/error.log', level: 'error' }), // 错误日志单独输出
      ],
    });
  }

  log(message: string, context?: string) {
    this.logger.info(message, { context: context || this.context });
  }

  error(message: string, trace?: string, context?: string) {
    this.logger.error(message, { trace, context: context || this.context });
  }

  warn(message: string, context?: string) {
    this.logger.warn(message, { context: context || this.context });
  }

  debug(message: string, context?: string) {
      this.logger.debug(message, { context: context || this.context });
  }
  verbose(message: string, context?: string) {
    this.logger.verbose(message, { context: context || this.context });
  }

}

3. 在 AppModule 中配置

// src/app.module.ts
import { Module, Logger } from '@nestjs/common';
import { WinstonLogger } from './logger/winston.logger';

@Module({
  providers: [
    {
      provide: Logger,
      useClass: WinstonLogger, // 使用自定义的 WinstonLogger
    },
  ],
})
export class AppModule {}

4. 在控制器中使用

// src/app.controller.ts
import { Controller, Get, Logger } from '@nestjs/common';

@Controller()
export class AppController {
  private readonly logger = new Logger(AppController.name);
  // 在构造函数中，建议传入当前类的名称作为 context
  @Get()
  getHello(): string {
    this.logger.log('Handling getHello request...');
    return 'Hello World!';
  }
}

现在，你的 NestJS 应用已经集成了 Winston，日志会同时输出到控制台和文件中。但是，这还远远不够，我们还需要实现请求上下文和链路追踪。

添加请求上下文信息

每次请求都应该有唯一的标识符，以及一些其他的上下文信息，如用户 ID、请求参数等。这些信息可以帮助我们更好地理解请求的执行过程，并在出现问题时快速定位。

1. 创建请求 ID 中间件

// src/middleware/request-id.middleware.ts
import { Injectable, NestMiddleware, Logger } from '@nestjs/common';
import { Request, Response, NextFunction } from 'express';
import { v4 as uuidv4 } from 'uuid';

@Injectable()
export class RequestIdMiddleware implements NestMiddleware {
  private readonly logger = new Logger(RequestIdMiddleware.name);
  use(req: Request, res: Response, next: NextFunction) {
    const requestId = uuidv4();
    req['requestId'] = requestId; // 将 requestId 添加到 req 对象中
    res.setHeader('X-Request-Id', requestId); // 将 requestId 添加到响应头中

    this.logger.log(`Request ID: ${requestId}`);
    next();
  }
}

2. 在 AppModule 中应用中间件

// src/app.module.ts
import { Module, NestModule, MiddlewareConsumer, Logger } from '@nestjs/common';
import { RequestIdMiddleware } from './middleware/request-id.middleware';
import { WinstonLogger } from './logger/winston.logger';

@Module({
  providers: [
    {
      provide: Logger,
      useClass: WinstonLogger, // 使用自定义的 WinstonLogger
    },
  ],
})
export class AppModule implements NestModule {
  configure(consumer: MiddlewareConsumer) {
    consumer.apply(RequestIdMiddleware).forRoutes('*'); // 对所有路由应用中间件
  }
}

3. 修改 WinstonLogger，添加请求 ID

// src/logger/winston.logger.ts
// ... (之前的代码)

  log(message: string, context?: string) {
    const requestId = this.getRequestId();
    this.logger.info(message, { context: context || this.context, requestId });
  }

  error(message: string, trace?: string, context?: string) {
    const requestId = this.getRequestId();
    this.logger.error(message, { trace, context: context || this.context, requestId });
  }

//...其他方法类似

  private getRequestId() {
    // 从 AsyncLocalStorage 中获取 requestId
    return (this as any)._httpContext?.getRequestId?.();
  }

//... (之后的代码) 

4. 利用 AsyncLocalStorage 存储请求上下文

由于 Node.js 的异步特性，我们需要使用 AsyncLocalStorage 来存储每个请求的上下文信息。AsyncLocalStorage 是 Node.js 提供的一个 API，可以在异步调用之间共享数据。
首先需要安装： npm install --save @nestjs/core

// src/logger/winston.logger.ts
import { LoggerService, Scope, Inject, Injectable } from '@nestjs/common';
import * as winston from 'winston';
import { AsyncLocalStorage } from 'async_hooks';
import { REQUEST } from '@nestjs/core';
import { Request } from 'express';

@Injectable({ scope: Scope.REQUEST })
export class WinstonLogger implements LoggerService {
    private readonly logger: winston.Logger;
    private readonly asyncLocalStorage = new AsyncLocalStorage<Map<string, any>>();

    constructor(@Inject(REQUEST) private readonly request: Request) {
        this.logger = winston.createLogger({
          level: 'info',
          format: winston.format.combine(
            winston.format.timestamp(),
            winston.format.json()
          ),
          transports: [
            new winston.transports.Console(),
            new winston.transports.File({ filename: 'logs/combined.log' }),
            new winston.transports.File({ filename: 'logs/error.log', level: 'error' }),
          ],
        });
    }

  log(message: string, context?: string) {
    const store = this.asyncLocalStorage.getStore();
    const requestId = store?.get('requestId');
    this.logger.info(message, { context: context || this.context, requestId });
  }
    // 其他方法类似地添加 requestId

    error(message: string, trace?: string, context?: string) {
        const store = this.asyncLocalStorage.getStore();
        const requestId = store?.get('requestId');
        this.logger.error(message, { trace, context: context || this.context, requestId });
    }

    warn(message: string, context?: string) {
        const store = this.asyncLocalStorage.getStore();
        const requestId = store?.get('requestId');
        this.logger.warn(message, { context: context || this.context, requestId });
    }
    debug(message: string, context?: string) {
        const store = this.asyncLocalStorage.getStore();
        const requestId = store?.get('requestId');
        this.logger.debug(message, { context: context || this.context, requestId });
    }

    verbose(message: string, context?: string) {
        const store = this.asyncLocalStorage.getStore();
        const requestId = store?.get('requestId');
        this.logger.verbose(message, { context: context || this.context, requestId });
    }

    setRequestId(requestId: string) {
        const store = this.asyncLocalStorage.getStore() || new Map();
        store.set('requestId', requestId);
        this.asyncLocalStorage.enterWith(store);
    }

}

// src/middleware/request-id.middleware.ts
// ...之前的代码
@Injectable()
export class RequestIdMiddleware implements NestMiddleware {
  private readonly logger = new Logger(RequestIdMiddleware.name);
  constructor(private readonly loggerService: WinstonLogger) {}

  use(req: Request, res: Response, next: NextFunction) {
    const requestId = uuidv4();
    req['requestId'] = requestId;
    res.setHeader('X-Request-Id', requestId);

    this.loggerService.setRequestId(requestId); // 设置 requestId

    this.logger.log(`Request ID: ${requestId}`);
    next();
  }
}

现在，你的日志中就会包含每个请求的唯一 ID 了。你还可以根据需要，添加其他的上下文信息，如用户 ID、请求参数等。

实现链路追踪

在微服务架构下，一个请求可能会经过多个服务，我们需要一种机制来追踪这个请求在各个服务之间的调用链。这就是链路追踪的作用。

实现链路追踪的方法有很多，这里我们介绍一种基于 HTTP Header 的简单实现：

1. 在入口服务（如 API 网关）生成一个全局唯一的 Trace ID。
2. 将 Trace ID 添加到 HTTP Header 中，向下游服务传递。
3. 下游服务接收到请求后，从 Header 中提取 Trace ID，并继续向下游传递。
4. 在每个服务的日志中，都记录 Trace ID。

这样，我们就可以通过 Trace ID 将一个请求在各个服务中的日志串联起来，形成一个完整的调用链。

在 NestJS 中，我们可以使用拦截器（Interceptor）来实现 Trace ID 的传递：

// src/interceptor/trace-id.interceptor.ts
import { Injectable, NestInterceptor, ExecutionContext, CallHandler, Logger } from '@nestjs/common';
import { Observable } from 'rxjs';
import { tap } from 'rxjs/operators';
import { v4 as uuidv4 } from 'uuid';

@Injectable()
export class TraceIdInterceptor implements NestInterceptor {
  private readonly logger = new Logger(TraceIdInterceptor.name);

  intercept(context: ExecutionContext, next: CallHandler): Observable<any> {
    const request = context.switchToHttp().getRequest();
    let traceId = request.headers['x-trace-id'];

    if (!traceId) {
      traceId = uuidv4();
      request.headers['x-trace-id'] = traceId; // 将 Trace ID 添加到请求头中
    }

    this.logger.log(`Trace ID: ${traceId}`);

    return next.handle().pipe(
      tap(() => {
        // 在响应中也添加 Trace ID
        context.switchToHttp().getResponse().setHeader('X-Trace-Id', traceId);
      })
    );
  }
}

在 AppModule 中全局注册拦截器：

// app.module.ts
import { APP_INTERCEPTOR } from '@nestjs/core';
import { TraceIdInterceptor } from './trace-id.interceptor';

@Module({
  providers: [
    {
      provide: APP_INTERCEPTOR,
      useClass: TraceIdInterceptor,
    },
  ],
})
export class AppModule {}

然后在 WinstonLogger 中，将 traceId 添加到日志：

// src/logger/winston.logger.ts
// ... (之前的代码)

  log(message: string, context?: string) {
    const store = this.asyncLocalStorage.getStore();
    const requestId = store?.get('requestId');
    const traceId = this.request.headers['x-trace-id'];
    this.logger.info(message, { context: context || this.context, requestId, traceId });
  }

//...其他方法做类似处理。

现在，你的日志中就会同时包含 requestId 和 traceId 了。requestId 用于标识同一个请求在同一个服务中的不同阶段，traceId 用于标识同一个请求在不同服务之间的调用链。

集成 Pino

集成 Pino 的过程与 Winston 类似，主要区别在于配置方式。

1. 安装依赖

npm install pino pino-http @nestjs/common

2. 创建自定义 Logger

// src/logger/pino.logger.ts
import { LoggerService, Scope, Inject, Injectable } from '@nestjs/common';
import pino from 'pino';
import { AsyncLocalStorage } from 'async_hooks';
import { REQUEST } from '@nestjs/core';
import { Request, Response } from 'express';

@Injectable({ scope: Scope.REQUEST })
export class PinoLogger implements LoggerService {
    private readonly logger: pino.Logger;
    private readonly asyncLocalStorage = new AsyncLocalStorage<Map<string, any>>();
    constructor(@Inject(REQUEST) private readonly request: Request) {
      this.logger = pino({
        level: 'info',
        prettyPrint: process.env.NODE_ENV !== 'production', // 开发环境开启 prettyPrint
        redact: ['req.headers.authorization'],  // 敏感信息脱敏
      });
    }

  log(message: string, context?: string) {
    const store = this.asyncLocalStorage.getStore();
    const requestId = store?.get('requestId');
    const traceId = this.request.headers['x-trace-id'];
      this.logger.info({ context: context || this.context, requestId, traceId }, message);
  }
    // 其他方法类似地添加 requestId 和 traceId
 error(message: string, trace?: string, context?: string) {
    const store = this.asyncLocalStorage.getStore();
    const requestId = store?.get('requestId');
    const traceId = this.request.headers['x-trace-id'];
      this.logger.error({ context: context || this.context, requestId, traceId, trace }, message);
  }

    warn(message: string, context?: string) {
         const store = this.asyncLocalStorage.getStore();
         const requestId = store?.get('requestId');
         const traceId = this.request.headers['x-trace-id'];
        this.logger.warn({ context: context || this.context, requestId, traceId }, message);
    }
    debug(message: string, context?: string) {
        const store = this.asyncLocalStorage.getStore();
        const requestId = store?.get('requestId');
         const traceId = this.request.headers['x-trace-id'];
        this.logger.debug({ context: context || this.context, requestId, traceId }, message);
    }

    verbose(message: string, context?: string) {
        const store = this.asyncLocalStorage.getStore();
        const requestId = store?.get('requestId');
         const traceId = this.request.headers['x-trace-id'];
        this.logger.verbose({ context: context || this.context, requestId, traceId }, message);
    }
    setRequestId(requestId: string) {
        const store = this.asyncLocalStorage.getStore() || new Map();
        store.set('requestId', requestId);
        this.asyncLocalStorage.enterWith(store);
    }

}

3. 在 AppModule 中配置

// src/app.module.ts
import { Module, Logger } from '@nestjs/common';
import { PinoLogger } from './logger/pino.logger';

@Module({
  providers: [
    {
      provide: Logger,
      useClass: PinoLogger, // 使用自定义的 PinoLogger
    },
  ],
})
export class AppModule {}

4. 添加 pino-http 中间件 (可选，但强烈推荐)

pino-http 是一个专门为 HTTP 请求设计的 Pino 中间件，它可以自动记录请求和响应的信息，并与 PinoLogger 无缝集成。

// src/app.module.ts
import { Module, NestModule, MiddlewareConsumer, Logger } from '@nestjs/common';
import { PinoLogger } from './logger/pino.logger';
import { RequestIdMiddleware } from './middleware/request-id.middleware';
import pinoHttp from 'pino-http';

@Module({
  providers: [
    {
      provide: Logger,
      useClass: PinoLogger,
    },
  ],
})
export class AppModule implements NestModule {
  configure(consumer: MiddlewareConsumer) {
      consumer.apply(RequestIdMiddleware).forRoutes('*');
    consumer
      .apply(
          pinoHttp({
              logger: new PinoLogger({} as any).logger, // 传入 PinoLogger 实例
               //  customProps: (req, res) => ({
               //      // 自定义属性
               //  }),
              // autoLogging: false, // 可以选择关闭自动日志
          })
      )
      .forRoutes('*');
  }
}

现在，你的 NestJS 应用已经集成了 Pino，并且可以自动记录请求和响应的信息，以及请求 ID 和 Trace ID。

总结

通过本文的学习，相信你已经掌握了如何在 NestJS 中集成 Winston 和 Pino，并实现请求上下文和链路追踪。这些技能可以帮助你构建更健壮、更易于维护的应用程序。记住，一个好的日志系统是系统稳定运行的基石，也是开发者排查问题的利器。希望你在实际项目中能够灵活运用这些知识，让你的应用“日”久弥新！