2.7 除錯

在響應式程式設計中，除錯是塊難啃的骨頭，這也是從指令式程式設計到響應式程式設計的切換過程中，學習曲線最陡峭的地方。

在指令式程式設計中，方法的呼叫關係擺在面上，我們通常可以通過stack trace追蹤的問題出現的位置。但是在非同步的響應式程式設計中，一方面有諸多的呼叫是在水面以下的，作為響應式開發庫的使用者是不需要了解的；另一方面，基於事件的非同步響應機制導致stack trace並非很容易在程式碼中按圖索驥的。

比如下邊的例子：

    @Test
    public void testBug() {
        getMonoWithException()
                .subscribe();
    }
 

1. single()方法只能接收一個元素，多了的話就會導致異常。

上邊的程式碼會報出如下的異常stack trace：

reactor.core.Exceptions$ErrorCallbackNotImplemented: java.lang.IndexOutOfBoundsException: Source emitted more than one item

Caused by: java.lang.IndexOutOfBoundsException: Source emitted more than one item
    at reactor.core.publisher.MonoSingle$SingleSubscriber.onNext(MonoSingle.java:129)
    at reactor.core.publisher.FluxFilterFuseable$FilterFuseableSubscriber.tryOnNext(FluxFilterFuseable.java:129)
    at reactor.core.publisher.FluxMapFuseable$MapFuseableConditionalSubscriber.tryOnNext(FluxMapFuseable.java:284)
    at reactor.core.publisher.FluxRange$RangeSubscriptionConditional.fastPath(FluxRange.java:273)
    at reactor.core.publisher.FluxRange$RangeSubscriptionConditional.request(FluxRange.java:251)
    at reactor.core.publisher.FluxMapFuseable$MapFuseableConditionalSubscriber.request(FluxMapFuseable.java:316)
    at reactor.core.publisher.FluxFilterFuseable$FilterFuseableSubscriber.request(FluxFilterFuseable.java:170)
    at reactor.core.publisher.MonoSingle$SingleSubscriber.request(MonoSingle.java:94)
    at reactor.core.publisher.LambdaMonoSubscriber.onSubscribe(LambdaMonoSubscriber.java:87)
    at reactor.core.publisher.MonoSingle$SingleSubscriber.onSubscribe(MonoSingle.java:114)
    at reactor.core.publisher.FluxFilterFuseable$FilterFuseableSubscriber.onSubscribe(FluxFilterFuseable.java:79)
    at reactor.core.publisher.FluxMapFuseable$MapFuseableConditionalSubscriber.onSubscribe(FluxMapFuseable.java:236)
    at reactor.core.publisher.FluxRange.subscribe(FluxRange.java:65)
    at reactor.core.publisher.FluxMapFuseable.subscribe(FluxMapFuseable.java:60)
    at reactor.core.publisher.FluxFilterFuseable.subscribe(FluxFilterFuseable.java:51)
    at reactor.core.publisher.MonoSingle.subscribe(MonoSingle.java:58)
    at reactor.core.publisher.Mono.subscribe(Mono.java:3077)
    at reactor.core.publisher.Mono.subscribeWith(Mono.java:3185)
    at reactor.core.publisher.Mono.subscribe(Mono.java:2962)
    at com.getset.Test_2_7.testBug(Test_2_7.java:19)
    ... 
 

比較明顯的資訊大概就是那句“Source emitted more than one item”。下邊的內容基本都是在Reactor庫內部的呼叫，而且上邊的stack trace的問題是出自.subscribe()那一行的。

如果對響應式流內部的Publisher、Subscriber和Subscription的機制比較熟悉，大概可以根據subscribe()或request()的順序大概猜測出來getMonoWithException()方法內大約經過了.map.filter.range的操作鏈，但是除此之外，確實獲取不到太多資訊。

另一方面，指令式程式設計的方式比較容易使用IDE的除錯工具進行單步或斷點除錯，而在非同步程式設計方式下，通常也不太好使。

以上這些都是在非同步的響應式程式設計中可能會遇到的窘境。解鈴還須繫鈴人，對於響應式程式設計的除錯還需要響應式程式設計庫本身提供除錯工具。

2.7.1 開啟除錯模式

Reactor提供了開啟除錯模式的方法。

Hooks.onOperatorDebug();

這個方法能夠開啟除錯模式，從而在丟擲異常時打印出一些有用的資訊。把這一行加上：

    @Test
    public void testBug() {
        Hooks.onOperatorDebug();
        getMonoWithException()
                .subscribe();
    }

這時候，除了上邊的那一套stack trace之外，增加了以下內容：

    Suppressed: reactor.core.publisher.FluxOnAssembly$OnAssemblyException: 
Assembly trace from producer [reactor.core.publisher.MonoSingle] :
    reactor.core.publisher.Flux.single(Flux.java:6473)
    com.getset.Test_2_7.getMonoWithException(Test_2_7.java:13)
    com.getset.Test_2_7.testBug(Test_2_7.java:19)
Error has been observed by the following operator(s):
    |_  Flux.single(Test_2_7.java:13)

這裡就可以明確找出問題根源了。

Hooks.onOperatorDebug()的實現原理在於在組裝期包裝各個操作符的構造方法，加入一些監測功能，所以這個 hook 應該在早於宣告的時候被啟用，最保險的方式就是在你程式的最開始就啟用它。以map操作符為例：

    public final <V> Flux<V> map(Function<? super T, ? extends V> mapper) {
        if (this instanceof Fuseable) {
            return onAssembly(new FluxMapFuseable<>(this, mapper));
        }
        return onAssembly(new FluxMap<>(this, mapper));
    }

可以看到，每次在返回新的Flux物件的時候，都會呼叫onAssembly方法，這裡就是Reactor可以在組裝期插手“搞事情”的地方。

Hooks.onOperatorDebug()是一種全域性性的Hook，會影響到應用中所有的操作符，所以其帶來的效能成本也是比較大的。如果我們大概知道可能的問題在哪，而對整個應用開啟除錯模式，也容易被茫茫多的除錯資訊淹沒。這時候，我們需要一種更加精準且廉價的定位方式。

2.7.2 使用 checkpoint() 來定位

如果你知道問題出在哪個鏈上，但是由於這個鏈的上游或下游來自其他的呼叫，就可以針對這個鏈使用checkpoint()進行問題定位。

checkpoint()操作符就像一個Hook，不過它的作用範圍僅限於這個鏈上。

    @Test
    public void checkBugWithCheckPoint() {
        getMonoWithException()
                .checkpoint()
                .subscribe();
    }

通過增加checkpoint()操作符，仍然可以打印出除錯資訊：

    Suppressed: reactor.core.publisher.FluxOnAssembly$OnAssemblyException: 
Assembly trace from producer [reactor.core.publisher.MonoSingle] :
    reactor.core.publisher.Mono.checkpoint(Mono.java:1367)
    reactor.core.publisher.Mono.checkpoint(Mono.java:1317)
    com.getset.Test_2_7.checkBugWithCheckPoint(Test_2_7.java:25)
Error has been observed by the following operator(s):
    |_  Mono.checkpoint(Test_2_7.java:25)

checkpoint()方法還有變體checkpoint(String description)，你可以傳入一個獨特的字串以方便在 assembly traceback 中進行識別。 這樣會省略掉stack trace，不過你可以依賴這個字串來定位到出問題的組裝點。checkpoint(String) 比 checkpoint 有更低的執行成本。如下：

    @Test
    public void checkBugWithCheckPoint2() {
        getMonoWithException()
                .checkpoint("checkBugWithCheckPoint2")
                .subscribe();
    }

加入用於標識的字串（方法名），輸出如下：

    Suppressed: reactor.core.publisher.FluxOnAssembly$OnAssemblyException: 
Assembly site of producer [reactor.core.publisher.MonoSingle] is identified by light checkpoint [I_HATE_BUGS]."description" : "checkBugWithCheckPoint2"

可以看到這裡確實省略了除錯的assembly traceback，但是我們通過上邊的資訊也可以定位到是single的問題。

上邊的例子比較簡單，當有許多的除錯資訊打印出來的時候，這個標識字串能夠方便我們在許多的控制檯輸出中定位到問題。

如果既希望有除錯資訊assembly traceback，也希望用上標識字串，還可以checkpoint(description, true)來實現，第二個引數true標識要列印assembly traceback。

2.7.3 使用log()操作符瞭解執行過程

最後一個方便除錯的工具就是我們前邊多次用到的log()操作符了，它能夠記錄其上游的Flux或 Mono的事件（包括onNext、onError、onComplete， 以及onSubscribe、cancel、和request）。

log操作符可以通過SLF4J使用類似Log4J和Logback這樣的公共的日誌工具來記錄日誌，如果SLF4J不存在的話，則直接將日誌輸出到控制檯。

控制檯使用 System.err 記錄WARN和ERROR級別的日誌，使用 System.out 記錄其他級別的日誌。