Dreamer Dreamer
首页
  • 分类
  • 标签
  • 归档
关于
GitHub (opens new window)

lycpan233

白日梦想家
首页
  • 分类
  • 标签
  • 归档
关于
GitHub (opens new window)
  • Mysql

  • Node

    • npm为什么父项目指定依赖版本后,可以影响到子项目的依赖
    • MacOS pnmp多个项目同个包,为什么没有共享存储空间?
    • pnpm 使用指南
    • pnpm 下载依赖更换源不生效
    • Commitizen + Commitlint + husky 实践
    • package.json 中波浪号~ 异或号^ 是什么意思?
    • 日志追踪
      • 背景
      • 示例
        • 1. 通过全局变量标识唯一值 ❌
        • 2. 通过参数传递方式实现唯一值标识 ❌
        • 3. Nodejs - AsyncLocalStorage ✅
      • AsyncLocalStorage 实现原理
        • AsyncLocalStorage 类
        • run()
        • async_hooks 类
      • 兼容性问题❗
      • 相关文档
  • Go

  • Docker

  • 后端
  • Node
lycpan233
2025-08-07
目录

日志追踪

# 背景

在日常开发中,我们常常会遇到一些难以预见的业务逻辑错误。为了解决这类问题,通常会借助一些技术手段来获取上下文信息,其中最常用的方法就是记录日志(log)。通过详尽的日志输出,我们可以清晰地掌握业务流程、数据变更等关键信息。

然而,随着业务场景的复杂化,我们逐渐受到项目运行环境、业务并发量以及代码实现复杂度等因素的限制。此时,如何从海量日志中精准地定位问题并获取相关的上下文信息,成为一项挑战。

基于上述的问题,我们不难想到,能否为每个请求分配一个唯一标识,从而确保在日志检索的时候,可以通过唯一标识进行定位?


# 示例

# 1. 通过全局变量标识唯一值 ❌

很容易我们想到一个方案,就是维护一个全局变量,当请求进来以后,我们初始化对应的变量,后续打印日志的时候,获取变量即可。

请看下方的全局变量的示例:

const axios = require('axios');
const koa = require('koa');

const app = new koa();
let traceId;

app.use(async ctx => {
  traceId = Math.random().toString(36).substring(2, 6);
  console.log('request start', traceId);

  // 模拟一些异步调用
  await someAsyncCall();

  console.log('request ending', traceId);
  ctx.body = 'Hello World' + traceId;
});

app.listen(3000);

async function someAsyncCall() {
  console.log('someAsyncCall start', traceId);

  return new Promise(resolve => setTimeout(() => {
    resolve();
    console.log('someAsyncCall end', traceId);
  }, 2000));
}

// 模拟客户端请求
(async () => {
  const arr = [];
  for (let i = 0; i < 2; i++) {
    arr.push(axios.get('http://localhost:3000'));
  }
  await Promise.allSettled(arr);
})();

// request start iqd9
// someAsyncCall start iqd9
// request start y71d
// someAsyncCall start y71d
// someAsyncCall end y71d
// request ending y71d
// someAsyncCall end y71d
// request ending y71d
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45

从上述示例不难看出,由于两个请求几乎同时发出,traceId 的值会被第二个请求覆盖,从而影响到第一个请求中后续的日志打印。

产生该问题的原因是 Nodejs 的全局变量被多个请求共享,不同于Java、C++ 等语言,会为每个请求分配线程,而线程天然拥有属于该请求的上下文环境(如线程局部变量)。

既然提到局部变量,那我们能不能尝试将 traceId 作为一个局部变量使用呢?

# 2. 通过参数传递方式实现唯一值标识 ❌

const axios = require('axios');
const koa = require('koa');

const app = new koa();

app.use(async ctx => {
  const traceId = Math.random().toString(36).substring(2, 6);
  ctx.traceId = traceId;
  console.log('request start', ctx.traceId);

  // 模拟一些异步调用
  await someAsyncCall(ctx);

  console.log('request ending', ctx.traceId);
  ctx.body = 'Hello World' + ctx.traceId;
});

app.listen(3000);

async function someAsyncCall(ctx) {
  console.log('someAsyncCall start', ctx.traceId);

  return new Promise(resolve => setTimeout(() => {
    resolve();
    console.log('someAsyncCall end', ctx.traceId);
  }, 2000));
}

// 模拟客户端请求
(async () => {
  const arr = [];
  for (let i = 0; i < 2; i++) {
    arr.push(axios.get('http://localhost:3000'));
  }
  await Promise.allSettled(arr);
})();

// request start ee6s
// someAsyncCall start ee6s
// request start h96m
// someAsyncCall start h96m
// someAsyncCall end ee6s
// request ending ee6s
// someAsyncCall end h96m
// request ending h96m
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45

当通过 参数传递 的方法也可以解决唯一标识的问题,但是其仍然存在一些问题:

  • 代码复杂度,每层函数都需要显式的传递 traceId 尽管,该参数与当前业务无关。

  • 边界情况难以触及,当调用一些中间件、三方服务时,函数签名固定,不支持传入。脱离同步栈(比如 setTimeout、事件监听、第三方异步库回调)的时候,也无法传入。

# 3. Nodejs - AsyncLocalStorage ✅

AsyncLocalStorage 是 Nodejs 提供的一种异步上下文跟踪解决方案。它类似于其他语言中的线程本地存储。我们可以通过它重构上面的例子。

const axios = require('axios');
const koa = require('koa');
const { AsyncLocalStorage } = require('async_hooks');
const asyncLocalStorage = new AsyncLocalStorage();

const app = new koa();

// 定义 log 函数
const log = (...args) => {
  const traceId = asyncLocalStorage.getStore();
  console.log(...args, traceId);
};

app.use(async (ctx, next) => {
  const traceId = Math.random().toString(36).substring(2, 6);
  asyncLocalStorage.run(traceId, async () => {
    await next();
  });
});

app.use(async ctx => {
  log('request start');

  // 模拟异步定时器回调
  await someAsyncCall();

  log('request ending');
  ctx.body = 'Hello World';
});

app.listen(3000);

async function someAsyncCall() {
  log('someAsyncCall start');

  return new Promise(resolve => setTimeout(() => {
    resolve();
    log('someAsyncCall end');
  }, 2000));
}

// 模拟客户端请求
(async () => {
  const arr = [];
  for (let i = 0; i < 3; i++) {
    arr.push(axios.get('http://localhost:3000'));
  }
  await Promise.allSettled(arr);
})();

// request start i43l
// someAsyncCall start i43l
// request start e2qy
// someAsyncCall start e2qy
// someAsyncCall end i43l
// request ending i43l
// someAsyncCall end e2qy
// request ending e2qy
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58

# AsyncLocalStorage 实现原理

# AsyncLocalStorage 类

const storageList = [];
const storageHook = createHook({
  // 注册一个异步事件初始化的 hook 
  init(asyncId, type, triggerAsyncId, resource) {
    // 当前的执行环境
    const currentResource = executionAsyncResource();
    for (let i = 0; i < storageList.length; ++i) { // 将当前执行环境的 store 传递给新初始化的异步事件
      storageList[i]._propagate(resource, currentResource, type);
    }
  },
});

function createHook(fns) {
  return new AsyncHook(fns);
}

class AsyncLocalStorage {
  constructor() {
    this.kResourceStore = Symbol('kResourceStore');
    this.enabled = false;
  }
  
  // 启动逻辑
  _enable() {
    if (!this.enabled) {
      this.enabled = true;
      ArrayPrototypePush(storageList, this); 
      storageHook.enable(); // 通过 async_hooks 注册 hook 事件
    }
  }

  // AsyncLocalStorage 核心逻辑
  run(store, callback, ...args) {
     // 判断传入的 store 是否和当前运行环境的 store 一致,避免重复执行
    if (ObjectIs(store, this.getStore())) {
      return ReflectApply(callback, null, args);
    }

    // 启动当前示例
    this._enable();

    // 获取当前正在执行的异步资源
    const resource = executionAsyncResource();
    const oldStore = resource[this.kResourceStore]; // 获取旧的资源的 store

    resource[this.kResourceStore] = store; // 赋值新 store 

    try {
      // 携带新 store 执行回调函数
      return ReflectApply(callback, null, args);
    } finally {
      resource[this.kResourceStore] = oldStore; // 无论失败与否都将旧 store 赋值回去
    }
  }
}

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56

# run()

AsyncLocalStorage 的核心方法为 run(store, callback) 。

  • 其接收 store 和 callback 参数,store 是上下文需要共享的变量,callback 则为后续需要执行的业务代码。对应使用方式:
import { AsyncLocalStorage } from "async_hooks";

const asyncLocalStorage = new AsyncLocalStorage();

// store
let traceId = 1;

// some async function
let asyncFunction = async () => {
  console.log(asyncLocalStorage.getStore()); // 1
};

// run
asyncLocalStorage.run(traceId++, asyncFunction);
1
2
3
4
5
6
7
8
9
10
11
12
13
14
  • run() 校验了 store 是否与当前环境的 store 一致。避免重复更新 store 。

  • 若是首次启动,会通过 createHook() 构造一个 asyncHooks 对象,并且初始化 init()事件,用于监听后续异步任务的初始化操作。

  • 记录当前环境的 store 并将新的 store 绑定到对应的异步事件上,后续执行无论成功与否都需要重新赋回旧变量。类似下面示例的感觉:

import { AsyncLocalStorage } from "async_hooks";

const asyncLocalStorage = new AsyncLocalStorage();

// store
let traceId = 1;

// some async function
let asyncFunction = async () => {
  console.log(asyncLocalStorage.getStore());
  if (traceId <= 3) asyncLocalStorage.run(traceId++, asyncFunction);
  console.log(asyncLocalStorage.getStore());
};

// run
asyncLocalStorage.run(traceId++, asyncFunction);
// 1
// 2
// 3
// 3
// 2
// 1
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22

由核心实现可以看出,AsyncLocalStorage 主要功能是创建了一个独立的上文环境,并且维护 store 和当前执行环境的关系。而对异步事件的跟踪,主要是依赖于 async_hooks 实现的。

# async_hooks 类

async_hooks 的核心实现基于底层 API 这里不深入探讨,仅对其功能做了解。

async_hooks 异步钩子,顾名思义其提供了一套监听异步资源动作的方法。具体实现如下:

class AsyncHook {
  constructor({ init, before, after, destroy, promiseResolve }) {
    // 校验参数是否为 func
    if (init !== undefined && typeof init !== 'function')
      throw new ERR_ASYNC_CALLBACK('hook.init');
    if (before !== undefined && typeof before !== 'function')
      throw new ERR_ASYNC_CALLBACK('hook.before');
    if (after !== undefined && typeof after !== 'function')
      throw new ERR_ASYNC_CALLBACK('hook.after');
    if (destroy !== undefined && typeof destroy !== 'function')
      throw new ERR_ASYNC_CALLBACK('hook.destroy');
    if (promiseResolve !== undefined && typeof promiseResolve !== 'function')
      throw new ERR_ASYNC_CALLBACK('hook.promiseResolve');
    
    // 初始化赋值
    this[init_symbol] = init;
    this[before_symbol] = before;
    this[after_symbol] = after;
    this[destroy_symbol] = destroy;
    this[promise_resolve_symbol] = promiseResolve;
  }

  enable() {
    // 获取当前的 hooks 数组和对应的计数器(如多少个 hook 含有 init/before 等)
    const { 0: hooks_array, 1: hook_fields } = getHookArrays();

    // 如果 hooks 已经启用, 就不重复添加
    if (ArrayPrototypeIncludes(hooks_array, this))
      return this;

    const prev_kTotals = hook_fields[kTotals];
    
    // 计算当前的 hooks 总数。 通过将 func 转 bool 值进行数值累加。
    hook_fields[kTotals] = hook_fields[kInit] += +!!this[init_symbol];
    hook_fields[kTotals] += hook_fields[kBefore] += +!!this[before_symbol];
    hook_fields[kTotals] += hook_fields[kAfter] += +!!this[after_symbol];
    hook_fields[kTotals] += hook_fields[kDestroy] += +!!this[destroy_symbol];
    hook_fields[kTotals] +=
        hook_fields[kPromiseResolve] += +!!this[promise_resolve_symbol];
    
    // 把这个 hook 加入 hooks 数组
    ArrayPrototypePush(hooks_array, this);

    // 如果是初次调用, 则启动 hooks
    if (prev_kTotals === 0 && hook_fields[kTotals] > 0) {
      enableHooks();
    }

    // 根据是否含有 promiseResolve 来更新 Promise hook 状态
    updatePromiseHookMode();

    return this;
  }

  disable() {
    const { 0: hooks_array, 1: hook_fields } = getHookArrays();
    
    // 找到当前 hook 在数组中的索引
    const index = ArrayPrototypeIndexOf(hooks_array, this);
    if (index === -1)
      return this; // 不存在则直接返回

    // 计算当前 hooks 总数
    const prev_kTotals = hook_fields[kTotals];

    hook_fields[kTotals] = hook_fields[kInit] -= +!!this[init_symbol];
    hook_fields[kTotals] += hook_fields[kBefore] -= +!!this[before_symbol];
    hook_fields[kTotals] += hook_fields[kAfter] -= +!!this[after_symbol];
    hook_fields[kTotals] += hook_fields[kDestroy] -= +!!this[destroy_symbol];
    hook_fields[kTotals] +=
        hook_fields[kPromiseResolve] -= +!!this[promise_resolve_symbol];
    
    // 移除当前 hook
    ArrayPrototypeSplice(hooks_array, index, 1);

    // 如果 hook 被移除完毕, 则关闭全局 async_hooks
    if (prev_kTotals > 0 && hook_fields[kTotals] === 0) {
      disableHooks();
    }

    return this;
  }
}

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84

async_hooks 类提供了 enable() 和 disble() 两个方法,这俩方法的主要功能在于是否监听异步资源的 hook 事件。例如下面的示例:

import async_hooks from "async_hooks";
import fs from "fs";

// 创建异步钩子回调函数
const hook = async_hooks.createHook({
  init(asyncId, type, triggerAsyncId, resource) {
    fs.writeSync(
      1,
      `init: asyncId=${asyncId}, type=${type}, triggerAsyncId=${triggerAsyncId}\n`
    );
  },
  before(asyncId) {
    fs.writeSync(1, `before: asyncId=${asyncId}\n`);
  },
  after(asyncId) {
    fs.writeSync(1, `after: asyncId=${asyncId}\n`);
  },
  destroy(asyncId) {
    fs.writeSync(1, `destroy: asyncId=${asyncId}\n`);
  },
  promiseResolve(asyncId) {
    fs.writeSync(1, `promiseResolve: asyncId=${asyncId}\n`);
  },
});

hook.enable();

// 自定义异步事件
Promise.resolve().then(() => {
  fs.writeSync(1, "custom log promise.then()\n");
});

// 延时 100ms 后禁用钩子(卸载监听)
setTimeout(() => {
  hook.disable();
  fs.writeSync(1, "AsyncHook disable \n");

  // 之后的异步操作将不会触发钩子回调
  setTimeout(() => {
    fs.writeSync(1, "new setTimeout\n");
  }, 50);
}, 100);
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42

这里着重介绍 async_hooks 的支持的几个事件。

// `init()` 在异步资源构造时被调用(但可能还未完成构造)
// 注意:此时传入的 resource 对象的字段可能尚未初始化完成
function init(asyncId, type, triggerAsyncId, resource) {
  // asyncId: 当前新建资源的 ID
  // type: 异步资源类型,例如 Timeout、PROMISE、TCPWRAP 等
  // triggerAsyncId: 触发这个异步资源的父资源 ID
  // resource: 底层资源对象
}

// `before()` 在异步资源的回调即将执行前被调用
// 对于 handle 类资源(如 TCPWrap),可能调用多次;对于 request 类型只会调用一次
function before(asyncId) {
  // asyncId: 即将执行回调的异步资源 ID
}

// `after()` 在异步资源的回调执行完之后调用
function after(asyncId) {
  // asyncId: 刚刚执行完回调的异步资源 ID
}

// `destroy()` 在异步资源生命周期结束(被销毁)时调用
function destroy(asyncId) {
  // asyncId: 即将销毁的异步资源 ID
}

// `promiseResolve()` 仅对 Promise 类型资源有效
// 当 Promise 被 resolve 或 reject 时调用
function promiseResolve(asyncId) {
  // asyncId: 被解决的 Promise 的异步资源 ID
}
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30

# 兼容性问题❗

  1. async_hooks 装载于 Nodejs v8.1.0 版本,至今仍为 实验性 阶段,且官网推荐优先使用 AsyncLocalStorage 异步上下文追踪。

  2. AsyncLocalStorage 装载于 Nodejs v12.17.0 版本,但上线以后存在性能和稳定性问题,后续因 v8 工程师提供更深层次的 API 后于 Nodejs v16.4.0 版本稳定,所以推荐在 v16.4.0 后续使用。

  3. asyncLocalStorage.enterWith(store) 截止于当前稳定版本 Nodejs v24.5.0 该 API 仍为 实验性 阶段。

  4. Bun 称近 100% 兼容 Nodejs API 但在 async_hooks 方面并没能使用 v8 相关的 API ,所以其强烈推荐不要使用它。


# 相关文档

  • Asynchronous context tracking # (opens new window)

  • Node 中的 AsyncLocalStorage 的前世今生和未来什么是 AsyncLocalStorage ?一般什 - 掘金 (opens new window)

  • github.com (opens new window)

  • Node.js compatibility – Runtime | Bun Docs (opens new window)

编辑 (opens new window)
上次更新: 2025/08/07, 03:14:04
package.json 中波浪号~ 异或号^ 是什么意思?
Wire 依赖注入

← package.json 中波浪号~ 异或号^ 是什么意思? Wire 依赖注入→

最近更新
01
docker基础概念
02-26
02
js 获取变量准确类型
02-19
03
Mysql SQL 优化思路
02-18
更多文章>
Theme by Vdoing | Copyright © 2023-2025 Dreamer | MIT License
粤ICP备2025379918号
  • 跟随系统
  • 浅色模式
  • 深色模式
  • 阅读模式