Agent socket in proxy tunnel closes abruptly after exactly 10k requests without throwing any errors

Funecio-Agrante commented 1 month ago

Node.js Version

v22.2.0

NPM Version

10.7.0

Operating System

Linux 5.15.0-107-generic x86_64 (Ubuntu 22.04.4 LTS)

Subsystem

events, http, https

Description

I'm trying to setup a local HTTP proxy to be able to throttle HTTPS requests from several concurrent processes to the same remote server. The setup is working.

It uses a custom agent to establish a connection through the proxy. The issue is that the agent's socket closes shortly after the execution starts, as it tries to execute an https.get and

it doesn't raise any errors I could catch
with the agent option keepAlive: true, it stops execution exactly after 10000 requests, ie, as the 10001st is being executed
with the agent option keepAlive: false, it stops execution somewhere in the range of 60k-100k requests

I did a bunch of testing and I can offer a few data points:

the 'close' event emitter is always triggered, but a reject statement within the event handler doesn't do anything. On the other hand, if I force a timeout after the 10k request (and before the process exits without errors), a reject statement within the timeout event handler does get executed as expected
Node does show a warning message, but again, no errors

Warning: Detected unsettled top-level await at file[...]

a very brief test with a custom agent on a direct https.get (without proxy) doesn't stop after 10k requests, so it doesn't seem to be any problem without the proxy setup

The server code is based on this example https://scraperjs.wordpress.com/2013/10/22/a-simple-https-tunneling-proxy-in-node-js/

The client code is based on this example

https://antoinevastel.com/nodejs/2022/02/26/nodejs-optimized-https-proxy-no-dependencies.html

Minimal Reproduction

You can use this code to start the server on a separate console window

// HTTP proxy tunneling server
import { HttpProxyTunnel } from "./proxy_class.js";

const proxyConf = {
  //proxy_host: "localhost",
  proxy_port: 3000
}

const proxy = new HttpProxyTunnel(proxyConf);
proxy.startProxy();

setInterval( () => {
  console.log(`<«»> Requests/sec: ${proxy.requests_sec} <«»> Delay: ${proxy.delay} <«»>`);
}, 10000)

You can use this code to make the requests on another console window. I provide a few different public endpoints that generate JSON responses. You can easily switch in the code.

// HTTPS requests via local HTTP proxy server

import { HttpProxyTunnel } from "./proxy_class.js";

// Pause function
const sleep = (ms) => {
  return new Promise(resolve => setTimeout(resolve, ms));
}

const url1 = new URL("https://api.x.immutable.com/v1/assets?page_size=100&cursor=eyJpZCI6IjB4MTdjNjRmYzRlYWMwNTM3Y2Y3MmVlZTkyNTNkNmMyY2NkY2M3MzEwNjYxMWY1ZjlkZmJiZTUxNWM1ZWY2MTBiOSIsIm5hbWUiOiJBdmFsYW5jaGUgV2F0Y2hlciIsInVwZGF0ZWRfYXQiOiIyMDIzLTAxLTEyVDAyOjUzOjM1LjEzNDQ4NFoifQ&order_by=updated_at&direction=asc&status=imx&sell_orders=false&collection=0xacb3c6a43d15b907e8433077b6d38ae40936fe2c&metadata=%7B%22proto%22:%5B%222263%22%5D,%22type%22:%5B%22card%22%5D%7D");
const url2 = new URL("https://api.ipify.org/?format=json");
const url = new URL("https://api.x.immutable.com/v1/mints/293773199");
const url4 = new URL("https://api.open-meteo.com/v1/forecast?latitude=52.52&longitude=13.41&current=temperature_2m,wind_speed_10m&hourly=temperature_2m,relative_humidity_2m,wind_speed_10m");
const url5 = new URL("https://api.tidesandcurrents.noaa.gov/api/prod/datagetter?date=today&station=8453662&product=visibility&time_zone=lst_ldt&units=metric&format=json");

const urls = new Array(12000).fill(url);

const proxyConf = {
  proxy_host: "localhost",
  proxy_port: 3000,
  remote_host: `${url.hostname}:443`
}

const httpsClient = new HttpProxyTunnel(proxyConf);
httpsClient.proxyAgent = await httpsClient.createAgent();
httpsClient.options.agent = httpsClient.proxyAgent;

httpsClient.agentSocket.on('close', async (hadError) => {
  console.log("(proxy_debug.js) Agent socket closed. Error?", hadError);
  await sleep(20000); // set this higher than timeout in constructor to trigger timeout event emitter
  console.log("(proxy_debug.js) Total number of HTTPS requests completed", httpsClient.httpsRequests);
})

for (const [i, url] of urls.entries()) {
  console.log(`${i + 1}/${urls.length}`);
  try {
    const res = await httpsClient.getURL(url)
    .then( async response => {
      if (response.status !== 200) {
        return response.status;
      }
      return response.body;
    })
    console.log(res, "\n");
  } catch (e) {
    console.log("Caught error here")
    console.log(e)
  }
}

The bulk of the logic is in a class you can copy from this Gist https://gist.github.com/Funecio-Agrante/a01f367cff6a0acbaf1ce90558abf5bd

If you lower the timeout in the constructor to less than 20000, you will see that the timeout event emitter gets triggered and the rejectstatement inside is executed; whereas the close event emitter is executed in the inverse situation and the reject statement there doesn't produce any effect.

It should take about 20 minutes to reach 10k requests and reproduce the issue.

Output

The script stops execution without errors, only a warning (that didn't exist in node v18). By printing to console within event emitter handlers, I get this information:

(proxy_debug.js) Agent socket closed. Error? false (getURL) Agent socket state closed 2024-05-16T20:04:37.619Z (getURL) Total number of HTTPS requests completed 10000 (proxy_debug.js) Total number of HTTPS requests completed 10000 Warning: Detected unsettled top-level await at file:///home/user/Documents/immutable/card_ownership/main/proxy_debug.js:37 const res = await httpsClient.getURL(url)

Before You Submit

[X] I have looked for issues that already exist before submitting this
[X] My issue follows the guidelines in the README file, and follows the 'How to ask a good question' guide at https://stackoverflow.com/help/how-to-ask

RedYetiDev commented 1 month ago

@nodejs/http

Funecio-Agrante commented 1 month ago

I managed to fix the part about not triggering errors. I was mixing Promise error handling that uses .catch blocks with async/await error handling that uses try...catch.

I can also confirm that somewhere between node v18 and the current node v22 there was a bug fix important for this situation. After cleaning up the catch logic with node v18 the code was still exiting without triggering any catch.

I still get an error every 10k requests, but now I know what the error is and I can handle it. I would still like to know why this happens. Perhaps it's a bug?

The error is

Error: socket hang up at ClientRequest. (file:///home/user/path/to/file/) at ClientRequest.emit (node:events:520:28) at TLSSocket.socketCloseListener (node:_http_client:475:11) at TLSSocket.emit (node:events:532:35) at node:net:338:12 at done (node:_tls_wrap:659:7) at TLSWrap.close (node:_tls_wrap:665:7) at closeSocketHandle (node:net:336:18) at Socket._destroy (node:net:826:7) at _destroy (node:internal/streams/destroy:122:10)

mcollina commented 1 month ago

Some servers kills a socket after X amount of request. This might be your case.

nodejs / help