RxJava 的 Observable 的 onNext 有时会被跳过答案

【问题标题】：RxJava's Observable's onNext is sometimes skippedRxJava 的 Observable 的 onNext 有时会被跳过
【发布时间】：2020-07-03 07:19:56
【问题描述】：

这是两个线程循环大约 100 毫秒的示例。奇特的是，循环的方式不是while(true)等，而是执行后用onNext将item添加到Observable的方式。

kotlin 编写的代码如下所示。

private val _ps_2_thread_loop = PublishSubject.create<Array<Any>>()

fun start() {
    _ps_2_thread_loop
        .observeOn(Schedulers.io())
        .map {
            val cmd = it[0] as String

            when(cmd) {
                "cmd0" -> {
                    LogEx.d("cmd0 start")
                    runBlocking { delay(100) }
                    LogEx.d("cmd0 fin")
                    _ps_2_thread_loop.onNext(arrayOf("cmd0"))
                }
            }

            return@map it
        }
        .observeOn(Schedulers.io())
        .map {
            val cmd = it[0] as String

            when(cmd) {
                "cmd1" -> {
                    LogEx.d("cmd1 start")
                    runBlocking { delay(100) }
                    LogEx.d("cmd1 fin")
                    _ps_2_thread_loop.onNext(arrayOf("cmd1"))
                }
            }

            return@map it
        }
        .subscribe()

    _ps_2_thread_loop.onNext(arrayOf("cmd0"))
    _ps_2_thread_loop.onNext(arrayOf("cmd1"))
}

预期结果是 cmd0 和 cmd1 被永久记录。但是，cmd0 或 cmd1 在中间被取消。在日志上，它似乎在 onNext 之前工作正常，但它似乎在 Observable 之后的某个地方被跳过，即 RxJava。

日志如下所示。

07-03 16:02:26.010 24540 24638 D LogEx   : MyTestActivity.kt:759:apply RxCachedThreadScheduler-1 cmd0 start
07-03 16:02:26.137 24540 24638 D LogEx   : MyTestActivity.kt:761:apply RxCachedThreadScheduler-1 cmd0 fin
07-03 16:02:26.140 24540 24638 D LogEx   : MyTestActivity.kt:759:apply RxCachedThreadScheduler-1 cmd0 start
07-03 16:02:26.141 24540 24639 D LogEx   : MyTestActivity.kt:774:apply RxCachedThreadScheduler-2 cmd1 start
07-03 16:02:26.242 24540 24638 D LogEx   : MyTestActivity.kt:761:apply RxCachedThreadScheduler-1 cmd0 fin
07-03 16:02:26.243 24540 24639 D LogEx   : MyTestActivity.kt:776:apply RxCachedThreadScheduler-2 cmd1 fin
07-03 16:02:26.243 24540 24638 D LogEx   : MyTestActivity.kt:759:apply RxCachedThreadScheduler-1 cmd0 start
07-03 16:02:26.345 24540 24638 D LogEx   : MyTestActivity.kt:761:apply RxCachedThreadScheduler-1 cmd0 fin
07-03 16:02:26.346 24540 24638 D LogEx   : MyTestActivity.kt:759:apply RxCachedThreadScheduler-1 cmd0 start
07-03 16:02:26.346 24540 24639 D LogEx   : MyTestActivity.kt:774:apply RxCachedThreadScheduler-2 cmd1 start
07-03 16:02:26.448 24540 24638 D LogEx   : MyTestActivity.kt:761:apply RxCachedThreadScheduler-1 cmd0 fin
07-03 16:02:26.448 24540 24639 D LogEx   : MyTestActivity.kt:776:apply RxCachedThreadScheduler-2 cmd1 fin
07-03 16:02:26.449 24540 24639 D LogEx   : MyTestActivity.kt:774:apply RxCachedThreadScheduler-2 cmd1 start
07-03 16:02:26.552 24540 24639 D LogEx   : MyTestActivity.kt:776:apply RxCachedThreadScheduler-2 cmd1 fin
07-03 16:02:26.554 24540 24639 D LogEx   : MyTestActivity.kt:774:apply RxCachedThreadScheduler-2 cmd1 start
07-03 16:02:26.658 24540 24639 D LogEx   : MyTestActivity.kt:776:apply RxCachedThreadScheduler-2 cmd1 fin
07-03 16:02:26.660 24540 24639 D LogEx   : MyTestActivity.kt:774:apply RxCachedThreadScheduler-2 cmd1 start
07-03 16:02:26.763 24540 24639 D LogEx   : MyTestActivity.kt:776:apply RxCachedThreadScheduler-2 cmd1 fin
07-03 16:02:26.766 24540 24639 D LogEx   : MyTestActivity.kt:774:apply RxCachedThreadScheduler-2 cmd1 start
07-03 16:02:26.867 24540 24639 D LogEx   : MyTestActivity.kt:776:apply RxCachedThreadScheduler-2 cmd1 fin
07-03 16:02:26.870 24540 24639 D LogEx   : MyTestActivity.kt:774:apply RxCachedThreadScheduler-2 cmd1 start
07-03 16:02:26.972 24540 24639 D LogEx   : MyTestActivity.kt:776:apply RxCachedThreadScheduler-2 cmd1 fin
07-03 16:02:26.975 24540 24639 D LogEx   : MyTestActivity.kt:774:apply RxCachedThreadScheduler-2 cmd1 start
07-03 16:02:27.077 24540 24639 D LogEx   : MyTestActivity.kt:776:apply RxCachedThreadScheduler-2 cmd1 fin
07-03 16:02:27.080 24540 24639 D LogEx   : MyTestActivity.kt:774:apply RxCachedThreadScheduler-2 cmd1 start
07-03 16:02:27.183 24540 24639 D LogEx   : MyTestActivity.kt:776:apply RxCachedThreadScheduler-2 cmd1 fin
07-03 16:02:27.186 24540 24639 D LogEx   : MyTestActivity.kt:774:apply RxCachedThreadScheduler-2 cmd1 start
07-03 16:02:27.289 24540 24639 D LogEx   : MyTestActivity.kt:776:apply RxCachedThreadScheduler-2 cmd1 fin
07-03 16:02:27.292 24540 24639 D LogEx   : MyTestActivity.kt:774:apply RxCachedThreadScheduler-2 cmd1 start
07-03 16:02:27.394 24540 24639 D LogEx   : MyTestActivity.kt:776:apply RxCachedThreadScheduler-2 cmd1 fin
07-03 16:02:27.397 24540 24639 D LogEx   : MyTestActivity.kt:774:apply RxCachedThreadScheduler-2 cmd1 start
07-03 16:02:27.500 24540 24639 D LogEx   : MyTestActivity.kt:776:apply RxCachedThreadScheduler-2 cmd1 fin
07-03 16:02:27.503 24540 24639 D LogEx   : MyTestActivity.kt:774:apply RxCachedThreadScheduler-2 cmd1 start
07-03 16:02:27.607 24540 24639 D LogEx   : MyTestActivity.kt:776:apply RxCachedThreadScheduler-2 cmd1 fin
07-03 16:02:27.610 24540 24639 D LogEx   : MyTestActivity.kt:774:apply RxCachedThreadScheduler-2 cmd1 start
07-03 16:02:27.715 24540 24639 D LogEx   : MyTestActivity.kt:776:apply RxCachedThreadScheduler-2 cmd1 fin
07-03 16:02:27.719 24540 24639 D LogEx   : MyTestActivity.kt:774:apply RxCachedThreadScheduler-2 cmd1 start
07-03 16:02:27.823 24540 24639 D LogEx   : MyTestActivity.kt:776:apply RxCachedThreadScheduler-2 cmd1 fin
07-03 16:02:27.826 24540 24639 D LogEx   : MyTestActivity.kt:774:apply RxCachedThreadScheduler-2 cmd1 start
07-03 16:02:27.930 24540 24639 D LogEx   : MyTestActivity.kt:776:apply RxCachedThreadScheduler-2 cmd1 fin
07-03 16:02:27.933 24540 24639 D LogEx   : MyTestActivity.kt:774:apply RxCachedThreadScheduler-2 cmd1 start
07-03 16:02:28.037 24540 24639 D LogEx   : MyTestActivity.kt:776:apply RxCachedThreadScheduler-2 cmd1 fin
07-03 16:02:28.040 24540 24639 D LogEx   : MyTestActivity.kt:774:apply RxCachedThreadScheduler-2 cmd1 start
07-03 16:02:28.143 24540 24639 D LogEx   : MyTestActivity.kt:776:apply RxCachedThreadScheduler-2 cmd1 fin
07-03 16:02:28.146 24540 24639 D LogEx   : MyTestActivity.kt:774:apply RxCachedThreadScheduler-2 cmd1 start
07-03 16:02:28.249 24540 24639 D LogEx   : MyTestActivity.kt:776:apply RxCachedThreadScheduler-2 cmd1 fin
07-03 16:02:28.252 24540 24639 D LogEx   : MyTestActivity.kt:774:apply RxCachedThreadScheduler-2 cmd1 start
07-03 16:02:28.356 24540 24639 D LogEx   : MyTestActivity.kt:776:apply RxCachedThreadScheduler-2 cmd1 fin
07-03 16:02:28.359 24540 24639 D LogEx   : MyTestActivity.kt:774:apply RxCachedThreadScheduler-2 cmd1 start
07-03 16:02:28.463 24540 24639 D LogEx   : MyTestActivity.kt:776:apply RxCachedThreadScheduler-2 cmd1 fin
07-03 16:02:28.466 24540 24639 D LogEx   : MyTestActivity.kt:774:apply RxCachedThreadScheduler-2 cmd1 start
07-03 16:02:28.569 24540 24639 D LogEx   : MyTestActivity.kt:776:apply RxCachedThreadScheduler-2 cmd1 fin
07-03 16:02:28.572 24540 24639 D LogEx   : MyTestActivity.kt:774:apply RxCachedThreadScheduler-2 cmd1 start
07-03 16:02:28.675 24540 24639 D LogEx   : MyTestActivity.kt:776:apply RxCachedThreadScheduler-2 cmd1 fin
07-03 16:02:28.678 24540 24639 D LogEx   : MyTestActivity.kt:774:apply RxCachedThreadScheduler-2 cmd1 start
07-03 16:02:28.784 24540 24639 D LogEx   : MyTestActivity.kt:776:apply RxCachedThreadScheduler-2 cmd1 fin
07-03 16:02:28.789 24540 24639 D LogEx   : MyTestActivity.kt:774:apply RxCachedThreadScheduler-2 cmd1 start
07-03 16:02:28.892 24540 24639 D LogEx   : MyTestActivity.kt:776:apply RxCachedThreadScheduler-2 cmd1 fin
07-03 16:02:28.896 24540 24639 D LogEx   : MyTestActivity.kt:774:apply RxCachedThreadScheduler-2 cmd1 start
07-03 16:02:28.999 24540 24639 D LogEx   : MyTestActivity.kt:776:apply RxCachedThreadScheduler-2 cmd1 fin
07-03 16:02:29.002 24540 24639 D LogEx   : MyTestActivity.kt:774:apply RxCachedThreadScheduler-2 cmd1 start
07-03 16:02:29.107 24540 24639 D LogEx   : MyTestActivity.kt:776:apply RxCachedThreadScheduler-2 cmd1 fin
...

【问题讨论】：

标签： android kotlin observable rx-java

【解决方案1】：

在自己做了一些额外的调试之后，我取得了一些进展。

在操作过程中似乎不应该调用 Observable 的 onNext（在本例中为 _ps_2_thread_loop）。在 map 中调用 _ps_2_thread_loop.onNext(arrayOf("cmd0")) 看起来像 goto 语句，是一种反模式。我还没有调试过 RxJava 内部，但这似乎是个问题。

所以，从需要onnext的部分特意返回退出map后，在3rd线程中收集，一次性处理onnext，实际正常执行。

代码：

private val _ps_2_thread_loop = PublishSubject.create<Array<Any>>()

fun _48_2_thread_loop() {
    _ps_2_thread_loop
        .observeOn(Schedulers.io())
        .map {
            val cmd = it[0] as String

            when (cmd) {
                "cmd0" -> {
                    LogEx.d("cmd0 start")
                    runBlocking { delay(100) }
                    LogEx.d("cmd0 fin")
                    return@map arrayOf("onnext", arrayOf("cmd0"))
                }
            }
            return@map it
        }
        .observeOn(Schedulers.io())
        .map {
            val cmd = it[0] as String

            when (cmd) {
                "cmd1" -> {
                    LogEx.d("cmd1 start")
                    runBlocking { delay(100) }
                    LogEx.d("cmd1 fin")
                    return@map arrayOf("onnext", arrayOf("cmd1"))
                }
            }
            return@map it
        }
        .observeOn(Schedulers.io())
        .map {
            val cmd = it[0] as String

            when (cmd) {
                "onnext" -> {
                    val onnextArray = it[1] as Array<Any>
                    _ps_2_thread_loop.onNext(onnextArray)
                }
            }

            return@map it
        }
        .subscribe()

    _ps_2_thread_loop.onNext(arrayOf("cmd0"))
    _ps_2_thread_loop.onNext(arrayOf("cmd1"))
}

日志：

07-03 17:39:51.716 13252 13914 D LogEx   : MyTestActivity.kt:760:apply RxCachedThreadScheduler-1 cmd0 start
07-03 17:39:51.840 13252 13914 D LogEx   : MyTestActivity.kt:762:apply RxCachedThreadScheduler-1 cmd0 fin
07-03 17:39:51.843 13252 13915 D LogEx   : MyTestActivity.kt:774:apply RxCachedThreadScheduler-2 cmd1 start
07-03 17:39:51.844 13252 13914 D LogEx   : MyTestActivity.kt:760:apply RxCachedThreadScheduler-1 cmd0 start
07-03 17:39:51.947 13252 13915 D LogEx   : MyTestActivity.kt:776:apply RxCachedThreadScheduler-2 cmd1 fin
07-03 17:39:51.947 13252 13914 D LogEx   : MyTestActivity.kt:762:apply RxCachedThreadScheduler-1 cmd0 fin
07-03 17:39:51.949 13252 13914 D LogEx   : MyTestActivity.kt:760:apply RxCachedThreadScheduler-1 cmd0 start
07-03 17:39:51.949 13252 13915 D LogEx   : MyTestActivity.kt:774:apply RxCachedThreadScheduler-2 cmd1 start
07-03 17:39:52.051 13252 13914 D LogEx   : MyTestActivity.kt:762:apply RxCachedThreadScheduler-1 cmd0 fin
07-03 17:39:52.051 13252 13915 D LogEx   : MyTestActivity.kt:776:apply RxCachedThreadScheduler-2 cmd1 fin
07-03 17:39:52.053 13252 13914 D LogEx   : MyTestActivity.kt:760:apply RxCachedThreadScheduler-1 cmd0 start
07-03 17:39:52.053 13252 13915 D LogEx   : MyTestActivity.kt:774:apply RxCachedThreadScheduler-2 cmd1 start
07-03 17:39:52.155 13252 13915 D LogEx   : MyTestActivity.kt:776:apply RxCachedThreadScheduler-2 cmd1 fin
07-03 17:39:52.155 13252 13914 D LogEx   : MyTestActivity.kt:762:apply RxCachedThreadScheduler-1 cmd0 fin
07-03 17:39:52.157 13252 13914 D LogEx   : MyTestActivity.kt:760:apply RxCachedThreadScheduler-1 cmd0 start
07-03 17:39:52.158 13252 13915 D LogEx   : MyTestActivity.kt:774:apply RxCachedThreadScheduler-2 cmd1 start
07-03 17:39:52.259 13252 13915 D LogEx   : MyTestActivity.kt:776:apply RxCachedThreadScheduler-2 cmd1 fin
07-03 17:39:52.260 13252 13914 D LogEx   : MyTestActivity.kt:762:apply RxCachedThreadScheduler-1 cmd0 fin
07-03 17:39:52.261 13252 13915 D LogEx   : MyTestActivity.kt:774:apply RxCachedThreadScheduler-2 cmd1 start
07-03 17:39:52.263 13252 13914 D LogEx   : MyTestActivity.kt:760:apply RxCachedThreadScheduler-1 cmd0 start
07-03 17:39:52.365 13252 13915 D LogEx   : MyTestActivity.kt:776:apply RxCachedThreadScheduler-2 cmd1 fin
07-03 17:39:52.366 13252 13914 D LogEx   : MyTestActivity.kt:762:apply RxCachedThreadScheduler-1 cmd0 fin
07-03 17:39:52.368 13252 13915 D LogEx   : MyTestActivity.kt:774:apply RxCachedThreadScheduler-2 cmd1 start
07-03 17:39:52.369 13252 13914 D LogEx   : MyTestActivity.kt:760:apply RxCachedThreadScheduler-1 cmd0 start
07-03 17:39:52.471 13252 13915 D LogEx   : MyTestActivity.kt:776:apply RxCachedThreadScheduler-2 cmd1 fin
07-03 17:39:52.473 13252 13914 D LogEx   : MyTestActivity.kt:762:apply RxCachedThreadScheduler-1 cmd0 fin
07-03 17:39:52.474 13252 13915 D LogEx   : MyTestActivity.kt:774:apply RxCachedThreadScheduler-2 cmd1 start
07-03 17:39:52.476 13252 13914 D LogEx   : MyTestActivity.kt:760:apply RxCachedThreadScheduler-1 cmd0 start
07-03 17:39:52.578 13252 13915 D LogEx   : MyTestActivity.kt:776:apply RxCachedThreadScheduler-2 cmd1 fin
07-03 17:39:52.578 13252 13914 D LogEx   : MyTestActivity.kt:762:apply RxCachedThreadScheduler-1 cmd0 fin
07-03 17:39:52.581 13252 13914 D LogEx   : MyTestActivity.kt:760:apply RxCachedThreadScheduler-1 cmd0 start
07-03 17:39:52.581 13252 13915 D LogEx   : MyTestActivity.kt:774:apply RxCachedThreadScheduler-2 cmd1 start
07-03 17:39:52.685 13252 13915 D LogEx   : MyTestActivity.kt:776:apply RxCachedThreadScheduler-2 cmd1 fin
07-03 17:39:52.685 13252 13914 D LogEx   : MyTestActivity.kt:762:apply RxCachedThreadScheduler-1 cmd0 fin
07-03 17:39:52.687 13252 13914 D LogEx   : MyTestActivity.kt:760:apply RxCachedThreadScheduler-1 cmd0 start
07-03 17:39:52.688 13252 13915 D LogEx   : MyTestActivity.kt:774:apply RxCachedThreadScheduler-2 cmd1 start
07-03 17:39:52.791 13252 13914 D LogEx   : MyTestActivity.kt:762:apply RxCachedThreadScheduler-1 cmd0 fin
07-03 17:39:52.791 13252 13915 D LogEx   : MyTestActivity.kt:776:apply RxCachedThreadScheduler-2 cmd1 fin

另外，这个问题不会出现在JVM中，而只会出现在Android ART中，所以我认为这是由于实现差异或Android调度程序中的错误。

【讨论】：

【解决方案2】：

在上篇文章中，为了修复onNext被忽略的现象，使用新的schduler新建了一个处理onNext的map，这里只处理。然而，这又产生了一个新问题。

有问题的代码：

    fun _48_pipeline_single_line() {
        val ps = PublishSubject.create<Array<Any>>()

        ps
            .observeOn(Schedulers.io())
            .map {
                val cmd = it[0] as String

                when (cmd) {
                    "cmd0" -> {
                        LogEx.d("cmd0 start")
                        runBlocking { delay(1_00) }
                        LogEx.d("cmd0 fin")
                        return@map arrayOf("onnext", arrayOf("cmd0"))
                    }
                }
                return@map it
            }
            .observeOn(Schedulers.io())
            .map {
                val cmd = it[0] as String

                when (cmd) {
                    "cmd1" -> {
                        LogEx.d("cmd1 start")
                        runBlocking { delay(10_000) }
                        LogEx.d("cmd1 fin")
                        return@map arrayOf("onnext", arrayOf("cmd1"))
                    }
                }
                return@map it
            }
            .observeOn(Schedulers.io())
            .map {
                val cmd = it[0] as String

                when (cmd) {
                    "onnext" -> {
                        val onnextArray = it[1] as Array<Any>
                        val incmd = onnextArray[0] as String
                        LogEx.d("onnext incmd[${incmd}]")
                        ps.onNext(onnextArray)
                    }
                }

                return@map it
            }
            .subscribe()


        ps.onNext(arrayOf("cmd0"))
        ps.onNext(arrayOf("cmd1"))
    }

记录问题发生的位置：

07-08 14:37:43.552 15217 15342 D LogEx   : MyTestActivity.kt:761:apply RxCachedThreadScheduler-1 cmd0 start
07-08 14:37:43.679 15217 15342 D LogEx   : MyTestActivity.kt:763:apply RxCachedThreadScheduler-1 cmd0 fin
07-08 14:37:43.682 15217 15343 D LogEx   : MyTestActivity.kt:775:apply RxCachedThreadScheduler-2 cmd1 start
07-08 14:37:43.683 15217 15344 D LogEx   : MyTestActivity.kt:791:apply RxCachedThreadScheduler-3 onnext incmd[cmd0]
07-08 14:37:43.684 15217 15342 D LogEx   : MyTestActivity.kt:761:apply RxCachedThreadScheduler-1 cmd0 start
07-08 14:37:43.786 15217 15342 D LogEx   : MyTestActivity.kt:763:apply RxCachedThreadScheduler-1 cmd0 fin
07-08 14:37:53.687 15217 15343 D LogEx   : MyTestActivity.kt:777:apply RxCachedThreadScheduler-2 cmd1 fin
07-08 14:37:53.689 15217 15344 D LogEx   : MyTestActivity.kt:791:apply RxCachedThreadScheduler-3 onnext incmd[cmd1]
07-08 14:37:53.690 15217 15344 D LogEx   : MyTestActivity.kt:791:apply RxCachedThreadScheduler-3 onnext incmd[cmd0]
07-08 14:37:53.696 15217 15342 D LogEx   : MyTestActivity.kt:761:apply RxCachedThreadScheduler-1 cmd0 start
07-08 14:37:53.701 15217 15343 D LogEx   : MyTestActivity.kt:775:apply RxCachedThreadScheduler-2 cmd1 start
07-08 14:37:53.811 15217 15342 D LogEx   : MyTestActivity.kt:763:apply RxCachedThreadScheduler-1 cmd0 fin

从日志中可以看出，在第二个 cmd0 之前它工作正常，但在等待 10 秒之后，cmd1 被终止，您可以看到此后 onnext 继续进行。这似乎是因为Schduler不同，而是按照作业队列中累积的顺序处理的。

我需要再次修改它。如果我再判断正确的话，cmd0和cmd1是不需要按顺序处理的操作，所以设计一个管道是没有必要和错误的。我认为通过将它们映射到地图来仅管理需要保持秩序的操作是正确的。所以修改后的代码和日志...

最后修改代码：

    fun _49_pipeline_double_line() {
        val ps0 = PublishSubject.create<String>()
        val ps1 = PublishSubject.create<String>()

        ps0
            .observeOn(Schedulers.io())
            .map {
                val cmd = it as String

                when (cmd) {
                    "cmd0" -> {
                        LogEx.d("cmd0 start")
                        runBlocking { delay(1_000) }
                        LogEx.d("cmd0 fin")
                        ps0.onNext("cmd0")
                    }
                }

                return@map it
            }
            .subscribe()

        ps1
            .observeOn(Schedulers.io())
            .map {
                val cmd = it as String

                when (cmd) {
                    "cmd1" -> {
                        LogEx.d("cmd1 start")
                        runBlocking { delay(10_000) }
                        LogEx.d("cmd1 fin")
                        ps1.onNext("cmd1")
                    }
                }

                return@map it
            }
            .subscribe()

        ps0.onNext("cmd0")
        ps1.onNext("cmd1")
    }

最后修改日志：

07-08 14:38:08.524 15356 15426 D LogEx   : MyTestActivity.kt:834:apply RxCachedThreadScheduler-2 cmd1 start
07-08 14:38:08.524 15356 15425 D LogEx   : MyTestActivity.kt:816:apply RxCachedThreadScheduler-1 cmd0 start
07-08 14:38:09.554 15356 15425 D LogEx   : MyTestActivity.kt:818:apply RxCachedThreadScheduler-1 cmd0 fin
07-08 14:38:09.555 15356 15425 D LogEx   : MyTestActivity.kt:816:apply RxCachedThreadScheduler-1 cmd0 start
07-08 14:38:10.558 15356 15425 D LogEx   : MyTestActivity.kt:818:apply RxCachedThreadScheduler-1 cmd0 fin
07-08 14:38:10.559 15356 15425 D LogEx   : MyTestActivity.kt:816:apply RxCachedThreadScheduler-1 cmd0 start
07-08 14:38:11.563 15356 15425 D LogEx   : MyTestActivity.kt:818:apply RxCachedThreadScheduler-1 cmd0 fin
07-08 14:38:11.565 15356 15425 D LogEx   : MyTestActivity.kt:816:apply RxCachedThreadScheduler-1 cmd0 start
07-08 14:38:12.574 15356 15425 D LogEx   : MyTestActivity.kt:818:apply RxCachedThreadScheduler-1 cmd0 fin
07-08 14:38:12.577 15356 15425 D LogEx   : MyTestActivity.kt:816:apply RxCachedThreadScheduler-1 cmd0 start
07-08 14:38:13.583 15356 15425 D LogEx   : MyTestActivity.kt:818:apply RxCachedThreadScheduler-1 cmd0 fin
07-08 14:38:13.586 15356 15425 D LogEx   : MyTestActivity.kt:816:apply RxCachedThreadScheduler-1 cmd0 start
07-08 14:38:14.592 15356 15425 D LogEx   : MyTestActivity.kt:818:apply RxCachedThreadScheduler-1 cmd0 fin
07-08 14:38:14.596 15356 15425 D LogEx   : MyTestActivity.kt:816:apply RxCachedThreadScheduler-1 cmd0 start
07-08 14:38:15.607 15356 15425 D LogEx   : MyTestActivity.kt:818:apply RxCachedThreadScheduler-1 cmd0 fin
07-08 14:38:15.613 15356 15425 D LogEx   : MyTestActivity.kt:816:apply RxCachedThreadScheduler-1 cmd0 start
07-08 14:38:16.618 15356 15425 D LogEx   : MyTestActivity.kt:818:apply RxCachedThreadScheduler-1 cmd0 fin
07-08 14:38:16.620 15356 15425 D LogEx   : MyTestActivity.kt:816:apply RxCachedThreadScheduler-1 cmd0 start
07-08 14:38:17.630 15356 15425 D LogEx   : MyTestActivity.kt:818:apply RxCachedThreadScheduler-1 cmd0 fin
07-08 14:38:17.636 15356 15425 D LogEx   : MyTestActivity.kt:816:apply RxCachedThreadScheduler-1 cmd0 start
07-08 14:38:18.555 15356 15426 D LogEx   : MyTestActivity.kt:836:apply RxCachedThreadScheduler-2 cmd1 fin
07-08 14:38:18.556 15356 15426 D LogEx   : MyTestActivity.kt:834:apply RxCachedThreadScheduler-2 cmd1 start
07-08 14:38:18.649 15356 15425 D LogEx   : MyTestActivity.kt:818:apply RxCachedThreadScheduler-1 cmd0 fin
07-08 14:38:18.653 15356 15425 D LogEx   : MyTestActivity.kt:816:apply RxCachedThreadScheduler-1 cmd0 start
07-08 14:38:19.659 15356 15425 D LogEx   : MyTestActivity.kt:818:apply RxCachedThreadScheduler-1 cmd0 fin
07-08 14:38:19.662 15356 15425 D LogEx   : MyTestActivity.kt:816:apply RxCachedThreadScheduler-1 cmd0 start
07-08 14:38:20.670 15356 15425 D LogEx   : MyTestActivity.kt:818:apply RxCachedThreadScheduler-1 cmd0 fin
07-08 14:38:20.674 15356 15425 D LogEx   : MyTestActivity.kt:816:apply RxCachedThreadScheduler-1 cmd0 start
07-08 14:38:21.680 15356 15425 D LogEx   : MyTestActivity.kt:818:apply RxCachedThreadScheduler-1 cmd0 fin
07-08 14:38:21.683 15356 15425 D LogEx   : MyTestActivity.kt:816:apply RxCachedThreadScheduler-1 cmd0 start
07-08 14:38:22.689 15356 15425 D LogEx   : MyTestActivity.kt:818:apply RxCachedThreadScheduler-1 cmd0 fin
07-08 14:38:22.692 15356 15425 D LogEx   : MyTestActivity.kt:816:apply RxCachedThreadScheduler-1 cmd0 start
07-08 14:38:23.695 15356 15425 D LogEx   : MyTestActivity.kt:818:apply RxCachedThreadScheduler-1 cmd0 fin
07-08 14:38:23.696 15356 15425 D LogEx   : MyTestActivity.kt:816:apply RxCachedThreadScheduler-1 cmd0 start

【讨论】：