[Bug] Description traceId cannot be obtained in webflux when an active throw exception occurs #12679

LikeRainDay · 2024-10-08T07:08:38Z

LikeRainDay
Oct 8, 2024

Search before asking

I had searched in the issues and found no similar issues.

Apache SkyWalking Component

Java Agent (apache/skywalking-java)

What happened

The interface is as follows. When I made the call, I found that I could not print the traceId.

    @GetMapping("/error_speech")
    public Mono<R<String>> errorSpeech() {
        final String s = TraceContext.traceId();
        log.info("test--error_speech : {}", s);
        return Mono.error(new RuntimeException("error"));
    }
}

The error log is as follows

2024-10-08 14:49:32.672 TID:N/A ERROR 18105 --- [ctor-http-nio-2] c.p.c.e.w.GlobalExceptionController      : 全局异常捕获:error

java.lang.RuntimeException: error
	at com.pkulaw.common.demo.tools.controller.TestController.$sw$original$errorSpeech$8f81qc3(TestController.java:29)
	Suppressed: reactor.core.publisher.FluxOnAssembly$OnAssemblyException: 
Assembly trace from producer [reactor.core.publisher.MonoError] :
	reactor.core.publisher.Mono.error(Mono.java:299)
	com.pkulaw.common.demo.tools.controller.TestController.$sw$original$errorSpeech$8f81qc3(TestController.java:29)
Error has been observed at the following site(s):
	*____________Mono.error ⇢ at com.pkulaw.common.demo.tools.controller.TestController.$sw$original$errorSpeech$8f81qc3(TestController.java:29)
	|_             Mono.map ⇢ at org.springframework.http.codec.json.AbstractJackson2Encoder.lambda$encode$7(AbstractJackson2Encoder.java:158)
	|_            Mono.flux ⇢ at org.springframework.http.codec.json.AbstractJackson2Encoder.lambda$encode$7(AbstractJackson2Encoder.java:159)
	*__Flux.deferContextual ⇢ at org.springframework.http.codec.json.AbstractJackson2Encoder.encode(AbstractJackson2Encoder.java:151)
	|_   Flux.singleOrEmpty ⇢ at org.springframework.http.codec.EncoderHttpMessageWriter.write(EncoderHttpMessageWriter.java:128)
	|_   Mono.switchIfEmpty ⇢ at org.springframework.http.codec.EncoderHttpMessageWriter.write(EncoderHttpMessageWriter.java:129)
	|_         Mono.flatMap ⇢ at org.springframework.http.codec.EncoderHttpMessageWriter.write(EncoderHttpMessageWriter.java:133)
	|_     Mono.doOnDiscard ⇢ at org.springframework.http.codec.EncoderHttpMessageWriter.write(EncoderHttpMessageWriter.java:139)
	|_           checkpoint ⇢ Handler com.pkulaw.common.demo.tools.controller.TestController#errorSpeech() [DispatcherHandler]
Original Stack Trace:
		at com.pkulaw.common.demo.tools.controller.TestController.$sw$original$errorSpeech$8f81qc3(TestController.java:29)
		at com.pkulaw.common.demo.tools.controller.TestController.$sw$original$errorSpeech$8f81qc3$accessor$$sw$c3c0952(TestController.java)
		at com.pkulaw.common.demo.tools.controller.TestController$$sw$auxiliary$4fg6ss1.call(Unknown Source)
		at org.apache.skywalking.apm.agent.core.plugin.interceptor.enhance.InstMethodsInter.intercept(InstMethodsInter.java:86)
		at com.pkulaw.common.demo.tools.controller.TestController.errorSpeech(TestController.java)
		at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
		at java.base/java.lang.reflect.Method.invoke(Method.java:580)
		at org.springframework.web.reactive.result.method.InvocableHandlerMethod.lambda$invoke$0(InvocableHandlerMethod.java:198)
		at reactor.core.publisher.FluxFlatMap.trySubscribeScalarMap(FluxFlatMap.java:153)
		at reactor.core.publisher.MonoFlatMap.subscribeOrReturn(MonoFlatMap.java:53)
		at reactor.core.publisher.InternalMonoOperator.subscribe(InternalMonoOperator.java:63)
		at reactor.core.publisher.MonoDefer.subscribe(MonoDefer.java:53)
		at reactor.core.publisher.InternalMonoOperator.subscribe(InternalMonoOperator.java:76)
		at reactor.core.publisher.MonoIgnoreThen$ThenIgnoreMain.subscribeNext(MonoIgnoreThen.java:241)
		at reactor.core.publisher.MonoIgnoreThen$ThenIgnoreMain.onComplete(MonoIgnoreThen.java:204)
		at reactor.core.publisher.MonoFlatMap$FlatMapMain.onComplete(MonoFlatMap.java:189)
		at reactor.core.publisher.Operators.complete(Operators.java:137)
		at reactor.core.publisher.MonoZip.subscribe(MonoZip.java:121)
		at reactor.core.publisher.Mono.subscribe(Mono.java:4568)
		at reactor.core.publisher.MonoIgnoreThen$ThenIgnoreMain.subscribeNext(MonoIgnoreThen.java:265)
		at reactor.core.publisher.MonoIgnoreThen.subscribe(MonoIgnoreThen.java:51)
		at reactor.core.publisher.InternalMonoOperator.subscribe(InternalMonoOperator.java:76)
		at reactor.core.publisher.MonoFlatMap$FlatMapMain.onNext(MonoFlatMap.java:165)
		at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onNext(FluxOnErrorResume.java:79)
		at reactor.core.publisher.FluxSwitchIfEmpty$SwitchIfEmptySubscriber.onNext(FluxSwitchIfEmpty.java:74)
		at reactor.core.publisher.MonoNext$NextSubscriber.onNext(MonoNext.java:82)
		at reactor.core.publisher.FluxConcatMapNoPrefetch$FluxConcatMapNoPrefetchSubscriber.innerNext(FluxConcatMapNoPrefetch.java:259)
		at reactor.core.publisher.FluxConcatMap$ConcatMapInner.onNext(FluxConcatMap.java:865)
		at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onNext(FluxMapFuseable.java:129)
		at reactor.core.publisher.MonoPeekTerminal$MonoTerminalPeekSubscriber.onNext(MonoPeekTerminal.java:180)
		at reactor.core.publisher.Operators$ScalarSubscription.request(Operators.java:2571)
		at reactor.core.publisher.MonoPeekTerminal$MonoTerminalPeekSubscriber.request(MonoPeekTerminal.java:139)
		at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.request(FluxMapFuseable.java:171)
		at reactor.core.publisher.Operators$MultiSubscriptionSubscriber.request(Operators.java:2331)
		at reactor.core.publisher.FluxConcatMapNoPrefetch$FluxConcatMapNoPrefetchSubscriber.request(FluxConcatMapNoPrefetch.java:339)
		at reactor.core.publisher.MonoNext$NextSubscriber.request(MonoNext.java:108)
		at reactor.core.publisher.Operators$MultiSubscriptionSubscriber.set(Operators.java:2367)
		at reactor.core.publisher.Operators$MultiSubscriptionSubscriber.onSubscribe(Operators.java:2241)
		at reactor.core.publisher.MonoNext$NextSubscriber.onSubscribe(MonoNext.java:70)
		at reactor.core.publisher.FluxConcatMapNoPrefetch$FluxConcatMapNoPrefetchSubscriber.onSubscribe(FluxConcatMapNoPrefetch.java:164)
		at reactor.core.publisher.FluxIterable.subscribe(FluxIterable.java:201)
		at reactor.core.publisher.FluxIterable.subscribe(FluxIterable.java:83)
		at reactor.core.publisher.InternalMonoOperator.subscribe(InternalMonoOperator.java:76)
		at reactor.core.publisher.MonoDefer.subscribe(MonoDefer.java:53)
		at reactor.core.publisher.InternalMonoOperator.subscribe(InternalMonoOperator.java:76)
		at reactor.core.publisher.MonoDefer.subscribe(MonoDefer.java:53)
		at reactor.core.publisher.Mono.subscribe(Mono.java:4568)
		at reactor.core.publisher.MonoIgnoreThen$ThenIgnoreMain.subscribeNext(MonoIgnoreThen.java:265)
		at reactor.core.publisher.MonoIgnoreThen.subscribe(MonoIgnoreThen.java:51)
		at reactor.core.publisher.Mono.subscribe(Mono.java:4568)
		at reactor.core.publisher.MonoIgnoreThen$ThenIgnoreMain.subscribeNext(MonoIgnoreThen.java:265)
		at reactor.core.publisher.MonoIgnoreThen.subscribe(MonoIgnoreThen.java:51)
		at reactor.core.publisher.InternalMonoOperator.subscribe(InternalMonoOperator.java:76)
		at reactor.core.publisher.MonoDeferContextual.subscribe(MonoDeferContextual.java:55)
		at reactor.core.publisher.InternalMonoOperator.subscribe(InternalMonoOperator.java:76)
		at reactor.netty.http.server.HttpServer$HttpServerHandle.onStateChange(HttpServer.java:1176)
		at reactor.netty.ReactorNetty$CompositeConnectionObserver.onStateChange(ReactorNetty.java:715)
		at reactor.netty.transport.ServerTransport$ChildObserver.onStateChange(ServerTransport.java:481)
		at reactor.netty.http.server.HttpServerOperations.onInboundNext(HttpServerOperations.java:781)
		at reactor.netty.channel.ChannelOperationsHandler.channelRead(ChannelOperationsHandler.java:115)
		at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444)
		at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
		at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412)
		at reactor.netty.http.server.HttpTrafficHandler.channelRead(HttpTrafficHandler.java:259)
		at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:442)
		at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
		at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412)
		at io.netty.channel.CombinedChannelDuplexHandler$DelegatingChannelHandlerContext.fireChannelRead(CombinedChannelDuplexHandler.java:436)
		at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:346)
		at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:318)
		at io.netty.channel.CombinedChannelDuplexHandler.channelRead(CombinedChannelDuplexHandler.java:251)
		at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:442)
		at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
		at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412)
		at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1407)
		at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:440)
		at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
		at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:918)
		at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:166)
		at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:788)
		at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:724)
		at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:650)
		at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:562)
		at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:994)
		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:1583

What you expected to happen

Whether the java agent does not support webflux sufficiently to print traceids at error points

How to reproduce

The dependencies are as follows. The springboot version is 3.3.2

    api 'org.apache.skywalking:apm-toolkit-logback-1.x:9.3.0'
    api 'org.apache.skywalking:apm-toolkit-trace:9.3.0'
    api 'org.springframework.boot:spring-boot-starter-webflux'

The test demo is as follows: A traceId cannot be printed in logback and a global exception is found that TraceContext.traceId() is N/A


@Slf4j
@RestController
@RequestMapping("/test")
public class TestController {

    @GetMapping("/tts")
    public Mono<String> textToSpeech() {
        final String s = TraceContext.traceId();
        log.info("test--tts : {}", s);
        throw new RuntimeException("test");
    }

}

Anything else

No response

Are you willing to submit a pull request to fix on your own?

Yes I am willing to submit a pull request on my own!

Code of Conduct

I agree to follow this project's Code of Conduct

wu-sheng · 2024-10-08T07:22:34Z

wu-sheng
Oct 8, 2024
Collaborator

https://skywalking.apache.org/docs/skywalking-java/latest/en/setup/service-agent/java-agent/application-toolkit-webflux/

Do you follow the docs? I don't think your way is correct.

0 replies

LikeRainDay · 2024-10-08T07:55:09Z

LikeRainDay
Oct 8, 2024
Author

I've seen this documentation, but it's mostly a manual scheme that keeps tracking from the client. Because my entry is the current controller. I tried to use webfilter for pre-filtering, but traceId was not generated for this stage. No traceId is printed in mdc when I throw a runtime exception. I hope there is a demo that can handle webflux exceptions for your reference. @wu-sheng

1 reply

wu-sheng Oct 8, 2024
Collaborator

If you are not typically like we provided, then we don't have experience about that.

Generally, async thread needs extra process.

LikeRainDay · 2024-10-08T08:00:38Z

LikeRainDay
Oct 8, 2024
Author

Expect TID to print normally and be captured globally when an exception is thrown.

2024-10-08 14:49:32.672 TID:N/A ERROR 18105 --- [ctor-http-nio-2] c.p.c.e.w.GlobalExceptionController      : 全局异常捕获:error

0 replies

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[Bug] Description traceId cannot be obtained in webflux when an active throw exception occurs #12679

{{title}}

{{editor}}'s edit

{{editor}}'s edit

Replies: 3 comments 1 reply

{{title}}

{{title}}

{{title}}

{{title}}

Select a reply

[Bug] Description traceId cannot be obtained in webflux when an active throw exception occurs #12679

LikeRainDay Oct 8, 2024

Search before asking

Apache SkyWalking Component

What happened

What you expected to happen

How to reproduce

Anything else

Are you willing to submit a pull request to fix on your own?

Code of Conduct

Replies: 3 comments · 1 reply

wu-sheng Oct 8, 2024 Collaborator

LikeRainDay Oct 8, 2024 Author

wu-sheng Oct 8, 2024 Collaborator

LikeRainDay Oct 8, 2024 Author

LikeRainDay
Oct 8, 2024

Replies: 3 comments 1 reply

wu-sheng
Oct 8, 2024
Collaborator

LikeRainDay
Oct 8, 2024
Author

wu-sheng Oct 8, 2024
Collaborator

LikeRainDay
Oct 8, 2024
Author