Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[async_hooks] Wrong after callback in case of uncaughtException #22982

Closed
Flarna opened this issue Sep 20, 2018 · 4 comments
Closed

[async_hooks] Wrong after callback in case of uncaughtException #22982

Flarna opened this issue Sep 20, 2018 · 4 comments
Labels
async_hooks Issues and PRs related to the async hooks subsystem. help wanted Issues that need assistance from volunteers or PRs that need help to proceed.

Comments

@Flarna
Copy link
Member

Flarna commented Sep 20, 2018

  • Version: 8.12.0, 10.11.0, master
  • Platform: windows
  • Subsystem: async_hooks

async_hooks call after with wrong id if an uncaughtException happens which does not end the process.

const async_hooks = require("async_hooks");
const fs = require("fs");

function init(asyncId, type, triggerAsyncId, resource) {
  fs.writeSync(1, `${type}(${asyncId}): trigger: ${triggerAsyncId} execution: ${async_hooks.executionAsyncId()}\n`);
}

function before(asyncId) {
  fs.writeSync(1, `before:  ${asyncId}\n`);
}

function after(asyncId) {
  fs.writeSync(1, `after:   ${asyncId}\n`);
}

function destroy(asyncId) {
  fs.writeSync(1, `destroy: ${asyncId}\n`);
}

async_hooks.createHook({ init, before, after, destroy }).enable();

process.nextTick(() => {
//setTimeout(() => {
  fs.writeSync(1, "in callback\n");
  throw new Error("foo");
}, 100);

process.on("uncaughtException", (e) => fs.writeSync(1, "uncaughtException\n"));

Results in

TickObject(5): trigger: 1 execution: 1
before:  5
in callback
uncaughtException
Immediate(6): trigger: 5 execution: 5
after:   5
after:   1   <=== I think this is not correct
destroy: 5
before:  6
after:   6
destroy: 6

if I change the sample above to use setTimeout instead process.nextTick the issue is limited to master and the async_id emitted is 0 instead 1.

I tried to find the root cause and I thought it's in _fatalException which should emit after for all except the last ids and in case there are no hooks clear all except the last.
But if I check the working setTimeout case in NodeJs 8.12.0 the stack only holds the async_ids for Timeout and TIMERWRAP but not the 0/1 entries.

@addaleax
Copy link
Member

I think the issue might be that we manually kick off nextTick from Module.runMain(), i.e. after running the main script, but while still on the main script stack. For other invocations, we only run the nextTick queue after returning to C++ from whatever callback we invoked, including for setTimeouts… does that make sense?

@addaleax addaleax added the async_hooks Issues and PRs related to the async hooks subsystem. label Sep 22, 2018
@apapirovski
Copy link
Member

So, a few issues involved here:

  1. When do the emitAfter loop in _fatalException, we need to ignore async frames with ID of 0.
  2. There's already a stack for nextTick upon the start of the program, as @addaleax mentioned above which leads it to the 1 being logged. This is technically not a bug but it could be confusing... I don't really have an opinion as to whether it should be fixed... maybe?

@Flarna
Copy link
Member Author

Flarna commented Sep 23, 2018

For completeness the results with other node versions:
Master setTimeout

Timeout(5): trigger: 1 execution: 1
before:  5
in callback
uncaughtException
Immediate(6): trigger: 5 execution: 5
after:   5
after:   0
destroy: 5
before:  6
after:   6
destroy: 6

10.11.0 setTimeout:

Timeout(5): trigger: 1 execution: 1
TIMERWRAP(6): trigger: 1 execution: 1
before:  6
before:  5
in callback
uncaughtException
Immediate(7): trigger: 5 execution: 5
after:   5
after:   6
before:  6  <== strange before/after 6 again here with no callback inbetween
after:   6
destroy: 5
before:  7
after:   7
destroy: 7
destroy: 6

8.12.0 setTimeout:

Timeout(5): trigger: 1 execution: 1
TIMERWRAP(6): trigger: 1 execution: 1
before:  6
before:  5
in callback
uncaughtException
Immediate(7): trigger: 5 execution: 5
after:   5
after:   6
destroy: 5
before:  7
after:   7
destroy: 7
destroy: 6

I think we should not signal after if there was no before signalled.

I'm not sure about the 0/1 entries. If there are present because "something" / "the system" is running we should not remove them. But is there any need to have them on stack at all? Why not default to 0/1 if there is nothing on stack?

@Flarna
Copy link
Member Author

Flarna commented Dec 19, 2019

The issue with nextTick seems to be solved since 13.2.0. I guess it was one of the commits from @addaleax done around 6.11.
setTimeout has not changed.

@jasnell jasnell added the help wanted Issues that need assistance from volunteers or PRs that need help to proceed. label Jun 26, 2020
apapirovski added a commit to apapirovski/node that referenced this issue Jan 7, 2022
Today, the global uncaught exception handler is the only
place where asyncId 0 is not ignored and we still proceed
to call emitAfter. This would've already failed one of
our correctness tests in async_hooks if not for some other
code meant to handle a different edge case.

Fixes: nodejs#22982
apapirovski added a commit to apapirovski/node that referenced this issue Jan 7, 2022
Today, the global uncaught exception handler is the only
place where asyncId 0 is not ignored and we still proceed
to call emitAfter. This would've already failed one of
our correctness tests in async_hooks if not for some other
code meant to handle a different edge case.

Fixes: nodejs#22982
@Flarna Flarna closed this as completed in 5178332 Jan 18, 2022
BethGriggs pushed a commit that referenced this issue Jan 25, 2022
Today, the global uncaught exception handler is the only
place where asyncId 0 is not ignored and we still proceed
to call emitAfter. This would've already failed one of
our correctness tests in async_hooks if not for some other
code meant to handle a different edge case.

Fixes: #22982

PR-URL: #41424
Reviewed-By: Gerhard Stöbich <deb2001-github@yahoo.de>
Reviewed-By: Antoine du Hamel <duhamelantoine1995@gmail.com>
Reviewed-By: James M Snell <jasnell@gmail.com>
Linkgoron pushed a commit to Linkgoron/node that referenced this issue Jan 31, 2022
Today, the global uncaught exception handler is the only
place where asyncId 0 is not ignored and we still proceed
to call emitAfter. This would've already failed one of
our correctness tests in async_hooks if not for some other
code meant to handle a different edge case.

Fixes: nodejs#22982

PR-URL: nodejs#41424
Reviewed-By: Gerhard Stöbich <deb2001-github@yahoo.de>
Reviewed-By: Antoine du Hamel <duhamelantoine1995@gmail.com>
Reviewed-By: James M Snell <jasnell@gmail.com>
danielleadams pushed a commit that referenced this issue Feb 26, 2022
Today, the global uncaught exception handler is the only
place where asyncId 0 is not ignored and we still proceed
to call emitAfter. This would've already failed one of
our correctness tests in async_hooks if not for some other
code meant to handle a different edge case.

Fixes: #22982

PR-URL: #41424
Reviewed-By: Gerhard Stöbich <deb2001-github@yahoo.de>
Reviewed-By: Antoine du Hamel <duhamelantoine1995@gmail.com>
Reviewed-By: James M Snell <jasnell@gmail.com>
danielleadams pushed a commit that referenced this issue Mar 14, 2022
Today, the global uncaught exception handler is the only
place where asyncId 0 is not ignored and we still proceed
to call emitAfter. This would've already failed one of
our correctness tests in async_hooks if not for some other
code meant to handle a different edge case.

Fixes: #22982

PR-URL: #41424
Reviewed-By: Gerhard Stöbich <deb2001-github@yahoo.de>
Reviewed-By: Antoine du Hamel <duhamelantoine1995@gmail.com>
Reviewed-By: James M Snell <jasnell@gmail.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
async_hooks Issues and PRs related to the async hooks subsystem. help wanted Issues that need assistance from volunteers or PRs that need help to proceed.
Projects
None yet
Development

Successfully merging a pull request may close this issue.

4 participants