FrankChen021 / bithon

An observability platform mainly for Java
Apache License 2.0
16 stars 5 forks source link

unclosed spans in webflux #649

Open FrankChen021 opened 1 year ago

FrankChen021 commented 1 year ago

Might be due to the exception thrown during receiving incoming http

[bTxId: 2c5d2055eb9c43db90adb5fea2959439, bSpanId: 85fa874a1bc6d704, bMode: T] [7576956b-5515] 500 Server Error for HTTP POST "/?default_format=TabSeparatedWithNamesAndTypes&password=HIDDEN"
reactor.netty.channel.AbortedException: Connection has been closed
    at reactor.netty.http.server.HttpServerOperations.onInboundClose(HttpServerOperations.java:587)
    Suppressed: reactor.core.publisher.FluxOnAssembly$OnAssemblyException: 
Error has been observed at the following site(s):
    |_ checkpoint ? org.springframework.cloud.gateway.filter.WeightCalculatorWebFilter [DefaultWebFilterChain]
    |_ checkpoint ? HTTP POST "/?default_format=TabSeparatedWithNamesAndTypes&password=HIDDEN" [ExceptionHandlingWebHandler]
Stack trace:
        at reactor.netty.http.server.HttpServerOperations.onInboundClose(HttpServerOperations.java:587)
        at reactor.netty.channel.ChannelOperationsHandler.channelInactive(ChannelOperationsHandler.java:73)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:262)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:248)
        at io.netty.channel.AbstractChannelHandlerContext.fireChannelInactive(AbstractChannelHandlerContext.java:241)
        at io.netty.channel.CombinedChannelDuplexHandler$DelegatingChannelHandlerContext.fireChannelInactive(CombinedChannelDuplexHandler.java:418)
        at io.netty.handler.codec.ByteToMessageDecoder.channelInputClosed(ByteToMessageDecoder.java:389)
        at io.netty.handler.codec.ByteToMessageDecoder.channelInactive(ByteToMessageDecoder.java:354)
        at io.netty.channel.CombinedChannelDuplexHandler.channelInactive(CombinedChannelDuplexHandler.java:221)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:262)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:248)
        at io.netty.channel.AbstractChannelHandlerContext.fireChannelInactive(AbstractChannelHandlerContext.java:241)
        at io.netty.channel.DefaultChannelPipeline$HeadContext.channelInactive(DefaultChannelPipeline.java:1405)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:262)
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:248)
        at io.netty.channel.DefaultChannelPipeline.fireChannelInactive(DefaultChannelPipeline.java:901)
        at io.netty.channel.AbstractChannel$AbstractUnsafe$8.run(AbstractChannel.java:831)
        at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164)
        at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:469)
        at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:384)
        at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986)
        at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
        at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
        at java.base/java.lang.Thread.run(Thread.java:829)

[bTxId: 2c5d2055eb9c43db90adb5fea2959439, bSpanId: 85fa874a1bc6d704, bMode: T] TraceContext does not finish correctly. [2] spans are still remained unfinished. This IS a bug.
Please adding -Dbithon.tracing.debug=true parameter to your application to turn on the span life time message to debug. 
Remained spans:

[TraceSpan[name=http-server, traceId=2c5d2055eb9c43db90adb5fea2959439, spanId=85fa7cd11bc6d703, parentId=null, clazz=org.springframework.http.server.reactive.ReactorHttpHandlerAdapter, method=apply, kind=SERVER, cost=-1693971705132005(micro seconds), exception=], TraceSpan[name=filter, traceId=2c5d2055eb9c43db90adb5fea2959439, spanId=85fa874a1bc6d704, parentId=85fa7cd11bc6d703, clazz=CacheBodyFilter, method=filter, kind=INTERNAL, cost=-1693971705132130(micro seconds), exception=]]