nodejs / node

Node.js JavaScript runtime ✨🐢🚀✨
https://nodejs.org
Other
106.43k stars 29.01k forks source link

When `ReadableStream` read fails, stack trace does not include the line responsible #53858

Open rotu opened 1 month ago

rotu commented 1 month ago

Version

22.2.0

Platform

Microsoft Windows NT 10.0.22635.0 x64

Subsystem

No response

What steps will reproduce the bug?

Save the following code to a file and run it:

import net from 'node:net'
import stream from 'node:stream'

const socket = net.connect(90, 'host.invalid.',)
socket.on("error", e => { console.warn("socket error:", e.message) })

let myStream = stream.Duplex.toWeb(socket)

console.log("next line throws")
await myStream.readable.getReader().read()
console.log("this line will never be reached")

How often does it reproduce? Is there a required condition?

No response

What is the expected behavior? Why is that the expected behavior?

From the output, you can see there was an error, but you can't see why that crashed the process. The output should mention the line number of the read() call so that the user can add necessary error handling.

Note that --async-stack-traces does not make the output any more useful.

What do you see instead?

> node index.mjs
next line throws
socket error: getaddrinfo ENOTFOUND host.invalid.
node:internal/modules/run_main:115
    triggerUncaughtException(
    ^

Error: getaddrinfo ENOTFOUND host.invalid.
    at GetAddrInfoReqWrap.onlookupall [as oncomplete] (node:dns:120:26) {
  errno: -3008,
  code: 'ENOTFOUND',
  syscall: 'getaddrinfo',
  hostname: 'host.invalid.'
}

Additional information

A bad and easy to forget workaround is to wrap each await call.

await reader.read().catch(e => { throw new AggregateError([e]) })

A better workaround might be possible with the (discouraged) async hooks API.

rotu commented 1 month ago

related to #30944

RedYetiDev commented 1 month ago

I think this is a duplicate of the referenced issue, but I'm not sure

Nevermind, I misread that issue

rotu commented 1 month ago

With synchronous errors, erroring code unwinds the same stack, so how you got to the erroring code also tells you how that error got back out to you. But with async errors, the code path that caused the error is not the same as the code path that the error will take on its way back out (in the form of other rejected promises).

I think it would be neat if, when a Promise is rejected with an error or error-like object and then awaited, a new error object is created with the await's stack frame appended. Still not sure how to do this with async hooks.

sosoba commented 1 month ago

This is a generic two-task cooperation problem. Asynchronous waiting for data from the stream (read()) and events (ENOTFOUND) that come from the operating system. Each of them has its own call stack.

The example can be simplified:

import {once, EventEmitter} from 'node:events';

const ee = new EventEmitter();

setTimeout(() => ee.emit('error', new Error('Not found')), 1);

await once(ee, 'data');

Probably you want to see "full" stack like:

Error: Not found
    at Timeout._onTimeout (./example.js:5:13)
    at listOnTimeout (node:internal/timers:581:17)
    at process.processTimers (node:internal/timers:519:7)
    at Events.once (./example.js:7:7)

But that's impossible now. The error object (and therefore its stack) is created only once in the first task, and once only returns it without any modification. And you see short stack:

Error: Not found
    at Timeout._onTimeout (./example.js:5:13)
    at listOnTimeout (node:internal/timers:581:17)
    at process.processTimers (node:internal/timers:519:7)

Wait functions like once or reader.read would need to add wrappers internally and nesting Exception or filling stactrace.

sosoba commented 1 month ago

fs/promises methods has internal wrapper which full erase event stacktrace and put "caller" stack:

https://github.com/nodejs/node/blob/v22.4.1/lib/internal/fs/promises.js#L149-L152

Maybe ReadableStreamDefaultReader and ReadableStreamBYOBReader need the same on their read method?

sosoba commented 1 month ago

There is another workaround:

const originalRead = ReadableStreamDefaultReader.prototype.read;
ReadableStreamDefaultReader.prototype.read = async function read(...args) {
  try {
    return await originalRead.call(this, ...args);
  } catch (e) {
    if (e instanceof Error) {
      Error.captureStackTrace(e, read); 
    }
    throw e;
  }
};
rotu commented 1 month ago

Maybe ReadableStreamDefaultReader and ReadableStreamBYOBReader need the same on their read method?

I think that would be a good idea.

This is a generic two-task cooperation problem. Asynchronous waiting for data from the stream (read()) and events (ENOTFOUND) that come from the operating system. Each of them has its own call stack.

There are also exposed promises from this API like ReadableStreamDefaultReader.closed without a function call to wrap.

Here's another simplification:

const p = Promise.withResolvers()
setTimeout(() => {
  p.reject(new Error())
}, 1)

await p.promise

Probably you want to see "full" stack like:

Error: Not found
    at Timeout._onTimeout (./example.js:5:13)
    at listOnTimeout (node:internal/timers:581:17)
    at process.processTimers (node:internal/timers:519:7)
    at Events.once (./example.js:7:7)

I think I'd probably want to see both where Error was created (process.processTimers) and the site at which the promise was unhandled (the call to read).

Here's my current best attempt at a workaround that adds the second stack instead of replacing it. I think it's the same general idea as handleErrorFromBinding:

async function rethrow(p) {
  try {
    return await p
  } catch (e) {
    if (!(e instanceof Error)) {
      throw new TypeError('tried to rethrow a non-error', { cause: e })
    }
    const e2 = { name: "rethrown" }
    Error.captureStackTrace(e2, rethrow)
    throw Object.create(e,
      {
        stack: {
          get: () => `${e.stack}\n${e2.stack}`
        }
      }
    )
  }
}

await rethrow(p.promise)