Version: v7.7.3
Platform: Windows 7x64
The purpose of this issue is really a more broad request for better stack traces with async/await but I figured I would start with a very specific case. If we need to broaden the description, I'm good with that. I've seen a number of lengthy discussion on this subject in various places but I don't see any actual issues for it so I thought I'd start one and hopefully it's not just a duplicate of something I missed.
I'm filing the specific issue here because it seems the async/await functionality just added provides less useful error handling than we could get with generators.
async function functionOne() {
await new Promise((resolve) => {
setTimeout(() => { resolve(); }, 1);
});
throw new Error('Something Bad');
}
async function functionTwo() {
await functionOne();
}
functionTwo()
.catch((error) => {
console.error(error);
});
Outputs:
Error: Something Bad
at functionOne (C:\Work\sandbox.js:5:9)
That stack is missing everything that called functionOne
(functionTwo
specifically).
The generator equivalent of this:
const co = require('co');
function* functionOne() {
yield new Promise((resolve) => {
setTimeout(() => { resolve(); }, 1);
});
throw new Error('Something Bad');
}
function* functionTwo() {
yield* functionOne();
}
co(functionTwo())
.catch((error) => {
console.log(error);
});
Outputs:
Error: Something Bad
at functionOne (C:\Work\sandbox.js:7:9)
at functionOne.next (<anonymous>)
at functionTwo (C:\Work\sandbox.js:11:10)
at functionTwo.next (<anonymous>)
at onFulfilled (C:\Work\NPS\nps-dev\node_modules\co\index.js:65:19)
Here you can see both functionOne
and functionTwo
in the stack.
If the error is thrown before any await
in the code, then you actually get a complete stack trace even if the function was called in a whole chain of awaits and regardless if those awaits were first or not:
async function throwFunction() {
throw new Error('Something bad');
}
async function functionOne() {
return await throwFunction();
}
async function functionTwo() {
return await Promise.resolve();
}
async function functionThree() {
await functionTwo();
return await functionOne();
}
functionThree()
.catch((error) => {
console.log(error);
});
Outputs:
Error: Something bad
at throwFunction (C:\Work\sandbox.js:2:9)
at functionOne (C:\Work\sandbox.js:6:16)
at functionThree (C:\Work\sandbox.js:15:16)
at process._tickCallback (internal/process/next_tick.js:109:7)
at Module.runMain (module.js:607:11)
at run (bootstrap_node.js:425:7)
at startup (bootstrap_node.js:146:9)
at bootstrap_node.js:540:3
The real driving force behind this was that I finally found the recipe to get complete stack traces, even when dealing with existing code using promises. With a try...catch in the generator, we can use VError
to weld together the errors thrown by promises with the stack of the code calling the generator. This does not seem to work with async functions.
Here's a more complete example using generators that I really wish would continue to work with async functions:
const co = require('co');
const VError = require('verror');
function calledFromAPromise() {
throw new Error('Something bad');
}
function doAPromise() {
return new Promise((resolve) => {
setTimeout(() => { resolve(); }, 1);
})
.then(() => { calledFromAPromise(); });
}
function* queryFunction() {
return yield* yieldRethrow(doAPromise());
}
function* functionOne() {
return yield* queryFunction();
}
function* functionTwo() {
return yield* functionOne();
}
function* yieldRethrow(iterable) {
try {
return yield iterable;
} catch (error) {
throw new VError(error);
}
}
co(functionTwo())
.catch((error) => {
console.log(error);
});
Outputs (with some non-relevant stuff removed):
{ VError: : Something bad
at yieldRethrow (C:\Work\sandbox.js:31:11)
at yieldRethrow.throw (<anonymous>)
at queryFunction (C:\Work\sandbox.js:16:17)
at functionOne (C:\Work\sandbox.js:20:17)
at functionTwo (C:\Work\sandbox.js:24:17)
at onRejected (C:\Work\NPS\nps-dev\node_modules\co\index.js:81:24)
jse_cause:
Error: Something bad
at calledFromAPromise (C:\Work\sandbox.js:5:9)
at Promise.then (C:\Work\sandbox.js:12:19),
The async equivalent outputs this:
{ VError: : Something bad
at yieldRethrow (C:\Work\sandbox.js:30:11)
jse_cause:
Error: Something bad
at calledFromAPromise (C:\Work\sandbox.js:4:9)
at Promise.then (C:\Work\sandbox.js:11:19),
As you can see, this has the same problem as at the top in that the rethrown error doesn't have a complete stack.
Cc @nodejs/diagnostics
That's because Error.stack only reflects the actual stack. The inspector provides async stack traces, but Error.stack will never include the async parts due to the overhead of collecting it.
Wouldn't it be nice if there was a way to enable async stack traces via a flag or something? Or when NODE_ENV === 'development'
and the like?
The overhead is huge, but there are cases when developers will want Error.stack to generate async errors for them.
You could run node with --inspect and enable async stack trace in DevTools.
I'm thinking something more command-liney would be better. Personally, I only use Chrome DevTools when I really want to figure out precisely what's happening. But most of the time, developers just want informative stack traces in their terminal.
something more command-liney would be better
Would node -r longjohn
work for you?
Arrr, meehaps
Would it be possible to add a V8 option that enables async error stacks for "normal" error.stack properties? Or would that be too risky?
We have promisehooks in V8 that will help you build these async stack traces. Node can use this API to expose an async stack trace.
The @nodejs/diagnostics plan for solving this is:
async_hooks
and land async_hooks
– PR: https://github.com/nodejs/node/pull/11883This problem is unlikely to be solved by node core directly, we will just give the tools to module authors such that they can solve it. For example I have written https://github.com/AndreasMadsen/trace, which uses an undocumented version of async_hooks
. _This won't solve this issue as is, because we still don't have the PromiseHook C++ API, but it will eventually be updated._
Just so I understand, what's the reasoning behind solving this in userland instead of node core?
And I guess the question I have is what changed? This problem didn't seem to exist with the equivalent generator code. I understand there are technical differences between generators and async/await but the fundamental idea that the VM pauses execution and then resumes seems the same and yet when we did that with generators, the full stack trace was available.
Generators are resumed from user code. Async functions are resumed from the micro task queue.
Just so I understand, what's the reasoning behind solving this in userland instead of node core?
Because it can be solved in userland, once the building blocks are in place. Node.js has always aimed at keeping the core minimal and instead embrace external modules, only things that are really difficult to implement in userland end up in node core. trace
is an 80 lines module (with mostly comments), so arguably it is not that hard. There are also different ways of implementing it, which involves tradeoffs between speed, memory, completeness, and usability. We will likely see different modules, that prioritize differently.
I would say that trace
prioritizes memory and completeness, while longjohn
prioritizes speed and usability (but I'm likely biased).
Generators are resumed from user code. Async functions are resumed from the micro task queue.
Correct. There is a second concern involving promises. Previously new Promise()
was used in combination with generators, this allowed long-stack-trace implementations to monkey-patch global.Promise
and essentially implement a _PromiseHook C++ API_ approximation this way. async function
consistently returns a promise using a v8 internal reference (not global.Promise
), thus monkey-patching global.Promise
is not enough.
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.
I would like to argue that this issue be re-opened. If for no other reason than it can be a place to report on any kind of progress that's made on adding better support for stack traces in Node. I think there is a legitimate gap in functionality here and until that gap can be closed, I would argue this issue should stay open.
I've reopened it. Also, I've changed it from "question" to "feature request"
Thanks! And to put a point on the real problem, imagine my database layer throws an error like the following:
error: syntax error at end of input
at Connection.parseE (C:\Project\node_modules\pg\lib\connection.js:567:11)
at Connection.parseMessage (C:\Project\node_modules\pg\lib\connection.js:391:17)
at Socket.<anonymous> (C:\Project\node_modules\pg\lib\connection.js:129:22)
at emitOne (events.js:96:13)
at Socket.emit (events.js:191:7)
at readableAddChunk (_stream_readable.js:178:18)
at Socket.Readable.push (_stream_readable.js:136:10)
at TCP.onread (net.js:560:20)
How is this information useful to me especially if it occurred in production where I don't know what caused it? There is not a single line of code in that stack from my code and the error from the library I'm using doesn't even tell me what's really wrong. I would have absolutely no hope of figuring out what the cause of this was without reviewing every single database statement in my code.
Am I in the minority here that thinks this is major issue in trying to deal with problems?
Just so I understand, what's the reasoning behind solving this in userland instead of node core?
Because it can be solved in userland, once the building blocks are in place. Node.js has always aimed at keeping the core minimal and instead embrace external modules, only things that are really difficult to implement in userland end up in node core.
And I guess I would like to challenge this as well. It seems to me that as something as fundamental as getting a full stack out of errors from my code is exactly what I would expect from my runtime platform. I'm not sure the argument that there are tradeoffs works in this particular case. I would argue that almost any reasonable production environment is going to want a feature like this and implemented in a way that doesn't have major downsides (like a huge performance hit). If such a thing can be done, almost everyone is going to want it and if it can't be done, almost nobody is going to want it. I don't see a lot of room for options here so giving me choices doesn't make me feel any better.
@TazmanianD +1. I've been keeping myself sane by using transform-async-to-generator
, and using Bluebird with long stack traces. I'm sure I'm missing out on performance gains from native async/await, but just like you I couldn't handle dealing with context-free stack traces.
You are not a minority. There is a secret solution called _coroutines_. Other languages like golang have them and they can also be enabled in node.js (npm install fibers
or npm install f-promise
(better interop with promises)).
Benefits: 1) you can eliminate 99% of your async/await syntax overhead, 2) perfect stack traces (without performance overhead - actually the opposite)
and using Bluebird with long stack traces.
From their own documentation:
Long stack traces imply a substantial performance penalty, around 4-5x for throughput`
Which I would consider unacceptable for production use. The irony here is that the major argument in favor of the asynchronous model of Node is precisely for performance reasons and if the first thing you do is something to kill performance precisely as a consequence of that model, you gotta ask what the point in using Node is :-).
npm install fibers or npm install f-promise
Oh man, you're my hero! It sounds like fibers is exactly what I've been wanting and I can see how they solve a bunch of different problems. I just played with it a bit but this may be a "user space" solution to my original problem that I'm actually happy with.
I did give your f-promise
library a try and one thing I noticed in a simple benchmark is that it does appear to be just a tad slower than using generators or async/await (about 2%). Is that a surprise? Of course such a small cost is totally worth the benefit.
There does seem to be a bunch of libraries built on top of fibers. Care to make an argument for yours over the others? You might want to consider having your library added to their list: https://github.com/laverdet/node-fibers/wiki.
Fibers' overhead depends on your code patterns. If you are writing low level code which is completely dominated by callbacks (each callback doing little work, with shallow stacks) I would not recommend fibers because of the overhead of switching into a fiber in every callback.
On the other hand, as soon as you start to have a somewhat thick layer of logic on top of async calls, then coroutines are a winner. An async function calling another async function will not involve any intermediate promise creation / promise resolution overhead; it will just be a direct, normal function call (this is why you get _perfect_ stack traces for free). So the deeper your stacks, the more you gain.
And this is no toy. Some frameworks (Meteor) have been built with fibers. The project I am involved with has been using it for 5+ years. We used it hidden under a preprocessor (streamline.js) initially, which gave us the option to swap fibers for pure callbacks or generators (in case something went wrong with fibers). But the newer parts of the project are now written with f-promise.
One important gotcha: fibers does not run in browsers, as it requires a binary add-on. I hope that coroutines will make it into JavaScript some day but there has been very strong resistance so far (the single-frame continuation rule).
The main selling point of my little library: the simplicity of its API (2 calls) and the ease of interop with promises (and callbacks too - just noticed this was not documented so I added it to the README). I also designed it to be a natural upgrade for the streamline.js community (CLS feature is compatible). But just google around and you'll find other libraries.
And I guess I would like to challenge this as well. It seems to me that as something as fundamental as getting a full stack out of errors from my code is exactly what I would expect from my runtime platform. I'm not sure the argument that there are tradeoffs works in this particular case. I would argue that almost any reasonable production environment is going to want a feature like this and implemented in a way that doesn't have major downsides (like a huge performance hit). If such a thing can be done, almost everyone is going to want it and if it can't be done, almost nobody is going to want it. I don't see a lot of room for options here so giving me choices doesn't make me feel any better.
There is no magic solution. I'm not saying it is impossible, but it is very difficult. The day we have high-performance long stack traces that works across all asynchronous boundaries (not just promises), then I will take a long vacation and stop working on node-core.
Until then, imperfect solutions with different trade-offs will have to compete.
I honestly think there is very little we can do here because looking at the stack will always have a high performance penalty. I am certain that as soon as there is something that could be done, it will also be done. Having a feature request for this does not really help a lot. Therefore I tend to closing this again and to remove the feature request label (besides the fact that it is a question and a feature request at the moment).
@AndreasMadsen what do you think?
@BridgeAR as I understand it, looking at the stack isn't really the expensive part, it is translateing the addresses to JavaScript callsites. So in theory, if there is an immutable data structure for that, then it only get expensive when actually printing the stack. But such a data structure is unlikely with a JIT runtime.
This feature request is definitely on V8 to implement, node already have the hooks for DevTools so our side isn't the problem.
I'm fine with closing this if there is a v8 issue.
CC @nodejs/v8
@AndreasMadsen Async stack trace is already available through Dev Tools / V8 Inspector after https://github.com/nodejs/node/pull/13870 (which integrates async_hooks with Inspector integration).
Async stack trace is already available through Dev Tools / V8 Inspector after #13870 (which integrates async_hooks with Inspector integration).
Yes, that is what I said.
node already have the hooks for DevTools so our side isn't the problem.
There is nothing more we can do right now.
Well it appears to me that fibers is a genuine solution to the problem which tells me that it obviously can be solved. Now that's not entirely fair because fibers is a much larger solution that does things you guys have obviously chosen to not include in node core.
What's still unclear to me is that if there is something on the V8 side that they can implement that would improve things for Node, either in node core or in user space. If there are things in V8 that have some reasonable plan for, I would argue keeping this open until then (as long as there is some reasonable timeframe). But given what I see in fibers so far, I won't complain if you want to just close this :-).
In any event, I think there's some possible room for some documentation or introduction from the Node team. I've been a Java developer for many years and a year ago I switched to a team using Node and decided to give it a try. I hated it and the top two reasons were callback hell and useless stack traces (which should tell you just how strongly I felt about this issue). Those two along with my displeasure in the weakly type nature of Javascript nearly turned me into an active opponent of Node. Fortunately, I eventually discovered solutions to all of my complaints. Promises help a little and generators/async/await/fibers are all total solutions to callback hell. Typescript is a 90% solution to my typing issue and up till now, I found generators to be a 75% solution to the stack trace problem (but not async/await which is why I started this issue).
So I've gone from almost being an active opponent to maybe not quite a fan but trending in that direction. But it took me an entire year to go through that process. I was working with people who had been using Node for years and they barely knew promises and nothing about generators and certainly not fibers. If you look at the getting started guide on Node's main home page, there is no mention of any of these additional technologies and every one of the examples shows off the usage of callbacks.
Perhaps you should consider some sort of "Node for Java developers" article that explains the pitfalls and potential solutions that someone like me can have. I gather you guys are taking a fairly agnostic approach to telling users what to do with Node and don't want to pick sides or recommend external modules or libraries but I think by not doing so, you leave a lot of people to the random luck of the internet to stumble across solutions to really common problems.
Looking at the stack is not expensive, as well as resolving could be not expensive if we correctly cache symbolized frames (as was measured in the wild there are not a lot of unique call frames). Currently we can speedup cache lookup I think 2 times if we remove support of Function.prototype.displayName from V8. I'm not sure how useful is this feature - displayName allows to change function name in stacks from JS runtime. [1] Or at least we can limited this feature that displayName can be changed only once before first call of this function.
AFAIR, penalty for promise.prototype.then was around 3-4 times slower, mostly because promise.prototype.then is super fast by itself. For Chromium setTImeout, setInterval and requestAnimationFrame async stack enabled/disabled almost non-observable from performance point of view. I can double check numbers.
Another point that in the world where we use async functions instead of promises, async stacks potentially can be very fast. Since it's enough to store only one pointer from one generator to another to reconstruct async stack trace.
@ak239 A problem we are having with async_hooks
and async stack traces is that Error.prepareStackTrace
is called lazily, thus when Error.prepareStackTrace
is called the async context is the context of error.stack
and not new Error()
. Would it be possible to get notified when an error is created and similarly when Error.captureStackTrace
is called?
We don't actually need to build the error string when a new error is created, we just need to get notified to set the context.
This won't be a fast solution but it a very good solution when performance isn't a concern.
_see https://github.com/AndreasMadsen/trace/issues/34 for the original discussion._
_/cc @fasterthanlime_
One note I would make on performance is that ideally the system under normal operation wouldn't have any noticeable performance impact. If building the stack traces is slow, but only when an error actually occurs, I would say that's quite acceptable. We're taught in the Java world that exceptions are expensive and you should only use them in exceptional circumstances and not as a means of normal control flow.
I came here looking for a way to show proper stacktraces when using async-await in node.js.
Until this feature is finished, using Bluebird promises with BLUEBIRD_LONG_STACK_TRACES=1
can serve as a workaround.
@ejoebstl that does not help for this particular issue. Long stack traces help if you're using raw promises. With await
the stack is blown away every time-see my issue https://github.com/tgriesser/knex/issues/2500 for example
Hi there. I think I've solved this in trace PR #40. I'd love any feedback or testing anybody could give this code :)
You can try it out by installing it from my repo:
npm install 'git://github.com/jbunton-atlassian/trace#a4e78d89e09ab4830f302bf85a30a528a5746e0b'
@capaj Depends. If you use i.e. babel or babel-node with transform-async-to-promises
it works. A lot of people seem to use this setup.
In my specific case, I was using it for unit tests and it was just what I needed. I agree that this is a hack, and the underlying issue should be fixed as soon as possible.
I experienced the same issue, how can I help?
I don't really need a whole stack, I really just need the freaking line number for the error. This should be a basic functionality for any coding tool. How does this not work in node?
@shkkmo Your description is lacking but it sounds like a different issue. File a new bug if you have a no third-party deps test case.
Regarding this issue, I think we should close it out. It's been discussed by knowledgeable people and if the consensus is that there are good reasons for why things are the way they are, then there's no point in keeping it open.
Closed due to the mentioned reasons.
Hm. I'm very happy that this issue has been been discussed by knowledgeable people, but I would appreciate a bit more of a background info. What is the proposed way to get the stack trace in this case?
Yeah, this is a massive headache for end users. For those of us who want to use async/await as intended, with native Promises, this requires us to make use of workarounds or hacks to get any useful debug information.
Who's intended to take care of this now? Is it supposed to be a v8 problem? If so, a link to a relevant place to follow up and track this would be incredible. If the solution is "there is no solution, use Bluebird/userland trace libraries/go back to callback hell" well...that'd be really good to know before building any more projects in Node.
I know that the Node.js guys want keep everything that can be done in userland out of the core. But to me, generating stack traces seems like an important enough feature to make an exception.
@aleksey-bykov You already got a warning and deletion further up this thread. Don't let it happen again.
I do want to add a last shout-out for the solution mentioned above that has been working for me. I've been using Node fibers and the f-promise
library for a short while now and it's been great. It is effectively a solution to this problem and I highly recommend it.
@TazmanianDI well, it might be a good solution for a new project, but for existing codebases 'rewrite using new library' doesn't sound too appealing.
I'm using trace
for debugging. For production the performance penalty is too big, but it does give you resonable stack traces. It works with native Promises.
(But as I wrote above, this is the kind of functionality you'd expect from the platform, whether it is V8 or Node.js.)
https://mathiasbynens.be/notes/async-stack-traces
I might misinterpret this but it looks like a v8 core dev explaining that performant async stack traces are possible?
@Janpot, it'd ge great if they get around to implementing that! 👍
The trace
library is a great userland solution, but most of our errors occur in prod environments...I guess that means the tradeoff is performance lag vs knowing where our errors are actually occurring. That's not really a great tradeoff to have to make IMO.
(on a related note, incorrect stack traces actually invalidates a lot of our error tracking tools; Stackdriver errors, for instance, groups a number of different errors under the same banner because the throw
site is the same)
We currently have no plans to change the way Error.stack
works in V8. All Mathias' blog post says is that tracking async stack traces for pure async/await can be done a lot cheaper than Promises in general. However, creating an Error object is expensive already. Following the chain of suspended async functions just makes it even more expensive.
I would consider experimenting with an implementation at some point, but no promises. And even if I had it by the end of this quarter, you would not get it until Node.js 10. Also, contributions are always welcome.
@ak1394
@TazmanianDI well, it might be a good solution for a new project, but for existing codebases 'rewrite using new library' doesn't sound too appealing.
Aye, you would need to add a new library but if your codebase is already based on async/await
, the conversion is very easy. It's more-or-less replace await x
with wait(x)
and async function
with just function
. Similarly with generators. It's almost a syntax difference; you shouldn't have to do any significant rewriting. You'll have to add some run
calls at your entry points as well (where the fibers start).
If your code is promise based, it's a bit more work but basically means just collapsing all your then/catch
calls and make them inline (something you'd have to do to switch to async/await
anyway).
@TazmanianD for libraries, that’s just not tenable - a solution that only works for app code really isn’t a viable solution.
I think for many apps trace is a viable option even in production.
I'd particularly love any feedback / testing on my improvements to it, see my earlier comment for details.
Edit: Note that my improvements to trace include fixing the memory leak that @foray1010 mentions below.
I doubt that using trace
in production
see my comment about memory leak of trace
in https://github.com/AndreasMadsen/trace/issues/35#issuecomment-361838159
Aye, you would need to add a new library but if your codebase is already based on async/await, the conversion is very easy. It's more-or-less replace await x with wait(x) and async function with just function. Similarly with generators. It's almost a syntax difference; you shouldn't have to do any significant rewriting. You'll have to add some run calls at your entry points as well (where the fibers start).
You'll have to forgive my skepticism @TazmanianD but none of that sounds easy...it sounds more like a totally rewrite of a codebase, really, along with end-to-end testing to ensure there's no unexpected changes in behaviour. Definitely an approach I'd consider for a greenfield project but not for an existing-in-production codebase.
This thread had one important question that was drowned out and never answered (afaict):
@ak239 A problem we are having with async_hooks and async stack traces is that Error.prepareStackTrace is called lazily, thus when Error.prepareStackTrace is called the async context is the context of error.stack and not new Error(). Would it be possible to get notified when an error is created and similarly when Error.captureStackTrace is called?
If such a callback existed in node, it looks like trace could work even with async/await code. Without such a callback, there's nothing more @AndreasMadsen can do in trace.
I'm retiring from this thread and I'd advise folks who don't develop node core to do the same (see https://github.com/nodejs/node/issues/11865#issuecomment-359298802 for a workaround, with a performance hit) - but I would like to see a response from the team (at some point) on whether such a callback is doable and if they're interested in adding it.
TL;DR: The issue hasn't been resolved, it should be reopened and restricted to collaborators to avoid noise.
Error.prepareStackTrace is called lazily, thus when Error.prepareStackTrace is called the async context is the context of error.stack and not new Error(). Would it be possible to get notified when an error is created and similarly when Error.captureStackTrace is called?
@fasterthanlime That wouldn't make a practical difference, if I understand your question correctly: while the stack trace is formatted lazily, it's captured eagerly.
@fasterthanlime That wouldn't make a practical difference, if I understand your question correctly: while the stack trace is formatted lazily, it's captured eagerly.
If I understood @AndreasMadsen correctly, the crux of the issue is that the stack trace is captured when an error is thrown, rather than when it's created. Having a callback when the error is created would let trace use another stack trace captured on new Error()
instead of the one it currently has, captured on throw. (I may be completely wrong!)
Reading the first few posts of https://github.com/AndreasMadsen/trace/issues/34 should give some context.
It’s worth noting that the stage 1 stack traces proposal will require that the trace be captured when the error is created; throwing it is irrelevant.
Yup. The content of Error.stack
is captured at Error creation, but formatted lazily.
@fasterthanlime Correct. It is impossible to give a long stack trace without knowing the async context at error creation. To get the async context at error creation, one needs a V8 supported hook for error creation.
@hashseed ^ I mentioned this at the Diagnostic WG, but never got around to open a V8 bug report.
This may be a totally ignorant question given I know nothing of the implementation details, but is there any lesson to be taken from Node fibers? That add-on appears to contain an actual solution to this problem and one that doesn't appear to have any significant performance impact. It is a native add-on and I don't know if that alters its usefulness here.
There seems to be some debate as to whether or not a solution is possible when it seems to me there is in fact already a solution but one that requires an add-on.
@hashseed I opened a feature request: https://bugs.chromium.org/p/v8/issues/detail?id=7525
@TazmanianDI node-fibers has massive memory overhead compared to promises. It creates a V8 context per thread of execution instead of just the one; that's not much lighter-weight than spawning a process per connection. I'm only mildly exaggerating.
@bnoordhuis
@TazmanianDI node-fibers has massive memory overhead compared to promises. It creates a V8 context per thread of execution instead of just the one; that's not much lighter-weight than spawning a process per connection. I'm only mildly exaggerating.
What makes you say that? This would seem to argue that it's not so heavy: https://groups.google.com/forum/#!topic/nodejs/3dbidW8fTYw.
I did a quick-and-dirty performance test before we switched to fibers (granted I didn't look at memory usage) and I found the performance difference between fibers and async/await as well as promises to be neglibible but maybe my test sucked. If it does have a heavy cost, then I would feel a bit alarmed as performance is a reason I didn't choose the other options mentioned above like longjohn which you don't want to run in production.
Oh, I misremember: it wasn't context-per-fiber that was the issue, it had to do with stack size and fibers being weak references.
A few years ago I helped Meteor debug a performance issue that turned out to be a build-up of fibers causing the garbage collector to melt down. Weak references need special handling in the garbage collector; you can't have too many without performance implications.
That's not to discourage you - if fibers work for you, great, use them - but it's not a general purpose solution.
@bnoordhuis
Here is that code that allocates a Fiber
: https://github.com/laverdet/node-fibers/blob/master/src/fibers.cc#L495
It does not create a new context; it uses the current context.
Also, stack allocation is pretty clever, with mmap
. See https://github.com/laverdet/node-fibers/blob/master/src/libcoro/coro.c#L653
Now, consider a pattern of deep stacks of async calls (async f1 awaiting on async f2 awaiting on async f3, ...) with state (local variables) that needs to be tracked in each function. How is state maintained? With fibers it is maintained directly in the fiber's stack. With promises, it is maintained in closures. Not sure who wins.
In my experience, fibers thrive with deep stacks of async calls.
There are gotchas of course and you must be careful to throttle the level of parallelism (because, despite what I said above, a Fiber object takes more memory than a promise) - but this is not aways a bad thing (ever run out of file descriptors?, or generated a DDOS against your database?).
Fibers are node's goroutines. Why would stackful coroutines be the norm in go, but unacceptable in JavaScript? And probably fibers could be made faster if they were baked into the language, instead of implemented as an add-on.
@bjouhier Regarding the fiber discussion: while it's definitely interesting, and useful, technology, going over to fibers is not a viable solution for many use cases discussed in this thread. Right now this discussion feels like it would be better suited for a separate issue so this issue can remain focused on the underlying problem with async/await errors.
@hashseed I was experimenting with traversing async function's generators for async stacks and I believe that I can find some related work on my machine and upload to codereview tool.
I have more generic question. I believe that our async stacks in DevTools are good enough for a lot of users and since in any case we include this code as part of inspector inside V8, could we add some V8 API which will enable our async stacks and include them to Error.stack. As next step we can add native module, let it be called 'devtools-async-stacks' which will just call this API. User would be able to require this module using -r flag with node to get devtools async stacks in terminal. It would be almost zero code on Node side and will just expose feature that we already have in V8.
@moberemk Well, the fibers topic was brought back to the discussion by @TazmanianDI, the OP of this issue. And fibers actually solve his problem.
I replied because @bnoordhuis's post was misleading and there has been a lot of negativity about fibers in the past. Thanks Ben for correcting.
Regarding stacktraces with async/await maybe I can share my experience with streamline.js, which is basically an early implementation of the async/await model.
Streamline provides long stack traces, even when the code is transpiled to callbacks. Actually it provides two stacktraces in this mode: the _raw_ stacktrace that V8 gives by default + an _async_ stacktrace which contains the stack of await calls. I found it important to provide both and not clobber the raw stack.
The async stacktrace is built by pushing a little _frame_ object containing filename + line number on a stack just before the await
call and popping it when the await
call returns (in a later turn of the event loop). This stack of frame objects is managed as a simple linked list. The pointer to the top of this stack is tracked in the async function's closure.
As streamline is a transpiler this was implemented by emitting extra code in each async function. For async/await it should be possible to implement something similar in the V8 compiler. Unfortunately this introduces overhead in all await
calls but this overhead is less than calling Error.captureStacktrace
. Unfortunately this cannot be polyfilled (how would the polyfill get __filename
and line number?)
Streamline supports 3 transpiling modes: pure callbacks, generators, and fibers. In the first two modes, errors carry the two stacktraces. In fibers mode the raw stacktrace is sufficient and there is zero overhead to obtain it.
@hashseed I was experimenting with traversing async function's generators for async stacks and I believe that I can find some related work on my machine and upload to codereview tool.
That sounds like a plan. But I think we should generally unify the way we store stack traces. The one on the Error object and the one we use for async stack traces are similar, but different. It would be awesome if we can share more of the implementation.
Do you somebody feel like writing a small lib that would implement async/await
using https://github.com/laverdet/node-fibers? I will try to write something using Futures from the same project but it will not be that effective. I do not understand how fibers work, otherwise, I would have done it myself.
This idea is far from a sexy solution but I didn't have much luck even with fibers.
Basically, we wrap a promise into a catchMe()
providing a factory-method that will create a new Error()
upon usage. That is necessary or all the catchMe()
calls will end up creating a bunch of errors just to deplete memory.
const me = require('./catch-me').catchMe
await me(() => Error(), iAmReturningPromise())
catch-me.js
async function catchMe(errorFactory, promise) {
try {
return await promise
} catch (e) {
e.stack += errorFactory().stack
throw e
}
}
module.exports = catchMe
I hope that somebody will help me to create a less verbose method...
@zatziky async/await is language syntax so you cannot just implement it with a library. You would have to transpile the code. I can give you some pointers if you are interested but this is more work than a library.
If you want to try fibers, I suggest that you start with something like f-promise
and that you temporarily forget about async/await. Once you get more comfortable, you can start to mix them (but you'll lose comprehensive stacktraces on the async/await bits).
@zatziky Instead of concatenating the stacks like you are, you should give the verror
library a try. It's basically a nested error that allows you to keep the entirety of each error including any details that might be on them. That was the solution we were using when we were using generators but that solution stopped working fully with async/await which is precisely what I created this issue originally to address.
We are gonna use a small module in our projects. It basically embraces the solution I proposed above:
https://github.com/amio-io/await-trace
Here's how you can quickly refactor the code:
@TazmanianDI I stayed with node's Error
instead of verror
because I would have create 2 error objects instead of only 1. But I like that verror
library. 👍
Can anyone recommend an issue to follow so I can get a notification when the issue mentioned in the OP title is fixed?
I will go back to the native Promise implementation once this problem is fixed, but in my case finding quickly the error line that breaks my code and/or unit-tests has priority over performance.
FWIW, even getting the single last line of non-library code would be useful
Still not fixed in Node 10. :(
@fgarcia The best current solution is @AndreasMadsen's trace, which sometimes doesn't work. Andreas' work on this is impressive, but there seems to be no way of fixing some cases without v8's help, so what you want to follow is his issue on v8's tracker.
/cc @nodejs/v8 @nodejs/diagnostics _Sorry to cc you on such a hot issue, but it would be great if we can get some progress in https://bugs.chromium.org/p/v8/issues/detail?id=7525. We talked about it at the Ottawa Diagnostic Summit, and our friends from V8 told me to open an issue. However, nothing is really happening._
Given that the error stacks proposal will require the stack be fully populated and probably frozen at error object creation time, i don’t think that v8 issue is likely to make much progress.
@ljharb that won't necessarily help solve this. Without a hook executed on stack traces creation there's no way to track their async execution context.
If v8 were to implement your proposal using Error.prepareStack
that should be enough (as it can be monkey-patched), but according to this issue they want to remove that function.
I guess a better solution would be to have a standard way to hook into the stack traces creation, and there use platform-specific APIs to enrich them with async execution info.
The spec would not allow a monkey patchable injection point.
The engine, of course, could inject whatever info it wanted at error object creation time.
@ljharb Can you link me to what proposal that is? But even if the error was "fully populated and probably frozen" it would be fine. We could just use a WeakMap
.
To be clear this is what I would like:
diff --git a/src/messages.cc b/src/messages.cc
index 1800b1ef71..494e717b2f 100644
--- a/src/messages.cc
+++ b/src/messages.cc
@@ -1138,6 +1138,24 @@ MaybeHandle<Object> ErrorUtils::Construct(
isolate->CaptureAndSetSimpleStackTrace(err, mode, caller),
Object);
+ // If there's a user-specified "Error.constructorHook" function, call it.
+ Handle<JSFunction> global_error = isolate->error_function();
+ Handle<Object> constructor_hook;
+ ASSIGN_RETURN_ON_EXCEPTION(
+ isolate, constructor_hook,
+ JSFunction::GetProperty(isolate, global_error, "constructorHook"),
+ Object);
+
+ if (constructor_hook->IsJSFunction()) {
+ const int argc = 1;
+ ScopedVector<Handle<Object>> argv(argc);
+ argv[0] = err;
+
+ RETURN_ON_EXCEPTION(isolate,
+ Execution::Call(isolate, constructor_hook, global_error, argc, argv.start()),
+ Object);
+ }
+
return err;
}
Then we can implement:
const errorCreationContext = new WeakMap();
Error.constructorHook = function (err) {
errorCreationContext.set(err, async_hooks.executionAsyncId);
}
One important point that may explain the difficulty here: the helpful stacktrace is the stack of await calls. The problem is that only the V8 compiler sees the await keywords.
Monkey patching Error
or Promise
won't really solve the problem because you won't be able to distinguish between Errors
/Promises
that flow though an await call and Errors
/Promises
that originate/flow elsewhere.
In short a proper solution requires superpowers: either tweaking the compiler or transpliling (so that you can tweak around await keywords), or tweaking the runtime (with fibers).
@AndreasMadsen https://github.com/tc39/proposal-error-stacks
@bjouhier just to clarify, we are talking about monkey patching some v8-specific properties of Error
, not replacing it. Doing that gives you the superpowers you referred to.
@alcuadrado and the proposed spec will actively forbid such monkeypatching, so that's not a viable long term strategy.
@ljharb The proposal only mentions freezing objects in GetStack
, GetStackFrames
, FromStackFrame
, FromStackFrameSpan
, FromStackFramePosition
. All of them freeze new objects.
I don't see why I wouldn't be able to monkey-patch Error.prepareStackTrace
. Note that it's a property of Error
, not of Error
's instances.
Am I missing something? What should a long-term solution look like in your opinion?
@alcuadrado the text isn't finalized, but it would include populating the [[ErrorData]] slot in the constructor, and it would prohibit returning different results for the same slot - ie, once observed, the stack is immutable.
@ljharb I see, thanks for the explanation.
A long-term solution for showing something similar to an async stack trace shouldn't assign anything to the actual error.stack
, but keep its data apart, right?
I think a hook on errors creation is still needed, as one would have to keep track of the async execution context at that moment.
@alcuadrado I'm still puzzled because I don't see how the error API would allow you to distinguish between errors that propagate through await
calls from errors that propagate through non-await calls (but maybe I did not dig deep enough).
Let me take 2 examples to illustrate my point, assuming promisified fs
API.
First a case with await
calls:
async function f3() { const data = await fs.readFile('invalid path'); return data[0]; }
async function f2() { const r = await f3(); return r + 1; }
async function f1() {
try { await f2(); }
catch (ex) { console.error(ex.stack); }
}
Here, no surprise. I'm expecting to see fs.readFile <- f3 <- f2 <- f1
in the stack trace
Now, let us consider calls without await
:
function f3() { return fs.readFile('invalid path'); }
function f2(promise) { promise.catch(err => console.error(err.stack)); }
function f1() {
const promise = f3();
console.log('doing something else');
f2(promise);
}
What should I get in the stacktrace?
fs.readFile <- f3 <- f1
? Stack where the promise got allocated? May be confusing because f3
completed normally and 'doing something else'
was printed on the console. A stack from the past, with ghost stack frames?promise.catch <- f2 <- f1
? Stack where the error was caught? Counter-intuitive because at odds with classical try/catch
where the stack is rooted in the try
block, not the catch
clause. Also a lot less informative.IMO the stacktrace should not contain f1
, nor f2
, nor f3
in this case, just the low level functions that invoked the callback inside the catch
method.
@bjouhier Sorry, my explanation was incomplete.
That v8 APIs aren't enough, but they can be used in conjunction with node's async-hook. The later gives you the information necessary to keep track of the different async execution contexts. For an excellent example of how to do it check trace.
@alcuadrado Fine but before diving into the how we have to know what we want to achieve. For this, it would useful to have an answer to the question that I raised above: which stacktrace would you expect to get in the second scenario above: fs.readFile <- f3 <- f1
, or promise.catch <- f2 <- f1
, or just the raw stack?
I would take a conservative approach here, which is to limit async stacktraces to the stack of frames suspended by an await
, because this is simple, natural and it can be implemented efficiently (I did it with the streamline.js transpiler and found it to be sufficient for most practical purposes).
The solutions around trace / async-hook seem more ambitious as they try to track stacks for _all_ continuation callbacks. Is this really useful? natural? Can it still be implemented efficiently (cpu but also memory)?
One advantage of limiting the feature to stacks of calls suspended by await
is that it becomes a pure _language_ feature. No dependency on a host library like async-hook; it can be implemented entirely in V8.
Async stacktraces in the browser!
@bjouhier I see your point. There are different approaches that can be taken. Having the ability to implement them in userland let the user choose.
Having your approach at language level would be useful from the get go to many people, but that should be proposed to the TC39, not to node.
@Trott There is still a lot of discussion here and it seems like some progress is being made to eventually having a solution for this. I think it would be good to reopen this issue.
Yes, but as @alcuadrado mentioned, what I'm proposing would need to be submitted to TC39. I can post to es-discuss if there is interest.
@bjouhier feel free, but until the stacks proposal progresses, there’s no concept of stacks in the language at all for you to propose changes to.
@ljharb Couldn't it be a string property. Something like awaitStack
. Actual formatting of the stack trace would be left to the engine, like current stack
property. Or a symbol, to avoid collision with existing properties.
@bjouhier i think you're misunderstanding; as far as the language spec currently is concerned, there's no such thing as stack traces, error stacks, stack frames, etc. The stage 1 proposal is the first attempt to standardize the concept - and anything stack-related would need to build off of that.
@ljharb Interesting!!
I never checked and thought that the standard would at least specify that errors have a stack
string property, but did not enforce anything else on stack format. But it does not even go that far! Error.prototype.stack
is just a de facto standard.
HERE Although not 100% relevant to the issue of async stack traces, but when you want to remember stacks using callbacks, checkout erotic
to be able to capture asynchronouse stacks! You will have to create an anchor at the point where you want the stack trace to begin, but that's the only way to deal with it ATM.
Usage:
import { readFile } from 'fs'
import erotic from 'erotic'
const read = async (path) => {
const er = erotic() // stack has the anchor point
await new Promise((resolve, reject) => {
readFile(path, (err, data) => {
if (err) {
const e = er(err) // stack also includes this line
return reject(e)
}
return resolve(data)
})
})
}
(async function example() {
const path = 'non-existent-file.txt'
try {
await read(path)
} catch ({ stack }) {
console.log(stack)
}
})()
Error: ENOENT: no such file or directory, open 'non-existent-file.txt'
at ReadFileContext.readFile [as callback] (/Users/zavr/adc/erotic/example/read-file.js:10:19)
at read (/Users/zavr/adc/erotic/example/read-file.js:5:14)
at example (/Users/zavr/adc/erotic/example/read-file.js:21:11)
at Object.<anonymous> (/Users/zavr/adc/erotic/example/read-file.js:25:3)
Instead of standard Node's
Error: ENOENT: no such file or directory, open 'non-existent-file.txt'
Or you can make it throw transparent errors (if you are a library author):
import { readFile } from 'fs'
import erotic from 'erotic'
const read = async (path) => {
const er = erotic(true)
await new Promise((resolve, reject) => {
readFile(path, (err, data) => {
if (err) {
const e = er(err)
return reject(e)
}
return resolve(data)
})
})
}
(async function example() {
const path = 'non-existent-file.txt'
try {
await read(path) // error appears to be thrown here
} catch ({ stack }) {
console.log(stack)
}
})()
Error: ENOENT: no such file or directory, open 'non-existent-file.txt'
at example (/Users/zavr/adc/erotic/example/transparent.js:21:11)
at Object.<anonymous> (/Users/zavr/adc/erotic/example/transparent.js:25:3)
Why is this issue closed?
Is there a resolution? I have found two recommendations that do not require changing code (longjohn and trace), neither of them work, the rest (fiber, f-promises, erotic) all require you to modify your code.
Why is this issue closed?
For inactivity. @Trott mentioned wanting to know if people disagree (presumably to re-open it if that was the case?). I'm fairly sure a good number of people disagree :)
A good number of people do disagree, but currently this issue seems to be thrown upstream to the V8 team/tc39. I've been following this for a while and there doesn't seem to be momentum on fixing this from the node side; if I'm wrong on that, it may be worth a core contributor stating that and limiting discussion to contributors only.
@Trott please reopen.
I really hope a solution is found before async/await spreads, the internet is already full of "why async/await is so much better than promises", debugging errors that have no pointers where they are coming from is a special kind of hell.
We are considering whether to natively offer long stack traces for async await. Nothing concrete right now though.
There is currently nothing that can be done in Node.js itself to improve the situation. I don't think we should reopen the issue as long as that's the case.
@hashseed perhaps some discussion can go into https://github.com/tc39/proposal-error-stacks on this. an Error.prototype.trace
which either represents the stack for sync or the conjoined stack/etc for async might be a positive direction.
no new things would be added to Error.prototype for this; it'd have to go on something like System, alongside getErrorStack
and friends. Please do open something for discussion on the repo, though.
I just read that entire long thread, and I still don't understand one basic thing: when/why did Node decide that stack traces are a user responsibility? Throughout most of programming history stack traces have been the responsibility of the core language.
I'm not saying that they shouldn't be a user responsibility, it's just that in all of the above I couldn't find a single post that said "this is why we're doing something no other language does, and making it your responsibility to use a 3rd-party library if you want accurate stack traces, instead of providing that functionality ourselves".
If someone could clarify this point I would find it very helpful.
@machineghost its not user responsibility, its engine responsibility. in this case, V8 has already started working on async stack traces, and at some point node will ship with a version of V8 where its enabled.
@devsnek Thanks so much for that clarification. It wasn't obvious to me from the above thread since some maintainers appeared to be saying the opposite, but your response makes much more sense..
V8 now offers an --async-stack-traces
flag! See: https://github.com/v8/v8.dev/pull/49/files#diff-af1399a75d6310211a72be0dc2571ea5R44
I'm not sure what if any Node's support this new V8 capability.
Current release (Node 11) just updated to v8 7.0; looks like the async stack traces are coming in 7.1 if I'm reading this right, so hopefully it'll be coming soon.
This V8 feature is still experimental and depends on a spec change to a particular detail of async/await. It also isn't able to reconstruct the full stack trace in some cases. But it's better than nothing. I hope you can use it by Node 12, but you probably can already check it out with Node Canary.
Just confirmed that the node version at https://nodejs.org/download/v8-canary/v12.0.0-v8-canary20181217e2f11a7b92/ supports the --async-stack-traces
flag mentioned in the article at v8 blog.
@eliranamar
Async stack traces @ 12.0
Detailed information about the implementation: https://docs.google.com/document/d/13Sy_kBIJGP0XT34V1CV3nkWya4TwYx9L3Yv45LdGB6Q/edit
Is --async-stack-traces
required in v12?
@gajus no. Those are tracked by default.
Are async stack traces supposed to work inside catch blocks? Or does it depend on the intervening code to have an async chain? They're missing for me with code like this in Node 12.16.2 at least... (connection.query involves event emitters under the hood)
I had hoped that the new Promise
created within the method would guarantee that the async stack trace gets added to whatever rejection error.
async query(sql, parameters) {
try {
await new Promise((resolve, reject) => connection.query(sql, (error, result) => error ? reject(error) : resolve(result)));
} catch (err) {
// None of these include the async stack traces...
console.error(err.stack)
console.error(new Error('Test').stack)
throw new Error('Test')
}
// but if we get here than this error does get the async stack trace
throw new Error('Test')
}
@TazmanianDI Edward j
Most helpful comment
Thanks! And to put a point on the real problem, imagine my database layer throws an error like the following:
How is this information useful to me especially if it occurred in production where I don't know what caused it? There is not a single line of code in that stack from my code and the error from the library I'm using doesn't even tell me what's really wrong. I would have absolutely no hope of figuring out what the cause of this was without reviewing every single database statement in my code.
Am I in the minority here that thinks this is major issue in trying to deal with problems?