1.x: Change the workers to capture the stack trace #3937

abersnaze · 2016-05-13T17:49:01Z

Watched @dlew presentation of the pit falls of debugging RxJava https://www.youtube.com/watch?v=QdmkXL7XikQ&feature=youtu.be&t=38m12s

This change is to create an exception when a thread based Scheduler.Worker is constructed and reused it for all subsequent scheduled actions to increase the readability of uncaught and fatal exceptions that bubble up to the schedulers but spread the cost out across many scheduled actions.

A future improvement to spread the cost out even more, that I didn't want to do in the first attempt, would to create the exception when Scheduler.io() is called and reuse the exception across multiple Workers.

The example from the presentation

import rx.Observable;
import rx.schedulers.Schedulers;

public class Main {
    public static void main(String[] args) throws InterruptedException {
        Observable.empty()
                .first()
                .subscribeOn(Schedulers.io())
                .subscribe();

        Thread.sleep(100);
    }
}

Used to print this just this exception with no mention the Main class.

Exception in thread "RxIoScheduler-2" java.lang.IllegalStateException: Exception thrown on Scheduler.Worker thread. Add `onError` handling.
    at rx.internal.schedulers.ScheduledAction.run(ScheduledAction.java:65)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)
Caused by: rx.exceptions.OnErrorNotImplementedException: Sequence contains no elements
    at rx.internal.util.InternalObservableUtils$ErrorNotImplementedAction.call(InternalObservableUtils.java:374)
    at rx.internal.util.InternalObservableUtils$ErrorNotImplementedAction.call(InternalObservableUtils.java:1)
    at rx.internal.util.ActionSubscriber.onError(ActionSubscriber.java:44)
    at rx.observers.SafeSubscriber._onError(SafeSubscriber.java:157)
    at rx.observers.SafeSubscriber.onError(SafeSubscriber.java:120)
    at rx.internal.operators.OperatorSubscribeOn$1$1.onError(OperatorSubscribeOn.java:59)
    at rx.internal.operators.OperatorSingle$ParentSubscriber.onCompleted(OperatorSingle.java:116)
    at rx.internal.operators.OperatorTake$1.onCompleted(OperatorTake.java:56)
    at rx.internal.operators.EmptyObservableHolder.call(EmptyObservableHolder.java:44)
    at rx.internal.operators.EmptyObservableHolder.call(EmptyObservableHolder.java:1)
    at rx.internal.operators.OnSubscribeLift.call(OnSubscribeLift.java:50)
    at rx.internal.operators.OnSubscribeLift.call(OnSubscribeLift.java:1)
    at rx.internal.operators.OnSubscribeLift.call(OnSubscribeLift.java:50)
    at rx.internal.operators.OnSubscribeLift.call(OnSubscribeLift.java:1)
    at rx.Observable.unsafeSubscribe(Observable.java:8460)
    at rx.internal.operators.OperatorSubscribeOn$1.call(OperatorSubscribeOn.java:94)
    at rx.internal.schedulers.CachedThreadScheduler$EventLoopWorker$1.call(CachedThreadScheduler.java:222)
    at rx.internal.schedulers.ScheduledAction.run(ScheduledAction.java:60)
    ... 7 more
Caused by: java.util.NoSuchElementException: Sequence contains no elements
    ... 19 more

But will now print the exception above but with an additional caused by

Caused by: rx.internal.schedulers.SchedulerContextException: Asynchronous work scheduled at
    at rx.internal.schedulers.NewThreadWorker.<init>(NewThreadWorker.java:36)
    at rx.internal.schedulers.CachedThreadScheduler$ThreadWorker.<init>(CachedThreadScheduler.java:235)
    at rx.internal.schedulers.CachedThreadScheduler$CachedWorkerPool.get(CachedThreadScheduler.java:86)
    at rx.internal.schedulers.CachedThreadScheduler$EventLoopWorker.<init>(CachedThreadScheduler.java:187)
    at rx.internal.schedulers.CachedThreadScheduler.createWorker(CachedThreadScheduler.java:173)
    at rx.internal.operators.OperatorSubscribeOn.call(OperatorSubscribeOn.java:42)
    at rx.internal.operators.OperatorSubscribeOn.call(OperatorSubscribeOn.java:1)
    at rx.Observable.subscribe(Observable.java:8553)
    at rx.Observable.subscribe(Observable.java:8520)
    at rx.Observable.subscribe(Observable.java:8316)
    at rx.schedulers.Main.main(Main.java:10)

akarnokd · 2016-05-13T18:04:15Z

No. At least make it conditional to a system parameter / global boolean variable.

stealthcode · 2016-05-13T18:27:13Z

👍 as is. The cost is very low and the benefit is very high.

abersnaze · 2016-05-13T18:41:01Z

@akarnokd added a system property to make if off by default.

stealthcode · 2016-05-13T18:42:09Z

I would like this to be default behavior. Learning Rx is hard and we are making it harder by default. Let users opt into over-optimizations.

akarnokd · 2016-05-13T18:43:15Z

src/main/java/rx/internal/schedulers/SchedulerContextException.java

+ */
+public class SchedulerContextException extends Exception {
+    public static Throwable create() {
+        if (System.getProperty("rxjava.captureSchedulerContext", "false").equals("true")) {


Better. Do you want this to be changeable at runtime?

Yes. When things go wrong it can be helpful to be able to enable more logging without having to restart the VM.

Okay, in that case, I'd consider a public static AtomicBoolean instead of the hash-lookup and string comparison. From security perspective, if you can set System properties, you could just as set an AtomicBoolean, right?

Probably just a static volatile boolean, right? Atomicity isn't needed
since it's only read by RxJava and only written by application code.

On Fri, May 13, 2016, 11:58 AM David Karnok notifications@github.com
wrote:

In src/main/java/rx/internal/schedulers/SchedulerContextException.java
#3937 (comment):

* http://www.apache.org/licenses/LICENSE-2.0

* Unless required by applicable law or agreed to in writing, software

* distributed under the License is distributed on an "AS IS" BASIS,

* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.

* See the License for the specific language governing permissions and

* limitations under the License.

/
+package rx.internal.schedulers;
+
+/*

* Used only for providing context around where work was scheduled should an error occur in a different thread.

*/
+public class SchedulerContextException extends Exception {

public static Throwable create() {

if (System.getProperty("rxjava.captureSchedulerContext", "false").equals("true")) {

Okay, in that case, I'd consider a public static AtomicBoolean instead of
the hash-lookup and string comparison. From security perspective, if you
can set System properties, you could just as set an AtomicBoolean, right?

—
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub
https://github.com/ReactiveX/RxJava/pull/3937/files/9630081dc8ef75edad8dc397a661cf61d4ee57fd#r63234396

anything else @JakeWharton @akarnokd?

akarnokd · 2016-05-13T21:55:29Z

You have a lot of test failures.

JakeWharton · 2016-05-13T21:58:42Z

src/main/java/rx/internal/schedulers/SchedulerContextException.java

+     * Immediately change the behavior to of the {@link SchedulerContextException#create()} method.
+     * @param captureSchedulerContext
+     */
+    public static void setCaptureSchedulerContext(boolean captureSchedulerContext) {


Is this meant to be public API for applications to use? Because it's currently in an internal package.

It wasn't an API until it was changed to volatile boolean and was just always reading from System.getProperty().

This seems unnecessary to me. System#getProperty checks the security manager. If the security manager throws an exception then the boolean is set to false (making it impossible to set to true).

I would rather we just read from a property always. Why wouldn't we do this?

robertroeser · 2016-05-13T22:09:07Z

RXJava is hard to debug - lots of people agree on this. I know of large non-trivial projects that avoided using RXJava because it hard to debug. Non-trivial projects do I/O, and serialization - those are the performance problems, not micro-optimizations. Users will care more about it being easier to debug than being micro-optimized. This should be default to make it less hard.

abersnaze · 2016-05-13T23:25:45Z

I've changed it back to always getting the value from the system properties because makes a fine public API and it makes the tests work again. I've added some code to mitigate the overhead of doing the check multiple times.

akarnokd · 2016-05-14T06:43:27Z

Still failing...

abersnaze · 2016-05-16T21:35:27Z

Found it the test worked if run in isolation but failed if they were run en masse because of caching. Added pooled work resets in two places seems to fix the issue.

akarnokd · 2016-05-16T22:20:46Z

src/test/java/rx/schedulers/AbstractSchedulerTests.java

+            });
+
+            try {
+                getScheduler().createWorker().schedule(new Action0() {


This leaks the worker.

…duled actions to increase the readability of uncaught and fatal exceptions that bubble up to the schedulers.

akarnokd · 2016-06-20T05:46:03Z

I want to increase debug support in RxJava, but I'd think, based on the feedback on #3965, that such capture is not enough.

I suggest closing this PR, unless you can spend some time with it before 1.1.7. Also I'd like your feedback on #4007. It's tracking grabs the stacktrace for observeOn as well (the triggerer of the Scheduled actions) and should help with non-fatal crashes over async boundaries.

A more elaborate solution would be that in case of a crash, the operator graph could be walked and dumped in a consumable format. Unfortunately, to support this, the Subscriber class has to be extended with methods to peek into the upstream and all operators have to set a Producer on their child subscribers to have the bidirectional link for the graph. Since Subscriber is public API, adding methods to it may not be a compatible change. For 2.x, there is no problem.

akarnokd · 2016-06-22T13:34:53Z

I'm closing this for now due to test failures and merge conflicts.

In addition, I suggest extending #4007, once merged, by adding Scheduler wrappers - similar to the OnAssembly wrappers, via the hooks to capture and signal the stacks.

If you have further input on the issue, don't hesitate to reopen this issue or post a new one.

akarnokd reviewed May 13, 2016
View reviewed changes

abersnaze force-pushed the stacks branch 2 times, most recently from 359ef10 to e277814 Compare May 13, 2016 21:39

akarnokd added the Enhancement label May 13, 2016

JakeWharton reviewed May 13, 2016
View reviewed changes

abersnaze force-pushed the stacks branch from e277814 to 7c69cb3 Compare May 13, 2016 23:22

abersnaze force-pushed the stacks branch from 7c69cb3 to 671eba5 Compare May 16, 2016 21:32

akarnokd reviewed May 16, 2016
View reviewed changes

akarnokd mentioned this pull request May 25, 2016

1.x: add optional tracking of worker creation sites + report it on error #3965

Closed

abersnaze force-pushed the stacks branch from 671eba5 to 9c758a0 Compare June 1, 2016 20:59

Change the workers to capture the stack trace for all subsequent sche…

c6ada18

…duled actions to increase the readability of uncaught and fatal exceptions that bubble up to the schedulers.

abersnaze force-pushed the stacks branch from 9c758a0 to c6ada18 Compare June 1, 2016 22:13

JakeWharton mentioned this pull request Jun 17, 2016

Proposal: Move the checks for missing onError() higher on the chain #4022

Closed

akarnokd changed the title ~~Change the workers to capture the stack trace~~ 1.x: Change the workers to capture the stack trace Jun 19, 2016

akarnokd closed this Jun 22, 2016

abersnaze deleted the stacks branch September 20, 2016 21:13

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

1.x: Change the workers to capture the stack trace #3937

1.x: Change the workers to capture the stack trace #3937

abersnaze commented May 13, 2016

akarnokd commented May 13, 2016

stealthcode commented May 13, 2016

abersnaze commented May 13, 2016

stealthcode commented May 13, 2016

akarnokd May 13, 2016

abersnaze May 13, 2016

akarnokd May 13, 2016

JakeWharton May 13, 2016

abersnaze May 13, 2016

akarnokd commented May 13, 2016

JakeWharton May 13, 2016

abersnaze May 13, 2016

stealthcode May 13, 2016

robertroeser commented May 13, 2016 •

edited

Loading

abersnaze commented May 13, 2016

akarnokd commented May 14, 2016

abersnaze commented May 16, 2016

akarnokd May 16, 2016

akarnokd commented Jun 20, 2016

akarnokd commented Jun 22, 2016

1.x: Change the workers to capture the stack trace #3937

1.x: Change the workers to capture the stack trace #3937

Conversation

abersnaze commented May 13, 2016

akarnokd commented May 13, 2016

stealthcode commented May 13, 2016

abersnaze commented May 13, 2016

stealthcode commented May 13, 2016

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

akarnokd commented May 13, 2016

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

robertroeser commented May 13, 2016 • edited Loading

abersnaze commented May 13, 2016

akarnokd commented May 14, 2016

abersnaze commented May 16, 2016

Choose a reason for hiding this comment

akarnokd commented Jun 20, 2016

akarnokd commented Jun 22, 2016

robertroeser commented May 13, 2016 •

edited

Loading