NestJS 进阶：AsyncLocalStorage 实现优雅请求上下文追踪，告别混乱日志

NestJS 进阶：AsyncLocalStorage 实现优雅请求上下文追踪，告别混乱日志

“喂，哥们，你那个接口又出问题了，赶紧看看日志！”

“啥？哪个接口？哪个环境？请求参数是啥？用户 ID 呢？能不能给点有用的信息啊！”

“我这只有报错信息，别的啥也不知道啊……”

相信不少后端开发者都经历过上面这种令人抓狂的对话。在微服务架构下，一个请求往往会跨越多个服务，传统的日志记录方式很难追踪整个请求链路，导致排查问题如同大海捞针。尤其是在高并发场景下，不同请求的日志混杂在一起，更是让人眼花缭乱，无从下手。

作为一名有追求的 NestJS 开发者，咱们当然不能忍受这种低效的协作方式。今天，我就来给大家分享一个 NestJS 进阶技巧——使用 AsyncLocalStorage 实现优雅的请求上下文追踪，彻底告别混乱的日志，让问题排查变得 so easy！

什么是请求上下文？

在聊 AsyncLocalStorage 之前，咱们先来搞清楚“请求上下文”这个概念。简单来说，请求上下文就是指一个请求从进入系统到最终响应的整个生命周期内所携带的信息。这些信息通常包括：

• 请求 ID (Request ID)：唯一标识一个请求，用于串联整个请求链路。
• 用户 ID (User ID)：标识发起请求的用户。
• 请求时间戳：记录请求进入系统的时间。
• 请求路径 (Request Path)：记录请求的 URL 路径。
• 请求方法 (Request Method)：记录请求的 HTTP 方法（GET、POST、PUT、DELETE 等）。
• 请求参数 (Request Parameters)：记录请求携带的参数。
• 客户端 IP：记录发起请求的客户端 IP 地址。
• Trace ID/Span ID: 分布式链路追踪系统的标识
• ……

有了这些信息，我们就可以清晰地还原出每个请求的完整轨迹，即使请求跨越了多个服务，也能轻松追踪到问题的根源。

传统方案的痛点

在没有 AsyncLocalStorage 之前，我们通常会采用以下几种方式来传递请求上下文：

1. 手动参数传递：在每个函数调用时，都将请求上下文信息作为参数显式传递。这种方式最直接，但也最繁琐，代码冗余度极高，而且容易遗漏。
2. 全局变量：将请求上下文信息存储在全局变量中。这种方式虽然避免了手动参数传递的麻烦，但全局变量容易造成命名冲突，而且在多线程环境下存在线程安全问题。
3. Thread Local Storage (TLS)：在 Java 等语言中，可以使用 TLS 来存储线程私有的数据。但 Node.js 是单线程的，虽然有 async_hooks 模块可以模拟类似的功能，但使用起来比较复杂，而且性能开销较大。
4. 中间件 + 闭包: 通过中间件来拦截请求，通过闭包来保存一些信息，但是如果在异步调用链中，这些信息会丢失或者错乱。

这些传统方案都存在各自的缺陷，要么代码冗余，要么线程不安全，要么性能开销大，总之都不够优雅。

AsyncLocalStorage 登场

AsyncLocalStorage 是 Node.js 内置的一个模块（Node.js v12.17.0+），它提供了一种在异步调用链中安全地存储和访问上下文数据的机制。AsyncLocalStorage 的核心思想是：为每个异步操作创建一个独立的存储空间，这个存储空间在整个异步调用链中都是可见的，而且不会被其他异步操作所干扰。

AsyncLocalStorage 的 API 非常简单，主要有以下几个方法：

• new AsyncLocalStorage()：创建一个新的 AsyncLocalStorage 实例。
• run(store, callback, ...args)：运行一个回调函数，并将 store 作为当前异步操作的上下文数据。callback 中的所有异步操作都可以访问到 store。
• getStore()：在 callback 中获取当前异步操作的上下文数据，即 run 方法传入的 store。
• enterWith(store): 进入一个预先设置好数据的上下文.
• exit(callback): 退出当前上下文

AsyncLocalStorage 的最大优势就是可以自动跟踪异步流程, 避免了手动传递上下文或使用全局变量的繁琐和风险。

在 NestJS 中使用 AsyncLocalStorage

在 NestJS 中使用 AsyncLocalStorage 非常简单，我们可以通过自定义中间件、拦截器或守卫来实现请求上下文的追踪。

1. 创建 AsyncLocalStorage 实例

首先，我们需要创建一个 AsyncLocalStorage 实例，用于存储请求上下文数据：

// src/common/async-local-storage.ts
import { AsyncLocalStorage } from 'async_hooks';
 
export const requestContext = new AsyncLocalStorage<Map<string, any>>();

这里我们创建了一个 requestContext 实例，它的存储类型是一个 Map，用于存储键值对形式的上下文数据。

2. 创建中间件

接下来，我们创建一个中间件，用于拦截每个请求，并初始化请求上下文：

// src/common/middleware/request-context.middleware.ts
import { Injectable, NestMiddleware } from '@nestjs/common';
import { Request, Response, NextFunction } from 'express';
import { requestContext } from '../async-local-storage';
import { v4 as uuidv4 } from 'uuid';
 
@Injectable()
export class RequestContextMiddleware implements NestMiddleware {
  use(req: Request, res: Response, next: NextFunction) {
    const store = new Map();
    // 生成唯一的请求 ID
    const requestId = uuidv4();
    store.set('requestId', requestId);
    store.set('requestTime', new Date());
 
    // 将请求上下文数据存储到 AsyncLocalStorage 中
    requestContext.run(store, () => {
      next();
    });
  }
}

在这个中间件中，我们做了以下几件事情：

• 从 express 中导入了 Request、Response 和 NextFunction。
• 使用uuid库生成一个唯一的请求 ID。
• 创建一个 Map 对象 store，用于存储请求上下文数据。
• 将请求 ID、请求时间等信息存储到 store 中。
• 调用 requestContext.run(store, next) 方法，将 store 作为当前异步操作的上下文数据，并执行 next() 函数，将请求传递给下一个中间件或控制器。

3. 注册中间件

然后，我们需要在 AppModule 中注册这个中间件：

// src/app.module.ts
import { Module, NestModule, MiddlewareConsumer } from '@nestjs/common';
import { RequestContextMiddleware } from './common/middleware/request-context.middleware';
 
@Module({})
export class AppModule implements NestModule {
  configure(consumer: MiddlewareConsumer) {
    consumer.apply(RequestContextMiddleware).forRoutes('*');
  }
}

这里我们使用 forRoutes('*') 将中间件应用到所有路由。

4. 在服务中使用请求上下文

现在，我们就可以在任何服务中通过 requestContext.getStore() 方法获取当前请求的上下文数据了：

// src/app.service.ts
import { Injectable } from '@nestjs/common';
import { requestContext } from './common/async-local-storage';
 
@Injectable()
export class AppService {
  getHello(): string {
    const store = requestContext.getStore();
    const requestId = store.get('requestId');
    const requestTime = store.get('requestTime');
 
    console.log(`[${requestId}] Request received at ${requestTime}`);
 
    return 'Hello World!';
  }
}

在这个例子中，我们在 AppService 的 getHello 方法中获取了请求 ID 和请求时间，并打印到控制台。这样，我们就可以在日志中清晰地看到每个请求的处理情况了。

5. 在拦截器中使用请求上下文

除了在服务中使用请求上下文，我们还可以在拦截器中使用它，例如，我们可以创建一个日志拦截器，用于记录每个请求的响应时间：

// src/common/interceptors/logging.interceptor.ts
import { Injectable, NestInterceptor, ExecutionContext, CallHandler } from '@nestjs/common';
import { Observable } from 'rxjs';
import { tap } from 'rxjs/operators';
import { requestContext } from '../async-local-storage';
 
@Injectable()
export class LoggingInterceptor implements NestInterceptor {
  intercept(context: ExecutionContext, next: CallHandler): Observable<any> {
    const store = requestContext.getStore();
    const requestId = store.get('requestId');
    const now = Date.now();
 
    return next.handle().pipe(
      tap(() => {
        const responseTime = Date.now() - now;
        console.log(`[${requestId}] Response time: ${responseTime}ms`);
      }),
    );
  }
}

在这个拦截器中，我们在请求处理前获取了请求 ID 和当前时间戳，然后在请求处理完成后计算响应时间，并打印到控制台。

6. 注册拦截器

同样, 我们需要在AppModule中注册这个拦截器:

// src/app.module.ts
import { Module, NestModule, MiddlewareConsumer } from '@nestjs/common';
import { RequestContextMiddleware } from './common/middleware/request-context.middleware';
import { APP_INTERCEPTOR } from '@nestjs/core';
import { LoggingInterceptor } from './common/interceptors/logging.interceptor';
 
@Module({
  providers: [
    {
      provide: APP_INTERCEPTOR,
      useClass: LoggingInterceptor,
    },
  ],
})
export class AppModule implements NestModule {
  configure(consumer: MiddlewareConsumer) {
    consumer.apply(RequestContextMiddleware).forRoutes('*');
  }
}

7. 丰富上下文信息

除了请求 ID 和请求时间，我们还可以根据实际需求向请求上下文中添加更多信息，例如用户 ID、请求参数、客户端 IP 等。这些信息可以从请求对象中获取，也可以通过其他方式获取。

// src/common/middleware/request-context.middleware.ts
// ... (之前的代码)
 
    //假设已经通过某种方式获取到了userId
    const userId = req.headers['x-user-id'];
    if (userId) {
      store.set('userId', userId);
    }
 
    // 获取客户端IP
     const clientIp = req.ip || req.socket.remoteAddress; 
     if(clientIp){
        store.set('clientIp', clientIp);
     }
 
// ... (之后的代码)

8. 在异步操作中使用

由于AsyncLocalStorage能自动跟踪异步调用链, 因此即使我们在service中有异步操作, 也依然能获取到正确的上下文.

// src/app.service.ts
import { Injectable } from '@nestjs/common';
import { requestContext } from './common/async-local-storage';
 
@Injectable()
export class AppService {
  async getHello(): Promise<string> {
    const store = requestContext.getStore();
    const requestId = store.get('requestId');
 
    // 模拟异步操作
    await new Promise((resolve) => setTimeout(resolve, 100));
 
    console.log(`[${requestId}] Request still tracked after async operation!`);
 
    return 'Hello World!';
  }
}

与其他方案的对比

总结

AsyncLocalStorage 为 NestJS 开发者提供了一种优雅、高效的方式来实现请求上下文追踪。它不仅简化了代码，提高了可维护性，还避免了传统方案的各种缺陷。通过 AsyncLocalStorage，我们可以轻松地追踪每个请求的完整生命周期，快速定位问题，提高开发效率。

希望本文能帮助你更好地理解和使用 AsyncLocalStorage，让你的 NestJS 项目更加健壮、高效！

如果你有任何问题或建议，欢迎在评论区留言交流！

补充：与日志库集成

为了更好地利用请求上下文信息，我们可以将 AsyncLocalStorage 与日志库集成，例如 winston 或 pino。这样，我们就可以在日志中自动包含请求 ID、用户 ID 等信息，方便后续的日志分析和问题排查。

以pino为例:

1. 安装: npm install pino pino-http --save

2. 在middleware中集成:

// src/common/middleware/request-context.middleware.ts
import { Injectable, NestMiddleware } from '@nestjs/common';
import { Request, Response, NextFunction } from 'express';
import { requestContext } from '../async-local-storage';
import { v4 as uuidv4 } from 'uuid';
import pino from 'pino';
 
@Injectable()
export class RequestContextMiddleware implements NestMiddleware {
  private readonly logger = pino(); // or pinoHttp() for more features.
 
  use(req: Request, res: Response, next: NextFunction) {
    const store = new Map();
    const requestId = uuidv4();
    store.set('requestId', requestId);
    store.set('requestTime', new Date());
 
    const childLogger = this.logger.child({ requestId });
    store.set('logger', childLogger);
 
    requestContext.run(store, () => {
      next();
    });
  }
}
 
//src/app.service.ts
import { Injectable } from '@nestjs/common';
import { requestContext } from './common/async-local-storage';
 
@Injectable()
export class AppService {
  async getHello(): Promise<string> {
    const store = requestContext.getStore();
    const logger = store.get('logger');
 
    logger.info('Processing getHello request...');
 
    // 模拟异步操作
    await new Promise((resolve) => setTimeout(resolve, 100));
 
    logger.info('Finished processing getHello request.');
 
    return 'Hello World!';
  }
}

这样，所有通过logger输出的日志都会自动带上requestId。

进阶：分布式链路追踪

在微服务架构下，一个请求可能会跨越多个服务。为了追踪整个请求链路，我们需要使用分布式链路追踪系统，例如 Jaeger、Zipkin 或 OpenTelemetry。这些系统通常会使用 Trace ID 和 Span ID 来标识请求链路和每个服务中的操作。我们可以将这些 ID 也存储到 AsyncLocalStorage 中，并在服务间传递，从而实现完整的分布式链路追踪。

由于分布式链路追踪涉及的内容较多，本文不再展开，感兴趣的同学可以自行研究。