search

FrankChen021 / bithon

An observability platform mainly for Java
Apache License 2.0
15 stars 4 forks source link

webflux spans are not collected if upstream connection is broken #588

Closed FrankChen021 closed 1 year ago

FrankChen021 commented 1 year ago 
2023-05-08 22:06:51.747 ERROR 22627 --- [tor-http-nio-10] a.w.r.e.AbstractErrorWebExceptionHandler : [bTxId: 8a1b3c9110b64e45aebcb92a1b1655ff, bSpanId: 5863edb700000343, bMode: T] [70cb4fa0-209]  500 Server Error for HTTP POST "/api/user/register"

io.netty.channel.AbstractChannel$AnnotatedConnectException: Connection refused: localhost/127.0.0.1:29526
    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 "/api/user/register" [ExceptionHandlingWebHandler]
Original Stack Trace:
Caused by: java.net.ConnectException: Connection refused
    at java.base/sun.nio.ch.Net.pollConnect(Native Method) ~[na:na]
    at java.base/sun.nio.ch.Net.pollConnectNow(Net.java:672) ~[na:na]
    at java.base/sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:946) ~[na:na]
    at io.netty.channel.socket.nio.NioSocketChannel.doFinishConnect(NioSocketChannel.java:337) ~[netty-transport-4.1.86.Final.jar:4.1.86.Final]
    at io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.finishConnect(AbstractNioChannel.java:334) ~[netty-transport-4.1.86.Final.jar:4.1.86.Final]
    at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:776) ~[netty-transport-4.1.86.Final.jar:4.1.86.Final]
    at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:724) ~[netty-transport-4.1.86.Final.jar:4.1.86.Final]
    at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:650) ~[netty-transport-4.1.86.Final.jar:4.1.86.Final]
    at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:562) ~[netty-transport-4.1.86.Final.jar:4.1.86.Final]
    at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997) ~[netty-common-4.1.86.Final.jar:4.1.86.Final]
    at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) ~[netty-common-4.1.86.Final.jar:4.1.86.Final]
    at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) ~[netty-common-4.1.86.Final.jar:4.1.86.Final]
    at java.base/java.lang.Thread.run(Thread.java:833) ~[na:na]

2023-05-08 22:06:51.747  WARN 22627 --- [tor-http-nio-10] o.b.a.o.t.context.impl.TracingContext    : [bTxId: 8a1b3c9110b64e45aebcb92a1b1655ff, bSpanId: 58637e5e00000342, bMode: T] TraceContext does not finish correctly. [4] spans are still remained in the stack. Please adding -Dbithon.tracing.debug=true parameter to your application to turn on the span life time message to debug. Remained spans: 
[TraceSpan[name=webflux, traceId=8a1b3c9110b64e45aebcb92a1b1655ff, spanId=5863b76200000340, parentId=null, clazz=org.springframework.http.server.reactive.ReactorHttpHandlerAdapter, method=apply, kind=SERVER, cost=-1683554811745019(micro seconds)], 
TraceSpan[name=filter, traceId=8a1b3c9110b64e45aebcb92a1b1655ff, spanId=5863a3f100000341, parentId=5863b76200000340, clazz=org.springframework.cloud.gateway.filter.AdaptCachedBodyGlobalFilter, method=filter, kind=NONE, cost=4(micro seconds)], 
TraceSpan[name=filter, traceId=8a1b3c9110b64e45aebcb92a1b1655ff, spanId=58637e5e00000342, parentId=5863b76200000340, clazz=org.springframework.cloud.gateway.filter.NettyRoutingFilter, method=filter, kind=NONE, cost=1417(micro seconds)], 
TraceSpan[name=httpclient, traceId=8a1b3c9110b64e45aebcb92a1b1655ff, spanId=5863edb700000343, parentId=58637e5e00000342, clazz=reactor.netty.http.client.HttpClientFinalizer, method=send, kind=CLIENT, cost=675(micro seconds)]]