Node 14 --> 16 seems to cause partial responses to timeout (206)

[allisonking]

Edit: made this an issue after making a minimal reproducible example #727

Hi all!

I'm seeing some strange behavior which I'd love some other thoughts on. This started happening when we upgraded to node 16 but is fixed when reverting back to node 14. Right now I have a bunch of puzzle pieces but am not sure how they go together yet.

We have a backend which streams audio using partial responses (206). Here's an example of the endpoint in our production instance. When we develop, we run it at localhost:10000, and run our frontend at localhost:3000 then rely on http-proxy-middleware to route API calls to localhost:10000. This was all working 💯 until we upgraded to node 16. Now in node 16, our requests to this endpoint cause a critical worker timeout in our backend (using gunicorn).

I isolated the frontend to a really simple express app + http-proxy-middleware as follows:

Dependencies

"express": "^4.17.3",
"http-proxy-middleware": "^2.0.3"

index.js

// include dependencies
const express = require("express");
const { createProxyMiddleware } = require("http-proxy-middleware");
// proxy middleware options
/** @type {import('http-proxy-middleware/dist/types').Options} */
const options = {
  changeOrigin: true,
  target: "http://localhost:10000",
  logLevel: "debug",
  onProxyRes: (proxyRes, req, res) => {
    // log original request and proxied request info
    const exchange = `[DEBUG] ${req.method} ${req.path} -> ${proxyRes.req.protocol}//${proxyRes.req.host}${proxyRes.req.path} [${proxyRes.statusCode}]`;
    console.log(exchange); // [DEBUG] GET / -> http://www.example.com [200]
  },
  onError: (err, req, res) => console.log({ err }),
};

// create the proxy (without context)
const exampleProxy = createProxyMiddleware(options);

// mount `exampleProxy` in web server
const app = express();
app.use("/api", exampleProxy);
app.listen(3000);

Run with

node index.js

Our backend is quite a bit more complicated to deal with chunking out audio to pass back for streaming. But it reliably times out when running node index.js with node 16, but works fine when running with node 14. Also, hitting the backend directly without the proxy has no issue.

It appears that in node 14, I would get these logs:

[HPM] Proxy created: /  -> http://localhost:10000
[HPM] Subscribed to http-proxy events: [ 'error', 'proxyRes', 'close' ]

[HPM] GET /api/conversations/play/7 -> http://localhost:10000
[DEBUG] GET /api/conversations/play/7 -> http://localhost/api/conversations/play/7 [200]
[HPM] GET /api/conversations/play/7 -> http://localhost:10000
[DEBUG] GET /api/conversations/play/7 -> http://localhost/api/conversations/play/7 [206]

Whereas in node 16, I see the same thing except that the [206] line comes much later, only after the backend has timed out.

One more thing which makes me really scratch my head: the timeout only occurs when I hit the endpoint from a browser, not if I use a CLI tool to curl it, for instance. It happens consistently in Chrome, Firefox, and Safari.

[fvilar]

Same problem here, any news?