Node绑定全局TraceID的实现方法

作者: 大飞小晶
来源: 51数据库
2021-08-23

问题描述

由于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 官方正努力将其变得生产可用。因此，在机器资源足够的情况下，使用本解决方案，牺牲部分性能，换取开发体验。

以上就是本文的全部内容，希望对大家的学习有所帮助，也希望大家多多支持。