Tracing for Spring Data CoroutineCrudRepository methods is timed incorrectly

ofelbaum commented 3 months ago

Describe the bug

It looks like traces collected for Spring Data repositories (backed by CoroutineCrudRepository) are reflecting just "assembly" phase. They typically are measured in microseconds (μs).

Steps to reproduce

Here is the project to demonstrate the issue https://github.com/ofelbaum/r2dbc-coroutine-demo

Expected behavior

Span duration for spans collected by "io.opentelemetry.spring-data" instrumentation is reflecting actual duration of an RDBMS operation

Actual behavior

Span duration for spans collected by "io.opentelemetry.spring-data" instrumentation is not reflecting actual duration of an RDBMS operation

Javaagent or library instrumentation version

https://github.com/open-telemetry/opentelemetry-java-instrumentation/releases/download/v2.2.0/opentelemetry-javaagent.jar

Environment

JDK: Java(TM) SE Runtime Environment (build 21.0.1+12-LTS-29) OS: macOS 14.2.1

Additional context

Looks like this issue is closely related to another https://github.com/open-telemetry/opentelemetry-java-instrumentation/issues/9500

ofelbaum commented 1 month ago

@laurit Thanks. I appreciate your help with fixing this.

As it was mentioned the issue might be fixed in #11168. I upgraded javaagent library from 2.2.0 to 2.4.0 in sample demo I prepared, but still have the issue :(

ofelbaum commented 3 weeks ago

@laurit Hello. It's me again :)

Just checked out new version 2.5.0 of javaagent with fix of this issue. Looks like it resolved partially. Span generated for CoroutineCrudRepository.findAll looks great, but span for CoroutineCrudRepository.findById still broken (splitted and has wrong duration).

Could you please take a look once again?

Sample demo updated with recent findings.

open-telemetry / opentelemetry-java-instrumentation