Node.js:setInterval中的断点

Jur*_*riy 3 javascript debugging v8 node.js

我正在调试node.js(Node version 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);
Run Code Online (Sandbox Code Playgroud)

```

我观察到的奇怪行为是setInterval()回调执行之间的暂停将取决于我在断点中花费了多少时间.例如,如果我在"调试器"行停留10秒然后恢复,我将在恢复后的 10秒内看到下一个数字.

我使用命令行节点调试器和节点检查器检查了此行为.

[UPDATE](为代码添加时间戳) 这是命令行中提取的调试会话行:

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
Run Code Online (Sandbox Code Playgroud)

基本上,最后一节中回调执行的时间差是17105,这几乎是完全正确的 <time-in-debug> + <interval-value>

这个问题没有重大的实际影响,但我很想了解下面的计时器机制.为什么它以这种奇怪的方式表现?

mtt*_*tth 5

简短的回答是,用于确定何时触发回调的时间被缓存,并且可能与回调的实际插入时间不同步.

这怎么可能?

要理解为什么会发生这种情况,有助于了解节点的定时器是如何实现的(在源代码中有很好的记录).在这里,我们需要记住的是:

  • 回调存储在由超时键入的映射中.例如,当您运行时setTimeout(foo, 10),foo将添加到具有超时的所有回调的列表中10.
  • 回调会跟踪它们的插入时间.我们将它称为insertionTime保持简单(它实际上timer._idleStart在源中).
  • 当超时启动时,节点记录当前时间(now)并按顺序运行超时的回调,直到没有留下回调或回调的插入时间为止now - insertionTime < timeout.在最后一种情况下,节点将延迟下一次超时唤醒,直到timeout - (now - insertionTime).

在你的情况下,这是发生的事情:

  1. t=0,inc插入回调列表中insertionTime=0.
  2. t=1000,超时唤醒,记录now=1000和运行inc.
  3. t=3000(或者无论你多长时间调试),inc完成并重新插入回调列表(因为你正在使用setInterval),这次是insertionTime=3000.
  4. t=3000,node继续浏览回调列表并找到新插入的回调.它计算now - insertionTime = -2000哪个小于timeout(因为now它仍然等于1000!).因此,它会在3000 = 1000 - (-2000)几毫秒后安排下一次回调执行.
  5. t=6000,超时再次唤醒,记录now=6000和运行inc.
  6. ...

通过运行程序,您可以获得计时器内部的一些可见性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
...
Run Code Online (Sandbox Code Playgroud)

据我所知,这看起来像节点中的一个错误.我不知道什么时候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.
Run Code Online (Sandbox Code Playgroud)

如果我们只添加f,它将最终每5秒运行一次.但是,如果我们还注册了(空)第二个回调,f则会每3秒正确运行一次!