CompositeException Behavior

[benjchristensen]

There are possibly improvements that need to be made specific to Android related to CompositeException.

History of the discussion and work on this can be found at ReactiveX/RxJava#1405

[tomrozb]

I've moved to io.reactivex:rxandroid:0.23.0 and still see this issue. @mttkay have you found something?

[mttkay]

No. I was able to reproduce it and got stuck by the time Android was
starting to call into native code.

Any suggestions for how to even debug this welcome!
On Nov 21, 2014 4:12 PM, "Tomasz Rozbicki" notifications@github.com wrote:

I've moved to io.reactivex:rxandroid:0.23.0 and still see this issue.
@mttkay https://github.com/mttkay have you found something?

—
Reply to this email directly or view it on GitHub
#21 (comment).

[tomrozb]

Here's what I've got so far. Sometimes I can find in the crash reports stack trace like below:

16:13:01.654                         E  Caused by: rx.exceptions.CompositeException$CompositeExceptionCausalChain: Chain of Causes for CompositeException In Order Received =>
16:13:01.654                         E      at android.util.Log.getStackTraceString(Log.java:410)
16:13:01.654                         E      at android.util.Slog.e(Slog.java:151)
16:13:01.654                         E      at com.android.internal.os.RuntimeInit$UncaughtHandler.uncaughtException(RuntimeInit.java:85)
16:13:01.654                         E      at java.lang.ThreadGroup.uncaughtException(ThreadGroup.java:693)
16:13:01.654                         E      at java.lang.ThreadGroup.uncaughtException(ThreadGroup.java:690)
16:13:01.654                         E      at rx.internal.schedulers.ScheduledAction.run(ScheduledAction.java:56)
16:13:01.654                         E      ... 9 more
16:13:01.654                         E  Caused by: java.net.ConnectException: failed to connect to /192.168.2.10 (port 8080) after 20000ms: isConnected failed: ECONNREFUSED (Connection refuse
                                        d)
16:13:01.654                         E      at libcore.io.IoBridge.isConnected(IoBridge.java:223)
16:13:01.654                         E      at libcore.io.IoBridge.connectErrno(IoBridge.java:161)
16:13:01.654                         E      at libcore.io.IoBridge.connect(IoBridge.java:112)
...

The most interesting part is: android.util.Log.getStackTraceString(Log.java:410) Looks like this class has been modified by manufacturer, the original one in API21 has only 225 lines, but in fact we don't know if the method implementation is different or not.

Now a simple test, put this code in the onError callback (You can use whatever logging utility you want). The seconds method is from Guava.

UnknownHostException hostException = new UnknownHostException("test");
Timber.e("Log", Log.getStackTraceString(hostException));
Timber.e("Guava", Throwables.getStackTraceAsString(hostException));

And here's the output. Nothing is printed from android.util.Log.getStackTraceString method. I have only Samsung devices, could somebody test this on Nexus with KitKat or at least confirm this on another Samsung device? I've tested it on S4, S5 and Note 3 all with 4.4.2.

16:43:51.151              SomeClass  E  Log                                                                                                                                                    
16:43:51.181                         E  Guava java.net.UnknownHostException: test                                                                                                              
                                            ...                                                               
16:43:51.181                         E      at rx.Observable$33.onError(Observable.java:7307)                                                                                                  
16:43:51.181                         E      at rx.observers.SafeSubscriber._onError(SafeSubscriber.java:127)                                                                                   
16:43:51.181                         E      at rx.observers.SafeSubscriber.onError(SafeSubscriber.java:96)                                                                                     
16:43:51.181                         E      at rx.internal.operators.NotificationLite.accept(NotificationLite.java:147)                                                                        
16:43:51.181                         E      at rx.internal.operators.OperatorObserveOn$ObserveOnSubscriber.pollQueue(OperatorObserveOn.java:177)                                               
16:43:51.181                         E      at rx.internal.operators.OperatorObserveOn$ObserveOnSubscriber.access$000(OperatorObserveOn.java:65)                                               
16:43:51.181                         E      at rx.internal.operators.OperatorObserveOn$ObserveOnSubscriber$2.call(OperatorObserveOn.java:153)                                                  
16:43:51.181                         E      at rx.internal.schedulers.ScheduledAction.run(ScheduledAction.java:45)                                                                             
16:43:51.181                         E      at android.os.Handler.handleCallback(Handler.java:733)                                                                                             
16:43:51.181                         E      at android.os.Handler.dispatchMessage(Handler.java:95)                                                                                             
16:43:51.181                         E      at android.os.Looper.loop(Looper.java:136)                                                                                                         
16:43:51.181                         E      at android.app.ActivityThread.main(ActivityThread.java:5586)                                                                                       
16:43:51.181                         E      at java.lang.reflect.Method.invokeNative(Native Method)                                                                                            
16:43:51.181                         E      at java.lang.reflect.Method.invoke(Method.java:515)                                                                                                
16:43:51.181                         E      at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:1268)                                                                
16:43:51.181                         E      at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1084)                                                                                   
16:43:51.181                         E      at dalvik.system.NativeStart.main(Native Method)  

[gderaco]

The reason of the exception (in my case) is this line in SafeSubscriber.java line 174
throw new OnErrorFailedException("Error occurred when trying to propagate error to Observer.onError", new CompositeException(Arrays.asList(e, e2)));
It throws exception because e2 is null.
In my case, the Throwable I pass to onError() method is android.os.NetworkOnMainThreadException

I think a buffer solution would be checking if e2 is null.

I'm using rxandroid 0.23 and Android 5.0.1 x86 emulator. Hope this can help.

[JakeWharton]

UnknownHostException's trace is never logged, FYI, as you can see in the source of Log.java. Is there still an issue beyond that?

[malachid]

I was getting a similar error whenever I used RetrofitError.getBody inside RxJava Subscriber.onError. Turns out it was being caused by the getBody call itself throwing an exception. Since initCause, setStackTrace, readObject, and addSuppressed all internally throw exceptions - maybe it's related.

[farmazon3000]

I think this issue is mentioned here http://stackoverflow.com/questions/24860942/observer-onerror-firing-off-inconsistently.

[tomrozb]

@farmazon3000 you're right. I'm not sure it still happens in the latest version of Rx, can somebody confirm?

[farmazon3000]

I'm using

compile 'io.reactivex:rxjava:1.0.12'
compile 'io.reactivex:rxandroid:0.24.0'

and it does happen.

[dlew]

Those aren't the latest versions of RxJava and RxAndroid. The latest are:

compile 'io.reactivex:rxjava:1.0.14'
compile 'io.reactivex:rxandroid:1.0.1'

[lunf]

I am on the latest version

  E/AndroidRuntime: java.lang.IllegalStateException: Fatal Exception thrown on Scheduler.Worker thread.
  E/AndroidRuntime:     at rx.internal.schedulers.ScheduledAction.run(ScheduledAction.java:62)
  E/AndroidRuntime:     at android.os.Handler.handleCallback(Handler.java:733)
  E/AndroidRuntime:     at android.os.Handler.dispatchMessage(Handler.java:95)
  E/AndroidRuntime:     at android.os.Looper.loop(Looper.java:136)
  E/AndroidRuntime:     at android.app.ActivityThread.main(ActivityThread.java:5001)
  E/AndroidRuntime:     at java.lang.reflect.Method.invokeNative(Native Method)
  E/AndroidRuntime:     at java.lang.reflect.Method.invoke(Method.java:515)
  E/AndroidRuntime:     at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:785)
  E/AndroidRuntime:     at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:601)
  E/AndroidRuntime:     at dalvik.system.NativeStart.main(Native Method)
  E/AndroidRuntime:  Caused by: rx.exceptions.OnErrorFailedException: Error occurred when trying to propagate error to Observer.onError
  E/AndroidRuntime:     at rx.observers.SafeSubscriber._onError(SafeSubscriber.java:201)
  E/AndroidRuntime:     at rx.observers.SafeSubscriber.onError(SafeSubscriber.java:111)
  E/AndroidRuntime:     at rx.observers.SafeSubscriber.onNext(SafeSubscriber.java:137)
  E/AndroidRuntime:     at rx.internal.operators.OperatorObserveOn$ObserveOnSubscriber.pollQueue(OperatorObserveOn.java:208)
  E/AndroidRuntime:     at rx.internal.operators.OperatorObserveOn$ObserveOnSubscriber$2.call(OperatorObserveOn.java:170)
  E/AndroidRuntime:     at rx.internal.schedulers.ScheduledAction.run(ScheduledAction.java:55)
  E/AndroidRuntime:     at android.os.Handler.handleCallback(Handler.java:733) 
  E/AndroidRuntime:     at android.os.Handler.dispatchMessage(Handler.java:95) 
  E/AndroidRuntime:     at android.os.Looper.loop(Looper.java:136) 
  E/AndroidRuntime:     at android.app.ActivityThread.main(ActivityThread.java:5001) 
  E/AndroidRuntime:     at java.lang.reflect.Method.invokeNative(Native Method) 
  E/AndroidRuntime:     at java.lang.reflect.Method.invoke(Method.java:515) 
  E/AndroidRuntime:     at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:785) 
  E/AndroidRuntime:     at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:601) 
  E/AndroidRuntime:     at dalvik.system.NativeStart.main(Native Method) 
  E/AndroidRuntime:  Caused by: rx.exceptions.CompositeException: 2 exceptions occurred. 
  E/AndroidRuntime:     at rx.observers.SafeSubscriber._onError(SafeSubscriber.java:201) 
  E/AndroidRuntime:     at rx.observers.SafeSubscriber.onError(SafeSubscriber.java:111) 
  E/AndroidRuntime:     at rx.observers.SafeSubscriber.onNext(SafeSubscriber.java:137) 
  E/AndroidRuntime:     at rx.internal.operators.OperatorObserveOn$ObserveOnSubscriber.pollQueue(OperatorObserveOn.java:208) 
  E/AndroidRuntime:     at rx.internal.operators.OperatorObserveOn$ObserveOnSubscriber$2.call(OperatorObserveOn.java:170) 
  E/AndroidRuntime:     at rx.internal.schedulers.ScheduledAction.run(ScheduledAction.java:55) 
  E/AndroidRuntime:     at android.os.Handler.handleCallback(Handler.java:733) 
  E/AndroidRuntime:     at android.os.Handler.dispatchMessage(Handler.java:95) 
  E/AndroidRuntime:     at android.os.Looper.loop(Looper.java:136) 
  E/AndroidRuntime:     at android.app.ActivityThread.main(ActivityThread.java:5001) 
  E/AndroidRuntime:     at java.lang.reflect.Method.invokeNative(Native Method) 
  E/AndroidRuntime:     at java.lang.reflect.Method.invoke(Method.java:515) 
  E/AndroidRuntime:     at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:785) 
  E/AndroidRuntime:     at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:601) 
  E/AndroidRuntime:     at dalvik.system.NativeStart.main(Native Method) 
  E/AndroidRuntime:  Caused by: rx.exceptions.CompositeException$CompositeExceptionCausalChain: Chain of Causes for CompositeException In Order Received =>
  E/AndroidRuntime:     at crittercism.android.bk.a(Unknown Source)
  E/AndroidRuntime:     at crittercism.android.bk.<init>(Unknown Source)
  E/AndroidRuntime:     at crittercism.android.az.a(Unknown Source)
  E/AndroidRuntime:     at crittercism.android.ay.uncaughtException(Unknown Source)```

[dimsuz]

Looks like it has nothing to do with RxAndroid. Your app's code threw an exception (most likely in your onError handler):

E/AndroidRuntime:     at crittercism.android.bk.a(Unknown Source)
E/AndroidRuntime:     at crittercism.android.bk.<init>(Unknown Source)
E/AndroidRuntime:     at crittercism.android.az.a(Unknown Source)
E/AndroidRuntime:     at crittercism.android.ay.uncaughtException(Unknown Source)

[malachid]

I just got it again (this time because I had a TextInputLayout without a child EditText) - but at least I knew what to look for. It would be nice if my own code showed up in the stack trace somewhere. Without that it turns out to be much harder to track down.

Key though - it's always because your onError is calling something that is throwing an error of some kind (may be runtime, error, etc - not necessarily a compile time exception).