业务上一个基于 Node.js 搭建的 JS 运行环境中,长久以来一直存在着零散的 setTimeout 延迟的反馈。
问题表现
众所周知,timer 从实现原理上讲就是不可能做到时间精度保证的,但当前问题的表现是,在可预见 event loop 空闲的场景下,setTimeout 依然出现了触发时机明显滞后于设置的 delay 的情况。经过多次尝试验证,可以确认当前 setTimeout 延迟的问题表现和 Promise 相关,构造出的最小的问题稳定复现代码片段如下:
setTimeout(() => {
console.info('setTimeout 1', Date.now())
setTimeout(() => {
console.info('setTimeout 2', Date.now())
}, 2000)
Promise.resolve().then(() => {
console.info('promise resolve 1', Date.now())
setTimeout(() => {
console.info('setTimeout 3', Date.now())
}, 0)
})
}, 0)
其中最后一个 setTimeout 会出现延迟问题。
具体来说,上述代码片段预期的输出类似:
setTimeout 1 1684218725316
promise resolve 1 1684218725316
setTimeout 3 1684218725318
setTimeout 2 1684218727316
即 “setTimeout 1”,“promise resolve 1” 和 “setTimeout 3” 应该被立即打印,之后间隔大约 2s 后,“setTimeout 2” 被打印。
而问题输出则类似:
setTimeout 1 1684218993040
promise resolve 1 1684218993040
setTimeout 3 1684218995041
setTimeout 2 1684218995041
即 “setTimeout 1”,“promise resolve 1” 被立即打印,之后间隔大约 2s 后,“setTimeout 3” 和 “setTimeout 2” 被打印( 具体差异在 console 输出的时间间隔 ),setTimeout 3 被延迟执行触发了。
在基于 JS Profiler 和 Systrace 确认了中间间隔的 2s JS 线程确实空闲之后,我只好把目光转回到 Node.js 的 setTimeout 实现上。
这里顺带提下我们业务上对于 Node.js 的改造使用情况作为背景。众所周知,Node.js 一般被作为独立的 JS 运行环境使用,但实际上官方也对 Node.js 作为类库嵌入到其他应用使用有所支持( 典型应用场景如 Electron )。后者和我们的实际应用场景类似,但仍然有所差异,具体来说,我们是在移动端已有的自建多 Context JS Runtime 上,使用 Node.js 对主 Context 进行增强,实现上,由于使用场景的不同,我们对于 Node.js 的初始化流程和官方实现有所差异,但对于 Node.js 的 setTimeout 实现,则没有改动。
Node.js 的 setTimeout 实现
来简单看下 Node.js 的 setTimeout 实现( 基于 v16.x 分支 )。
对 Node.js 稍有了解的同学都知道,Node.js 的 event loop 是基于 libuv 的 event loop 实现的,但实际上 Node.js 的 timer 实现并非简单对 libuv timer 的直接封装,而是使用 JS 自行封装了一整套 timer 的管理逻辑,再使用 libuv timer 的能力来实现定时回调,整个 Node.js timer 的实现只使用到了一个 uv 的 timer handle。
实际上 Node.js 至少在 v11.0.0 版本就已经是这个实现,并且在当前的 v20.0.2 版本上还是这个实现,整体的设计可以参考 lib/internal/timer.js 文件头的注释 “HOW and WHY the timers implementation works the way it does”,在 JS 实现上主要是使用了三个数据结构来做 timers 的管理:
- 将 delay 值相同的 timer 使用双向链表组织起来
- timer 链表以 delay 为 key 存储在一个全局 map 中
- timer 链表同时存储在一个全局小顶堆中,主要基于链表头 timer 的过期时间( expiry )做排序
- 注意到 expiry 和 delay 实际上不是一个概念,比如 0s 和 1s 时各触发一个 delay 为 2s 的 setTimeout,则第一个 expiry 大约在 2s 时,第二个大约在 3s 时
Node.js 这个相对复杂的数据结构设计应该是有其历史原因在的。
更早的时候 JS 的实现只有 key 为 delay,value 为 timer 链表的全局 map,每个 timer 链表最终会持有一个 uv 的 timer handle,timer 的排序实际上是 uv 内部的小顶堆实现的,这里 timer 链表的设计实际上也是为了减少 uv timer handle 的数量;直到 v11.0.0 之前的版本,Node.js 才将 timer 的完整管理逻辑统一放到了 JS 实现,由此 timer handle 的使用数量也进一步减少到了一个。
现有的 timer 设计基本上已经将跨语言边界的调用频次降到了最低( 实际上除了 timer handle 的注册之外,还有 GetNow 一类的操作需要从 JS 调用到 C++ )。顺带一提,v20.0.0 版本上 Node.js 已经用到了 V8 的 fast API Call 进一步优化了 timer 跨语言调用的开销。
基于 Node.js 的 setTimeout 实现排查
了解了 Node.js 的 setTimeout 实现之后,来看看怎么接着定位 setTimeout 延迟的问题。timer 问题的尴尬之处在于,一旦断点停下来观察调用栈,便容易因为时间流逝而错过问题现场,只好老老实实打日志分析了。
setTimeout 函数的实现是构造 JS 的 Timeout 对象之后调用 insert 将 Timeout 对象加入到前述的 JS timer 管理数据结构中,这里可能会触发 uv timer 的注册。JS 调到 C++ 注册 uv timer 回调使用的是 scheduleTimer,而 timer 到期之后 C++ 回调触发的 JS 函数则是 processTimers。
在这几个函数内部都打上日志可以追踪 setTimeout 被调用到真正注册 uv timer 之间的关联。另外,注意到在当前 uv timer 到期之后的处理逻辑中,实际是可能存在有 JS 的 Timeout 对象 expiry 还没到期的情况的,但 processTimers 中却没有再调用 scheduleTimer 重新触发 uv 的 timer 注册,实际上,在 timer 到期之后触发的 C++ 回调函数 RunTimers 中,在调用 JS 的 processTimers 之后,如果 processTimers 的返回值不是 0,则会基于返回值使用 scheduleTimer 的 C++ 实现重新注册 uv timer( 真是个奇怪的设计,实际上在 processTimers 内部实现中直接调用 scheduleTimer 的话,JS 的实现就是完整的流程,代码也更为可读 )。因此,我们在 C++ 的 scheduleTimer 实现上也打上日志,确保不会漏掉 uv timer 的注册。
具体的日志打印情况如下:
结合前面问题代码片段的 console 打印,完整的日志输出类似:
2023-05-18 21:30:05.575 I [lib] insert, msecs: 1, start: 970 <- setTimeout 1 insert
2023-05-18 21:30:05.575 I [lib] insert, nextExpiry: Infinity, expiry: 971
2023-05-18 21:30:05.576 E [src] ScheduleTimer, duration_ms: 1 <- setTimeout 1,触发 ScheduleTimer
2023-05-18 21:30:05.578 I [lib] processTimers, now: 973 <- setTimeout 1,回调 processTimers
2023-05-18 21:30:05.578 I setTimeout 1 1684416605578 <- setTimeout 1 console 打印输出
2023-05-18 21:30:05.579 I [lib] insert, msecs: 2000, start: 974 <- setTimeout 2 insert
2023-05-18 21:30:05.579 I [lib] insert, nextExpiry: Infinity, expiry: 2974
2023-05-18 21:30:05.579 E [src] ScheduleTimer, duration_ms: 2000 <- setTimeout 2,触发 ScheduleTimer
2023-05-18 21:30:05.579 I [lib] processTimers, nextExpiry: 2974 <- setTimeout 1,回调的 processTimers 执行完成,计算得到 nextExpiry 为 2974
2023-05-18 21:30:05.579 I promise resolve 1 1684416605579 <- promise console 打印输出
2023-05-18 21:30:05.579 I [lib] insert, msecs: 1, start: 975 <- setTimeout 3 insert
2023-05-18 21:30:05.579 I [lib] insert, nextExpiry: 2974, expiry: 976
2023-05-18 21:30:05.579 E [src] ScheduleTimer, duration_ms: 1 <- setTimeout 3,触发 ScheduleTimer
2023-05-18 21:30:05.579 E [src] ScheduleTimer, duration_ms: 1999 <- setTimeout 1,回调的 processTimers 返回的 nextExpiry 触发 C++ 调用 ScheduleTimer
2023-05-18 21:30:07.580 I [lib] processTimers, now: 2975 <- setTimeout 2,回调 processTimers
2023-05-18 21:30:07.583 I setTimeout 3 1684416607583 <- setTimeout 3 console 打印输出
2023-05-18 21:30:07.584 I setTimeout 2 1684416607584 <- setTimeout 2 console 打印输出
2023-05-18 21:30:07.584 I [lib] processTimers, nextExpiry: 0
<- 后给出了该行日志打印对应的执行流程。
可以看到,在 setTimeout 1 对应的 processTimers 执行完成返回 C++ 之后,C++ 拿到 processTimers 的返回值触发 ScheduleTimer ( 实际就是 setTimeout 2 对应的 ScheduleTimer )之前,promise 被执行了。此时,promsie 内部的 setTimeout 3 执行,触发了 setTimeout 3 对应的 ScheduleTimer 被执行。由于紧接着的两次 ScheduleTimer 实际使用的是同一个 uv 的 timer handle,会使得后调用的 ScheduleTimer 覆盖掉先调用的 ScheduleTimer,即 setTimeout 3 的 ScheduleTimer 实际没有生效,直到 2s 后 setTimeout 3 对应的 processTimers 被触发,JS 遍历小顶堆时发现 setTimeout 3 已经过期,才会触发 setTimeout 3 的回调。也就表现为了 setTimeout 3 被延迟了 2s 调用。
上述流程的关键问题在于,在第一次 processTimers 返回之后,C++ 触发 ScheduleTimer 之前,意外执行了 promise。从 Node.js 的 timer 设计来讲,在 processTimers 计算出 nextExpiry 返回之后,显然紧接着就应该触发 ScheduleTimer,中间不应该出现 JS 代码执行的情况,也就是说,promise 出现了在预期外的时机被执行的情况。
具体看下 C++ RunTimers 的实现:
可以看到,在 processTimers 执行( 即 cb->Call )之后,紧跟着就是调用了 ScheduleTimer,中间不存在其他显式触发 promise 执行的逻辑。那么,是否可能在 RunTimers 使用的 V8 接口内部会触发 promise 被执行?在 V8 的实现上,promise 是记录在 MicrotaskQueue 中,在 microtask 的执行时机被执行的,来具体看下 V8 microtask 的执行时机。
V8 microtask 的执行时机
从 V8 导出的 MicrotasksPolicy 的定义上可以看到,V8 的 microtask 执行存在三种策略:
- explicit:V8 的宿主需要自行在合适的时机手动调用 Isolate::PerformMicrotaskCheckpoint 来触发 microtask 执行
- scoped:V8 的宿主在调用 V8 相关接口时需要使用 MicrotasksScope 包裹,顶层 MicrotasksScope 析构时会触发 microtask 执行
- auto:V8 内部自动触发 microtask 的执行,触发的时机是 JS 调用栈清空时
- 这里题外说一句,长久以来我一直认为 microtask 的执行时机应该是在 event loop 当次 event 的处理完成之后,在进入阻塞 / 处理新的 event 之前,这个时机实际上和 JS 调用栈清空并不是严格对齐的。但实际从 MDN 文档来看,microtask 在 JS 调用栈清空时执行应该是浏览器的标准行为了,此外,ChatGPT 的意思是,实际 Dart 的 microtask 执行时机也是类似的,即在 Dart 的调用栈清空时。
那具体 microtask 执行策略的选取是怎么决定的呢?
在 V8 的实现上,MicrotasksPolicy 是和 MicrotaskQueue 实例绑定的,默认情况( 即使用 V8 接口创建 Context 时不额外指定 MicrotaskQueue 实例的情况 )下,整个 JS Runtime 共享同一个 MicrotaskQueue,该 MicrotaskQueue 对应的 MicrotasksPolicy 默认是 auto。
这三种 microtask 执行策略,最终都是通过调用 MicrotaskQueue 的 PerformCheckpoint 来触发 microtask 执行的。
对于 auto 的情况,V8 自行使用 CallDepthScope 包裹了内部实现,在顶层 CallDepthScope 析构时触发 PerformCheckpoint,整体的工作原理和 scoped 的情况类似。
PerformCheckpoint,顾名思义,会做 Checkpoint 检查,实际上不一定真正触发 microtask 的执行。具体使用上,我们可以通过 SuppressMicrotaskExecutionScope 来禁止内部的 PerformCheckpoint 触发 microtask 的执行。
基于 V8 microtask 的执行时机排查
显然按文档描述,V8 microtask 执行策略为 auto 的情况比较符合问题表现。
这里需要进一步确认下,我们 microtask 的执行策略是否为 auto?以及当前( 即 processTimers 执行完成时 )是否 JS 调用栈为空?
processTimers 执行完成时 JS 调用栈是否就清空了?显然是的,processTimers 是由 Node.js 的 event loop 在唤醒时由 C++ 触发的,从 JS 调用栈的视角看不存在更为底层的调用了,这一点抓取 JS 的 Profile 也可以看出来。
Node.js 的 microtask 执行策略是否为 auto?其实不是的,Node.js 初始化时指定了 microtask 执行策略为 explicit,在内部实现上通过在各种时机手动调用 runMicrotasks 来驱动 microtask 执行。
但正如前面提到的,我们业务上对于 Node.js 的主要魔改在于,初始化流程和官方实现有所差异🙈,实际上,这里的差异就包括 microtask 执行策略的设置,我们在实现上直接省略了这一步,JS Runtime 最终使用的是 V8 默认的策略 auto。( Node.js 在接口注释上表示别乱改 Node.js 的设置,可能会出事,我们确实也没改,只是直接不调那个接口罢了🐶
原因及修复方案
到这里终于破案了。
对于 microtask 的执行,我们使用了 V8 默认的执行策略 auto,使得在 Node.js timer 的内部实现中,在 JS 和 C++ 的边界上,promise 在 Node.js 预期外被执行了,由此 promise 内部的 setTimeout 调用的 delay 参数没有被正确设置到 event loop 上,最终表现为了 setTimeout 延迟。
修复方案也很明确了,有两个思路:
- 对齐 Node.js 的原本实现,设置 microtask 的执行策略为 explicit,但整体的改动从业务角度来说影响面比较大
- 考虑直接对当前问题逻辑打补丁,避免在其中 promise 被执行,属于是头痛医头,脚痛医脚的处理了。具体也有两个改法:
- 在 Node.js 的 processTimers 实现内部直接调用 scheduleTimer,避免 processTimers 和 scheduleTimer 中间存在可以跑 promise 的 gap
- 对于 Node.js 的 RunTimers 实现,使用 SuppressMicrotaskExecutionScope 来包裹,避免在其中 promise 被执行。注意到这个改法的影响面实际要大得多,因为 processTimers 内部 Node.js 原本就会触发 promise 执行,修改之后至少会使得原本在 timer 间隙执行的 promise 都被延后了
One More Thing:Promise 的执行时机
前面提到在 V8 实现上,promise 是基于 microtask 实现的,这也符合我们对 promise 的一般认知。
为什么要说是在 V8 实现上?因为从 JS 标准的视角来说,是不包含 microtask 这样的概念的。从 Promise/A+ 规范来看,promise 的执行只需要保证在 JS 调用栈清空之后( 保证异步 )即可,具体的执行时机就属于平台实现细节了。
其他的 JS 引擎,会怎么实现 promise 的异步支持呢?以实现简单的 QuickJS 为例,QuickJS 在 JSRuntime 内部使用链表记录了 promise 一类的异步任务,需要宿主手动调用 JS_ExecutePendingJob 来驱动 promise 的执行。