async_hooks: proper id stacking for Promises

[addaleax]

Fixes: #13583

This won’t fix everything, but I think this is something that just qualifies as a right thing to do.

Checklist

• make -j4 test (UNIX), or vcbuild test (Windows) passes
• tests and/or benchmarks are included
• commit message follows commit guidelines

Affected core subsystem(s)

async_hooks

/cc @nodejs/async_hooks

[AndreasMadsen]

why test that the triggerId propagates correctly? Maybe you were thinking of testing async_hooks.triggerId()?

[addaleax]

Nah, this is just because it seemed easy to add an assertion for. Do you think I should drop it / test other things as well?

[AndreasMadsen]

I found the assert hard to read, so either add a comment or remove it. You should definitely check that async_hooks.triggerId() is correct, since that is the second parameter in push_ids.

[AndreasMadsen]

I think this could have bad side-effects in combination with #13509. Consider:

Promise.resolve(1).then(function () {
  // something that implicitly requires `async_hooks` and enables PromiseHooks
  process.nextTick(function () {

  });

  // At this point, PromiseHooks will pop the id stack, but nothing will have been
  // pushed because PromiseHooks was enabled late.
});

[addaleax]

@AndreasMadsen Good point, I’ll take care of that. Give me a minute. :)

[addaleax]

@AndreasMadsen You are right. I’ve rebased this on #13509 (which in turn is rebased on master) … I had to do some clever¹ stuff to get things working, but I think this makes sense and is consistent.

¹ edit to clarify: the bad kind of clever. ;)

[trevnorris]

LGTM. If you wouldn't mind adding more detail to the git commit message about what it is you're doing. And you may need to fix the timing on some of the tests after #13509 lands.

[addaleax]

@trevnorris Okay, updated. The commit message is a bit more descriptive now, and the tests should pass now that #13509 has landed.

CI: https://ci.nodejs.org/job/node-test-commit/10486/

[AndreasMadsen]

Oh, interesting. Is this something we should fix? With for example

if (env->async_hooks()->fields()[AsyncHooks::kTotals])
  return;

[addaleax]

We can’t because we need the pop_ids() call to happen, so we need the PromiseHook working until at least the kAfter occurs.

This shouldn’t be a problem, it’s just emitting events for nobody to witness.

[AndreasMadsen]

Since we are going with the temp fix, I guess this is okay. But I really want to see a better solution. I'm not really convinced there aren't some obscure bug with the right .enable() and .disable() calls.

[trevnorris]

Please don't loose this check.

[addaleax]

@trevnorris I know why you put it there, and I am not a fan of removing it, but do you have a better suggestion?

It’s good the cctest is there, it basically checks the same thing, right?

[trevnorris]

Ah yup. See now why it must to be removed. Nm.

[trevnorris]

@addaleax Thanks for working on this. I'm running a couple tests now and will get back with you as soon as I'm done.

[trevnorris]

@addaleax Your patch gave me an idea. That disable() doesn't need to trigger removing the PromiseHook. Instead we identify where in the stack we should check if PromiseHook should be removed. Here's a patch on top of yours that shows what I mean, and passes all tests:

AsyncWrap remove PromiseHook callback

diff --git a/lib/async_hooks.js b/lib/async_hooks.js
index 53ce038..7deb5ed 100644
--- a/lib/async_hooks.js
+++ b/lib/async_hooks.js
@@ -139,8 +139,8 @@ class AsyncHook {
     hook_fields[kTotals] += hook_fields[kDestroy] -= +!!this[destroy_symbol];
     hooks_array.splice(index, 1);
 
-    if (prev_kTotals > 0 && hook_fields[kTotals] === 0)
-      async_wrap.disablePromiseHook();
+    // Disabling of PromiseHook() will happen automatically at the end of
+    // synchronous execution.
 
     return this;
   }
diff --git a/src/async-wrap.cc b/src/async-wrap.cc
index 327fe36..41eba0f 100644
--- a/src/async-wrap.cc
+++ b/src/async-wrap.cc
@@ -437,15 +437,10 @@ static void EnablePromiseHook(const FunctionCallbackInfo<Value>& args) {
 }
 
 
-static void DisablePromiseHook(const FunctionCallbackInfo<Value>& args) {
-  Environment* env = Environment::GetCurrent(args);
-
-  // Delay the call to `RemovePromiseHook` because we might currently be
-  // between the `before` and `after` calls of a Promise.
-  env->isolate()->EnqueueMicrotask([](void* data) {
-    Environment* env = static_cast<Environment*>(data);
-    env->RemovePromiseHook(PromiseHook, data);
-  }, static_cast<void*>(env));
+void AsyncWrap::CheckAndRemovePromiseHook(Environment* env) {
+  if (env->async_hooks()->fields()[AsyncHooks::kTotals] == 0) {
+    env->RemovePromiseHook(PromiseHook, static_cast<void*>(env));
+  }
 }
 
 
@@ -506,7 +501,6 @@ void AsyncWrap::Initialize(Local<Object> target,
   env->SetMethod(target, "clearIdStack", ClearIdStack);
   env->SetMethod(target, "addIdToDestroyList", QueueDestroyId);
   env->SetMethod(target, "enablePromiseHook", EnablePromiseHook);
-  env->SetMethod(target, "disablePromiseHook", DisablePromiseHook);
 
   v8::PropertyAttribute ReadOnlyDontDelete =
       static_cast<v8::PropertyAttribute>(v8::ReadOnly | v8::DontDelete);
@@ -691,6 +685,8 @@ Local<Value> AsyncWrap::MakeCallback(const Local<Function> cb,
   // Finally... Get to running the user's callback.
   MaybeLocal<Value> ret = cb->Call(env()->context(), object(), argc, argv);
 
+  CheckAndRemovePromiseHook(env());
+
   Local<Value> ret_v;
   if (!ret.ToLocal(&ret_v)) {
     return Local<Value>();
@@ -717,6 +713,8 @@ Local<Value> AsyncWrap::MakeCallback(const Local<Function> cb,
   CHECK_EQ(env()->current_async_id(), 0);
   CHECK_EQ(env()->trigger_id(), 0);
 
+  CheckAndRemovePromiseHook(env());
+
   Local<Object> process = env()->process_object();
 
   if (tick_info->length() == 0) {
diff --git a/src/async-wrap.h b/src/async-wrap.h
index fa37ea1..d657343 100644
--- a/src/async-wrap.h
+++ b/src/async-wrap.h
@@ -111,6 +111,8 @@ class AsyncWrap : public BaseObject {
   static bool EmitBefore(Environment* env, double id);
   static bool EmitAfter(Environment* env, double id);
 
+  static void CheckAndRemovePromiseHook(Environment* env);
+
   inline ProviderType provider_type() const;
 
   inline double get_id() const;
diff --git a/src/env.cc b/src/env.cc
index 0087f71..1f4ed15 100644
--- a/src/env.cc
+++ b/src/env.cc
@@ -204,6 +204,7 @@ bool Environment::RemovePromiseHook(promise_hook_func fn, void* arg) {
 
   if (it == promise_hooks_.end()) return false;
 
+  CHECK_GT(it->enable_count_, 0);
   if (--it->enable_count_ > 0) return true;
 
   promise_hooks_.erase(it);
diff --git a/src/node.cc b/src/node.cc
index bbce102..090bcab 100644
--- a/src/node.cc
+++ b/src/node.cc
@@ -1326,6 +1326,8 @@ MaybeLocal<Value> MakeCallback(Environment* env,
 
     ret = callback->Call(env->context(), recv, argc, argv);
 
+    AsyncWrap::CheckAndRemovePromiseHook(env);
+
     if (ret.IsEmpty()) {
       // NOTE: For backwards compatibility with public API we return Undefined()
       // if the top level call threw.
@@ -1365,7 +1367,11 @@ MaybeLocal<Value> MakeCallback(Environment* env,
     return ret;
   }
 
-  if (env->tick_callback_function()->Call(process, 0, nullptr).IsEmpty()) {
+  auto tc_ret = env->tick_callback_function()->Call(process, 0, nullptr);
+
+  AsyncWrap::CheckAndRemovePromiseHook(env);
+
+  if (tc_ret.IsEmpty()) {
     return Undefined(env->isolate());
   }
 
@@ -3611,6 +3617,8 @@ void LoadEnvironment(Environment* env) {
   // like Node's I/O bindings may want to replace 'f' with their own function.
   Local<Value> arg = env->process_object();
   f->Call(Null(env->isolate()), 1, &arg);
+
+  AsyncWrap::CheckAndRemovePromiseHook(env);
 }
 
 static void PrintHelp() {

[addaleax]

@trevnorris I see, that would probably work. But what’s the advantage? It should have the same effects, right? In that case I’d probably prefer a version that keeps the information flow a bit more localized, instead of spread out over the various async calling facilities…

(Side note, since this is reminding me: What’s speaking against merging the two MakeCallback implementations? It seemed to pass testing last I checked, and the methods are already in that dangerous almost-but-not-quite identical shape…)

[trevnorris]

@addaleax

It should have the same effects, right? In that case I’d probably prefer a version that keeps the information flow a bit more localized, instead of spread out over the various async calling facilities…

It causes a timing discrepancy in one edge case. Since the microtask queue is only drained after the nexttick queue is drained there's a timing issue with 'uncaughtException':

'use strict';

process.on('uncaughtException', () => { });

const s = setImmediate(() => Promise.resolve(42));

const h = require('async_hooks').createHook({
  init(id, type) { process._rawDebug(id, type) },
}).enable();

process.nextTick(() => {
  process.nextTick(() => h.disable());
  throw new Error();
});

I'd expect no PROMISE in the init() call but it shows up. Also, having it added to the microtask queue means it will disable the PromiseHook while interleaving between nextTick calls.

What’s speaking against merging the two MakeCallback implementations?

To verify, you mean node::MakeCallback and node::AsyncWrap::MakeCallback?

[addaleax]

@trevnorris Ah, I see… I dug around that whole code a bit on the weekend, and yes, it’s a terrible tangle of edge cases. :/

Maybe ~AsyncCallbackScope would be a better case to call RemovePromiseHook, though? That should make things a bit simpler (I’d also like to merge that with AsyncHooks::ExecScope, if you don’t think that’s a terrible idea…).

What’s speaking against merging the two MakeCallback implementations?

To verify, you mean node::MakeCallback and node::AsyncWrap::MakeCallback?

Yup, those two. :)

[trevnorris]

@addaleax

Maybe ~AsyncCallbackScope would be a better case to call RemovePromiseHook, though?

Ah yes. Should have seen this before. This wraps all necessary locations.

I’d also like to merge that with AsyncHooks::ExecScope, if you don’t think that’s a terrible idea…

If you can get AsyncCallbackScope to do the same as ExecScope::Dispose() (b/c lifetime of the id isn't the same as the lifetime of the AsyncCallbackScope) then I'd say we go for it.

Yup, those two. :)

Let me look back at why they weren't merged. When I first implemented AsyncWrap I wanted to make a single MakeCallback but there were a couple important reasons why I didn't. Sounds like you already have a patch for this. If you do, mind sharing?

[addaleax]

Sounds like you already have a patch for this. If you do, mind sharing?

Nothing particularly exciting, I’d say:

diff --git a/src/async-wrap.cc b/src/async-wrap.cc
index d7cdc4198c94..6ab8ec227537 100644
--- a/src/async-wrap.cc
+++ b/src/async-wrap.cc
@@ -666,65 +666,10 @@ void AsyncWrap::EmitAsyncInit(Environment* env,
 Local<Value> AsyncWrap::MakeCallback(const Local<Function> cb,
                                      int argc,
                                      Local<Value>* argv) {
-  CHECK(env()->context() == env()->isolate()->GetCurrentContext());
-
-  Environment::AsyncCallbackScope callback_scope(env());
-
-  Environment::AsyncHooks::ExecScope exec_scope(env(),
-                                                get_id(),
-                                                get_trigger_id());
-
-  if (!PreCallbackExecution(this, true)) {
-    return Local<Value>();
-  }
-
-  // Finally... Get to running the user's callback.
-  MaybeLocal<Value> ret = cb->Call(env()->context(), object(), argc, argv);
-
-  Local<Value> ret_v;
-  if (!ret.ToLocal(&ret_v)) {
-    return Local<Value>();
-  }
-
-  if (!PostCallbackExecution(this, true)) {
-    return Local<Value>();
-  }
-
-  exec_scope.Dispose();
-
-  if (callback_scope.in_makecallback()) {
-    return ret_v;
-  }
-
-  Environment::TickInfo* tick_info = env()->tick_info();
-
-  if (tick_info->length() == 0) {
-    env()->isolate()->RunMicrotasks();
-  }
-
-  // Make sure the stack unwound properly. If there are nested MakeCallback's
-  // then it should return early and not reach this code.
-  CHECK_EQ(env()->current_async_id(), 0);
-  CHECK_EQ(env()->trigger_id(), 0);
-
-  Local<Object> process = env()->process_object();
-
-  if (tick_info->length() == 0) {
-    tick_info->set_index(0);
-    return ret_v;
-  }
-
-  MaybeLocal<Value> rcheck =
-      env()->tick_callback_function()->Call(env()->context(),
-                                            process,
-                                            0,
-                                            nullptr);
-
-  // Make sure the stack unwound properly.
-  CHECK_EQ(env()->current_async_id(), 0);
-  CHECK_EQ(env()->trigger_id(), 0);
-
-  return rcheck.IsEmpty() ? Local<Value>() : ret_v;
+  return node::MakeCallback(env()->isolate(),
+                            object(), cb, argc, argv,
+                            get_id(), get_trigger_id())
+      .FromMaybe(Local<Value>());
 }
 
 
diff --git a/src/node.cc b/src/node.cc
index bbce10220fe1..643e1096cac9 100644
--- a/src/node.cc
+++ b/src/node.cc
@@ -1355,8 +1355,8 @@ MaybeLocal<Value> MakeCallback(Environment* env,
 
   // Make sure the stack unwound properly. If there are nested MakeCallback's
   // then it should return early and not reach this code.
-  CHECK_EQ(env->current_async_id(), async_id);
-  CHECK_EQ(env->trigger_id(), trigger_id);
+  /*CHECK_EQ(env->current_async_id(), async_id);
+  CHECK_EQ(env->trigger_id(), trigger_id);*/
 
   Local<Object> process = env->process_object();
 

I don’t quite recall why the last checks were failing.

[addaleax]

Landed in af1a551