Improve call-stacks in async fs oprations

[AndreasMadsen]

Before the patch:

fs.open('/missing', 'r', function (e) { console.error(e.stack); });

would output Error: ENOENT, open './missing/' with no stack trace.

With this patch, a complete stack trace is returned:

Error: ENOENT, open './missing/'
    at makeCallback (fs.js:296:15)
    at Object.fs.open (fs.js:325:14)
    at Object.<anonymous> (/Users/Andreas/GitHub/node/stack.js:4:4)
    at Module._compile (module.js:449:26)
    at Object.Module._extensions..js (module.js:467:10)
    at Module.load (module.js:356:32)
    at Function.Module._load (module.js:312:12)
    at Module.runMain (module.js:487:10)
    at exports.bindHistory (util.js:531:14)

The patch expose a util._bindHistory method there handle all the magic, I did not put it in fs since could be useful in other core modules. However I'm too lazy to check them now :)

The magic error API is documented at: http://code.google.com/p/v8/wiki/JavaScriptStackTraceApi

[TooTallNate]

I'm guessing this is gonna hurt performance

[AndreasMadsen]

@TooTallNate right, had not thought much about it.

I've executed ./node benchmark/fs-readfile.js, this was the result:

without patch:

read the file 106835 times (higher is better)
93606.6 ns per read (lower is better)
10683 reads per sec (higher is better)

with patch:

read the file 50342 times (higher is better)
198660.85 ns per read (lower is better)
5033.7 reads per sec (higher is better)

There is a significant performance decrease. Digging in it this is what I found:

Commenting out: https://github.com/joyent/node/pull/3816/files#L1R529

read the file 60390 times (higher is better)
165604.39 ns per read (lower is better)
6038.48 reads per sec (higher is better)

And also commenting out: https://github.com/joyent/node/pull/3816/files#L1R525

read the file 109102 times (higher is better)
91663.95 ns per read (lower is better)
10909.41 reads per sec (higher is better)

[AndreasMadsen]

Perhaps we could extend the process.env.NODE_DEBUG so it would turn this on and off.

I just speed 30 minutes, trying to find where a ENOENT bug was in a huge project. I finally gave up and wrote this patch, it barely took me one minute to fix it knowing the call stack.

I agree that the performance hit is way to big, but having this feature is a lifesaver.

[bnoordhuis]

Andreas, this is something you can do from user land by monkey-patching fs methods, right?

[AndreasMadsen]

@bnoordhuis yes, but it will require monkey-patching all fs method and possibly other methods, since there no way to interact with makeCallback (in fs) and that is too much maintenance for me.

If we had some process._beforeCallback like we have process._makeCallback then it would be reasonable to just mokey-patch that.

[isaacs]

I would not be opposed to adding a general-purpose prepareCallback function in master that would allow users to add these kinds of debugging hooks. But it would have to be a performance-neutral no-op by default.

As it is, this is just too much of a perf hit to accept. Sorry.

[domenic]

@AndreasMadsen I think this might help? It does the monkey-patching everywhere I believe:

https://github.com/tlrobinson/long-stack-traces/

[AndreasMadsen]

@domenic thanks for the tip, unfortunately it do only mokeypatch: setTimeout, setInterval, process.nextTick and EventEmitter

And from what I can see, it do not help with errors returned in callbacks.

@isaacs I will look intro it, would it be okay to just move:

// Ensure that callbacks run in the global context. Only use this function
// for callbacks that are passed to the binding layer, callbacks that are
// invoked from JS already run in the proper scope.
function makeCallback(cb) {
  if (typeof cb !== 'function') {
    // faster than returning a ref to a global no-op function
    return function() {};
  }

  return function() {
    return cb.apply(null, arguments);
  };
}

intro process.prepareCallback. It is not exactly a no-op function and I'm not sure its better, it would just be nice too know how the possibilities.

[bnoordhuis]

/me puts foot down

This doesn't belong in core. There are means to achieve this without any modifications to the core whatsoever.

yes, but it will require monkey-patching all fs method and possibly other methods, since there no way to interact with makeCallback (in fs) and that is too much maintenance for me.

So you want to dump the maintenance on us instead? :-/

[AndreasMadsen]

So you want to dump the maintenance on us instead? :-/

exactly

[AndreasMadsen]

@bnoordhuis I've created a module called async-hook, there is a process.prepareCallback implementation.

But I need the following, for it to be good:

1. To avoid constant maintenance it use the JSON formated nodecore documentation, and search for parameters named callback. But the documentation is not consistent (server.listen use the word listeningListener), could we make a general rule about always using callback for a function-as-argument there is only executed once?

2. To avoid a lot of require noise, async-hook do only monkey-patch modules you require or have required. Detecting future require calls is done by monkey-patching require('module').prototype.require which is public API (I think). Detecting already required nodecore modules is however done by looking at process.moduleLoadList and that is not public API, could we make something like process.moduleLoadList public API?

[bnoordhuis]

To avoid constant maintenance it use the JSON formated nodecore documentation, and search for parameters named callback. But the documentation is not consistent (server.listen use the word listeningListener), could we make a general rule about always using callback for a function-as-argument there is only executed once?

I'd say 'yes' but it probably won't work in practice. People won't know, forget or overlook that when writing or reviewing documentation patches.

2. To avoid a lot of require noise, async-hook do only monkey-patch modules you require or have required. Detecting future require calls is done by monkey-patching require('module').prototype.require which is public API (I think). Detecting already required nodecore modules is however done by looking at process.moduleLoadList and that is not public API, could we make something like process.moduleLoadList public API?

No. I don't see us changing it anytime soon but I reserve the right to make changes if the need arises. :-)

[AndreasMadsen]

I'd say 'yes' but it probably won't work in practice.

That sounds reasonable. And it isn't a big problem since new API won't be introduced in stable node versions.

No. I don't see us changing it anytime soon but I reserve the right to make changes if the need arises. :-)

That's very unfortunately. Async-hook needs to be something I trust a lot, since its primarily for debugging purpose and I don't want to see wrong error messages because process.moduleLoadList has changed. Do you have any suggestions?

[bnoordhuis]

Do you have any suggestions?

Keep a close eye on commits to the main repo?

[wbyoung]

It may be nice to add a note somewhere on the documentation page for the fs module that errors don't contain stack traces for performance reasons. I'll happily write a few lines to document that if the node team feels this is an acceptable idea.

After a decently long search, I ended up here, and I have finally confirmed that no stack trace for these errors is intended behavior. I suspected it was for performance, but this confirms it.

I wanted to share, though, that in searching for this, I did run across a few examples of fs.readFile or similar that actually did show a stack trace being logged. Perhaps that was an older version of node, but that added confusion. The fact that fs.readFileSync and other synchronous functions throw errors with full stack traces came as a surprise. Additionally, I somewhat expected that the NODE_DEBUG option would allow me to see a stack trace. And finally, since the err is an instance of Error, I was again surprised that there was no stack associated with it.

I'd like to politely disagree with the argument that since this can be done from user space, that it should be done that way. This is functionality built in with node, so it feels very logical to me to support stack traces to debug. If NODE_DEBUG throws errors for missing callbacks when using the fs module, why shouldn't stack traces be generated for errors working with files? If the argument is purely performance related and it's important to maintain performance with NODE_DEBUG enabled (while missing callbacks are considered programmer error), then I understand.

[othiym23]

@wbyoung This is an old PR now, and much has happened since it was filed. I think @bnoordhuis and @TooTallNate were right to be concerned about the performance implications of the original patch, and were eventually proven right about third-party modules stepping up to do the job. longjohn, at the very least, brought long stacktraces to the point of being generally useful, without requiring long stacktraces to be added to core code.

The async hooks that were discussed in this issue were eventually added to Node itself, although you'll either need to add a polyfill (in the form of the async-listener module) or deal with an undocumented / semi-hidden low-level API in Node 0.12 (when it's released) to get at them. The stackup module builds on this interface to provide (reasonably) efficient long stacktraces, and can be used to create your own tracing and introspection tools with relatively little effort (once you wrap your head around the concept, and get how it works, which does take a lot of work).

Node is never throwing away stacktrace information. It's giving you what it has – async fs operations that error will give you the stack they had when they encountered the error. The reason synchronous operations have fuller stacktraces is exactly because they're synchronous – part of what makes the asynchronous operations async is the fact that the stack gets reset at the point where Node waits for the filesystem (or whatever is causing an action to be asynchronous) to do something. If you have to generate an Error object at each of those points (which is what this patch, and all long stacktrace modules, do), you're paying the considerable cost of capturing the execution state at every async branching point as a hedge against the relatively tiny number of cases in which that can be used to provide additional context for errors. Creating the Error object is expensive, reading the stacktrace off them is expensive (because the stacktrace is generated lazily), and dealing with the garbage-collection overhead of managing all those additional objects is expensive. Combine that with the maintenance cost of keeping that code in core, and it's pretty easy to justify moving this functionality into third-party modules.

[AndreasMadsen]

I ended up implementing this issue with my trace module, which use the JSON documentation in node v0.10 and the async listener API in v0.11

Also the lack of a stack trace in fs is no different than any other node core module, e.q. the net module.

[bnoordhuis]

FWIW, I've been going back and forth on long stack traces in core.

Yes, they add overhead, especially with a naive implementation of stitching together Error#stack values.

On the other hand, trying to debug a running production application without long stack traces is a sure way to lose your sanity. Using longjohn in production is often not an option because it adds too much CPU and memory overhead.

I did a prototype for one of our (i.e. StrongLoop's) products a while ago where instead of creating a full-blown Error object, we just scan the stack and store the raw function addresses in a FixedArray (a trimmed down version of a normal JS array) with some thread-local storage hackery that matches stack traces to, for want of a better word, "execution contexts" (the chain of callbacks, to a first approximation.)

Capturing function addresses is cheap. You get slightly more page faults because you repeatedly walk the stack but that's generally noise in the numbers. Paradoxically, it's really only an issue when you do it infrequently because only then do stack pages get swapped out again.

The captured addresses don't get turned into an actual stack trace until needed. That has the downside that you have to run with --no_compact_code_space or you may end up with bogus stack frames.

That could probably be remedied by using the %CollectStackTrace() intrinsic. While a fair bit slower, it might still be preferable over --no_compact_code_space with long-lived programs.

Another solution would be to store not just the function address but a pointer to the code object as well. That has the same issue as %CollectStackTrace() - i.e. it's slower - but the difference might be insignificant. I didn't benchmark it so that's pure speculation at this point.

Apropos the FixedArray, a worthwhile optimization would be to specialize it to a type that the garbage collector doesn't scan. There are some possible caveats with that so that would require further investigation

Having said all that, I don't really have time to pursue it right now unless sponsored so if someone wants to run with it, you're welcome to.

[wbyoung]

@othiym23 I wasn't actually thinking about long stack traces. It appears that I actually misread the initial issue, thinking it was closely related.

I'm a little off topic from this conversation, but I guess it's still related. I was just thinking of the error having any stack trace. I was surprised to find errors without a stack at all.

var fs = require('fs');

fs.readFile('/path/to/nowhere', function(err, contnets) {
  console.log(err);
});

// { [Error: ENOENT, open '/path/to/nowhere'] errno: 34, code: 'ENOENT', path: '/path/to/nowhere' }

Now that you've drawn my attention back to the fact that we're discussing long stack traces here, I'm realizing that the stack trace wouldn't provide much more information anyway, but it's a little surprising to get nothing but the error message. At least other async errors give you an idea that they came from something asynchronous (allowing you to quickly arrive at the fact that they're asynchronous). For me, at least, having no stack trace doesn't really indicate that it was something asynchronous. It will now, but that's not a conclusion that I can come to quickly without seeing the trace that includes something to indicate async behavior.

I was thinking for a decent amount of time — where's the stack trace for this error, and I got tunnel vision in to trying to figure out why it had none. Was it my code that threw an error with no trace or something else? If it had a stack to begin with (even just something that said async fs starting point and wasn't really a stack trace, those thoughts wouldn't have crossed my mind.

setTimeout(function() {
  throw new Error('example async error');
}, 0);

// /path/to/script.js:10
//   throw new Error('example async error');
//         ^
// Error: example async error
//     at null._onTimeout (/path/to/script.js:10:9)
//     at Timer.listOnTimeout [as ontimeout] (timers.js:110:15)


process.nextTick(function() {
  throw new Error('example async error');
});

// /path/to/script.js:22
//   throw new Error('example async error');
//         ^
// Error: example async error
//     at /path/to/script.js:22:9
//     at process._tickCallback (node.js:415:13)
//     at Function.Module.runMain (module.js:499:11)
//     at startup (node.js:119:16)
//     at node.js:902:3

I realize that the above code is showing me my code because it's stuff that I wrote that throws an error. That's not what concerns me. The difference is that the stack trace shows me it's asynchronous via _onTimeout or _tickCallback. The error that comes back from fs calls has no indication of where it came from, no stack at all.

[othiym23]

@wbyoung If you want the stack, you need this instead of what you have now:

fs.readFile('/path/to/nowhere', function(err, contnets) {
  console.log(err.stack);
});

Because the stack is expensive to generate, err.stack is actually an accessor that generates the stack on need, and it isn't included in Error.prototype.toString by default. You're right that the resulting stacktrace isn't going to be super informative, but you'll have it.

[othiym23]

@bnoordhuis That's a good, simple approach that brings with it the cost of some additional complexity, and I'd be curious to hear what @trevnorris, as the person who would likely have to maintain that, thinks of it. This feels like it's not entirely unrelated to his AsyncWrap work, and it would be very helpful in a lot of cases to be able to cheaply realize long stacktraces. Not super jazzed about requiring --no-compact-code-space, though.

[wbyoung]

@othiym23 for that, I just get Error: ENOENT, open '/path/to/nowhere'.

These were some of the first things I tried. Also,

  for (name in err) { console.log(name); }

Just gives me errno, code, and path.

At this point, I have good understanding of what's going on. It makes sense, and I'll remember this as I see this in the future. It still just surprises me to see no stack trace on there.

[trevnorris]

I worked a long time on #7145 to help with these cases. This way users would be able to implement their own long stack trace implementation, but with more fine-tuned control over what they'd actually be tracking, and when they'd be tracking it.

@tjfontaine has said the AsyncListener stuff won't make it into 0.12, but in another module instead. I'm not sure what's going on with that, but fwiw that PR should allow users to easily keep track of long stack traces.

BTW: I've kept the PR up-to-date w/ latest master in the chance it actually gets merged into core.

[stefanpenner]

an opt-in performance hit ala DEBUG_FS would really help some gnarly debugging sessions.

[domenic]

+1, this is one of the big remaining areas where even when you pull out all the tricks (e.g. domains, long stack trace modules) Node is inferior to other programming environments.

I know we're waiting for AsyncListener's future evolution to bring the perfect instrumentation/debugging features for everything stack-trace related but in the meantime just a "good enough" mode where fs, net, etc. errors actually have stack traces would be super nice.

[bnoordhuis]

Doesn't longjohn work for that? There is minimal long stack trace functionality built into the fs module but it's only for when you forgot a callback. Compare:

$ node -e 'require("fs").stat("fail")'
fs: missing callback Error: ENOENT, stat 'fail'

$ env NODE_DEBUG=fs node -e 'require("fs").stat("fail")'
fs: missing callback Error: ENOENT, stat 'fail'
    at rethrow (fs.js:64:21)
    at makeCallback (fs.js:103:12)
    at Object.fs.stat (fs.js:673:14)
    at [eval]:1:15
    at Object.<anonymous> ([eval]-wrapper:6:22)
    at Module._compile (module.js:456:26)
    at evalScript (node.js:536:25)
    at startup (node.js:80:7)
    at node.js:906:3

[stefanpenner]

@bnoordhuis as far as i can tell that stops being useful as soon as you actually attach a callback. The resulting errors stack doesn't appear useful.

[trevnorris]

We're not going to override (i.e. "monkey patch") native functionality. It's not Node's place to do such things.

[AndreasMadsen]

Somhow you don't see the latest changes, maybe it is because the PR is closed.

[llafuente]

Could be another aproach you could test.
Save the Argument object, remember calee property (the deprecated one that will never disapear, i hope) could generate a similar stack trace only when needed.

Seems resonable to use a deprecated property ?
Notice strict mode.

[bjouhier]

There are already several userland solutions that address the stack problems. Please don't make any change that would break them or slow things down for everyone. If people want better stack traces they can use existing userland solutions (or invent their own).

Allocating an Error object is very costly.

IMO, stack traces should reflect the language that you are using:

• If you choose to stick to vanilla JavaScript (no fibers, no preprocessor) then you should expect to get what the native JS engine gives you (i.e. the current callback's stack).
• If you are ready to go with a language extension that provides some kind of sync abstraction over continuation callbacks (syntax may vary), then you should expect err.stack to reflect the "long" stack.
• If you want something in-between (long stacktrace with vanilla JS) you should get it from a library, not from some kind of monkey patch.

[trevnorris]

@AndreasMadsen Yeah, seems that the force push to the branch is not preventing us from reopening the PR, even if we wanted to.

As @bjouhier stated, there are plenty of user-land modules to handle this type of thing. And in the future, once the AsyncListener API is hammered out, Node will introduce bindings that allow users to tap into this functionality more easily. But for now Node isn't going to implement changes this way. It's fundamentally a hack and we're working on adding more expressive APIs that allow developers to implement this type of functionality the way they want.

[domenic]

@trevnorris so the official node core position is that all async fs calls will, out of the box, have empty stack traces forever?

[trevnorris]

@domenic node core's official position is that we don't manually jack with stack traces by storing an error object prior to running the function just so the stack can be appended if there is an error on the return. It's a hack and ridiculous request. We are working on APIs to allow users to implement modules that achieve this type of functionality and more, but we aren't going to make everyone suffer by constantly generating stack traces for every fs call.

[domenic]

@trevnorris I'm not really interested in Node core's position on the implementation mechanisms. I am interested in your position on whether fs will have usable stack traces out of the box, however that is achieved.

It sounds like the answer is officially no?

[stefanpenner]

@domenic ya, if you need to debug your fs code it must be over engineered. You should try breaking it into smaller modules...

in all seriousness i hope that (at least in some debug mode) node can provide sensible stack traces here. I know this isn't the browser, but the recent effort in that space to optionally add stacks across all async boundaries has improved developer ergonomics dramatically. Similar performance concerns exist, so it is disabled by default, but can be enabled when a problem arises.

[trevnorris]

@domenic As much as developers seem to ignore this fact, the implementation mechanism is a huge consideration on what goes in. So the question isn't

whether fs [should] have usable stack traces out of the box

The question, at this moment and in the implementation case, is whether we'll allow a new Error() to run for each call to fs.*(). Your phrasing of the question makes it sound like, "Do you want Node to suck less or not?".

The answer is no, we won't allow new Error() to be run for every fs.*(). As @stefanpenner pointed out, we're working on the ability to allow users to add their own stack traces. This way it simultaneously addresses 3 concerns: 1) Introduce a uniform way to trace asynchronous calls, instead of one-offing solutions per module; 2) Allow users full implementation flexibility in how they want stack traces done; 3) Don't introduce the performance hit unless explicitly requested by the user.

[domenic]

It feels like you are dodging the question, but I think it may be because I have been unclear why I am asking.

I am asking for a statement from Node core that I can take to other developers who are just learning Node. These developers do not care about new Error() or any user-extensible mechanisms for adding stack traces. They do care about debuggability (at least on par with other async languages), and probably do care about performance as well.

I am hoping you can give me a statement I can take to them. Hopefully you see when I frame it this way that "we won't allow new Error() to be run for every fs.*()" is not a useful statement in that regard.

An example of a useful statement would be e.g. "fs will never have usable stack traces out of the box," or "fs will never have usable stack traces out of the box because it is technically impossible to do that without a 27x slowdown, in the context of Node's current architectural choices," or even "fs will never have usable stack traces out of the box for performance reasons, but you can use a command-line argument to get usable stack traces during your debugging sessions" (a la #3816 (comment)).

Can you help me out by giving me such a statement I can communicate to those learning Node or coming to it from other runtimes and languages?

If I had to guess, your current position would be "fs will never have usable stack traces out of the box, but in the future you may be able to find a third-party module that intercepts fs calls and gives them usable stack traces." But I would rather not guess, since I don't want to put words in your mouth.

I think this kind of developer communication, on a non-implementation level, is important.

[llafuente]

How about: Solve it in C++ with a build option to remove performance hit (i would prefer an argument but should be enough)

You can eval JS code in C, well, why not eval new Error() inside an #ifdef, I hope stack trace is right, maybe the first step is wrong but the rest should be ok.

I didn't see any way to create an error without eval in v8 API apart from ThrowException

any reasons this should not work ?

[trevnorris]

@domenic The mere phrase

"fs will never have usable stack traces [...]"

is complete opinion and non-technical. Please tell me you can at least see that.

Here's an official, and technically correct, answer:

Node.js does not, by default, generate stack traces that extend beyond the life of synchronous code execution because the performance penalty is too high. Node is currently working on an API that will allow in-depth analysis of all asynchronous code execution uniformly across all native Node modules. Including the ability to generate "long" stack traces.

If that doesn't convey the appropriate information you need then I'm not sure what to tell you.

@llafuente A build option to remove performance penalties isn't an option.

[domenic]

Sure. When I am asked "why are fs's stack traces useless" I will answer "well actually, the correct term is 'does not extend beyond the life of synchronous code execution'".

Sounds good, and thanks for your time.

[trevnorris]

@domenic np :)

[bjouhier]

@domenic
Repeating myself a bit: if developers want stack traces that span across continuation callbacks they should use a language or runtime extension with sync semantics.

Some of these solutions have very little runtime overhead (a lot less than new Error()) and they have been available for 3+ years. If you use them you get meaningful stack traces across all async APIs, not just fs.

These problems (stack trace, exception handling and usability) should be addressed at the language level, not at the node level. The day we'll have some kind of async/await baked into the language, we'll get this solved. In the mean time we are just hacking around.

Note: ES6 does not yet provide any API to get stack frame information from a generator (find out where it is currrently yielding). With this kind of API we can very efficiently reconstruct long stack traces from generators. See https://github.com/bjouhier/galaxy-stack. IMO, it is more important to push for features languages like this (I submitted the request to es-discuss several months ago) than to to push for hacks in node core.

[domenic]

@bjouhier I will repeat what I have said many times already in this thread. This bug is not about long stack traces, and I don't want those. I just want short stack traces, whereas currently fs has no stack trace at all.

[trevnorris]

@domenic I'm sure you understand this, but for posterity might as well explain it in detail.

The stack trace generated by the error only shows the synchronous execution. The callback passed to asynchronous fs functions is called from node::AsyncWrap::MakeCallback() when the call is complete. So if we included the native functions in the call stack, it would look something like:

Error: ENOENT, stat
    at node::AsyncWrap::MakeCallback() (src/async-wrap-inl.h:184)
    at node::After() (src/node_file.cc:236)
    at uv__fs_done() (deps/uv/src/unix/fs.c:870)
    at pthread_once()

Note: Actually MakeCallback() wouldn't show up in the call stack because it's marked as inline, and hence there's never any actual function call.

Unfortunately we're not able to include native calls in the JS stack traces. Honestly that's a feature I would like to have, but alas it's not available.

[wbyoung]

@trevnorris I've been following the conversation that you've been having with @domenic and appreciate your feedback.

I have one followup question regarding fs errors containing some sort of stack trace. Please keep in mind that it's been a while since I looked at the Node code, and I've only ever looked at it, so I don't have the same level of understanding that you have.

My question is along the same lines as @domenic's and pertains to stack traces (and not long stack traces). I fully understand that creating a new error for every fs call would cause performance problems. I'm curious if you are also concerned with performance in the case where errors do occur. The reason I'm asking is because it seems like there's a middle-ground here: call new Error() only once it's known that an error has occurred rather than when the function begins.

The issue that I imagine is that sometimes there will be frequent calls that are expected to fail and not wanting to add a performance hit because of that (for instance, trying to remove a file, but not caring if it's not there & this happening frequently).

Please also see my previous comments about lack of any stack information. I wouldn't even care if the stack was generated at compile time rather than at runtime. It could even be a fake stack. Just some sort of indication that this error came from some sort of async thing internal to Node would certainly make the mental jump during debugging easier.

In reading my comments, please understand that I've read the discussion and mention of things like asyncListener. I'm really just adding my +1 to @domenic's sentiment. Having worked with a lot of languages over time including JS in the browser, I found the lack of stack trace lead me down the wrong path & think this could be improved for everyone.

Thanks in advance for your response.

[bjouhier]

What about the following wrapper (userland, of course)?

var fs = require('fs');
// list is incomplete ...
['stat', 'readFile', 'writeFile'].forEach(function(name) {
    var fn = fs[name];
    fs[name] = function() {
        var cb = arguments[arguments.length - 1];
        if (typeof cb === "function") {
            arguments[arguments.length - 1] = function(err) {
                if (err) {
                    var e = arguments[0] = new Error(err.message);
                    e.errno = err.errno;
                    e.code = err.code;
                }
                cb.apply(this, arguments);
            }
        }
        return fn.apply(this, arguments);
    }
});

It will give you the source line of the callback in fs module and it will only allocate an Error if the call fails.

[AndreasMadsen]

@bjouhier I don't see how that is particularly helpful. But it inspires an interesting question: @trevnorris could we add the name of the fs function to the error message. That would provide information there could reduce the search from say fs.read to fs.readFile.

[bjouhier]

@AndreasMadsen
Well, before:

/Users/bruno/dev/junk/better-fs-stacks.js:23
    throw err;
          ^
Error: EISDIR, read

After:

/Users/bruno/dev/junk/better-fs-stacks.js:24
    throw err;
          ^
Error: EISDIR, read
    at arguments.(anonymous function) (/Users/bruno/dev/junk/better-fs-stacks.js:12:29)
    at fs.js:237:16
    at Object.oncomplete (fs.js:107:15)

[AndreasMadsen]

I will elaporate then, (you should do the same, such as explaining why it is useful):

at arguments.(anonymous function) (/Users/bruno/dev/junk/better-fs-stacks.js:12:29)

This line just refer to the part of the code there monkey-patches the fs methods. It is just noise.

at fs.js:237:16

This line refer to fs.readFile (I don't know your node version, so I'm guessing). I'm saying that extending the error message with this information would be more useful.

at Object.oncomplete (fs.js:107:15)

This line just means that it was an async fs method. Not more useful that the line above.

[bjouhier]

@AndreasMadsen The second line is the key information that you were looking for and that you did not have at all before.

Yes, you have to look into fs.js to find the name of the source function. This could be improved at no cost by naming these callbacks in fs.js.

And this is pure userland wrapper, with little runtime overhead (much less than a systematic call to new Error()).

[trevnorris]

@wbyoung

The reason I'm asking is because it seems like there's a middle-ground here: call new Error() only once it's known that an error has occurred rather than when the function begins.

That's exactly what currently happens. We don't know if there's an error until uv_fs_*() has run its callback. At which time Node generates an error and returns it to the user. I tried to make that clear by showing the call stack that included the native function calls.

I wouldn't even care if the stack was generated at compile time rather than at runtime.

That's impossible to do. You might as well just grep the source code for all the calls to the fs function in question.

Just some sort of indication that this error came from some sort of async thing internal to Node would certainly make the mental jump during debugging easier.

The fact the error is being analyzed from within a callback is 100% indication that the call was made asynchronously. e.g.:

fs.stat('/not/here/', function statComplete(er) {
  // The error wasn't automatically thrown, and instead passed to
  // a callback, so we know the call was asynchronous.
});

@AndreasMadsen

could we add the name of the fs function to the error message. That would provide information there could reduce the search from say fs.read to fs.readFile.

I think improvements can be made. For example, in fs.readFile() it first has to do a fs.open(). If an error occurs during this phase, currently, we just pass the error to the callback. Here's the code:

  fs.open(path, flag, 438 /*=0666*/, function(er, fd_) {
    if (er) return callback(er);

Whereas we could instead generate more informative information since we know the callback is being made from within fs.readFile(). Same with the fs.fstat() that has to be called within fs.open().

So it does seem there can be improvements made to some fs functions. Specifically those that have to chain asynchronous calls together in order to accomplish the request.

@domenic Is the above more along the lines of what you were requesting?

[wbyoung]

@trevnorris the last time I tried this, I ended up with no stack property on the error, though. Are you saying that may have changed (was fixed) and the error should contain a stack?

[bjouhier]

@wbyoung It's not fixed in 0.10. The before/after output that I posted above was generated with 0.10.27. With vanilla fs, the stack trace is empty. With the wrapper you get at least a line number in fs.js.

This is not a complete surprise though: the exception occurs in C++ code, outside of any JS stack. So, if there were to be a stack trace on the original exception it would have to be a C++ stack, not a JS one. In the little wrapper that I gave above, I transform the C++ exception into a JS exception, to get a JS stack.

But note that this JS stack reflects the context where the exception was wrapped, not the context where the original exception was thrown.

[wbyoung]

@bjouhier the stack trace is empty or there's no stack property at all on the Error object?

[bjouhier]

@wbyoung The stack property is not empty but it just contains the error message. For example: Error: EISDIR, read