Skip to content
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

camel-quarkus-opentelemetry gives empty traceId in the logs #33991

Closed
ffbilsel opened this issue Jun 12, 2023 · 7 comments
Closed

camel-quarkus-opentelemetry gives empty traceId in the logs #33991

ffbilsel opened this issue Jun 12, 2023 · 7 comments
Labels

Comments

@ffbilsel
Copy link

ffbilsel commented Jun 12, 2023

Describe the bug

Hello. We use camel kafka quarkus in our project with these dependencies
<dependency> <groupId>org.apache.camel.quarkus</groupId> <artifactId>camel-quarkus-opentelemetry</artifactId> </dependency>
<dependency> <groupId>io.quarkus</groupId> <artifactId>quarkus-opentelemetry</artifactId> </dependency>

And the logger is configured in the application.properties file by this line
%quarkus.log.console.format=%d{HH:mm:ss} %-5p traceId=%X{traceId}, spanId=%X{spanId} [%c{2.}] (%t) %s%e%n

Since I added the camel-quarkus-opentelemetry dependency, I see a trace created when a camel route is triggered (using jaeger). But all the logs that are created has empty traceId and spanId.

Sample code from our apllication :
@ApplicationScoped public class Routes extends RouteBuilder { @Override public void configure() throws Exception { from("kafka:{{kafka.x.in.topic.name}}").routeId("x") .log("Received : \"${body}\"").etc }

Sample output:
12:48:13 INFO traceId=, spanId= [x] (Camel (camel-1) thread #17 - KafkaConsumer[x.topic.in]) Received : "{ "payload": { ... }, "time": "2023-06-05T07:00:07Z" }"

Expected behavior

traceId and spanId fields in the logs should have been filled with the created trace's info such as:
12:48:13 INFO traceId=xyz, spanId=abc [x] (Camel (camel-1) thread #17 - KafkaConsumer[x.topic.in]) Received : "{ "payload": { ... }, "time": "2023-06-05T07:00:07Z" }"

Actual behavior

traceId and spanId fields are empty
12:48:13 INFO traceId=, spanId= [x] (Camel (camel-1) thread #17 - KafkaConsumer[x.topic.in]) Received : "{ "payload": { ... }, "time": "2023-06-05T07:00:07Z" }"

How to Reproduce?

  1. add these dependencies <dependency> <groupId>org.apache.camel.quarkus</groupId> <artifactId>camel-quarkus-opentelemetry</artifactId> </dependency>
    <dependency> <groupId>io.quarkus</groupId> <artifactId>quarkus-opentelemetry</artifactId> </dependency>
  2. add this line to your application properties file %quarkus.log.console.format=%d{HH:mm:ss} %-5p traceId=%X{traceId}, spanId=%X{spanId} [%c{2.}] (%t) %s%e%n
  3. Trigger a camel kafka route

Output of uname -a or ver

No response

Output of java -version

java 17

GraalVM version (if different from Java)

No response

Quarkus version or git rev

quarkus 3.1.1 final

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

mvnw

Additional information

No response

@ffbilsel ffbilsel added the kind/bug Something isn't working label Jun 12, 2023
@quarkus-bot
Copy link

quarkus-bot bot commented Jun 12, 2023

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

@gsmet
Copy link
Member

gsmet commented Jun 13, 2023

@brunobat I let you judge if this should be redirected to the Camel Quarkus project.

@brunobat
Copy link
Contributor

Thanks Guillaume. @ffbilsel after receiving the kafka event, if you create a new span, do those spans get integrated under the same trace or are they split, meaning they look like totally different traces?

@ffbilsel
Copy link
Author

@brunobat It seems the problem was the MDC keys were trace_id & span_id instead of traceId & spanId. So now I can see the traceId and spanId in the logs.
But there is another issue. We also use opentelemetry jdbc dependecy:
<dependency> <groupId>io.opentelemetry.instrumentation</groupId> <artifactId>opentelemetry-jdbc</artifactId> </dependency>.

When a camel route is triggered there are some sql queries that we run. I expect these queries to be shown in the same trace with the camel route. But instead they are in a new and different trace.

@brunobat
Copy link
Contributor

That looks like a context propagation issue to me.
Do you have a sample project?
We have tests on Quarkus proving the OTel context propagation to the JDBC layer. Most likely 'camel-quarkus-opentelemetry' is not propagating the context properly.
Can you please, after the event is received from kafka, can you call another method, annotated with @WithSpan in different service? Just to make sure it will also be split.
If that's the case, you need to report this issue on the camel side.

@ffbilsel
Copy link
Author

ffbilsel commented Jun 13, 2023

Thank you. "Can you please, after the event is received from kafka, can you call another method, annotated with @WithSpan in different service? Just to make sure it will also be split." yes, it is split.

@brunobat
Copy link
Contributor

Will close the issue on this side and will add will help with the camel side.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

3 participants