Ryan Schmitt created HTTPCLIENT-2145:
----------------------------------------

             Summary: Inactive connection validation hangs on HTTP/2 
connections after server sends GOAWAY
                 Key: HTTPCLIENT-2145
                 URL: https://issues.apache.org/jira/browse/HTTPCLIENT-2145
             Project: HttpComponents HttpClient
          Issue Type: Bug
          Components: HttpClient (async)
    Affects Versions: 5.0.3
            Reporter: Ryan Schmitt


I've discovered that HTTP/2 inactive connection validation hangs forever if a 
GOAWAY frame has previously been received on that connection. I've captured 
DEBUG logs showing the effect of validating such a connection.

Without inactive connection validation:
{noformat}
01 Apr 2021 11:17:32,251 [DEBUG] (coral-client-orchestrator-19) 
org.apache.hc.client5.http.impl.async.InternalAbstractHttpAsyncClient: 
ex-00000002: preparing request execution
01 Apr 2021 11:17:32,252 [DEBUG] (coral-client-orchestrator-19) 
org.apache.hc.client5.http.impl.async.AsyncProtocolExec: ex-00000002: target 
auth state: UNCHALLENGED
01 Apr 2021 11:17:32,252 [DEBUG] (coral-client-orchestrator-19) 
org.apache.hc.client5.http.impl.async.AsyncProtocolExec: ex-00000002: proxy 
auth state: UNCHALLENGED
01 Apr 2021 11:17:32,252 [DEBUG] (coral-client-orchestrator-19) 
org.apache.hc.client5.http.impl.async.AsyncConnectExec: ex-00000002: acquiring 
connection with route {}->http://localhost:8000
01 Apr 2021 11:17:32,252 [DEBUG] (coral-client-orchestrator-19) 
org.apache.hc.client5.http.impl.async.InternalHttpAsyncClient: ex-00000002: 
acquiring endpoint (2500 MILLISECONDS)
01 Apr 2021 11:17:32,252 [DEBUG] (coral-client-orchestrator-19) 
org.apache.hc.client5.http.impl.nio.PoolingAsyncClientConnectionManager: 
ex-00000002: endpoint lease request (2500 MILLISECONDS) [route: 
{}->http://localhost:8000][total available: 1; route allocated: 1 of 
2147483647; total allocated: 1 of 2147483647]
01 Apr 2021 11:17:32,252 [DEBUG] (coral-client-orchestrator-19) 
org.apache.hc.client5.http.impl.nio.PoolingAsyncClientConnectionManager: 
ex-00000002: endpoint leased [route: {}->http://localhost:8000][total 
available: 0; route allocated: 1 of 2147483647; total allocated: 1 of 
2147483647]
01 Apr 2021 11:17:32,253 [DEBUG] (coral-client-orchestrator-19) 
org.apache.hc.client5.http.impl.nio.PoolingAsyncClientConnectionManager: 
ex-00000002: acquired ep-00000001
01 Apr 2021 11:17:32,253 [DEBUG] (coral-client-orchestrator-19) 
org.apache.hc.client5.http.impl.nio.DefaultManagedAsyncClientConnection: 
c-00000000: Shutdown connection IMMEDIATE
01 Apr 2021 11:17:32,253 [DEBUG] (coral-client-orchestrator-19) 
org.apache.hc.client5.http.impl.async.InternalHttpAsyncClient: ex-00000002: 
acquired endpoint ep-00000001
01 Apr 2021 11:17:32,253 [DEBUG] (coral-client-orchestrator-19) 
org.apache.hc.client5.http.impl.async.InternalHttpAsyncClient: ep-00000001: 
connecting endpoint (2500 MILLISECONDS)
01 Apr 2021 11:17:32,253 [DEBUG] (coral-client-orchestrator-19) 
org.apache.hc.client5.http.impl.nio.PoolingAsyncClientConnectionManager: 
ep-00000001: connecting endpoint to http://localhost:8000 (2500 MILLISECONDS)
01 Apr 2021 11:17:32,253 [DEBUG] (coral-client-orchestrator-19) 
org.apache.hc.client5.http.impl.nio.MultihomeIOSessionRequester: 
http://localhost:8000: resolving remote address
01 Apr 2021 11:17:32,253 [DEBUG] (coral-client-orchestrator-19) 
org.apache.hc.client5.http.impl.nio.MultihomeIOSessionRequester: 
http://localhost:8000: resolved to [localhost/127.0.0.1, 
localhost/0:0:0:0:0:0:0:1]
01 Apr 2021 11:17:32,253 [DEBUG] (coral-client-orchestrator-19) 
org.apache.hc.client5.http.impl.nio.MultihomeIOSessionRequester: 
http://localhost:8000: connecting null to localhost/127.0.0.1:8000 (2500 
MILLISECONDS)
01 Apr 2021 11:17:32,254 [DEBUG] (httpclient-dispatch-2) 
org.apache.hc.client5.http.impl.nio.MultihomeIOSessionRequester: 
http://localhost:8000: connected c-00000001 
/127.0.0.1:50735->localhost/127.0.0.1:8000
01 Apr 2021 11:17:32,254 [DEBUG] (httpclient-dispatch-2) 
org.apache.hc.client5.http.impl.nio.PoolingAsyncClientConnectionManager: 
ep-00000001: connected c-00000001
01 Apr 2021 11:17:32,254 [DEBUG] (httpclient-dispatch-2) 
org.apache.hc.client5.http.impl.async.InternalHttpAsyncClient: ep-00000001: 
endpoint connected
01 Apr 2021 11:17:32,254 [DEBUG] (httpclient-dispatch-2) 
org.apache.hc.client5.http.impl.async.AsyncConnectExec: ex-00000002: connected 
to target
01 Apr 2021 11:17:32,254 [DEBUG] (httpclient-dispatch-2) 
org.apache.hc.client5.http.impl.async.AsyncConnectExec: ex-00000002: route 
fully established{noformat}

With inactive connection validation:
{noformat}
01 Apr 2021 11:00:19,656 [DEBUG] (coral-client-orchestrator-19) 
org.apache.hc.client5.http.impl.async.InternalAbstractHttpAsyncClient: 
ex-00000002: preparing request execution
01 Apr 2021 11:00:19,657 [DEBUG] (coral-client-orchestrator-19) 
org.apache.hc.client5.http.impl.async.AsyncProtocolExec: ex-00000002: target 
auth state: UNCHALLENGED
01 Apr 2021 11:00:19,657 [DEBUG] (coral-client-orchestrator-19) 
org.apache.hc.client5.http.impl.async.AsyncProtocolExec: ex-00000002: proxy 
auth state: UNCHALLENGED
01 Apr 2021 11:00:19,657 [DEBUG] (coral-client-orchestrator-19) 
org.apache.hc.client5.http.impl.async.AsyncConnectExec: ex-00000002: acquiring 
connection with route {}->http://localhost:8000
01 Apr 2021 11:00:19,657 [DEBUG] (coral-client-orchestrator-19) 
org.apache.hc.client5.http.impl.async.InternalHttpAsyncClient: ex-00000002: 
acquiring endpoint (2500 MILLISECONDS)
01 Apr 2021 11:00:19,657 [DEBUG] (coral-client-orchestrator-19) 
org.apache.hc.client5.http.impl.nio.PoolingAsyncClientConnectionManager: 
ex-00000002: endpoint lease request (2500 MILLISECONDS) [route: 
{}->http://localhost:8000][total available: 1; route allocated: 1 of 
2147483647; total allocated: 1 of 2147483647]
01 Apr 2021 11:00:19,658 [DEBUG] (coral-client-orchestrator-19) 
org.apache.hc.client5.http.impl.nio.DefaultManagedAsyncClientConnection: 
c-00000000: PingCommand with IMMEDIATE priority
[ nothing happens ]
{noformat}



--
This message was sent by Atlassian Jira
(v8.3.4#803005)

---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]

Reply via email to