Auto-Instrumentation across Message Queue (RabbitMQ): traceId lost in subsequent spans

[Johnny850807]

Describe the bug

Say, A passes a message to B via a message queue (RabbitMQ)
The message's consumer B invokes C and then C invokes D to handle the message. (C and D are annotated with @WithSpan)
Then I should see the trace has A -> B -> C -> D, instead I only see A -> B

(Furthermore, in C and D's logs, the trace_id value is lost)

I can confirm that I can find the traceparent header included as the message's header, but
the auto-instrumentation doesn't use the same traceparent as the traceId for the subsequent spans (C, D)

Is this a feature or a bug?
How do I have A --(message queue)--> B -> C -> D traced so that I can see more clearly into asynchronous flows?

What version are you using?

opentelemetry-api: 1.0.0
opentelemetry-extension-annotations: 1.0.0
opentelemetry-javaagent: 1.0.0
org.springframework.boot: 2.4.3
spring-boot-starter-amqp: 2.3.2.RELEASE

Environment

Compiler/Runtime: AdoptOpenJDK 11.0.9
OS: macOS 10.15.5

[mateuszrzeszutek]

Javaagent 0.14.0 only supports OTel API & annotations 0.14.0. Can you try using javaagent with the same version as the annotations extension?

[Johnny850807]

Javaagent 0.14.0 only supports OTel API & annotations 0.14.0. Can you try using javaagent with the same version as the annotations extension?

Sorry, it's Javaagent 1.0.0, I mistyped the version.

[mateuszrzeszutek]

Can you share the code responsible for consuming the message (B and the call to C ideally)? Or, if it's feasible, create a small example app that reproduces this issue?

[Johnny850807]

Can you share the code responsible for consuming the message (B and the call to C ideally)? Or, if it's feasible, create a small example app that reproduces this issue?

Sorry for the late reply, here's the small app that can reproduce the issue.
https://github.com/Johnny850807/Spring-Boot-Demo-Observability-with-Open-Telemetry

It's a simple sign-up/sign-in demo app. After a sign-up request succeeds, the log shows:

The whole sequence of the Sign-Up request is UserController -> SignUp -> UserRepository -> AmqpTemplate -> SignUpHandler (RabbitListener) -> RestTemplate (Another request) -> UserController -> UserRepository

As shown in the SignUpHandler's code below, it queries for another [GET] API after it receives a message from the message queue. This is not shown in the trace as I expected.

@Slf4j
@Configuration
public class SignUpHandler {
    public static final String QUEUE = "queue";
    private final RestTemplate restTemplate = new RestTemplate();

    @Bean
    public Queue queue() {
        return new Queue(QUEUE);
    }

    @RabbitListener(queues = QUEUE)
    public void handle(String signUpUserId) {
        int id = Integer.parseInt(signUpUserId);
        User user = restTemplate.getForEntity("http://localhost:8080/api/users/" + id, User.class).getBody();
        log.info("Handle sign-up: {}", user);
    }
}

[mateuszrzeszutek]

I see - @RabbitListener not working properly has already come up before: #2436

Thanks for the example! It should make tracking this down much easier.

[Asafb26]

Hi is there anything new/workaround to fix this issue? Thanks

[mateuszrzeszutek]

Sorry, we don't have any news on this yet 🙇‍♂️

[Johnny850807]

Appreciate!! I'm just gonna demonstrate this in the next week, now the cool asynchronous trace can be shown to the people.