Setting callback for on 'data' event of stderr causes error on v10.0.0 #21203

jesobreira · 2018-06-08T00:37:35Z

Version: 10.0.0
Platform: OS X 10.13.2
Subsystem: Process

I am unable to set a callback on the 'data' event (since process.stderr is a net.Socket stream, it should emit the data event).

The following snippet works on v8.0.0 but throws an error on v10.0.0:

process.stderr.on('data', function(data) {
    // not relevant, error is threw anyway
});

Error threw:

Error: read ENOTCONN
    at WriteStream.Socket._read (net.js:530:20)
    at WriteStream.Readable.read (_stream_readable.js:458:10)
    at resume_ (_stream_readable.js:897:12)
    at process._tickCallback (internal/process/next_tick.js:174:19)
    at Function.Module.runMain (internal/modules/cjs/loader.js:721:11)
    at startup (internal/bootstrap/node.js:228:19)
    at bootstrapNodeJSCore (internal/bootstrap/node.js:575:3)
Emitted 'error' event at:
    at emitErrorNT (internal/streams/destroy.js:92:8)
    at emitErrorAndCloseNT (internal/streams/destroy.js:59:3)
    at process._tickCallback (internal/process/next_tick.js:174:19)
    [... lines matching original stack trace ...]
    at bootstrapNodeJSCore (internal/bootstrap/node.js:575:3)

The text was updated successfully, but these errors were encountered:

ryzokuken · 2018-06-08T10:17:19Z

Okay, it doesn't throw on Node 8 and throws on 10.

/cc @nodejs/process @nodejs/streams

ryzokuken · 2018-06-08T10:24:05Z

Even if it's a valid error, we should try throwing something descriptive.

mcollina · 2018-06-08T18:32:12Z

This is likely a bug on stdout/stderr and net, and not on stream.

jrasanen · 2018-06-09T17:15:28Z

I git bisected when the error was introduced, if that helps (this commit):

ae2b5bcb7c17a2d2a488f234c736201eed8200db is the first bad commit
commit ae2b5bcb7c17a2d2a488f234c736201eed8200db
Author: cjihrig <cjihrig@gmail.com>
Date:   Mon Apr 2 13:33:48 2018 -0400

    deps: upgrade libuv to 1.20.0

    Notable changes:
    - uv_fs_copyfile() adds support for copy-on-write behavior.
    - uv_relative_path() now uses the long directory name
      for handle->dirw.
    - File operations on files > 2 GB on 32-bit platforms are
      working again.
    - uv_fs_fchmod() on Windows works on files with the
      Archive flag cleared.

    Fixes: https://github.com/nodejs/node/issues/19170
    Fixes: https://github.com/nodejs/node/issues/19455
    Fixes: https://github.com/nodejs/node/issues/12803
    PR-URL: https://github.com/nodejs/node/pull/19758
    Reviewed-By: Ben Noordhuis <info@bnoordhuis.nl>
    Reviewed-By: Santiago Gimeno <santiago.gimeno@gmail.com>
    Reviewed-By: James M Snell <jasnell@gmail.com>

:040000 040000 b5f3cc6178caf6ee1a46ee21fc89c83b2b32a69c c093efd2a818669a8aa2d3641905d6cf2e432c30 M	deps

cjihrig · 2018-06-10T03:20:33Z

The specific commit in libuv responsible for this is libuv/libuv@8f9ba2a. Specifically, the return -ENOTCONN; when uv_read_start() is called on a stream that is not readable.

This breakage was not intended, but this is arguably a bug in Node (or the application code) as the socket's readable property is false.

thatshailesh · 2018-06-21T05:58:09Z

Hi All, would like to work on this need some guidance, as per comments i think this hasn't been fixed yet please let me know if this still need to fixed for me to proceed :)

AyushG3112 · 2018-06-24T11:03:08Z

Same issue exists with v10.5.0 and stdout

process.stdout.on('data', function(data) {
    
});

AyushG3112 · 2018-06-24T12:37:14Z

Resolving issue is more complicated than it seemed at first glance(atleast to me), but the gist of the issue is is the stdout or stderrs fd handle type corresponds to TTY, PIPE or TCP, the stream is created as a WriteStream instead of a DuplexStream.

Relevant code is at:

node/lib/internal/process/stdio.js

Lines 164 to 197 in cdb5985

    
           function createWritableStdioStream(fd) { 
        
             var stream; 
        
             const tty_wrap = process.binding('tty_wrap'); 
        
             // Note stream._type is used for test-module-load-list.js 
        
             switch (tty_wrap.guessHandleType(fd)) { 
        
               case 'TTY': 
        
                 var tty = require('tty'); 
        
                 stream = new tty.WriteStream(fd); 
        
                 stream._type = 'tty'; 
        
                 break; 
        
               case 'FILE': 
        
                 const SyncWriteStream = require('internal/fs/sync_write_stream'); 
        
                 stream = new SyncWriteStream(fd, { autoClose: false }); 
        
                 stream._type = 'fs'; 
        
                 break; 
        
               case 'PIPE': 
        
               case 'TCP': 
        
                 var net = require('net'); 
        
                 stream = new net.Socket({ 
        
                   fd: fd, 
        
                   readable: false, 
        
                   writable: true 
        
                 }); 
        
                 stream._type = 'pipe'; 
        
                 break; 
        
               default: 
        
                 // Probably an error on in uv_guess_handle() 
        
                 throw new ERR_UNKNOWN_STREAM_TYPE(); 
        
             }

IamManchanda · 2018-06-24T13:16:41Z

V

…

On Sun, Jun 24, 2018, 5:08 PM Ayush Gupta ***@***.***> wrote: Found the issue, PR coming in a bit if the fix works. — You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub <#21203 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AEvYgA23bcuvV_aHIdWKVgiYpePFDMAvks5t_3o_gaJpZM4UfUp1> .

gireeshpunathil · 2018-06-25T06:35:11Z

I guess this is the relevant code, for a top level Node process (stdout / err is a TTY):

node/lib/tty.js

Lines 82 to 86 in 831821b

    
           net.Socket.call(this, { 
        
             handle: tty, 
        
             readable: false, 
        
             writable: true 
        
           });

While I think this is a design decision rather than a bug, the ask in the first comment looks like valid requirement to me, at least allowing stdio to be readable - absorbing stdio logs without allowing the write onto the actual device (don't know if it is possible though) can be useful for custom redirections without code modifications.

mcollina · 2018-07-04T13:04:29Z

I'm proposing #21654 as a fix for this to be landed in master and Node 10. Then we might want to change this behavior in Node 11 to produce an explicative error.

This change avoid an 'read ENOTCONN' error introduced by libuv 1.20.0 when trying to read from a TTY WriteStream. Instead, we are throwing a more actionable ERR_TTY_WRITABLE_NOT_READABLE. Fixes: nodejs#21203

addaleax · 2018-09-21T17:11:28Z

I’m reopening this since #22997 should be a good step towards making this work again

This reverts commit 91eec00. Refs: nodejs#21654 Refs: nodejs#21203

Allow reading from stdio streams that are conventionally associated with process output, since this is only convention. This involves disabling the oddness around closing stdio streams. Its purpose is to prevent the file descriptors 0 through 2 from being closed, since doing so can lead to information leaks when new file descriptors are being opened; instead, not doing anything seems like a more reasonable choice. Fixes: nodejs#21203

This reverts commit 91eec00. Refs: #21654 Refs: #21203 PR-URL: #23053 Reviewed-By: James M Snell <jasnell@gmail.com>

Allow reading from stdio streams that are conventionally associated with process output, since this is only convention. This involves disabling the oddness around closing stdio streams. Its purpose is to prevent the file descriptors 0 through 2 from being closed, since doing so can lead to information leaks when new file descriptors are being opened; instead, not doing anything seems like a more reasonable choice. Fixes: #21203 PR-URL: #23053 Reviewed-By: James M Snell <jasnell@gmail.com>

This reverts commit 91eec00. Refs: #21654 Refs: #21203 PR-URL: #23053 Reviewed-By: James M Snell <jasnell@gmail.com>

Allow reading from stdio streams that are conventionally associated with process output, since this is only convention. This involves disabling the oddness around closing stdio streams. Its purpose is to prevent the file descriptors 0 through 2 from being closed, since doing so can lead to information leaks when new file descriptors are being opened; instead, not doing anything seems like a more reasonable choice. Fixes: #21203 PR-URL: #23053 Reviewed-By: James M Snell <jasnell@gmail.com>

…1063) (close: #1064) Refs: - nodejs/node#21203 - nodejs/node@cbc3ef6

Allow reading from stdio streams that are conventionally associated with process output, since this is only convention. This involves disabling the oddness around closing stdio streams. Its purpose is to prevent the file descriptors 0 through 2 from being closed, since doing so can lead to information leaks when new file descriptors are being opened; instead, not doing anything seems like a more reasonable choice. Fixes: #21203 Backport-PR-URL: #25351 PR-URL: #23053 Reviewed-By: James M Snell <jasnell@gmail.com>

…1063) (close: #1064) Refs: - nodejs/node#21203 - nodejs/node@cbc3ef6

ZissisT · 2020-04-03T13:49:47Z

I am a bit confused on what was the solution for this one (fixed or it still throws error but in another way?).
I notice a very similar behavior in v12.16.1
No error was thrown in v8.11.4 but when I try to upgrade to v12.16.1 I get same error.

In my project these lines of code exist for redirecting stderr to syslogger

        process.addListener('uncaughtException', err => {
            // Log this in syslog
            .
            .
        });

        process.stderr.on('data', function(data) {
            // Redirect data to syslogger
        });

This triggers uncaughtException listener always with

Error: read ENOTCONN
at tryReadStart (net.js:567:20)
at Socket._read (net.js:578:5)
at Socket.Readable.read (_stream_readable.js:478:10)
at Socket.read (net.js:618:39)
at resume_ (_stream_readable.js:965:12)
at processTicksAndRejections (internal/process/task_queues.js:84:21)

Whatever the callback is, exception is thrown.
Is this expected? If yes, what causes this to be thrown now and not before (so I know how to change my code)
Thank you

Allow reading from stdio streams that are conventionally associated with process output, since this is only convention. This involves disabling the oddness around closing stdio streams. Its purpose is to prevent the file descriptors 0 through 2 from being closed, since doing so can lead to information leaks when new file descriptors are being opened; instead, not doing anything seems like a more reasonable choice. Fixes: nodejs/node#21203 PR-URL: nodejs/node#23053 Reviewed-By: James M Snell <jasnell@gmail.com>

ryzokuken added process Issues and PRs related to the process subsystem. confirmed-bug Issues with confirmed bugs. stream Issues and PRs related to the stream subsystem. labels Jun 8, 2018

mcollina added the net Issues and PRs related to the net subsystem. label Jun 8, 2018

benjamingr added libuv Issues and PRs related to the libuv dependency or the uv binding. and removed libuv Issues and PRs related to the libuv dependency or the uv binding. labels Jun 9, 2018

mcollina mentioned this issue Jul 4, 2018

tty: make _read throw ERR_TTY_WRITABLE_NOT_READABLE #21654

Closed

3 tasks

mcollina closed this as completed in 91eec00 Aug 22, 2018

addaleax reopened this Sep 21, 2018

addaleax added a commit to addaleax/node that referenced this issue Sep 24, 2018

Revert "tty: make _read throw ERR_TTY_WRITABLE_NOT_READABLE"

a4e4e48

This reverts commit 91eec00. Refs: nodejs#21654 Refs: nodejs#21203

addaleax added a commit that referenced this issue Oct 4, 2018

Revert "tty: make _read throw ERR_TTY_WRITABLE_NOT_READABLE"

c7405fe

This reverts commit 91eec00. Refs: #21654 Refs: #21203 PR-URL: #23053 Reviewed-By: James M Snell <jasnell@gmail.com>

addaleax closed this as completed in cbc3ef6 Oct 4, 2018

targos pushed a commit that referenced this issue Oct 5, 2018

Revert "tty: make _read throw ERR_TTY_WRITABLE_NOT_READABLE"

090d879

This reverts commit 91eec00. Refs: #21654 Refs: #21203 PR-URL: #23053 Reviewed-By: James M Snell <jasnell@gmail.com>

jasnell pushed a commit that referenced this issue Oct 17, 2018

Revert "tty: make _read throw ERR_TTY_WRITABLE_NOT_READABLE"

c834be0

This reverts commit 91eec00. Refs: #21654 Refs: #21203 PR-URL: #23053 Reviewed-By: James M Snell <jasnell@gmail.com>

This was referenced Oct 23, 2018

“Unknown system error -75” nodejs fs.stat large files #19455

Closed

Updating libuv on 8.x and 10.x #23833

Closed

spiltcoffee mentioned this issue Dec 3, 2018

vuepress dev broken on nodejs v10 and greater vuejs/vuepress#1063

Closed

1 task

ulivz added a commit to vuejs/vuepress that referenced this issue Dec 3, 2018

fix($core): vuepress dev broken on nodejs v10 and greater (close: #…

39e9673

…1063) (close: #1064) Refs: - nodejs/node#21203 - nodejs/node@cbc3ef6

shaun554 added a commit to shaun554/vuepress that referenced this issue Mar 21, 2019

fix($core): vuepress dev broken on nodejs v10 and greater (close: #…

b3259ea

…1063) (close: #1064) Refs: - nodejs/node#21203 - nodejs/node@cbc3ef6

devs-cloud pushed a commit to devs-cloud/vue-dev that referenced this issue Dec 27, 2019

fix($core): vuepress dev broken on nodejs v10 and greater (close: #…

adef3a1

…1063) (close: #1064) Refs: - nodejs/node#21203 - nodejs/node@cbc3ef6

ggoodman mentioned this issue Apr 20, 2020

spawn EAGAIN produces a sequence of uncaught exceptions that cannot be handled #32943

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Setting callback for on 'data' event of stderr causes error on v10.0.0 #21203

Setting callback for on 'data' event of stderr causes error on v10.0.0 #21203

jesobreira commented Jun 8, 2018

ryzokuken commented Jun 8, 2018

ryzokuken commented Jun 8, 2018

mcollina commented Jun 8, 2018

jrasanen commented Jun 9, 2018 •

edited

cjihrig commented Jun 10, 2018

thatshailesh commented Jun 21, 2018 •

edited

AyushG3112 commented Jun 24, 2018 •

edited

AyushG3112 commented Jun 24, 2018 •

edited

IamManchanda commented Jun 24, 2018 via email

gireeshpunathil commented Jun 25, 2018

mcollina commented Jul 4, 2018

addaleax commented Sep 21, 2018

ZissisT commented Apr 3, 2020

Setting callback for on 'data' event of stderr causes error on v10.0.0 #21203

Setting callback for on 'data' event of stderr causes error on v10.0.0 #21203

Comments

jesobreira commented Jun 8, 2018

ryzokuken commented Jun 8, 2018

ryzokuken commented Jun 8, 2018

mcollina commented Jun 8, 2018

jrasanen commented Jun 9, 2018 • edited

cjihrig commented Jun 10, 2018

thatshailesh commented Jun 21, 2018 • edited

AyushG3112 commented Jun 24, 2018 • edited

AyushG3112 commented Jun 24, 2018 • edited

IamManchanda commented Jun 24, 2018 via email

gireeshpunathil commented Jun 25, 2018

mcollina commented Jul 4, 2018

addaleax commented Sep 21, 2018

ZissisT commented Apr 3, 2020

jrasanen commented Jun 9, 2018 •

edited

thatshailesh commented Jun 21, 2018 •

edited

AyushG3112 commented Jun 24, 2018 •

edited

AyushG3112 commented Jun 24, 2018 •

edited