Missing async callstacks on setTimeout

[roblourens]

When debugging Chrome, you can have code like

setTimeout(() => {
  console.log('timeout');
})

and if you pause in the timeout handler and enable async callstacks in Chrome DevTools, you'll see the callstack that lead to calling setTimeout:

But if I debug the same code in Node using the inspector protocol, I don't see async callstacks in this case. But I do see async callstacks for Promises. So it must have something to do with Node's timer implementation. Is there any way that it could surface async callstacks too?

[Fishrock123]

@nodejs/v8-inspector does anyone know what hooks would have to be implemented? I will gladly take the hooks and put them in the correct places in the timers code once I know what they are. XD

[Fishrock123]

ping @nodejs/v8-inspector

[bnoordhuis]

@Fishrock123 I believe it's these: https://github.com/nodejs/node/blob/v7.7.3/deps/v8/include/v8-inspector.h#L230-L236

[Fishrock123]

Hmmm, that requires us to make some sort of ID for each timer scheduling by the looks of it? Maybe we could re-use the async_id once async_hooks lands.

Also, we'll have to add a lot of jumping in-and-out of C++ I think. :/

[bajtos]

It makes me wonder: can we extend async_hooks implementation to automatically call V8Inspector::asyncTask* methods? My hope is that such implementation would fix async call-stacks once for all, from built-in Node.js APIs like setTimeout to 3rd-party code implementing TaskQueue or ConnectionPool pattern (as long as they correctly integrate with async_hook).

Considering that async_hook already has some C++ layer, it may be possible to avoid unnecessary jumping in-and-out of C++ if we can invoke V8Inspector::asyncTask* from that C++ code.

Thoughts?

cc @trevnorris @AndreasMadsen

Is this something to include in nodejs/diagnostics#29?

[AndreasMadsen]

as long as they correctly integrate with async_hook.

This is a very big assumption. If we assume this, then all other long-stack-trace implementation that uses async_hooks will also work.

Considering that async_hook already has some C++ layer, it may be possible to avoid unnecessary jumping in-and-out of C++ if we can invoke V8Inspector::asyncTask* from that C++ code.

The timer, nextTick and http (maybe more) calls the javascript embedder API for emitting the events, so we will need some javascript interface to V8Inspector::asyncTask*. Considering this I doubt that we can make this a zero cost operation, thus there will likely need to be some opt-in option.

Is this something to include in nodejs/diagnostics#29?

Lets just track the async_hooks progress in that issue. This is more related to the V8Inspector integration.

[bajtos]

@AndreasMadsen thank you for chiming in!

as long as they correctly integrate with async_hook.

This is a very big assumption.

Well, I think once async_hooks becomes the standard for observing async operations, and more and more tooling start to rely on that (e.g. continuation-local-storage or APM agents), the ecosystem will have to integrate with async_hook. Similarly as they had to eventually integrate with domains API.

If we assume this, then all other long-stack-trace implementation that uses async_hooks will also work.

Yes! How awesome that will be!

Maybe I am overly enthusiastic, but it seems to me that async_hooks is the only long-term solution to enable robust and reliable support for things like long-stack-traces or continuation-local-storage. The more benefits we can enable by async_hooks, the more likely module authors should be to integrate with this new API.

The timer, nextTick and http (maybe more) calls the javascript embedder API for emitting the events, so we will need some javascript interface to V8Inspector::asyncTask*.

I admit my knowledge of Node.js internals is minimal, therefore I am happy to trust your judgment here.

Considering this I doubt that we can make this a zero cost operation, thus there will likely need to be some opt-in option.

From my point of view as Node.js user, I would prefer the opt-in/opt-out mechanism to be automatic:

• when the inspector is running (e.g. via node --inspect), then asyncTask* methods should be invoked
• when the inspector is not running (e.g. in production), then asycnTask* methods can be bypassed

BTW, a mechanism to detect whether the Node.js app is being debugged/inspected would be useful even outside of Node.js core. See e.g. petkaantonov/bluebird#1364, where we are discussing how to enable async stack traces when debugging bluebird in the inspector. It already works in Chrome DevTools, where Bluebird detects the inspector and switches to a different TaskQueue implementation (see petkaantonov/bluebird@d37d0ff).

[AndreasMadsen]

From my point of view as Node.js user, I would prefer the opt-in/opt-out mechanism to be automatic ... (e.g. via node --inspect).

This makes sense to me.

Maybe I am overly enthusiastic, but it seems to me that async_hooks is the only long-term solution to enable robust and reliable support for things like long-stack-traces or continuation-local-storage.

The problem is that every module that does something special to the async stack (e.g. native binding, or ConnectionPool) need to integrate with async_hooks. If just one is missing we lose the async context. I fear that understanding when special hooks are required will be difficult, also for experienced module authors (it was for me, when I back in 2012 when I wrote the first version of trace). – Maybe we can eventually document often occurring patterns.

I have a lot to say about this, but I will stop myself here. I have been teaching about async context for years at different events, it is just something that requires a very different mental model.

[Fishrock123]

This should be easier now that async_hooks has landed. I might be able to take a look next week.

[alexkozy]

It would be great to add calls to V8 Inspector asyncTask* methods to corresponded async_hooks methods.

Our general strategy to support async stacks in Chrome:

1. instrumenting all async primitives in platform (Chrome).
2. provide console.tagStack API for cases when frameworks has own async primitives like message loops to link scheduling of callback with callback call. This method is optional and mostly can be emulated with promises.

So we need to support node platform async primitives to get cool async stacks in DevTools.

edit (@AndreasMadsen): fixed link.