Skip to content

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

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

Closed
mgenov opened this issue May 3, 2019 · 15 comments

Comments

@mgenov
Copy link

mgenov commented May 3, 2019

[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:
Screen Shot 2019-05-03 at 18 34 22

Screen Shot 2019-05-03 at 18 35 06

Steps to reproduce:

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

Relevant Code:

N/A

@var-const
Copy link
Contributor

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
Copy link
Author

mgenov commented May 4, 2019

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
Copy link
Contributor

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
Copy link
Author

mgenov commented May 7, 2019

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:
image

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

@mgenov
Copy link
Author

mgenov commented Jul 18, 2019

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
Copy link
Contributor

wilhuff commented Jul 18, 2019

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.

@PratyeshSingh
Copy link

Hi Everyone,
I have also the same ANR issue reported more than 100K in play console.

case 1:-
ANR because of Broadcast of Intent { act=com.google.android.c2dm.intent.RECEIVE in FirebaseInstanceIdReceiver

"main" prio=5 tid=1 Waiting
| group="main" sCount=1 dsCount=0 obj=0x751a5000 self=0xb8d3a630
| sysTid=29578 nice=-4 cgrp=apps sched=0/0 handle=0xb6fb6ec8
| state=S schedstat=( 1264064036 710641375 2251 ) utm=96 stm=30 core=0 HZ=100
| stack=0xbe31d000-0xbe31f000 stackSize=8MB
| held mutexes=
at java.lang.Object.wait! (Native method)

waiting on <0x13be0a86> (a java.lang.Object)
at java.lang.Thread.parkFor (Thread.java:1220)
locked <0x13be0a86> (a java.lang.Object)
at sun.misc.Unsafe.park (Unsafe.java:299)
at java.util.concurrent.locks.LockSupport.park (LockSupport.java:157)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt (AbstractQueuedSynchronizer.java:813)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly (AbstractQueuedSynchronizer.java:973)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly (AbstractQueuedSynchronizer.java:1281)
at java.util.concurrent.CountDownLatch.await (CountDownLatch.java:202)
at android.app.SharedPreferencesImpl$EditorImpl$1.run (SharedPreferencesImpl.java:363)
at android.app.QueuedWork.waitToFinish (QueuedWork.java:88)
at android.app.ActivityThread.handleServiceArgs (ActivityThread.java:3272)
at android.app.ActivityThread.access$2200 (ActivityThread.java:168)
at android.app.ActivityThread$H.handleMessage (ActivityThread.java:1491)
at android.os.Handler.dispatchMessage (Handler.java:102)
at android.os.Looper.loop (Looper.java:135)
at android.app.ActivityThread.main (ActivityThread.java:5753)
at java.lang.reflect.Method.invoke! (Native method)
at java.lang.reflect.Method.invoke (Method.java:372)
at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run (ZygoteInit.java:1405)
at com.android.internal.os.ZygoteInit.main (ZygoteInit.java:1200)

case 2:-
Fatal Exception: java.lang.RuntimeException: Unable to start receiver com.google.firebase.iid.FirebaseInstanceIdReceiver: java.util.concurrent.RejectedExecutionException: Task com.google.firebase.messaging.h@c7b0009 rejected from java.util.concurrent.ThreadPoolExecutor@a57f20e[Shutting down, pool size = 1, active threads = 1, queued tasks = 6, completed tasks = 1]
at android.app.ActivityThread.handleReceiver(ActivityThread.java:3230)
at android.app.ActivityThread.-wrap17()
at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1698)
at android.os.Handler.dispatchMessage(Handler.java:106)
at android.os.Looper.loop(Looper.java:176)
at android.app.ActivityThread.main(ActivityThread.java:6635)
at java.lang.reflect.Method.invoke(Method.java)
at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:547)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:823)

//firebase lib
implementation 'com.google.firebase:firebase-messaging:19.0.1'
implementation 'com.google.firebase:firebase-core:17.0.0'
implementation 'com.google.firebase:firebase-appindexing:19.0.0'
implementation 'com.google.firebase:firebase-config:18.0.0'

// sdk version
compileSdkVersion = 28
minSdkVersion = 17
targetSdkVersion = 28

for more details regard to this ANR please look
Please help me on it if anyone of you are having solution of this.
Thanks in advance.

@wilhuff
Copy link
Contributor

wilhuff commented Nov 5, 2019

@Pratyesh your stack traces are related to Firebase Messaging, but this issue is related to Firestore. Please create a new issue with as many details as you can share so that the Messaging team can help.

@saturnism
Copy link

Happened when running inside of JUnit, and also having the work submitted to an ExecutorService.

java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@45e3e93c[Not completed, task = java.util.concurrent.Executors$RunnableAdapter@4dee307[Wrapped task = com.google.cloud.firestore.TransactionRunner$1@e16744]] rejected from java.util.concurrent.ScheduledThreadPoolExecutor@7d93518[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 2]
java.util.concurrent.RejectedExecutionException: Task java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@45e3e93c[Not completed, task = java.util.concurrent.Executors$RunnableAdapter@4dee307[Wrapped task = com.google.cloud.firestore.TransactionRunner$1@e16744]] rejected from java.util.concurrent.ScheduledThreadPoolExecutor@7d93518[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 2]
	at java.base/java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2057)
	at java.base/java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:827)
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor.delayedExecute(ScheduledThreadPoolExecutor.java:340)
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor.schedule(ScheduledThreadPoolExecutor.java:562)
	at com.google.cloud.firestore.TransactionRunner.run(TransactionRunner.java:104)
	at com.google.cloud.firestore.FirestoreImpl.runAsyncTransaction(FirestoreImpl.java:316)
	at com.google.cloud.firestore.FirestoreImpl.runTransaction(FirestoreImpl.java:283)
...

@sag-007
Copy link

sag-007 commented May 13, 2020

E/AndroidRuntime: FATAL EXCEPTION: main
Process: com.example.final_project, PID: 7321
java.lang.RuntimeException: Unable to start activity ComponentInfo{com.example.final_project/com.example.final_project.SignUp}: java.util.concurrent.RejectedExecutionException: Task java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@b347041 rejected from com.google.firebase.database.core.utilities.DefaultRunLoop$1@2cdc9e6[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 1]
at android.app.ActivityThread.performLaunchActivity(ActivityThread.java:2913)
at android.app.ActivityThread.handleLaunchActivity(ActivityThread.java:3048)
at android.app.servertransaction.LaunchActivityItem.execute(LaunchActivityItem.java:78)
at android.app.servertransaction.TransactionExecutor.executeCallbacks(TransactionExecutor.java:108)
at android.app.servertransaction.TransactionExecutor.execute(TransactionExecutor.java:68)
at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1808)
at android.os.Handler.dispatchMessage(Handler.java:106)
at android.os.Looper.loop(Looper.java:193)
at android.app.ActivityThread.main(ActivityThread.java:6669)
at java.lang.reflect.Method.invoke(Native Method)
at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:493)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:858)
Caused by: java.util.concurrent.RejectedExecutionException: Task java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@b347041 rejected from com.google.firebase.database.core.utilities.DefaultRunLoop$1@2cdc9e6[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 1]
at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2085)
at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:848)
at java.util.concurrent.ScheduledThreadPoolExecutor.delayedExecute(ScheduledThreadPoolExecutor.java:334)
at java.util.concurrent.ScheduledThreadPoolExecutor.schedule(ScheduledThreadPoolExecutor.java:562)
at java.util.concurrent.ScheduledThreadPoolExecutor.execute(ScheduledThreadPoolExecutor.java:654)
at com.google.firebase.database.core.utilities.DefaultRunLoop.scheduleNow(com.google.firebase:firebase-database@@16.0.4:105)
at com.google.firebase.database.core.Repo.scheduleNow(com.google.firebase:firebase-database@@16.0.4:276)
at com.google.firebase.database.Query.addEventRegistration(com.google.firebase:firebase-database@@16.0.4:233)
at com.google.firebase.database.Query.addValueEventListener(com.google.firebase:firebase-database@@16.0.4:149)
at com.example.final_project.SignUp.updateUsers(SignUp.java:53)
at com.example.final_project.SignUp.onCreate(SignUp.java:48)
at android.app.Activity.performCreate(Activity.java:7136)
at android.app.Activity.performCreate(Activity.java:7127)
at android.app.Instrumentation.callActivityOnCreate(Instrumentation.java:1271)
at android.app.ActivityThread.performLaunchActivity(ActivityThread.java:2893)
at android.app.ActivityThread.handleLaunchActivity(ActivityThread.java:3048) 
at android.app.servertransaction.LaunchActivityItem.execute(LaunchActivityItem.java:78) 
at android.app.servertransaction.TransactionExecutor.executeCallbacks(TransactionExecutor.java:108) 
at android.app.servertransaction.TransactionExecutor.execute(TransactionExecutor.java:68) 
at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1808) 
at android.os.Handler.dispatchMessage(Handler.java:106) 
at android.os.Looper.loop(Looper.java:193) 
at android.app.ActivityThread.main(ActivityThread.java:6669) 
at java.lang.reflect.Method.invoke(Native Method) 
at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:493) 
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:858) 
I/Process: Sending signal. PID: 7321 SIG: 9
Process 7321 terminated.

my application crashes when trying to run the application and shows the following error!!

@wilhuff
Copy link
Contributor

wilhuff commented May 13, 2020

@sag-007 though the exception name is in common with the one in this issue, you’re using the Realtime Database, not Firestore.

Please open a new issue with all the details in the template.

@NativeDevlopment
Copy link

Fatal Exception: java.util.concurrent.RejectedExecutionException
Task java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@3660204 rejected from com.google.firebase.database.core.utilities.DefaultRunLoop$1@4741e17[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 5061]

@argzdev
Copy link
Contributor

argzdev commented Nov 15, 2021

Hi @mgenov, just bumping this thread. May I ask if you're still encountering this issue on the latest SDK?

@google-oss-bot
Copy link
Contributor

Hey @mgenov. We need more information to resolve this issue but there hasn't been an update in 5 weekdays. I'm marking the issue as stale and if there are no new updates in the next 5 days I will close it automatically.

If you have more information that will help us get to the bottom of this, just add a comment!

@google-oss-bot
Copy link
Contributor

Since there haven't been any recent updates here, I am going to close this issue.

@mgenov if you're still experiencing this problem and want to continue the discussion just leave a comment here and we are happy to re-open this.

@firebase firebase locked and limited conversation to collaborators Dec 30, 2021
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

No branches or pull requests

9 participants