Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Error [ERR_MULTIPLE_CALLBACK]: Callback called multiple times #369

Open
MBR-0001 opened this issue May 14, 2020 · 21 comments
Open

Error [ERR_MULTIPLE_CALLBACK]: Callback called multiple times #369

MBR-0001 opened this issue May 14, 2020 · 21 comments

Comments

@MBR-0001
Copy link

MBR-0001 commented May 14, 2020

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
Copy link

ryanoshea commented May 17, 2020

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
Copy link
Author

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

@hotyhuang
Copy link

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
Copy link

gaxolio commented Jun 8, 2020

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
Copy link

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
Copy link

gaxolio commented Jun 11, 2020

@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
Copy link

gaxolio commented Jun 15, 2020

@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
Copy link

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
Copy link

gaxolio commented Jun 16, 2020

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
Copy link

@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
Copy link

nemphys commented Sep 21, 2020

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
Copy link

aphix commented Sep 23, 2020

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
Copy link

nemphys commented Sep 23, 2020

@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
Copy link

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
Copy link

aphix commented Sep 23, 2020

@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
Copy link

aphix commented Sep 24, 2020

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
Copy link

JoshOY commented Nov 10, 2020

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

@gaxolio
Copy link

gaxolio commented Nov 18, 2020

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
Copy link

JoshOY commented Nov 18, 2020

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
Copy link

gaxolio commented Nov 18, 2020

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
Copy link

JoshOY commented Nov 18, 2020

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 :-)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Development

No branches or pull requests

7 participants