[Micrometer tracing] PubSub Binder does not propagate tracing data

[poznachowski]

Hello.

We are migrating our SB 2.x services to SB 3.x and it looks like last thing that blocks us is the tracing capability. We are using Pub/Sub messaging with Spring Cloud Stream abstraction.

I came up with simple project that reproduces the issue: https://github.com/poznachowski/sb3streamtracingpubsub To reproduce just spin Pub/Sub emulator with docker-compose, run the application and trigger sending / receiving msg with localhost:8080 url.

2023-07-04T23:33:21.260+08:00  INFO [test-app,64a43bc116c85a50d4c93dc1dc3bf1dd,d4c93dc1dc3bf1dd] 18913 --- [nio-8080-exec-1] p.p.sb3tracingpubsub.TestProducer        : Sending EVENT
2023-07-04T23:33:21.365+08:00  INFO [test-app,64a43bc1cb467df495cd174e9d205b6d,c86c8605779d116a] 18913 --- [sub-subscriber1] p.p.sb3tracingpubsub.TestConsumer        : Event came: TestEvent[id=id1, value=value]

As can be seen in the logs traceId differs.

There is a lot of layers that are involved and I'm struggling with finding the issue. I dediced to raise the issue here (as opposed to spring cloud stream repository) as I changed the example to use RabbitMQ binder (https://github.com/poznachowski/sb3streamtracingpubsub/tree/rabbit_check) and it works like a charm:

2023-07-04T23:37:44.306+08:00  INFO [test-app,64a43cc86fb43c49417fffb851634466,417fffb851634466] 20175 --- [nio-8080-exec-1] p.p.sb3tracingpubsub.TestProducer        : Sending EVENT
2023-07-04T23:37:44.350+08:00  INFO [test-app,64a43cc86fb43c49417fffb851634466,e9ea5ac2a5aa32a0] 20175 --- [opic.test-app-1] p.p.sb3tracingpubsub.TestConsumer        : Event came: TestEvent[id=id1, value=value]

What I've seen is that RabbitTemplate (KafkaTemplate as well) received Micrometer observation support. Maybe something similiar has to be done for Pub/Sub ?

[meltsufin]

We have experimental support for Pub/Sub tracing. Did you try enabling it via spring.cloud.gcp.trace.pubsub.enabled=true?

[dannyjiang001]

Hi, my tracing propagation from producer to consumer is working but having issues propagating tracing context to executor threads. Using examples from https://amithkumarg.medium.com/micrometer-tracing-in-spring-boot-context-propagation-for-async-scheduled-newspan-b80f4f4b2c9f

It's working on the first message received from the consumer.

2023-07-05T18:03:06.457Z  INFO [skywalker-workers,64a5b0593bffd8378114c6ee848c758a,7bc0128a4ae4de0b] 52617 --- [ub-subscriber33] c.m.e.s.config.AsyncTraceContextConfig   : context accessor, key: micrometer.observation, value: {name=spring.cloud.function(null), error=null, context=name='spring.cloud.function', contextualName='null', error='null', lowCardinalityKeyValues=[spring.cloud.function.definition='togglePipeline'], highCardinalityKeyValues=[], map=[class io.micrometer.core.instrument.Timer$Sample='io.micrometer.core.instrument.Timer$Sample@2800cb5e', class io.micrometer.core.instrument.LongTaskTimer$Sample='SampleImpl{duration(seconds)=0.072444875, duration(nanos)=7.2444875E7, startTimeNanos=233299957769000}', class io.micrometer.tracing.handler.TracingObservationHandler$TracingContext='TracingContext{span=64a5b0593bffd8378114c6ee848c758a/7bc0128a4ae4de0b}'], parentObservation=null}

But subsequence messages received by the same consumer have micrometer.observation value = null

2023-07-05T18:03:21.693Z  INFO [skywalker-workers,64a5b069e21c938c451bb23b06a43629,fbb4189171d3a7f2] 52617 --- [ub-subscriber24] c.m.e.s.config.AsyncTraceContextConfig   : context accessor, key: micrometer.observation, value: null

[poznachowski]

@meltsufin thanks for response.

Enabling the flag worked. Still 2 remarks from my side:

1. TracePubSubAutoConfiguration depends (@ConditionalOnClass) on MessagingTracing which is contained in brave-instrumentation-messaging library. Sleuth project included this transitively, where io.micrometer:micrometer-tracing-bridge-brave does not (contains only brave-instrumentation-http). So the configuration was silently ignored until I manually added the brave-instrumentation-messaging dependency. Maybe it would be good to document it somewhere?
2. I've stumbled upon this experimental support before. However, due to the fact that docs resides under Cloud Trace section I had the impression that it is useful only when using Cloud Trace (which is not the case here).

[meltsufin]

@poznachowski Thanks for the update! I'm glad it worked for you! We haven't really considered the use of this support without Cloud Trace, but I guess it does make sense that it would work. If you have a suggestion on how to update our reference documentation to explain this, we would be very grateful for a contribution. 😉