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.

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

java.lang.IllegalStateException: too early; can't read the trailers yet #3049

Closed
YuriiKot opened this issue Jul 25, 2024 · 10 comments
Closed

Comments

@YuriiKot
Copy link

YuriiKot commented Jul 25, 2024

Hello!

We have an Android app with huge amount of users and getting crash in Android app

java.lang.IllegalStateException: too early; can't read the trailers yet
        at okhttp3.internal.http2.Http2Stream.trailers(Http2Stream:163)
        at okhttp3.internal.http2.Http2ExchangeCodec.trailers(Http2ExchangeCodec:118)
        at okhttp3.internal.connection.Exchange.trailers(Exchange:140)
        at okhttp3.Response.trailers(Response:180)
        at com.squareup.wire.internal.GrpcKt.grpcResponseToException(GrpcKt:195)
        at com.squareup.wire.internal.GrpcKt$readFromResponseBodyCallback$1$onResponse$1.invokeSuspend(GrpcKt:109)
        at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(BaseContinuationImpl:33)
        at kotlinx.coroutines.DispatchedTask.run(DispatchedTask:108)
        at kotlinx.coroutines.EventLoopImplBase.processNextEvent(EventLoopImplBase:280)
        at kotlinx.coroutines.BlockingCoroutine.joinBlocking(BlockingCoroutine:85)
        at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking(BuildersKt__BuildersKt:59)
        at kotlinx.coroutines.BuildersKt.runBlocking(BuildersKt:1)
        at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking$default(BuildersKt__BuildersKt:38)
        at kotlinx.coroutines.BuildersKt.runBlocking$default(BuildersKt:1)
        at com.squareup.wire.internal.GrpcKt$readFromResponseBodyCallback$1.onResponse(GrpcKt:98)
        at okhttp3.internal.connection.RealCall$AsyncCall.run(RealCall:519)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:644)
        at java.lang.Thread.run(Thread.java:1012)

Related thread trace

Thread 2919 - OkHttp https://api.xxx.com/... - (WAITING)
        at java.lang.Object.wait(Object.java:-2)
        at java.lang.Object.wait(Object.java:386)
        at java.lang.Object.wait(Object.java:524)
        at okhttp3.internal.http2.Http2Stream.waitForIo$okhttp(Http2Stream:714)
        at okhttp3.internal.http2.Http2Stream$FramingSource.read(Http2Stream:376)
        at okhttp3.internal.connection.Exchange$ResponseBodySource.read(Exchange:281)
        at okio.RealBufferedSource.exhausted(RealBufferedSource:200)
        at com.squareup.wire.internal.GrpcMessageSource.read(GrpcMessageSource:37)
        at com.squareup.wire.internal.GrpcKt$readFromResponseBodyCallback$1$onResponse$1.invokeSuspend(GrpcKt:104)
        at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(BaseContinuationImpl:33)
        at kotlinx.coroutines.DispatchedTask.run(DispatchedTask:108)
        at kotlinx.coroutines.EventLoopImplBase.processNextEvent(EventLoopImplBase:280)
        at kotlinx.coroutines.BlockingCoroutine.joinBlocking(BlockingCoroutine:85)
        at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking(BuildersKt__BuildersKt:59)
        at kotlinx.coroutines.BuildersKt.runBlocking(BuildersKt:1)
        at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking$default(BuildersKt__BuildersKt:38)
        at kotlinx.coroutines.BuildersKt.runBlocking$default(BuildersKt:1)
        at com.squareup.wire.internal.GrpcKt$readFromResponseBodyCallback$1.onResponse(GrpcKt:98)
        at okhttp3.internal.connection.RealCall$AsyncCall.run(RealCall:519)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:644)
        at java.lang.Thread.run(Thread.java:1012)

Most of the time happens in background after activity stop or resume and trying to establish connection

Steps to reproduce:

  1. Start bidi
  2. Throw IOException here
  3. Throw IllegalStateException here

It's rare edge case for prod that you need to have those 2 exceptions, but still around 0.002%

@oldergod
Copy link
Member

oldergod commented Aug 6, 2024

Thanks for reporting.
I fail to see the steps you list in the stacktrace you give us; for instance the stacktrace has grpcResponseToException once but you say it's called twice.

It could be that OkHttp throws on reading, and that after OkHttp threw, Wire tries to read the trailers and this fails.

@YuriiKot
Copy link
Author

YuriiKot commented Aug 6, 2024

@oldergod You are right, updated steps to reproduce. I guess IOException is really thrown during read. New steps give similar stacktrace

@oldergod
Copy link
Member

oldergod commented Aug 7, 2024

Is there no trace from OkHttp's read? And your trace isn't analyzable by the IDE right now, are you modifying it, or is it how the play console shows it?

@YuriiKot
Copy link
Author

YuriiKot commented Aug 7, 2024

This trace is from Bugsnag reported thread. I see trace from another thread though

Object.java:-2 java.lang.Object.wait
Object.java:386 java.lang.Object.wait
Object.java:524 java.lang.Object.wait
Http2Stream:714 okhttp3.internal.http2.Http2Stream.waitForIo$okhttp
Http2Stream:376 okhttp3.internal.http2.Http2Stream$FramingSource.read
Exchange:281 okhttp3.internal.connection.Exchange$ResponseBodySource.read
RealBufferedSource:265 okio.RealBufferedSource.read
RealBufferedSource:76 okio.RealBufferedSource.read
OkHttpNetwork:189 io.bitdrift.capture.network.okhttp.OkHttpNetwork$StreamState.consumeResponse
OkHttpNetwork:97 io.bitdrift.capture.network.okhttp.OkHttpNetwork$StreamState.access$consumeResponse
OkHttpNetwork:138 io.bitdrift.capture.network.okhttp.OkHttpNetwork$StreamState$2$onResponse$1.run
ThreadPoolExecutor.java:1145 java.util.concurrent.ThreadPoolExecutor.runWorker
ThreadPoolExecutor.java:644 java.util.concurrent.ThreadPoolExecutor$Worker.run
Thread.java:1012 java.lang.Thread.run

@oldergod
Copy link
Member

oldergod commented Aug 7, 2024

Got it. I recommend using the "raw" version of those when sharing with others.

image

@YuriiKot
Copy link
Author

YuriiKot commented Aug 9, 2024

Thanks, good call. I also found another thread with proper trace and updated the question accordingly. In previous messages I guess it was bitdrift logger or something

@YuriiKot
Copy link
Author

@oldergod Do you have any recommendations or a workaround to address the issue?

@oldergod
Copy link
Member

oldergod commented Sep 2, 2024

I think OkHttp throws on reading and Wire is wrong in reading the trailers if it cannot. If you don't know what the problem is in the reading (or if the cause is elsewhere), I don't see much. I'll try to update Wire so that we don't read the trailers if we are not to.

@YuriiKot
Copy link
Author

YuriiKot commented Sep 4, 2024

Thanks. I don't see reading problem. Our current setup works in prod for 10M+ users. This might be some edge case, but still appears to be the top 1 crash

@oldergod
Copy link
Member

Closed with #3087 hopefully.
Will be in next release happening this week.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants