Error [ERR_MULTIPLE_CALLBACK]: Callback called multiple times

[MBR-0001]

Error [ERR_MULTIPLE_CALLBACK]: Callback called multiple times
at onwrite (_stream_writable.js:465:11)
at WriteWrap.onWriteComplete [as oncomplete] (internal/stream_base_commons.js:82:12)
at E:\stuff\node_modules\handle-thing\lib\handle.js:204:9
at afterWrite (E:\stuff\node_modules\spdy-transport\node_modules\readable-stream\lib_stream_writable.js:469:3)
at onwrite (E:\stuff\node_modules\spdy-transport\node_modules\readable-stream\lib_stream_writable.js:461:7)
at WritableState.onwrite (E:\stuff\node_modules\spdy-transport\node_modules\readable-stream\lib_stream_writable.js:160:5)
at processTicksAndRejections (internal/process/task_queues.js:75:11)

how to reproduce: send a video to a browser and while it is loading (and playing) the video reload the page

[ryanoshea]

I also see this issue when using spdy in an Express.js app that uses an async pattern in one of its request handlers. ryanoshea/ryanoshea.com#31. It only happens on Node v12, but not v10.

[MBR-0001]

This happens to me when sending files using express on node v13

[hotyhuang]

I am facing the same issue when upgrading nodejs from v10.15.3 to v12.17.0 -lts, wanted to open a same issue...
My env:

"express": "4.17.1"
"spdy": "4.0.1",

If someone needs a POC, I can create a github repo to reproduce.

[gaxolio]

Hi, I too have the same problem.
Unfortunately I can't reproduce the problem.
Sometimes, when it happens and nodejs crashes, "forever process" can't get it started again.
MyEnv
NodeJs v12.16.1
Express 4.17.1
Spdy 4.0.2

` _stream_writable.js:475
throw new ERR_MULTIPLE_CALLBACK();
^

Error [ERR_MULTIPLE_CALLBACK]: Callback called multiple times
at onwrite (_stream_writable.js:475:11)
at WriteWrap.onWriteComplete [as oncomplete] (internal/stream_base_commons.js:87:12)
at Immediate._onImmediate (/webserver/node_modules/handle-thing/lib/handle.js:127:11)
at processImmediate (internal/timers.js:456:21) {
code: 'ERR_MULTIPLE_CALLBACK'
NODEJS: }`

[hotyhuang]

Hi, I created the POC, and also found a fix to the library handle-thing. Plz check:
https://github.com/hotyhuang/SSEexample

Fix: spdy-http2/handle-thing#16

[gaxolio]

@hotyhuang I'm trying your modification and it seems to work !!!
I do further tests.
Great!!!

Hi, I created the POC, and also found a fix to the library handle-thing. Plz check:
https://github.com/hotyhuang/SSEexample

Fix: spdy-http2/handle-thing#16

[gaxolio]

@hotyhuang ,
Hi, I have done further tests and the error still appears. much less than before. Before your change, we used nodejs v.12.16.1 and the error occurred every now and then. Then we moved on to version v.12.6.3 and the error was continuous. Now, after your modification, even with version 12.16.3. the error rarely appears but reappears. I can add that I use the nodejs npm sse-channel v.3.1.1 package.

Hi, I created the POC, and also found a fix to the library handle-thing. Plz check:
https://github.com/hotyhuang/SSEexample

Fix: spdy-http2/handle-thing#16

[hotyhuang]

Hi @gaxolio ,
Thanks for the feedback. But everything running fine on my end, even by using node v12.16.3. Do you have the steps to reproduce? or if you can create a github repo that will be perfect.

Hi, I have done further tests and the error still appears. much less than before. Before your change, we used nodejs v.12.16.1 and the error occurred every now and then. Then we moved on to version v.12.6.3 and the error was continuous. Now, after your modification, even with version 12.16.3. the error rarely appears but reappears. I can add that I use the nodejs npm sse-channel v.3.1.1 package.

[gaxolio]

Hi @hotyhuang , I can't reproduce the problem systematically.
As I said, I use sse-channel, a shared-worker on my client opens 4 streams (/ stream/1, / stream/2 ...) connected with the 'h2' protocol.
On the webserver (node 12.16.3) 4 distinct channels are opened (sseChannel1, sseChannel2 ...) and then events are sent. Occasionally an error occurs when sending events.

In short here are the steps for each stream(4):

1 - app.get('/streams/x', function(req, res) {...
2 - let confStatusChannel = new SseChannel();
3 - confStatusChannel.addClient(req, res, function(err){...
4 - when an event is generated
5 - confStatusChannel.send({ id: id, event: event, data: strdata });

Occasionally the error appears when sending an event, nodejs no longer responds and I have to restart it. It does not end with an error.
I understand that this information is not enough but I can't post the code.
Thanks

[hotyhuang]

@gaxolio I cannot get the error as you've mentioned, everything looks fine with the fix.... Created a repo by sse-channel, maybe you can help decorate this repo, to reproduce the issue:
https://github.com/hotyhuang/SSEexample/tree/channel

[nemphys]

I am also facing this issue randomly on canceled requests (Node v.12.18.3), but with the "fix" I always get the following error when trying to do a file upload:

TypeError: this._handle.readStop is not a function
at Socket.onSocketPause (_http_server.js:824:18)
at Socket.emit (events.js:315:20)
at Socket.Readable.pause (_stream_readable.js:996:10)
at Socket.pause (net.js:606:40)
at readStop (_http_incoming.js:37:12)
at HTTPParser.parserOnBody (_http_common.js:134:7)
at Deceiver.emitBody (\node_modules\http-deceiver\lib\deceiver.js:233:18)
at HTTPParser.execute (\node_modules\http-deceiver\lib\deceiver.js:211:10)
at socketOnData (_http_server.js:563:22)
at Socket.emit (events.js:315:20)
at addChunk (_stream_readable.js:295:12)
at readableAddChunk (_stream_readable.js:271:9)
at Socket.Readable.push (_stream_readable.js:212:10)
at Handle.onStreamRead [as onread] (internal/stream_base_commons.js:186:23)
at Handle._onread (\node_modules\handle-thing\lib\handle.js:50:10)
at Stream. (\node_modules\handle-thing\lib\handle.js:104:10)

[aphix]

Having only done a small bit of digging, it seems like a perfect storm of outright incompatibility with the HTTP/2 spec, upgrades in core node, hacks (sorry, polyfills? ponyfills? whatever it is now), and the now-outdated protocol of SPDY, combined with the fact that this package is no longer maintained for the reasons mentioned above...

For better or worse, this is the solution I found for now (still need to dig further):

Throw this near the top of after your server.listen in your entry point (e.g. node thisFile.js)

const majorNodeVersion = Number.parseInt(process.version.slice(1).split('.')[0], 10);
const isNodeV12 = majorNodeVersion === 12;

process.prependListener('uncaughtException', (error) => {
    if (isNodeV12 && error && (error.code === 'ERR_MULTIPLE_CALLBACK')) {
        console.error(error); // Do your logging here
        return; // Don't rethrow because that'll blow it all up
    }

    throw error; // Keep this to throw and shut down for every other fatal error.
})

All that said, migrate your stuff to the native http2 (in v12+) module (e.g. const httpServer = require('http2')) as soon as is reasonable.

Edit: Ended up reverting to core https module instead of spdy as the above hack is not entirely reliable.

[nemphys]

@aphix are you sure it's safe to just swallow the error? I thought this was always a no-no.

As for the http2 migration, it will be done the minute the express.js folks finally release proper support for the native implementation (if that ever happens)...

[ryanoshea]

As for the http2 migration, it will be done the minute the express.js folks finally release proper support for the native implementation (if that ever happens)...

Every couple of years I come back to this project thinking surely they’ve added support for it and so far that hasn’t worked.

[aphix]

@nemphys looking at the stack traces & profiles/flamegraphs, the same error was already thrown and caught as expected, which is what tears down the inflight req in the first place, but you're right that eating unexpected errors is generally not good, however I'd consider this one expected (if somewhat random in terms of reproducibility) at this point.

Definitely log it (as seen in the snippet) and rethrow anything else you don't expect (as in the snippet), and if you wish to restrict it further you could make sure the string/stack trace has "handle-thing" in it or something, but that seemed like a potential maintenance nightmare to me, as timing when the 2nd cb is hit could likely change the stacktrace.

This is really a bandaid to prevent that specific error from tearing down your whole server.

Note that it's far less likely to happen between two servers/applications than it is between a server and a browser client, at least.

I've actually yet to see this happen in any server-server reqs over a few million transactions during this past week, but can trigger it manually with a browser spamming refresh quite easily.

[aphix]

Following up after more testing yesterday:

There's some gnarly hack in stream_readable that force prepends its listener to uncaught exceptions as a fix for older node versions, but does not validate that the running version needs the hack before doing so, meaning that my above fix may not work in all cases so I reverted to using the native https module as I wasn't getting any benefit from HTTP/2 methods like req.push since I'm behind an AWS ALB anyway.

Good luck to others, but I've given up on getting spdy to work reliably in v12 for the time being.

[JoshOY]

The same issue troubled me recently. Found that upgrading node.js from v12.18.3 to v14.15.0 would solve this problem.

[gaxolio]

The same issue troubled me recently. Found that upgrading node.js from v12.18.3 to v14.15.0 would solve this problem.

Hi @JoshOY . Please could you confirm that after the upgrading to v14.15.0 you have definitely solved the problem?
Many thanks

[JoshOY]

The same issue troubled me recently. Found that upgrading node.js from v12.18.3 to v14.15.0 would solve this problem.

Hi @JoshOY . Please could you confirm that after the upgrading to v14.15.0 you have definitely solved the problem?
Many thanks

Hi @gaxolio ,

The background is that we are proxying https requests with an framework based on express + http-proxy-middleware during our project development. Technically speaking I'm not 100% sure about whether doing the upgrade solves all usage scenarios since the root case seems to be a runtime-level defect. But according to my colleague's and my personal observation, node v10.x and v14.x works fine, and at least we no longer meet any problem after doing the upgrade to v14. I will feedback later if there's any other bug exposed.

[gaxolio]

Hi @JoshOY , thanks for your support.
Indeed, reading the updates of version 14, I read that improvements have been made to the Streams API.
These changes may have solved the problem.
I'll try the new version in a test environment.
Thanks, bye

[JoshOY]

Hi @JoshOY , thanks for your support.
Indeed, reading the updates of version 14, I read that improvements have been made to the Streams API.
These changes may have solved the problem.
I'll try the new version in a test environment.
Thanks, bye

Glad to help! You're welcome :-)