search

helidon-io / helidon

Java libraries for writing microservices
https://helidon.io
Apache License 2.0
3.44k stars 562 forks source link

Helidon tracing spans are not appearing in traces when used in combination with otel span via Helidon open telemetry in MP application #8892

Open AshokVardhanM opened 2 weeks ago

AshokVardhanM commented 2 weeks ago

Helidon tracing spans are not appearing in traces when used in combination with otel span via Helidon open telemetry

Environment Details

Problem Description

We have created a Helidon MP application that uses a combination of otel spans and helidon tracing spans in a REST service. When the service execution is completed, we only see otel spans but not the Helidon tracing spans in the traces. I see that Tracer.global is returning a NoOpTracer in this case.

I will attach the sample application to reproduce the problem.

Steps to reproduce

  1. Start the jaeger locally on machine or any jaeger server running
  2. start the application attached in this ticket and execute the REST service "http://localhost:8080/greet/{name}" then verify the traces on jaeger UI. helidon-quickstart-mp.zip
AshokVardhanM commented 1 week ago

@tjquinno can you please take a look at this ticket .

AshokVardhanM commented 1 week ago

This is reproducible even on Helidon version 4.0.10

tjquinno commented 1 week ago

There might be some issues with your reproducer steps.

  1. When I build using mvn clean package and run using java -jar target/helidon-quickstart-mp.jar Otel reports this:

    INFO io.opentelemetry.api.GlobalOpenTelemetry Thread[#44,BatchSpanProcessor_WorkerThread-1,5,main]: 
AutoConfiguredOpenTelemetrySdk found on classpath but automatic configuration is disabled. 
To enable, run your JVM with -Dotel.java.global-autoconfigure.enabled=true

    Did you notice that message?

  2. When I add that setting to the java command I get this: 
    SEVERE io.opentelemetry.api.GlobalOpenTelemetry Thread[#44,BatchSpanProcessor_WorkerThread-1,5,main]: 
Error automatically configuring OpenTelemetry SDK. OpenTelemetry will not be enabled.
io.opentelemetry.sdk.autoconfigure.spi.ConfigurationException: 
otel.metrics.exporter set to "otlp" but opentelemetry-exporter-otlp not found on classpath. 
Make sure to add it as a dependency.
  3. When I add that runtime dependency and rebuild and rerun and access the endpoint I get this message approximately every minute: 
    SEVERE io.opentelemetry.exporter.internal.grpc.OkHttpGrpcExporter Thread[#73,OkHttp http://localhost:4317/...,5,main]: 
Failed to export metrics. The request could not be executed. 
Full error message: Failed to connect to localhost/[fe80:0:0:0:0:0:0:1%1]:4317

    Were you expecting Otel on its own to report to Jaeger?

AshokVardhanM commented 1 week ago

@tjquinn

I don't remember any of these messages appearing when I started the sample application. No, I am not expecting Otel to report on its own. I have the following Otel configuration. I will try again and update you this thread. otel: sdk: disabled: false traces: exporter: jaeger propagators: tracecontext,baggage,b3,b3multi

AshokVardhanM commented 1 week ago

FYI, I was running Jaeger locally using the following command : docker run -d -e COLLECTOR_ZIPKIN_HOST_PORT=:9411 -e COLLECTOR_OTLP_ENABLED=true -p 6831:6831/udp -p 6832:6832/udp -p 5778:5778 -p 16686:16686 -p 4317:4317 -p 4318:4318 -p 14250:14250 -p 14268:14268 -p 14269:14269 -p 9411:9411 jaegertracing/all-in-one:latest

AshokVardhanM commented 1 week ago

I have started the sample application and verified that none of the SEVERE log messages you have observed are present in my case. I just got this INFO log message 2024.06.25 12:00:32 INFO io.opentelemetry.api.GlobalOpenTelemetry Thread[#47,BatchSpanProcessor_WorkerThread-1,5,main]: AutoConfiguredOpenTelemetrySdk found on classpath but automatic configuration is disabled. To enable, run your JVM with -Dotel.java.global-autoconfigure.enabled=true Please let me know if you want to sync up over a call on this. Thanks :slightly_smiling_face:

AshokVardhanM commented 1 week ago

Complete logs here : /Library/Java/JavaVirtualMachines/jdk-21.jdk/Contents/Home/bin/java -agentlib:jdwp=transport=dt_socket,address=127.0.0.1:52060,suspend=y,server=n -Dfile.encoding=UTF-8 -Dsun.stdout.encoding=UTF-8 -Dsun.stderr.encoding=UTF-8 -classpath /Applications/IntelliJ IDEA CE.app/Contents/lib/idea_rt.jar -jar /Users/ashokmallenipalli/Helidon4/helidon-quickstart-mp/target/helidon-quickstart-mp.jar Connected to the target VM, address: '127.0.0.1:52060', transport: 'socket' 2024.06.25 11:58:56 INFO io.helidon.tracing.tracerresolver.TracerResolverBuilder Thread[#1,main,5,main]: TracerResolver not configured, tracing is disabled 2024.06.25 11:58:56 WARNING io.helidon.openapi.OpenApiFeature Thread[#1,main,5,main]: Static OpenAPI file not found, checked: [META-INF/openapi.yml, META-INF/openapi.yaml, META-INF/openapi.json] SLF4J: No SLF4J providers were found. SLF4J: Defaulting to no-operation (NOP) logger implementation SLF4J: See https://www.slf4j.org/codes.html#noProviders for further details. 2024.06.25 11:58:57 INFO io.helidon.microprofile.server.ServerCdiExtension Thread[#1,main,5,main]: Registering JAX-RS Application: HelidonMP 2024.06.25 11:58:57 WARNING org.glassfish.jersey.server.wadl.WadlFeature Thread[#1,main,5,main]: JAX-B API not found . WADL feature is disabled. 2024.06.25 11:58:59 INFO io.helidon.webserver.ServerListener VirtualThread[#51,start @default (/0.0.0.0:8080)]/runnable@ForkJoinPool-1-worker-1: [0x7242a12f] http://0.0.0.0:8080 bound for socket '@default' 2024.06.25 11:58:59 INFO io.helidon.webserver.LoomServer Thread[#1,main,5,main]: Started all channels in 44 milliseconds. 6220 milliseconds since JVM startup. Java 21+35-LTS-2513 2024.06.25 11:58:59 INFO io.helidon.microprofile.server.ServerCdiExtension Thread[#1,main,5,main]: Server started on http://localhost:8080 (and all other host addresses) in 6230 milliseconds (since JVM startup). 2024.06.25 11:58:59 INFO io.helidon.microprofile.openapi.FilteredIndexViewsBuilder Thread[#1,main,5,main]: Could not locate the Jandex index file META-INF/jandex.idx, building an in-memory index... Consider using the Jandex maven plug-in during your build to add it to your app. 2024.06.25 11:58:59 WARN io.smallrye.openapi.runtime.scanner Thread[#1,main,5,main]: SROAP04005: Could not find schema class in index: io.helidon.examples.quickstart.mp.Message 2024.06.25 11:58:59 WARN io.smallrye.openapi.runtime.scanner Thread[#1,main,5,main]: SROAP04005: Could not find schema class in index: io.helidon.examples.quickstart.mp.Message 2024.06.25 11:58:59 WARN io.smallrye.openapi.runtime.scanner Thread[#1,main,5,main]: SROAP04005: Could not find schema class in index: io.helidon.examples.quickstart.mp.Message 2024.06.25 11:58:59 INFO io.helidon.common.features.HelidonFeatures Thread[#54,features-thread,5,main]: Helidon MP 4.0.10 features: [CDI, Config, Health, Metrics, Open API, Server, Telemetry, Tracing] 2024.06.25 11:58:59 WARNING io.helidon.common.features.HelidonFeatures.deprecated Thread[#54,features-thread,5,main]: You are using deprecated features. These APIs will be removed from Helidon! 2024.06.25 11:58:59 INFO io.helidon.common.features.HelidonFeatures.deprecated Thread[#54,features-thread,5,main]: Deprecated feature: Tracing since 4.0.0 (Tracing) 2024.06.25 11:58:59 INFO io.helidon.common.features.HelidonFeatures.preview Thread[#54,features-thread,5,main]: You are using preview features. These APIs are production ready, yet may change more frequently. Please follow Helidon release changelog! 2024.06.25 11:58:59 INFO io.helidon.common.features.HelidonFeatures.preview Thread[#54,features-thread,5,main]: Preview feature: Telemetry since 1.0.0 (Telemetry) tracer obj in getMsg is :io.opentelemetry.sdk.trace.SdkTracer@7e52a26b 2024.06.25 12:00:32 INFO io.opentelemetry.api.GlobalOpenTelemetry Thread[#47,BatchSpanProcessor_WorkerThread-1,5,main]: AutoConfiguredOpenTelemetrySdk found on classpath but automatic configuration is disabled. To enable, run your JVM with -Dotel.java.global-autoconfigure.enabled=true

tjquinno commented 1 week ago

It looks as if you are now facing an OTel configuration issue, not a Helidon one.

The Helidon OTel-related code (helidon-tracing-providers-opentelemetry) bridges between the Helidon tracing API and the OTel API so your application can use the neutral Helidon tracing API, but beyond that the configuration of OTel is up to you. OpenTelemetry does not look at Helidon or MicroProfile config files and, currently, Helidon does not map Helidon config to OTel config for you. (If you saw documentation or other information that suggested adding an otel section to the Helidon config please let us know.)

You configure OpenTelemetry settings following the OTel documentation: https://opentelemetry.io/docs/languages/java/configuration/

You need to set as either a Java system property or an environment variable otel.sdk.disabled to false which it seems you are now doing and, as the message from OTel in your most recent output indicates, try setting otel.java.global-autoconfigure.enabled to true depending on how you want OTel to behave.