process: swallow stdout/stderr error events #9470

Fishrock123 · 2016-11-04T20:01:26Z

Checklist

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

Affected core subsystem(s)

process, console

Description of change

This is a step in making console safe, swallows EPIPE and other
errors by registering an empty 'error' event listener.

Also fixes writes to stdout/stderr not working after end() is called,
even though we already override destroy() so the stream is never
actually closed.

Refs: #831
Fixes: #947
Fixes: #9403

Mentioning some people from issue #831 "console should be safe": @vkurchatkin, @benjamingr, @nodejs/streams

(This patch was made live during https://www.twitch.tv/nodesource/v/98991703 if you'd like to see me working on this in retrospect. :P)

This is a step in making `console` safe, swallows EPIPE and other errors by registering an empty 'error' event listener. Also fixes writes to stdout/stderr not working after `end()` is called, even though we already override `destroy()` so the stream is never actually closed. Refs: nodejs#831 Fixes: nodejs#947 Fixes: nodejs#9403

Fishrock123 · 2016-11-04T20:05:02Z

lib/internal/process/stdio.js

+    //   get() {
+    //     return true;
+    //   }
+    // });


@nodejs/streams this affected some other tests but I wasn't able to tell why.

=== release test-http-chunk-problem === Path: parallel/test-http-chunk-problem assert.js:85 throw new assert.AssertionError({ ^ AssertionError: '8c206a1a87599f532ce68675536f0b1546900d7a' == 'bafcbe972b6e69cd415ded38cb995f1bca983929' at cp.exec (/Users/Jeremiah/Documents/node/test/parallel/test-http-chunk-problem.js:55:20) at ChildProcess.exithandler (child_process.js:202:7) at emitTwo (events.js:106:13) at ChildProcess.emit (events.js:191:7) at maybeClose (internal/child_process.js:877:16) at Socket.<anonymous> (internal/child_process.js:334:11) at emitOne (events.js:96:13) at Socket.emit (events.js:188:7) at Pipe._handle.close [as _onclose] (net.js:501:12)

&

=== release test-stdin-pipe-large === Path: parallel/test-stdin-pipe-large assert.js:85 throw new assert.AssertionError({ ^ AssertionError: 131072 === 1048576 at Socket.child.stdout.on.common.mustCall (/Users/Jeremiah/Documents/node/test/parallel/test-stdin-pipe-large.js:22:10) at Socket.<anonymous> (/Users/Jeremiah/Documents/node/test/common.js:421:15) at emitNone (events.js:91:20) at Socket.emit (events.js:185:7) at endReadableNT (_stream_readable.js:974:12) at _combinedTickCallback (internal/process/next_tick.js:74:11) at process._tickCallback (internal/process/next_tick.js:98:9)

(The current patch works, but I think maybe having destroyed = true by default always would work better?) 9I don't think we can re-set it after destroy() and not hit what it is needed to skip.

addaleax · 2016-11-04T20:05:31Z

lib/internal/process/stdio.js

      er = er || new Error('process.stdout cannot be closed.');
      stdout.emit('error', er);
    };
    if (stdout.isTTY) {
      process.on('SIGWINCH', () => stdout._refreshSize());
    }
+    stdout.on('error', () => {});


I am not sure this is a good idea. If my program writes stdout to a file and that fails, it should definitely not pass silently – if this is about making console safe, maybe something more specific to console would be a better idea?

Hmmm, perhaps. I'd like to have a bit more discussion, I don't know if throwing from stdio on process is a good idea either. There are a lot of libraries that do raw writes that could be affected by e.g. EPIPE from an outside source, and that doesn't really make sense to crash on IMO.

I'm not convinced that we should do this in the first place. I'm with @addaleax.

Even if we land, a comment on why that handler is there is 100% needed.

Another -1. Hiding failure != safety.

mcollina · 2016-11-05T09:47:41Z

I'm generally 👎 on haltering how the stream internals work for specific cases, as they make code brittle, and can cause failures in unrelated areas of the codebase, as you discovered.

The problem of this fix is that after https://github.com/nodejs/node/blob/master/lib/internal/process/stdio.js#L12 is emitted, that stream should not be used again. If we want to achieve this, we need to "refresh" the _writableState, and restore the stream to a pristine state. Maybe we can just allocate a new one.

I agree that console should be safe.

Side note, maybe we should all sit together at the next collaborator summit and discuss some goals on stdout/stderr, as the current situation is very complex.

Fishrock123 · 2016-11-05T13:48:30Z

I'm generally 👎 on haltering how the stream internals work for specific cases, as they make code brittle, and can cause failures in unrelated areas of the codebase, as you discovered.

While I don't disagree with this, I'm not really sure there are other reliable ways of doing that that catch all cases. (That is, things that need to not print newlines need to use process.std{io}, and I still think thrown EPIPE from an external source there is probably bad behaviour from a user perspective. (Hint: I am a user here.)

The problem of this fix is that after https://github.com/nodejs/node/blob/master/lib/internal/process/stdio.js#L12 is emitted, that stream should not be used again.

I'm going to disagree here, I feel like overriding this specifically says "tell the user the operation you just did cannot be done but do not actually close (i.e. move on)".

Do you have a different interpretation of that?

Alternatively, would it work to not fix the second "bug" then and always emit these errors, but still not throw them? (I could live with that I think, but I still think it is rather confusing.)

If we want to achieve this, we need to "refresh" the _writableState, and restore the stream to a pristine state. Maybe we can just allocate a new one.

I unsure how much overhead re-allocating would be, maybe I could try it.

I agree that console should be safe.

I think guaranteeing safety there will cause much confusion that stdio itself is not. I don't like that inconsistency one bit.

Side note, maybe we should all sit together at the next collaborator summit and discuss some goals on stdout/stderr, as the current situation is very complex.

Agreed, will you be at the Collab summit in Austin?

benjamingr · 2016-11-05T13:54:32Z

I think this is the lesser of two evils so I'm generally 👍 on this.

jasnell · 2016-11-06T00:30:33Z

I'd started down this path a while back and opted not to pursue it for the same concerns that have been expressed already. I believe that @bnoordhuis had suggested at some point having stdout/stderr automatically reopen to /dev/null (or platform equivalent) if they became invalid or closed at any time. Not sure if that's a great option either, however. Not entirely sure yet how this should be fixed but I'm reasonably certain that I'm -1 on this particular approach.

jasnell · 2016-11-06T00:31:08Z

lib/internal/process/stdio.js

@@ -8,26 +8,64 @@ function setupStdio() {
  function getStdout() {
    if (stdout) return stdout;
    stdout = createWritableStdioStream(1);
+
+    Object.defineProperty(stdout._writableState, 'ended', {
+      set() {},


value: true ?

mutually exclusive with getters and still overwritable.

Fishrock123 · 2016-11-06T00:33:32Z

Not entirely sure yet how this should be fixed but I'm reasonably certain that I'm -1 on this particular approach.

@jasnell are you talking about the state manipulation or general errors from stdio?

jasnell · 2016-11-06T00:34:55Z

I'm referring most specifically to intercepting the errors from stdio. I'm +1 on making console writes safe, just don't think this is the way to do it.

addaleax · 2016-11-06T13:37:36Z

I think guaranteeing safety there will cause much confusion that stdio itself is not. I don't like that inconsistency one bit.

I find it interesting that in my head this difference seems completely consistent – stdio are streams and should behave more or less like all other I/O streams (it’s weird enough that you can’t end() them for some reason?), whereas console is mostly a debugging help that is more of a “best effort” thing anyway.

Fishrock123 · 2016-11-06T13:57:25Z

Another option would be to add a console#rawWrite() to cover the regular uses of process.stdout.write() that does no formatting and does not append /n. In that case we may be able to try/catch... or register a handler there.

That differs more from browsers, but we aren't guaranteeing any consistency there anyways.

mcollina · 2016-11-06T14:07:09Z

@Fishrock123 that might be a very good idea. Even _rawWrite, if we think it's just for internal use.

Fishrock123 · 2016-11-06T14:10:53Z

if we think it's just for internal use.

I think that would probably defeat the purpose.

mcollina · 2016-11-06T14:14:25Z

Maybe I did not understand: can you make an example on how you would use rawWrite vs console.log or process.stdout.write?

Fishrock123 · 2016-11-06T14:15:49Z

If we make only console safe, we need a way to write via the console that does no formatting and does not append a newline. That is, make alternatives to using process.stdout.write directly that are still "safe".

mcollina · 2016-11-06T14:22:33Z

Ok, I'm on board.

sam-github · 2016-11-18T15:56:16Z

I'm having trouble understanding the goal of this from the commit message and PR conversation.

This is a step in making console safe, swallows EPIPE and other
errors by registering an empty 'error' event listener.

How is ignoring errors "safe"? If I write some code that writes to stdout with console.log, are you taking the position its OK if that output never gets written to stdout, and my code never knows that it didn't?

Also fixes writes to stdout/stderr not working after end() is called,
even though we already override destroy() so the stream is never
actually closed.

Why do we do that? Shouldn't end mean... "end"?

jasnell · 2016-11-18T17:18:48Z

I much refer going the console.rawWrite() approach but there need to be two (one each for stdout and stderr). Perhaps console.rawout() and console.rawerr()?

Also, I'm not particularly fond of the idea, but it may be worthwhile considering a flag that would allow users to opt-out of console safety in the off chance that this kind of change breaks existing code that is dependent on failures.

bnoordhuis · 2016-11-18T20:37:05Z

Gawd no, not more flags. No fan of adding non-standard console methods either. The people pushing for these changes should present a convincing argument why the currents fails-when-kaput behavior is so bad that it needs changing.

I believe that @bnoordhuis had suggested at some point having stdout/stderr automatically reopen to /dev/null (or platform equivalent) if they became invalid or closed at any time.

That's a different kind of safe, it's to block an attacker from redirecting stdout or stderr to a socket that they control.

jasnell · 2016-11-18T20:38:23Z

lol.. as I said, I'm not particularly a fan of the idea.

Fishrock123 · 2016-11-18T21:17:17Z

No fan of adding non-standard console methods either.

Our console is already non-standard and we haven't worked to make it standard, so... shrug.

The people pushing for these changes should present a convincing argument why the currents fails-when-kaput behavior is so bad that it needs changing.

It fails user expectations pretty badly. See also #831

sam-github · 2016-11-18T21:30:35Z

It fails user expectations pretty badly. See also #831

Can you enumerate the expectations? Is the only user expectations here the one in #831?

Its hard to read the minds of users, but it looks like that specific user thinks of node's console.log as-if it was a browser's console.log, a best effort to dump some text into a place a developer could see it, if they had the browser dev tools open. As such, use of console should never throw an exception, because its a debug tool... if things are going wrong, you don't want them to go more wrong when you start dumping debug info to the debug console!

That's fair, that is one user groups "expectation".

But node doesn't have a dev tools console, and node's console.log doesn't direct to some magical dev-only place... it writes to stdout.

So basically, this user expects to use console.log like a terminal is a browser dev console, despite that fact that it is not.

There are many more complaints of people exiting before the event loop drains, and reporting that their output did not actually hit screen or disk. Those people expect console to be reliable, and this "safe" option is going the other way.

I'm thoroughly -1 on this based on #481, but if there are other "user expectations" you can link to, I'd like to see them.

jasnell · 2016-11-18T21:36:26Z

fwiw, there are cases where console.log will actually EPIPE unexpectedly when stdout/stderr are pipes and the other end closes (and we have no way of detecting the close). Whether or not that is enough of a justification, I'm not convinced.

sam-github · 2016-11-18T21:40:45Z

@jasnell justification for what, this PRs approach of discarding all errors? Or justification for making sure errors are emitted, so the user can decide to ignore them if they want, or know that they failed to write to stdout if they want that? I think its justification for the latter, probably obvious from my last comment.

jasnell · 2016-11-18T21:44:17Z

Justification for making console writes safe for whatever definition of safe you want.

sam-github · 2016-11-18T21:48:06Z

Everyone wants safe, its self evidently good! :-) And so not such a useful word... some think silently discarding user output is safe, some think its unsafe. Would be nice to have a better word, but I'm out of ideas ATM.

Fishrock123 · 2016-11-21T15:34:10Z

The expectation is that console.*() alone will never terminate your program.

sam-github · 2016-11-21T16:30:05Z

@Fishrock123 who's expectation? Please respond to #9470 (comment)

You are in danger of just repeating the same claim that users expect console.log to silently discard data, over and over. Back it up. I am a user, too, and have fair number of code bases where we very carefully let the event loop drain so that data from console.log is guaranteed not to be truncated by process.exit, it is certainly not our expectation that console.log silently discard data.

jasnell · 2016-11-21T16:37:23Z

I believe the idea is that not all (or even perhaps most) Node.js users are aware that carefully allowing the event loop to drain in order to capture all of the console.log output is something they're supposed to do.

sam-github · 2016-11-21T16:53:27Z

@jasnell That is tangential: I'm saying we go through some trouble already to make sure we get all output from console.log, so sabotaging our efforts by making console.log unsafe (silently discarding output) is not meeting our expectations.

The issue tracker is full of people complaining about calling console.log but not getting the output, for various reasons.

There is one issue where someone mistakenly thought console.log functions like it does in a web browser, an understandable mistake, but a mistake non-the-less.

I suggest that pretty much everyone who comes to node from any other env other than browser-side js thinks (rightly, up to this PR) that console.log is the equivalent of ruby/C/C++/python/java/etc/etc's output routines, not a browser debug facility. This PR will conflict with their expectations.

Fishrock123 · 2016-11-22T15:30:56Z

At the very least it is my expectation, and those issues imply it is other also.

It's quite ridiculous that piping into e.g. head -1 crashed by default. 🤦

Fishrock123 · 2016-11-22T15:31:13Z

(Spoilers: I use Node too.)

sam-github · 2016-11-22T15:58:27Z

% ruby p.rb | head -n 1
hello
p.rb:2:in `write': Broken pipe @ io_write - <STDOUT> (Errno::EPIPE)
        from p.rb:2:in `puts'
        from p.rb:2:in `puts'
        from p.rb:2:in `<main>'
% cat p.rb
while true do
  puts "hello"
end

I think I could write similar code in pretty much any language except the browser, which does not even have stdout or pipes, and has a radically different console from a normal terminal.

So, what you call "facepalm" is what pretty much every other programming language does.

@Fishrock123 I know its your expectation, and I respect that, and even understand why you might have that expectation, and certainly understand why a browser developer would have that expectation.
The question is.... does anybody else other you and one other browser dev you've found expect console.log to discard output?

addaleax · 2016-11-22T16:03:41Z

So, what you call "facepalm" is what pretty much every other programming language does.

That may be the case for Python, Ruby and Node because they freely use exceptions as part of their standard library, so it doesn’t really apply to “pretty much every other programming”. In C or C++, you could just not check for errors and be fine with that.

certainly understand why a browser developer would have that expectation.

That browser developers have an easy path into the back-end side is one of the main reasons for Node’s success IMHO.

does anybody else other you and one other browser dev you've found expect console.log to discard output?

I would expect console.log to never fail, in part because it doesn’t seem to expose any mechanisms for failing in a programatically accessible way, unlike process.stdout which does.

mcollina · 2016-11-22T16:13:59Z

@sam-github:

The question is.... does anybody else other you and one other browser dev you've found expect console.log to discard output?

we should respect the fact that people accustomed to console.log in the browser will find console.log in node different.

IMHO this difference is not solvable. They should be different, because the runtime env is completely different. I'm ok in a node --browser-console that automatically re-routes console.log to the Chrome devtools. That will solve the issue, but unfortunately is not possible (or maybe it is, but it is something completely different from this).

@addaleax

I would expect console.log to never fail, in part because it doesn’t seem to expose any mechanisms for failing in a programatically accessible way, unlike process.stdout which does.

I agree with you, but I want to retain the possibility for process.stdout to fail. Preventing process.stdout to fail will cause all sort of problems in any stream processing. I think we need to find a way to reconcile these two, and allow console.log to swallow errors, but process.stdout not to.
Production software will not use console.log directly, but rather some logger API on top of process.stdout.

addaleax · 2016-11-22T16:20:07Z

@mcollina Yeah, totally agreeing, I think the process.stdout behaviour is correct here. After all, EPIPE and stuff are there for a reason.

sam-github · 2016-11-22T16:55:40Z

In C or C++, you could just not check for errors and be fine with that.

A C prog would get SIGPIPEd, and would terminate with a status indicating that, unless it ignored SIGPIPE, the equivalent of choosing to do process.stdout.on('error', function(){}).

C++ iostreams I haven't used much, don't know how errors are signalled, but a c++ prog would also get SIGPIPEd unless it arranged to ignore it.

AFAICT, with this PR, the following node program would never exit:

function write() {
  console.log("hello");
  setImmediate(write)
}
write();

when called like node prog.js | head -n1.

Even if desireable, I don't think there is a way for console.log to ignore only errors related to the buffers it wrote to the process.stdout stream, without causing errors for all buffers written to the stream to be ignored. That doesn't seem to fit the stream model.

addaleax · 2016-11-22T17:30:06Z

Even if desireable, I don't think there is a way for console.log to ignore only errors related to the buffers it wrote to the process.stdout stream, without causing errors for all buffers written to the stream to be ignored.

What would you think of something like addaleax@78beb44? It’s kind of an ad-hoc solution but it does work.

mcollina · 2016-11-22T17:36:10Z

@addaleax I'm very 👎 on anything that touches streams to fix a specific issue somewhere else.

addaleax · 2016-11-22T17:52:52Z

@mcollina Yeah, don’t disagree. (But I wonder whether this is actually a deficiency in the streams API that should maybe be addressed there.)

Anyway, addaleax/node@299f647 seems like a better way, and one that I would feel comfortable PRing. (Edit: #9744)

sam-github · 2016-11-22T18:12:16Z

@addaleax Streams are a rats nest I don't feel qualified to comment on, but your code does seem to work to my non-expert eyes.

Also, I don't agree that console should behave like it does in the browser :-), I think it should behave like it does in languages that have stdout!

If I could change history, I would not have console be named 'console' at all, I'd have it be named something that makes it clear that it is not a browser debug API, and let npm user-land provide a whatwg/ECMA/whoever console API if they want/need one for code that can run in node or browsers. But I can't change the past, and changing the name of console would break the world, so better to document, and move on, IMO.

Fixes: nodejs#831 Fixes: nodejs#947 Ref: nodejs#9470

Fixes: #831 Fixes: #947 Ref: #9470 PR-URL: #9744 Reviewed-By: Matteo Collina <[email protected]> Reviewed-By: James M Snell <[email protected]> Reviewed-By: Sakthipriyan Vairamani <[email protected]>

addaleax · 2017-02-15T20:31:52Z

@Fishrock123 I’ve just landed #9744 – seems okay to close this?

jasnell · 2017-03-22T22:14:34Z

ping @Fishrock123

jasnell · 2017-03-24T22:49:56Z

Closing given that #9744 landed

Fishrock123 added semver-major PRs that contain breaking changes and should be released in the next major version. process Issues and PRs related to the process subsystem. console Issues and PRs related to the console subsystem. labels Nov 4, 2016

Fishrock123 commented Nov 4, 2016

View reviewed changes

addaleax reviewed Nov 4, 2016

View reviewed changes

jasnell reviewed Nov 6, 2016

View reviewed changes

Fishrock123 mentioned this pull request Nov 21, 2016

EPIPE errors thrown when piping to a closed stream #947

Closed

Fishrock123 mentioned this pull request Nov 23, 2016

console: do not emit error events #9744

Closed

3 tasks

Fishrock123 mentioned this pull request Dec 5, 2016

Proposal: add a console.write method #10119

Closed

addaleax added a commit to addaleax/node that referenced this pull request Feb 11, 2017

console: do not emit error events

43e9611

Fixes: nodejs#831 Fixes: nodejs#947 Ref: nodejs#9470

jasnell closed this Mar 24, 2017

mcollina mentioned this pull request Jun 21, 2017

"write after end" error when stdout was end()-ed #9403

Closed

process: swallow stdout/stderr error events #9470

process: swallow stdout/stderr error events #9470

Conversation

Fishrock123 commented Nov 4, 2016 • edited Loading

Checklist

Affected core subsystem(s)

Description of change

Fishrock123 Nov 4, 2016

Choose a reason for hiding this comment

Fishrock123 Nov 4, 2016

Choose a reason for hiding this comment

addaleax Nov 4, 2016 • edited Loading

Choose a reason for hiding this comment

Fishrock123 Nov 4, 2016

Choose a reason for hiding this comment

mcollina Nov 5, 2016

Choose a reason for hiding this comment

bnoordhuis Nov 5, 2016

Choose a reason for hiding this comment

mcollina commented Nov 5, 2016

Fishrock123 commented Nov 5, 2016

benjamingr commented Nov 5, 2016

jasnell commented Nov 6, 2016

jasnell Nov 6, 2016

Choose a reason for hiding this comment

Fishrock123 Nov 6, 2016

Choose a reason for hiding this comment

Fishrock123 commented Nov 6, 2016 • edited Loading

jasnell commented Nov 6, 2016

addaleax commented Nov 6, 2016

Fishrock123 commented Nov 6, 2016 • edited Loading

mcollina commented Nov 6, 2016

Fishrock123 commented Nov 6, 2016

mcollina commented Nov 6, 2016

Fishrock123 commented Nov 6, 2016

mcollina commented Nov 6, 2016

sam-github commented Nov 18, 2016

jasnell commented Nov 18, 2016

bnoordhuis commented Nov 18, 2016

jasnell commented Nov 18, 2016

Fishrock123 commented Nov 18, 2016

sam-github commented Nov 18, 2016

jasnell commented Nov 18, 2016

sam-github commented Nov 18, 2016

jasnell commented Nov 18, 2016

sam-github commented Nov 18, 2016

Fishrock123 commented Nov 21, 2016 • edited Loading

sam-github commented Nov 21, 2016

jasnell commented Nov 21, 2016

sam-github commented Nov 21, 2016

Fishrock123 commented Nov 22, 2016

Fishrock123 commented Nov 22, 2016

sam-github commented Nov 22, 2016 • edited Loading

addaleax commented Nov 22, 2016

mcollina commented Nov 22, 2016 • edited Loading

addaleax commented Nov 22, 2016

sam-github commented Nov 22, 2016

addaleax commented Nov 22, 2016

mcollina commented Nov 22, 2016

addaleax commented Nov 22, 2016 • edited Loading

sam-github commented Nov 22, 2016

addaleax commented Feb 15, 2017

jasnell commented Mar 22, 2017

jasnell commented Mar 24, 2017

Fishrock123 commented Nov 4, 2016 •

edited

Loading

addaleax Nov 4, 2016 •

edited

Loading

Fishrock123 commented Nov 6, 2016 •

edited

Loading

Fishrock123 commented Nov 6, 2016 •

edited

Loading

Fishrock123 commented Nov 21, 2016 •

edited

Loading

sam-github commented Nov 22, 2016 •

edited

Loading

mcollina commented Nov 22, 2016 •

edited

Loading

addaleax commented Nov 22, 2016 •

edited

Loading