feature request: a way to inspect what's in the event loop

[joeybaker]

I recently struggled with debugging a test suite that wouldn't exit. The (tape) tests all finished, but the final result wasn't printed out and the process just hung.

We eventually tracked the problem down to a few long-running setTimeouts that, while fine in app code, needed to be cleared in the tests so that the process could exit.

This debugging process would have been a lot easier if there was a way to see what V8 had in the event loop, by call stack. Perhaps an API like:

setTimeout(() => {console.log('hi')}, 2000)
setTimeout(() => {console.log('hi')}, 1000)

process.getEventLoop( (stacks) =>
  stacks.forEach(console.log.bind(console))
  // ['setTimeout file.js:2']
  // ['setTimeout file.js:1']

stacks is an array of arrays sorted by their order in the event loop and containing the call stack for each item.

Does this already exist? Is it possible?

[mscdex]

There are a couple of undocumented functions that can get you most of what is still on the event loop, but not necessarily everything last I heard: process._getActiveHandles() gets you handles that are still alive and process._getActiveRequests() gets you info about active libuv requests (IIRC).

I do agree that a polished version of these internal functions should be public because trying to find out what is keeping the event loop alive is a problem that I see/hear fairly often.

[joeybaker]

@mscdex Thanks for triaging. I wasn't aware for those methods so thanks also for the tip. As you say though… a formal API would be great.

[Olegas]

Wow! This is awesome! 👍

[alexfernandez]

Are there any examples on how to use process._getActiveHandles() and process._getActiveRequests()? I am trying to extract stack traces but no luck so far.

[petkaantonov]

@alexfernandez what stack traces?

[alexfernandez]

I am trying to extract the stack traces of the callbacks that keep my process from ending. This is something that a formal API should definitely support; and which I don't know how to do with the _getActive...() functions.

[bnoordhuis]

process._getActiveHandles() and process._getActiveRequests() don't collect stack traces because that's prohibitively expensive CPU- and memory-wise, and because there isn't necessarily a 1-to-1 mapping between internal handles and user-facing objects.

[alexfernandez]

Thanks for your quick answer. Is there any published example on how to use those two functions, so that I can be sure that I am not overlooking any interesting info in their interfaces?

[bnoordhuis]

Not really. I added them a few years ago to make debugging a little easier for core devs. They assume fairly deep understanding of the event loop's inner workings and probably aren't that useful for general purpose debugging (although many people do use them that way.)

[joeybaker]

Just documenting: @thlorenz is working on a module that uses _getActiveHandles() to kinda sorta do this. https://github.com/thlorenz/active-handles

[alexfernandez]

That is very cool, thanks!

[a70ma]

I'm working on a small project that logs values about process and os, it contains _getActiveHandles() count too:
https://github.com/a70ma/moninode

[thefourtheye]

@mscdex I used your comment in one of my stackoverflow answers. Please feel free to edit and improve it 😊

[joeybaker]

https://github.com/mafintosh/why-is-node-running solves this by copy/pasting/modifying node internals. It gives a pretty good idea of what would need to be done to land this in core.

[alexfernandez]

+1 to @mafintosh 's approach. It would be even cooler to return an object so you can log it with the desired priority, send it by mail or whatever.

[bendpx]

is this issue still being considered?

[Fishrock123]

@bendpx for now you can use these:

There are a couple of undocumented functions that can get you most of what is still on the event loop, but not necessarily everything last I heard: process._getActiveHandles() gets you handles that are still alive and process._getActiveRequests() gets you info about active libuv requests (IIRC).

[creeperyang]

Anyone work on this?

And it's great if node could offer something like NODE_DEBUG=event_loop and at least output every turn (start) of event loop.

[Fishrock123]

Async-Hooks should solve this.

The EP is here: https://github.com/nodejs/node-eps/blob/master/006-asynchooks-api.md
Pull request at: #11883

Do note that you need to run Async-Hooks before you want the data, but you can easily look through it afterwards to see what would have been in "one" "tick".

[creeperyang]

@Fishrock123 Thanks a lot.

[Trott]

Should this be closed now that async-hooks is a thing?

[Trott]

This issue has been inactive for sufficiently long that it seems like perhaps it should be closed. Feel free to re-open (or leave a comment requesting that it be re-opened) if you disagree. I'm just tidying up and not acting on a super-strong opinion or anything like that.

[tecfu]

"This issue has been inactive for sufficiently long that it seems like perhaps it should be closed."

I can't see a drop off in conversation about an issue after two years open ever being a valid rationale for closing it. This just speculation, but perhaps people are less likely to bet a dead horse at this point since its obvious that no one has stepped up to address this.

[Trott]

I can't see a drop off in conversation about an issue after two years open ever being a valid rationale for closing it.

OK, fine, make me actually explain the rationale rather than rely on my boilerplate issue-triaging text.

People can use async-hooks for this functionality. If there are use cases that aren't covered by that, no one has mentioned them (at least not as far as I can see).

The question "Should this be closed now that async-hooks is a thing?" received no responses other than two thumbs-up emoji responses, including one from the person who originally opened this issue.

Ergo, approximately a week after posing the "can this be closed?" question and not getting a response to the contrary (but getting two apparent gestures of agreement that it could be closed), I decided to close it but added the "Oh, hey, if you want this to be re-opened, just leave a comment" boilerplate in case I was wrong.

I'll update the boilerplate to just say "It seems like this can be closed" rather than mentioning idleness/staleness as a reason.

[piranna]

A link to the async-hooks would be good... El 15/08/2017 07:08, "Rich Trott" <notifications@github.com> escribió:

…

I can't see a drop off in conversation about an issue after two years open ever being a valid rationale for closing it. OK, fine, make me actually explain the rationale rather than rely on my boilerplate issue-triaging text. People can use async-hooks for this functionality. If there are use cases that aren't covered by that, no one has mentioned them (at least not as far as I can see). The question "Should this be closed now that async-hooks is a thing?" received no responses other than two thumbs-up emoji responses, including one from the person who originally opened this issue. Ergo, approximately a week after posing the "can this be closed?" question and not getting a response to the contrary (but getting two apparent gestures of agreement that it could be closed), I decided to close it but added the "Oh, hey, if you want this to be re-opened, just leave a comment" boilerplate in case I was wrong. I'll update the boilerplate to just say "It seems like this can be closed" rather than mentioning idleness/staleness as a reason. — You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub <#1128 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AAgfvkSjs6LqPyKZtxFTeuNLUnsstaMBks5sYSe8gaJpZM4DtT1S> .

[Trott]

Current docs for async hooks: https://nodejs.org/dist/latest-v8.x/docs/api/async_hooks.html

[piranna]

Thank you :-)

[jspenguin2017]

That would require constant tracking of asynchronous hooks right? That would probably slow things down in runtime.
I think most people here are asking for is a function that dumps as much useful information as possible to identify what is holding event loop open when they are trying to shut down their server. Like the shut down handler calls that function on the second press of Ctrl + C for debugging, it really doesn't matter if it takes 1 or 2 minutes to collect the line numbers as the server is probably already shut down and just waiting for some unknown timer or something to get cleared.

[piranna]

I think most people here are asking for is a function that dumps as much useful information as possible to identify what is holding event loop open when they are trying to shut down their server. Like the shut down handler calls that function on the second press of Ctrl + C for debugging, it really doesn't matter if it takes 1 or 2 minutes to collect the line numbers as the server is probably already shut down and just waiting for some unknown timer or something to get cleared.

Yes, that's what I want, to know what's pending on the events queue not allowing the process to finish. Since Node.js allows to receive signals for debugging purposses, probably it would be just enough to connect to it when server is not clossing and exec a function to show what's on the events queue.