Node.js: setInterval 中的断点

Question

我正在调试一个 node.js（Node 版本 6.2.1）程序，其中包含 setInterval()。代码很简单：

const log = console.log;

let cnt = 0;
const inc = () => {
    const beforeDebug = Date.now();
    log('Before debug time', beforeDebug);

    debugger;

    const afterDebug = Date.now();
    log('After debug time', Date.now());

    log('Time spent in debug', afterDebug - beforeDebug);
    log(`[${cnt++}]`);
};
setInterval(inc, 1000);

```

我观察到的奇怪行为是 setInterval() 回调执行之间的暂停将取决于我在断点处花费的时间。例如，如果我在 'debugger' 行停留 10 秒然后恢复，我只会在 10 秒后看到下一个数字在我恢复后

我用命令行节点调试器和节点检查器检查了这个行为。

[更新]（为代码添加了时间戳） 这是命令行中调试会话的提取行：

Debugger listening on port 5858
connecting to 127.0.0.1:5858 ... ok

< Before debug time 1467952218915
< After debug time 1467952235018
< Time spent in debug 16103

< Before debug time 1467952252123

基本上上一节中回调执行的时间差是17105，几乎正好是<time-in-debug> + <interval-value>

这个问题没有太大的实际影响，但是我很想了解下定时器的机制。为什么它的行为如此奇怪？

Answer 1

~~Node.js 在一个线程中运行您的代码。当您暂停执行时，相应的回调也会延迟到您恢复执行。~~

这是一个不使用调试器的替代示例

var blockUntil = Date.now() + 7000;

function f() {
    console.log('Before: ', Date.now())
    while (Date.now() < blockUntil); // busy loop
    console.log(' After: ', Date.now())
}

setInterval(f, 1000);

而且我可以确认它可以在没有调试器的情况下重现。

Before:  1467966150871
 After:  1467966156847
Before:  1467966163851
 After:  1467966163851
Before:  1467966164856
 After:  1467966164856
Before:  1467966165859
 After:  1467966165859
Before:  1467966166864
 After:  1467966166864

Answer 2

简而言之，用于确定何时触发回调的时间是cached and can get out of sync with a callback's actual insertion time。

这怎么可能？

要理解为什么会发生这种情况，有助于了解节点的计时器是如何实现的（有很好的记录in the source）。在这里，我们需要记住的是：

回调存储在以超时为键的映射中。例如，当你运行 setTimeout(foo, 10) 时，那么 foo 将被添加到所有超时回调的列表中 10.
回调跟踪它们被插入的时间。为了简单起见，我们将其称为 insertionTime（在源代码中实际上是 timer._idleStart）。
当超时开始时，节点会记录当前时间 (now) 并运行按顺序发送超时的回调，直到没有剩余回调或回调的插入时间为 now - insertionTime < timeout. In that last case, node will delay the next wakeup of this timeout 直到 timeout - (now - insertionTime).

在您的情况下，会发生以下情况：

t=0、inc 被插入到带有 insertionTime=0 的回调列表中。
t=1000，超时唤醒，记录now=1000，运行s inc.
t=3000（或者无论你调试了多长时间），inc 完成并获得 reinserted in the callback list（因为你使用的是 setInterval），这次使用 insertionTime=3000.
t=3000，节点不断遍历回调列表，找到新插入的回调。它计算出小于 timeout 的 now - insertionTime = -2000（因为 now 仍然等于 1000！）。因此，它会在 3000 = 1000 - (-2000) 毫秒后安排下一次回调执行。
t=6000，超时再次唤醒，记录now=6000，运行s inc.
...

您可以通过运行将您的程序与 NODE_DEBUG=timer:

结合来了解定时器内部结构

$ NODE_DEBUG=timer node setinterval.js
TIMER 98831: no 1000 list was found in insert, creating a new one
TIMER 98831: timeout callback 1000
TIMER 98831: now: 1067
inc
TIMER 98831: 1000 list wait because diff is -2000
TIMER 98831: timeout callback 1000


TIMER 98831: now: 6072
inc
TIMER 98831: 1000 list wait because diff is -2000
...

据我所知，这看起来像是节点中的错误。我看不出什么时候在上面设置负 diff 才有意义。

我们能做些什么？

您似乎是出于好奇才问这个问题，但如果您需要防止这种额外的延迟，您可以通过确保至少有一个其他回调来解决相同的超时来解决这个问题。这将强制更新 now.

function f() {
  var end = Date.now() + 2000;
  while (Date.now() < end); // 2 second busy loop.
  console.log('f: ' + Date.now());
}
setInterval(f, 1000);

setTimeout(function () {
  setInterval(function () {}, 1000);
}, 10); // Small delay to make sure they don't run in the same wakeup.

如果我们只添加 f，它将每 5 秒结束一次运行ning。但是，如果我们还注册了（空的）第二个回调，f 将每 3 秒正确地运行！

Node.js: setInterval 中的断点

Node.js: breakpoints in setInterval

javascript

debugging

v8

node.js

这怎么可能？

我们能做些什么？