console: do not emit error events

[addaleax]

Checklist

• make -j8 test (UNIX), or vcbuild test nosign (Windows) passes
• tests and/or benchmarks are included
• commit message follows commit guidelines

Affected core subsystem(s)

console

Description of change

Never fail for streams errors resulting from the console.* methods.

I know relatively little about the backstory here, so feel free to shoot this down quickly if it’s already been discussed and discarded.

/cc @Fishrock123

[mcollina]

this 'error' function is added over and over again at every write.
I think the function should be added after stream.write synchronously, and then removed in the callback.
Beware of not allocating any new callbacks here, we will be adding strain to the gc for nothing (they can all be top level).

[addaleax]

'error' function is added over and over again at every write.

Only if it fails? Like, maybe there’s a performance impact, but only in situations where the process current emits an uncaught exception.

I think the function should be added after stream.write synchronously, and then removed in the callback.

The error event is emitted after the callback, so I don’t think that works.

Beware of not allocating any new callbacks here, we will be adding strain to the gc for nothing (they can all be top level).

Done, thanks for pointing that out.

[mcollina]

The error event is emitted after the callback, so I don’t think that works.

Then this PR creates a memory leak, and after a single console.log is used, any 'error' event will be swallowed.

[addaleax]

@mcollina This is .once, not .on? If the callback sees an err argument, then that error will be emitted as an 'error' event, so the extra listener will be called and removed.

[mcollina]

ooh, I did not notice, sorry. Add a comment there, so it's easy to understand what's going on.

[mcollina]

LGTM if CI is green.
Some comments needed to explain what's going on.

[addaleax]

Added a bit of text for clarification.

CI: https://ci.nodejs.org/job/node-test-commit/6136/

[Fishrock123]

Previous related discussion at #9470

I'll take a look soon but this will also necessitate console.writeUnformatted/Raw so that people writing status bars etc can also avoid EPIPE and related issues.

[Fishrock123]

That would make it admittedly less browser-like but browser conformity wasn't why I revived this in the first place.

[addaleax]

@Fishrock123 I’m not sure how I feel about that yet, but notice how this change could also be applied as an/in an userland module. I assume the set of packages (like progress bars) which want a “safe” behaviour is quite overseeable?

[Fishrock123]

You can already do this in userland by just adding an error handler to stdio streams. The point is that it would be by default.

[mcollina]

@Fishrock123 I've always used direct process.stdout when dealing with progress bars. Is it customary to do it via console.log? Do you have some examples of this on npm?

Maybe those are two separate things, aren't they?

[jasnell]

hmm... can we guarantee this? For instance, if the callback ends up getting deferred by some buffering thing and some other error occurs that consumes the noop handler here....

[addaleax]

node/lib/_stream_writable.js

Lines 338 to 347 in 0a265df

	function onwriteError(stream, state, sync, er, cb) {
	--state.pendingcb;
	if (sync)
	process.nextTick(cb, er);
	else
	cb(er);
	stream._writableState.errorEmitted = true;
	stream.emit('error', er);
	}

… buffering or anything like that shouldn’t be the problem. But maybe this doesn’t work when the callback is called synchronously? I’d have to try it out but maybe @mcollina knows an answer off the top of his head?

(update: fixed link)

[mcollina]

@addaleax, technically @jasnell has a point. You will need to wrap write in a once and removeListenerpair : in https://github.com/nodejs/node/blob/master/lib/_stream_writable.js#L340-L346, if sync  is true the error is emitted before, then after.

[addaleax]

ugh right, thanks for pointing out the “right” solution for this… updated and added tests for both scenarios

PTAL

[mcollina]

@addaleax, technically @jasnell has a point. You will need to wrap write in a once and removeListenerpair : in https://github.com/nodejs/node/blob/master/lib/_stream_writable.js#L340-L346, if sync  is true the error is emitted before, then after.

[addaleax]

new CI: https://ci.nodejs.org/job/node-test-commit/6445/

[mcollina]

LGTM if CI is green

[addaleax]

@Fishrock123 Since you assigned this to yourself… what are the things you’d like to see/talk about here?

[addaleax]

ping @Fishrock123 ?

[addaleax]

@Fishrock123 It’s been a while… unless there are any objections, I’d like to land this in the next couple of days.

[jasnell]

Rather than allocating a closure here, can this be made a top level function?

[addaleax]

It can’t be top-level because it still needs access to the stream but I’ve attached these to the console object itself, does that work for you? It definitely avoids the closure problem.

[jasnell]

Hmm... going back to the earlier point, is the write operation guaranteed to be complete by the time we hit this?

[addaleax]

No but that’s not a problem. Asynchronous errors are handled from inside the callback.

[jasnell]

It would be helpful to have additional tests that verify this works with a variety of stdout/stderr configurations (e.g. stdio as a file, stdio as a pipe, etc)

[addaleax]

I’ve updated this with tests for something that errors asynchronously… the inner workings of console aren’t really tied to I/O at all, so I’m not sure it makes sense to add explicit tests for these

[jasnell]

The main thing that I'm hoping for is that this would fix the issue reported in #831

[addaleax]

CI: https://ci.nodejs.org/job/node-test-commit/7361/

[addaleax]

@jasnell please take another look when you have the time :)

[jasnell]

Reviewing now...

[jasnell]

A minor nit but generally LGTM

[jasnell]

Just to be on the safe side, there should likely be a check that verifies this version of write is being called. I'm not certain if common.mustCall() would work here.

[addaleax]

@jasnell Done, good point. (Sorry for being late, must have overlooked your replies.)

[addaleax]

CI: https://ci.nodejs.org/job/node-test-commit/7925/
CITGM: https://ci.nodejs.org/view/Node.js-citgm/job/citgm-smoker/576/
CITGM for master: https://ci.nodejs.org/view/Node.js-citgm/job/citgm-smoker/578/

[jasnell]

Still LGTM and +1 to semver-major

[addaleax]

Landed in f18e08d

[Fishrock123]

I still hold that this requires us to implement a console function with equivalent functionality to process.stdout.write() but with this safety.

[addaleax]

@Fishrock123 Sorry, what exactly are you suggesting?

[Fishrock123]

I will make a PR shortly. (hopefully)

[litmit]

This PR possible problematic.

After commit f18e08d a lot of calls console.log() cause memory leaks.

See #11568 for details.