Skip to content
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

OnError while emitting onNext value: object.toString #1401

Merged
merged 3 commits into from Jul 7, 2014

Conversation

samhendley
Copy link

  public OnNextValue(Object value) {
        super("OnError while emitting onNext value: " + value);
        this.value = value;
    }

I know this is probably a helpful error message in some cases but this can be a really costly operation when an objects toString is an expensive call or contains alot of output. I don't think we should be printing this in any case but if so it should be on demand (overload of getMessage()) rather than eagerly.

In my case it is causing a toString of a large context object that is normally only used for debugging purposes which makes the exception logs hard to use and they are rolling over the log files very quickly.

There is an added danger that if there is a bug in the toString method it will cause inconsistent exception creation. If the object throws an exception while rendering a string it will actually end up not seeing the real exception.

@samhendley
Copy link
Author

Forgot to include the results of the test:

Here is the expected error:

On Error: java.lang.IllegalArgumentException: Failure while handling
    at rx.exceptions.OnNextValueTest$1.call(OnNextValueTest.java:87)
    at rx.exceptions.OnNextValueTest$1.call(OnNextValueTest.java:84)
    at rx.internal.operators.OperatorMap$1.onNext(OperatorMap.java:54)
    at rx.Observable$3.call(Observable.java:1551)
    at rx.Observable$3.call(Observable.java:1546)
    at rx.Observable$2.call(Observable.java:159)
    at rx.Observable$2.call(Observable.java:155)
    at rx.Observable.subscribe(Observable.java:6921)
    at rx.Observable.subscribe(Observable.java:6800)
    at rx.exceptions.OnNextValueTest.addOnNextValueExceptionAdded(OnNextValueTest.java:83)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:45)
    at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
    at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:42)
    at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)
    at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:263)
    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:68)
    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:47)
    at org.junit.runners.ParentRunner$3.run(ParentRunner.java:231)
    at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:60)
    at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:229)
    at org.junit.runners.ParentRunner.access$000(ParentRunner.java:50)
    at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:222)
    at org.junit.runners.ParentRunner.run(ParentRunner.java:300)
    at org.junit.runner.JUnitCore.run(JUnitCore.java:157)
    at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:74)
    at com.intellij.rt.execution.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:211)
    at com.intellij.rt.execution.junit.JUnitStarter.main(JUnitStarter.java:67)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at com.intellij.rt.execution.application.AppMain.main(AppMain.java:134)
Caused by: rx.exceptions.OnErrorThrowable$OnNextValue: OnError while emitting onNext value: BadToString
    at rx.exceptions.OnErrorThrowable.addValueAsLastCause(OnErrorThrowable.java:98)
    at rx.internal.operators.OperatorMap$1.onNext(OperatorMap.java:56)
    ... 33 more

Heres what we get with an exception in toString

On Error: java.lang.IllegalArgumentException: Error Making toString
    at rx.exceptions.OnNextValueTest$BadToString.toString(OnNextValueTest.java:39)
    at java.lang.String.valueOf(String.java:2854)
    at java.lang.StringBuilder.append(StringBuilder.java:128)
    at rx.exceptions.OnErrorThrowable$OnNextValue.<init>(OnErrorThrowable.java:119)
    at rx.exceptions.OnErrorThrowable.addValueAsLastCause(OnErrorThrowable.java:98)
    at rx.internal.operators.OperatorMap$1.onNext(OperatorMap.java:56)
    at rx.Observable$3.call(Observable.java:1551)
    at rx.Observable$3.call(Observable.java:1546)
    at rx.Observable$2.call(Observable.java:159)
    at rx.Observable$2.call(Observable.java:155)
    at rx.Observable.subscribe(Observable.java:6921)
    at rx.Observable.subscribe(Observable.java:6800)
    at rx.exceptions.OnNextValueTest.addOnNextValueExceptionNotAddedWithBadString(OnNextValueTest.java:97)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:45)
    at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
    at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:42)
    at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)
    at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:263)
    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:68)
    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:47)
    at org.junit.runners.ParentRunner$3.run(ParentRunner.java:231)
    at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:60)
    at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:229)
    at org.junit.runners.ParentRunner.access$000(ParentRunner.java:50)
    at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:222)
    at org.junit.runners.ParentRunner.run(ParentRunner.java:300)
    at org.junit.runner.JUnitCore.run(JUnitCore.java:157)
    at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:74)
    at com.intellij.rt.execution.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:211)
    at com.intellij.rt.execution.junit.JUnitStarter.main(JUnitStarter.java:67)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at com.intellij.rt.execution.application.AppMain.main(AppMain.java:134)

And a system,err output of

rx.exceptions.CompositeException: 2 exceptions occurred. See them in causal chain below.
    at rx.observers.SafeSubscriber._onError(SafeSubscriber.java:182)
    at rx.observers.SafeSubscriber.onError(SafeSubscriber.java:103)
    at rx.Observable$2.call(Observable.java:167)
    at rx.Observable$2.call(Observable.java:155)
    at rx.Observable.subscribe(Observable.java:6921)
    at rx.Observable.subscribe(Observable.java:6800)
    at rx.exceptions.OnNextValueTest.addOnNextValueExceptionNotAddedWithBadString(OnNextValueTest.java:97)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:45)
    at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
    at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:42)
    at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)
    at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:263)
    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:68)
    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:47)
    at org.junit.runners.ParentRunner$3.run(ParentRunner.java:231)
    at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:60)
    at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:229)
    at org.junit.runners.ParentRunner.access$000(ParentRunner.java:50)
    at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:222)
    at org.junit.runners.ParentRunner.run(ParentRunner.java:300)
    at org.junit.runner.JUnitCore.run(JUnitCore.java:157)
    at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:74)
    at com.intellij.rt.execution.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:211)
    at com.intellij.rt.execution.junit.JUnitStarter.main(JUnitStarter.java:67)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at com.intellij.rt.execution.application.AppMain.main(AppMain.java:134)
  ComposedException 1 :
    java.lang.IllegalArgumentException: Error Making toString
        at rx.exceptions.OnNextValueTest$BadToString.toString(OnNextValueTest.java:39)
        at java.lang.String.valueOf(String.java:2854)
        at java.lang.StringBuilder.append(StringBuilder.java:128)
        at rx.exceptions.OnErrorThrowable$OnNextValue.<init>(OnErrorThrowable.java:119)
        at rx.exceptions.OnErrorThrowable.addValueAsLastCause(OnErrorThrowable.java:98)
        at rx.internal.operators.OperatorMap$1.onNext(OperatorMap.java:56)
        at rx.Observable$3.call(Observable.java:1551)
        at rx.Observable$3.call(Observable.java:1546)
        at rx.Observable$2.call(Observable.java:159)
        at rx.Observable$2.call(Observable.java:155)
        at rx.Observable.subscribe(Observable.java:6921)
        at rx.Observable.subscribe(Observable.java:6800)
        at rx.exceptions.OnNextValueTest.addOnNextValueExceptionNotAddedWithBadString(OnNextValueTest.java:97)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:45)
        at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
        at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:42)
        at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)
        at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:263)
        at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:68)
        at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:47)
        at org.junit.runners.ParentRunner$3.run(ParentRunner.java:231)
        at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:60)
        at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:229)
        at org.junit.runners.ParentRunner.access$000(ParentRunner.java:50)
        at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:222)
        at org.junit.runners.ParentRunner.run(ParentRunner.java:300)
        at org.junit.runner.JUnitCore.run(JUnitCore.java:157)
        at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:74)
        at com.intellij.rt.execution.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:211)
        at com.intellij.rt.execution.junit.JUnitStarter.main(JUnitStarter.java:67)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at com.intellij.rt.execution.application.AppMain.main(AppMain.java:134)
  ComposedException 2 :
    java.lang.AssertionError: No Cause on throwablejava.lang.IllegalArgumentException: Error Making toString
        at org.junit.Assert.fail(Assert.java:93)
        at org.junit.Assert.assertTrue(Assert.java:43)
        at rx.exceptions.OnNextValueTest$BadToStringObserver.onError(OnNextValueTest.java:60)
        at rx.Observable$29.onError(Observable.java:6809)
        at rx.observers.SafeSubscriber._onError(SafeSubscriber.java:135)
        at rx.observers.SafeSubscriber.onError(SafeSubscriber.java:103)
        at rx.Observable$2.call(Observable.java:167)
        at rx.Observable$2.call(Observable.java:155)
        at rx.Observable.subscribe(Observable.java:6921)
        at rx.Observable.subscribe(Observable.java:6800)
        at rx.exceptions.OnNextValueTest.addOnNextValueExceptionNotAddedWithBadString(OnNextValueTest.java:97)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:45)
        at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
        at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:42)
        at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)
        at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:263)
        at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:68)
        at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:47)
        at org.junit.runners.ParentRunner$3.run(ParentRunner.java:231)
        at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:60)
        at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:229)
        at org.junit.runners.ParentRunner.access$000(ParentRunner.java:50)
        at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:222)
        at org.junit.runners.ParentRunner.run(ParentRunner.java:300)
        at org.junit.runner.JUnitCore.run(JUnitCore.java:157)
        at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:74)
        at com.intellij.rt.execution.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:211)
        at com.intellij.rt.execution.junit.JUnitStarter.main(JUnitStarter.java:67)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
        at com.intellij.rt.execution.application.AppMain.main(AppMain.java:134)

@cloudbees-pull-request-builder

RxJava-pull-requests #1349 SUCCESS
This pull request looks good

@benjchristensen
Copy link
Member

This rather defeats the point of OnErrorThrowable ... which exists to help debugging.

What change do you recommend that doesn't defeat the current purpose of OnErrorThrowable that allows someone to know what value caused the error?

@samhendley
Copy link
Author

The exception can still contain the value, it just shouldn't be eagerly toStringed into the base exception message. If the user code wants to handle those exceptions and print out the related object they are free to do so.

In any case It is only sometimes helpful to know what value is being processed when a request failed. What if the cause of the failure is a downed connection to an external service or a cache being disconnected, something unrelated to the data being processed. It doesn't matter what value caused the error, any value would have failed and seeing this in the log may cause people to assume it was related to this specific value.

try{
  // processing
}catch(Exception e){
   logger.log("Exception in processing: ", e);
   if(e.getCause() instanceOf OnNextValue){
      logger.log("Value that was being processed when it failed: ", ((OnNextValue)e.getCause()).getValue);       
    }
}

@benjchristensen
Copy link
Member

In any case It is only sometimes helpful to know what value is being processed when a request failed.

Obviously, but it's very valuable when it is indeed related to the value.

How about we include the toString value if it is a primitive type (Number, String, Boolean), otherwise just retain the object reference inside the OnErrorThrowable?

@samhendley
Copy link
Author

I think that is a good idea, we can also print out the classname of unknown objects. How about this?

/**
 * Render the object if it is a basic type. This avoids the library making potentially expensive
 * or calls to toString() which may throw exceptions. See PR #1401 for details.
 *
 * @param value
 *        the item that the Observable was trying to emit at the time of the exception
 * @return a string version of the object if primitive, otherwise the classname of the object
 */
private static String renderValue(Object value){
    if(value == null){
        return "null";
    }
    if(value.getClass().isPrimitive()){
        return value.toString();
    }
    if(value instanceof String){
        return (String)value;
    }
    return value.getClass().getSimpleName() + ".class;
}

I played with the wording a bit to try to make it obvious this is a class name of the instance, not the Class itself but everything I thought of might be misinterpreted.

Caused by: rx.exceptions.OnErrorThrowable$OnNextValue: OnError while emitting onNext value: BadToString.class
    at rx.exceptions.OnErrorThrowable.addValueAsLastCause(OnErrorThrowable.java:98)

@cloudbees-pull-request-builder

RxJava-pull-requests #1352 SUCCESS
This pull request looks good

@benjchristensen
Copy link
Member

I like it. Merging. Thanks @samhendley

benjchristensen added a commit that referenced this pull request Jul 7, 2014
OnError while emitting onNext value: object.toString
@benjchristensen benjchristensen merged commit 8bf8102 into ReactiveX:master Jul 7, 2014
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

3 participants