http: OutgoingMessage change writable after end #14024

Kasher · 2017-07-01T11:17:58Z

When an OutgoingMessage is closed (for example, using the end
method), its 'writable' property should be changed to false - since it
is not writable anymore. The 'writable' property should have the
opposite value of the 'finished' property.

Checklist

make -j4 test (UNIX), or vcbuild test (Windows) passes
tests and/or benchmarks are included
commit message follows commit guidelines

Affected core subsystem(s)

http

Issue: #14023

gireeshpunathil · 2017-07-02T15:46:33Z

Thank you! Does it make sense to add another test case which asserts that response refuses to write after end()? While your test is fine, it looks to me more directed, rather than testing the function of Outgoing Message.

Here is a code which writes after end() with the existing code - you may tune this into a test case:

var http = require('http')
const net = require('net')

var server = http.createServer(function(req, res) {
  res.write('hello ')
  res.end('write after ')
  res._send('end!')
})
server.listen(25000, () => {
  var data = 'GET / HTTP/1.0\r\nContent-Type: text/plain\r\nContent-Length: 0\r\n\r\n'
  const client = net.createConnection({ port: 25000}, () => {
    client.write(data)
  })
  client.on('data', (data) => {
    console.log(data.toString())
  })
  client.on('end', () => {
    server.close()
  })
})

Kasher · 2017-07-02T16:45:04Z

@gireeshpunathil , Thanks for your response.

I totally agree with what you wrote (my test is quite too strict to the case I fixed), but I wasn't able to write a less-strict test that reproduces this issue.

Unfortunately, the code you attached doesn't reproduce the issue.
The issue I'm referring to is an edge case, which happens due to some race between the piping code and the fact that the response was closed. I attached some code that reproduces this to the issue I opened (#14023), but even with that code - it doesn't reproduce every time :\

When I tried to execute the code you wrote, I got the following result:

HTTP/1.1 200 OK
Date: Sun, 02 Jul 2017 16:27:59 GMT
Connection: close

hello write after end!

Which is fine in my opinion.

Any call to _send or write in OutgoingMessage after the response was closed will result in a "write after end" error, but that's by design. I believe that that's not the case when you use streams though (where you don't directly call send or write or any method on the response).

Any suggestion on how to reproduce this consistently will be much appreciated. I would be more than happy to write a less-strict test that reproduces this :)

Thanks again!

gireeshpunathil · 2017-07-03T04:46:23Z

@Kasher - does this fail for you? (where data is a huge file in the disc)

const http = require('http')
const fs = require('fs')

const server = http.createServer((req, res) => {
  req.on('end', () => {
    console.log("Server: Client request was closed, closing server's request and client's response.");
    res.end()
  })
  fs.createReadStream('data').pipe(res)
})
server.listen(25000, () => {
  const client = http.get('http://localhost:25000/', (res) => {
    res.pipe(process.stdout)
  })
})

Kasher · 2017-07-07T12:40:54Z

@gireeshpunathil Thanks again.
Unfortunately, this doesn't reproduce this either.
I've managed to reproduce it in a small unit test, and I added it to my PR: https://github.com/nodejs/node/pull/14024/files#diff-f48f06a77b4005be724d14b42ab7f87d

When an OutgoingMessage is closed (for example, using the `end` method), its 'writable' property should be changed to false - since it is not writable anymore. The 'writable' property should have the opposite value of the 'finished' property.

gireeshpunathil · 2017-07-07T13:32:54Z

thank you!

Kasher · 2017-07-08T16:58:20Z

Thanks for approving this @gireeshpunathil .
Just asking since I'm not sure - how do we proceed? Should we open a CI?
Thanks in advance!

gireeshpunathil · 2017-07-09T02:11:33Z

@Kasher - thanks for checking. Let us wait for one or two more reviews.
/cc @nodejs/http @nodejs/streams
CI: https://ci.nodejs.org/job/node-test-pull-request/9049/

mcollina

Good spot. I think this should be fixed, but I also think that OutgoingMessage.pipe() should throw an exception.

mcollina · 2017-07-10T07:10:46Z

test/parallel/test-http-outgoing-finish-writable.js

+    port: server.address().port,
+    method: 'GET',
+    path: '/'
+  }).end();


What http.request returns is an OutgoingMessage as well, we might want to change that it there as well.

mcollina · 2017-07-10T07:12:30Z

test/parallel/test-pipe-outgoing-message-data-emitted-after-ended.js

+
+    // If we got here - 'write after end' wasn't raised and the test passed.
+    setTimeout(() => server.close(), 10);
+  }, 10);


This is going to be very flaky. Can you refactor the test to not rely on timers?

Sure thing. I totally agree with you. Basically I needed setTimeout with a timeout of zero (or process.nextTick). I'll change to one of these.

mcollina · 2017-07-10T07:25:55Z

test/parallel/test-pipe-outgoing-message-data-emitted-after-ended.js

+const server = http.createServer(common.mustCall(function(req, res) {
+  console.log('Got a request, piping an OutgoingMessage to it.');
+  const outgointMessage = new OutgoingMessage();
+  outgointMessage.pipe(res);


OutgoingMessage should really be write-only, and not be piped. The fact that OutgoingMessage has a pipe method is related to Node.js history, and it should not be used. Why Does this use case matter to you?

I agree. OutgoingMessage is just an example of a type that inherits from Stream. A better practice would be to create a new type that inherits from Stream and use this in the test. I would change this.

I chose OutgoingMessage since if I pipe from it, the outcome will be very similar to what happens when I use request npm .

I guess this should either be disabled (by throwing an exception as you suggested), or it should work.
Here is what they do in request npm:

They call to pipe on a type that inherits from Stream (the type is called Request):
https://github.com/request/request/blob/master/request.js#L1489

Upon data on an IncomingResponse, they emit this on the Request:
https://github.com/request/request/blob/master/request.js#L1082

For more detailed explanation you can read my reply: #14024 (comment)

Kasher · 2017-07-10T12:13:51Z

@mcollina, Thank you very much for you review.
I totally agree with your comments.
The write after end error is raised when I use request npm and when I call their implementation of pipe. Lets go over this:
First, I guess request npm implemented pipe as they did to support something like that:

req.pipe(request('http://mysite.com/doodle.png')).pipe(resp)

(taken from their main page).

We can see from their source code, that when I call pipe on a Request (which is a type that inherits from Stream: https://github.com/request/request/blob/master/request.js#L131 ), they basically call stream's pipe: https://github.com/request/request/blob/master/request.js#L1489 .

Then, they create a ClientRequest: https://github.com/request/request/blob/master/request.js#L748 .
When the response event is raised, they call a method called onRequestResponse: https://github.com/request/request/blob/master/request.js#L772

In this method, we can see that they register to the reponse's data event, and they emit it on the Request (the type that inherits from Stream and was originally piped): https://github.com/request/request/blob/master/request.js#L1082

This might raise the write after end error, and this is what I try to avoid.

I will try to refactor my unit tests so they won't use OutgoingMessage. In other words, I will reproduce such behavior with a custom type that inherits from Stream, instead of abusing OutgoingMessage.

However, I guess their current implementation shouldn't cause the write after end flow, since this if clause: https://github.com/nodejs/node/blob/master/lib/internal/streams/legacy.js#L15 should return false (which doesn't happen now, and that's what my PR fixes).

Should I throw an exception in OutgoingMessage's pipe method as well (as it should be write-only and shouldn't be piped)? It won't solve the issue, but it might save some time to other developers that try to pipe from OutgoingMessage for some reason.

Thanks again, waiting for your reply for further instructions :)

mcollina · 2017-07-10T13:04:16Z

@Kasher looking at request code, the problem you are facing does not come down from OutgoingMessage, but from the Request object (https://github.com/request/request/blob/master/request.js#L118), as they are not setting writable = false either.

Kasher · 2017-07-10T14:49:29Z

@mcollina Thanks, but I'm not sure I fully understand what you mean. I pipe a Request object to a ServerResponse object (in order to pipe something from the internet back to the client). ServerResponse inherits from OutgoingMessage: https://github.com/nodejs/node/blob/master/lib/_http_server.js#L122 .
The code here: https://github.com/nodejs/node/blob/master/lib/internal/streams/legacy.js#L15 checks if the destination is writable, and if I understand this correctly - the destination is an instance of ServerResponse (which means it is also an instance of OutgoingMessage).

Did I miss something?

Thanks again :)

mcollina · 2017-07-10T15:37:34Z

I think your request example is calling Response.prototype.pipe, not OutgoingMessage.prototype.pipe.

Kasher · 2017-07-10T17:21:44Z

@mcollina Thanks again, but I'm not sure I get it. I use serverRequest.pipe(res); in my example, where serverRequest is an instance of Request. So basically I call Request.prototype.pipe, which calls to Stream.prototype.pipe:

In this call, self is my serverRequest (an instance of Request), and dest is res (an instance of ServerResponse).

Later on, when data is emitted on serverRequest, we reach this code: https://github.com/nodejs/node/blob/master/lib/internal/streams/legacy.js#L15
and over here, again, dest is my res, which is a ServerResponse, which inherits from OutgoingMessage. So the call to write is executed on an OutgoingMessage (in addition, the fact that we see

Error: write after end
    at ServerResponse.OutgoingMessage.write (_http_outgoing.js:442:15)at  ServerResponse.OutgoingMessage.write (_http_outgoing.js:442:15)

in the stack supports this). In addition, when I added the fix, the error is never thrown (in other words, I couldn't reproduce this issue).

What did I miss?

Thanks.

mcollina · 2017-07-10T17:31:04Z

@Kasher in this line https://github.com/nodejs/node/pull/14024/files#diff-f48f06a77b4005be724d14b42ab7f87dR9, you are testing the reverse of that pipe.

Kasher · 2017-07-10T19:27:54Z

@mcollina Oh, you're talking about the test!
Sorry, I totally misunderstood you. I was talking about this issue I opened: #14023

Regarding the test - You're right. OutgoingMessage is just an example of a type that inherits from Stream. It was simple and quick for me to try and reproduce it using this type. A better practice would be to create a new type that inherits from Stream and to use this in the test. I will change this.

Should I add throw an exception in OutgoingMessage's pipe function? This would have saved us several hours :)

Thanks again, and sorry for the inconvenience.

mcollina · 2017-07-10T19:39:24Z

Let's separate the .pipe() change to the .writable = false change as the first would be semver-major.

Kasher · 2017-07-11T15:29:23Z

@mcollina , I've made the required changes.
I hope the tests are better now. I would really appreciate it if you could take a look.

Thanks!

mcollina

There a bit more nits on the test, but this looks good.

LGTM when those are solved.

mcollina · 2017-07-11T15:31:25Z

test/parallel/test-http-outgoing-finish-writable.js

+  assert(res.writable, 'Res should be writable when it is received \
+                          and opened.');
+  assert(!res.finished, 'Res shouldn\'t be finished when it is received \
+                          and opened.');


Can you use assert.strictEqual without a message here and in the rest of the tests?

mcollina · 2017-07-11T15:32:18Z

test/parallel/test-http-outgoing-finish-writable.js

+const common = require('../common');
+const assert = require('assert');
+const http = require('http');
+


can you add a little comment explaining what this test is about here?

mcollina · 2017-07-11T15:54:54Z

test/parallel/test-pipe-outgoing-message-data-emitted-after-ended.js

+  myStream.pipe(res);
+
+  process.nextTick(() => {
+    console.log('Closing response.');


can you remove the console.log statements?

mcollina · 2017-07-11T15:55:39Z

test/parallel/test-pipe-outgoing-message-data-emitted-after-ended.js

+
+    // If we got here - 'write after end' wasn't raised and the test passed.
+    process.nextTick(() => server.close());
+  });


I would also add common.mustCall on both the process.nextTick.

Kasher · 2017-07-11T17:16:11Z

@mcollina done :)

mcollina · 2017-07-12T07:58:20Z

test/parallel/test-pipe-outgoing-message-data-emitted-after-ended.js

+const http = require('http');
+const util = require('util');
+const stream = require('stream');
+


Can you add a little explanation here as well?

mcollina · 2017-07-30T11:02:01Z

This is ok to be backported to 6.x when the time is due.

Kasher · 2017-07-30T11:49:18Z

Thank you very much @mcollina @TimothyGu !
Much appreciated :)

MylesBorins · 2017-08-16T07:25:31Z

@mcollina what about v4.x? would you consider this a major bug?

When an OutgoingMessage is closed (for example, using the `end` method), its 'writable' property should be changed to false - since it is not writable anymore. The 'writable' property should have the opposite value of the 'finished' property. PR-URL: #14024 Fixes: #14023 Reviewed-By: Matteo Collina <matteo.collina@gmail.com> Reviewed-By: Gireesh Punathil <gpunathi@in.ibm.com>

mcollina · 2017-08-16T07:31:40Z

I'm ok with backporting to 6.x and 4.x.

When an OutgoingMessage is closed (for example, using the `end` method), its 'writable' property should be changed to false - since it is not writable anymore. The 'writable' property should have the opposite value of the 'finished' property. PR-URL: #14024 Fixes: #14023 Reviewed-By: Matteo Collina <matteo.collina@gmail.com> Reviewed-By: Gireesh Punathil <gpunathi@in.ibm.com>

mcollina · 2017-09-14T09:24:54Z

Unfortunately we need to revert this: #15404.

Setting writable = false in IncomingMessage.end made some errors being swallowed in some very popular OSS libraries that we must support. This commit add some of those use cases to the tests, so we avoid further regressions. We should reevaluate how to set writable = false in IncomingMessage in a way that does not break the ecosystem. See: nodejs#14024 Fixes: nodejs#15029

Setting writable = false in IncomingMessage.end made some errors being swallowed in some very popular OSS libraries that we must support. This commit add some of those use cases to the tests, so we avoid further regressions. We should reevaluate how to set writable = false in IncomingMessage in a way that does not break the ecosystem. See: #14024 Fixes: #15029 PR-URL: #15404 Reviewed-By: James M Snell <jasnell@gmail.com> Reviewed-By: Colin Ihrig <cjihrig@gmail.com> Reviewed-By: Ruben Bridgewater <ruben@bridgewater.de>

Setting writable = false in IncomingMessage.end made some errors being swallowed in some very popular OSS libraries that we must support. This commit add some of those use cases to the tests, so we avoid further regressions. We should reevaluate how to set writable = false in IncomingMessage in a way that does not break the ecosystem. See: nodejs/node#14024 Fixes: nodejs/node#15029 PR-URL: nodejs/node#15404 Reviewed-By: James M Snell <jasnell@gmail.com> Reviewed-By: Colin Ihrig <cjihrig@gmail.com> Reviewed-By: Ruben Bridgewater <ruben@bridgewater.de>

MylesBorins · 2017-10-16T21:58:13Z

Looks like this never made it to v4.x or 6.x

phew

mcollina · 2017-10-16T22:03:02Z

This was close.

missbruni · 2018-04-24T15:10:15Z

How should we be solving this issue? Is there another resolution? I am having the same bug when trying to pipe streams.

nodejs-github-bot added the http Issues or PRs related to the http subsystem. label Jul 1, 2017

Kasher mentioned this pull request Jul 1, 2017

Write after end when piping a ClientRequest to ServerResponse #14023

Closed

Kasher force-pushed the http_outgoing_mark_as_not_writable_upon_close branch 2 times, most recently from 641175f to 554d987 Compare July 7, 2017 12:38

Kasher force-pushed the http_outgoing_mark_as_not_writable_upon_close branch from 554d987 to 28b4f4d Compare July 7, 2017 12:53

Kasher force-pushed the http_outgoing_mark_as_not_writable_upon_close branch from 28b4f4d to 20b6326 Compare July 7, 2017 12:59

gireeshpunathil approved these changes Jul 7, 2017

View reviewed changes

mcollina requested changes Jul 10, 2017

View reviewed changes

Review fixes.

17365ea

mcollina reviewed Jul 11, 2017

View reviewed changes

Review fixes 2.0.

fd89a7e

mcollina reviewed Jul 12, 2017

View reviewed changes

MylesBorins added land-on-v6.x and removed lts-watch-v6.x labels Aug 16, 2017

MylesBorins mentioned this pull request Aug 16, 2017

v6.11.3-proposal #14852

Merged

SimenB mentioned this pull request Aug 25, 2017

Possible bug in streams between node 8.1.4 and 8.2.0 #15029

Closed

trygve-lie mentioned this pull request Aug 30, 2017

"premature close" error not thrown in node 8.2.0 or newer mafintosh/end-of-stream#14

Closed

mcollina mentioned this pull request Sep 14, 2017

http: revert #14024 writable is never set to false #15404

Closed

3 tasks

mcollina added dont-land-on-v6.x and removed land-on-v6.x labels Sep 14, 2017

jasnell mentioned this pull request Sep 20, 2017

Node.js 8.6.0 Release Proposal #15509

Merged

ronag mentioned this pull request Jul 16, 2019

http: writable set to false #28715

Closed

4 tasks

http: OutgoingMessage change writable after end #14024

http: OutgoingMessage change writable after end #14024

Conversation

Kasher commented Jul 1, 2017

Checklist

Affected core subsystem(s)

gireeshpunathil commented Jul 2, 2017

Kasher commented Jul 2, 2017

gireeshpunathil commented Jul 3, 2017

Kasher commented Jul 7, 2017

gireeshpunathil commented Jul 7, 2017

Kasher commented Jul 8, 2017

gireeshpunathil commented Jul 9, 2017

mcollina left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Kasher Jul 10, 2017 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Kasher Jul 10, 2017 • edited Loading

Choose a reason for hiding this comment

Kasher commented Jul 10, 2017 • edited Loading

mcollina commented Jul 10, 2017

Kasher commented Jul 10, 2017

mcollina commented Jul 10, 2017

Kasher commented Jul 10, 2017 • edited Loading

mcollina commented Jul 10, 2017

Kasher commented Jul 10, 2017 • edited Loading

mcollina commented Jul 10, 2017

Kasher commented Jul 11, 2017

mcollina left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Kasher commented Jul 11, 2017

Choose a reason for hiding this comment

mcollina commented Jul 30, 2017

Kasher commented Jul 30, 2017

MylesBorins commented Aug 16, 2017

mcollina commented Aug 16, 2017

mcollina commented Sep 14, 2017

MylesBorins commented Oct 16, 2017

mcollina commented Oct 16, 2017

missbruni commented Apr 24, 2018

Kasher Jul 10, 2017 •

edited

Loading

Kasher Jul 10, 2017 •

edited

Loading

Kasher commented Jul 10, 2017 •

edited

Loading

Kasher commented Jul 10, 2017 •

edited

Loading

Kasher commented Jul 10, 2017 •

edited

Loading