Search code examples
spring-cloud-sleuth

Spring JMS consumer does not have parent span Id rightly set

My sample application makes use of

  • spring-boot-starter-activemq (2.3.1)
  • spring-boot-starter-web (2.3.1)
  • pring-cloud-starter-sleuth (2.2.3)

On the published message I see the X-Parent-Span-Id, X-Trace-Id and b3 properties rightly set. However the logs in the JMS Listener (AMQ consumer) have a different parentId (X-B3-ParentSpanId).

Why do the logs on the AMQ consumer side not have the same parentId as present in the message?

Note - The traceId shows up fine.

Flow

Server 1 --> Server 2 (AMQ producer) ---> AMQ consumer

Server1 logs

{"@timestamp":"2020-07-26T18:42:19.258+01:00","@version":"1","message":"Received greet request","logger_name":"com.spike.server.HelloController","thread_name":"http-nio-8080-exec-9","level":"INFO","level_value":20000,"traceId":"e4ac9c00ba990cf2","spanId":"e4ac9c00ba990cf2","spanExportable":"true","X-Span-Export":"true","X-B3-SpanId":"e4ac9c00ba990cf2","X-B3-TraceId":"e4ac9c00ba990cf2"}

Server 2 (AMQ producer) logs

{"@timestamp":"2020-07-26T18:42:19.262+01:00","@version":"1","message":"Received audit request","logger_name":"com.spike.upstream.AuditController","thread_name":"http-nio-8081-exec-9","level":"INFO","level_value":20000,"traceId":"e4ac9c00ba990cf2","spanId":"aed4a3863c141dde","spanExportable":"true","X-Span-Export":"true","X-B3-SpanId":"aed4a3863c141dde","X-B3-ParentSpanId":"e4ac9c00ba990cf2","X-B3-TraceId":"e4ac9c00ba990cf2","parentId":"e4ac9c00ba990cf2"}

AMQ consumer logs

{"@timestamp":"2020-07-26T18:42:19.270+01:00","@version":"1","message":"Received message: hello world","logger_name":"com.spike.consumer.Consumer","thread_name":"DefaultMessageListenerContainer-1","level":"INFO","level_value":20000,"traceId":"e4ac9c00ba990cf2","spanId":"9f7928f65ee2479d","spanExportable":"true","X-Span-Export":"true","X-B3-SpanId":"9f7928f65ee2479d","X-B3-ParentSpanId":"70f25884c40b2dc7","X-B3-TraceId":"e4ac9c00ba990cf2","parentId":"70f25884c40b2dc7"}
Solution

  • I think I got what you're asking about. So the mismatch in parent Ids is related to the fact that between the consumer and the producer we introduce a "jms" service and if the broker was correlated you would have seen how long it takes exactly in the broker. Check out the following images in Imgur https://i.sstatic.net/NwkAh.jpg