Incorrect retries on connection that still succeeded #8472
Comments
|
Can you turn on logging with https://square.github.io/okhttp/features/events/ And provide that output? |
|
Here's the logs leading up to the exception. Hope it helps. |
|
Need the event logging that I linked to. Or a logging network interceptor |
|
Sorry. Misundestood the logs you wanted. Here's the extra logs : The log says response failed at 17:00:20.668, even though the request was received and the server answered. |
|
Has this problem been solved? I have also reproduced it。thanks |
|
I haven't had any news since I posted the logs. |
thanks!!! |
Excuse me, can you reproduce the issue consistently? |
|
Actually, I found the issue, and was able to reproduce it consistently (see below for server and client code). The problem is that According to RFC 2616, there is no limitation on the header size, however, a lot of softwares add limitations (the provided response will provide an error in cURL, while it will work like a charm on Firefox). Can you confirm that this was due to an "oversized" header ? I would be more than happy to solve this issue, but we should agree on what we want to do here :
I will start from now on to work on that last option. Python3 Server codeimport socket
import random
import string
def generate_random_string(length):
return ''.join(random.choices(string.ascii_letters + string.digits, k=length))
random_string = ''.join(random.choices(string.ascii_letters + string.digits, k=256 * 1024 - 48))
# Création d'un socket TCP
with socket.socket(socket.AF_INET, socket.SOCK_STREAM) as server_socket:
server_socket.bind(('127.0.0.1', 8080))
server_socket.listen()
while True:
conn, addr = server_socket.accept()
with conn:
response = (
"HTTP/1.1 200 OK\n"
"Content-Type: text/plain\n"
f"MyHeader:{random_string}\n"
"Content-Length: 14\n"
"\n"
"Erreur de requête"
)
conn.sendall(response.encode('utf-8'))Kotlin client code with OkHttpimport okhttp3.OkHttpClient;
import okhttp3.Request;
import okhttp3.Response;
import okhttp3.ResponseBody;
public class OkHttpTest {
private static final String ENDPOINT = "http://127.0.0.1:8080";
public static void main(String... args) {
OkHttpClient client = new OkHttpClient();
try {
Request request = new Request.Builder()
.url(ENDPOINT)
.build();
try (Response response = client.newCall(request).execute()) {
ResponseBody body = response.body();
System.out.println(body.string());
}
} catch(Exception e) {
e.printStackTrace();
}
}
}Error stacktrace |
|
Anyone with the error, could you try with #8504 and tell me if it is working now? |
Cool! However, I still have one question. Why did the issue not happen with okhttp v3.x as mentioned in the second paragraph of issue description. |
@gahfy And I think the last third line of this log, which prints "\n not found, limit = 0, content=...", indicated a header of length 0. |
|
@Endeavour233 I don't know why v3 worked, as I don't know the release date of v3. It is actually like this (this kind of error) since 2017 in the git history. |
Got it, thank you. One more question, though I've understood how limit = 0 happens, I think |
|
@Endeavour233 This This is more "guess" than certainty, but if you have any reproductible scenario, I can investigate more on this. I understand that it might be complicated to share private results, but maybe you can try to compile with the code in #8504 and see if the error still occurs in your scenario (setting |
Sorry, I can't reproduce the issue(I am just another one who is interested in this issue). Could you please explain what you mean by saying |
|
@gahfy |
|
Hi. |
We've wanted to upgrade OkHttp v4.x for quite a while now, but we can't because of some change regarding the connection pool and its impact on the retry policy. In some cases, we can see a connection going to a server and being answered (we use proxyman to track network flows, and we can see both request and response going through), but for some reason, OkHttp decides to silently drop that connection even though it was successful and retry it (not sure if the connection was deemed stale and thus closed). So we see a second request going through in proxyman (which ends up with an error from the server in some cases because it was already processed the first time, authentication for instance), and in our code, the only result that we receive is that second one (the server error).
We've encountered the problem with all v 4.x versions that we've tested so far, but never had the problem with v3.x (currently 3.14.9). The exact conditions are hard to reproduce, but if you disable the retryOnConnectionFailure, you end up with an IOException. This means that for some reason, the socket was closed by OkHttp v4.x, in a way that did not happen in OkHttp v3.x, leading to this exception:
Error response
java.io.IOException: unexpected end of stream on https://www.xxxxxxxxxx.fr/...
at okhttp3.internal.http1.Http1ExchangeCodec.readResponseHeaders(Http1ExchangeCodec.kt:210)
at okhttp3.internal.connection.Exchange.readResponseHeaders(Exchange.kt:110)
at okhttp3.internal.http.CallServerInterceptor.intercept(CallServerInterceptor.kt:93)
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
at okhttp3.internal.connection.ConnectInterceptor.intercept(ConnectInterceptor.kt:34)
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
at okhttp3.internal.cache.CacheInterceptor.intercept(CacheInterceptor.kt:95)
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
at okhttp3.internal.http.BridgeInterceptor.intercept(BridgeInterceptor.kt:83)
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
at okhttp3.internal.http.RetryAndFollowUpInterceptor.intercept(RetryAndFollowUpInterceptor.kt:76)
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
at okhttp3.internal.connection.RealCall.getResponseWithInterceptorChain$okhttp(RealCall.kt:201)
at okhttp3.internal.connection.RealCall$AsyncCall.run(RealCall.kt:517)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1137)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:637)
at java.lang.Thread.run(Thread.java:1012)
Caused by: java.io.EOFException: \n not found: limit=0 content=…
at okio.RealBufferedSource.readUtf8LineStrict(RealBufferedSource.kt:335)
at okhttp3.internal.http1.HeadersReader.readLine(HeadersReader.kt:29)
at okhttp3.internal.http1.Http1ExchangeCodec.readResponseHeaders(Http1ExchangeCodec.kt:180)
at okhttp3.internal.connection.Exchange.readResponseHeaders(Exchange.kt:110)
at okhttp3.internal.http.CallServerInterceptor.intercept(CallServerInterceptor.kt:93)
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
at okhttp3.internal.connection.ConnectInterceptor.intercept(ConnectInterceptor.kt:34)
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
at okhttp3.internal.cache.CacheInterceptor.intercept(CacheInterceptor.kt:95)
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
at okhttp3.internal.http.BridgeInterceptor.intercept(BridgeInterceptor.kt:83)
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
at okhttp3.internal.http.RetryAndFollowUpInterceptor.intercept(RetryAndFollowUpInterceptor.kt:76)
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
at okhttp3.internal.connection.RealCall.getResponseWithInterceptorChain$okhttp(RealCall.kt:201)
at okhttp3.internal.connection.RealCall$AsyncCall.run(RealCall.kt:517)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1137)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:637)
at java.lang.Thread.run(Thread.java:1012)
at okhttp3.internal.connection.RealCall$AsyncCall.run(RealCall.kt:525)
at okhttp3.internal.http1.Http1ExchangeCodec.readResponseHeaders(Http1ExchangeCodec.kt:210)
at okhttp3.internal.connection.Exchange.readResponseHeaders(Exchange.kt:110)
at okhttp3.internal.http.CallServerInterceptor.intercept(CallServerInterceptor.kt:93)
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
at okhttp3.internal.connection.ConnectInterceptor.intercept(ConnectInterceptor.kt:34)
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
at okhttp3.internal.cache.CacheInterceptor.intercept(CacheInterceptor.kt:95)
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
at okhttp3.internal.http.BridgeInterceptor.intercept(BridgeInterceptor.kt:83)
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
at okhttp3.internal.http.RetryAndFollowUpInterceptor.intercept(RetryAndFollowUpInterceptor.kt:76)
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
at okhttp3.internal.connection.RealCall.getResponseWithInterceptorChain$okhttp(RealCall.kt:201)
at okhttp3.internal.connection.RealCall$AsyncCall.run(RealCall.kt:517)
at okhttp3.internal.http1.HeadersReader.readLine(HeadersReader.kt:29)
at okhttp3.internal.http1.Http1ExchangeCodec.readResponseHeaders(Http1ExchangeCodec.kt:180)
The text was updated successfully, but these errors were encountered: