[HTTPCLIENT-2222] ProtocolNegotiationException and ConnectionClosedException with httpclient5

• Type: Bug
• Status: Resolved
• Priority: Major
• Resolution: Fixed
• Affects Version/s: 5.1.2, 5.1.3
• Fix Version/s: 5.1.4
• Component/s: HttpClient (async)
• Environment: GNU/Linux 5.4 with JDK11.
• Flags: Important

Language

Java

• Assignee: Unassigned
• Reporter: Gaojie Liu
• Created: 09/Jun/22 05:36
• Updated: 11/Jul/22 18:05
• Resolved: 23/Jun/22 12:10

Description

We are using httpclient5 to talk HTTP/2 to a Netty H2 server and we are using a pretty standard way to construct a HttpClient5 client as follows:

final IOReactorConfig ioReactorConfig = IOReactorConfig.custom()
    .setSoKeepAlive(true)
    .setTcpNoDelay(true)
    .setSoTimeout(Timeout.ofMilliseconds(requestTimeOutInMilliseconds))
    .setIoThreadCount(ioThreadCount)
    .build();

final TlsStrategy tlsStrategy = skipCipherCheck ?
    VeniceClientTlsStrategyBuilder.create()
        .setSslContext(sslContext)
        .setTlsVersions(TLS.V_1_3, TLS.V_1_2)
        .build()
    : ClientTlsStrategyBuilder.create()
        .setSslContext(sslContext)
        .setTlsVersions(TLS.V_1_3, TLS.V_1_2)
        .build();

final CloseableHttpAsyncClient client = HttpAsyncClients.customHttp2().setTlsStrategy(tlsStrategy)
    .setIOReactorConfig(ioReactorConfig)
    .setDefaultRequestConfig(RequestConfig.custom()
        .setResponseTimeout(Timeout.ofMilliseconds(requestTimeOutInMilliseconds))
        .setConnectionRequestTimeout(Timeout.ofMilliseconds(requestTimeOutInMilliseconds))
        .setConnectTimeout(Timeout.ofMilliseconds(connectTimeOutInMilliseconds))
        .build())
    .build();

client.start(); 

When we deployed this to prod, we discovered the following exceptions in the first 30 mins and later, it seems become more stable:

org.apache.hc.core5.http.ConnectionClosedException: Connection is closed
        at org.apache.hc.core5.http2.impl.nio.AbstractH2StreamMultiplexer.onDisconnect(AbstractH2StreamMultiplexer.java:568) ~[httpcore5-h2-5.1.2.jar:5.1.2]
        at org.apache.hc.core5.http2.impl.nio.AbstractH2IOEventHandler.disconnected(AbstractH2IOEventHandler.java:96) ~[httpcore5-h2-5.1.2.jar:5.1.2]
        at org.apache.hc.core5.http2.impl.nio.ClientH2IOEventHandler.disconnected(ClientH2IOEventHandler.java:39) ~[httpcore5-h2-5.1.2.jar:5.1.2]
        at org.apache.hc.core5.reactor.ssl.SSLIOSession$1.disconnected(SSLIOSession.java:212) ~[httpcore5-5.1.2.jar:5.1.2]
        at org.apache.hc.core5.reactor.InternalDataChannel.disconnected(InternalDataChannel.java:193) ~[httpcore5-5.1.2.jar:5.1.2]
        at org.apache.hc.core5.reactor.SingleCoreIOReactor.processClosedSessions(SingleCoreIOReactor.java:231) ~[httpcore5-5.1.2.jar:5.1.2]
        at org.apache.hc.core5.reactor.SingleCoreIOReactor.doExecute(SingleCoreIOReactor.java:133) ~[httpcore5-5.1.2.jar:5.1.2]
        at org.apache.hc.core5.reactor.AbstractSingleCoreIOReactor.execute(AbstractSingleCoreIOReactor.java:85) ~[httpcore5-5.1.2.jar:5.1.2]
        at org.apache.hc.core5.reactor.IOReactorWorker.run(IOReactorWorker.java:44) ~[httpcore5-5.1.2.jar:5.1.2]
        at java.lang.Thread.run(Thread.java:834) [?:?]org.apache.hc.core5.http2.impl.nio.ProtocolNegotiationException: Unexpected input
        at org.apache.hc.core5.http2.impl.nio.H2OnlyClientProtocolNegotiator.inputReady(H2OnlyClientProtocolNegotiator.java:133) ~[httpcore5-h2-5.1.2.jar:5.1.2]
        at org.apache.hc.core5.reactor.ssl.SSLIOSession.decryptData(SSLIOSession.java:549) ~[httpcore5-5.1.2.jar:5.1.2]
        at org.apache.hc.core5.reactor.ssl.SSLIOSession.access$400(SSLIOSession.java:72) ~[httpcore5-5.1.2.jar:5.1.2]
        at org.apache.hc.core5.reactor.ssl.SSLIOSession$1.inputReady(SSLIOSession.java:172) ~[httpcore5-5.1.2.jar:5.1.2]
        at org.apache.hc.core5.reactor.InternalDataChannel.onIOEvent(InternalDataChannel.java:131) ~[httpcore5-5.1.2.jar:5.1.2]
        at org.apache.hc.core5.reactor.InternalChannel.handleIOEvent(InternalChannel.java:51) ~[httpcore5-5.1.2.jar:5.1.2]
        at org.apache.hc.core5.reactor.SingleCoreIOReactor.processEvents(SingleCoreIOReactor.java:178) ~[httpcore5-5.1.2.jar:5.1.2]
        at org.apache.hc.core5.reactor.SingleCoreIOReactor.doExecute(SingleCoreIOReactor.java:127) ~[httpcore5-5.1.2.jar:5.1.2]
        at org.apache.hc.core5.reactor.AbstractSingleCoreIOReactor.execute(AbstractSingleCoreIOReactor.java:85) ~[httpcore5-5.1.2.jar:5.1.2]
        at org.apache.hc.core5.reactor.IOReactorWorker.run(IOReactorWorker.java:44) ~[httpcore5-5.1.2.jar:5.1.2]
        at java.lang.Thread.run(Thread.java:834) [?:?] 

Is it a known issue?

We tried the latest release of httpclient5: 5.2-beta1, the ConnectionClosedException exception would happen much more frequent.

Let me know if you need more information.