[
https://issues.apache.org/jira/browse/HTTPCLIENT-2352?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17908456#comment-17908456
]
Mark Slater commented on HTTPCLIENT-2352:
-----------------------------------------
Hi [~olegk]
With DEBUG logging turned on for either {{org.apache.hc.client5.http2.frame}}
or {{org.apache.hc.client5.http2.flow}}, I’m unable to reproduce the issue. I
suspect this is because producing the Strings for the log messages is slowing
something down; I can’t reproduce it even with debug logs being sent to a no-op
appender:
{code:java}
<appender name="null" class="ch.qos.logback.core.helpers.NOPAppender" />
<Logger name="org.apache.hc.client5.http2.frame" level="debug" addivity="false">
<appender-ref ref="null"/>
</Logger>
{code}
I can, however, reproduce it with DEBUG logging turned on for the other two
loggers your requested – see [attached (slightly redacted)
file|^apache-client.log]. Let me know if there’s some more specific DEBUG
logging I can switch on.
I’m slightly confused by the references to HTTP/1.1 in the logs. The responses
I get claim to be HTTP/2, and this seems to be backed up by the stack trace.
> Race condition causing java.lang.ArithmeticException: Update causes flow
> control window to exceed 2147483647
> ------------------------------------------------------------------------------------------------------------
>
> Key: HTTPCLIENT-2352
> URL: https://issues.apache.org/jira/browse/HTTPCLIENT-2352
> Project: HttpComponents HttpClient
> Issue Type: Bug
> Components: HttpClient (async)
> Affects Versions: 5.3.1
> Reporter: Mark Slater
> Priority: Major
> Attachments: apache-client.log
>
> Time Spent: 1h
> Remaining Estimate: 0h
>
> I’m getting {{java.lang.ArithmeticException: Update causes flow control
> window to exceed 2147483647}} intermittently when making HTTP/2 requests
> using HTTP Client 5.3.1 as the engine for the [Ktor HTTP Client
> 3.0.3|https://github.com/ktorio/ktor/tree/3.0.3]. It occurs in about 10% of
> requests to some addresses from my desktop.
> I’ve found what seems to be a race condition that appears to be the root
> cause of the problem in
> {{[org.apache.hc.core5.http2.impl.nio.AbstractH2StreamMultiplexer|https://github.com/apache/httpcomponents-core/blob/rel/v5.2.4/httpcore5-h2/src/main/java/org/apache/hc/core5/http2/impl/nio/AbstractH2StreamMultiplexer.java]}}
> (version 5.2.4 is used by this version of HTTP Client).
> This is the stack trace I get:
> {code:java}
> Caused by: java.lang.ArithmeticException: Update causes flow control window
> to exceed 2147483647
> at
> org.apache.hc.core5.http2.impl.nio.AbstractH2StreamMultiplexer.updateWindow(AbstractH2StreamMultiplexer.java:215)
> at
> org.apache.hc.core5.http2.impl.nio.AbstractH2StreamMultiplexer.updateInputWindow(AbstractH2StreamMultiplexer.java:225)
> at
> org.apache.hc.core5.http2.impl.nio.AbstractH2StreamMultiplexer.incrementInputCapacity(AbstractH2StreamMultiplexer.java:385)
> at
> org.apache.hc.core5.http2.impl.nio.AbstractH2StreamMultiplexer.access$1200(AbstractH2StreamMultiplexer.java:94)
> at
> org.apache.hc.core5.http2.impl.nio.AbstractH2StreamMultiplexer$H2StreamChannelImpl.update(AbstractH2StreamMultiplexer.java:1448)
> at
> io.ktor.client.engine.apache5.ApacheResponseConsumer.updateCapacity(ApacheResponseConsumer.kt:131)
> at
> io.ktor.client.engine.apache5.BasicResponseConsumer.updateCapacity(ApacheResponseConsumer.kt:54)
> at
> org.apache.hc.client5.http.impl.async.HttpAsyncMainClientExec$1.updateCapacity(HttpAsyncMainClientExec.java:233)
> at
> org.apache.hc.core5.http2.impl.nio.ClientH2StreamHandler.updateInputCapacity(ClientH2StreamHandler.java:226)
> at
> org.apache.hc.core5.http2.impl.nio.AbstractH2StreamMultiplexer$H2Stream.produceInputCapacityUpdate(AbstractH2StreamMultiplexer.java:1662)
> at
> org.apache.hc.core5.http2.impl.nio.AbstractH2StreamMultiplexer.consumeDataFrame(AbstractH2StreamMultiplexer.java:1030)
> at
> org.apache.hc.core5.http2.impl.nio.AbstractH2StreamMultiplexer.consumeFrame(AbstractH2StreamMultiplexer.java:735)
> at
> org.apache.hc.core5.http2.impl.nio.AbstractH2StreamMultiplexer.onInput(AbstractH2StreamMultiplexer.java:446)
> at
> org.apache.hc.core5.http2.impl.nio.AbstractH2IOEventHandler.inputReady(AbstractH2IOEventHandler.java:65)
> at
> org.apache.hc.core5.http2.impl.nio.ClientH2IOEventHandler.inputReady(ClientH2IOEventHandler.java:39)
> at
> org.apache.hc.core5.reactor.ssl.SSLIOSession.decryptData(SSLIOSession.java:609)
> at
> org.apache.hc.core5.reactor.ssl.SSLIOSession.access$200(SSLIOSession.java:74)
> at
> org.apache.hc.core5.reactor.ssl.SSLIOSession$1.inputReady(SSLIOSession.java:202)
> at
> org.apache.hc.core5.reactor.InternalDataChannel.onIOEvent(InternalDataChannel.java:142)
> at
> org.apache.hc.core5.reactor.InternalChannel.handleIOEvent(InternalChannel.java:51)
> ... 5 more
> {code}
> The problem is in the
> {{[updateWindow|https://github.com/apache/httpcomponents-core/blob/rel/v5.2.4/httpcore5-h2/src/main/java/org/apache/hc/core5/http2/impl/nio/AbstractH2StreamMultiplexer.java#L202]}}
> method, which attempts to adjust the flow control window by a delta computed
> previously. The method caters for the window size changing concurrently with
> the computation and validation of the new size by aborting and retrying
> conflicted calls. However, it doesn’t cater for the consequences of
> out-of-order deltas.
> On connect, the size of {{connInputWindow}} is increased by the
> {{[maximizeConnWindow|https://github.com/apache/httpcomponents-core/blob/rel/v5.2.4/httpcore5-h2/src/main/java/org/apache/hc/core5/http2/impl/nio/AbstractH2StreamMultiplexer.java#L1049]}}
> method to {{{}Integer.MAX_VALUE{}}}, the largest permitted size. As data is
> consumed and received, the
> {{[updateWindow|https://github.com/apache/httpcomponents-core/blob/rel/v5.2.4/httpcore5-h2/src/main/java/org/apache/hc/core5/http2/impl/nio/AbstractH2StreamMultiplexer.java#L202]}}
> method is called with positive and negative deltas to reflect the changes in
> available capacity. However, the order in which these updates are applied is
> not guaranteed. If a negative delta due to the receipt of data is applied
> after the positive delta due to some of that data being consumed, the window
> size will be increased beyond {{Integer.MAX_VALUE,}} and
> {{ArithmeticException}} will be thrown.
> It would be possible to mitigate this somewhat (perhaps entirely) if
> {{[maximizeConnWindow|https://github.com/apache/httpcomponents-core/blob/rel/v5.2.4/httpcore5-h2/src/main/java/org/apache/hc/core5/http2/impl/nio/AbstractH2StreamMultiplexer.java#L1049]}}
> could be configured to use a maximum size somewhat less than
> {{{}Integer.MAX_VALUE{}}}, but I’m not familiar enough with HTTP/2 to know if
> this would have wider consequences.
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@hc.apache.org
For additional commands, e-mail: dev-h...@hc.apache.org
