open-telemetry / opentelemetry-java-instrumentation

OpenTelemetry auto-instrumentation and instrumentation libraries for Java
https://opentelemetry.io
Apache License 2.0
1.79k stars 782 forks source link

Adding AutoConfigurationCustomizerProvider bean breaks trace exporting #11669

Closed apanagiotidis-soundhound closed 2 days ago

apanagiotidis-soundhound commented 5 days ago

Describe the bug I have a Spring Boot application sending traces to Jaeger. I am using opentelemetry-spring-boot-starter and this works as expected, i.e., I can see traces in Jaeger. When I add an AutoConfigurationCustomizerProvider bean (e.g., to add SpanProcessors) then no traces are exported at all.

Steps to reproduce

What did you expect to see? I expect to see spans exported the same way as without a custom AutoConfigurationCustomizerProvider.

What did you see instead? No traces/spans are exported at all.

What version and what artifacts are you using? I am using Maven, my parent project is org.springframework.boot spring-boot-starter-parent 3.3.1.

I have this in dependencyManagement:

These are the relevant dependencies:

Environment Compiler: openjdk 21 2023-09-19 LTS OpenJDK Runtime Environment Temurin-21+35 (build 21+35-LTS) OpenJDK 64-Bit Server VM Temurin-21+35 (build 21+35-LTS, mixed mode)

OS: macOS 14.5

Additional context This repository has a minimal reproducible example: https://github.com/apanagiotidis-soundhound/literate-octo-barnacle

zeitlinger commented 4 days ago

there are wrong dependencies from micrometer, e.g. micrometer-tracing-bridge-otel

Here's what you need: https://opentelemetry.io/docs/zero-code/java/spring-boot-starter/getting-started/

apanagiotidis-soundhound commented 3 days ago

Hi @zeitlinger, thanks for looking into this.

Per your advice I removed all Micrometer dependencies from pom.xml, but the issue persists. I updated the demo repository accordingly, if you want to verify.

I am curious: are you saying that we cannot use Micrometer's dependencies? I am asking because I also tried removing micrometer-tracing-bridge-otel from our actual application, and that breaks tracing across our services, e.g., a downstream service no longer shows up in Jaeger in the same trace, only as separate service in Jaeger. I also noticed that the trace is a lot less detailed without micrometer-tracing-bridge-otel, so we are actually losing quite some information if we need to remove it.

zeitlinger commented 3 days ago

Per your advice I removed all Micrometer dependencies from pom.xml, but the issue persists. I updated the demo repository accordingly, if you want to verify.

I tested with your project - with console exporter: works

2024-06-25T16:24:32.971+02:00  INFO 246515 --- [otel-customizer-demo] [nio-8080-exec-1] i.o.e.logging.LoggingSpanExporter        : 'GET /hello' : dab2bce7c87665e303a06bcb66ffc95f 26986c81b00897e7 SERVER [tracer: io.opentelemetry.spring-webmvc-6.0:2.5.0-alpha] AttributesMap{data={http.request.method=GET, server.port=8080, network.peer.port=54258, network.protocol.version=1.1, http.route=/hello, server.address=localhost, client.address=127.0.0.1, user_agent.original=IntelliJ HTTP Client/IntelliJ IDEA 2024.1.4, http.response.status_code=200, network.peer.address=127.0.0.1, url.path=/hello, url.scheme=http}, capacity=128, totalAddedValues=12}

how I enabled console exporter

Index: src/main/resources/application.yaml
IDEA additional info:
Subsystem: com.intellij.openapi.diff.impl.patch.CharsetEP
<+>UTF-8
===================================================================
diff --git a/src/main/resources/application.yaml b/src/main/resources/application.yaml
--- a/src/main/resources/application.yaml   (revision 4d98220658537d6d8a0127f37daf1b5813451b2d)
+++ b/src/main/resources/application.yaml   (date 1719325373525)
@@ -30,7 +30,7 @@
   sdk:
     disabled: false
   traces:
-    exporter: otlp
+    exporter: console

 logging:
   level:

I am curious: are you saying that we cannot use Micrometer's dependencies?

that is right - see https://github.com/open-telemetry/opentelemetry-java-instrumentation/discussions/11403

I am asking because I also tried removing micrometer-tracing-bridge-otel from our actual application, and that breaks tracing across our services, e.g., a downstream service no longer shows up in Jaeger in the same trace, only as separate service in Jaeger.

looks like an issue with propagators: https://opentelemetry.io/docs/languages/java/configuration/#propagators

I also noticed that the trace is a lot less detailed without micrometer-tracing-bridge-otel, so we are actually losing quite some information if we need to remove it.

see https://github.com/open-telemetry/opentelemetry-java-instrumentation/discussions/11403

if you add more details, I might be able to point out how to configure the feature you're missing (if we have it)

apanagiotidis-soundhound commented 3 days ago

I updated the demo repository to use the console exporter and the issue persists:

To verify this you can un-/comment @Bean in https://github.com/apanagiotidis-soundhound/literate-octo-barnacle/blob/master/src/main/java/otelcustomizer/demo/OpenTelemetryConfiguration.java#L14

looks like an issue with propagators: https://opentelemetry.io/docs/languages/java/configuration/#propagators

Maybe, but the default is w3c (i.e., traceparent and baggage headers) for both Micrometer and OpenTelemetry, so why would that break if we remove Micrometer from the sender?

if you add more details, I might be able to point out how to configure the feature you're missing (if we have it)

I will gather some details and a comparison of the traces to make my use case clearer in a follow-up post.

apanagiotidis-soundhound commented 3 days ago

looks like an issue with propagators: https://opentelemetry.io/docs/languages/java/configuration/#propagators

I verified that the traceparent header is sent with and without Micrometer in the sender; in both they ended in -01, and trace probability is 1.0 on both services.

Without Micrometer in the sender, the receiver seems to still start a new trace.

This might be a different issue unrelated to this ticket though, so I don't want to derail the discussion too much from that.

apanagiotidis-soundhound commented 3 days ago

This is how a trace looks with Micrometer and OpenTelemetry:

trace-with-micrometer

This is the same call without Micrometer, and only OpenTelemetry:

trace-without-mirometer

if you add more details, I might be able to point out how to configure the feature you're missing (if we have it)

I ended up using both Micrometer and OpenTelemetry due to these reasons:

Sorry if this got a bit lengthy; I guess it boils down to OpenTelemetry allowing more/better control of spans but adding a custom SpanProcessor breaks traces, hence this ticket 😅 Note that I did not dig deep into Micrometer for this because it was easier/quicker to find how to mutate spans in OpenTelemetry.

Finally, #11403 seems to highlight differences between Micrometer and OpenTelemetry but it does not explain why they should be used mutually exclusive, so my conclusion is that we can use them together. Since they seem to work together, my assumption was that the issue of this ticket is not due to incompatibility, but I would like to understand this better, if you could elaborate, since this might also prove helpful for others.

laurit commented 3 days ago

@apanagiotidis-soundhound spans are exported using a span processor. Typically there is a BatchSpanProcessor that delegates to the exporter. As far as I can tell by using addSpanProcessorCustomizer you are replacing the span processor that exports the spans with a span processor that doesn't do anything. If you want to add a span processor then try addTracerProviderCustomizer like in https://github.com/open-telemetry/opentelemetry-java-instrumentation/blob/4d6b1cdf3831f16e01e4b4082803e56c2bb11033/examples/extension/src/main/java/com/example/javaagent/DemoAutoConfigurationCustomizerProvider.java#L35

apanagiotidis-soundhound commented 2 days ago

Hey @laurit, thanks for that suggestion. I can confirm that it works, i.e., a SpanProcessor added via addTracerProviderCustomizer is called and the trace is exported (i.e., shows up in Jaeger and console). I also updated the demo repository to verify this.

So it seems addSpanProcessorCustomizer is a bit confusing. The Javadoc states:

Adds a BiFunction to invoke for all autoconfigured io.opentelemetry.sdk.trace.SpanProcessor. The return value of the BiFunction will replace the passed-in argument. In contrast to addSpanExporterCustomizer(BiFunction) this allows modifications to happen before batching occurs. As a result, it is possible to efficiently filter spans, add artificial spans or delay spans for enhancing them with external, > delayed data. Multiple calls will execute the customizers in order.

I am not sure if I would have expected the observed behaviour from this and its name.

Anyway, since I can register a SpanProcessor now, I feel like this issue is resolved.

Thanks a lot everyone!