Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

How to debug in webflux?

I use Spring Boot 2.1.1.RELEASE with webflux.

Dependencies are like below:

<dependency>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-webflux</artifactId>
</dependency>

Here goes the Controller, I use Hooks.onOperatorDebug(); as reactor's document says it Can open debug mode.

@RestController
public class TestController {
    @GetMapping("/test")
    public Mono test(String a) {
        Hooks.onOperatorDebug();
        return Mono.just("test1")
                .map(t -> t + "test2")
                .zipWith(Mono.error(() -> new IllegalArgumentException("error")));
    }

    @PostMapping("/test")
    public Mono post(@RequestBody Req req) {
        return Mono.just(req);
    }
}

class Req {
    private String a;
    private String b;

    public String getA() {
        return a;
    }

    public void setA(String a) {
        this.a = a;
    }

    public String getB() {
        return b;
    }

    public void setB(String b) {
        this.b = b;
    }
}

log level is below:

logging:
  level:
    root: trace

When I call <http://localhost:8080/test> , I Can only get logs like below:

2018-12-10 21:41:17.001 DEBUG 31340 --- [ctor-http-nio-2] r.n.http.server.HttpServerOperations     : [id: 0x7cc865b4, L:/0:0:0:0:0:0:0:1:8080 - R:/0:0:0:0:0:0:0:1:52638] Increasing pending responses, now 1
2018-12-10 21:41:17.001 DEBUG 31340 --- [ctor-http-nio-2] reactor.netty.http.server.HttpServer     : [id: 0x7cc865b4, L:/0:0:0:0:0:0:0:1:8080 - R:/0:0:0:0:0:0:0:1:52638] Handler is being applied: org.springframework.http.server.reactive.ReactorHttpHandlerAdapter@3a0ad630
2018-12-10 21:41:17.002 TRACE 31340 --- [ctor-http-nio-2] o.s.w.s.adapter.HttpWebHandlerAdapter    : [7cc865b4] HTTP GET "/test?a=b", headers={masked}
2018-12-10 21:41:17.002 TRACE 31340 --- [ctor-http-nio-2] o.s.b.f.s.DefaultListableBeanFactory     : Returning cached instance of singleton bean 'testController'
2018-12-10 21:41:17.002 DEBUG 31340 --- [ctor-http-nio-2] s.w.r.r.m.a.RequestMappingHandlerMapping : [7cc865b4] Mapped to public reactor.core.publisher.Mono com.itmuch.webfluxtest.TestController.test(java.lang.String)
2018-12-10 21:41:17.003 DEBUG 31340 --- [ctor-http-nio-2] reactor.core.publisher.Hooks             : Enabling stacktrace debugging via onOperatorDebug
2018-12-10 21:41:17.003 DEBUG 31340 --- [ctor-http-nio-2] reactor.core.publisher.Hooks             : Hooking onEachOperator: onOperatorDebug
2018-12-10 21:41:17.003 DEBUG 31340 --- [ctor-http-nio-2] o.s.w.r.r.m.a.ResponseBodyResultHandler  : Using 'application/json;charset=UTF-8;q=0.8' given [text/html, application/xhtml+xml, image/webp, image/apng, application/xml;q=0.9, */*;q=0.8] and supported [application/json;charset=UTF-8, application/*+json;charset=UTF-8, text/event-stream]
2018-12-10 21:41:17.003 DEBUG 31340 --- [ctor-http-nio-2] o.s.w.r.r.m.a.ResponseBodyResultHandler  : [7cc865b4] 0..1 [?]
2018-12-10 21:41:17.008 TRACE 31340 --- [ctor-http-nio-2] o.s.w.r.function.server.RouterFunctions  : [7cc865b4] Matched org.springframework.boot.autoconfigure.web.reactive.error.DefaultErrorWebExceptionHandler$$Lambda$520/509612428@4c3d17a7
2018-12-10 21:41:17.009 TRACE 31340 --- [ctor-http-nio-2] o.s.c.e.PropertySourcesPropertyResolver  : Searching for key 'spring.template.provider.cache' in PropertySource 'server.ports'
2018-12-10 21:41:17.009 TRACE 31340 --- [ctor-http-nio-2] o.s.c.e.PropertySourcesPropertyResolver  : Searching for key 'spring.template.provider.cache' in PropertySource 'configurationProperties'
2018-12-10 21:41:17.009 TRACE 31340 --- [ctor-http-nio-2] o.s.c.e.PropertySourcesPropertyResolver  : Searching for key 'spring.template.provider.cache' in PropertySource 'systemProperties'
2018-12-10 21:41:17.009 TRACE 31340 --- [ctor-http-nio-2] o.s.c.e.PropertySourcesPropertyResolver  : Searching for key 'spring.template.provider.cache' in PropertySource 'systemEnvironment'
2018-12-10 21:41:17.009 TRACE 31340 --- [ctor-http-nio-2] o.s.c.e.PropertySourcesPropertyResolver  : Searching for key 'spring.template.provider.cache' in PropertySource 'random'
2018-12-10 21:41:17.009 TRACE 31340 --- [ctor-http-nio-2] o.s.c.e.PropertySourcesPropertyResolver  : Searching for key 'spring.template.provider.cache' in PropertySource 'applicationConfig: [classpath:/application.yml]'
2018-12-10 21:41:17.009 TRACE 31340 --- [ctor-http-nio-2] o.s.c.e.PropertySourcesPropertyResolver  : Could not find key 'spring.template.provider.cache' in any property source
2018-12-10 21:41:17.009 TRACE 31340 --- [ctor-http-nio-2] o.s.c.e.PropertySourcesPropertyResolver  : Searching for key 'spring.template.provider.cache' in PropertySource 'server.ports'
2018-12-10 21:41:17.009 TRACE 31340 --- [ctor-http-nio-2] o.s.c.e.PropertySourcesPropertyResolver  : Searching for key 'spring.template.provider.cache' in PropertySource 'configurationProperties'
2018-12-10 21:41:17.009 TRACE 31340 --- [ctor-http-nio-2] o.s.c.e.PropertySourcesPropertyResolver  : Searching for key 'spring.template.provider.cache' in PropertySource 'systemProperties'
2018-12-10 21:41:17.009 TRACE 31340 --- [ctor-http-nio-2] o.s.c.e.PropertySourcesPropertyResolver  : Searching for key 'spring.template.provider.cache' in PropertySource 'systemEnvironment'
2018-12-10 21:41:17.009 TRACE 31340 --- [ctor-http-nio-2] o.s.c.e.PropertySourcesPropertyResolver  : Searching for key 'spring.template.provider.cache' in PropertySource 'random'
2018-12-10 21:41:17.009 TRACE 31340 --- [ctor-http-nio-2] o.s.c.e.PropertySourcesPropertyResolver  : Searching for key 'spring.template.provider.cache' in PropertySource 'applicationConfig: [classpath:/application.yml]'
2018-12-10 21:41:17.010 TRACE 31340 --- [ctor-http-nio-2] o.s.c.e.PropertySourcesPropertyResolver  : Could not find key 'spring.template.provider.cache' in any property source
2018-12-10 21:41:17.010 TRACE 31340 --- [ctor-http-nio-2] o.s.c.e.PropertySourcesPropertyResolver  : Searching for key 'spring.template.provider.cache' in PropertySource 'server.ports'
2018-12-10 21:41:17.010 TRACE 31340 --- [ctor-http-nio-2] o.s.c.e.PropertySourcesPropertyResolver  : Searching for key 'spring.template.provider.cache' in PropertySource 'configurationProperties'
2018-12-10 21:41:17.010 TRACE 31340 --- [ctor-http-nio-2] o.s.c.e.PropertySourcesPropertyResolver  : Searching for key 'spring.template.provider.cache' in PropertySource 'systemProperties'
2018-12-10 21:41:17.010 TRACE 31340 --- [ctor-http-nio-2] o.s.c.e.PropertySourcesPropertyResolver  : Searching for key 'spring.template.provider.cache' in PropertySource 'systemEnvironment'
2018-12-10 21:41:17.010 TRACE 31340 --- [ctor-http-nio-2] o.s.c.e.PropertySourcesPropertyResolver  : Searching for key 'spring.template.provider.cache' in PropertySource 'random'
2018-12-10 21:41:17.010 TRACE 31340 --- [ctor-http-nio-2] o.s.c.e.PropertySourcesPropertyResolver  : Searching for key 'spring.template.provider.cache' in PropertySource 'applicationConfig: [classpath:/application.yml]'
2018-12-10 21:41:17.010 TRACE 31340 --- [ctor-http-nio-2] o.s.c.e.PropertySourcesPropertyResolver  : Could not find key 'spring.template.provider.cache' in any property source
2018-12-10 21:41:17.010 DEBUG 31340 --- [ctor-http-nio-2] .a.w.r.e.DefaultErrorWebExceptionHandler : [7cc865b4] Resolved [IllegalArgumentException: error] for HTTP GET /test
2018-12-10 21:41:17.011 TRACE 31340 --- [ctor-http-nio-2] o.s.core.codec.CharSequenceEncoder       : [7cc865b4] Writing "<html><body><h1>Whitelabel Error Page</h1><p>This application has no configured error view, so you are seeing this as a fallback.</p><div id='created'>Mon Dec 10 21:41:17 CST 2018</div><div>There was an unexpected error (type=Internal Server Error, status=500).</div><div>error</div></body></html>"
2018-12-10 21:41:17.011 DEBUG 31340 --- [ctor-http-nio-2] r.n.channel.ChannelOperationsHandler     : [id: 0x7cc865b4, L:/0:0:0:0:0:0:0:1:8080 - R:/0:0:0:0:0:0:0:1:52638] Writing object DefaultHttpResponse(decodeResult: success, version: HTTP/1.1)
HTTP/1.1 500 Internal Server Error
Content-Type: text/html
Content-Length: 297
2018-12-10 21:41:17.011 DEBUG 31340 --- [ctor-http-nio-2] r.n.channel.ChannelOperationsHandler     : [id: 0x7cc865b4, L:/0:0:0:0:0:0:0:1:8080 - R:/0:0:0:0:0:0:0:1:52638] Writing object 
2018-12-10 21:41:17.011 TRACE 31340 --- [ctor-http-nio-2] r.n.channel.ChannelOperationsHandler     : [id: 0x7cc865b4, L:/0:0:0:0:0:0:0:1:8080 - R:/0:0:0:0:0:0:0:1:52638] Pending write size = 297
2018-12-10 21:41:17.012 TRACE 31340 --- [ctor-http-nio-2] o.s.w.s.adapter.HttpWebHandlerAdapter    : [7cc865b4] Completed 500 INTERNAL_SERVER_ERROR, headers={masked}
2018-12-10 21:41:17.012 TRACE 31340 --- [ctor-http-nio-2] o.s.h.s.r.ReactorHttpHandlerAdapter      : [7cc865b4] Handling completed
2018-12-10 21:41:17.012 DEBUG 31340 --- [ctor-http-nio-2] r.n.http.server.HttpServerOperations     : [id: 0x7cc865b4, L:/0:0:0:0:0:0:0:1:8080 - R:/0:0:0:0:0:0:0:1:52638] Last HTTP response frame
2018-12-10 21:41:17.012 DEBUG 31340 --- [ctor-http-nio-2] r.n.channel.ChannelOperationsHandler     : [id: 0x7cc865b4, L:/0:0:0:0:0:0:0:1:8080 - R:/0:0:0:0:0:0:0:1:52638] Writing object EmptyLastHttpContent
2018-12-10 21:41:17.012 DEBUG 31340 --- [ctor-http-nio-2] r.n.http.server.HttpServerOperations     : [id: 0x7cc865b4, L:/0:0:0:0:0:0:0:1:8080 - R:/0:0:0:0:0:0:0:1:52638] Decreasing pending responses, now 0
2018-12-10 21:41:17.013 TRACE 31340 --- [ctor-http-nio-2] reactor.netty.channel.ChannelOperations  : [id: 0x7cc865b4, L:/0:0:0:0:0:0:0:1:8080 - R:/0:0:0:0:0:0:0:1:52638] Disposing ChannelOperation from a channel

java.lang.Exception: ChannelOperation terminal stack
    at reactor.netty.channel.ChannelOperations.terminate(ChannelOperations.java:363) [reactor-netty-0.8.3.RELEASE.jar:0.8.3.RELEASE]
    at reactor.netty.http.server.HttpServerOperations.cleanHandlerTerminate(HttpServerOperations.java:509) [reactor-netty-0.8.3.RELEASE.jar:0.8.3.RELEASE]
    at reactor.netty.http.server.HttpTrafficHandler.operationComplete(HttpTrafficHandler.java:297) [reactor-netty-0.8.3.RELEASE.jar:0.8.3.RELEASE]
    at reactor.netty.http.server.HttpTrafficHandler.operationComplete(HttpTrafficHandler.java:54) [reactor-netty-0.8.3.RELEASE.jar:0.8.3.RELEASE]
    at io.netty.util.concurrent.DefaultPromise.notifyListener0(DefaultPromise.java:511) [netty-common-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.util.concurrent.DefaultPromise.notifyListenersNow(DefaultPromise.java:485) [netty-common-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.util.concurrent.DefaultPromise.notifyListeners(DefaultPromise.java:424) [netty-common-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.util.concurrent.DefaultPromise.trySuccess(DefaultPromise.java:103) [netty-common-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.util.internal.PromiseNotificationUtil.trySuccess(PromiseNotificationUtil.java:48) [netty-common-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.channel.ChannelOutboundBuffer.safeSuccess(ChannelOutboundBuffer.java:696) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.channel.ChannelOutboundBuffer.remove(ChannelOutboundBuffer.java:258) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.channel.nio.AbstractNioByteChannel.doWriteInternal(AbstractNioByteChannel.java:216) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.channel.nio.AbstractNioByteChannel.doWrite0(AbstractNioByteChannel.java:209) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.channel.socket.nio.NioSocketChannel.doWrite(NioSocketChannel.java:397) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.channel.AbstractChannel$AbstractUnsafe.flush0(AbstractChannel.java:934) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.flush0(AbstractNioChannel.java:360) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.channel.AbstractChannel$AbstractUnsafe.flush(AbstractChannel.java:901) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.channel.DefaultChannelPipeline$HeadContext.flush(DefaultChannelPipeline.java:1396) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:776) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.channel.AbstractChannelHandlerContext.invokeFlush(AbstractChannelHandlerContext.java:768) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.channel.AbstractChannelHandlerContext.flush(AbstractChannelHandlerContext.java:749) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.channel.CombinedChannelDuplexHandler$DelegatingChannelHandlerContext.flush(CombinedChannelDuplexHandler.java:533) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.channel.ChannelOutboundHandlerAdapter.flush(ChannelOutboundHandlerAdapter.java:115) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.channel.CombinedChannelDuplexHandler.flush(CombinedChannelDuplexHandler.java:358) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:776) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.channel.AbstractChannelHandlerContext.invokeFlush(AbstractChannelHandlerContext.java:768) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.channel.AbstractChannelHandlerContext.flush(AbstractChannelHandlerContext.java:749) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.channel.ChannelDuplexHandler.flush(ChannelDuplexHandler.java:117) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:776) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.channel.AbstractChannelHandlerContext.invokeFlush(AbstractChannelHandlerContext.java:768) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.channel.AbstractChannelHandlerContext.flush(AbstractChannelHandlerContext.java:749) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at reactor.netty.channel.ChannelOperationsHandler.doWrite(ChannelOperationsHandler.java:283) [reactor-netty-0.8.3.RELEASE.jar:0.8.3.RELEASE]
    at reactor.netty.channel.ChannelOperationsHandler.drain(ChannelOperationsHandler.java:465) [reactor-netty-0.8.3.RELEASE.jar:0.8.3.RELEASE]
    at reactor.netty.channel.ChannelOperationsHandler.flush(ChannelOperationsHandler.java:194) [reactor-netty-0.8.3.RELEASE.jar:0.8.3.RELEASE]
    at io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:776) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.channel.AbstractChannelHandlerContext.invokeWriteAndFlush(AbstractChannelHandlerContext.java:802) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.channel.AbstractChannelHandlerContext.write(AbstractChannelHandlerContext.java:814) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.channel.AbstractChannelHandlerContext.writeAndFlush(AbstractChannelHandlerContext.java:794) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.channel.AbstractChannelHandlerContext.writeAndFlush(AbstractChannelHandlerContext.java:837) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.channel.DefaultChannelPipeline.writeAndFlush(DefaultChannelPipeline.java:1071) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.channel.AbstractChannel.writeAndFlush(AbstractChannel.java:300) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at reactor.netty.http.server.HttpServerOperations.onOutboundComplete(HttpServerOperations.java:487) [reactor-netty-0.8.3.RELEASE.jar:0.8.3.RELEASE]
    at reactor.netty.channel.ChannelOperations.onComplete(ChannelOperations.java:191) [reactor-netty-0.8.3.RELEASE.jar:0.8.3.RELEASE]
    at reactor.core.publisher.FluxOnAssembly$OnAssemblySubscriber.onComplete(FluxOnAssembly.java:383) [reactor-core-3.2.3.RELEASE.jar:3.2.3.RELEASE]
    at reactor.core.publisher.MonoPeekTerminal$MonoTerminalPeekSubscriber.onComplete(MonoPeekTerminal.java:321) [reactor-core-3.2.3.RELEASE.jar:3.2.3.RELEASE]
    at reactor.core.publisher.FluxOnAssembly$OnAssemblySubscriber.onComplete(FluxOnAssembly.java:383) [reactor-core-3.2.3.RELEASE.jar:3.2.3.RELEASE]
    at reactor.core.publisher.FluxPeekFuseable$PeekFuseableConditionalSubscriber.onComplete(FluxPeekFuseable.java:578) [reactor-core-3.2.3.RELEASE.jar:3.2.3.RELEASE]
    at reactor.core.publisher.FluxOnAssembly$OnAssemblySubscriber.onComplete(FluxOnAssembly.java:383) [reactor-core-3.2.3.RELEASE.jar:3.2.3.RELEASE]
    at reactor.core.publisher.Operators$MonoSubscriber.onComplete(Operators.java:1516) [reactor-core-3.2.3.RELEASE.jar:3.2.3.RELEASE]
    at reactor.core.publisher.MonoIgnoreThen$ThenAcceptInner.onComplete(MonoIgnoreThen.java:314) [reactor-core-3.2.3.RELEASE.jar:3.2.3.RELEASE]
    at reactor.core.publisher.FluxOnAssembly$OnAssemblySubscriber.onComplete(FluxOnAssembly.java:383) [reactor-core-3.2.3.RELEASE.jar:3.2.3.RELEASE]
    at reactor.core.publisher.Operators.complete(Operators.java:131) [reactor-core-3.2.3.RELEASE.jar:3.2.3.RELEASE]
    at reactor.core.publisher.MonoEmpty.subscribe(MonoEmpty.java:45) [reactor-core-3.2.3.RELEASE.jar:3.2.3.RELEASE]
    at reactor.core.publisher.MonoDefer.subscribe(MonoDefer.java:52) [reactor-core-3.2.3.RELEASE.jar:3.2.3.RELEASE]
    at reactor.core.publisher.MonoOnAssembly.subscribe(MonoOnAssembly.java:76) [reactor-core-3.2.3.RELEASE.jar:3.2.3.RELEASE]
    at reactor.core.publisher.MonoIgnoreThen$ThenIgnoreMain.drain(MonoIgnoreThen.java:153) [reactor-core-3.2.3.RELEASE.jar:3.2.3.RELEASE]
    at reactor.core.publisher.MonoIgnoreThen.subscribe(MonoIgnoreThen.java:56) [reactor-core-3.2.3.RELEASE.jar:3.2.3.RELEASE]
    at reactor.core.publisher.MonoOnAssembly.subscribe(MonoOnAssembly.java:71) [reactor-core-3.2.3.RELEASE.jar:3.2.3.RELEASE]
    at reactor.core.publisher.MonoPeekFuseable.subscribe(MonoPeekFuseable.java:70) [reactor-core-3.2.3.RELEASE.jar:3.2.3.RELEASE]
    at reactor.core.publisher.MonoOnAssembly.subscribe(MonoOnAssembly.java:71) [reactor-core-3.2.3.RELEASE.jar:3.2.3.RELEASE]
    at reactor.core.publisher.MonoPeekTerminal.subscribe(MonoPeekTerminal.java:61) [reactor-core-3.2.3.RELEASE.jar:3.2.3.RELEASE]
    at reactor.core.publisher.MonoOnAssembly.subscribe(MonoOnAssembly.java:76) [reactor-core-3.2.3.RELEASE.jar:3.2.3.RELEASE]
    at reactor.netty.http.server.HttpServerHandle.onStateChange(HttpServerHandle.java:64) [reactor-netty-0.8.3.RELEASE.jar:0.8.3.RELEASE]
    at reactor.netty.tcp.TcpServerBind$ChildObserver.onStateChange(TcpServerBind.java:226) [reactor-netty-0.8.3.RELEASE.jar:0.8.3.RELEASE]
    at reactor.netty.http.server.HttpServerOperations.onInboundNext(HttpServerOperations.java:434) [reactor-netty-0.8.3.RELEASE.jar:0.8.3.RELEASE]
    at reactor.netty.channel.ChannelOperationsHandler.channelRead(ChannelOperationsHandler.java:141) [reactor-netty-0.8.3.RELEASE.jar:0.8.3.RELEASE]
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at reactor.netty.http.server.HttpTrafficHandler.channelRead(HttpTrafficHandler.java:159) [reactor-netty-0.8.3.RELEASE.jar:0.8.3.RELEASE]
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.channel.CombinedChannelDuplexHandler$DelegatingChannelHandlerContext.fireChannelRead(CombinedChannelDuplexHandler.java:438) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:323) [netty-codec-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:297) [netty-codec-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.channel.CombinedChannelDuplexHandler.channelRead(CombinedChannelDuplexHandler.java:253) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1434) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:965) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:163) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:648) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:583) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:500) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:462) [netty-transport-4.1.31.Final.jar:4.1.31.Final]
    at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:897) [netty-common-4.1.31.Final.jar:4.1.31.Final]
    at java.lang.Thread.run(Thread.java:748) [na:1.8.0_192]

2018-12-10 21:41:17.013 DEBUG 31340 --- [ctor-http-nio-2] r.n.channel.ChannelOperationsHandler     : [id: 0x7cc865b4, L:/0:0:0:0:0:0:0:1:8080 - R:/0:0:0:0:0:0:0:1:52638] No ChannelOperation attached. Dropping: EmptyLastHttpContent

The reactor's debug mode is not been actived.

So I wonder How to debug in spring webflux?Or is there anyway help us find errors in our code quickly?

like image 203
eacdy Avatar asked Dec 10 '18 13:12

eacdy


1 Answers

In reactor, Hooks.onOperatorDebug() instruments the Reactor operators to collect more information about the current stack during the execution. This has a performance cost, and should not be done in production. This is a static call that needs to be done only once per JVM execution, so no need to repeat it for every controller call. With Spring Boot, this is done automatically for you is you have the spring-boot-devtools dependency on classpath.

Since Spring Boot 2.1, you can get better logs for web-related operations by setting to DEBUG the web logging group, so logging.level.web=debug. This will log useful information about web requests processing.

In your case, you seem also to be missing information about the execution of the Reactor pipeline. In this case, you should add log() operators in your pipeline to understand what signals are going through your pipeline.

In this particular code snippet, I'm seeing several things:

  • the String a method parameter seems odd since it's not coupled with an annotation that fetches data from the incoming request such as @RequestParam
  • the Mono.zipWith(Mono) operator doesn't make sense here; the result will always be an error signal with an IllegalArgumentException. So it is expected for the Spring Boot error handling to process that exception and render an HTML error page
like image 161
Brian Clozel Avatar answered Oct 27 '22 14:10

Brian Clozel