async_hooks: AsyncResource.runInAsyncScope causes Node process to crash

[alexandervain]

• Version: v12.16.0
• Platform: Darwin xxxxx 18.7.0 Darwin Kernel Version 18.7.0: Sun Dec 1 18:59:03 PST 2019; root:xnu-4903.278.19~1/RELEASE_X86_64 x86_64
• Subsystem: async_hooks

What steps will reproduce the bug?

There are 2 flavours to the crash. Run the following simplified code to reproduce.

Version 1:

  const {AsyncResource} = require('async_hooks');
  new AsyncResource('Foo').runInAsyncScope(() => {throw new Error()});

Version 2:

  const {AsyncResource} = require('async_hooks');
  const run = () => new AsyncResource('Foo').runInAsyncScope(() => {throw new Error()});
  Promise.resolve().then(run).catch(console.log)

How often does it reproduce? Is there a required condition?

Reproduces constantly

What is the expected behavior?

For Node not to crash

What do you see instead?

Node process crashes with the following output.

Version 1:

Welcome to Node.js v12.16.0.
Type ".help" for more information.
> const {AsyncResource} = require('async_hooks');
undefined
> new AsyncResource('Foo').runInAsyncScope(() => {throw new Error()});
Uncaught Error
    at repl:1:55
    at AsyncResource.runInAsyncScope (async_hooks.js:176:7)
> Error: async hook stack has become corrupted (actual: 28, expected: 5)
 1: 0x10000b7f1 node::AsyncHooks::pop_async_id(double) [/Users/user/.nvm/versions/node/v12.16.0/bin/node]
 2: 0x10000189a node::InternalCallbackScope::Close() [/Users/user/.nvm/versions/node/v12.16.0/bin/node]
 3: 0x100001b2f node::InternalMakeCallback(node::Environment*, v8::Local<v8::Object>, v8::Local<v8::Function>, int, v8::Local<v8::Value>*, node::async_context) [/Users/user/.nvm/versions/node/v12.16.0/bin/node]
 4: 0x10001475c node::AsyncWrap::MakeCallback(v8::Local<v8::Function>, int, v8::Local<v8::Value>*) [/Users/user/.nvm/versions/node/v12.16.0/bin/node]
 5: 0x1001085f2 node::StreamBase::CallJSOnreadMethod(long, v8::Local<v8::ArrayBuffer>, unsigned long, node::StreamBase::StreamBaseJSChecks) [/Users/user/.nvm/versions/node/v12.16.0/bin/node]
 6: 0x100109f31 node::EmitToJSStreamListener::OnStreamRead(long, uv_buf_t const&) [/Users/user/.nvm/versions/node/v12.16.0/bin/node]
 7: 0x10010e263 node::LibuvStreamWrap::OnUvRead(long, uv_buf_t const*) [/Users/user/.nvm/versions/node/v12.16.0/bin/node]
 8: 0x1008c3d8a uv__stream_io [/Users/user/.nvm/versions/node/v12.16.0/bin/node]
 9: 0x1008cba7f uv__io_poll [/Users/user/.nvm/versions/node/v12.16.0/bin/node]
10: 0x1008bb036 uv_run [/Users/user/.nvm/versions/node/v12.16.0/bin/node]
11: 0x1000b6836 node::NodeMainInstance::Run() [/Users/user/.nvm/versions/node/v12.16.0/bin/node]
12: 0x10005dd94 node::Start(int, char**) [/Users/user/.nvm/versions/node/v12.16.0/bin/node]
13: 0x7fff67e8f3d5 start [/usr/lib/system/libdyld.dylib]

Version 2:

Welcome to Node.js v12.16.0.
Type ".help" for more information.
>   const {AsyncResource} = require('async_hooks');
undefined
>   const run = () => new AsyncResource('Foo').runInAsyncScope(() => {throw new Error()});
undefined
>   Promise.resolve().then(run).catch(console.log)
Promise { <pending> }
> Error
    at repl:1:75
    at AsyncResource.runInAsyncScope (async_hooks.js:176:7)
    at run (repl:1:46)
    at processTicksAndRejections (internal/process/task_queues.js:97:5)
node[78213]: ../src/api/callback.cc:117:void node::InternalCallbackScope::Close(): Assertion `(env_->execution_async_id()) == (0)' failed.
 1: 0x100080dde node::Abort() [/Users/user/.nvm/versions/node/v12.16.0/bin/node]
 2: 0x100080b86 node::AppendExceptionLine(node::Environment*, v8::Local<v8::Value>, v8::Local<v8::Message>, node::ErrorHandlingMode) [/Users/user/.nvm/versions/node/v12.16.0/bin/node]
 3: 0x10000194c node::InternalCallbackScope::Close() [/Users/user/.nvm/versions/node/v12.16.0/bin/node]
 4: 0x100001b2f node::InternalMakeCallback(node::Environment*, v8::Local<v8::Object>, v8::Local<v8::Function>, int, v8::Local<v8::Value>*, node::async_context) [/Users/user/.nvm/versions/node/v12.16.0/bin/node]
 5: 0x100001d0f node::MakeCallback(v8::Isolate*, v8::Local<v8::Object>, v8::Local<v8::Function>, int, v8::Local<v8::Value>*, node::async_context) [/Users/user/.nvm/versions/node/v12.16.0/bin/node]
 6: 0x10003a362 node::Environment::CheckImmediate(uv_check_s*) [/Users/user/.nvm/versions/node/v12.16.0/bin/node]
 7: 0x1008c0d46 uv__run_check [/Users/user/.nvm/versions/node/v12.16.0/bin/node]
 8: 0x1008bb03e uv_run [/Users/user/.nvm/versions/node/v12.16.0/bin/node]
 9: 0x1000b6836 node::NodeMainInstance::Run() [/Users/user/.nvm/versions/node/v12.16.0/bin/node]
10: 0x10005dd94 node::Start(int, char**) [/Users/user/.nvm/versions/node/v12.16.0/bin/node]
11: 0x7fff67e8f3d5 start [/usr/lib/system/libdyld.dylib]
[1]    78213 abort      node

Additional information

Same code works fine with Node 12.15.0.

[MylesBorins]

I've reverted this change on v12.x

e07237c

We can close this once the fix in #31783 lands on master