如何使用Node.js perf_hooks按正确顺序记录性能日志？

不需要手动计算耗时、也不需要硬编码调整数组位置，直接使用原生PerformanceObserver接口即可实现符合流程执行顺序的输出。

原因说明 #

performance.getEntriesByType()的返回值固定按照startTime字段升序排列，所有以start标记为起点的measure条目，startTime值完全一致，会被归为同一排序分组，最终排列顺序和你创建measure的代码顺序无关，因此总耗时条目会被插到step1条目之后，打乱阅读顺序。
PerformanceObserver是性能API自带的异步监听接口，会严格按照代码中调用performance.measure()的先后顺序推送新生成的性能条目，完全匹配代码执行流程，不需要额外排序就能得到符合直觉的输出顺序。

实现代码 #

const measureList = [];
// 初始化观察者，仅采集measure类型条目
const obs = new PerformanceObserver((entryList) => {
  entryList.getEntries().forEach(entry => measureList.push(entry));
});
obs.observe({ type: 'measure', buffered: false });

performance.mark('start');

setTimeout(() => {
  performance.mark('step1');
  performance.measure('Duration of step 1', 'start', 'step1');

  performance.mark('step2');
  performance.measure('Duration of step 2', 'step1', 'step2');

  performance.mark('step3');
  performance.measure('Duration of step 3', 'step2', 'step3');
  
  // 所有步骤执行完成后，再创建总耗时统计
  performance.mark('end');
  performance.measure('Duration of total', 'start', 'end');

  // 等待所有条目推送完成后输出结果
  setTimeout(() => {
    obs.disconnect();
    measureList.forEach(entry => {
      console.log(`${entry.name}: ${entry.duration} ms`);
    });
  }, 0);
}, 100);

运行后得到的输出顺序和预期完全一致：

Duration of step 1: 111.59999999962747 ms
Duration of step 2: 0.09999999962747097 ms
Duration of step 3: 0 ms
Duration of total: 111.69999999925494 ms

可选轻量方案 #

如果不想使用观察者模式，也可以利用条目原生属性做一次简单排序：拿到getEntriesByType('measure')的结果后，先按startTime升序排列，同startTime的条目按duration升序排列即可。因为同起点的统计条目，覆盖流程越长duration越大，总耗时作为覆盖全流程的条目自然会排在同分组的最后，不需要手动识别总耗时条目做特殊处理。

内容的提问来源于stack exchange，提问作者Carrick