Search code examples
quarkusjaegeropentracing

Is OpenTracing enabled for Reactive Routes in Quarkus?


I have recently changed my Quarkus application from RestEasy to Reactive Routes to implement my HTTP endpoints.

My Quarkus app had OpenTracing enabled and it was working fine. After changing the HTTP resource layer I can not see any trace in Jaeger.

After setting log level in DEBUG I can see my application is registered in Jaeger but I don't see any traceId or spanId in logs neither traces in Jaeger:

15:44:36 DEBUG traceId=, spanId=, sampled= [io.qu.ja.ru.JaegerDeploymentRecorder] (main) Registering tracer to GlobalTracer JaegerTracer(version=Java-0.34.3, serviceName=employee, reporter=RemoteReporter(sender=HttpSender(), closeEnqueueTimeout=1000), sampler=ConstSampler(decision=true, tags={sampler.type=const, sampler.param=true}), tags={hostname=employee-8569585469-tg8wg, jaeger.version=Java-0.34.3, ip=10.244.0.21}, zipkinSharedRpcSpan=false, expandExceptionLogs=false, useTraceId128Bit=false)
15:45:03 INFO  traceId=, spanId=, sampled= [or.se.po.re.EmployeeResource] (vert.x-eventloop-thread-0) getEmployees

I'm using the latest version of Quarkus which is 1.9.2.Final.

Is it enabled OpenTracing when I'm using Reactive Routes?


Solution

  • Yes, adding @Traced enable to activate tracing on reactive routes.

    Unfortunately, using both JAX-RS reactive and reactive routes bugs the tracing on event-loop threads used by JAX-RS reactive endpoint when they get executed.

    I only started Quarkus 2 days ago so i don't really the reason of this behavior (and whether it's normal or it's a bug), but obviously switching between two completely mess up the tracing.

    Here is an example to easily reproduce it:

    • Create a REST Easy reactive endpoint returning an empty Multi
    • Create a custom reactive route
    • set up the IO threads to 2 (easier to quickly reproduce it)
    • Run the application, and request the two endpoints alternatively

    Here is a screenshot that show the issue enter image description here

    As you can see, as soon as the JAX-RS resource is it and executed on one of the two threads available, it "corrupts" it, messing the trace_id reported (i don't know if it's the generation or the reporting on logs that is broken) on logs for the next calls of the reactive route.

    This does not happen on the JAX-RS resource, as you can notice on the screenshot as well. So it seems to be related to reactive routes only.

    Another point here is the fact that JAX-RS Reactive resources are incorrectly reported on Jaeger. (with a mention to a missing root span) Not sure if it's related to the issue but that's also another annoying point.

    I'm thinking to completely remove the JAX-RS Reactive endpoint and replace them by normal reactive route to eliminate this bug. I would appreciate if someone with more experience than me could verify this or tell me what i did wrong :)

    EDIT 1: I added a route filter with priority 500 to clear the MDC and the bug is still there, so definitely not coming from MDC.

    EDIT 2: I opened a bug report on Quarkus

    EDIT 3: It seems related to how both implementations works (thread locals versus context propagation in actor based context) So, unless JAX-RS reactive resources are marked @Blocking (and get executed in a separated thread pool), JAX-RS reactive and Vertx reactive routes are incompatible when it comes to tracing (but also probably the same for MDC related informations since MDC is also thread related)