ERR_STREAM_WRITE_AFTER_END when issuing upgrade request on non-existent URL

[jfedyczak]

On version 0.3.19 (and I believe in 0.4 also), when issuing upgrade request on wrong URL i.e. /prefix/wrongpath, fake_response calls res.end() in a try..catch block and then res.end() is being called for the second time in handle_404 method - which throws...

[newyorkpizza]

@jfedyczak What version of Node are you using? Is it v10.15.x? We've observed the same exception on Node v10.15.0 (we did not try any other v10.15.x version), but does not repro on 8.15.0.

[jfedyczak]

@newyorkpizza Yes. node 10.15.0

[cakoose]

This is reproducible with v0.3.19 and the "echo" example: https://github.com/sockjs/sockjs-node/tree/v0.3.19/examples/echo

If you start the server with Node 10.15.0 and hit it with Curl:

curl http://localhost:9999/echo/upgrade -v -X GET -H 'Connection: Upgrade' -H 'Upgrade: websocket'

The server will crash:

SockJS v0.3.19 bound to "/echo"
 [*] Listening on 0.0.0.0:9999
events.js:167
      throw er; // Unhandled 'error' event
      ^

Error [ERR_STREAM_WRITE_AFTER_END]: write after end
    at writeAfterEnd (_stream_writable.js:243:12)
    at Socket.Writable.write (_stream_writable.js:291:5)
    at Socket.Writable.end (_stream_writable.js:579:10)
    at Socket.end (net.js:548:31)
    at App.handle_404 (/Users/kannan/h/sockjs-write-after-end/node_modules/sockjs/lib/sockjs.js:61:11)
    at Listener.webjs_handler (/Users/kannan/h/sockjs-write-after-end/node_modules/sockjs/lib/webjs.js:115:28)
    at Listener.handler (/Users/kannan/h/sockjs-write-after-end/node_modules/sockjs/lib/sockjs.js:150:12)
    at Listener.handler (/Users/kannan/h/sockjs-write-after-end/node_modules/sockjs/lib/sockjs.js:6:59)
    at Server.<anonymous> (/Users/kannan/h/sockjs-write-after-end/node_modules/sockjs/lib/sockjs.js:157:24)
    at Server.new_handler (/Users/kannan/h/sockjs-write-after-end/node_modules/sockjs/lib/utils.js:86:19)
Emitted 'error' event at:
    at writeAfterEnd (_stream_writable.js:245:10)
    at Socket.Writable.write (_stream_writable.js:291:5)
    [... lines matching original stack trace ...]
    at Server.new_handler (/Users/kannan/h/sockjs-write-after-end/node_modules/sockjs/lib/utils.js:86:19)

With Node 8.15.0, the server doesn't crash:

SockJS v0.3.19 bound to "/echo"
 [*] Listening on 0.0.0.0:9999
GET /echo/upgrade 1ms (unfinished)

[macinjosh32]

Any suggestions for a patch or workaround? We’ve been seeing this crash several times per hour ever since upgrading to Node.js v10.13.0 in late 2018.

[brycekahle]

@cakoose Thanks for repro steps.

I'll take a look and see if I can solve this in a reliable way.

[cakoose]

Just checked with Node 12.10.0. The issue still occurs.

SockJS v0.3.19 bound to "/echo"
 [*] Listening on 0.0.0.0:9999
events.js:186
      throw er; // Unhandled 'error' event
      ^

Error [ERR_STREAM_WRITE_AFTER_END]: write after end
    at writeAfterEnd (_stream_writable.js:250:14)
    at Socket.Writable.write (_stream_writable.js:299:5)
    at Socket.Writable.end (_stream_writable.js:587:10)
    at Socket.end (net.js:574:31)
    at App.handle_404 (/Users/kannan/h/sockjs-write-after-end/node_modules/sockjs/lib/sockjs.js:61:11)
    at Listener.webjs_handler (/Users/kannan/h/sockjs-write-after-end/node_modules/sockjs/lib/webjs.js:115:28)
    at Listener.handler (/Users/kannan/h/sockjs-write-after-end/node_modules/sockjs/lib/sockjs.js:150:12)
    at Listener.handler (/Users/kannan/h/sockjs-write-after-end/node_modules/sockjs/lib/sockjs.js:6:59)
    at Server.<anonymous> (/Users/kannan/h/sockjs-write-after-end/node_modules/sockjs/lib/sockjs.js:157:24)
    at Server.new_handler (/Users/kannan/h/sockjs-write-after-end/node_modules/sockjs/lib/utils.js:86:19)
Emitted 'error' event on Socket instance at:
    at errorOrDestroy (internal/streams/destroy.js:107:12)
    at writeAfterEnd (_stream_writable.js:252:3)
    at Socket.Writable.write (_stream_writable.js:299:5)
    [... lines matching original stack trace ...]
    at Server.<anonymous> (/Users/kannan/h/sockjs-write-after-end/node_modules/sockjs/lib/sockjs.js:157:24)

[cakoose]

@brycekahle: This is blocking our Node upgrade and so I'm thinking about taking a deeper look. Any pointers?

[brycekahle]

@cakoose By chance, have you tried the master branch?

[cakoose]

Yes, still happens on master (pulled from Git today)

$ ~/node/master-2019-11-19/bin/node server.js
SockJS v0.3.19 bound to "/echo"
 [*] Listening on 0.0.0.0:9999
events.js:187
      throw er; // Unhandled 'error' event
      ^

Error [ERR_STREAM_WRITE_AFTER_END]: write after end
    at writeAfterEnd (_stream_writable.js:259:14)
    at Socket.Writable.write (_stream_writable.js:308:5)
    at Socket.Writable.end (_stream_writable.js:605:10)
    at Socket.end (net.js:580:31)
    at App.handle_404 (/Users/kannan/h/node-write-after-end/sockjs/node_modules/sockjs/lib/sockjs.js:61:11)
    at Listener.webjs_handler (/Users/kannan/h/node-write-after-end/sockjs/node_modules/sockjs/lib/webjs.js:115:28)
    at Listener.handler (/Users/kannan/h/node-write-after-end/sockjs/node_modules/sockjs/lib/sockjs.js:150:12)
    at Listener.handler (/Users/kannan/h/node-write-after-end/sockjs/node_modules/sockjs/lib/sockjs.js:6:59)
    at Server.<anonymous> (/Users/kannan/h/node-write-after-end/sockjs/node_modules/sockjs/lib/sockjs.js:157:24)
    at Server.new_handler (/Users/kannan/h/node-write-after-end/sockjs/node_modules/sockjs/lib/utils.js:86:19)
Emitted 'error' event on Socket instance at:
    at errorOrDestroy (internal/streams/destroy.js:128:12)
    at writeAfterEnd (_stream_writable.js:261:3)
    at Socket.Writable.write (_stream_writable.js:308:5)
    [... lines matching original stack trace ...]
    at Server.<anonymous> (/Users/kannan/h/node-write-after-end/sockjs/node_modules/sockjs/lib/sockjs.js:157:24) {
  code: 'ERR_STREAM_WRITE_AFTER_END'
}

Also happens on the 12.13.1 proposed release branch, which is what we want to upgrade to.

[brycekahle]

@cakoose I opened #265 which I believe should fix the issue. Do you need a backport to 0.3.X?

[cakoose]

Oh, thanks!

And yes, a backport would be appreciated. But I can also just fork and cherry-pick for the time being.

[grabopaw]

When do you plan to release sockjs 0.4 ? (with ERR_STREAM_WRITE_AFTER_END fix, or fix backport to 0.3.19)
I encountered the issue by using webpack-dev-server module (which has sockjs "0.3.19" as dependency )