node 6 IncomingMessage events fix

[davidmarkclements]

Something seems to have changed between v4 and v6 around event ordering and piped streams,

The following will behave differently between v4 and v6 (the end event is ignored in v6)

var fs = require('fs')
var Busboy = require('busboy')
var http = require('http')

http.createServer((req, res) => {
  var busboy = new Busboy({ headers: req.headers })
  req.pipe(busboy)

  busboy.on('file', (field, file) => {
    var dest = fs.createWriteStream('/dev/null')
    file.pipe(dest)
  })

  req.on('end', () => console.log('req end')) // logs in v4, not in v6
  res.end(':)')
}).listen(8080)

Wrapping boy.emit('finish') in a setImmediate solves this,
I haven't found any side effects to doing this, although that doesn't mean there may be some

[mscdex]

Can you provide a full example (including client side and a file) to reproduce the issue you're describing first?

[davidmarkclements]

Ah so I was testing the above with curl, should have included

$ curl -v -F userfile1=@/bin/echo http://localhost:8080

I'm unable to share the actual code I'm working on (it's for a book), but the side effect of this is it prevents the pump module from working effectively (because it uses end-of-stream on every stream in a pipeline, and req isn't firing end events in v6 when it's piped to busboy instance)

[mscdex]

Your code example + that curl usage works for me. 'req end' is printed to the console. I tested with node v6.9.1.

Out of curiosity, did you try moving your res.end() into a busboy.on('finish', ...) event handler?

[davidmarkclements]

ok sorry - I changed the file to /bin/echo so it would be easier, but it turns out the problem only occurs if the file < 16384 (i.e. the highWaterMark)

$ dd if=/dev/random bs=1 count=16383 > fail
$ dd if=/dev/random bs=1 count=16384 > pass
$ curl -v -F userfile1=@fail http://localhost:8080 # node v6 will not log req end, but v4 will
$ curl -v -F userfile1=@pass http://localhost:8080 # node v6 will log req end (as will v4)

If you put res.end in the finish handler, the behavior is the same

Given that it's actually related to watermark size, perhaps there is a better solution than setImmediate - I wonder if it's related to cork/uncork..

[mcollina]

@davidmarkclements the problem is that you are calling res.end() before the file has finished uploading. Can you please verify?

[davidmarkclements]

@mcollina - no that isn't it - this happens regardless of when res.end is called (you could wrap it in a 10 second setTimeout and it would make no difference)

I've not explained the problem very well, just to outline it:

The end event on the request object is not fired WHEN

1. Node version is 6+ AND
2. the request object is piped to a busboy instance AND
3. a busboy FileStream instance (passed via the file event handler) is piped to another stream

This has unwanted side effects at higher levels, for instance the pattern of using pump
for pipeline management becomes unworkable because it relies on each stream ending.

[mscdex]

I can duplicate it now. Whatever it is it seems to have started in node v4.5.0, node versions prior to that work fine.

It appears that node is automatically unpipe()ing when the destination stream is finished, but this causes the request (readable) stream to not emit end because it's somehow stuck in an unfinished state. You can verify this by calling req.resume() from busboy.on('finish', () => { ... })

EDIT: Looking at the node changelog, my first guess is possibly nodejs/node#7211

[mscdex]

Ok, bisecting reveals it's this PR: nodejs/node#5419

EDIT: node issue posted here: nodejs/node#10344

[jemmyw]

Any update on this bug? I see that the node PR has been closed without a fix.

[mscdex]

There should no longer be a problem with this in busboy v1.0.0.