observeOn() / subscribeOn() thread detection

[Android-s14]

Is it supposed to be like this by design: when I hide observeOn() / subscribeOn() behind compose(), for example, in logs I see:

... -> onSubscribe() :: @SubscribeOn -> main

Frankly, looking through some logs right now I don't see any other thread apart from "main"; I have to inject standard logging with Thread.currentThread() inside operators to check that it's not the main thread. I haven't tried it with primitive observables though.

Another example will also print "main" thread:

Observable.defer(...).subscribeOn(Schedulers.io()).mergeWith(Observable.<Bitmap> just(null));

[android10]

@Android-s14 Can you paste your code as an example? I want to reproduce the issue first. As far as I know compose() is used to chain custom operators and there might be a problem with that.

[Android-s14]

No problem, here's a snippet:

getObservable().subscribe(new Action1<Boolean>() {
    @Override
    public void call(Boolean aBoolean) {
        System.out.println(aBoolean);
    }
});

@RxLogObservable
private Observable<Boolean> getObservable() {
    return Observable.just(true, false).subscribeOn(Schedulers.io());
}

Logcat:

   11-11 19:42:15.759  13593-13593/com.example.android D/Class﹕ Frodo => [@Observable :: @InClass -> Class :: @Method -> getObservable()]
    11-11 19:42:15.777  13593-13593/com.example.android D/Class﹕ Frodo => [@Observable#getObservable -> onSubscribe() :: @SubscribeOn -> main]
    11-11 19:42:15.781  13593-13818/com.example.android D/Class﹕ Frodo => [@Observable#getObservable -> onNext() -> true]
    11-11 19:42:15.781  13593-13818/com.example.android D/Class﹕ Frodo => [@Observable#getObservable -> onNext() -> false]
    11-11 19:42:15.781  13593-13818/com.example.android D/Class﹕ Frodo => [@Observable#getObservable -> onCompleted()]
    11-11 19:42:15.781  13593-13818/com.example.android D/Class﹕ Frodo => [@Observable#getObservable -> onTerminate() :: @Emitted -> 2 elements :: @Time -> 4 ms]
    11-11 19:42:15.781  13593-13818/com.example.android D/Class﹕ Frodo => [@Observable#getObservable -> onUnsubscribe() :: @ObserveOn -> RxCachedThreadScheduler-1]

[Android-s14]

Do I read logs incorrectly? onSubscribe() :: @SubscribeOn -> main tells me that the generating part is executed on the main thread, although it is not.

[marwinxxii]

I can confirm this.

@Override
protected void onCreate(Bundle savedInstanceState) {
    super.onCreate(savedInstanceState);
    frodoTest().subscribe();
}

@RxLogObservable
private Observable<Object> frodoTest() {
    return Observable.create(new Observable.OnSubscribe<Object>() {
        @Override
        public void call(Subscriber<? super Object> subscriber) {
            try {
                Thread.sleep(2000l);
            } catch (InterruptedException e) {
                subscriber.onError(e);
            }
            subscriber.onNext(0);
            subscriber.onCompleted();
        }
    }).subscribeOn(Schedulers.computation());
}

Logs following:

Frodo => [@Observable :: @InClass -> MainActivity :: @Method -> frodoTest()]
Frodo => [@Observable#frodoTest -> onSubscribe() :: @SubscribeOn -> main]
Frodo => [@Observable#frodoTest -> onNext() -> 0]
Frodo => [@Observable#frodoTest -> onCompleted()]
Frodo => [@Observable#frodoTest -> onTerminate() :: @Emitted -> 1 element :: @Time -> 2009 ms]
Frodo => [@Observable#frodoTest -> onUnsubscribe() :: @ObserveOn -> RxComputationThreadPool-1]

[android10]

Nice feedback guys. I have to change the output here, since it is wrong. Will label this as a bug and fix it asap for the next release, which would be happen very soon. Keep you in the loop.

[android10]

@Android-s14 @marwinxxii this works as expected:

      observableSample.stringItem()
          .subscribeOn(Schedulers.computation())
          .observeOn(AndroidSchedulers.mainThread())
          .subscribe(
              new Subscriber<String>() {
                @Override public void onCompleted() {
                  //no op
                }

                @Override public void onError(Throwable e) {
                  //no op
                }

                @Override public void onNext(String s) {
                  //no op
                }
              });

I have to dive deeper here, there is something I'm not understanding within this behavior.

[Android-s14]

Indeed, playing around with a simple observable I noticed that placing subscribeOn() inside the method that returns an Observable and is annotated with @RxLogObservable results in the "main" log message, while applying subscribeOn() outside of the annotated method returns the correct thread.

[android10]

@Android-s14 nice input. This behavior definitely deserves more investigation.

[android10]

@Android-s14 @marwinxxii this was fixed here: https://github.com/android10/frodo/commit/7531d7f633b9ce581b0eb2afb08954fbfed2ea0d

I'm not gonna close this issue until I release a new version which is happening very soon. Thanks again for the feedback.

[Android-s14]

@android10 thank you a lot for your work, looking forward to try the new version out

[android10]

Hey guys, there is a new frodo version: 0.8.2. Here are the release notes: https://github.com/android10/frodo/wiki/Release-Notes

I'm closing this bug since is supposed to be fixed. Any feedback is welcome.

[android10]

By the way, I added new functionality for narrowing down Logging scope. Check the documentation: https://github.com/android10/frodo/wiki/@RxLogObservable