java 11 HttpClient 导致无休止的 SSL 循环答案

【问题标题】：java 11 HttpClient leads to endless SSL loopjava 11 HttpClient 导致无休止的 SSL 循环
【发布时间】：2019-06-26 09:35:58
【问题描述】：

我正在使用 new java.net.http.HttpClient 和 sendAsync 方法。 HttpClient 在 Singelton 中，并像这样创建一次： HttpClient.newBuilder().build() 所以真的没什么特别的。

这些请求可以是POST 或GET，但我不知道是什么导致了问题。

每天只有几个请求，但有时一个线程会使用 100% 的 cpu 内核。而且不是马上，而是在请求完成一段时间后。

所以当甚至有 2 个无限循环发生时，我做了一个线程转储，以下 2 个线程脱颖而出：

"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)

同样的观察，但在另一个容器上只有一个线程受到影响。

"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)

我正在使用的一些示例代码

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

Java 版本

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)

优先使用 HTTP 2 时也会出现该问题

更新

我是否以错误的方式使用HttpClient？这可能是服务器问题吗？是不是这个bughttps://bugs.openjdk.java.net/browse/JDK-8207009？

客户端连接到 cloudflare 服务
出现问题时，没有通过可见的 netstat 到 cloudflare 的开放连接
我可以将问题定位到 http2 + tlsv1.3（使用 nginx docker 映像：nginx:1.15-alpine，当然启用了 tls1.3）

根据 https://bugs.openjdk.java.net/browse/JDK-8241054

，Bug 现在似乎已修复

【问题讨论】：

我可以在 Mac 上的 JDK 13 上重现这一点，只需一个阻塞的 HttpClient::send 后跟一个 Thread.sleep(Long.MAX_VALUE)。更改 TLS 无济于事。
此问题已在 JDK 13 b04 中修复；我使用的是早期版本。
@kantianethics 任何线索到底是什么导致了这个问题？
见bugs.openjdk.java.net/browse/JDK-8217094
在 JDK 11.0.10 中，此错误现在位于 httpserver 中，使用 jdk.tls.disabledAlgorithms=TLSv1.3 修复有助于在每个新客户端请求之前的每个新客户端请求之后服务器线程卡在 doClosure() 上时完成

标签： java multithreading http http2 java-11

【解决方案1】：

尝试禁用 TLSv1.3 或 SSLv3 看看是否有帮助。

在命令行设置系统属性：-Djdk.tls.disabledAlgorithms=TLSv1.3

或者在<java_home>/conf/security/java.security中定义属性

如果您认为这是一个实现错误，您可能需要打开一个问题。

【讨论】：

也考虑过 TLS 1.3 问题......也许是这里的这个错误 bugs.openjdk.java.net/browse/JDK-8207009 - 不确定它是否在我的版本中得到修复
有趣的链接。谢谢。
禁用 TLS 1.3 没有帮助：/
哦，有趣的查拉图斯特拉。
刚刚发现即使使用-Djdk.tls.disabledAlgorithms=TLSv1.3，客户端仍然使用 TLS v1.3

【解决方案2】：

正如@jspcal 在禁用 TLS 1.3 之前所说的那样。

tl;dr：通过扩展/覆盖禁用 tlsv1.3

<java_home>/conf/security/java.securityjdk.tls.disabledAlgorithms 属性

由于我的应用程序在 docker 容器中运行，我更改了基础映像以禁用 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

据我所知，无法通过系统属性设置此（安全）属性！另请参阅sun.security.util.DisabledAlgorithmConstraints#PROPERTY_TLS_DISABLED_ALGS，它实际上已准备好属性。

更新：错误仍然存在于 11.0.2

【讨论】：

我在 OpenJDK 11.0.6 上也看到了同样的问题

【解决方案3】：

我遇到了同样的问题，发现 bug report

正在等待 JDK 11.0.8 发布。

【讨论】：

【解决方案4】：

该错误已针对 11.0.10 Java 版本修复。

【讨论】：

我认为在这种情况下，如果您可以在相应的错误跟踪器中提供指向该问题的链接，那就太好了