Tracing: Spans are not in the right order and do not respect the naming convention

[joegoldman2]

Library name

Azure.Messaging.ServiceBus

Please describe the feature.

I have an application that uses the Azure Service Bus SDK through MassTransit.
Today, I'm sending the telemetry to Application Insights using the OpenTelemetry collector and the Azure Monitor exporter. I find that the result is cleaner when I subscribe to MT activity source rather than the Azure one:

With TracerProviderBuilder.AddSource("MassTransit"):

With TracerProviderBuilder.AddSource("Azure.*"):

Two issues with Azure activity source:

• The send and process activities are at the same level (same parent id). I expect the process activity to be under the send one. Probably because the Azure SDK is setting the traceparent in the message's headers before starting the send activity (so the traceparent corresponds to the request POST /orders).
• The name of the spans created by MT are following the spec: <destination name> <operation name> and are easier to understand.

cc @lmolkova

[github-actions]

Thanks for the feedback! We are routing this to the appropriate team for follow-up. cc @cijothomas @rajkumar-rangaraj @reyang @TimothyMothra @vishweshbankwar.

[lmolkova]

Thanks for reporting this @joegoldman2

The send and process activities are at the same level (same parent id). I expect the process activity to be under the send one. Probably because the Azure SDK is setting the traceparent in the message's headers before starting the send activity (so the traceparent corresponds to the request POST /orders).

ServiceBus SDK creates the following spans

• Message span (create operation in OTel spec). Its context goes on the wire
  • Process span is linked to it and also becomes a child of it.
• Send span is linked to a message, but it's usually a message sibling and an uncle of process.

this behavior aligns with OTel spec, and we will probably polish it further (#43355)

Could you please check the data (parent ids) and check if it's the case. If you see that based on parent-id "send and process activities are at the same level (same parent id)", it's definitely an issue.

The name of the spans created by MT are following the spec: and are easier to understand.

You're right. We'll fix it.

[joegoldman2]

Could you please check the data (parent ids) and check if it's the case. If you see that based on parent-id "send and process activities are at the same level (same parent id)", it's definitely an issue.

It seems that send and process activities have the correct ids. I think what makes the result strange compared to MassTransit is the additional activity called Message, which has the same id as the send activity.

I exported the data using the debug exporter of the OTel collector:

otel-collector  | ScopeSpans #0
otel-collector  | ScopeSpans SchemaURL:
otel-collector  | InstrumentationScope Azure.Messaging.ServiceBus.Message
otel-collector  | Span #0
otel-collector  |     Trace ID       : bdac052a452b23d96c925dbb6cf43693
otel-collector  |     Parent ID      : a1b3a313243c9116
otel-collector  |     ID             : c6c3f02898627a2f
otel-collector  |     Name           : Message
otel-collector  |     Kind           : Producer
otel-collector  |     Start time     : 2024-05-01 14:38:35.0075534 +0000 UTC
otel-collector  |     End time       : 2024-05-01 14:38:35.0076055 +0000 UTC
otel-collector  |     Status code    : Unset
otel-collector  |     Status message :
otel-collector  | Attributes:
otel-collector  |      -> az.namespace: Str(Microsoft.ServiceBus)
otel-collector  |      -> messaging.system: Str(servicebus)
otel-collector  |      -> server.address: Str(xxxx.servicebus.windows.net)
otel-collector  |      -> messaging.destination.name: Str(orders)
otel-collector  |      -> az.schema_url: Str(https://opentelemetry.io/schemas/1.23.0)

// Send span
otel-collector  | ScopeSpans #1
otel-collector  | ScopeSpans SchemaURL:
otel-collector  | InstrumentationScope Azure.Messaging.ServiceBus.ServiceBusSender
otel-collector  | Span #0
otel-collector  |     Trace ID       : bdac052a452b23d96c925dbb6cf43693
otel-collector  |     Parent ID      : a1b3a313243c9116
otel-collector  |     ID             : 4d362ae1fee9c224
otel-collector  |     Name           : ServiceBusSender.Send
otel-collector  |     Kind           : Client
otel-collector  |     Start time     : 2024-05-01 14:38:35.0078473 +0000 UTC
otel-collector  |     End time       : 2024-05-01 14:38:35.0703801 +0000 UTC
otel-collector  |     Status code    : Unset
otel-collector  |     Status message :
otel-collector  | Attributes:
otel-collector  |      -> az.namespace: Str(Microsoft.ServiceBus)
otel-collector  |      -> messaging.system: Str(servicebus)
otel-collector  |      -> messaging.operation: Str(publish)
otel-collector  |      -> server.address: Str(xxxx.servicebus.windows.net)
otel-collector  |      -> messaging.destination.name: Str(orders)
otel-collector  |      -> az.schema_url: Str(https://opentelemetry.io/schemas/1.23.0)
otel-collector  | Links:
otel-collector  | SpanLink #0
otel-collector  |      -> Trace ID: bdac052a452b23d96c925dbb6cf43693
otel-collector  |      -> ID: c6c3f02898627a2f
otel-collector  |      -> TraceState:
otel-collector  |      -> DroppedAttributesCount: 0

// Receive + Complete part
otel-collector  | ScopeSpans #0
otel-collector  | ScopeSpans SchemaURL:
otel-collector  | InstrumentationScope Azure.Messaging.ServiceBus.ServiceBusReceiver
otel-collector  | Span #0
otel-collector  |     Trace ID       : a027daa1769107022fe96f01b380f5ee
otel-collector  |     Parent ID      :
otel-collector  |     ID             : db59a7456c2fa8c5
otel-collector  |     Name           : ServiceBusReceiver.Receive
otel-collector  |     Kind           : Client
otel-collector  |     Start time     : 2024-05-01 16:37:57.1256906 +0000 UTC
otel-collector  |     End time       : 2024-05-01 14:38:35.0709157 +0000 UTC
otel-collector  |     Status code    : Unset
otel-collector  |     Status message :
otel-collector  | Attributes:
otel-collector  |      -> az.namespace: Str(Microsoft.ServiceBus)
otel-collector  |      -> messaging.system: Str(servicebus)
otel-collector  |      -> messaging.operation: Str(receive)
otel-collector  |      -> server.address: Str(xxxx.servicebus.windows.net)
otel-collector  |      -> messaging.destination.name: Str(orders)
otel-collector  |      -> az.schema_url: Str(https://opentelemetry.io/schemas/1.23.0)
otel-collector  | Links:
otel-collector  | SpanLink #0
otel-collector  |      -> Trace ID: bdac052a452b23d96c925dbb6cf43693
otel-collector  |      -> ID: c6c3f02898627a2f
otel-collector  |      -> TraceState:
otel-collector  |      -> DroppedAttributesCount: 0
otel-collector  | Span #1
otel-collector  |     Trace ID       : bdac052a452b23d96c925dbb6cf43693
otel-collector  |     Parent ID      : 37e763ceecb05303
otel-collector  |     ID             : 79b56d97672881e1
otel-collector  |     Name           : ServiceBusReceiver.Complete
otel-collector  |     Kind           : Client
otel-collector  |     Start time     : 2024-05-01 14:38:35.0748708 +0000 UTC
otel-collector  |     End time       : 2024-05-01 14:38:35.1695553 +0000 UTC
otel-collector  |     Status code    : Unset
otel-collector  |     Status message :
otel-collector  | Attributes:
otel-collector  |      -> az.namespace: Str(Microsoft.ServiceBus)
otel-collector  |      -> messaging.system: Str(servicebus)
otel-collector  |      -> messaging.operation: Str(settle)
otel-collector  |      -> server.address: Str(xxxx.servicebus.windows.net)
otel-collector  |      -> messaging.destination.name: Str(orders)
otel-collector  |      -> az.schema_url: Str(https://opentelemetry.io/schemas/1.23.0)
otel-collector  | Links:
otel-collector  | SpanLink #0
otel-collector  |      -> Trace ID: bdac052a452b23d96c925dbb6cf43693
otel-collector  |      -> ID: c6c3f02898627a2f
otel-collector  |      -> TraceState:
otel-collector  |      -> DroppedAttributesCount: 0
otel-collector  | ScopeSpans #1
otel-collector  | ScopeSpans SchemaURL:
otel-collector  | InstrumentationScope Azure.Messaging.ServiceBus.ServiceBusProcessor
otel-collector  | Span #0
otel-collector  |     Trace ID       : bdac052a452b23d96c925dbb6cf43693
otel-collector  |     Parent ID      : c6c3f02898627a2f
otel-collector  |     ID             : 37e763ceecb05303
otel-collector  |     Name           : ServiceBusProcessor.ProcessMessage
otel-collector  |     Kind           : Consumer
otel-collector  |     Start time     : 2024-05-01 14:38:35.0709788 +0000 UTC
otel-collector  |     End time       : 2024-05-01 14:38:35.1738795 +0000 UTC
otel-collector  |     Status code    : Unset
otel-collector  |     Status message :
otel-collector  | Attributes:
otel-collector  |      -> az.namespace: Str(Microsoft.ServiceBus)
otel-collector  |      -> messaging.system: Str(servicebus)
otel-collector  |      -> messaging.operation: Str(process)
otel-collector  |      -> server.address: Str(xxxx.servicebus.windows.net)
otel-collector  |      -> messaging.destination.name: Str(orders)
otel-collector  |      -> az.schema_url: Str(https://opentelemetry.io/schemas/1.23.0)
otel-collector  |      -> messaging.masstransit.message_id: Str(dc450000-3349-a4f9-ebf6-08dc69fd251c)
otel-collector  |      -> messaging.message.conversation_id: Str(dc450000-3349-a4f9-fc38-08dc69fd251c)
otel-collector  |      -> messaging.masstransit.destination_address: Str(sb://xxxx.servicebus.windows.net/orders)

You can see the first two spans (Message and ServiceBusSender.Send) have the same parent id (and it's probably ok). But the activity Message started before the activity ServiceBusSender.Send, so it appears before and gives the impression that the process part (receive + process) didn't happen after the send activity:

Maybe a solution to make it clearer is not to subscribe to all Azure.* sources, but only to Azure.Messaging.ServiceBus., Azure.Messaging.ServiceBus.ServiceBusReceiver and Azure.Messaging.ServiceBus.ServiceBusProcessor (in order to skip Azure.Messaging.ServiceBus.Message). But it makes things more complex because today the OTel SDK doesn't (easily) support source exclusion (to subscribe to all Azure.* and just exclude the one you're not interested in for example).

Also I wonder whether the activity ServiceBusProcessor.ProcessMessage should not have the ServiceBusSender.Send activity as its parent rather than the Message activity , as is the case today.