java 11 HttpClient leads to endless SSL loop

Question

I am using the new java.net.http.HttpClient with the sendAsync method. The HttpClient is inside a Singelton and is created once like so: HttpClient.newBuilder().build() so really nothing special.

Those requests can be POST or GET but I don't know which causes the trouble.

There are just a few requests a day but from time to time one thread uses 100% of a cpu core. And not imminently but after some time when the request has finished.

So I did a thread dump when there were even 2 of those endless loops occurring, the following 2 threads stood out:

"HttpClient-4-Worker-5" #144 daemon prio=5 os_prio=0 cpu=511298.10ms elapsed=520.71s tid=0x00007f684403e800 nid=0x2d6b runnable  [0x00007f68ac162000]
   java.lang.Thread.State: RUNNABLE
        at jdk.internal.net.http.common.SSLFlowDelegate$Writer.processData(java.net.http@11.0.2/SSLFlowDelegate.java:771)
        at jdk.internal.net.http.common.SSLFlowDelegate$Writer$WriterDownstreamPusher.run(java.net.http@11.0.2/SSLFlowDelegate.java:645)
        at jdk.internal.net.http.common.SequentialScheduler$CompleteRestartableTask.run(java.net.http@11.0.2/SequentialScheduler.java:147)
        at jdk.internal.net.http.common.SequentialScheduler$SchedulableTask.run(java.net.http@11.0.2/SequentialScheduler.java:198)
        at jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(java.net.http@11.0.2/SequentialScheduler.java:271)
        at jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(java.net.http@11.0.2/SequentialScheduler.java:224)
        at jdk.internal.net.http.common.SSLFlowDelegate$Writer.triggerWrite(java.net.http@11.0.2/SSLFlowDelegate.java:722)
        at jdk.internal.net.http.common.SSLFlowDelegate.doHandshake(java.net.http@11.0.2/SSLFlowDelegate.java:1024)
        at jdk.internal.net.http.common.SSLFlowDelegate.doClosure(java.net.http@11.0.2/SSLFlowDelegate.java:1094)
        at jdk.internal.net.http.common.SSLFlowDelegate$Reader.unwrapBuffer(java.net.http@11.0.2/SSLFlowDelegate.java:500)
        at jdk.internal.net.http.common.SSLFlowDelegate$Reader.processData(java.net.http@11.0.2/SSLFlowDelegate.java:389)
        - locked <0x00000000fba68950> (a java.lang.Object)
        at jdk.internal.net.http.common.SSLFlowDelegate$Reader$ReaderDownstreamPusher.run(java.net.http@11.0.2/SSLFlowDelegate.java:263)
        at jdk.internal.net.http.common.SequentialScheduler$SynchronizedRestartableTask.run(java.net.http@11.0.2/SequentialScheduler.java:175)
        - locked <0x00000000fbbca3e8> (a java.lang.Object)
        at jdk.internal.net.http.common.SequentialScheduler$CompleteRestartableTask.run(java.net.http@11.0.2/SequentialScheduler.java:147)
        at jdk.internal.net.http.common.SequentialScheduler$SchedulableTask.run(java.net.http@11.0.2/SequentialScheduler.java:198)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.2/ThreadPoolExecutor.java:1128)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.2/ThreadPoolExecutor.java:628)
        at java.lang.Thread.run(java.base@11.0.2/Thread.java:834)

   Locked ownable synchronizers:
        - <0x00000000fc1ff920> (a java.util.concurrent.ThreadPoolExecutor$Worker)





"HttpClient-4-Worker-2" #82 daemon prio=5 os_prio=0 cpu=4266156.67ms elapsed=4311.42s tid=0x00007f6844007000 nid=0x29ee runnable  [0x00007f686fffd000]
   java.lang.Thread.State: RUNNABLE
        at jdk.internal.net.http.common.SSLFlowDelegate$Writer.processData(java.net.http@11.0.2/SSLFlowDelegate.java:771)
        at jdk.internal.net.http.common.SSLFlowDelegate$Writer$WriterDownstreamPusher.run(java.net.http@11.0.2/SSLFlowDelegate.java:645)
        at jdk.internal.net.http.common.SequentialScheduler$CompleteRestartableTask.run(java.net.http@11.0.2/SequentialScheduler.java:147)
        at jdk.internal.net.http.common.SequentialScheduler$SchedulableTask.run(java.net.http@11.0.2/SequentialScheduler.java:198)
        at jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(java.net.http@11.0.2/SequentialScheduler.java:271)
        at jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(java.net.http@11.0.2/SequentialScheduler.java:224)
        at jdk.internal.net.http.common.SSLFlowDelegate$Writer.triggerWrite(java.net.http@11.0.2/SSLFlowDelegate.java:722)
        at jdk.internal.net.http.common.SSLFlowDelegate.doHandshake(java.net.http@11.0.2/SSLFlowDelegate.java:1024)
        at jdk.internal.net.http.common.SSLFlowDelegate.doClosure(java.net.http@11.0.2/SSLFlowDelegate.java:1094)
        at jdk.internal.net.http.common.SSLFlowDelegate$Reader.unwrapBuffer(java.net.http@11.0.2/SSLFlowDelegate.java:500)
        at jdk.internal.net.http.common.SSLFlowDelegate$Reader.processData(java.net.http@11.0.2/SSLFlowDelegate.java:389)
        - locked <0x00000000f97668d0> (a java.lang.Object)
        at jdk.internal.net.http.common.SSLFlowDelegate$Reader$ReaderDownstreamPusher.run(java.net.http@11.0.2/SSLFlowDelegate.java:263)
        at jdk.internal.net.http.common.SequentialScheduler$SynchronizedRestartableTask.run(java.net.http@11.0.2/SequentialScheduler.java:175)
        - locked <0x00000000f97668f0> (a java.lang.Object)
        at jdk.internal.net.http.common.SequentialScheduler$CompleteRestartableTask.run(java.net.http@11.0.2/SequentialScheduler.java:147)
        at jdk.internal.net.http.common.SequentialScheduler$SchedulableTask.run(java.net.http@11.0.2/SequentialScheduler.java:198)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.2/ThreadPoolExecutor.java:1128)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.2/ThreadPoolExecutor.java:628)
        at java.lang.Thread.run(java.base@11.0.2/Thread.java:834)

   Locked ownable synchronizers:
        - <0x00000000f9894cc0> (a java.util.concurrent.ThreadPoolExecutor$Worker)

Same observation but on another container where only one thread was affected.

"HttpClient-3-Worker-2" #120 daemon prio=5 os_prio=0 cpu=1100568.51ms elapsed=1113.79s tid=0x00007eff3003b800 nid=0x479 runnable  [0x00007eff83bf8000]
   java.lang.Thread.State: RUNNABLE
        at sun.security.ssl.SSLEngineImpl.wrap(java.base@11.0.1/SSLEngineImpl.java:136)
        - eliminated <0x00000000f9796e08> (a sun.security.ssl.SSLEngineImpl)
        at sun.security.ssl.SSLEngineImpl.wrap(java.base@11.0.1/SSLEngineImpl.java:116)
        - locked <0x00000000f9796e08> (a sun.security.ssl.SSLEngineImpl)
        at javax.net.ssl.SSLEngine.wrap(java.base@11.0.1/SSLEngine.java:519)
        at jdk.internal.net.http.common.SSLFlowDelegate$Writer.wrapBuffers(java.net.http@11.0.1/SSLFlowDelegate.java:821)
        at jdk.internal.net.http.common.SSLFlowDelegate$Writer.processData(java.net.http@11.0.1/SSLFlowDelegate.java:736)
        at jdk.internal.net.http.common.SSLFlowDelegate$Writer$WriterDownstreamPusher.run(java.net.http@11.0.1/SSLFlowDelegate.java:645)
        at jdk.internal.net.http.common.SequentialScheduler$CompleteRestartableTask.run(java.net.http@11.0.1/SequentialScheduler.java:147)
        at jdk.internal.net.http.common.SequentialScheduler$SchedulableTask.run(java.net.http@11.0.1/SequentialScheduler.java:198)
        at jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(java.net.http@11.0.1/SequentialScheduler.java:271)
        at jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(java.net.http@11.0.1/SequentialScheduler.java:224)
        at jdk.internal.net.http.common.SSLFlowDelegate$Writer.triggerWrite(java.net.http@11.0.1/SSLFlowDelegate.java:722)
        at jdk.internal.net.http.common.SSLFlowDelegate.doHandshake(java.net.http@11.0.1/SSLFlowDelegate.java:1024)
        at jdk.internal.net.http.common.SSLFlowDelegate.doClosure(java.net.http@11.0.1/SSLFlowDelegate.java:1094)
        at jdk.internal.net.http.common.SSLFlowDelegate$Reader.unwrapBuffer(java.net.http@11.0.1/SSLFlowDelegate.java:500)
        at jdk.internal.net.http.common.SSLFlowDelegate$Reader.processData(java.net.http@11.0.1/SSLFlowDelegate.java:389)
        - locked <0x00000000f9797010> (a java.lang.Object)
        at jdk.internal.net.http.common.SSLFlowDelegate$Reader$ReaderDownstreamPusher.run(java.net.http@11.0.1/SSLFlowDelegate.java:263)
        at jdk.internal.net.http.common.SequentialScheduler$SynchronizedRestartableTask.run(java.net.http@11.0.1/SequentialScheduler.java:175)
        - locked <0x00000000f9797030> (a java.lang.Object)
        at jdk.internal.net.http.common.SequentialScheduler$CompleteRestartableTask.run(java.net.http@11.0.1/SequentialScheduler.java:147)
        at jdk.internal.net.http.common.SequentialScheduler$SchedulableTask.run(java.net.http@11.0.1/SequentialScheduler.java:198)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.1/ThreadPoolExecutor.java:1128)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.1/ThreadPoolExecutor.java:628)
        at java.lang.Thread.run(java.base@11.0.1/Thread.java:834)

Some example code I am using

httpClient.sendAsync(request, HttpResponse.BodyHandlers.ofString())
                                .thenApply(logResponse());

Java Version

openjdk version "11.0.2" 2019-01-15
OpenJDK Runtime Environment (build 11.0.2+9-Debian-3)
OpenJDK 64-Bit Server VM (build 11.0.2+9-Debian-3, mixed mode, sharing)

The problem also occurs when preferring HTTP 2

Updates

Am I using the HttpClient in a wrong way? Could this be a Server Problem? Is it maybe this bug https://bugs.openjdk.java.net/browse/JDK-8207009?

Client connects to a cloudflare service
When the issue occurs there are is no open connection to cloudflare via netstat visible
I can pin the problem to http2 + tlsv1.3 (using the nginx docker image: nginx:1.15-alpine with tls1.3 enabled of course)

Bug appears to be fixed now according to https://bugs.openjdk.java.net/browse/JDK-8241054

I can reproduce this on Mac on JDK 13 with just a blocking HttpClient::send followed by a Thread.sleep(Long.MAX_VALUE). Changing TLS did nothing. — kantianethics, Feb 03 '19 at 08:29
This issue is fixed in JDK 13 b04; I was using an earlier build. — kantianethics, Feb 03 '19 at 18:08
In JDK 11.0.10 this bug is now in httpserver, fix with jdk.tls.disabledAlgorithms=TLSv1.3 helps when server thread is stucked at doClosure() after each new client's request before previous request was finished — Stanislav Orlov, Apr 11 '21 at 19:35

Zarathustra · Accepted Answer · 2019-09-30T17:15:38.247

As @jspcal said before disable TLS 1.3.

tl;dr: disable tlsv1.3 via extending/overwriting

<java_home>/conf/security/java.security the jdk.tls.disabledAlgorithms property

Since my application is running in a docker container I changed the base image to disable tls1.3

FROM openjdk:11-jre
...

RUN sed -i "/jdk.tls.disabledAlgorithms=/ s/=.*/=TLSv1.3, SSLv3, RC4, MD5withRSA, DH keySize < 1024, EC keySize < 224, DES40_CBC, RC4_40, 3DES_EDE_CBC/" $(readlink -f /usr/bin/java | sed "s:bin/java::")/conf/security/java.security

As far as I know there is no way of setting this (security) property via a system property! See also sun.security.util.DisabledAlgorithmConstraints#PROPERTY_TLS_DISABLED_ALGS which actually ready the property.

Update: Bug is still present in 11.0.2

I see the same problem also with OpenJDK 11.0.6 – markus Jun 04 '20 at 09:12 — markus, Jun 04 '20 at 09:12

score 9 · Answer 2 · answered Feb 01 '19 at 19:20

9

Try disabling TLSv1.3 or SSLv3 to see if that helps.

Set the system property on the command line: -Djdk.tls.disabledAlgorithms=TLSv1.3

Or define the property in <java_home>/conf/security/java.security

If you think it's an implementation bug, you may want to open an issue.

answered Feb 01 '19 at 19:20

jspcal

50,847
7
72
76

Thought about TLS 1.3 issues too ... maybe its this bug here https://bugs.openjdk.java.net/browse/JDK-8207009 - not sure if it is fixed in my version – Zarathustra Feb 01 '19 at 20:06
Interesting link. Thanks. – jspcal Feb 01 '19 at 20:08
1

Disabling TLS 1.3 did not help :/ – Zarathustra Feb 08 '19 at 10:06
Oh interesting Zarathustra. – jspcal Feb 09 '19 at 01:42
2

Just found out that even with `-Djdk.tls.disabledAlgorithms=TLSv1.3` the client still uses TLS v1.3 – Zarathustra Feb 12 '19 at 15:56
Disabling TLS 1.3 doesn't work - https://stackoverflow.com/questions/55298459/java-11-httpclient-leads-to-endless-ssl-loop-even-with-disabled-tlsv-1-3 – slesh Mar 22 '19 at 12:24
the parameter -Djdk.tls.disabledAlgorithms=TLSv1.3 does not work – freedev Jun 30 '20 at 10:05

score 9 · Answer 3 · answered May 06 '20 at 21:09

9

I run into the same issue and found the bug report

It is awaiting JDK 11.0.8 release.

answered May 06 '20 at 21:09

Sergey Rymsha

91
1
3

score 4 · Answer 4 · answered Mar 04 '21 at 08:18

4

The bug was fixed for the 11.0.10 Java version.

answered Mar 04 '21 at 08:18

gnupinguin

81
4

1

I think in this instance it would be great if you could provide a link to the issue in the appropriate bug tracker – Gavin Mar 04 '21 at 08:58

java 11 HttpClient leads to endless SSL loop

4 Answers4

Linked