Timeout event after response finish

[PeterBurner]

hi there

I'm experiencing a weird timeout problem. Please look at the following pseudocode:

const httpLib = require('http'),
    proxyLib = require('http-proxy');

const proxy = proxyLib
    .createProxyServer({
        changeOrigin: true,
        proxyTimeout: 10000,
        timeout: 15000
    })
    .on('proxyRes', (proxyRes, req, res) => {
        console.log(req.socket.timeout); // 15000ms
        res.once('finish', () => {
            req.socket.myFinished = true;
            console.log(req.socket.timeout); // 5000ms
            console.log(new Date().getTime() - req.socket.myTimestamp); // 100ms
            console.log('response sent');
        })
    })
    .on('error', () => console.log('not called on timeout'));

const server = httpLib
    .createServer((req, res) => {
        req.socket.myTimestamp = new Date().getTime();
        proxy.web(req, res, { target: '...' })
    })
    .on('timeout', (socket) => {
        console.log(socket.timeout); // 5000ms
        console.log(new Date().getTime() - socket.myTimestamp); // 5023ms
        console.log(socket.myFinished); // true
        console.log('timeout');
    });

I am using http-proxy v1.18.0. I have a pretty normal configuration. I relay requests to another server. Everything works just fine. I don't get any error responses or timeouts on clientside. BUT there are random timeout events in Node. They are independend of client and proxy target. Whats weird about them is that they occur after the response finish event. As far as I understand it, this event is emited after all the response data is sent to the client. So why is there a timeout after this? Also the socket.timeout property seems to be reset after the response is sent. Before it has the correct value I passed to http-proxy afterwards its always 5000. If I debug my code and look at the call stack, the timeout event originates form this line: web-incoming.js#L185

Can somebody please explain to me why these timeoutes occur and how I need to handle them? Can I ignore them? Do I need to call some kind of .close() on the socket? Is there maybe a .end() missing in the line mentioned above? ...

Side note: if I add a AWS Web Application Firewall infront of my server those timeout events occur more often (about one event every ten seconds instead of one every two minutes). Since the WAF does not modify the traffic content my guess would be that this whole problem originates somewhere pretty low level.

Thanks in advance Peter

[paulrutter]

I'm having a very similar issue with the same configuration. Having a hard timing tracking where the timeout is coming from.

All proxied requests seem to work just fine, although our logging shows intermittent timeouts. Version used: 1.18.0, Node.js 12.16.1

[p0fi]

I'm seeing the same behavior on my setup. The timeouts seem very random.

[paulrutter]

To make sure this module is the cause of the timeout issues, i've updated the code to not use http-proxy module, but use "request" instead.

https://github.com/request/request

And since pipe() returns the destination stream in ≥ Node 0.5.x you can do one line proxying. :)

req.pipe(request('http://mysite.com/doodle.png')).pipe(resp)

This is another simple way of proxying a HTTP request. Up until now, the issue hasn't come up. I will be monitoring it upcoming days.

UPDATE It still keeps happening, and i narrowed it down to the "Transfer-Encoding" header which (weirdly) sometimes is present on the request. If this is the case, the request fails to be proxied properly.

[gabmontes]

I have a similar issue but it seems to be related to sending the Accept-Encoding header. If present, some responses from the proxied server are not returned to the caller. The response in m case always have Transfer-Encoding: chunked but the request header is the one that makes a difference.

Note: I'm using v1.17.0 here.

@paulrutter any other clue on what might be happening here?

[paulrutter]

I will share my analysis on the issue:

• eventually, the node-http-proxy was not the cause of the issue
• cause: some mobile browsers/apps (especially Facebook app), sometimes send a request containing the "Transfer-Encoding: chunked" header (note that this is a request header, not a response header). In our situation, where node-http-proxy is the second "proxy" in the request chain (the first is a Java application), these hop-by-hop headers (https://www.freesoft.org/CIE/RFC/2068/143.htm) are already handled by the first proxy and thus shouldn't be proxied to node-http-proxy.
• solution: in the first proxy (the java application), all hop-by-hop headers are now filtered when sending the request to the second proxy. This solves the situation where the headers says it's sending the request in chunks, while this is not actually the case; node-http-proxy will wait endlessly for the request to be complete, while it already is.

Although not related to this module, i hope it helps narrowing down your issue.

[gabmontes]

@paulrutter thanks for the info!

After deeper analysis on my part too, this package was not the issue either. We used node-http-proxy-json to re-write the response and that one was causing problems. Fortunately the issue (https://github.com/langjt/node-http-proxy-json/issues/16) was fixed there. Updating the package seemed to fix all our problems so far.