Fatal Error when using async wrap APIs

[mike-kaufman]

Hi -

The program below causes a crash in node (both mac OS w/ node 5.6 & Win Server 2012 R2 with node 5.9).

'use strict';

var asyncWrap = process.binding('async_wrap');

function setupHooks() {
    asyncWrap.disable();

    asyncWrap.setupHooks(
        function init() {
            asyncWrap.disable();
             console.log('hello from init');
             asyncWrap.enable();
        },
        function before() {
        },
        function after() {
        },
        function destroy() {
        });

    asyncWrap.enable();
}

function doSomethingAsync() {

    // comment out line below to prevent crash
    console.log('setting timeout');

    setTimeout(function t1() {
        console.log('timeout fired');
    }, 1000);
}

// uncomment line below to prevent crash
//doSomethingAsync();
setupHooks();
doSomethingAsync();

The Fatal Error is coming from async-wrap-inl.h, lines 57-58.
The exception seems to be getting set in deps/v8/src/ic/ic.cc, lines 654-656, as the passed-in object is undefined.

The stack of the above call (on windows) is the following:

node.exe!v8::internal::LoadIC::Load(v8::internal::Handlev8::internal::Object object, v8::internal::Handlev8::internal::Name name) Line 680 C++
node.exe!v8::internal::__RT_impl_Runtime_LoadIC_Miss(v8::internal::Arguments args, v8::internal::Isolate * isolate) Line 2389 C++
node.exe!v8::internal::Runtime_LoadIC_Miss(int args_length, v8::internal::Object * * args_object, v8::internal::Isolate * isolate) Line 2371 C++
000001bcc860b61f() Unknown
000002f100000004() Unknown
-- many similar frames omitted--

Any help/suggestions appreciated. It's odd that the crash is prevented by calling doSomethingAsync() at least once before calling setupHooks() and doSomethingAsync() a second time. Also, crash is prevented by removing the first console.log statement in doSomethingAsync().

Thanks,

Mike

[mike-kaufman]

Update: I debugged through this a bit more, and here's what seems to be happening.

1. This console.log statement in above code triggers a NativeModule.load('console') call:

  function doSomethingAsync() {

// comment out line below to prevent crash
console.log('setting timeout');
...

2. NativeModule.load implementation first caches the console module, and then compiles it. (Node.js, lines 905-906)
3. During compilation, console module (line 100) will new up the default Console instance. This triggers a call to new tty.WriteStream(). which calls net.Socket.call(...) (tty.js, line 45). This last call triggers the call to the registered async init callback.
4. The async-init callback also has a dep on console. I believe (but haven't verified) that it is picking up the partially compiled console module, and failing because certain types are undefined.

Net of the above seems to be a cyclic dependency that occurs when loading some module X triggers an async operation and the async-init handler has a dep on that module X.

Are there specific things that can be done to fix this?

Thanks,

Mike

[AndreasMadsen]

• You can use Asyncwrap more node#5756 if you want to see the error message instead of just node::AsyncWrap::AsyncWrap init hook threw.
• Yes the first console.log() will cause other handle objects to be created. But I'm not sure why that would call the init hook when asyncWrap is disabled.
• If it is just a matter of debugging, you can use a sync version of console.log() such as process._rawDebug('message') or fs.writeSync(1, 'message'). Even if asyncWrap is enabled that won't create a recursive loop.

[mike-kaufman]

•Yes the first console.log() will cause other handle objects to be created. But I'm not sure why that would call the init hook when asyncWrap is disabled.

Thanks Andreas. There's effectively a cyclic dependency that occurs when loading a module triggers an AsyncWrap construction (before the module's compilation is completed), the AsyncWrap construction calls the async-wrap init() handler, and the init() handler, having a dep on the (partially compiled) module, attempts to use it. This causes exceptions (probably non-deterministic depending on which parts of the module have been compiled), and code calling the init() handler errors out with a fatal error.

The question I have is what is the right fix in the runtime? E.g., can this situation of using a partially-compiled module be detected and "failed fast" with an appropriate error message? Or, is there a more general work-around?

(I understand that I can use process._rawDebug and this goes away (or a require('console') before my handlers are hooked in), but these don't address the root cause.)

[AndreasMadsen]

/cc @trevnorris

[trevnorris]

To make sure we're on the same page, using the nodejs/node#5756 patch the following script works fine for me:

'use strict';

const async_wrap = process.binding('async_wrap');

async_wrap.setupHooks({
  init: function init() {
    if (console && typeof console.log === 'function')
      console.log('hi');
  }
});
async_wrap.enable();

setTimeout(() => console.log('foo'), 100);

Though excluding the conditional does cause the application to error out because the console module hasn't been loaded yet. Are you suggesting we preemtively load the console module so this doesn't happen?

[mike-kaufman]

Are you suggesting we preemtively load the console module so this doesn't happen?

I wasn't suggesting that, but that may not be a bad idea, given that console is widely used for debugging and can easily trigger this behavior.

That said, the root cause is more general. Namely, anytime the load of a module X triggers an async operation, and the async init() handler, also tries to load module X, then async init() handler will pick up the partially compiled module. I haven't tried it, but you should be able to repro this with a something other than console.

My question here is "what is the right fix"? e.g.,

• is there some way to hoist explicit & implicit loads out of an init handler? Or is that way too complicated?
• Is there some way to detect the attempted usage of partially compiled module and fail fast with an appropriate error message?
• is there some way to run the handlers in a different "context" such that they don't see a partially compiled module?

[joshgav]

closing old AsyncWrap issues, please start a new thread if appropriate