TLSWrap objects grow with HTTP keep-alive enabled until out of memory error occurs

[mgilbey]

• Version:

$ node -p process.versions
{
  node: '14.2.0',
  v8: '8.1.307.31-node.33',
  uv: '1.37.0',
  zlib: '1.2.11',
  brotli: '1.0.7',
  ares: '1.16.0',
  modules: '83',
  nghttp2: '1.40.0',
  napi: '6',
  llhttp: '2.0.4',
  openssl: '1.1.1g',
  cldr: '36.1',
  icu: '66.1',
  tz: '2019c',
  unicode: '13.0'
}

• Platform: Darwin <host> 19.4.0 Darwin Kernel Version 19.4.0: Wed Mar 4 22:28:40 PST 2020; root:xnu-6153.101.6~15/RELEASE_X86_64 x86_64 and node docker image node:13.13.0-alpine

• Subsystem: https

What steps will reproduce the bug?

I have created a script to reproduce at https://github.com/mgilbey/node-tls-wrap

The script runs a TLS server and https Agent to be self contained, but only the Agent is needed to reproduce the problem with a HTTPS server to connect to. The classes are only used to help identify which objects are holding references in the heap snapshots.

The script will open 100 connections, send and receive two HTTP requests on each connection (demonstrating keep-alive functions as expected) and then lets the sockets close due to the keep-alive timeout. This repeats five times, leaving 501 TLSWrap objects in memory. The scripts forces a garbage collection, and then collects a heap dump before exiting.

The agent reports the expected number of active / free sockets (never more than 100).

How often does it reproduce? Is there a required condition?

The script will consistently reproduce the issue.

I believe the salient points for reproduction are:

• https Agent with keepAlive enabled
• The number of open sockets never exceeds the maxSockets Agent option.
• Sockets are closed due to the keepAlive timeout specified by the Agent being reached.

What is the expected behavior?

TLSWrap and TLSSocket objects are garbage collected when the socket from the agent is closed due to the keep-alive timeout, and no further keep-alive socket re-use is possible.

What do you see instead?

TLSWrap and TLSSocket objects will grow in memory until the old-space heap limits are reached at e.g. 10 or 300 MB limits. The number of TLSWrap and TLSSocket objects in memory will exceed the maxSockets, maxFreeSockets or maxCachedSessions Agent options.

An allocation timeline and heap snapshot are also included in the repository.

Each TLSWrap object has four retainers, although none appear to be the https Agent.

Additional information

To demonstrate the process crashing due to heap limits, run with --max-old-space-size=10 and increase the number of iterations on line 128 to 50. You can increase heap and the number of iterations should you be more patient.

The issue does not reproduce with the http Agent.

The cause appears to be very similar to resolved issue #19859 that affected the http Agent, particularly the reference to the open sockets being less than the maxSockets option.

[addaleax]

@mgilbey Can you check whether this was introduced between v13.8.0 and v13.9.0? I’m kind of suspecting 9fdb6e6 here, based on the retainer output.

If yes, #31745 might fix this, although it requires some updating as indicated in the PR. I’ll get on that.

[mgilbey]

I've checked versions 13.0.0, 13.8.0 and 13.9.0 but all fail to close connections after the keep-alive timeout has elapsed, meaning that they bypass the test entirely, and leak unclosed sockets instead of closed ones.

I went back to 12.6.3 and it behaves as expected with sockets closed after the keep-alive timeout elapses and does not retain TLSWrap objects. When it completes the snapshot only references a single TLSWrap object, which would be expected when both the client and server are destroyed.

Conversely the 13.x versions above retain the TLSWrap objects even after client, server and all sockets are closed, which suggests that the retention was before 9fdb6e6.

[omsmith]

Ran into what appears to be the same or similar issue when updating node.js to 14.3 (from 8.x) in one of our services. In our case we're also using keep-alive and to exacerbate the issue, we deliberately destroy sockets 10 minutes after first use to ensure we're responding to DNS changes of servers that may not necessarily close connections.

We've set up the service to take heapsnapshots every hour. Here's a comparison of one of the workers between hour 1 and hour 2 of operation, June 2 00:48Z and 01:48Z respectively. In this case I don't have an hour 3, because a graceful restart was necessary ahead of any OOM issues.

I compiled and deployed a package of v14.x with 6f6bf01 cherry-picked on top. This appears to have resolved the issue, and the service thankfully made it through the night without intervention. Certainly some slightly different load profiles due to difference in time, but meaningful nonetheless. Here's a comparison of one of the workers between hour 1 and hour 9 of operation.

Thank you @addaleax, and thanks @mgilbey for reporting the issue - hope it's fixed for you as well.

[abartomeu]

Since I upgraded from 12.16.3 to 12.17 I have had a memory leak in production that I am trying to figure out. I took a memory snapshot in the staging environment and I can see 898 TLSWrap objects with the same 4 retainers as mentioned by @mgilbey. I couldn't validate yet that is the leak because I was only able to take one snapshot but if it is, it was introduced in 12.17.

[christhegrand]

We also started seeing this after upgrading from 12.16 to 12.17.

[abartomeu]

I have done further testing on this issue. I have taken a memory snapshot in after 24 hours and I see 64000 TLSWrap objects using about 400MB of memory. In previous experiments I have seen that the number of these TLSWrap objects is always growing. I also tested that even 10 mins after I stopped all traffic to my service, and Http keepalive should have expired, the TLSWrap objects were still around.

Is there any chances we could get this fixed?