OpenTelemetry not working with RESTEasy reactive mode

[osbornk]

Describe the bug

I am trying to setup OpenTelementry on two on Kotlin 1.6.10 and Quarkus 2.6.1. I have a trivial application that takes an input and then makes an HTTP call to another endpoint (on the same application).

If I use RESTEasy Reactive with a synchronous function it works fine. I get a full trace from the HTTP end.

Here is my server:

quarkus.opentelemetry.enabled=true 
quarkus.opentelemetry.propagators=b3,b3multi,tracecontext
quarkus.opentelemetry.tracer.sampler=on
quarkus.opentelemetry.tracer.sampler.parent-based=true

@Path("/hello")
class GreetingController(
    private val tracer: Tracer,

    @RestClient
    private val repeaterClient: RepeaterClient
) {
    @Path("sync")
    @POST
    @Produces(MediaType.TEXT_PLAIN)
    fun sync(name: String): String {
        val span = tracer.spanBuilder("inside sync").startSpan()

        try {
            val repeat = repeaterClient.sync(name)
            return "Hello $name $repeat - sync"
        } finally {
            span.end()
        }
    }

    @Path("async")
    @POST
    @Produces(MediaType.TEXT_PLAIN)
    fun async(name: String): Uni<String> {
        val span = tracer.spanBuilder("inside async").startSpan()

        try {
            return repeaterClient.async(name).onItem()
                .transform { repeat -> "Hello $name $repeat - async" } //.await().indefinitely()
        } finally {
            span.end()
        }
    }

    @Path("coroutine")
    @POST
    @Produces(MediaType.TEXT_PLAIN)
    suspend fun coroutine(name: String): String {
        val span = tracer.spanBuilder("inside coroutine").startSpan()

        try {
            val repeat = repeaterClient.coroutine(name)

            return "Hello $name $repeat - coroutine"
        } finally {
            span.end()
        }
    }
}

@Path("/repeat")
@RegisterRestClient(configKey = "repeater-api")
interface RepeaterClient {
    @Path("repeat")
    @POST
    fun sync(repeat: String): String

    @Path("repeat")
    @POST
    fun async(repeat: String): Uni<String>

    @Path("repeat")
    @POST
    suspend fun coroutine(repeat: String): String
}

@Path("repeat")
class RepeaterController(
    private val tracer: Tracer
) {
    @Path("repeat")
    @POST
    @Produces(MediaType.TEXT_PLAIN)
    fun repeat(repeat: String): String {
        val span = tracer.spanBuilder("inside repeat").startSpan()

        try {
            return repeat
        } finally {
            span.end()
        }
    }
}

If I call /hello/sync I get a single trace that includes the original HTTP POST, inside sync, the HTTP repeat client, the HTTP repeat POST server, and inside repeat.

If I call /hello/async, I get three traces. The first trace is a single space of the HTTP POST (hello/async). The second trace is inside async. And the third trace includes 3 spans the HTTP repeat client, the HTTP repeat POST server, and inside repeat

Using /hello/coroutine gave me the exact same results.

I previously tried Quarkus 2.5.x and it gave slightly different results. Instead of three traces, I got two traces. The first two traces were a single trace.

Expected behavior

I expect a single trace.

Actual behavior

My request is split into three different traces.

How to Reproduce?

No response

Output of uname -a or ver

Darwin MacBook-Pro 21.2.0 Darwin Kernel Version 21.2.0: Sun Nov 28 20:28:54 PST 2021; root:xnu-8019.61.5~1/RELEASE_X86_64 x86_64

Output of java -version

openjdk version "17.0.1" 2021-10-19

GraalVM version (if different from Java)

No response

Quarkus version or git rev

2.1.1-final

Build tool (ie. output of mvnw --version or gradlew --version)

Gradle 7.3

Additional information

No response

[quarkus-bot]

/cc @FroMage, @evanchooly, @geoand, @radcortez, @stuartwdouglas

[geoand]

Can you please attach a sample project that exhibits the problematic behavior? It would be a tremendous help...

[osbornk]

Here you go:
https://github.com/osbornk/quarkus-otel

The test instructions are in the README.

An interesting thing I found is that this behavior seems to be specific to posting a HTTP body, such as raw text of JSON. When using query parameters, everything works fine. That is definitely a bit odd, but it is consisytent.

[geoand]

Thanks.

@radcortez I don't see where OTel is integrated with JAX-RS, so I can't really tell what's going on. Do you have any idea?

[radcortez]

Yes. Check the opentelemetry extension and https://github.com/quarkusio/quarkus/blob/57f6a9d9cb288cce2b558d793948b8d0e56ea806/extensions/opentelemetry/opentelemetry/runtime/src/main/java/io/quarkus/opentelemetry/runtime/tracing/vertx/OpenTelemetryVertxTracer.java

Since I have been doing the OTel integration work I can pick this up if you want :)

[geoand]

Since I have been doing the OTel integration work I can pick this up if you want :)

That would probably be best as I don't see any touch points with RESTEasy Reactive :).
FWIW, this looks like some kind of race condition

[osbornk]

Thanks for looking into this and let me know if you need any further information or testing. I am pushing to introduce Quarkus on GraalVM at my company and this is basically the one last unsolved problem. We love OpenTelemetry.

[radcortez]

Just to provide some feedback: I was able to reproduce the issue and found a problem in the way the context is retrieved for certain situations. I'll provide a fix soon.