SSL Connection Leak

[wufei2016]

We recently upgraded to 9.4.9.v20180320, we observed that there are about 200000 unclosed jetty connections for running 12 hours and the cpu usage become higher and higher during the test.
After a few days investigation, I think this should be a regression for "HTTP Close #1832 #2338". It works without any issue if we switch to 9.4.8.v20180619

[joakime]

Jetty 9.4.12.v20180830 is the latest codebase and has hundreds of bug fixes over 9.4.9.
Please retest with 9.4.12.

Jetty 9.4.8 is vulnerable to multiple CVEs, we do not recommend running that version.
https://www.eclipse.org/lists/jetty-announce/msg00123.html

[wufei2016]

We tested 9.4.12, but unfortunately, it still has the same issue

[sbordet]

@wufei2016 we have had other reports of this kind, and all of them turned out to not be a Jetty problem.
The problem with your report is that you provide no evidence of what you say, so we have nothing to work on.

If you can reproduce the issue, please attach a reproducible project for us to replicate.

Attach also a JVM thread dump and a server dump, so that we can analyze the situation.

[joakime]

@wufei2016 any update? do you have a reproduction case? or a server dump that we can analyze?

[wufei2016]

I can provide the jetty log file if it helps. The dump file is too big. it is about 20G.

[sbordet]

@wufei2016 I doubt the server dump file is 20G. We're not asking for the heap dump, but the server dump which is a text file easily compressible.

[joakime]

@wufei2016 please follow the link that @sbordet provided on how to collect a Jetty server dump.
The Jetty server dump is not a heapdump, it's a textual representation of the state of the server at the point in time when you trigger it.
This textual representation will be quite manageable in size. (often under 50kb)

[wufei2016]

Here is the Jetty server dump:

serverDump.zip

[sbordet]

The server dump shows 1046 connections that you have configured with a quite long idle timeout, 5 minutes.

998 of them are in TLS NEED_WRAP state, which is strange; 1031 have only processed just 1 request.

It is as if after the first request they are trying to close the connection and write the TLS close_notify message but they cannot.

I see you are using FIPS SslContextFactory. Are you sure you don't have any exception in the server logs? See also #2010 and #1547.

What exact JVM version and vendor are you using?

[wufei2016]

FIPSSslContextFactory is a wrapper which overrides getKeyManagers to workaround FIPS mode issue.
In our test, we didn't enable FIPS mode. We didn't see any exception in the server log.

Here is JVM info:
openjdk version "1.8.0_172"
OpenJDK Runtime Environment (Zulu 8.30.0.1-win64) (build 1.8.0_172-b01)
OpenJDK 64-Bit Server VM (Zulu 8.30.0.1-win64) (build 25.172-b01, mixed mode)

We also tested it on oracle jdk 1.8.0_181 and oracle jdk 1.8.0_151, we got same result.

[sbordet]

@wufei2016 what we see from the server dump is strange, but I have no idea how that situation could possibly be generated.
So we need either a reproduction test case, or DEBUG logs with a network trace taken e.g. via Wireshark.

[wufei2016]

Here is the debug log and network trace:
debugLogAndNetworkTrace.zip

[sbordet]

Thanks, we have been able to reproduce the issue.
We are discussing the fix and we will update the issue.

[gregw]

There is definitely something strange going on. The current fixes in the branch do make it better, but it is still not perfect. Thus I don't think we've fully understood the hole in selection/closing after such request handling. More analysis needed but confident we've got a good reproduction now so we'll have a good fix next week.

[gregw]

The problem was that if there was unconsumed input AND an EOF after a persistent request, then the consumeAll method would consume both the content and the EOF before recycling the request. The EOF was then seen in END state rather than in start state, so an earlyEOF event was not generated. This was compounded by end-chunk and TLS close handshakes looking like unconsumed input if the servlet had not read the -1.
The fix is to better handle a -1 read between requests.

[gregw]

The previous fix broke the proxy, so 041e8fd is an alternative fix that makes the MessageComplete event separable from the last Content event.

[sunng87]

I can reproduce this issue on 9.4.15 with TLS backed by conscrypt. Even if idleTimeout was set to a reasonable value, SslConnection were still retained in memory forever. Also with Conscrypt, we got off-heap memory leak because of this connection leak too.

To reproduce, start an https server and create some load with tools like wrk. You will see the process memory footprint goes straightly with connections you created. By dumping heap, there will as many SslConnection instance as the connections you created.