nodejs/node

fs async functions (both callback and promises APIs) return Errors without stack trace

ZFail opened this issue · 17 comments

ZFail commented
  • Version: 13.3.0
  • Platform: Windows 10 x64
const fs = require('fs')
fs.readFile('nonexistentfile', (err) => console.log(err.stack))

What is the expected output?
The err.stack should contain error text and stack
Same as readFileSync function:

Error: ENOENT: no such file or directory, open 'nonexistentfile'
at Object.openSync (fs.js:446:3)
at Object.readFileSync (fs.js:348:35)
...

What do you see instead?
err.stack only contains error text

Error: ENOENT: no such file or directory, open 'C:\dev\projects\ntest\nonexistentfile'

fs.writeFile have same trouble
Аnother strange thing is that the error text is also different (local/absolute path)

This is sadly a known issue. Tracking the actual call site would be a significant impact for all fs functions and it is therefore not implemented so far. We tried to find solutions but failed so far.

I thought there would already be an issue for this but I failed finding it.

There’s definitely a number of userland solutions for this issue, though, e.g. https://www.npmjs.com/package/trace.

I wouldn’t mind bringing such an opt-in solution into core.

@addaleax good point, we might just add a flag for that.

can someone provide a summary of what the technical issue here is?

@devsnek tracking the original call site for the async operation. The only way to really do that is (AFAIK) to create a stack trace for all calls. So it'll reduce the average performance for successful fs calls significantly.

am i right in saying that the problem is that the error is created in c++ land while the js stack is empty?

I believe we do not even attempt to create a proper error in that case. It would not point to the actual call site.

@devsnek Yes, that is correct. The exception is created in FSReqAfterScope::Reject.

I’m actually not sure anymore if long stack trace modules solve this. Fixing this might also require us to add better async support for these kinds of operations; the error is currently created outside of the async scope, so no async tracking is available.

One thing that might be helpful for making async stack traces work better here is making FSReqAfterScope create an InternalCallbackScope (and remove the one in FSReqPromise<AliasedBufferT>::Resolve + replace MakeCallbacks with a plain Call()). That way, the error could be created inside the callback scope.

What about the fs.promises? Is it possible to add full stack traces for fs async functions?
https://v8.dev/blog/fast-async#improved-developer-experience
https://bit.ly/v8-zero-cost-async-stack-traces

@heroboy If you're talking about the await optimization proposal, that's been implemented in Node.js v12.x and up. You can check if your node binary supports it like this:

$ node --v8-options | grep async.stack.traces
  --async-stack-traces (include async stack traces in Error.stack)

Note that the optimization won't work if your program monkey-patches Promise.

@bnoordhuis , No. I know current nodejs support this. And I know only async await functions have good support to async stack traces, many Promise functions will lost the stack.So if this issues fixed, will the fs.promises functions have the full stack traces? Will you make effort to make many nodejs' promisify functions to support this?

There's no need to do anything on Node's side, if I understand your question correctly. It's all done inside V8. The one caveat is that it only works with await and native promises.

I'm in a situation where I really need stack traces to debug an fs-intensive application (a build system), yet the available information about what is necessary to achieve fs tracing is vague. From this thread I understand the following:

  • Current node versions have the ability to propagate stack traces through async calls.
  • That doesn't help because there's nothing to propagate in the first place.

The only ways to rectify the situation would then be to either change to sync fs calls or to wrap every call in a try-catch that throws its own error. Have I summed up the situation correctly?

I tested the following code on node v16.13.1 on MacOS:

// async.js
const fs = require("fs/promises");

process.on("uncaughtException", (e) => {
  console.error(e.stack || e);
});

async function main() {
  await fs.readFile("doesntexist");
}

main();

I have not yet discovered any usable environmental workaround. node -r trace ./async.js makes no difference.

Is there a solution that doesn't change the code?

I've gotten around this by wrapping the caught error in a new Error:

const fs = require(`fs`);
  try {
    await fs.promises.readFile(`filePath`).catch((err)=>{
      throw new Error(err);
    });
  } catch (error) {
    console.error(error);
  }

Something like this should work too:

  fs.readFile(`filePath`, (err)=>{
    if (err) throw new Error(err);
  });

By the way this seems to be a common issue for other JS runtimes : denoland/deno#11859 oven-sh/bun#3972 but as noted in the Deno issue Chrome actually threads the information together in the DevTools console (when inspector is enabled), so I think at least we could do something similar. I already stepped into into the promise hooks code multiple times when I tried to debug the snippet in #49045 using inspector, so obviously we already have the information - and the overhead - in that case (can't make sense of the async hook stuff myself now, at least without some effort, maybe @nodejs/promises-debugging @nodejs/async_hooks would have better clues).