NodeJS error with .catch and console.log promise?

Question

When I run the following code, I get different results depending on whether I was marked console.log("fnError: ", fnError) or not. This seems very unpleasant to me.

How is there a console.log call in the world that affects my promises?

 function run() { var fn = function(){ throw new Error("incorrect message"); }; // returns a promise that should fail with // an error object whose .message is "correct message" var promisifiedFn = function(){ return Promise.resolve() .then(fn) .catch((fnError) => { // commenting this out fixes things! // console.log("fnError: ", fnError); /////////////////////////////////////// fnError.message = "correct message"; throw fnError; }) } promisifiedFn().catch((e) => { console.log("caught error.message:", e.message); console.log("caught error:", e); }); } run(); 

The above gives:

 // fnError: Error: incorrect message // at fn (/Users/sam/dev/ethereum/pennyeth/js/temp.js:18:9) // at <anonymous> // at process._tickCallback (internal/process/next_tick.js:169:7) // ... // caught error.message: correct message // caught error: Error: incorrect message // at fn (/Users/sam/dev/ethereum/pennyeth/js/temp.js:18:9) // at <anonymous> // at process._tickCallback (internal/process/next_tick.js:169:7) // ... 

Pay attention to the registration of the "wrong message". And if you comment out console.log("fnError: ", fnError) , you get the following:

 // caught error.message: correct message // caught error: Error: correct message // at fn (/Users/sam/dev/ethereum/pennyeth/js/temp.js:18:9) // at <anonymous> // at process._tickCallback (internal/process/next_tick.js:169:7) // .... 

Running node 8.0.0

Answer 1

This is the expected behavior.

A registration error (which passes through util.inspect or String ) evaluates its .stack property. The stack line is not initialized when the error object is created, but is created with ease to save memory. The stack trace will contain an error message, and when you change the .message property .message it will be reflected or not in the stack trace, depending on whether it has already been created.

From the description of the V8 stack trace API :

Performance stack traces are not formatted when they are captured, but on request, the first time they access the stack property.

and the official node Error documentation :

A string representing the stack trace is generated lazily when the error.stack property is available .

Answer 2

I was able to reproduce this “error” with only 4 lines below.

 var e = new Error('first'); console.log(e); e.message = 'new'; console.log(e); 

I tried Chrome 59 and it did not have the same problem.

However, Node 7.9.0, Node 8.0.0 and Node 8.1.2 are all problems.

I reported a bug on GitHub # 13832 so that we could see what came of it.

Update 1 . To show that this is not a time issue, we can add setTimeout calls

 var e = new Error('first'); console.log(e); setTimeout(() => { e.message = 'new'; }, 1000); setTimeout(() => console.log(e), 2000); 

The problem persists even if we wait to call console.log() , which makes me think that the output is cached.

Update 2 . I got a response from mscdex on GitHub:

It is expected that what you see is a stack trace that includes an error message after creating it. The stack trace is generated lazily and only once (for performance reasons), so you see the same result both times.

If you, however, change your code to e.message output, you will see the expected output change.

Ultimately, both mscdex and Bergi say the main reason is lazy pricing.

What you are doing is probably not a common scenario, so I would not do it in the future, since the node.js command does not appear that will change this behavior.