Node: Stream.pipeline doesn't report failures if process.stdout is in the pipeline.

[spaghetti-is-pasta]

• Version: v11.11.0
• Platform: Linux 3.10.0-693.21.1.el7.x86_64
• Subsystem:

Below is a simple example of a pipeline starting with a Readable, Transform, and then process.stdout. Failures in the Transform do not get reported by Stream.pipeline.

const { Transform, Readable, pipeline } = require('stream')

const reader = new Readable({
  read(size) { this.push("foo") }
})

let count = 0;

const transform = new Transform({
  transform(chunk, enc, cb) {
    if (count++ >= 5)
      this.emit("error", new Error("this-error-gets-hidden"))
    else
      cb(null, count.toString() + "\n")
  }
})

pipeline(
  reader,
  transform,
  process.stdout,
  e => e ? console.error(e) : console.log("done")
)

The error that is emitted never shows up in the pipeline's callback. The pipeline does stop on the 5th iteration as expected, but the error gets gobbled up somehow. If process.stdout is removed from the pipeline, the error is displayed as expected.

Interestingly, the following works as expected:

pipeline(
  reader,
  transform,
  e => e ? console.error(e) : console.log("done")
).pipe(
  process.stdout
)

[Himself65]

you can handle the error by yourself to fix it

const { Transform, Readable, pipeline } = require('stream')

const reader = new Readable({
  read (size) {
    this.push('foo')
  }
})

let count = 0

const transform = new Transform({
  transform (chunk, enc, cb) {
    if (count++ >= 5) {
      this.emit('error', new Error('this-error-gets-hidden'))
    } else {
      cb(null, count.toString() + '\n')
    }
  }
})

// handle it
transform.on('error', (e) => {
  console.log(e)
})

pipeline(
  reader,
  transform,
  process.stdout,
  e => e ? console.error(e) : console.log('done')
)

[Himself65]

I found that onerror handler only just destroy itself and not to deliver the error message 😕

https://github.com/nodejs/node/blob/6e81a959d0b1d23ecc0ae96ce969da8192ad60f9/lib/_stream_readable.js#L715-L721

[bnoordhuis]

process.stdout actually ends up with _two_ 'error' listeners, the other one being:
https://github.com/nodejs/node/blob/6e81a959d0b1d23ecc0ae96ce969da8192ad60f9/lib/internal/streams/end-of-stream.js#L52-L54
I speculate errorOrDestroy() is never actually called.

[mcollina]

I don't think this is a bug in pipeline, but rather in https://github.com/nodejs/node/blob/6f77af541e4336037f08a876e1a3fa657fd22675/lib/internal/fs/sync_write_stream.js#L27-L36.

cc @tadjik1

[tadjik1]

@mcollina my PR fixes this problem as well:

const { Transform, Readable, pipeline } = require('stream')
const fs = require('fs')

const reader = new Readable({
  read(size) { this.push("foo") }
})

let count = 0;

const transform = new Transform({
  transform(chunk, enc, cb) {
    if (count++ >= 5)
      this.emit("error", new Error("this-error-gets-hidden"))
    else
      cb(null, count.toString() + "\n")
  }
})

pipeline(
  reader,
  transform,
  process.stdout,
  e => fs.writeFileSync('out.txt', `done with ${e ? e.message : 'no error'}`)
)

note: I'm not using console.log because when stdout destroyed it's no longer possible to print messages

[mcollina]

Here is a fix for this specific issue: https://github.com/nodejs/node/pull/26691.

The problem was caused by net.Socket having set emitClose: false  because it was emitted its own event in _destroy(), and stdio.js was overriding _destroy without emitting 'close'. That PR fixes that.

[craigphicks]

Doesn't seem to be fixed using the following versions:

$ npm -v
6.9.0
$ node --version
v10.16.3

npm outdated returns nothing.

As a workaround I used this:

class Workaround extends stream.Writable {
  constructor(){
    super()
  }
  _write(chunk,enc,callback){
    process.stdout.write(chunk)
    callback(null)
  }
  _final(callback){
    process.stdout.write('Workaround _final was called\n')
    callback(null)
  }  
}

The _final not necessary, it is only there to see if it got called. It seems that _final doesn't get called. Unsure whether that is meaningful or not.

Is it just a matter of delay between fix and stable version?

[mcollina]

I think it's a separate bug, because the script at the top reports the error on both 10.16.3 and 12.11, but it does not on 10.16.0.

Can you open a new issue with a full script to reproduce?

[mcollina]

I think it's a separate bug, because the script at the top reports the error on both 10.16.3 and 12.11, but it does not on 10.16.0.

Can you open a new issue with a full script to reproduce?

[craigphicks]

On the other hand, maybe the default of trying to close the last stream is OK, and for those specials cases (like stdout) where its not desirable, the workaround is pretty simple.

[mcollina]

I do not think I can help without a full repro of the problem you are experiencing. Can you open a new issue with a way to reproduce and tag me? Thanks