Crashing setUpNotification IllegalStateException

[hosshan]

Summary

after connecting to a device then enabling the notifications #### Preconditions
BLE ON #### Steps to reproduce actual result 1. Connect device 2. Setup notification #### Actual result

FATAL EXCEPTION: RxNewThreadScheduler-2339
Process: jp.co.qoled.furost, PID: 13127
java.lang.IllegalStateException: Fatal Exception thrown on Scheduler.Worker thread.
    at rx.internal.schedulers.ScheduledAction.run(ScheduledAction.java:62)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:423)
    at java.util.concurrent.FutureTask.run(FutureTask.java:237)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:269)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1113)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:588)
    at java.lang.Thread.run(Thread.java:818)
 Caused by: java.util.concurrent.RejectedExecutionException: Task java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@6260155 rejected from java.util.concurrent.ScheduledThreadPoolExecutor@91c340c[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 1]
    at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2014)
    at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:794)
    at java.util.concurrent.ScheduledThreadPoolExecutor.delayedExecute(ScheduledThreadPoolExecutor.java:302)
    at java.util.concurrent.ScheduledThreadPoolExecutor.schedule(ScheduledThreadPoolExecutor.java:527)
    at java.util.concurrent.ScheduledThreadPoolExecutor.submit(ScheduledThreadPoolExecutor.java:626)
    at rx.internal.schedulers.NewThreadWorker.scheduleActual(NewThreadWorker.java:239)
    at rx.internal.schedulers.NewThreadWorker.schedule(NewThreadWorker.java:224)
    at rx.internal.schedulers.NewThreadWorker.schedule(NewThreadWorker.java:216)
    at rx.internal.operators.OperatorSubscribeOn$1$1$1.request(OperatorSubscribeOn.java:82)
    at rx.Subscriber.request(Subscriber.java:157)
    at rx.internal.operators.OperatorObserveOn$ObserveOnSubscriber.call(OperatorObserveOn.java:225)
    at rx.internal.schedulers.ScheduledAction.run(ScheduledAction.java:55)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:423) 
    at java.util.concurrent.FutureTask.run(FutureTask.java:237) 
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:269) 
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1113) 
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:588) 
    at java.lang.Thread.run(Thread.java:818) 

Expected result

Crashing app.

[dariuszseweryn]

Hello there,

I have a few questions:

1. is the issue reproducible?
2. what device do you use?
3. could you show the code snippet you execute?

Best Regards

[hosshan]

i sure

1. yes. i communicate notificating device rate 90ms.
2. Nexus6 and Sony SO-04F
3. reproducing sample program when setup notification and leave few minute.

connectionObservable
                    .flatMap(rxBleConnection -> rxBleConnection.setupNotification(characteristicUuid))
                    .doOnNext(notificationObservable -> runOnUiThread(this::notificationHasBeenSetUp))
                    .flatMap(notificationObservable -> notificationObservable)
                    .observeOn(AndroidSchedulers.mainThread())
                    .subscribe(this::onNotificationReceived, this::onNotificationSetupFailure);

[dariuszseweryn]

Finally I had some time to dig up your situation. I have checked Google for the java.util.concurrent.RejectedExecutionException and found this article: https://examples.javacodegeeks.com/core-java/util/concurrent/rejectedexecutionexception/java-util-concurrent-rejectedexecutionexception-how-to-solve-rejectedexecutionexception/

As I don't see in the stacktrace any indication that the exception is being thrown anywhere in the library itself I suppose that there is some problem with too many things happening on the Android main thread. Have you checked what would happen if you replaced yours runOnUiThread(this::notificationHasBeenSetUp) and this::onNotificationReceived, this::onNotificationSetupFailure with simple Log.d() statements?

[Stjerndal]

I'm getting the same problem. This is how i setup notifications.

getConnectionObservable()
    .flatMap(rxBleConnection -> rxBleConnection.setupNotification(UUID_DATA_CHARA))
    //.doOnNext(notificationObservable -> getRxAppCompatActivity().runOnUiThread(this::notificationHasBeenSetUp))
    .doOnNext(notificationObservable -> notificationHasBeenSetUp())
    .flatMap(notificationObservable -> notificationObservable)
    .observeOn(AndroidSchedulers.mainThread())
    .subscribe(this::onNotificationReceived, this::onNotificationSetupFailure);

My app has a set of devices and every 30 seconds, it connects to them, writes to a characteristic and subscribes to notifications. When a notification is received shortly after, the app disconnects from the device and waits another 30 seconds.

This can go on for several minutes, but sooner or later i get the RejectedExecutionException.

FATAL EXCEPTION: RxNewThreadScheduler-143
Process: m.application, PID: 12147
java.lang.IllegalStateException: Fatal Exception thrown on Scheduler.Worker thread.
    at rx.internal.schedulers.ScheduledAction.run(ScheduledAction.java:62)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:423)
    at java.util.concurrent.FutureTask.run(FutureTask.java:237)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:154)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:269)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1113)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:588)
    at java.lang.Thread.run(Thread.java:818)
Caused by: java.util.concurrent.RejectedExecutionException: Task java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask@384aea9 rejected from java.util.concurrent.ScheduledThreadPoolExecutor@246b230[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 1]
    at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2014)
    at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:794)
    at java.util.concurrent.ScheduledThreadPoolExecutor.delayedExecute(ScheduledThreadPoolExecutor.java:302)
    at java.util.concurrent.ScheduledThreadPoolExecutor.schedule(ScheduledThreadPoolExecutor.java:527)
    at java.util.concurrent.ScheduledThreadPoolExecutor.submit(ScheduledThreadPoolExecutor.java:626)
    at rx.internal.schedulers.NewThreadWorker.scheduleActual(NewThreadWorker.java:239)
    at rx.internal.schedulers.NewThreadWorker.schedule(NewThreadWorker.java:224)
    at rx.internal.schedulers.NewThreadWorker.schedule(NewThreadWorker.java:216)
    at rx.internal.operators.OperatorSubscribeOn$1$1$1.request(OperatorSubscribeOn.java:82)
    at rx.Subscriber.request(Subscriber.java:157)
    at rx.internal.operators.OperatorObserveOn$ObserveOnSubscriber.call(OperatorObserveOn.java:225)
    at rx.internal.schedulers.ScheduledAction.run(ScheduledAction.java:55)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:423) 
    at java.util.concurrent.FutureTask.run(FutureTask.java:237) 
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:154) 
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:269) 
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1113) 
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:588) 
    at java.lang.Thread.run(Thread.java:818) `

Are you suggesting that I should try disconnecting straight after setting up notifications, and not executing anything else after the setup (this::notificationHasBeenSetUp, onNotificationReceived, onNotificationSetupFailure?

[dariuszseweryn]

I might have an idea what is the problem. in RxBleCallback the callbackScheduler is a Schedulers.newThread(). Changing it to Schedulers.computation() may solve the problem.

@Stjerndal Do you work with the sources or do you use maven to get the dependency?

[Stjerndal]

Maven, but could potentially try to use the source with that change within the next few days.

[dariuszseweryn]

@Stjerndal @Reyurnible
I have changed the Scheduler in RxBleCallback to Schedulers.computation() - this should fix the problem. The fix is in the current SNAPSHOT release. Could you take a look?

compile "com.polidea.rxandroidble:rxandroidble:1.1.0-SNAPSHOT"

[Stjerndal]

Awesome, I will check it out!

[dariuszseweryn]

Please give a feedback here so we will know what's the status.

[Stjerndal]

Results are promising! The error has not occurred yet, and I've had the application running for a couple of hours as of now. This was however sometimes possible before the fix, where the app would occasionally be able to run an hour or two before crashing.

I will keep it running during the day and report back.

[Stjerndal]

The issue seems to be resolved. I've been able to have it running for many hours without it occurring. Thanks, really appreciate it!

I did however run into another problem. The app did not crash or throw exceptions after that many hours, but suddenly it was just unable to connect to the BLE devices at all, instantly giving the GATT status 133 when attempting. I tried to connect to the same BLE devices with another Android device, and was successful. Only after a reboot of the first Android device, it could connect to the BLE devices again. A restart of the bluetooth adapter did not suffice.

I have not have the time to investigate this new issue properly, it might not even be RxAndroidBle that causes it. I just thought I'd mention it in case you have heard of something like this before. I will come back and maybe create a new Issue once I've studied the problem a bit more.

PS.
Running Android 6.0.1.

[dariuszseweryn]

Glad to help. It will be officially available in 1.0.3 release.

That's a known bug. In my opinion it's related to the wobbly Android BLE Stack - sometimes it happened to me if the gatt connections weren't disposed properly but it shouldn't be a problem now. If you will have any ideas - feel free to create an issue.

If you encounter this situation next time you can try switching off BT and Wifi then switching them on as BT and Wifi stacks on Android are partially shared.

Best Regards