Couldn't do get request after turning off internet

[kate-fin]

Hello.

I do POST request for getting token, next do GET request to get data. I turn off my internet connection, after that turn on it and do GET request again.

Link to the project: https://github.com/kate-fin/OkHttpDoesntWorkApplication.git
You just need click the button, turn off internet, turn it on and click button again

Log of error:
E/AndroidRuntime: FATAL EXCEPTION: OkHttp Dispatcher
Process: com.example.okhttpdoesntworkapplication, PID: 30701
java.lang.IllegalStateException: state: 0
at okhttp3.internal.http1.Http1ExchangeCodec.readResponseHeaders(Http1ExchangeCodec.kt:173)
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.logging.HttpLoggingInterceptor.intercept(HttpLoggingInterceptor.kt:222)
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:1167)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
at java.lang.Thread.run(Thread.java:923)
D/OOMEventManagerFK: checkEventAndDumpForJE: 0
I/Process: Sending signal. PID: 30701 SIG: 9

You could answer me to [email protected]

Thank you.

[yschimke]

Thanks for the great reproduction. Was able to reproduce with 5.0.0-alpha2, but couldn't on 4.9.1.

To unblock you, I'd suggest building against 4.9.1 until we fix this issue.

[yschimke]

@swankjesse I'm still taking a look, but most likely candidate is 9533117

[yschimke]

If it fails writing the request headers

  /** Returns bytes of a request header for sending on an HTTP transport. */
  fun writeRequest(headers: Headers, requestLine: String) {
    check(state == STATE_IDLE) { "state: $state" }
    sink.writeUtf8(requestLine).writeUtf8("\r\n")
    for (i in 0 until headers.size) {
      sink.writeUtf8(headers.name(i))
          .writeUtf8(": ")
          .writeUtf8(headers.value(i))
          .writeUtf8("\r\n")
    }
    sink.writeUtf8("\r\n")
    state = STATE_OPEN_REQUEST_BODY
  }

Then we try to read after the exception, but are in STATE_IDLE

  override fun readResponseHeaders(expectContinue: Boolean): Response.Builder? {
    check(state == STATE_OPEN_REQUEST_BODY ||
        state == STATE_WRITING_REQUEST_BODY ||
        state == STATE_READ_RESPONSE_HEADERS) {
      "state: $state"
    }

We could either

a) Not try to read response headers if we haven't successfully written the request headers, so we only attempt to read the response headers if sending the body fails.
b) Add state == STATE_IDLE to readResponseHeaders.

[yschimke]

Quick attempt at a reproduction on JDK didn't work, I suspect I'm not faithfully reproducing the actual observable behaviour on Android after a network disconnection (airplane mode etc). No luck making a reproducing test yet.

[swankjesse]

Of the two options I think a makes the most sense. I think you're right that it's a logic bug I introduced in that commit.

[yschimke]

Closing as a likely dupe of #3278

[OliverMatz]

The same problem happens sporadically on my system after making a couple of changes, including an update of okhttp from 4.10.0 to 4.11.0. Here is my stacktrace:

java.lang.IllegalStateException: state: 0
	at deployment.myproject.war//okhttp3.internal.http1.Http1ExchangeCodec.readResponseHeaders(Http1ExchangeCodec.kt:173)
	at deployment.myproject.war//okhttp3.internal.connection.Exchange.readResponseHeaders(Exchange.kt:110)
	at deployment.myproject.war//okhttp3.internal.http.CallServerInterceptor.intercept(CallServerInterceptor.kt:93)
	at deployment.myproject.war//okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
	at deployment.myproject.war//okhttp3.internal.connection.ConnectInterceptor.intercept(ConnectInterceptor.kt:34)
	at deployment.myproject.war//okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
	at deployment.myproject.war//okhttp3.internal.cache.CacheInterceptor.intercept(CacheInterceptor.kt:95)
	at deployment.myproject.war//okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
	at deployment.myproject.war//okhttp3.internal.http.BridgeInterceptor.intercept(BridgeInterceptor.kt:83)
	at deployment.myproject.war//okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
	at deployment.myproject.war//okhttp3.internal.http.RetryAndFollowUpInterceptor.intercept(RetryAndFollowUpInterceptor.kt:76)
	at deployment.myproject.war//okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
	at deployment.myproject.war//de.myproject.SpecificTimeoutInterceptor.intercept(SpecificTimeoutInterceptor.java:43)
	at deployment.myproject.war//okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
	at deployment.myproject.war//okhttp3.logging.HttpLoggingInterceptor.intercept(HttpLoggingInterceptor.kt:221)
	at deployment.myproject.war//okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
	at deployment.myproject.war//de.myproject.RetrofitFactory.lambda$createRetrofit$0(RetrofitFactory.java:129)
	at deployment.myproject.war//okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
	at deployment.myproject.war//okhttp3.internal.connection.RealCall.getResponseWithInterceptorChain$okhttp(RealCall.kt:201)
	at deployment.myproject.war//okhttp3.internal.connection.RealCall.execute(RealCall.kt:154)
	at deployment.myproject.war//retrofit2.OkHttpCall.execute(OkHttpCall.java:204)

[yschimke]

Will take a look again.

[yschimke]

Timing of #7453 jives with a regression between 4.10 and 4.11.

But that doesn't link in with the original bug report, so I suspect two bugs. One existing, and one in 4.11.

But I tried the repro at the top and the content has changed, even swallowing 404, I don't think we get the same observable behaviour. Servers returning an early response must be a factor...

So no repro, but I'll test a few more things.

[yschimke]

@kate-fin are you able to repro still?

[Twinsen81]

We have started experiencing the same crash after updating OkHttp 4.10.0 -> 4.12.0:

Fatal Exception: java.lang.IllegalStateException: state: 0
       at okhttp3.internal.http1.Http1ExchangeCodec.readResponseHeaders(Http1ExchangeCodec.kt:173)
       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 com.smartadserver.android.coresdk.util.SCSUtil$1.intercept(SCSUtil.java:452)
       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:1167)
       at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
       at java.lang.Thread.run(Thread.java:764)

[theapache64]

I am getting the same error, but only when the fullMode is enabled. I am using 5.0.0-alpha.8

[yschimke]

I tried to reproduce without success. Not sure if AGP, R8 or a bug/race condition in OkHttp.

Without a repro, it's hard to take further.

[yschimke]

Interestingly 4.10 to 4.12 does change this code to allow reading response headers early

[bubbleguuum]

I also got a single report of this crash for my app (so fairly rare) using v4.12.
I do no have an easy repro but the logging attached to the crash report seems to indicate it is related
to a http server returning an error 404.

[ashar340]

Facing the same issue and the trace is identical for the crash, any update on this?