expressjs / express

Fast, unopinionated, minimalist web framework for node.
https://expressjs.com
MIT License
65.58k stars 16.17k forks source link

Sometimes my express app seems to be into IO-blocking mode, until I press `Ctrl+C` in cmd window to abort #3363

Closed chenzx closed 7 years ago

chenzx commented 7 years ago

I setup a test webapp server to return some JSON data use the res.json(...) API with Node 6.10 and express 4.15.3. And I enabled the gzip compression and chunked encoding(seems it's node default?)

Then i found that if client side sends too many requests, then express server side seems to be into a IO-blocking mode, i then tried Ctrl+C to end the node process in command window, but weirdly, express output a lot of console.log message, and then everything returns to normal state.

By not knowing the why, i tried to add res.end() after each res.json() call, then this weird scene just went away. But i can't understand what happened.

(1)If i enable the gzip compression and set Content-Length, then clients may wait untill the enough compressed bytes received, (2)If i both enable the gzip compression and the chunked encoding, no Content-Length, then due to no explicit marks to say data is fully received, server side MUST use res.end() to close the socket connection?

dougwilson commented 7 years ago

Hi @chenzx that sounds very strange, and I don't think I've heard of this issue before. I would love to try to debug through it, but need some more information:

Can you provide a full example app that has this issue and provide instructions for how to trigger the app to get into this state? Thanks for the report!

chenzx commented 7 years ago

Sample code is here: https://github.com/chenzx/node-neteaseCloudMusic-mockserver/blob/master/app.js To sum, it's a simple test server which mocks a music service web api, which provides json data response and mp3 download.

Maybe there is some API mis-use?

dougwilson commented 7 years ago

Thanks for the example!

Maybe there is some API mis-use?

It's possible, but that code example at almost 500 lines long is too long to really eye-ball for any. Perhaps if you can provide instructions for how to trigger the app to get into the state you described I can at least then just look at a subsection of the app?

chenzx commented 7 years ago

I guess that, maybe it's due to client browser kernel's max 6 concurrent connections per host limit. But if so, the io blocking side should be client, not the express server side.

Also i can't understand why Ctrl+C will trigger the server's blocking state to unblocked. Maybe some io is been buffered and a signal just flushes it?

Or maybe it's due to my premature hack, which tries to log the response headers JUST before they will be sent to client, (following the compression middleware's hacks)?

chenzx commented 7 years ago

I just checked some code, express's res.json() just calls res.send(), which will set Content-Length header field, but if i force to enable gzip compression, then the middleware expression will remove the Content-Length field, and the final response will be Content-Encoding: gzip and Transfer-Encoding: chunked applied.

I guess when this happens, server code MUST calls the res.end() in the final app.get(), or the client will continue to wait for data, since there is no Connection: close set, the under tcp socket will keep open, which finally reaches the browser's max 6-connection limit?

dougwilson commented 7 years ago

I'm not sure, as res.send() already calls res.end() internally. I would love to help figure it out, attach a debugger to the app and see where it is going wrong. Perhaps if you can provide instructions for how to trigger the app to get into the state you described I can?

chenzx commented 7 years ago

Also there is a difference: the client doesn't set Connection: close; to JSON request, but the static mp3 file request is sent by gstreamer module, which set a Connection: close, which hopes the server side close the connection after the data fully sent.

In a production env, CDN always should follow the client's Connection: close hint, but in my testing server script case, i just programmed a fake CDN server which is in the same express app. Maybe the express's server-static middleware doesn't respect the Connection: close hint?

This is just a guess. Currently i still can't figure out why. Perhaps it's due to NodeJS's non-blocking IO: every IO operation needs a callback notify, but sometime the callback just doesn't trigger, which is hard to track the exact reason.

dougwilson commented 7 years ago

Express.js just sits on top of the Node.js core "http" module and it's server. Node.js core is what handles the Connection: close stuff. If the connection is not closing, that is likely a bug in the Node.js core itself.

dougwilson commented 7 years ago

If you are interested, all the logic to handle the connection: close stuff is in https://github.com/nodejs/node/blob/master/lib/_http_outgoing.js

dougwilson commented 7 years ago

Closing since since there hasn't been a follow up. I don't know how to reproduce, and it sounds like a Node.js core bug.