Observing event flows

4 min read
On trails:EDANETstep 7/7

When a call becomes a chain of events, there is no single call stack and no single log to read. Correlation ties everything caused by one thing back together. Two ids do most of the work, both from the event’s envelopeAnatomy of an eventAn envelope that says which event it is and when it happened, and a payload that carries the facts.Opens in a new tab. The correlation id is the same on every message in one flow, such as one order. The causation id is the id of the message that directly caused this one, so the chain of causes can be followed step by step. MassTransit has the same two ideas: ConversationId groups the related messages and InitiatorId carries the correlation from the message being consumed.

One trace across services

A distributed trace adds timing. It has a trace id shared by every step, and each step is a span with a parent. The W3C traceparent header carries this as version-trace-id-parent-id-flags. Over HTTP the header travels with the request. Over a broker it has to be copied into the message’s headers by the producer and restored as the parent by the consumer, or the trace breaks into separate pieces.

One trace across four services: the Orders request starts the trace, Inventory and Payments handle OrderPlaced in parallel, and Notifications handles PaymentReceived. Every span carries the same trace id. ONE TRACE ID ON EVERY SPAN: 4bf92f3577b34da6a3ce929d0e0e4736 ORDERS INVENTORY PAYMENTS NOTIFICATIONS POST /orders reserve stock charge payment send confirmation EACH ARROW IS A MESSAGE; THE TRACE CONTEXT TRAVELS IN ITS HEADERS
The Orders request starts the trace. Each message hop continues it.

How much of that is automatic depends on the library.

  • MassTransit emits spans from an ActivitySource named MassTransit. If an activity is active when Publish or Send is called, it becomes the parent, and MassTransit adds headers to the message so the consumer continues the trace. Its metrics come from a .NET Meter that is added with AddMeter.
  • Azure Service Bus carries the context in a Diagnostic-Id message property in W3C format, and the ServiceBusProcessor handler is instrumented. Microsoft describes its OpenTelemetry support as experimental, and it is switched on with an AppContext switch or an environment variable.
  • With a raw client such as RabbitMQ.Client or Confluent.Kafka, this note did not check for built-in tracing, so the application stamps the context itself, as in the second snippet below.
Program.csC#
// The Service Bus client's tracing is behind a switch (experimental).AppContext.SetSwitch("Azure.Experimental.EnableActivitySource", true); builder.Services.AddOpenTelemetry()    .ConfigureResource(r => r.AddService("orders"))    .WithTracing(t => t        .AddAspNetCoreInstrumentation()        .AddSource("MassTransit")   // MassTransit        .AddSource("Azure.*")       // Azure SDK, including Service Bus        .AddOtlpExporter());

For a raw client, the application does what the libraries do: it starts a producer activity, writes its id into a header, and starts the consumer activity with that id as the parent. Activity.Id is in W3C format by default in current .NET.

Propagation.csC#
static readonly ActivitySource Source = new("Shop.Messaging"); // Producer: stamp the current trace onto the outgoing message.using (var send = Source.StartActivity("orders.placed publish", ActivityKind.Producer)){    headers["traceparent"] = send?.Id;    // ... publish ...} // Consumer: continue the trace from the incoming message.headers.TryGetValue("traceparent", out var parent);using var process = Source.StartActivity(    "orders.placed process", ActivityKind.Consumer, parent);// ... handle the message ...

OpenTelemetry’s messaging conventions mark producer spans as PRODUCER and processing spans as CONSUMER. They use span links as the default way to relate a consumer to the producer, so a tracing tool may show a message hop as a link rather than as a parent and child.

Numbers that warn first

A trace explains one message after it went wrong. Three numbers show a problem building up, before a customer notices.

SignalWhat a rise meansWhere to read it
Queue depthMessages are arriving faster than they are handled, or the consumers have stopped.RabbitMQ: messages ready and unacknowledged, in the management UI, the HTTP API or the Prometheus plugin. Service Bus: the active message count.
Consumer lagA Kafka consumer group is behind. Lag is the latest offset in a partition minus the group's offset. It counts offsets, not time.Kafka's consumer-group tools and the broker's consumer-lag metrics.
Dead-letter countConsumers are giving up on messages. Any count above zero deserves a look.Service Bus: the dead-letter sub-queue count. MassTransit: the `_error` queue. RabbitMQ: the queue behind the dead-letter exchange.
Table 1. Early-warning signals for messaging

Queue depth and consumer lag can climb while every request still succeeds, so a steady rise is the first sign of a consumer that is slower than its producers. The dead-letter count is the number of failures that retries did not fix (see dead-letter queuesDead-letter queuesWhere a message goes when it cannot be processed, so the rest of the traffic keeps moving.Opens in a new tab).

Where it fits

Correlation ids belong in every message and every log line from the start, because they cannot be added to messages already sent. Traces and alerts on these three numbers are the next layer. LLM agents need the same discipline for their own reasons: traceabilityTraceabilityLog the whole reasoning trace, so any answer can be explained afterwards.Opens in a new tab keeps the whole reasoning trace of an agent, and agent metricsAgent metricsSix numbers that say whether a deployed agent is healthy.Opens in a new tab picks the numbers worth tracking.

Sources