node icon indicating copy to clipboard operation
node copied to clipboard

Modifying `error.message` does not update `error.stack` if `stream.destroy(error)` has been called

Open ehmicky opened this issue 3 months ago • 7 comments

Version

v21.1.0

Platform

Linux ether-laptop 6.5.0-15-generic #15-Ubuntu SMP PREEMPT_DYNAMIC Tue Jan 9 17:03:36 UTC 2024 x86_64 x86_64 x86_64 GNU/Linux

Subsystem

No response

What steps will reproduce the bug?

import {Writable} from 'node:stream'

const error = new Error('This failed')
const stream = new Writable()
stream.destroy(error)
stream.on('error', () => {})
error.message = `Additional info: ${error.message}`
// This does not print 'Additional info', but should
console.log(error)
// Error: This failed
//  at file:///...
//  ...

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

No.

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

Printed error should show "Additional info".

What do you see instead?

Printed error does not show "Additional info".

Additional information

This is due to #34103, specifically this:

Always stringify error.stack, because the small performance penalty that comes with it is worth the reduced risk of memory leaks. (I’ve confirmed that this also fixes the test with the patch below.)

As implemented in:

https://github.com/nodejs/node/blob/8a41d9b636be86350cd32847c3f89d327c4f6ff7/lib/internal/streams/destroy.js#L35

If error.message is modified later on (e.g. due to prepending some additional information), the change won't be reflected with error.stack. This is unfortunate because error.stack is used by util.inspect(), which is itself used by console.log().

ehmicky avatar Feb 10 '24 04:02 ehmicky

Shouldn't it be reported to V8 instead?

climba03003 avatar Feb 10 '24 10:02 climba03003

It seems to be working correctly on Chrome

marco-ippolito avatar Feb 10 '24 18:02 marco-ippolito

Chrome does not have stream.destroy(), so cannot be impacted by this bug.

error.stack is memoized by V8. However, this is intentional and not a bug. This issue is not reporting error.stack memoization, but the improper usage of that memoization.

The bug is that Node.js has the following line inside stream.destroy(error) in order to intentionally use that memoization:

https://github.com/nodejs/node/blob/8a41d9b636be86350cd32847c3f89d327c4f6ff7/lib/internal/streams/destroy.js#L33-L35

This workaround was meant for the unit tests, but it is creating user-facing problems.

ehmicky avatar Feb 10 '24 19:02 ehmicky

@marco-ippolito

I don't think it works in Chrome. If it works in Chrome, it will works in Node.js.

err = Error('foo')
err.stack
err.message = `bar ${err.message}`
console.log(err)

Chrome 121.0.6167.161 image

FireFox image

This issue is not reporting error.stack memoization, but the improper usage of that memoization.

I think it is a bug in V8 because the memorization of stack trace variables leads to the user cannot properly cache or recycle the error when it dispose (it is the cause of memory leak). The problem it tends to stop is not only related to the test case, but also the user environment.

If the trick err.stack pre-calculation cannot be used, then the internal should never cache the Error since it is unsafe to do so.

climba03003 avatar Feb 11 '24 05:02 climba03003

Memoizing error.stack in V8 is not a bug, it is a performance feature, which has been around for many years. Therefore it is unlikely to be removed by the V8 team.

The bug being reported relates to the Node.js stream API, in particular stream.destroy(), and is not related to Chrome.

What can be fixed though is the workaround highlighted in my initial message. It appears that this workaround was intended to fix some automated tests, but it unfortunately creates user-facing issues.

ehmicky avatar Feb 11 '24 07:02 ehmicky

What can be fixed though is the workaround highlighted in my initial message. It appears that this workaround was intended to fix some automated tests, but it unfortunately creates user-facing issues.

If the memory leak exists in test, which means it will also happen in user code. So, I don't think it only happen in test only. The proper fix means stream should keep the error in reference.

If the memory leak did not pop up in first place, there is no need of workaround. So, it is a bug in V8 which cause memory leak. Isn't it?

climba03003 avatar Feb 11 '24 07:02 climba03003

Yes, that's a good point about this not being only an issue with the automated tests, but a memory leak which could potentially be experienced by users too.

error.stack memoization with V8 has been around for around 7 years. I have actually written a few libraries to work around this specific issue (set-error-message , set-error-stack and modern-errors).

The V8 implementation might introduce a memory leak per @addaleax comment:

What’s happening is that the error.stack property refers to the full stack frames of its creation. V8 does this to be able to compute error.stack lazily as a string, instead of always formatting it directly even if it isn’t used. Those stack frames in turn can refer to the actual values of variables in that stack frame.

However, if this is the case, it is unclear how many years for this bug to be solved. It is also unclear to me whether the v8 team would agree that this is a bug. As mentioned by @addaleax:

Ask the V8 team for a solution to this. [...] The big downside is that this probably takes some time to implement.

The approach in #34103 has not been to wait for the potential V8 bug to be fixed, but instead of find a workaround right away. That workaround has a problem which (I think) might not have been anticipated based on @addaleax comment:

Always stringify error.stack, because the small performance penalty that comes with it is worth the reduced risk of memory leaks.

Beyond the small performance penalty, this workaround introduces a bigger problem: modifying error.message does not update error.stack. Modifying error.message in catch block to add some information is a common practice. It seems like this side effect might have been unforeseen, as it is not mentioned in the PR.

I am curious whether a different workaround exists that would not have this side effect. :thinking:

ehmicky avatar Feb 12 '24 22:02 ehmicky