(reactor) Debug--Response Spring's Path wizard

This series of articles index the "Response Spring's word Wizard"
Previously summary Reactor 3 Quick Start | Responsive Flow Specification
This article tests the source code

2.7 Commissioning

In responsive programming, debugging is a hard-to-chew bone, which is the steepest of the learning curve from imperative programming to responsive programming.

In imperative programming, the method's invocation relationship is placed on the surface, and we can usually trace the problem through the stack trace where it appears. However, in asynchronous responsive programming, there are many calls that are below the surface of the water, as users of the Responsive Development library do not need to know; On the other hand, the event-based asynchronous response mechanism causes the stack trace to not be easily retrace in the code.

For example, below:

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

1. single()Method can only receive one element, and if more, it will cause an exception.

The upper code will report the following exception stack trace:

Reactor.core.exceptions$errorcallbacknotimplemented:java.lang.indexoutofboundsexception:source emitted more than One itemcaused by:java.lang.IndexOutOfBoundsException:Source emitted more than one item at Reactor.core.publisher.Mon Osingle$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) ...

The more obvious information is probably the phrase "Source emitted more than one item". The following is basically a call inside the reactor library, and the problem with the stack trace above is from .subscribe() that line.

If you are familiar with the mechanisms of Publisher, Subscriber, and subscription within a responsive flow, you can probably guess in terms of subscribe() or request() in the order in which the getMonoWithException() operation chain is about to pass .map.filter.range , but beyond that, Do not get too much information.

On the other hand, imperative programming is easier to use with IDE's debugging Tools for single-Step or breakpoint debugging, and in asynchronous programming, it is often less so.

These are the dilemmas that you might encounter in asynchronous, responsive programming. It is also necessary to ring the bell, and for the debugging of responsive programming, the response programming library itself is required to provide debugging tools.

2.7.1 Turn on Debug mode

Reactor provides a way to turn on debug mode.

Hooks.onOperatorDebug();

This method enables debugging mode to print out some useful information when an exception is thrown. Add this line:

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

This time, in addition to the stack trace above, the following additions were added:

    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)

Here you can pinpoint the root cause of the problem.

Hooks.onOperatorDebug()The implementation of the principle lies in the assembly period of the packaging of the various operators of the construction method, adding some monitoring functions, so this hook should be activated earlier than the declaration, the most safe way is to activate it at the very beginning of your program. Take the map operator as an example:

    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));    }

You can see that every time a new flux object is returned, the method is called, and onAssembly this is where reactor can step into the "doing things" during the assembly period.

Hooks.onOperatorDebug()is a global hook that affects all the operators in the application, so the performance cost is also relatively large. If we know probably where the problem is, and the entire application to open debug mode, but also easy to be overwhelmed by the vast number of debugging information. At this point, we need a more precise and inexpensive way to locate.

2.7.2 using Checkpoint () to locate

If you know which chain the problem is on, but because the chain is upstream or downstream from other calls, you can use Checkpoint () for this chain to locate the problem.

checkpoint()The operator is like a hook, but its scope is limited to this chain.

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

By adding checkpoint() operators, you can still print out debug information:

    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()Method also has variants checkpoint(String description) , you can pass in a unique string to facilitate identification in the assembly Traceback. This will omit the stack trace, but you can rely on the string to locate the problematic assembly point. Checkpoint (String) has a lower execution cost than checkpoint. As follows:

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

Add a string (method name) for identification, and the output is as follows:

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

You can see that the debug assembly Traceback is omitted here, but we can also locate the problem by using the above information single .

The above example is simple, and when there is a lot of debugging information to print out, this identification string can be convenient for us to locate the problem in many console output.

If you want to have debug information assembly Traceback, also want to use the identity string, also can be checkpoint(description, true) implemented, the second parameter true identifies the assembly Traceback to print.

2.7.3 using the log () operator to understand the execution process

The last tool for debugging is the operator we used many times before log() , and it is able to record its upstream flux or Mono events (including,,, and,,, onNext onError onComplete onSubscribe cancel and request ).

logThe SLF4J operator can log logs using public logging tools like log4j and Logback, and output the log directly to the console if the slf4j does not exist.

The console uses System.err logging WARN and ERROR level logs to log other levels using System.out.

(reactor) Debug--Response Spring's Path wizard