Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

multithreaded http2 GET occasionally throws IllegalStateException #3521

Closed
ifedorenko opened this issue Aug 14, 2017 · 4 comments
Closed

multithreaded http2 GET occasionally throws IllegalStateException #3521

ifedorenko opened this issue Aug 14, 2017 · 4 comments
Labels
bug Bug in existing code
Milestone
3.9

Comments

@ifedorenko
Copy link

I get infrequent exceptions like below when downloading artifacts from nginx on multiple threads over http2. The problem is likely related to (or at least made more severe by) nginx sending GOAWAY frames to force the client acquire new connection. I am using okhttp 3.9.0-SNAPSHOT with swankjesse's fix for #3516. I can provide nginx config and a small java app that triggers the problem semi-reliably but don't have proper standalone test.

java.lang.IllegalStateException
	at okhttp3.internal.connection.StreamAllocation.acquire(StreamAllocation.java:419)
	at okhttp3.ConnectionPool.get(ConnectionPool.java:126)
	at okhttp3.OkHttpClient$1.get(OkHttpClient.java:152)
	at okhttp3.internal.connection.StreamAllocation.findConnection(StreamAllocation.java:175)
	at okhttp3.internal.connection.StreamAllocation.findHealthyConnection(StreamAllocation.java:133)
	at okhttp3.internal.connection.StreamAllocation.newStream(StreamAllocation.java:112)
	at okhttp3.internal.connection.ConnectInterceptor.intercept(ConnectInterceptor.java:42)
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147)
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:121)
	at okhttp3.internal.cache.CacheInterceptor.intercept(CacheInterceptor.java:93)
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147)
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:121)
	at okhttp3.internal.http.BridgeInterceptor.intercept(BridgeInterceptor.java:93)
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147)
	at okhttp3.internal.http.RetryAndFollowUpInterceptor.intercept(RetryAndFollowUpInterceptor.java:125)
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147)
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:121)
	at okhttp3.RealCall.getResponseWithInterceptorChain(RealCall.java:202)
	at okhttp3.RealCall.execute(RealCall.java:77)
	at test.okhttp.DownloadTest.download(DownloadTest.java:96)
	at test.okhttp.DownloadTest.lambda$0(DownloadTest.java:77)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at java.lang.Thread.run(Thread.java:748)

All download threads share the same OkHttpClient instance and each download thread runs this (abbreviated) code:

Request request = new Request.Builder() //
    .url("https://localhost:8443/...") //
    .build();
try (Response response = client.newCall(request).execute()) {
    if (response.isSuccessful()) {
        response.body().string();
    }
}

I also see another exception that may or may not be related:

java.net.ConnectException: Failed to connect to localhost/0:0:0:0:0:0:0:1:8443
	at okhttp3.internal.connection.RealConnection.connectSocket(RealConnection.java:240)
	at okhttp3.internal.connection.RealConnection.connect(RealConnection.java:158)
	at okhttp3.internal.connection.StreamAllocation.findConnection(StreamAllocation.java:239)
	at okhttp3.internal.connection.StreamAllocation.findHealthyConnection(StreamAllocation.java:133)
	at okhttp3.internal.connection.StreamAllocation.newStream(StreamAllocation.java:112)
	at okhttp3.internal.connection.ConnectInterceptor.intercept(ConnectInterceptor.java:42)
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147)
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:121)
	at okhttp3.internal.cache.CacheInterceptor.intercept(CacheInterceptor.java:93)
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147)
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:121)
	at okhttp3.internal.http.BridgeInterceptor.intercept(BridgeInterceptor.java:93)
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147)
	at okhttp3.internal.http.RetryAndFollowUpInterceptor.intercept(RetryAndFollowUpInterceptor.java:125)
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147)
	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:121)
	at okhttp3.RealCall.getResponseWithInterceptorChain(RealCall.java:202)
	at okhttp3.RealCall.execute(RealCall.java:77)
	at test.okhttp.DownloadTest.download(DownloadTest.java:96)
	at test.okhttp.DownloadTest.lambda$0(DownloadTest.java:77)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at java.lang.Thread.run(Thread.java:748)
Caused by: java.net.ConnectException: Connection refused (Connection refused)
	at java.net.PlainSocketImpl.socketConnect(Native Method)
	at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350)
	at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206)
	at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188)
	at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
	at java.net.Socket.connect(Socket.java:589)
	at okhttp3.internal.platform.Platform.connectSocket(Platform.java:125)
	at okhttp3.internal.connection.RealConnection.connectSocket(RealConnection.java:238)
	... 23 more
@dave-r12
Copy link
Collaborator

@ifedorenko do any of the requests result in a redirect or auth challenge?

dave-r12 added a commit that referenced this issue Aug 15, 2017
@dave-r12
Recover from a previous allocated connection with noNewStreams.
58928f5 
This is an edge case that can occur with HTTP/2. Since multiple requests
use the same connection, it's possible for one request to flag the
connection as bad during a follow-up request.

#3521
@dave-r12 dave-r12 mentioned this issue Aug 15, 2017
Merged
@ifedorenko
Copy link
Author

No, no redirects and no auth challenges according to nginx logs (all requests have status=200).

@dave-r12
Copy link
Collaborator

Gotcha -- if you want some help feel free to provide the config and test case. I can help take a look.

dave-r12 added a commit that referenced this issue Aug 17, 2017
@dave-r12
Recover from a previous allocated connection with noNewStreams.
cfbe4eb 
This is an edge case that can occur with HTTP/2. Since multiple requests
use the same connection, it's possible for one request to flag the
connection as bad during a follow-up request.

#3521
@ifedorenko
Copy link
Author

I ran more tests and see rather wide variety of exceptions thrown when nginx tells okhttp GOWAY. I believe specific exception depends on state of individual http2 stream and timing of GOAWAY.

IllegalStateException is fixed by #3525 and I believe happens when one failed stream marks the connection as noNewStreams while another failed stream attempts recovery using the same connection.

All other exceptions are subclasses of IOException and while annoying do not cause real problems because they are already covered by retry-with-backoff logic in my code. I can document the exceptions I see in my test if anyone is interested.

dave-r12 added a commit that referenced this issue Aug 30, 2017
@dave-r12
Recover from an already-allocated connection that restricts new streams.
3af9f9e 
This is an edge case that can occur with HTTP/2. Since multiple requests
use the same connection, it's possible for one request to restrict the
connection from creating new streams during a follow-up request.

#3521
@swankjesse swankjesse added the bug Bug in existing code label Aug 30, 2017
@swankjesse swankjesse added this to the 3.9 milestone Aug 30, 2017
swankjesse pushed a commit that referenced this issue Aug 31, 2017
@dave-r12 @swankjesse
Recover from an already-allocated connection that restricts new strea…
abe5d62 
…ms. (#3525)

This is an edge case that can occur with HTTP/2. Since multiple requests
use the same connection, it's possible for one request to restrict the
connection from creating new streams during a follow-up request.

#3521
@swankjesse swankjesse mentioned this issue Sep 26, 2017
Closed
@peter-mach peter-mach mentioned this issue Nov 29, 2017
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug Bug in existing code
Projects
None yet
Milestone
3.9
Development

No branches or pull requests
3 participants
@ifedorenko @swankjesse @dave-r12