firebase/firestore: rejected task using com.google.firebase.firestore.util.AsyncQueue

[mgenov]

[REQUIRED] Step 2: Describe your environment

• Firebase Component: Firestore
• Component version: 18.2.0
• Affected Android Versions: 4.2.2, 5.1.1

[REQUIRED] Step 3: Describe the problem

Got this stack trace from crashlytics:

Fatal Exception: java.util.concurrent.RejectedExecutionException: Task java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@3c12814d rejected from com.google.firebase.firestore.util.AsyncQueue$1@394ca676[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 6141]
       at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2011)
       at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:793)
       at java.util.concurrent.ScheduledThreadPoolExecutor.delayedExecute(ScheduledThreadPoolExecutor.java:298)
       at java.util.concurrent.ScheduledThreadPoolExecutor.schedule(ScheduledThreadPoolExecutor.java:503)
       at java.util.concurrent.ScheduledThreadPoolExecutor.execute(ScheduledThreadPoolExecutor.java:592)
       at io.grpc.internal.SerializingExecutor.schedule(SerializingExecutor.java:93)
       at io.grpc.internal.SerializingExecutor.execute(SerializingExecutor.java:86)
       at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.closed(ClientCallImpl.java:588)
       at io.grpc.internal.ForwardingClientStreamListener.closed(ForwardingClientStreamListener.java:39)
       at io.grpc.internal.InternalSubchannel$CallTracingTransport$1$1.closed(InternalSubchannel.java:716)
       at io.grpc.internal.DelayedStream$DelayedStreamListener$5.run(DelayedStream.java:441)
       at io.grpc.internal.DelayedStream$DelayedStreamListener.delayOrExecute(DelayedStream.java:383)
       at io.grpc.internal.DelayedStream$DelayedStreamListener.closed(DelayedStream.java:438)
       at io.grpc.internal.AbstractClientStream$TransportState.closeListener(AbstractClientStream.java:452)
       at io.grpc.internal.AbstractClientStream$TransportState.access$400(AbstractClientStream.java:212)
       at io.grpc.internal.AbstractClientStream$TransportState$1.run(AbstractClientStream.java:435)
       at io.grpc.internal.AbstractClientStream$TransportState.deframerClosed(AbstractClientStream.java:273)
       at io.grpc.internal.Http2ClientStreamTransportState.deframerClosed(Http2ClientStreamTransportState.java:31)
       at io.grpc.okhttp.OkHttpClientStream$TransportState.deframerClosed(OkHttpClientStream.java:282)
       at io.grpc.internal.MessageDeframer.close(MessageDeframer.java:229)
       at io.grpc.internal.MessageDeframer.closeWhenComplete(MessageDeframer.java:191)
       at io.grpc.internal.AbstractStream$TransportState.closeDeframer(AbstractStream.java:183)
       at io.grpc.internal.AbstractClientStream$TransportState.transportReportStatus(AbstractClientStream.java:438)
       at io.grpc.okhttp.OkHttpClientTransport.startGoAway(OkHttpClientTransport.java:765)
       at io.grpc.okhttp.OkHttpClientTransport.access$1700(OkHttpClientTransport.java:102)
       at io.grpc.okhttp.OkHttpClientTransport$ClientFrameHandler.run(OkHttpClientTransport.java:980)
       at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1112)
       at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587)
       at java.lang.Thread.run(Thread.java:818)

Here is the device information:

Steps to reproduce:

It happens rarely but the amount of devices in production is less than 100.

Relevant Code:

N/A

[var-const]

Thank you for reporting the issue. The exception seems to be coming from deep inside gRPC internals. Can you provide any additional information? Are there any specific steps that trigger the exception? Would it be possible for you to obtain a log? (FirebaseFirestore.setLoggingEnabled(true);).

[mgenov]

Not sure that crashlytics is going to report the output of logcat if setLoggingEnabled is set to true. It would be nice if you can give me some notes/direction on how to deploy the application with these settings.

This is the complete stack trace of the crash with information regarding all threads:
com.clouway.politis_issue_crash_5CCABF8D02FE000127AD058EE5CFC375_DNE_0_v2.txt

[var-const]

Thank you for the full stack trace.

Unfortunately, at the moment Firestore logs cannot be extracted from Crashlytics. If this issue is critical for you, we could give you guidance on how to achieve that -- it would require code changes to Firestore.

The exception that triggered the crash is actually secondary. It is raised when Firestore async queue is shut down, but something (gRPC in this case) still tries to enqueue a task on it. The root cause is whatever made the async queue shut down -- unfortunately, it is not represented in the stack trace. We plan to add some defensive code to the async queue to make sure the original exception doesn't vanish without a trace.

One more question -- do you see any other crashes in Crashlytics that could plausibly be the same issue? Because the root issue is that async queue got shut down, it may manifest with a different stack trace.

[mgenov]

Here is another one that might be related.

Fatal Exception: java.lang.OutOfMemoryError: pthread_create (1040KB stack) failed: Try again
       at java.lang.Thread.nativeCreate(Thread.java)
       at java.lang.Thread.start(Thread.java:1063)
       at java.util.concurrent.ThreadPoolExecutor.addWorker(ThreadPoolExecutor.java:920)
       at java.util.concurrent.ThreadPoolExecutor.ensurePrestart(ThreadPoolExecutor.java:1553)
       at java.util.concurrent.ScheduledThreadPoolExecutor.delayedExecute(ScheduledThreadPoolExecutor.java:306)
       at java.util.concurrent.ScheduledThreadPoolExecutor.schedule(ScheduledThreadPoolExecutor.java:503)
       at java.util.concurrent.ScheduledThreadPoolExecutor.execute(ScheduledThreadPoolExecutor.java:592)
       at okhttp3.internal.http2.Http2Connection$ReaderRunnable.applyAndAckSettings(Http2Connection.java:739)
       at okhttp3.internal.http2.Http2Connection$ReaderRunnable.settings(Http2Connection.java:711)
       at okhttp3.internal.http2.Http2Reader.readSettings(Http2Reader.java:289)
       at okhttp3.internal.http2.Http2Reader.nextFrame(Http2Reader.java:141)
       at okhttp3.internal.http2.Http2Reader.readConnectionPreface(Http2Reader.java:80)
       at okhttp3.internal.http2.Http2Connection$ReaderRunnable.execute(Http2Connection.java:609)
       at okhttp3.internal.NamedRunnable.run(NamedRunnable.java:32)
       at java.lang.Thread.run(Thread.java:818)

The strange thing here is that device memory usage is really low and I'm not sure that memory is the real cause of the problem:

The complete stack trace:
com.clouway.politis_issue_crash_5CCBF57F031100011493A312B5FE0130_DNE_0_v2.txt

[mgenov]

Got another similar exception:

Fatal Exception: java.util.concurrent.RejectedExecutionException: Task java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@129542b3 rejected from com.google.firebase.firestore.util.AsyncQueue$1@2d522070[Shutting down, pool size = 1, active threads = 1, queued tasks = 0, completed tasks = 6373]
       at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution + 2011(ThreadPoolExecutor.java:2011)
       at java.util.concurrent.ThreadPoolExecutor.reject + 793(ThreadPoolExecutor.java:793)
       at java.util.concurrent.ScheduledThreadPoolExecutor.delayedExecute + 298(ScheduledThreadPoolExecutor.java:298)
       at java.util.concurrent.ScheduledThreadPoolExecutor.schedule + 503(ScheduledThreadPoolExecutor.java:503)
       at java.util.concurrent.ScheduledThreadPoolExecutor.execute + 592(ScheduledThreadPoolExecutor.java:592)
       at com.google.android.gms.tasks.zzk.onComplete + 11(:11)
       at com.google.android.gms.tasks.zzr.zza + 19(:19)
       at com.google.android.gms.tasks.zzu.setException + 102(:102)
       at com.google.android.gms.tasks.zzd.run + 13(:13)
       at android.os.Handler.handleCallback + 739(Handler.java:739)
       at android.os.Handler.dispatchMessage + 95(Handler.java:95)
       at android.os.Looper.loop + 135(Looper.java:135)
       at android.app.ActivityThread.main + 5254(ActivityThread.java:5254)
       at java.lang.reflect.Method.invoke(Method.java)
       at java.lang.reflect.Method.invoke + 372(Method.java:372)
       at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run + 902(ZygoteInit.java:902)
       at com.android.internal.os.ZygoteInit.main + 697(ZygoteInit.java:697)

[wilhuff]

This last stack trace doesn't really tell us anything. After's there's been a failure of some kind, Firestore shuts down its internal queue. What's happening here is that something is trying to execute an on-completion handler on that queue after a crash but failing to do so. There's no indication what was trying to run though.

In any case this is already a secondary failure. Something else is the actual failure and isn't indicated here.