EPIPE with the repl and cat?

[TooTallNate]

Basically, I'm seeing EPIPE errors when a "large" amount of data gets printed to the output stream when using the repl over pipes. To reproduce, inspect a largish object in the repl, like process or even process.env. This is on OS X, happens on both Terminal and iTerm2.

☮ ~/node (master) ⚡ ./node | cat
> process
{ EventEmitter: [Function: EventEmitter],
  title: './node',
  version: 'v0.7.7-pre',
  assert: [Function],
  config: 
   { target_defaults: 
      { cflags: [],
        default_configuration: 'Release',
        defines: [],
        include_dirs: [],
        libraries: [Object] },
     variables: 
      { host_arch: 'x64',
        node_install_npm: true,
        node_install_waf: true,
        node_prefix: '',
        node_shared_v8: false,
        node_shared_zlib: true,
        node_use_dtrace: false,
        node_use_openssl: true,
        node_use_system_openssl: true,
        strict_aliasing: true,
        target_arch: 'x64',
        v8_use_snapshot: true } },
  moduleLoadList: 
   [ 'Binding evals',
     'Binding natives',
     'NativeModule events',
     'NativeModule buffer',
     'Binding buffer',
     'NativeModule assert',
     'NativeModule util',
     'NativeModule path',
     'NativeModule module',
     'NativeModule tty',
     'NativeModule net',
     'Nativewrite error


events.js:48
        throw arguments[1]; // Unhandled 'error' event
                       ^
Error: write EPIPE
    at errnoException (net.js:685:11)
    at Object.afterWrite [as oncomplete] (net.js:510:18)

So that's bad. I've also seen cat print to the screen: cat: write error: Resource temporarily unavailable. Interestingly, if we turn stdin into a pipe as well, then it seems to work over cat (the -i flag on node makes it enter the repl, rather than interpret stdin as a piped-in JS file):

echo process | ./node -i | cat

So this is a little strange to me. Naively, it seems like something possibly on our (libuv?) end, but I really don't know the fine details here.

Another interesting tidbit is that I get essentially the same behavior when running a repl over an HTTP server, connecting using curl. It works seemingly ok, but if you print out process.env for example, then curl crashes with: curl: (23) Failed writing body (0 != 2020). See this gist: https://gist.github.com/2053342

[TooTallNate]

This also dates back to at least node v0.4.12, so we know it's not necessarily related to libuv.

[Southern]

Seems to work fine for me.

~$ node | cat
> process
{ title: 'node',
  EventEmitter: [Function: EventEmitter],
  version: 'v0.7.7-pre',
  assert: [Function],
  moduleLoadList: 
   [ 'Binding evals',
     'Binding natives',
     'NativeModule events',
     'NativeModule buffer',
     'Binding buffer',
     'NativeModule assert',
     'NativeModule util',
     'NativeModule module',
     'NativeModule path',
     'NativeModule tty',
     'NativeModule net',
     'NativeModule stream',
     'NativeModule timers',
     'Binding timer_wrap',
     'NativeModule _linklist',
     'Binding tty_wrap',
     'NativeModule vm',
     'NativeModule fs',
     'Binding fs',
     'Binding constants',
     'NativeModule readline',
     'Binding pipe_wrap' ],
  config: 
   { target_defaults: 
      { cflags: [],
        default_configuration: 'Debug',
        defines: [],
        include_dirs: [],
        libraries: [] },
     variables: 
      { host_arch: 'x64',
        node_install_npm: true,
        node_install_waf: true,
        node_prefix: '',
        node_shared_v8: false,
        node_shared_zlib: false,
        node_use_dtrace: false,
        node_use_openssl: true,
        node_use_system_openssl: false,
        strict_aliasing: true,
        target_arch: 'x64',
        v8_use_snapshot: true } },
  _tickCallback: [Function],
  versions: 
   { http_parser: '1.0',
     node: '0.7.7-pre',
     v8: '3.9.17',
     ares: '1.7.5-DEV',
     uv: '0.6',
     zlib: '1.2.3',
     openssl: '0.9.8r' },
  arch: 'x64',
  nextTick: [Function],
  platform: 'linux',
  stdout: [Getter],
  argv: [ 'node' ],
  stderr: [Getter],
  execArgv: [],
  stdin: [Getter],
  openStdin: [Function],
  env: 
   { [...snip...] },
  pid: 6329,
  exit: [Function],
  features: 
   { debug: false,
     uv: true,
     ipv6: true,
     tls_npn: true,
     tls_sni: true,
     tls: true },
  kill: [Function],
  execPath: '/usr/local/bin/node',
  addListener: [Function],
  on: [Function],
  debugPort: 5858,
  removeListener: [Function],
  _needTickCallback: [Function],
  reallyExit: [Function],
  abort: [Function],
  chdir: [Function],
  cwd: [Function],
  umask: [Function],
  getuid: [Function],
  setuid: [Function],
  setgid: [Function],
  getgid: [Function],
  _kill: [Function],
  _debugProcess: [Function],
  _debugPause: [Function],
  _debugEnd: [Function],
  hrtime: [Function],
  dlopen: [Function],
  uptime: [Function],
  memoryUsage: [Function],
  uvCounters: [Function],
  binding: [Function] }

Just pulled from master again, to make sure it wasn't a recent bug.

~$ node | cat
> process
{ title: 'node',
  EventEmitter: [Function: EventEmitter],
  assert: [Function],
  version: 'v0.7.8-pre',
  config: 
   { target_defaults: 
      { cflags: [],
        default_configuration: 'Debug',
        defines: [],
        include_dirs: [],
        libraries: [] },
     variables: 
      { host_arch: 'x64',
        node_install_npm: true,
        node_install_waf: true,
        node_prefix: '',
        node_shared_v8: false,
        node_shared_zlib: false,
        node_use_dtrace: false,
        node_use_openssl: true,
        node_use_system_openssl: false,
        strict_aliasing: true,
        target_arch: 'x64',
        v8_use_snapshot: true } },
  moduleLoadList: 
   [ 'Binding evals',
     'Binding natives',
     'NativeModule events',
     'NativeModule buffer',
     'Binding buffer',
     'NativeModule assert',
     'NativeModule util',
     'NativeModule module',
     'NativeModule path',
     'NativeModule tty',
     'NativeModule net',
     'NativeModule stream',
     'NativeModule timers',
     'Binding timer_wrap',
     'NativeModule _linklist',
     'Binding tty_wrap',
     'NativeModule vm',
     'NativeModule fs',
     'Binding fs',
     'Binding constants',
     'NativeModule readline',
     'Binding pipe_wrap' ],
  versions: 
   { http_parser: '1.0',
     node: '0.7.8-pre',
     v8: '3.9.24.7',
     ares: '1.7.5-DEV',
     uv: '0.6',
     zlib: '1.2.3',
     openssl: '0.9.8r' },
  _tickCallback: [Function],
  nextTick: [Function],
  arch: 'x64',
  stdout: [Getter],
  platform: 'linux',
  stderr: [Getter],
  argv: [ 'node' ],
  stdin: [Getter],
  execArgv: [],
  openStdin: [Function],
  env: 
   { [..snip..] },
  exit: [Function],
  pid: 14164,
  features: 
   { debug: false,
     uv: true,
     ipv6: true,
     tls_npn: true,
     tls_sni: true,
     tls: true },
  kill: [Function],
  execPath: '/usr/local/bin/node',
  addListener: [Function],
  on: [Function],
  debugPort: 5858,
  _needTickCallback: [Function],
  removeListener: [Function],
  reallyExit: [Function],
  abort: [Function],
  chdir: [Function],
  cwd: [Function],
  umask: [Function],
  getuid: [Function],
  setuid: [Function],
  setgid: [Function],
  getgid: [Function],
  _kill: [Function],
  _debugProcess: [Function],
  _debugPause: [Function],
  _debugEnd: [Function],
  hrtime: [Function],
  dlopen: [Function],
  uptime: [Function],
  memoryUsage: [Function],
  uvCounters: [Function],
  binding: [Function] }

Have you tried seeing if the SIGPIPE event is triggered? process.on('SIGPIPE', function() { throw new Error('Pipe closed.'); });

[mmalecki]

Can reproduce on Mac OS X. Works without problems on Linux.

[TooTallNate]

@Southern There does not appear to be a "SIGPIPE" event that happens.

[TooTallNate]

Ok this does indeed seem to be an OS X problem. I tried it on Solaris, Windows, and Linux and it worked as expected in all those places. I didn't try my REPL over curl example on all those platforms, but I think that is a different problem now.

@mmalecki @Southern Can you guys try out the REPL over curl example as well? Requires node v0.7.7.

[Southern]

Not sure that my testing it would be of any help, since I am using Linux.

[TooTallNate]

@Southern I have a feeling that the "repl-over-curl" situation is a little different. I was able to reproduce a similar crash in curl by printing out a large object like global to the repl, on both OS X and Ubuntu.

Interestingly Windows was ok, though the color codes do not get interpreted properly since curl doesn't know how to handle them.

[mhart]

Is #3211 a simple test case of the same thing? (edit: perhaps not - SIGPIPE is being triggered in my case) (edit again: well... sometimes it is, sometimes it's not - could be the process is terminating before it's caught in some cases)

[vvo]

Have reproduced this on Ubuntu 12.04 too when too much content get written to repls and lot of connections.

https://gist.github.com/3906440: test files that almost always give

Error: write EPIPE
    at errnoException (net.js:769:11)
    at Object.afterWrite (net.js:593:19)

Node 0.8.12

-> % uname -ra
Linux [...] 3.2.0-32-generic [...] Ubuntu [...] x86_64 x86_64 x86_64 GNU/Linux

Maybe this is just an inode problem? dunno

[bnoordhuis]

I'm going to close this because it's not really a node bug. When you run node | cat the following happens:

1. node reads from the tty and writes to the pipe.
2. cat reads from the pipe and writes to the tty.
3. node puts the tty in non-blocking mode.
4. When cat tries to write, it eventually gets an EAGAIN (meaning: tty output buffer full). It's not equipped to handle that and exits.
5. The read end of the pipe is closed. When node next tries to write, it gets an EPIPE error.

tl;dr It's a bug in cat, it should switch to polling mode when it sees EAGAIN but it doesn't.

It may be possible to work around that by reopening /dev/tty in node but I'm a) not sure that'll work at all, and b) that it'll work on all supported Unices.

[TooTallNate]

@bnoordhuis I appreciate the explanation and it makes perfect sense to me. I'm confused, though, at why only OS X seems to exhibit this behavior, and the other OSs seem alright.

[bnoordhuis]

OS X seems to exhibit this behavior, and the other OSs seem alright.

It happens on Linux as well but the tty output buffer is a lot bigger there, on the order of 256 kB.

On OS X, it's around 4 kB (or 8 or 16 kB - a lot smaller anyway) so it fills up faster.

[TooTallNate]

I learn so much from you Ben :)

On Tue, Dec 4, 2012 at 6:35 PM, Ben Noordhuis notifications@github.comwrote:

OS X seems to exhibit this behavior, and the other OSs seem alright.

It happens on Linux as well but the tty output buffer is a lot bigger
there, on the order of 256 kB.

On OS X, it's around 4 kB (or 8 or 16 kB - a lot smaller anyway) so it
fills up faster.

—
Reply to this email directly or view it on GitHubhttps://github.com//issues/3027#issuecomment-11025814.