René's URL Explorer Experiment

{"@context":"https://schema.org","@type":"DiscussionForumPosting","headline":"Write after end when piping a ClientRequest to ServerResponse","articleBody":"* **Version**: v4.8.3\r\n* **Platform**: Linux\r\n\r\nHey,\r\n\r\nI 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) :\r\n`this.writable = true;`\r\nAs 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.\r\nHowever, 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`. \r\n\r\nThe 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` .\r\n\r\nThis 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.\r\n\r\nThe following simple code reproduces this (note that I use the `request` npm):\r\n\r\nServer:\r\n```\r\n'use strict';\r\nconst http = require('http');\r\nconst port = 9876;\r\nconst request = require('request');\r\n\r\n// ***************** Server ******************\r\n\r\n// URL of some big file that we want to stream to the client.\r\nconst bigFileUrl = \"http://distribution.bbb3d.renderfarming.net/video/mp4/bbb_sunflower_native_60fps_normal.mp4\";\r\n\r\nconst requestHandler = (req, res) =\u003e {\r\n    console.log(\"Server: Got a new request.\");\r\n\r\n    // Creating a server request to some file\r\n    let requestOptions = {\r\n        url: bigFileUrl\r\n    };\r\n    let serverRequest = request(requestOptions);\r\n    // Piping the data from the server's request to the client's response\r\n    serverRequest.pipe(res);\r\n\r\n    // When the client's request is ended, closing the client's response and the server's request\r\n    req.on('close', () =\u003e {\r\n        console.log(\"Server: Client request was closed, closing server's request and client's response.\");\r\n        res.end();\r\n        serverRequest.abort();\r\n    });\r\n}\r\n\r\nconst server = http.createServer(requestHandler);\r\n\r\nserver.listen(port, (err) =\u003e {\r\n    console.log('server is listening on ', port);\r\n});\r\n```\r\n\r\nClient:\r\n```\r\n'use strict';\r\nconst http = require('http');\r\nconst port = 9876;\r\nconst request = require('request');\r\nconst stream = require('stream');\r\n\r\n// ***************** Client ******************\r\n\r\nfunction randomInt(low, high) {\r\n    return Math.floor(Math.random() * (high - low) + low);\r\n}\r\n\r\nlet requestId = 0;\r\nlet concurrentRequests = 0;\r\n\r\nsetInterval(function() {\r\n    const currentRequestId = ++requestId;\r\n    const timeout = randomInt(0, 3000);\r\n    console.log(\"Client: Initiating a new request with id \", currentRequestId, \". Closing after \", timeout, \r\n    \t\t\t\"ms. There are currently \", (++concurrentRequests), \" concurrent requests.\");\r\n\r\n    let req = request({\r\n        url: \"http://localhost:\" + port\r\n    });\r\n    // piping the response to some stream. Doesn't really matter to which stream.\r\n    let outputStream = new stream.Writable({\r\n\t  write: function(chunk, encoding, next) {\r\n\t    next();\r\n\t  }\r\n\t});\r\n    req.pipe(outputStream);\r\n\r\n    setTimeout(function() {\r\n        console.log(\"Client: Closing request number\", currentRequestId, \". There are currently \", (--concurrentRequests), \" concurrent requests.\");\r\n        req.abort();\r\n    }, timeout);\r\n\r\n}, 100);\r\n```\r\n\r\nSimple output (of the server):\r\n\r\n```\r\nnode server_write_after_end.js \r\nserver is listening on  9876\r\nServer: Got a new request.\r\nServer: Got a new request.\r\nServer: Got a new request.\r\nServer: Got a new request.\r\nServer: Got a new request.\r\nServer: Client request was closed, closing server's request and client's response.\r\nServer: Client request was closed, closing server's request and client's response.\r\nServer: Got a new request.\r\nServer: Got a new request.\r\nServer: Got a new request.\r\nServer: Client request was closed, closing server's request and client's response.\r\nServer: Got a new request.\r\nServer: Got a new request.\r\nServer: Got a new request.\r\nServer: Got a new request.\r\nServer: Got a new request.\r\nServer: Client request was closed, closing server's request and client's response.\r\nstream.js:74\r\n      throw er; // Unhandled stream error in pipe.\r\n      ^\r\n\r\nError: write after end\r\n    at ServerResponse.OutgoingMessage.write (_http_outgoing.js:442:15)\r\n    at Request.ondata (stream.js:31:26)\r\n    at emitOne (events.js:77:13)\r\n    at Request.emit (events.js:169:7)\r\n    at IncomingMessage.\u003canonymous\u003e (/home/roee/dev/flash-testing/node_modules/request/request.js:1088:12)\r\n    at emitOne (events.js:77:13)\r\n    at IncomingMessage.emit (events.js:169:7)\r\n    at IncomingMessage.Readable.read (_stream_readable.js:368:10)\r\n    at flow (_stream_readable.js:759:26)\r\n    at resume_ (_stream_readable.js:739:3)\r\n```\r\n\r\nAs 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:\r\n`if (dest.writable) { ... } `\r\nSo, if my `OutgoingMessage`'s `writable` property was indeed changed to false once it was closed, the error wouldn't have been raised at all.\r\n\r\nNote 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.\r\n\r\nI've opened a PR with a fix to this issue:\r\n#14024 \r\nAfter applying this fix, my application works as expected and I never get any `write after end` errors in my scenario.\r\n\r\nAny help will be appreciated.\r\nThanks!\r\n\r\n\r\n\r\n\r\n\r\n","author":{"url":"https://github.com/Kasher","@type":"Person","name":"Kasher"},"datePublished":"2017-07-01T11:17:29.000Z","interactionStatistic":{"@type":"InteractionCounter","interactionType":"https://schema.org/CommentAction","userInteractionCount":3},"url":"https://github.com/14023/node/issues/14023"}