侧边栏壁纸
博主头像
一笑痕

人生若只如初见,
是可喜亦或者是可悲?

  • 累计撰写 166 篇文章
  • 累计收到 7 条评论

trace id 要在进异步之前挂上,晚一步就丢

2026-10-8 / 0 评论 / 10 阅读

trace id 要在进异步之前挂上,晚一步就丢

几个请求同时进来,日志行会互相穿插。想按一次请求把相关的行捞出来,就得让每一层打印都带上同一串 id。id 好生成,麻烦在怎么让它自动传到下游每一层异步调用,不用在函数之间当参数递。Node 的 async_hooks 模块里有个 AsyncLocalStorage,专门做这件事,本机 node 是 v26.8.1。照能跑起来的最小顺序走一遍,每一步都是可以直接执行的一小段。

最小的一步:把 store 包进 run

import { AsyncLocalStorage } from 'node:async_hooks';

const als = new AsyncLocalStorage();

als.run({ traceId: 't-001' }, () => {
  console.log(als.getStore().traceId); // t-001
});

run 的第一个参数是任意对象,第二个参数是回调。在回调以及它触发的异步资源里,getStore() 拿到的都是同一个对象。回调同步跑完,这份 store 就跟着消失。存成单独的 .mjs 用 node 跑一次,打印 t-001。

跨 await 与跨 setTimeout 都还在

async function crossAwait() {
  await Promise.resolve();
  await new Promise((r) => setTimeout(r, 1));
  return als.getStore()?.traceId;
}

await als.run({ traceId: 't-002' }, async () => {
  console.log(await crossAwait()); // t-002
});

await als.run({ traceId: 't-003' }, () => new Promise((resolve) => {
  setTimeout(() => {
    console.log(als.getStore()?.traceId); // t-003
    resolve();
  }, 0);
}));

两个 await 之后读到 t-002,把读取放进 setTimeout 回调读到 t-003。决定结果的不是流逝的时间,是这条异步在哪个上下文里发起。异步资源会继承发起它的那个上下文,之后无论隔了多少个事件循环,读到的还是同一份。

什么时候会丢

顶层代码,也就是没有被任何 run 包住的那部分,读 getStore() 得到 undefined。

console.log(als.getStore()); // undefined

把回调存起来、等离开 run 之后再调用,读到的同样是 undefined。回调不会记住它被定义时的上下文,它在哪被调用,就落在哪的上下文里。

let saved;
als.run({ traceId: 't-007' }, () => {
  saved = () => als.getStore()?.traceId;
  console.log(saved()); // t-007,此刻还在 run 内
});
console.log(saved());   // undefined,run 已经结束

还有一种更隐蔽的写法:在初始化阶段先把 store 抓进闭包,之后一直复用那个引用。抓到的只是第一次那份对象,后面的请求读它还是旧值。这一点在本机实测里也复现了,新请求里读到的仍是上一个 id。

事件总线要留意 emit 的位置

import { EventEmitter } from 'node:events';
const bus = new EventEmitter();
bus.on('ping', () => console.log(als.getStore()?.traceId));

als.run({ traceId: 't-008' }, () => bus.emit('ping')); // t-008
bus.emit('ping');                                      // undefined

监听器读到的是 emit 那一刻的上下文。在 run 里发事件,监听器看到 t-008;换到 run 外面发,同一个监听器看到 undefined。中间件、任务队列这类先注册回调、之后从别处触发的库,如果触发动作不在请求上下文里,id 就从这里断开。

一个最小的 HTTP 服务

import http from 'node:http';

let n = 0;
const server = http.createServer((req, res) => {
  const traceId = `req-${++n}`;
  als.run({ traceId }, async () => {
    const seen = [als.getStore().traceId];
    seen.push(await getUser());   // 中间层,内部有一次 await
    seen.push(await writeLog());  // 底层,内部有一次 await
    res.end(JSON.stringify({ traceId, seen }));
  });
});

getUser 与 writeLog 各自 await 一次,再读一次 getStore()。三层读到的都是同一个 id,响应里 req-1 会出现三次。

本机跑出来的完整输出

== 0. 环境 ==
  node v26.8.1
  AsyncLocalStorage 从 node:async_hooks 取到: 可用

== 1. run 里放一个 store,同步读回来 ==
  run 内同步读 getStore().traceId:t-001

== 2. 跨 await 读 store ==
  两个 await 之后:t-002

== 3. 跨 setTimeout 读 store ==
  setTimeout 回调里:t-003

== 4. 跨 Promise 链读 store ==
  .then 链末:t-004

== 5. run 之外读 store ==
  没有任何 run 包裹的顶层代码,getStore() 是:undefined

== 6. 把 store 在初始化时抓进闭包,之后复用 ==
  run 结束后看 captured.traceId:t-006a
  新请求里 captured.traceId 仍然是:t-006a(期望 t-006b,实际拿的是旧的)

== 7. 把回调存起来,稍后在 run 之外执行 ==
  在 run 内立刻调用这个回调:t-007
  离开 run 之后再调用同一个回调:undefined

== 8. EventEmitter:读的是 emit 那一刻的上下文 ==
  监听器读到:t-008
  监听器读到:undefined

== 9. HTTP 服务:每个请求一个 trace id,穿过三层异步 ==
  顺序请求 1:入口 中间层 底层 读到的是 req-1 / req-1 / req-1(请求自己的 id 是 req-1)
  顺序请求 2:入口 中间层 底层 读到的是 req-2 / req-2 / req-2(请求自己的 id 是 req-2)

== 10. 两个并发请求,各自拿自己的 id ==
  并发 A:req-3 / req-3 / req-3(req-3)
  并发 B:req-4 / req-4 / req-4(req-4)
  有没有串号:没有,各层读到的都是本请求的 id

== 11. enterWith:不包回调,直接建立上下文 ==
  enterWith 之后同步读:t-011
  再 await 一次:t-011
  (enterWith 影响它之后当前执行路径上的所有代码,不会再自动还原)

== 12. 版本与来源 ==
  process.versions.node = 26.8.1
  process.versions.v8 = 14.6.202.34-node.28

顺序请求给的是 req-1 与 req-2,各三层都读到自己的 id。两个并发请求分别是 req-3 和 req-4,中间没有串号,说明上下文是按请求分开的,不会乱。

enterWith 不包回调

const als2 = new AsyncLocalStorage();
als2.enterWith({ traceId: 't-011' });
console.log(als2.getStore()?.traceId); // t-011

await someAsyncWork();
console.log(als2.getStore()?.traceId); // 还是 t-011

enterWith 把 store 直接设到当前执行路径上,之后所有代码都能看到它,await 之后也一样,直到被下一次 run 覆盖或这条路径结束。它的用处是在请求入口一次性建立上下文,代价是不会自动还原,脚本里连着测几段容易互相污染。

落在写法上的取舍

落地时先把请求处理入口套上一层 run,业务函数里只负责 getStore。模块加载阶段不要提前把 store 抓走,需要时现取,否则抓到的永远是第一份。用到的库在哪一段触发回调,那段就得在请求上下文里。

我的取舍是只在入口 run 一次,不在业务代码里散着写 enterWith,好处是上下文的边界一眼能看清;代价是中间某层如果自己开了新的执行线,仍然要手动把它接回请求的上下文。要不要用它,取决于日志是否需要按请求串起来;只跑单次、没有并发的脚本,把 id 当参数传反而更直白。

    🤞 分享