search

cgeo / cgeo

c:geo - The powerful Android geocaching app.
www.cgeo.org
Apache License 2.0
1.39k stars 565 forks source link

RejectedExecutionException #8402

Open Lineflyer opened 4 years ago

Lineflyer commented 4 years ago

From Google Play flagged as new for beta version 2020.05.31-RC 1 report, Android 9

io.reactivex.rxjava3.exceptions.UndeliverableException: 

  at io.reactivex.rxjava3.plugins.RxJavaPlugins.onError (RxJavaPlugins.java:367)

  at io.reactivex.rxjava3.internal.schedulers.NewThreadWorker.scheduleActual (NewThreadWorker.java:153)

  at io.reactivex.rxjava3.internal.schedulers.NewThreadWorker.schedule (NewThreadWorker.java:50)

  at io.reactivex.rxjava3.core.Scheduler$Worker$PeriodicTask.run (Scheduler.java:535)

  at io.reactivex.rxjava3.internal.schedulers.ScheduledRunnable.run (ScheduledRunnable.java:65)

  at io.reactivex.rxjava3.internal.schedulers.ScheduledRunnable.call (ScheduledRunnable.java:56)

  at java.util.concurrent.FutureTask.run (FutureTask.java:266)

  at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run (ScheduledThreadPoolExecutor.java:301)

  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)
Caused by: java.util.concurrent.RejectedExecutionException: 

  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:579)

  at io.reactivex.rxjava3.internal.schedulers.NewThreadWorker.scheduleActual (NewThreadWorker.java:146)
bekuno commented 4 years ago

Maybe this point is helpful: https://github.com/ReactiveX/RxJava/wiki/What's-different-in-3.0#more-undeliverable-errors

moving-bits commented 4 years ago

I have no idea how to fix this, not even where this comes from, the error log is not very specific...

@UniQP Do you have an idea how to tackle this one?

Lineflyer commented 4 years ago

We had a similar report in the past: #6388 which was "fixed" by @samueltardieu in https://github.com/cgeo/cgeo/commit/13d48efa94b513f5d99375325653f9f6fa1062d7

Lineflyer commented 4 years ago

This is the most prominent crash report right now for release 2020.06.14, however still "only" 545 reports for 486 users.

moving-bits commented 4 years ago

RxJava is out of my scope of knowledge. Maybe @UniQP can help?

Lineflyer commented 4 years ago

FYI: This is still the crash event with highest appearance and amount of users affected Also for 2020.08.04.

If we miss knowledge about this topic, how about checking if a new RXjava version is available? Or @samueltardieu or @UniQP might have an idea?

Stack trace example of current version:

io.reactivex.rxjava3.exceptions.UndeliverableException: 

  at io.reactivex.rxjava3.plugins.RxJavaPlugins.onError (RxJavaPlugins.java:367)

  at io.reactivex.rxjava3.internal.schedulers.NewThreadWorker.scheduleActual (NewThreadWorker.java:153)

  at io.reactivex.rxjava3.internal.schedulers.NewThreadWorker.schedule (NewThreadWorker.java:50)

  at io.reactivex.rxjava3.core.Scheduler$Worker$PeriodicTask.run (Scheduler.java:535)

  at io.reactivex.rxjava3.internal.schedulers.ScheduledRunnable.run (ScheduledRunnable.java:65)

  at io.reactivex.rxjava3.internal.schedulers.ScheduledRunnable.call (ScheduledRunnable.java:56)

  at java.util.concurrent.FutureTask.run (FutureTask.java:266)

  at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run (ScheduledThreadPoolExecutor.java:301)

  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:919)
Caused by: java.util.concurrent.RejectedExecutionException: 

  at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution (ThreadPoolExecutor.java:2086)

  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:579)

  at io.reactivex.rxjava3.internal.schedulers.NewThreadWorker.scheduleActual (NewThreadWorker.java:146)
bekuno commented 4 years ago

current:

    implementation 'io.reactivex.rxjava3:rxjava:3.0.4'
    implementation "io.reactivex.rxjava3:rxandroid:3.0.0"

An Update to rxjava:3.0.5 is available, rxandroid is unchanged. see https://github.com/ReactiveX/RxJava/releases/tag/v3.0.5

moving-bits commented 4 years ago

As of today > 3.400 occurrences, in the last 60 days mainly happening with release versions 2020.08.04 and 2020.07.02, but also occurring with 2020.06.14. (Play Console does list for the last 60 days only, so older versions may be harmed as well, but no longer listed here.) Also still happening in the latest beta versions.

Any ideas how to tackle this?

UniQP commented 4 years ago

The following line of the stack trace looks interesting: at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution (ThreadPoolExecutor.java:2086)

As far as I can see, we don't create a ThreadPoolExecutor that uses the AbortPolicy (which is the default policy). So the ThreadPoolExecutor is probably created by RxJava itself. That said, it might help to check whether we use an operator that can throw a RejectedExecutionException.

Of course, it would also help to know in which use case the problem occurs.

eddiemuc commented 4 years ago

I have no knowledge of RxJava. But following up on what @UniQP I did a usage search of package "rxjava3

I found at least one place where default schedulers of RxJava are used: class GPXIndividualRouteImporter makes a call to Schedulers.io(). If I understand @UniQP correctly this might create a ThreadPoolExecutor with AbortPolicy

Also, can it be that this exception/crash only happens when users close the app anyway (and thus pending messages can't be delivered any more)? THis would mean imho that the problem is not so severe

moving-bits commented 4 years ago

@UniQP @eddiemuc Thanks for having a quick glance on this.

I have no knowledge of RxJava.

Me neither.

I found at least one place where default schedulers of RxJava are used: class GPXIndividualRouteImporter makes a call to Schedulers.io().

IIRC we should have a few more places where Schedulers.io() is used. But let's get a response from @UniQP whether those may be the culprit.

Also, can it be that this exception/crash only happens when users close the app anyway (and thus pending messages can't be delivered any more)? THis would mean imho that the problem is not so severe

Not necessarily closing the app, but may be closing an activity as well. Still it would be nice to get rid of the exceptions.

bekuno commented 4 years ago

From https://github.com/ReactiveX/RxJava/wiki/What's-different-in-3.0#more-undeliverable-errors there is a link to a details page for error handling https://github.com/ReactiveX/RxJava/wiki/What's-different-in-3.0#more-undeliverable-errors . Android is more strict and terminates the application in such uncaught exception cases. Then there is a long description for the necessary error handling and the possibilities.

UniQP commented 4 years ago

First of all, I'm also not an RxJava expert.

Schedulers.io() is not bounded to a number of working threads; thus, we shouldn't run into a RejectedExecutionException.

However, I missed two Schedulers yesterday: AndroidRxUtils.computationScheduler (which is Schedulers.computation()) and AndroidRxUtils.looperCallbacksScheduler. I'm not sure whether the latter can throw a RejectedExecutionException (I rather doubt it) but the computationScheduler can do for sure, because it's bounded to a fixed number of worker threads.

There are only a few uses of the computationScheduler, so catching and logging the exceptions there could help us to figure out who causes the RejectedExecutionException.

We could also call RxJavaPlugins.setFailOnNonBlockingScheduler(true) to identify cases where we block a thread on the computationScheduler.

moving-bits commented 4 years ago

Thanks @UniQP for your analysis!

Looking for Schedulers.computation() and AndroidRxUtils.computationScheduler there are less than ten founds for it. As the error is relatively new, it might be caused by one of the more recent usages of it, the most prominent being recalculating an individual route (used in both CGeoMap and NewMap:

AndroidRxUtils.andThenOnUi(Schedulers.computation(), () -> {
    tracks.calculateNavigationRoute();
    trackLayer.updateRoute(tracks);
}, () -> trackLayer.requestRedraw());

Would you suggest a different scheduler for this type of call? Where to put try/catch - around the whole code segment shown above, inside the first lambda, or where else?

UniQP commented 4 years ago

@moving-bits I would argue that ….updateRoute(tracks) should also run on the UI thread (so it should be moved to the second lambda). Furthermore, in CGeoMap.routingModeChanged() the last line should be moved into an else block, right?

A try/catch needs to be around the whole code segment.

eddiemuc commented 3 years ago

A little off-topic (and as already asked in another place): I see many occurences in c:geo code where anonymous instances of AsyncTaskare created to perform actions in the background and then resync with UI thread. Should in general all those occurences be replaced by calls to AndroidRxUtils.andThenOnUi instead? If not, when would one use AsyncTask and when AndroidRxUtils.andThenOnUi ?

Examples of AsyncTask-usages can be found e.g. in CacheListActivity(but in many other activities as well): (And Android Studio warns me always that those may be a source of memory leak)

image

Lineflyer commented 3 years ago

With our new beta version 2020.11.14-RC (which should AFAICS include the try/catch implemented in #9167) the problem is still reported. Not sure if something changed compared to before:

io.reactivex.rxjava3.exceptions.UndeliverableException: 
  at io.reactivex.rxjava3.plugins.RxJavaPlugins.onError (RxJavaPlugins.java:367)
  at io.reactivex.rxjava3.internal.schedulers.NewThreadWorker.scheduleActual (NewThreadWorker.java:153)
  at io.reactivex.rxjava3.internal.schedulers.NewThreadWorker.schedule (NewThreadWorker.java:50)
  at io.reactivex.rxjava3.core.Scheduler$Worker$PeriodicTask.run (Scheduler.java:535)
  at io.reactivex.rxjava3.internal.schedulers.ScheduledRunnable.run (ScheduledRunnable.java:65)
  at io.reactivex.rxjava3.internal.schedulers.ScheduledRunnable.call (ScheduledRunnable.java:56)
  at java.util.concurrent.FutureTask.run (FutureTask.java:266)
  at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run (ScheduledThreadPoolExecutor.java:301)
  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:919)
Caused by: java.util.concurrent.RejectedExecutionException: 
  at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution (ThreadPoolExecutor.java:2086)
  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:579)
  at io.reactivex.rxjava3.internal.schedulers.NewThreadWorker.scheduleActual (NewThreadWorker.java:146)
Lineflyer commented 3 years ago

BTW: Was also already included in earlier releases as the try/catch change was done on release branch in October 2020.

Lineflyer commented 3 years ago

Still happening in release 2020.11.23:

io.reactivex.rxjava3.exceptions.UndeliverableException: 
  at io.reactivex.rxjava3.plugins.RxJavaPlugins.onError (RxJavaPlugins.java:367)
  at io.reactivex.rxjava3.internal.schedulers.NewThreadWorker.scheduleActual (NewThreadWorker.java:153)
  at io.reactivex.rxjava3.internal.schedulers.NewThreadWorker.schedule (NewThreadWorker.java:50)
  at io.reactivex.rxjava3.core.Scheduler$Worker$PeriodicTask.run (Scheduler.java:535)
  at io.reactivex.rxjava3.internal.schedulers.ScheduledRunnable.run (ScheduledRunnable.java:65)
  at io.reactivex.rxjava3.internal.schedulers.ScheduledRunnable.call (ScheduledRunnable.java:56)
  at java.util.concurrent.FutureTask.run (FutureTask.java:266)
  at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run (ScheduledThreadPoolExecutor.java:301)
  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:919)
Caused by: java.util.concurrent.RejectedExecutionException: 
  at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution (ThreadPoolExecutor.java:2086)
  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:579)
  at io.reactivex.rxjava3.internal.schedulers.NewThreadWorker.scheduleActual (NewThreadWorker.java:146)
eddiemuc commented 3 years ago

Looking into source, this might be a different problem. Apparently a ScheduledThreadPoolExecutorwas asked to perform a task after it was already shut down (look at line 333 directly before 334 in following source snippet of ScheduledThreadPookExecutorof Android SDK 29):

image

Lineflyer commented 3 years ago

Still happening in 2020.12.22-RC AFAICS

Lineflyer commented 3 years ago

Just to confirm: Still happening with 2021.01.10 and 2021.01.16

We have a real small bunch of crashed (so the release seems to be very good :)) ) so this is one of the last remaining long-time issues by now on Google Play Console.

Example for 2021.01.16:

io.reactivex.rxjava3.exceptions.UndeliverableException: 
  at io.reactivex.rxjava3.plugins.RxJavaPlugins.onError (RxJavaPlugins.java:367)
  at io.reactivex.rxjava3.internal.schedulers.NewThreadWorker.scheduleActual (NewThreadWorker.java:153)
  at io.reactivex.rxjava3.internal.schedulers.NewThreadWorker.schedule (NewThreadWorker.java:50)
  at io.reactivex.rxjava3.core.Scheduler$Worker$PeriodicTask.run (Scheduler.java:535)
  at io.reactivex.rxjava3.internal.schedulers.ScheduledRunnable.run (ScheduledRunnable.java:65)
  at io.reactivex.rxjava3.internal.schedulers.ScheduledRunnable.call (ScheduledRunnable.java:56)
  at java.util.concurrent.FutureTask.run (FutureTask.java:266)
  at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run (ScheduledThreadPoolExecutor.java:301)
  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:919)
Caused by: java.util.concurrent.RejectedExecutionException: 
  at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution (ThreadPoolExecutor.java:2086)
  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:579)
  at io.reactivex.rxjava3.internal.schedulers.NewThreadWorker.scheduleActual (NewThreadWorker.java:146)
Lineflyer commented 2 years ago

Google Play reports 99,4% of sessions without crash, but this is still happening on 2022.01.13 and 2022.01.16 as most prominent crash.

io.reactivex.rxjava3.exceptions.UndeliverableException: 
  at io.reactivex.rxjava3.plugins.RxJavaPlugins.onError (RxJavaPlugins.java:372)
  at io.reactivex.rxjava3.internal.schedulers.NewThreadWorker.scheduleActual (NewThreadWorker.java:151)
  at io.reactivex.rxjava3.internal.schedulers.NewThreadWorker.schedule (NewThreadWorker.java:50)
  at io.reactivex.rxjava3.core.Scheduler$Worker$PeriodicTask.run (Scheduler.java:565)
  at io.reactivex.rxjava3.internal.schedulers.ScheduledRunnable.run (ScheduledRunnable.java:65)
  at io.reactivex.rxjava3.internal.schedulers.ScheduledRunnable.call (ScheduledRunnable.java:56)
  at java.util.concurrent.FutureTask.run (FutureTask.java:266)
  at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run (ScheduledThreadPoolExecutor.java:301)
  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:919)
Caused by: java.util.concurrent.RejectedExecutionException: 
  at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution (ThreadPoolExecutor.java:2086)
  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:579)
  at io.reactivex.rxjava3.internal.schedulers.NewThreadWorker.scheduleActual (NewThreadWorker.java:144)
moving-bits commented 2 years ago

Found an article mentioning a possible solution to the RejectedExecutionException issue: re-queue the task as soon as there is a new slot available, see https://reflectoring.io/rxjava-reactive-batch-processing/ (This would be for the error case that we are sending too many tasks to a limited scheduler.) Maybe someone can make sense of this and try to implement it in c:geo, if useful?

On the other hand some of the error messages look like the thread pool being used is in a shutdown state, so that it has to reject the new task (see screenshots above). How can this happen - how/when are pools being created and destroyed?

moving-bits commented 2 years ago

I want to bring some attention back to this long-lasting error, as it is still the most prominent error for our new release 2022.06.06, with more than 50 occurrences in just a couple of days. It's being reported across several Android versions and different mobile models. Error log is still the same as mentioned above in @Lineflyer's report.

Lineflyer commented 1 year ago

Still happening with recent releases (e.g. 2022.11.13).

Error log for 2022.11.13:

Exception io.reactivex.rxjava3.exceptions.UndeliverableException:
  at io.reactivex.rxjava3.plugins.RxJavaPlugins.onError (RxJavaPlugins.java:372)
  at io.reactivex.rxjava3.internal.schedulers.NewThreadWorker.scheduleActual (NewThreadWorker.java:151)
  at io.reactivex.rxjava3.internal.schedulers.NewThreadWorker.schedule (NewThreadWorker.java:50)
  at io.reactivex.rxjava3.core.Scheduler$Worker$PeriodicTask.run (Scheduler.java:565)
  at io.reactivex.rxjava3.internal.schedulers.ScheduledRunnable.run (ScheduledRunnable.java:65)
  at io.reactivex.rxjava3.internal.schedulers.ScheduledRunnable.call (ScheduledRunnable.java:56)
  at java.util.concurrent.FutureTask.run (FutureTask.java:266)
  at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run (ScheduledThreadPoolExecutor.java:301)
  at java.util.concurrent.ThreadPoolExecutor.processTask (ThreadPoolExecutor.java:1187)
  at java.util.concurrent.ThreadPoolExecutor.runWorker (ThreadPoolExecutor.java:1152)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run (ThreadPoolExecutor.java:641)
  at java.lang.Thread.run (Thread.java:784)
Caused by java.util.concurrent.RejectedExecutionException:
  at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution (ThreadPoolExecutor.java:2104)
  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:579)
  at io.reactivex.rxjava3.internal.schedulers.NewThreadWorker.scheduleActual (NewThreadWorker.java:144)