jdbc-observations / datasource-micrometer

Micrometer Observation API instrumentation and Spring Boot 3 Auto-Configuration for JDBC APIs
Apache License 2.0
50 stars 8 forks source link

Error exporting spans with Spring Boot 3.2.0 #30

Closed kcsurapaneni closed 6 months ago

kcsurapaneni commented 6 months ago

Description:

Issue:

When using the datasource-micrometer-spring-boot dependency in a Spring Boot 3.2.0 project, an error is encountered in the logs with the following stack trace:

2023-12-19T22:40:51.954Z  WARN [app,,] 1 --- [app] [BatchSpanProcessor_WorkerThread-1] [] i.o.exporter.zipkin.ZipkinSpanExporter   : Failed to export spans

org.springframework.web.client.HttpClientErrorException$BadRequest: 400 Bad Request: "valid annotation timestamp required<EOL>"
    at org.springframework.web.client.HttpClientErrorException.create(HttpClientErrorException.java:103)
    at org.springframework.web.client.DefaultResponseErrorHandler.handleError(DefaultResponseErrorHandler.java:183)
    at org.springframework.web.client.DefaultResponseErrorHandler.handleError(DefaultResponseErrorHandler.java:137)
    at org.springframework.web.client.ResponseErrorHandler.handleError(ResponseErrorHandler.java:63)
    at org.springframework.web.client.RestTemplate.handleResponse(RestTemplate.java:932)
    at org.springframework.web.client.RestTemplate.doExecute(RestTemplate.java:881)
    at org.springframework.web.client.RestTemplate.execute(RestTemplate.java:781)
    at org.springframework.web.client.RestTemplate.exchange(RestTemplate.java:663)
    at org.springframework.boot.actuate.autoconfigure.tracing.zipkin.ZipkinRestTemplateSender$RestTemplateHttpPostCall.doExecute(ZipkinRestTemplateSender.java:68)
    at org.springframework.boot.actuate.autoconfigure.tracing.zipkin.ZipkinRestTemplateSender$RestTemplateHttpPostCall.doEnqueue(ZipkinRestTemplateSender.java:75)
    at zipkin2.Call$Base.enqueue(Call.java:406)
    at io.opentelemetry.exporter.zipkin.ZipkinSpanExporter.export(ZipkinSpanExporter.java:82)
    at io.micrometer.tracing.otel.bridge.CompositeSpanExporter.lambda$export$3(CompositeSpanExporter.java:88)
    at java.base/java.lang.Iterable.forEach(Iterable.java:75)
    at io.micrometer.tracing.otel.bridge.CompositeSpanExporter.export(CompositeSpanExporter.java:88)
    at io.opentelemetry.sdk.trace.export.BatchSpanProcessor$Worker.exportCurrentBatch(BatchSpanProcessor.java:327)
    at io.opentelemetry.sdk.trace.export.BatchSpanProcessor$Worker.run(BatchSpanProcessor.java:245)
    at java.base/java.lang.Thread.run(Thread.java:833)

Investigation:

Initially, it was suspected that the issue might be with spring-projects or open-telemetry. A detailed investigation was carried out, and it was found that the error persists with the datasource-micrometer-spring-boot dependency. There is no error when this dependency is not added, as demonstrated in this branch: observability/tree/sb_3_2_0_db. However, when adding the dependency, the error occurs, as shown in this branch: observability/tree/sb_3_2_0_db_and_datasource_micrometer_tracing.

References:

The issue has been discussed on Stack Overflow: Exception in Observability stack after upgrading Spring Boot from 3.1.3 to 3.2.0.

Reproduction Steps:

  1. Clone the repository from observability/tree/sb_3_2_0_db_and_datasource_micrometer_tracing.
  2. Run the project.
  3. Observe the error in the logs.

Expected Behavior:

The application should run without errors when using the datasource-micrometer-spring-boot dependency in Spring Boot 3.2.0.

Attachments:

Environment Information:

ttddyy commented 6 months ago

Hi, Can you try with the latest Micrometer Tracing 1.2.1 which fixed the annotation with timestamp=0. (It’ll come with Boot 3.2.1)

kcsurapaneni commented 6 months ago

Hello @ttddyy , I attempted to address the issue by incorporating io.micrometer:micrometer-tracing-bridge-otel:1.2.1, but unfortunately, the problem persists. You can review the situation in the following branch: GitHub Repository - Issue Branch.

ttddyy commented 6 months ago

Can you debug to see what is the timestamp of the span annotations? The connection span creates ‘acquired’ and ‘commit’ annotations.

I’m out this week and don’t have pc. I’ll try to look into it next week if time permits.

ttddyy commented 6 months ago

@kcsurapaneni I looked your sb_3_2_0_db_and_datasource_micrometer_tracing_and_mt_1_2_1 branch.

> ./mvnw dependency:tree -Dincludes=io.micrometer:micrometer-tracing
[INFO] Scanning for projects...
[INFO]
[INFO] -----------------------< com.observability:app >------------------------
[INFO] Building app 0.0.1-SNAPSHOT
[INFO]   from pom.xml
[INFO] --------------------------------[ jar ]---------------------------------
[INFO]
[INFO] --- dependency:3.6.1:tree (default-cli) @ app ---
[INFO] com.observability:app:jar:0.0.1-SNAPSHOT
[INFO] \- io.micrometer:micrometer-tracing-bridge-otel:jar:1.2.1:compile
[INFO]    \- io.micrometer:micrometer-tracing:jar:1.2.0:compile
[INFO] ------------------------------------------------------------------------
...

It is not using micrometer-tracing=1.2.1. This is because you specified micrometer-tracing-bridge-otel=1.2.1 in the pom. However, since it uses spring boot 3.2.0 as the parent pom, the micrometer-tracing transitive dependency resolved to 1.2.0. Please make sure to use the micrometer-tracing=1.2.1 and check whether the problem still persists. If it does, please provide the timestamp value for those annotations.

kcsurapaneni commented 6 months ago

Appreciate your input, @ttddyy. You're correct. I mistakenly assumed that upgrading io.micrometer:micrometer-tracing-bridge-otel:1.2.1 would automatically bump up io.micrometer:micrometer-tracing to the same version, but it didn't. After updating the Spring Boot version to 3.2.1, both of these versions were upgraded to 1.2.1, resolving the issue. My apologies for not thoroughly investigating this earlier.