Ubuntu JS日志中如何追踪请求链路

Ubuntu环境下通过JS日志追踪请求链路的方法

在Ubuntu上部署Node.js应用，一旦请求量上来，或者系统变得复杂，排查问题就成了头疼事。一个请求进来，经过了哪些中间件、调用了哪些服务、耗时卡在哪里，如果日志是零散的，无异于大海捞针。今天，我们就来系统地梳理一下，如何通过JS日志，构建起清晰的请求链路追踪体系。

1. 基础日志配置：记录请求基本信息

万丈高楼平地起，链路追踪的第一步，就是把每个请求的基本信息记录下来。这通常离不开成熟的日志库，比如 winston 和 morgan。

• 使用 morgan（HTTP请求专用中间件）：morgan 可以说是为HTTP日志而生的，它提供了开箱即用的预定义格式（如 dev、combined），也支持高度自定义。对于快速上手非常友好。

  const morgan = require('morgan');
  app.use(morgan(':method :url :status :res[content-length] - :response-time ms')); // 自定义格式

  运行后，控制台就会输出类似 GET /api/users 200 123 - 45ms 这样的日志，一目了然地告诉你：这是一个GET请求，访问了 /api/users，状态码是200，响应花了45毫秒。
• 使用 winston（结构化日志库）：如果应用要上生产环境，winston 会是更强大的选择。它支持JSON格式输出，可以同时将日志写入文件和控制台，方便后续的集中处理。

  const winston = require('winston');
  const logger = winston.createLogger({
    level: 'info',
    format: winston.format.combine(
      winston.format.timestamp(),
      winston.format.json()
    ),
    transports: [
      new winston.transports.File({ filename: 'logs/error.log', level: 'error' }),
      new winston.transports.File({ filename: 'logs/combined.log' }),
      new winston.transports.Console() // 开发环境输出到控制台
    ]
  });
  
  // 请求日志中间件
  app.use((req, res, next) => {
    logger.info({
      message: 'Incoming request',
      method: req.method,
      url: req.originalUrl,
      headers: req.headers
    });
    next();
  });

  这种结构化的JSON日志，是后续接入ELK、Grafana等分析工具的理想数据源。

2. 关联请求上下文：实现全链路TraceID

基础日志记录了单次请求，但在微服务或异步场景下，一个用户操作可能触发多个服务调用。怎么把这些散落的日志串起来？关键就在于一个贯穿始终的唯一标识——traceId。

这里需要借助上下文存储技术，在异步调用链中传递这个ID。目前主流有两种方式：

• 使用 AsyncLocalStorage（Node.js原生API，v14.17.0+）：这是Node.js官方提供的方案，无需引入额外依赖，性能也更好。它的核心思想是为每个请求创建一个独立的存储上下文。

  const { AsyncLocalStorage } = require('async_hooks');
  const asyncLocalStorage = new AsyncLocalStorage();
  
  // 请求中间件：生成并绑定traceId
  app.use((req, res, next) => {
    const traceId = req.headers['x-trace-id'] || generateUniqueId(); // 从请求头获取或生成
    asyncLocalStorage.run(traceId, () => {
      req.traceId = traceId; // 将traceId挂载到请求对象
      next();
    });
  });
  
  // 日志中间件：从上下文中获取traceId
  app.use((req, res, next) => {
    const traceId = asyncLocalStorage.getStore();
    logger.info({ traceId, method: req.method, url: req.originalUrl });
    next();
  });
  
  function generateUniqueId() {
    return Math.random().toString(36).substr(2, 9);
  }

  这样，在整个请求的生命周期内，任何地方都能通过 asyncLocalStorage.getStore() 拿到同一个 traceId。
• 使用 cls-hooked（第三方库，兼容旧版本）：如果你的Node版本较低，或者更喜欢简洁的API，cls-hooked 是个不错的备选。它是对 async_hooks 的封装，概念上类似于创建一个命名空间。

  const cls = require('cls-hooked');
  const session = cls.createNamespace('request');
  
  app.use((req, res, next) => {
    session.run(() => {
      session.set('traceId', req.headers['x-trace-id'] || generateUniqueId());
      next();
    });
  });
  
  // 日志中间件：从session中获取traceId
  app.use((req, res, next) => {
    const traceId = session.get('traceId');
    logger.info({ traceId, method: req.method, url: req.originalUrl });
    next();
  });

  无论采用哪种方式，目标都是一致的：让来自同一个源头请求的所有日志，都带上相同的 traceId。这样，在日志系统里一搜这个ID，整条链路的来龙去脉就清晰了。

3. 中间件增强：记录请求/响应详情

有了唯一标识，接下来可以丰富日志的内容，特别是记录请求的耗时和关键数据，这对于定位性能瓶颈和调试复杂业务逻辑至关重要。

• 记录请求开始时间与耗时：一个很实用的技巧是在请求开始时记录时间戳，在响应结束时计算耗时。

  app.use((req, res, next) => {
    const start = Date.now();
    res.on('finish', () => {
      const duration = Date.now() - start;
      logger.info({
        traceId: req.traceId,
        method: req.method,
        url: req.originalUrl,
        status: res.statusCode,
        duration
      });
    });
    next();
  });

  日志输出会是这样的结构：{"traceId":"abc123","method":"GET","url":"/api/users","status":200,"duration":45}，直接告诉你这次调用花了多少时间。
• 记录请求/响应体（需谨慎）：在调试阶段，有时需要看到具体的请求参数和返回数据。但这里有个安全红线：必须过滤敏感信息（如密码、令牌）。

  // 记录请求体（以POST/PUT为例）
  app.use((req, res, next) => {
    if (req.method === 'POST' || req.method === 'PUT') {
      // 深拷贝一份，避免意外修改原数据
      req.bodyCopy = JSON.parse(JSON.stringify(req.body));
      logger.debug({ traceId: req.traceId, body: req.bodyCopy });
    }
    next();
  });
  
  // 拦截并记录响应体
  app.use((req, res, next) => {
    const originalSend = res.send;
    res.send = function(data) {
      res.locals.responseBody = data;
      originalSend.call(this, data);
    };
    next();
  });
  
  // 在响应后记录
  app.use((req, res, next) => {
    if (res.locals.responseBody) {
      logger.debug({ traceId: req.traceId, responseBody: res.locals.responseBody });
    }
  });

  切记：这类包含业务数据的日志，务必仅限在开发或测试环境开启（如设置日志级别为 debug），生产环境必须关闭或进行严格的脱敏处理。

4. 集中式日志管理：集中存储与分析

当应用部署在多台Ubuntu服务器上时，登录每台机器看日志是不现实的。我们需要把日志集中起来，进行统一的存储、检索和可视化分析。

• ELK Stack（Elasticsearch + Logstash + Kibana）：这是最经典的日志解决方案之一。
  • Logstash配置：它的角色是“日志搬运工”，负责从你的应用日志文件（比如 /var/log/my-js-app.log）里读取数据，解析后发送给Elasticsearch。

    input {
      file {
        path => "/var/log/my-js-app.log"
        start_position => "beginning"
        codec => "json"
      }
    }
    output {
      elasticsearch {
        hosts => ["localhost:9200"]
        index => "nodejs-logs-%{+YYYY.MM.dd}"
      }
    }

  • Kibana可视化：数据进入Elasticsearch后，就可以用Kibana这个强大的前端工具了。你可以轻松创建仪表盘，实时展示请求量、错误率、平均响应时间、慢请求排行等关键指标，所有日志都可以用 traceId 进行关联查询。
• Prometheus + Grafana：如果你更关注指标监控而非原始日志检索，这个组合是另一个方向。
  • Prometheus客户端：在Node.js应用里使用 prom-client 库定义和暴露指标。

    const promClient = require('prom-client');
    const httpRequestCounter = new promClient.Counter({
      name: 'http_requests_total',
      help: 'Total HTTP requests',
      labelNames: ['method', 'path', 'status']
    });
    
    app.use((req, res, next) => {
      httpRequestCounter.inc({ method: req.method, path: req.originalUrl, status: res.statusCode });
      next();
    });
    
    app.get('/metrics', async (req, res) => {
      res.set('Content-Type', promClient.register.contentType);
      res.end(await promClient.register.metrics());
    });

  • Grafana仪表盘：Prometheus定时拉取 /metrics 接口的数据，Grafana则连接Prometheus数据源，绘制出精美的监控图表，并设置报警规则。

5. 高级工具：链路追踪系统

对于跨多个服务的复杂分布式系统，前面提到的 traceId 手动传递方式会显得力不从心。这时就需要专业的分布式链路追踪系统，比如 OpenTelemetry 或 Jaeger。

• OpenTelemetry示例：OpenTelemetry 是目前云原生领域的事实标准，它提供了一套统一的API。

  const { NodeTracerProvider } = require('@opentelemetry/sdk-trace-node');
  const { SimpleSpanProcessor } = require('@opentelemetry/sdk-trace-base');
  const { JaegerExporter } = require('@opentelemetry/exporter-jaeger');
  const { registerInstrumentations } = require('@opentelemetry/instrumentation');
  const { HttpInstrumentation } = require('@opentelemetry/instrumentation-http');
  
  const provider = new NodeTracerProvider();
  provider.addSpanProcessor(
    new SimpleSpanProcessor(new JaegerExporter({ endpoint: 'http://localhost:14268/api/traces' }))
  );
  provider.register();
  
  // 自动为HTTP请求注入追踪
  registerInstrumentations({
    instrumentations: [new HttpInstrumentation()]
  });
  
  // 也可以手动创建更细粒度的Span
  const tracer = provider.getTracer('my-app');
  app.get('/api/users', (req, res) => {
    const span = tracer.startSpan('get-users');
    // ... 业务逻辑
    span.end();
    res.send([{ id: 1, name: 'Alice' }]);
  });

  配置好后，所有的服务间调用（包括HTTP、gRPC等）都会被自动记录并关联。你可以打开Jaeger的UI界面，看到一个请求从网关到用户服务，再到订单服务、数据库的完整调用树，每个环节的耗时、是否出错都清清楚楚。这才是真正意义上的端到端（End-to-End）链路追踪。

从最基础的请求日志记录，到引入唯一的TraceID串联上下文，再到中间件增强记录关键数据，最后通过集中化日志平台或专业的APM工具进行宏观分析——这套组合拳打下来，无论在Ubuntu单机环境还是复杂的分布式架构下，请求链路都将变得透明、可追溯。选择哪种方案，取决于你系统的复杂度和团队的运维能力，但核心思路是相通的：让每一次请求都有迹可循。