Skip to content

Infinite loop in timers in Node 11 #23935

@jcubic

Description

@jcubic
  • Version: v11.0.0
  • Platform: Linux jcubic 4.18.13-100.fc27.x86_64 deps: update openssl to 1.0.1j #1 SMP Wed Oct 10 18:34:01 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux
  • Subsystem: timers

I have jest test that was working in Node 10 and it's broken in Node 11, I've reported the issue to jest framework but this may be issue with Node 11, I don't see much breaking changes to setTimeout in Changelog. Only the one that execute tick after each timer.

the problem is probably with setTimeout function, after code run successfully (it sometimes don't give output) when I run in debug mode

node --inspect-brk ./node_modules/jest/bin/jest.js --runInBand \
  --coverage --testMatch '**/__tests__/*.spec.js'
``

and when I pause when script stack (in Chrome, when it stuck) it point to timers.js file:

It created infinite loop in those 2 functions:

```js
function processTimers(now) {
  debug('process timer lists %d', now);
  nextExpiry = Infinity;

  let list;
  let ranAtLeastOneList = false;
  while (list = queue.peek()) {
    if (list.expiry > now) {
      nextExpiry = list.expiry;
      return refCount > 0 ? nextExpiry : -nextExpiry;
    }
    if (ranAtLeastOneList)
      runNextTicks();
    else
      ranAtLeastOneList = true;
    listOnTimeout(list, now);
  }
  return 0;
}

function listOnTimeout(list, now) {
  const msecs = list.msecs;

  debug('timeout callback %d', msecs);

  var diff, timer;
  let ranAtLeastOneTimer = false;
  while (timer = L.peek(list)) {
    diff = now - timer._idleStart;

    // Check if this loop iteration is too early for the next timer.
    // This happens if there are more timers scheduled for later in the list.
    if (diff < msecs) {
      list.expiry = timer._idleStart + msecs;
      list.id = timerListId++;
      queue.percolateDown(1);
      debug('%d list wait because diff is %d', msecs, diff);
      return;
    }

    if (ranAtLeastOneTimer)
      runNextTicks();
    else
      ranAtLeastOneTimer = true;

    // The actual logic for when a timeout happens.
    L.remove(timer);

    const asyncId = timer[async_id_symbol];

    if (!timer._onTimeout) {
      if (timer[kRefed])
        refCount--;
      timer[kRefed] = null;

      if (destroyHooksExist() && !timer._destroyed) {
        emitDestroy(asyncId);
        timer._destroyed = true;
      }
      continue;
    }

    emitBefore(asyncId, timer[trigger_async_id_symbol]);

    let start;
    if (timer._repeat)
      start = getLibuvNow();

    try {
      const args = timer._timerArgs;
      if (!args)
        timer._onTimeout();
      else
        Reflect.apply(timer._onTimeout, timer, args);
    } finally {
      if (timer._repeat && timer._idleTimeout !== -1) {
        timer._idleTimeout = timer._repeat;
        if (start === undefined)
          start = getLibuvNow();
        insert(timer, timer[kRefed], start);
      } else {
        if (timer[kRefed])
          refCount--;
        timer[kRefed] = null;

        if (destroyHooksExist() && !timer._destroyed) {
          emitDestroy(timer[async_id_symbol]);
          timer._destroyed = true;
        }
      }
    }

    emitAfter(asyncId);
  }

  // If `L.peek(list)` returned nothing, the list was either empty or we have
  // called all of the timer timeouts.
  // As such, we can remove the list from the object map and the PriorityQueue.
  debug('%d list empty', msecs);

  // The current list may have been removed and recreated since the reference
  // to `list` was created. Make sure they're the same instance of the list
  // before destroying.
  if (list === lists[msecs]) {
    delete lists[msecs];
    queue.shift();
  }
}

The problem is that the script is not ending. it keep processing event that it should finish. And node inspector don't give async stack trace I only see two functions processTimers and listOnTimeout.

I've tried to debug setTimeout function to see why it's freezing I've put this code in jest test:

global.global_timers = {};
(function(setTimeout) {
    var counter = 0;
    global.setTimeout = function(fn, timer) {
        var c = counter++;
        global.global_timers[c] = new Error().stack;
        return setTimeout(function() {
            delete global.global_timers[c];
            fn();
        }, timer);
    };
})(setTimeout);

but when I pause in Inspector setTimeout is original function and there are no global_timers variable.

Metadata

Metadata

Assignees

No one assigned

    Labels

    duplicateIssues and PRs that are duplicates of other issues or PRs.timersIssues and PRs related to the timers subsystem / setImmediate, setInterval, setTimeout.

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions