search

ReactiveX / RxJava

RxJava – Reactive Extensions for the JVM – a library for composing asynchronous and event-based programs using observable sequences for the Java VM.
Apache License 2.0
47.91k stars 7.6k forks source link

Computation Scheduler gets interrupted thousands of times per second? #1913

Closed daschl closed 9 years ago

daschl commented 9 years ago

Hi folks,

I've been debugging the Couchbase Java SDK with the flight recorder a bit and something very odd came up. Even though nothing is in the logs, it looks like my computation scheduler is interrupted thousands of times per second.

screen shot 2014-12-01 at 15 43 43

screen shot 2014-12-01 at 15 44 38

Has anyone seen this before or an idea why that could be?

akarnokd commented 9 years ago

Did you run this against 1.0.1? In #1898 I finally eliminated the self-interrupt. (I knew about this since I wrote ScheduledAction half-a-year ago, but lacked idea of how to fix it :)

daschl commented 9 years ago

@akarnokd actually yes, this is against 1.0.1

Let me know what info I can get you to track this down? Looks like you got an initial handle on that already

akarnokd commented 9 years ago

My bet is that some code swings around and calls unsubscribe on the ScheduledAction from some other thread before run() completes.

daschl commented 9 years ago

@akarnokd any idea on how to debug this properly? I can dig in for sure but you maybe have some more pointers.

Btw, do you think this has a perf impact as well?

akarnokd commented 9 years ago

You can place a breakpoint on ScheduledAction L122 and see if it is triggered. Second option is to place a breakpoint on Thread.interrupt() to see who is calling; but without seeing what's going on in your system, the interrupt may come from somewhere else entirely. I'm not familiar with Flightrecorder but the mere observation of your system may trigger interrupts, wouldn't be surprised.

I measured ~10% throughput increase on simple tasks because self-interrupting triggers bookkeeping in the threadpool after the task's completion which takes up time from the next task.

daschl commented 9 years ago

This is with 1.0.2.

screen shot 2014-12-02 at 08 04 08

daschl commented 9 years ago

Thanks @benjchristensen and @akarnokd for shipping this so quickly. I'll ship the next patch release of the SDK with 1.0.2 this week.

akarnokd commented 9 years ago

Great. I though #1898 was shipped with 1.0.1.

daschl commented 9 years ago

@akarnokd looks like it didn't? Ben put it into 1.0.2 release log as well.

benjchristensen commented 9 years ago

Yes it was 1.0.2. That profiling result is a major improvement.