Write after end when piping a ClientRequest to ServerResponse

[Kasher]

• Version: v4.8.3
• Platform: Linux

Hey,

I believe there is a minor issue in _http_outgoing.js code. In the constructor, the property writable is changed to true (https://github.com/nodejs/node/blob/v4.x/lib/_http_outgoing.js#L64) :
this.writable = true;
As of my understanding, this property is set in the constructor since OutgoingMessage inherits from Stream, and in Stream's code, this property might be checked to validate that a stream is writable.
However, this property is never changed to false in _http_outgoing.js. Even when the message is closed (i.e. the end method was called), this property remains true.

The class OutgoingMessage maintains another property, finished, which indicates whether the OutgoingMessage was finished already or not. In the constructor finished is set to false, and later on, in the end method, it is set to true. I believe that finished and writable should have opposite values, since when a OutgoingMessage is closed - it is not writable anymore and it is finished .

This minor issue doesn't have much effect, but it might raise a lot of write after end errors, especially when piping. I can easily catch such errors so the process won't crash, but I guess the error shouldn't be raised in the first place.

The following simple code reproduces this (note that I use the request npm):

Server:

'use strict';
const http = require('http');
const port = 9876;
const request = require('request');

// ***************** Server ******************

// URL of some big file that we want to stream to the client.
const bigFileUrl = "http://distribution.bbb3d.renderfarming.net/video/mp4/bbb_sunflower_native_60fps_normal.mp4";

const requestHandler = (req, res) => {
    console.log("Server: Got a new request.");

    // Creating a server request to some file
    let requestOptions = {
        url: bigFileUrl
    };
    let serverRequest = request(requestOptions);
    // Piping the data from the server's request to the client's response
    serverRequest.pipe(res);

    // When the client's request is ended, closing the client's response and the server's request
    req.on('close', () => {
        console.log("Server: Client request was closed, closing server's request and client's response.");
        res.end();
        serverRequest.abort();
    });
}

const server = http.createServer(requestHandler);

server.listen(port, (err) => {
    console.log('server is listening on ', port);
});

Client:

'use strict';
const http = require('http');
const port = 9876;
const request = require('request');
const stream = require('stream');

// ***************** Client ******************

function randomInt(low, high) {
    return Math.floor(Math.random() * (high - low) + low);
}

let requestId = 0;
let concurrentRequests = 0;

setInterval(function() {
    const currentRequestId = ++requestId;
    const timeout = randomInt(0, 3000);
    console.log("Client: Initiating a new request with id ", currentRequestId, ". Closing after ", timeout, 
    			"ms. There are currently ", (++concurrentRequests), " concurrent requests.");

    let req = request({
        url: "http://localhost:" + port
    });
    // piping the response to some stream. Doesn't really matter to which stream.
    let outputStream = new stream.Writable({
	  write: function(chunk, encoding, next) {
	    next();
	  }
	});
    req.pipe(outputStream);

    setTimeout(function() {
        console.log("Client: Closing request number", currentRequestId, ". There are currently ", (--concurrentRequests), " concurrent requests.");
        req.abort();
    }, timeout);

}, 100);

Simple output (of the server):

node server_write_after_end.js 
server is listening on  9876
Server: Got a new request.
Server: Got a new request.
Server: Got a new request.
Server: Got a new request.
Server: Got a new request.
Server: Client request was closed, closing server's request and client's response.
Server: Client request was closed, closing server's request and client's response.
Server: Got a new request.
Server: Got a new request.
Server: Got a new request.
Server: Client request was closed, closing server's request and client's response.
Server: Got a new request.
Server: Got a new request.
Server: Got a new request.
Server: Got a new request.
Server: Got a new request.
Server: Client request was closed, closing server's request and client's response.
stream.js:74
      throw er; // Unhandled stream error in pipe.
      ^

Error: write after end
    at ServerResponse.OutgoingMessage.write (_http_outgoing.js:442:15)
    at Request.ondata (stream.js:31:26)
    at emitOne (events.js:77:13)
    at Request.emit (events.js:169:7)
    at IncomingMessage.<anonymous> (/home/roee/dev/flash-testing/node_modules/request/request.js:1088:12)
    at emitOne (events.js:77:13)
    at IncomingMessage.emit (events.js:169:7)
    at IncomingMessage.Readable.read (_stream_readable.js:368:10)
    at flow (_stream_readable.js:759:26)
    at resume_ (_stream_readable.js:739:3)

As you can see from the stack, we reach stream.js line 31. In line 30 (https://github.com/nodejs/node/blob/v4.x/lib/stream.js#L30) we can find the condition that should have failed:
if (dest.writable) { ... }
So, if my OutgoingMessage's writable property was indeed changed to false once it was closed, the error wouldn't have been raised at all.

Note that this probably happens due to race (between the client's request that was closed and the server's request, or actually the server-request's response, that got some new data), hence the code I attached doesn't reproduce this immediately and the output may not be the same as I attached.

I've opened a PR with a fix to this issue:
#14024
After applying this fix, my application works as expected and I never get any write after end errors in my scenario.

Any help will be appreciated.
Thanks!

[mcollina]

Which version of request are you using? I cannot correlate your line number to the current master of request.

[Kasher]

@mcollina , Thanks.
I'm using request version 2.75.0, but it reproduces with the latest version as well.

[mcollina]

Fixed in 649d77b.