Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Stream.pipeline doesn't report failures if process.stdout is in the pipeline. #26550

Closed
spaghetti-is-pasta opened this issue Mar 9, 2019 · 11 comments
Labels
stream Issues and PRs related to the stream subsystem.

Comments

@spaghetti-is-pasta
Copy link

  • 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
)
@spaghetti-is-pasta spaghetti-is-pasta changed the title Stream.pipeline doesn't report failures if process.stdout in the pipeline. Stream.pipeline doesn't report failures if process.stdout is in the pipeline. Mar 9, 2019
@himself65
Copy link
Member

himself65 commented Mar 10, 2019

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
Copy link
Member

himself65 commented Mar 10, 2019

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

function onerror(er) {
debug('onerror', er);
unpipe();
dest.removeListener('error', onerror);
if (EE.listenerCount(dest, 'error') === 0)
errorOrDestroy(dest, er);
}

@bnoordhuis
Copy link
Member

process.stdout actually ends up with two 'error' listeners, the other one being:

const onerror = (err) => {
callback.call(stream, err);
};

I speculate errorOrDestroy() is never actually called.

@bnoordhuis bnoordhuis added the stream Issues and PRs related to the stream subsystem. label Mar 12, 2019
@mcollina
Copy link
Member

I don't think this is a bug in pipeline, but rather in

SyncWriteStream.prototype._destroy = function() {
if (this.fd === null) // already destroy()ed
return;
if (this.autoClose)
closeSync(this.fd);
this.fd = null;
return true;
};
.

cc @tadjik1

@tadjik1
Copy link
Contributor

tadjik1 commented Mar 15, 2019

@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
Copy link
Member

Here is a fix for this specific issue: #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.

targos pushed a commit to targos/node that referenced this issue Mar 27, 2019
Fix: nodejs#26550

PR-URL: nodejs#26691
Fixes: https://github.com/false
Fixes: nodejs#26550
Reviewed-By: James M Snell <jasnell@gmail.com>
Reviewed-By: Anna Henningsen <anna@addaleax.net>
targos pushed a commit that referenced this issue Mar 27, 2019
Fix: #26550

PR-URL: #26691
Fixes: https://github.com/false
Fixes: #26550
Reviewed-By: James M Snell <jasnell@gmail.com>
Reviewed-By: Anna Henningsen <anna@addaleax.net>
BethGriggs pushed a commit that referenced this issue Jul 9, 2019
Fix: #26550

PR-URL: #26691
Fixes: https://github.com/false
Fixes: #26550
Reviewed-By: James M Snell <jasnell@gmail.com>
Reviewed-By: Anna Henningsen <anna@addaleax.net>
BethGriggs pushed a commit that referenced this issue Jul 17, 2019
Fix: #26550

PR-URL: #26691
Fixes: https://github.com/false
Fixes: #26550
Reviewed-By: James M Snell <jasnell@gmail.com>
Reviewed-By: Anna Henningsen <anna@addaleax.net>
@craigphicks
Copy link

craigphicks commented Sep 25, 2019

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
Copy link
Member

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?

1 similar comment
@mcollina
Copy link
Member

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
Copy link

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
Copy link
Member

mcollina commented Nov 5, 2019

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

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
stream Issues and PRs related to the stream subsystem.
Projects
None yet
6 participants