nextTick in Promise callback triggered after setTimeout expiration

[mathbruyen]

• node 0.11.13 ran with harmony flag
• env: Debian Jessie & Ubuntu precise 64 (vagrant box)

When registering a next tick event within a promise callback while a setTimeout is waiting, nextTick callback will wait until timeout expires before triggering.

For example running node --harmony file.js on

Promise.resolve({}).then(function () {
  process.nextTick(console.log.bind(console, 'tick'));
  return 'end';
}).then(console.log.bind(console));
setTimeout(console.log.bind(console, 'timeout'), 2000);

quickly displays end, then waits 2s to display timeout and eventually tick. Tick should come way before timeout expires.

Prepending the example with var Promise = require('es6-promise').Promise; (Promise polyfill) displays tick right after end and then waits 2s to displays timeout.

Using setImmediate instead of nextTick gives the expected behavior, tick right at the beginning.

I discovered it because some streams I created in tests wait until test timeout to start pumping. I am unsure about the relation to setTimeout because when using fs streams data is pumped right away, it seems more related to having an external event somehow restarting the event loop.

I'm a bit out of tools to diagnose deeper the issue, I tried node-inspector but it seem to be at a lower level, if one can point me to some resources I am willing to continue diagnosing.

[vkurchatkin]

This happens only on first tick, because nextTick queue is flushed from js, so this happens before promise callbacks are invoked. Looks like it would be trivial to fix.

[vkurchatkin]

Here is a quick fix:

diff --git a/lib/module.js b/lib/module.js
index 11b9f85..8fe1afe 100644
--- a/lib/module.js
+++ b/lib/module.js
@@ -488,6 +488,7 @@ Module._extensions['.node'] = process.dlopen;
 Module.runMain = function() {
   // Load the main module--the command line argument.
   Module._load(process.argv[1], null, true);
+  process._runMicrotasks();
   // Handle any nextTicks added in the first tick of the program
   process._tickCallback();
 };
diff --git a/src/node.cc b/src/node.cc
index 5d13e8b..4ddfe33 100644
--- a/src/node.cc
+++ b/src/node.cc
@@ -957,6 +957,10 @@ void SetupDomainUse(const FunctionCallbackInfo<Value>& args) {
       FIXED_ONE_BYTE_STRING(args.GetIsolate(), "_setupDomainUse"));
 }

+void RunMicrotasks(const FunctionCallbackInfo<Value>& args) {
+  V8::RunMicrotasks(args.GetIsolate());
+}
+

 void SetupNextTick(const FunctionCallbackInfo<Value>& args) {
   HandleScope handle_scope(args.GetIsolate());
@@ -2780,6 +2784,7 @@ void SetupProcessObject(Environment* env,
   NODE_SET_METHOD(process, "_setupAsyncListener", SetupAsyncListener);
   NODE_SET_METHOD(process, "_setupNextTick", SetupNextTick);
   NODE_SET_METHOD(process, "_setupDomainUse", SetupDomainUse);
+  NODE_SET_METHOD(process, "_runMicrotasks", RunMicrotasks);

   // pre-set _events object for faster emit checks
   process->Set(env->events_string(), Object::New(env->isolate()));

[vkurchatkin]

After giving some thought, I can say that it's more complicated. Consider following case:

function scheduleMicrotask (fn) {
  Promise.resolve({}).then(fn);
}

setTimeout(function () {
  console.log(1);

  process.nextTick(function () {
    console.log(2);

    scheduleMicrotask(function () {
      console.log(3);

      process.nextTick(function () {
        console.log(4);
      })

      setTimeout(function () {
        console.log(5)
      }, 0);

    });

  })

}, 0);

When we resolve a promise inside nextTick callback we end up in the same situation.

[mathbruyen]

so is the root cause that anything scheduled inside promise callback is ignored? Is Node doing something special for nextTick or could it be backed by setImmediate?

[vkurchatkin]

the problem is that normally all user code is executed before next tick queue is processed, but native promise handlers are called after that in some cases. nextTick is quite different than setImmediate and most promise implementations and polyfills use nextTick on node (https://github.com/jakearchibald/es6-promise/blob/master/lib/promise/asap.js#L8), so they have no such problem.

[trevnorris]

On Jun 3, 2014 10:37 AM, "Vladimir Kurchatkin" notifications@github.com
wrote:

the problem is that normally all user code is executed before next tick
queue is processed, but native promise handlers are called after that in
some cases.

If by "native promise handlers" you mean Promise() in master, you're
already hosed. That implementation is borked. Also, it's impossible for
code to run after the nextTickQueue is processed. The only possibility is
that a nextTick callback is added that executes all the promise code. And
if it happens to be the last callback added then it could operate as if it
were running afterwards.

[vkurchatkin]

it's impossible for code to run after the nextTickQueue is processed

@trevnorris well, it's possible with promises.

process.nextTick(function () {
  console.log(1);
});

Promise.resolve().then(function () {
  console.log(2);
});

[trevnorris]

On Jun 3, 2014 11:05 AM, "Vladimir Kurchatkin" notifications@github.com
wrote:

it's impossible for code to run after the nextTickQueue is processed

@trevnorris well, it's possible with promises.

So I assume you're talking about V8 native Promises?

[vkurchatkin]

@trevnorris yep

[trevnorris]

@vkurchatkin Currently the V8 Promises implementation is borked and I wouldn't put any merit in how it's currently implemented. Why they decided to remove the flag for exposure is beyond me.

[vkurchatkin]

@trevnorris what do you mean by "borked"?

[trevnorris]

@vkurchatkin It doesn't follow specification. So anything you write using it today may not work in a future release.

[mathbruyen]

Then maybe it would be better to fully disable it. In my app I assumed a
global Promise object as an indicator to native promises (otherwise it
loads a userland one) and the app breaks with 0.11.13 (waits for the next
call to process the previous one)
On Jun 4, 2014 11:25 PM, "Trevor Norris" notifications@github.com wrote:

@vkurchatkin https://github.com/vkurchatkin It doesn't follow
specification. So anything you write using it today may not work in a
future release.

—
Reply to this email directly or view it on GitHub
#7714 (comment).

[trevnorris]

On Jun 6, 2014 2:53 AM, "Mathieu Bruyen" notifications@github.com wrote:

Then maybe it would be better to fully disable it.

The problem is there is no disabling of Promises in V8 at this point. For
some reason they took it out from behind the harmony flag and made it a
default. Users have the ability to override it, but it'll be there
regardless.

Only other insane option I can see is we remove it from the global scope on
startup.

[mathbruyen]

And is there any status on their plan/progress on fixing it?
On Jun 6, 2014 1:00 PM, "Trevor Norris" notifications@github.com wrote:

On Jun 6, 2014 2:53 AM, "Mathieu Bruyen" notifications@github.com wrote:

Then maybe it would be better to fully disable it.

The problem is there is no disabling of Promises in V8 at this point. For
some reason they took it out from behind the harmony flag and made it a
default. Users have the ability to override it, but it'll be there
regardless.

Only other insane option I can see is we remove it from the global scope on
startup.

—
Reply to this email directly or view it on GitHub
#7714 (comment).

[vkurchatkin]

@mathbruyen https://code.google.com/p/v8/issues/list?can=2&q=promise&colspec=ID+Type+Status+Priority+Owner+Summary+HW+OS+Area+Stars&x=priority&y=owner&cells=tiles

[vkurchatkin]

@mathbruyen some bugs reside in chromium bug tracker for some reason: https://code.google.com/p/chromium/issues/detail?id=372788
https://code.google.com/p/chromium/issues/detail?id=346167

Also relevant: #7549

[vkurchatkin]

anyway, even if promises were 100% compliant with spec, they still would be unusable in node:

var http = require('http');

function getThing (key) {
  return new Promise(function (resolve, reject) {
    process.nextTick(function () {
      resolve(key);
    });
  });
}

http.createServer(function (req, res) {

  getThing('food')
    .then(function (food) {
      return getThing('stuff')
        .then(function (stuff) {
          return food + ' & ' + stuff;
        });
    })
   .then(function (stuff) {
      res.writeHead(200);
      res.end(stuff);
    });

}).listen(3000);

this makes requests hang until some unrelated callback is called.

[othiym23]

This somewhat unsatisfying thread explains Google's rationale for moving Promises and WeakMaps from behing the staging flag. This is part of the reason I wasn't super thrilled about the sudden upgrade to V8 3.25, @trevnorris. There are going to be more issues like this.

[trevnorris]

This is part of the reason I wasn't super thrilled about the sudden
upgrade to V8 3.25, @trevnorris. There are going to be more issues like
this.

TBH this is the least of my worries right now. They've completely screwed
the use of the API that Buffer depends on, and their supposed fix only made
things worse.

Though at the same time it's unreasonable for us to stick to a version of
V8 so far behind latest stable. Either we figure out how to deal with the
V8 team's insane API and internal changes or we discuss another solution
(possibly just as insane like forking V8).

Basically, sticking to 3.24 when 3.27 will probably reach stable before
v0.12 is cut puts us at a disadvantage in terms of being able to back port
any critical/security fixes that may arise.

I'm not sure of the appropriate solution, but remaining so far back doesn't
seem like a plausible one to me.

[othiym23]

Though at the same time it's unreasonable for us to stick to a version of V8 so far behind latest stable.

Why? In the absence of specific reasons to upgrade, there doesn't seem to be a lot of pressure on Node to track V8 releases. Security fixes are comparatively rare, and most of the recent new releases seem to have brought complications (embedding API changes, the ArrayBuffer performance regression, etc) with them, which weakens the argument that we'll end up using an "unsupported" version of V8. I mean, we effectively are already.

[mathbruyen]

My personal opinion would be to upgrade asap otherwise the gap increases and eventually no one wants to do a single upgrade.

On the issue itself is nextTick doing something fundamentally different from setImmediate? Otherwise it could be easier to let V8 handle that logic itself and simply redirect nextTick to setImmediate.

Otherwise, how is node doing for processing nextTick queue at the end of setTimeout callbacks for example? If there is some kind of hook then maybe a similar can be triggered for promises.

Last one I see would be for nextTick to check whether it knows the queue will be processed and otherwise set itself something to process like

function processNextTickQueue() {
  /* ... */
  queueWillBeProcessed = false;
}
function nextTick(fn) {
  if (queueWillBeProcessed) { // set to true inside setTimeout callbacks, let to false otherwise
    setImmediate(processNextTickQueue);
    queueWillBeProcessed = true;
  }
  addToNextTickQueue(fn);
}

[vkurchatkin]

is nextTick doing something fundamentally different from setImmediate

Yes, they are quite different (picture is a bit old, but almost correct):

[mathbruyen]

Is the before/after I/O difference explained on Stack Overflow valid? If that's the case I guess performances for some app would degrade with setImmediate. I insisted on that solution because dropping a ad-hoc solution in favour of reusing a standard would be great to me.

Then according to @vkurchatkin diagram there is a hook which allows for custom stuff to happen after timeouts, is there a chance to have a similar hook for promises? Or do you prefer the other option of having a flag?

[piscisaureus]

@trevnorris What is the issue with the v8 promise implementation. I spoke with a v8 engineer on monday - he wasn't aware of any issues with their promises, and he said he'd look into it if we filed a bug.

[trevnorris]

@piscisaureus First off, the above event loop diagram is completely off. Here's a more appropriate diagram: https://gist.github.com/trevnorris/05531d8339f8e265bd49

@domenic You had better information about what was wrong w/ V8's implementation of Promises. IIRC you had a URL that addressed this.

[domenic]

The only problem with V8's promise implementation is that they don't handle bad arguments correctly (e.g. promise.then(null, function) doesn't work as expected). This sounds more serious.

It's notable that their promise implementation uses a microtask queue, similar to (but presumably distinct from) process.nextTick, which I believe is new.

[dougwilson]

It's notable that their promise implementation uses a microtask queue, similar to (but presumably distinct from) process.nextTick, which I believe is new.

Right. I believe the reason for the "hangs" is because I think the Node.js event loop needs to be aware of the microtask queue.

[vkurchatkin]

@dougwilson not event loop but nextTick implementation. Also the same problem with Object.observe, as it also uses EnqueueMicrotask under the hood:

setTimeout(function () {
  process.nextTick(function () {
    var obj = {};

    Object.observe(obj, function () {
      process.nextTick(function () {
        console.log(1);
      });
    });

    obj.a = 1;
  });

  setTimeout(function () {
    console.log(2);
  }, 0);

}, 0);

[trevnorris]

On Jul 4, 2014 11:02 AM, "Douglas Christopher Wilson" <
notifications@github.com> wrote:

I think the Node.js event loop needs to be aware of the microtask queue.

Can we give a better definition to "being aware"? There is an internal API
for the micro task queue, but how that's supposed to be managed within the
entire scheme of the event loop and next tick queue isn't obvious.

[trevnorris]

On Jul 4, 2014 10:57 AM, "Domenic Denicola" notifications@github.com
wrote:

The only problem with V8's promise implementation is that they don't
handle bad arguments correctly (e.g. promise.then(null, function) doesn't
work as expected). This sounds more serious.

3.27 is now stable. Do you know of they've fixed the issue in that branch?

[dougwilson]

Can we give a better definition to "being aware"? There is an internal API for the micro task queue, but how that's supposed to be managed within the entire scheme of the event loop and next tick queue isn't obvious.

Look at your diagram https://gist.github.com/trevnorris/05531d8339f8e265bd49, I believe isolate->RunMicrotasks(); needs to be called at the end of every one of those boxes, right after the nextTick queue is drained. The nextTick in Node.js is actually what the new "microtask" queue is in JS, I believe (while setImmediate is a "macrotask"). process.nextTick could potentially be renamed to like setMicrotask or some crap.

[dougwilson]

Anyway, I don't know enough about how the internals of Node.js (C++ side) fit together to really make a PR. AFAIK the best way to "fix" this stuff would be to remove the next tick queue, and instead have process.nextTick add microtasks in v8, then swap all the calls to drain the next tick queue with calls to drain the microtask queue and everything should work right.

[domenic]

3.27 is now stable. Do you know of they've fixed the issue in that branch?

It looks like it was fixed in 3.26.28, so yes.

I think the Node.js event loop needs to be aware of the microtask queue.

Can we give a better definition to "being aware"? There is an internal API for the micro task queue, but how that's supposed to be managed within the entire scheme of the event loop and next tick queue isn't obvious.

/cc @rossberg-chromium @rafaelw who may be able to help clarify what the intention is for how embedders use the microtask queue. However...

AFAIK the best way to "fix" this stuff would be to remove the next tick queue, and instead have process.nextTick add microtasks in v8, then swap all the calls to drain the next tick queue with calls to drain the microtask queue and everything should work right.

I agree this is in theory the best approach: V8's microtask queue is an in-V8 realization of Node's process.nextTick queue.

I imagine it's not entirely practical given how the nextTick queue is hooked (e.g. by domains and the like), in which case having two parallel queues might be the best fix for now.

[Fishrock123]

So, is this gona be fixed for 0.12 or?

[trevnorris]

This operates as I'd expect. The nextTickQueue is only processed when a call is made through the native MakeCallback. Since setTimeout() is the function that causes MakeCallback to fire that's when nextTickQueue is processed.

Take the following:

Promise.resolve({}).then(function () {
  process.nextTick(function() { console.log('tick'); });
  setImmediate(function() { console.log('immediate'); });
  return 'end';
}).then(function() { console.log('then') });

setTimeout(function() {
  console.log('timeout');
}, 2000);

Output:

then
immediate
tick
timeout

The issue is only during the bootstrap phase:

setTimeout(function() {
  Promise.resolve({}).then(function () {
    process.nextTick(function() { console.log('tick'); });
    return 'end';
  }).then(function() { console.log('then') });

  setTimeout(function() {
    console.log('timeout');
  }, 2000);
}, 0);

Output:

then
tick
timeout

That output is expected because the callbacks are run synchronously. So the nextTick() won't fire until after all then() callbacks have fired.

As far as the bootstrapping issue, we can forcefully process the nextTickQueue just before the event loop starts. Here's the patch:

diff --git a/src/node.cc b/src/node.cc
index b49bd4e..8aa03bb 100644
--- a/src/node.cc
+++ b/src/node.cc
@@ -3510,6 +3510,9 @@ int Start(int argc, char** argv) {
     // be removed.
     {
       Context::Scope context_scope(env->context());
+      // Process the nextTickQueue that was added during bootstrap within
+      // Promises.
+      env->tick_callback_function()->Call(env->process_object(), 0, NULL);
       bool more;
       do {
         more = uv_run(env->event_loop(), UV_RUN_ONCE);
diff --git a/src/node.js b/src/node.js
index 4d08ee0..d7a1787 100644
--- a/src/node.js
+++ b/src/node.js
@@ -644,7 +644,7 @@
       if (isSignal(type)) {
         assert(signalWraps.hasOwnProperty(type));

-        if (EventEmitter.listenerCount(this, type) === 0) {
+        if (NativeModule.require('events').listenerCount(this, type) === 0) {
           signalWraps[type].close();
           delete signalWraps[type];
         }

/cc @indutny @tjfontaine What do you guys think about this hack?

Edit: I updated the diff to prevent test-process-kill-pid.js from throwing because EventEmitter isn't available in the updated case.

[vkurchatkin]

@trevnorris please, review my test cases in this thread. bootstrapping is the easiest part of the problem and solution is obvious (kind of). The actual problem is recursive calls (e.g. nextTick -> resolve -> nextTick). This affects both first tick and code called from MakeCallback.

[trevnorris]

Fixed by 30bd7b6.

[domq]

Can 30bd7b6 be merged into master? Thanks!

[trevnorris]

@domq It will be when we merge the v0.12 branch back to master. There's no activity right now on master though because we're preping for the v0.12 release.

[benjamingr]

Hey, I figured it out but if someone feels like leaving clarification and reasoning I would love to have you answer http://stackoverflow.com/q/27647742/1348195

It's not a big deal but it would be appreciated.

[vkurchatkin]

@benjamingr my pleasure!

[rafaelw]

Sorry for the late response. I'm not sure how helpful I can be here. The existing V8 microtask queue should be considered a primordial implementation of what will ultimately be specified in ES6 for Task Queues (I forget the exact language). As of the last Tc-39 there was still some lack of clarity of how that will be structured.

I would naively assume it would be nice for Node to use the ES-specified task structures, but I'm very unfamiliar with the requirements. I would encourage someone who is to participate in the nailing down of ES6 task queues.

[vkurchatkin]

@rafaelw could you possibly review #8325 and #8648 (comment)? Using v8 microtask queue would be nice, but it works slightly different than node's microtask queue and also low-level control is required for some features (domains).