Node 绑定全局 TraceID

问题描述

因为Node.js的单线程模型的限制，咱们没法设置全局 traceid 来聚合请求，即实现输出日志与请求的绑定。若是不实现日志和请求的绑定，咱们难以判断日志输出与对应用户请求的对应关系，这对线上问题排查带来了困难。

例如，在用户访问 retrieveOne API 时，其会调用 retrieveOneSub 函数，若是咱们想在 retrieveOneSub 函数中输出当前请求对应的学生信息，是繁琐的。在 course-se 现有实现下，咱们针对此问题的解决方法是：

• 方案1：在调用 retrieveOneSub 函数的父函数，即 retrieveOne 内，对 paramData 进行解构，输出学生相关信息，但该方案没法细化日志输出粒度。
• 方案2：修改 retrieveOneSub 函数签名，接收 paramData 为其参数，该方案能确保日志输出粒度，但在调用链很深的状况下，须要给各函数修改函数签名，使其接收 paramData ，颇具工做量，并不太可行。

/** * 返回获取一份提交的函数 * @param {ParamData} paramData * @param {Context} ctx * @param {string} id */
export async function retrieveOne(paramData, ctx, id) {
  const { subModel } = paramData.ce;
  const sub_asgn_id = Number(id);

  // 经过 paramData.user 获取 user 相关信息，如 user_id ，
  // 但没法细化日志输出粒度，除非修改 retrieveOneSub 的签名，
  // 添加 paramData 为其参数。
  const { user_id } = paramData.user;
  console.log(`${user_id} is trying to retreive one submission.`);
  // 调用了 retrieveOneSub 函数。
  const sub = await retrieveOneSub(sub_asgn_id, subModel);
  const submission = sub;
  assign(sub, { sub_asgn_id });
  assign(paramData, { submission, sub });
  return sub;
}

/** * 从数据库获取一份提交 * @param {number} sub_asgn_id * @param {SubModel} model */
async function retrieveOneSub(sub_asgn_id, model) {
  const [sub] = await model.findById(sub_asgn_id);
  if (!sub) {
    throw new ME.SoftError(ME.NOT_FOUND, '找不到该提交');
  }
  return sub;
}
复制代码

Async Hooks

其实，针对以上的问题，咱们还能够从 Node 的 Async Hooks 实验性 API 方面入手。在 Node.js v8.x 后，官方提供了可用于监听异步行为的 Async Hooks（异步钩子）API 的支持。

Async Scope

Async Hooks 对每个（同步或异步）函数提供了一个 Async Scope ，咱们可调用 executionAsyncId 方法获取当前函数的 Async ID ，调用 triggerAsyncId 获取当前函数调用者的 Async ID。

const asyncHooks = require("async_hooks");
const { executionAsyncId, triggerAsyncId } = asyncHooks;

console.log(`top level: ${executionAsyncId()} ${triggerAsyncId()}`);

const f = () => {
  console.log(`f: ${executionAsyncId()} ${triggerAsyncId()}`);
};

f();

const g = () => {
  console.log(`setTimeout: ${executionAsyncId()} ${triggerAsyncId()}`);
  setTimeout(() => {
    console.log(`inner setTimeout: ${executionAsyncId()} ${triggerAsyncId()}`);
  }, 0);
};

setTimeout(g, 0);
setTimeout(g, 0);
复制代码

在上述代码中，咱们使用 setTimeout 模拟一个异步调用过程，且在该异步过程当中咱们调用了 handler 同步函数，咱们在每一个函数内都输出其对应的 Async ID 和 Trigger Async ID 。执行上述代码后，其运行结果以下。

top level: 1 0
f: 1 0
setTimeout: 7 1       
setTimeout: 9 1       
inner setTimeout: 11 7
inner setTimeout: 13 9
复制代码

经过上述日志输出，咱们得出如下信息：

• 调用同步函数，不会改变其 Async ID ，如函数 f 内的 Async ID 和其调用者的 Async ID 相同。
• 同一个函数，被不一样时刻进行异步调用，会分配至不一样的 Async ID ，如上述代码中的 g 函数。

追踪异步资源

正如咱们前面所说的，Async Hooks 可用于追踪异步资源。为了实现此目的，咱们须要了解 Async Hooks 的相关 API ，具体说明参照如下代码中的注释。

const asyncHooks = require("async_hooks");

// 建立一个 AsyncHooks 实例。
const hooks = asyncHooks.createHook({
  // 对象构造时会触发 init 事件。
  init: function(asyncId, type, triggerId, resource) {},
  // 在执行回调前会触发 before 事件。
  before: function(asyncId) {},
  // 在执行回调后会触发 after 事件。
  after: function(asyncId) {},
  // 在销毁对象后会触发 destroy 事件。
  destroy: function(asyncId) {}
});

// 容许该实例中对异步函数启用 hooks 。
hooks.enable();

// 关闭对异步资源的追踪。
hooks.disable();
复制代码

咱们在调用 createHook 时，可注入 init 、before、after 和 destroy 函数，用于追踪异步资源的不一样生命周期。

全新解决方案

基于 Async Hooks API ，咱们便可设计如下解决方案，实现日志与请求记录的绑定，即 Trace ID 的全局绑定。

const asyncHooks = require("async_hooks");
const { executionAsyncId } = asyncHooks;

// 保存异步调用的上下文。
const contexts = {};

const hooks = asyncHooks.createHook({
  // 对象构造时会触发 init 事件。
  init: function(asyncId, type, triggerId, resource) {
    // triggerId 即为当前函数的调用者的 asyncId 。
    if (contexts[triggerId]) {
      // 设置当前函数的异步上下文与调用者的异步上下文一致。
      contexts[asyncId] = contexts[triggerId];
    }
  },
  // 在销毁对象后会触发 destroy 事件。
  destroy: function(asyncId) {
    if (!contexts[asyncId]) return;
    // 销毁当前异步上下文。
    delete contexts[asyncId];
  }
});

// 关键！容许该实例中对异步函数启用 hooks 。
hooks.enable();

// 模拟业务处理函数。
function handler(params) {
  // 设置 context ，可在中间件中完成此操做（如 Logger Middleware）。
  contexts[executionAsyncId()] = params;
  
  // 如下是业务逻辑。
  console.log(`handler ${JSON.stringify(params)}`);
  f();
}

function f() {
  setTimeout(() => {
    // 输出所属异步过程的 params 。
    console.log(`setTimeout ${JSON.stringify(contexts[executionAsyncId()])}`);
  });
}

// 模拟两个异步过程（两个请求）。
setTimeout(handler, 0, { id: 0 });
setTimeout(handler, 0, { id: 1 });
复制代码

在上述代码中，咱们先声明了 contexts 用于存储每一个异步过程当中的上下文数据（如 Trace ID），随后咱们建立了一个 Async Hooks 实例。咱们在异步资源初始化时，设置当前 Async ID 对应的上下文数据，使得其数据为调用者的上下文数据；咱们在异步资源被销毁时，删除其对应的上下文数据。

经过这种方式，咱们只需在一开始设置上下文数据，便可在其引起的各个过程（同步和异步过程）中，得到上下文数据，从而解决了问题。

执行上述代码，其运行结果以下。根据输出日志可知，咱们的解决方案是可行的。

handler {"id":0}
handler {"id":1}
setTimeout {"id":0}
setTimeout {"id":1}
复制代码

不过须要注意的是，Async Hooks 是实验性 API ，存在必定的性能损耗，但 Node 官方正努力将其变得生产可用。所以，在机器资源足够的状况下，使用本解决方案，牺牲部分性能，换取开发体验。