Closed tonivj5 closed 2 years ago
@vdeturckheim, @Qard any thoughts on why connecting the debugger might b e related.
Possibly a bug in PromiseHook. I do recall there was a bunch of debugger escape hatch stuff in the same codegen parts as where PromiseHook connects its own event triggering logic. Could be somewhere an event is not firing. Could be worth using v8.promiseHooks to log which events are being received and compare. π€
I have a very similar problem with async_hooks
. I just behaves differently when I attach a debugger. What happens is that the before
and after
callbacks are not called for all hooks when debugger is attached (works fine when it is not). Currently, for me, unclear why.
Possibly a bug in PromiseHook. I do recall there was a bunch of debugger escape hatch stuff in the same codegen parts as where PromiseHook connects its own event triggering logic. Could be somewhere an event is not firing. Could be worth using v8.promiseHooks to log which events are being received and compare. thinking
Here is the reproduction updated with the promiseHooks
output added:
const { AsyncLocalStorage } = require("async_hooks");
const { setTimeout } = require("timers/promises");
const { promiseHooks } = require("v8");
promiseHooks.createHook({
init: (promise, parent) => {
console.log("a promise was created", { promise, parent });
},
settled: (promise) => {
console.log("a promise resolved or rejected", { promise });
},
before: (promise) => {
console.log("a promise is about to call a then handler", { promise });
},
after: (promise) => {
console.log("a promise is done calling a then handler", { promise });
},
});
const als = new AsyncLocalStorage();
function runIssue() {
als.run("contextualized", () => {
syncStep();
asyncStep();
});
console.log(`> Out: ${als.getStore()}`);
}
function syncStep() {
console.log(`> Sync step: ${als.getStore()}`);
}
async function asyncStep() {
console.log(`> Before async ${als.getStore()}`);
await setTimeout(1);
console.log(`> After async ${als.getStore()}`);
}
runIssue();
Output without attach any debugger:
> Sync step: contextualized
a promise was created { promise: Promise { <pending> }, parent: undefined }
> Before async contextualized
a promise was created { promise: Promise { <pending> }, parent: undefined }
a promise was created {
promise: Promise { <pending> },
parent: Promise {
<pending>,
[Symbol(async_id_symbol)]: 6,
[Symbol(trigger_async_id_symbol)]: 1,
[Symbol(kResourceStore)]: 'contextualized'
}
}
> Out: undefined
a promise resolved or rejected {
promise: Promise {
<pending>,
[Symbol(async_id_symbol)]: 6,
[Symbol(trigger_async_id_symbol)]: 1,
[Symbol(kResourceStore)]: 'contextualized'
}
}
a promise is about to call a then handler {
promise: Promise {
<pending>,
[Symbol(async_id_symbol)]: 8,
[Symbol(trigger_async_id_symbol)]: 6,
[Symbol(kResourceStore)]: 'contextualized'
}
}
> After async contextualized
a promise resolved or rejected {
promise: Promise {
<pending>,
[Symbol(async_id_symbol)]: 5,
[Symbol(trigger_async_id_symbol)]: 1,
[Symbol(kResourceStore)]: 'contextualized'
}
}
a promise resolved or rejected {
promise: Promise {
<pending>,
[Symbol(async_id_symbol)]: 8,
[Symbol(trigger_async_id_symbol)]: 6,
[Symbol(kResourceStore)]: 'contextualized'
}
}
a promise is done calling a then handler {
promise: Promise {
undefined,
[Symbol(async_id_symbol)]: 8,
[Symbol(trigger_async_id_symbol)]: 6,
[Symbol(kResourceStore)]: 'contextualized'
}
}
Output attaching a debugger:
Debugger attached.
> Sync step: contextualized
a promise was created { promise: Promise { <pending> }, parent: undefined }
> Before async contextualized
a promise was created { promise: Promise { <pending> }, parent: undefined }
> Out: undefined
a promise resolved or rejected {
promise: Promise {
<pending>,
[Symbol(async_id_symbol)]: 9,
[Symbol(trigger_async_id_symbol)]: 1,
[Symbol(kResourceStore)]: 'contextualized'
}
}
a promise is about to call a then handler { promise: Promise { <pending> } }
> After async undefined
a promise resolved or rejected {
promise: Promise {
<pending>,
[Symbol(async_id_symbol)]: 8,
[Symbol(trigger_async_id_symbol)]: 1,
[Symbol(kResourceStore)]: 'contextualized'
}
}
a promise resolved or rejected {
promise: Promise {
<pending>,
[Symbol(async_id_symbol)]: 13,
[Symbol(trigger_async_id_symbol)]: 0
}
}
a promise is done calling a then handler {
promise: Promise {
undefined,
[Symbol(async_id_symbol)]: 13,
[Symbol(trigger_async_id_symbol)]: 0
}
}
Waiting for the debugger to disconnect...
I have tested with latest versions (18.3.0
& 18.4.0
), so the unexpected behavior follow happening.
If I can add any other information to fix this bug, let me know @Qard ππ»
Appears to be missing the init event for the await linking back to the async function as the parent. Not sure off-hand what the cause would be, but I'll see if I can find some time to look at this soon. π€
Bug is still occurring in 18.6.0.
Yep, I haven't had the time to investigate further yet.
I've got a fix for V8 now. https://chromium-review.googlesource.com/c/v8/v8/+/3779922
I'll get that backported whenever it lands. :)
Fix was launched on https://github.com/nodejs/node/releases/tag/v18.9.0
Version
>= 18.0.0
Platform
Linux 5.10.9-051009-generic #202101191835 SMP Tue Jan 19 19:17:55 UTC 2021 x86_64 x86_64 x86_64 GNU/Linux
Subsystem
Linux Mint
What steps will reproduce the bug?
How often does it reproduce? Is there a required condition?
Doing several tests I could say it's always reproducible attaching a debugger
What is the expected behavior?
Expected output:
What do you see instead?
Output attaching a debugger (using vscode or chrome devtools):
Additional information
The issue has been introduced between
17.9.0
(it works as expected) and18.0.0
(it doesn't work, neither18.1.0
or18.2.0
)