Why is there no async stacktrace when rethrowing an asynchronous exception? With node 12+, the exception when running the following code:
async function crash() {
try {
await (async () => {throw new Error('dead');})();
} catch (e) {
throw new Error('rethrow');
}
}
async function foo() {
await new Promise(resolve => setTimeout(() => resolve(), 1));
await crash();
}
async function entrypoint() {
try {
await foo();
} catch(e) {
console.log(e.stack);
}
}
entrypoint();
is woefully incomplete:
Error: rethrow
at crash (/async-stackt/crash.js:6:15)
I found a workaround by defining the exception in the beginning of crash()
, which yields a much nicer:
Error: rethrow
at crash (/workaround.js:2:17)
at foo (/workaround.js:12:11)
at async entrypoint (/workaround.js:17:9)
This is not optimal, since the error has to be constructed in advance whether it is needed or not, and the stacktrace is somewhat imprecise.
Why is the stack trace incomplete when throwing an error from an async catch block? Is there any workaround or change to the code to get a complete stack trace in the first place?
That stack trace is showing you what's ON the stack at that time. When you make an asynchronous call such as setTimeout()
, it runs the setTimeout()
which registers a timer that will fire some time in the future and then it continues execution. Since you're using await
here, it pauses the execution of foo()
, but it continues execution of the code after where foo()
was called. Since that's also an await
, it continues executing the code that called entrypoint()
. After that finishes, the stack is entirely empty.
Then, sometime later, your timer fires and its callback gets called with a completely clean stack. In your case, the setTimeout()
callback just calls resolve()
which then triggers a promise to schedule its resolve handlers to run on the next event loop tick. That returns back to the system and the stack frame is again empty. On that next tick of the event loop, the promise resolve handlers are called and that satisfies the await
on that promise which is inside a function context. When that await
is satisfied, the rest of that function starts to execute.
When that function gets to the end of its execution, the interpreter knows that this was a suspended function context. There is no return
from the function to happen because that already happened earlier. Instead, since this is an async
function, the end of the function execution resolves the promise that this async
function returns. Resolving that promise then schedules its resolve handlers to be called on the next tick of the event loop and then it returns control back to the system. The stack frame is again empty. On that next tick of the event loop, it calls the resolve handlers which satisifies the await
in the await foo()
statement and the entrypoint()
function can continue to run, picking up where it was last suspended.
So, the key here is that when the timer goes off, execution goes from foo
back to entrypoint
, not via a stack and a return
statement (that function already returned awhile ago), but via promises getting resolved. So, at the time the timer goes off and you then call crash()
, the stack is indeed empty except for the function call to crash()
itself.
This concept of an empty stack when promises are resolved goes to the heart of how an async
function actually works so it's important to understand that. You have to remember that it pauses the internal execution of the function containing the await
, but as soon as it hits the first await
, it immediately causes the function to return a promise and the the callers continue further execution. The caller is not paused unless they also so an await
in which case the callers of the caller continuing executing. At some point, somebody gets to continue executing and eventually, it returns control back to the system with a now-empty stack.
The timer event (or some other promise triggering event) then gets called with a completely empty stack frame with no remnants from the original call sequence.
Unfortunately, the only work-around I'm aware of now is to do what you found - create the Error object earlier when the original stack is still alive. If I remember correctly, there is a discussion about adding some features to the Javascript language to make asynchronous tracing easier. I don't remember the details of the proposal, but perhaps by remembering what the stack frame was when the function was originally called since what it is after the promise is resolved/rejected and when the Error object is created is no longer very useful.
In case anyone was unfamiliar with how async
functions work and how they suspend their own execution upon the first await
, but then return
early, here's a little demo:
function delay(t) {
return new Promise(resolve => {
setTimeout(resolve, t);
});
}
async function stepA() {
console.log("5");
await stepB();
console.log("6");
}
async function stepB() {
console.log("3");
await delay(50);
console.log("4");
}
console.log("1");
stepA();
console.log("2");
This generates the following output. If you follow this execution path step-by-step, you will see how each await
causes an early return from that function and can then see how the stack frame will be empty once the promise that is being awaited gets resolved. This is the output generated:
1
5
3
2
4
6
It's clear why 1
is first as it's the first thing to execute.
Then, it should be clear why 5
comes next when stepA()
is first called.
Then, stepA
calls stepB()
so as it begins to execute, that's why we see 3
next.
Then, stepB
calls await delay(50)
. That executes delay(50)
which starts a timer and then immediately returns a promise that is hooked to that timer. It then hits the await
and it stops execution of stepB
.
When stepB
hit that await
, it causes stepB
at that point to return a promise that comes from the function being async
. That promise will be hooked to stepB
execution eventually (in the future) getting a chance to finish all of its execution. For now the execution of stepB
is suspended.
When stepB
returns its promise, that goes back to where stepA
executed await stepB();
. Now that stepB()
has returned (an unfulfilled promise), then stepA
hits its await
on that unfulfilled
promise. That suspends the execution of stepA
and it returns a promise at that point.
So, now that the original function call to stepA()
has returned (an unfulfilled promise) and there is no await
on that function call, that top level code after that function call continues to execute and we see the console output the 2
.
That console.log("2")
is that last statement to execute here so control is returned back to the interpreter. At this point, the stack frame is completely empty.
Then, sometime later, the timer fires. That inserts an event in the JS event queue. When the JS interpreter is free, it picks up that event and calls the timer callback associated with that event. This does only one thing (call resolve()
on a promise) and then returns. Calling resolve on that promise schedules that promise to trigger it's .then()
handlers on the next tick of the event loop. When that happens, the await
on the line of code await delay(50);
gets satisfied and execution of that function resumes. We then see the 4
in the console as the last line of stepB
executes.
After the console.log("4");
executes, stepB
has now finished executing and it can resolve it's async
promise (the one returned by it earlier). Resolving that promise tells it to schedule its .then()
handlers for the next tick of the event loop. Control goes back to the JS interpreter.
On the next tick of the event loop, the .then()
handlers notify the await
in the await stepB();
that the promise has now been resolved and execution of stepA
continues and now we see 6
in the console. That is the last line of stepA
to execute to it can resolve its async
promise and return control back to the system.
As it turns out, there is nobody listening to the async
promise that the call to stepA()
returned so there is no further execution.
I ran into the same issue in Node 12 and found out that it was fixed in a later version of V8: commit.
Gotta wait for Node 14, I guess...
The bug had to do with the stack trace not being tracked in catch
blocks. So one workaround is to use the Promise's .catch
function instead:
async function crash() {
await (async () => {throw new Error('dead');})()
.catch(e => { throw new Error('rethrow'); });
}
If you love us? You can donate to us via Paypal or buy me a coffee so we can maintain and grow! Thank you!
Donate Us With