Skip to content

OpenTelemetry: context of sender not active in consumer #38061

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
computerlove opened this issue Jan 5, 2024 · 12 comments · Fixed by #45683
Closed

OpenTelemetry: context of sender not active in consumer #38061

computerlove opened this issue Jan 5, 2024 · 12 comments · Fixed by #45683
Labels
area/tracing kind/bug Something isn't working
Milestone

Comments

@computerlove
Copy link

Describe the bug

When a @ConsumeEventmethod is executed the OpenTelementry context of the sender is not active.
The result of this is that logging MDC, and further calls do not get a tracing context.
Annotating the method with @WithSpan does activate a context, but it is not based on the existing context.
Stepping though the code I can see that the underlying Vert.x Message does have the existing context stored in the tracefield.

Expected behavior

The Opentelemetry context of message sender is active, a new span is created when @WithSpan is used.

Actual behavior

@WithSpan activates a context, but it is not based on the context of the sender.
Without @WithSpan no context is active, and rest client calls does not get a traceid.

How to Reproduce?

A reproducer: https://github.com/computerlove/quarkus-trace-mdc-eventbus
It creates a Thread that first set up a OpenTracing Context, sends a event bus message, which sends a rest request.

Output of uname -a or ver

na

Output of java -version

21

Quarkus version or git rev

3.6.4

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

No response

Additional information

No response

@computerlove computerlove added the kind/bug Something isn't working label Jan 5, 2024
Copy link

quarkus-bot bot commented Jan 5, 2024

/cc @brunobat (opentelemetry), @radcortez (opentelemetry)

@gian1200
Copy link
Contributor

gian1200 commented Jul 12, 2024

I'm also facing this issue (the other way around,: an HTTP Request that uses EventBus to make it async).

However, I'm not sure if it's a bug or an enhancement request. The docs (here and/or here) says that only http requests are supported for quarkus-vertx.

@thomascube
Copy link

I stumbled upon the same problem. My way to work around it is to pass Context.current() as a field in the EventBus message and extract it in the receiver:

@ConsumeEvent("TEST-EVENT")
public String testEvent(MyEventObj event) {
    try (var _ = event.getOtelContext().makeCurrent()) {
        // do work
    }
}

Would love to have this implicitly done by the EventBus itself.

@VishnuTeja27
Copy link

I faced the same when blocking = true or virtualThread= true.
Existing issue for the same: #41864

@gian1200
Copy link
Contributor

gian1200 commented Mar 28, 2025

Hi, quick question. Was this implementation reverted? I just updated to Quarkus 3.20 (from 3.15) but the traceId is still not visible in the logs (mdc empty).

Code is similar to this:

@Path("/dummyroot")
public class DummyResource {

    private final EventBus eventBus;

    @Inject
    public DummyResource (EventBus eventBus) {
        this.eventBus = eventBus;
    }

    @POST
    @Path("/dummy")
    public Response process(DTO request) {
        // some code
        Log.info("this log has traceId");
        eventBus.send("blocking-dummy-consumer", request);
        // some code
    }

    @ConsumeEvent(value = "blocking-dummy-consumer", blocking = true)
    void consumeBlockingDummyEvent(DTO request) {
        try {
            // some code, including calling method from another injected object
        } catch (Exception e) {
            Log.error("this log doesn't have traceId", e);
        }
    }

}

@brunobat
Copy link
Contributor

@gian1200 are you formating the output log? Trace Ids will not show up by default.
Example:
quarkus.log.console.format=%d{HH:mm:ss} %-5p traceId=%X{traceId}, parentId=%X{parentId}, spanId=%X{spanId}, sampled=%X{sampled} [%c{2.}] (%t) %s%e%n
See: https://quarkus.io/guides/opentelemetry-tracing#create-the-configuration

@gian1200
Copy link
Contributor

On local, yes. We actually do:

quarkus.log.console.format=%d{yyyy-MM-dd HH:mm:ss,SSS} %-5p %X [%c{3.}] (%t) %s%e%n

Example log:

2025-03-28 08:14:45,396 INFO  {sampled=true, spanId=d6e3c8ec40413ab7, traceId=843553e6fabb522b1f09b58033da48d0} [com.xxx.xxx.res.DummyResource] (executor-thread-1) Some random Log with traceId
2025-03-28 08:14:46,130 INFO  {} [com.xxx.xxx.ser.DummyService] (vert.x-worker-thread-1) Starting here there is no mdc info
2025-03-28 08:14:46,132 INFO  {} [comxxx.xxx.ser.ObjectStorageService] (vert.x-worker-thread-1) Log with no mdc info                 
2025-03-28 08:14:48,193 ERROR {} [com.xxx.xxx.res.DummyResource] (vert.x-worker-thread-1) Error log with no mdc info

On cloud we use quarkus-logging-json which shows the same information.

@brunobat
Copy link
Contributor

@gian1200 tracing info needs to be retreived from the MDC context like this:%X{traceId}, parentId=%X{parentId}, spanId=%X{spanId}

@gian1200
Copy link
Contributor

gian1200 commented Mar 28, 2025

@brunobat, thanks for answering. %X prints all the values in the MDC context (https://quarkus.io/guides/logging#logging-format). No need to specify the key.
Notice how the first log from the example has everything from the context info.

{sampled=true, spanId=d6e3c8ec40413ab7, traceId=843553e6fabb522b1f09b58033da48d0}

@brunobat
Copy link
Contributor

Please file an a bug with a reproducer. This issue is closed.

@gian1200
Copy link
Contributor

done #47063

@computerlove
Copy link
Author

I'm pretty sure the reproducer for this issue still reproduces the issue. Meaning that the issue I reported may not really have been fixed.
When the release that contained the commit that closed this issue was released I did try the reproducer and did not get traceid in the event consumer. But did not have time to double check it, and then forgot the issue.

I will try to check my reproducer again.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area/tracing kind/bug Something isn't working
Projects
Status: Done
Development

Successfully merging a pull request may close this issue.

5 participants