[Bug][Backend][Observability] #575 was fixed in ONE publisher — BookController (5 publish sites) and 3 others still ship RabbitMQ messages with no traceparent, so user-initiated flows appear in Jaeger as disconnected orphan traces #597

Closed
opened 2026-07-14 21:31:22 +00:00 by spikerj · 2 comments
Owner

Filed by: QA Team — referencing #575, which is CLOSED. The fix is correct but was applied to one publisher only. The same defect is live in several others, including the user-facing book pipeline.

Summary

#575 ("ScheduledTaskPublisher does not propagate W3C trace context on publish — violates AGENTS.md non-negotiable #1") was fixed and closed. I verified the fix in origin/masterScheduledTaskPublisher now correctly starts a producer Activity and calls ActivityHelper.InjectTraceContext(properties, activity). That part is genuinely done.

But the bug was treated as a one-file bug. It is a class bug. Auditing every BasicPublishAsync call site against current master, several origin publishers still construct a fresh BasicProperties with no trace injection at all.

Confirmed trace-blind origin publishers

These files contain zero references to ActivityHelper and do not copy incoming headers — so the message leaves with no traceparent:

File Publish sites
SpikerSoft.Api/Domain/Books/BookController.cs 5
SpikerSoft.Business/Domain/Calendar/Services/CalendarNotificationService.cs 1
SpikerSoft.EventHandlers.SecurityScanner/Services/SecurityScanService.cs 1
SpikerSoft.EventHandlers.UploadCoordinator/Services/StalenessDetectorService.cs 1

Also flagged and worth a look (they reference ActivityHelper somewhere but the specific publish appears uninstrumented — needs an owner's eye rather than my grep): SpikerSoft.EventHandlers.Scheduler/Services/NotificationEventPublisher.cs:91, LeaseManagerService.cs:388/797, LessonRegradeWorkerHostedService.cs:403, LessonRegradeClient.cs:102.

The worst offender is user-facing

BookController.cs publishes five times and references ActivityHelper zero times. Verbatim from line ~655:

var properties = new BasicProperties
{
    Persistent = true,
    MessageId = Guid.NewGuid().ToString(),
    Timestamp = new AmqpTimestamp(DateTimeOffset.UtcNow.ToUnixTimeSeconds()),
    CorrelationId = workflow.UploadId
};

await channel.BasicPublishAsync("image.extraction", "image.description.requested", false, properties, body, ct);

No traceparent. Compare the correct pattern, from BookManagementConsumer.cs:212 — the downstream consumer of this very flow:

// Inject trace context for distributed tracing
ActivityHelper.InjectTraceContext(properties, publishActivity);
await _channel.BasicPublishAsync(exchange, routingKey, false, properties, body, cancellationToken);

So the worker does it right; the API that kicks the work off does not.

Why this matters more than "a missing header"

Consumers call ActivityHelper.StartActivityFromRabbitMQMessage(...), which extracts the parent from traceparent. With no traceparent, that call starts a brand-new ROOT trace. The result is not a slightly-degraded trace — it is two completely disconnected traces with no link between them.

Concretely: a user uploads a book → the API's HTTP span ends there. The image-description / metadata / book-management work appears in Jaeger as an unrelated orphan trace with no path back to the request or the user that caused it. Correlation IDs are set, so you can grep your way across, but the distributed trace — the thing Jaeger exists for — is severed at exactly the boundary that matters.

This is consistent with what I see in Jaeger today: the API's traces are almost entirely internal RabbitMQ/SignalR plumbing, and real user-initiated flows do not connect end-to-end.

This is the same AGENTS.md non-negotiable #1 violation that #575 was raised for:

"Telemetry config key is exactly Jaeger:EndPoint; every RabbitMQ publish/consume must propagate W3C trace context via ActivityHelper."

What is NOT broken (checked, so nobody re-chases these)

  • RabbitMQRetryHelper — I initially suspected the shared retry/DLQ ladder (26 consumers depend on it) of dropping trace context, because its comment says "Preserve correlation and trace context" while only copying CorrelationId/MessageId. It is fine. Both the retry path (line 135) and the DLQ path (line ~217) copy the incoming headers wholesale via new Dictionary<string, object?>(eventArgs.BasicProperties.Headers ?? ...), so traceparent survives. No action needed.
  • ScheduledTaskPublisher#575's fix is present and correct in master.
  • The two remaining autoAck: true sites (LessonRegradeClient, RabbitMqMessageBusPublisher) are on Direct-Reply-To pseudo-queues, where RabbitMQ requires noAck. Correct as written — not a repeat of #573.

Fix

Apply #575's pattern to each origin publisher: start a producer Activity, then ActivityHelper.InjectTraceContext(properties, activity) before publishing.

Suggest a guard so this class cannot regress again — the same reasoning as #596. A CI check, or better, funnel all publishing through a single helper that injects unconditionally, so it is impossible to publish without trace context rather than merely discouraged.

Related

  • #575 (closed) — same bug, fixed in one file only.
  • #588 (open) — telemetry misregistration (.AddService positional-arg bug) in EventHandlers.Infrastructure. Same subsystem.
  • #594 (open) — Serilog level hardcoded, appsettings ignored. Also observability, also in the shared host builder.
**Filed by: QA Team** — referencing **#575**, which is **CLOSED**. The fix is correct but was applied to **one publisher only**. The same defect is live in several others, including the user-facing book pipeline. ## Summary **#575** ("ScheduledTaskPublisher does not propagate W3C trace context on publish — violates AGENTS.md non-negotiable #1") was fixed and closed. I verified the fix in `origin/master` — `ScheduledTaskPublisher` now correctly starts a producer Activity and calls `ActivityHelper.InjectTraceContext(properties, activity)`. That part is genuinely done. But the bug was treated as a one-file bug. It is a **class** bug. Auditing every `BasicPublishAsync` call site against current master, several **origin publishers** still construct a fresh `BasicProperties` with **no trace injection at all**. ## Confirmed trace-blind origin publishers These files contain **zero references to `ActivityHelper`** and do **not** copy incoming headers — so the message leaves with no `traceparent`: | File | Publish sites | |---|---| | **`SpikerSoft.Api/Domain/Books/BookController.cs`** | **5** | | `SpikerSoft.Business/Domain/Calendar/Services/CalendarNotificationService.cs` | 1 | | `SpikerSoft.EventHandlers.SecurityScanner/Services/SecurityScanService.cs` | 1 | | `SpikerSoft.EventHandlers.UploadCoordinator/Services/StalenessDetectorService.cs` | 1 | Also flagged and worth a look (they reference `ActivityHelper` somewhere but the specific publish appears uninstrumented — needs an owner's eye rather than my grep): `SpikerSoft.EventHandlers.Scheduler/Services/NotificationEventPublisher.cs:91`, `LeaseManagerService.cs:388/797`, `LessonRegradeWorkerHostedService.cs:403`, `LessonRegradeClient.cs:102`. ## The worst offender is user-facing `BookController.cs` publishes **five** times and references `ActivityHelper` **zero** times. Verbatim from line ~655: ```csharp var properties = new BasicProperties { Persistent = true, MessageId = Guid.NewGuid().ToString(), Timestamp = new AmqpTimestamp(DateTimeOffset.UtcNow.ToUnixTimeSeconds()), CorrelationId = workflow.UploadId }; await channel.BasicPublishAsync("image.extraction", "image.description.requested", false, properties, body, ct); ``` No `traceparent`. Compare the correct pattern, from `BookManagementConsumer.cs:212` — the **downstream consumer of this very flow**: ```csharp // Inject trace context for distributed tracing ActivityHelper.InjectTraceContext(properties, publishActivity); await _channel.BasicPublishAsync(exchange, routingKey, false, properties, body, cancellationToken); ``` So the worker does it right; the API that kicks the work off does not. ## Why this matters more than "a missing header" Consumers call `ActivityHelper.StartActivityFromRabbitMQMessage(...)`, which extracts the parent from `traceparent`. **With no `traceparent`, that call starts a brand-new ROOT trace.** The result is not a slightly-degraded trace — it is **two completely disconnected traces** with no link between them. Concretely: a user uploads a book → the API's HTTP span ends there. The image-description / metadata / book-management work appears in Jaeger as an **unrelated orphan trace** with no path back to the request or the user that caused it. Correlation IDs are set, so you can *grep* your way across, but the distributed trace — the thing Jaeger exists for — is severed at exactly the boundary that matters. This is consistent with what I see in Jaeger today: the API's traces are almost entirely internal RabbitMQ/SignalR plumbing, and real user-initiated flows do not connect end-to-end. This is the **same AGENTS.md non-negotiable #1 violation** that #575 was raised for: > *"Telemetry config key is exactly `Jaeger:EndPoint`; every RabbitMQ publish/consume must propagate W3C trace context via `ActivityHelper`."* ## What is NOT broken (checked, so nobody re-chases these) - **`RabbitMQRetryHelper`** — I initially suspected the shared retry/DLQ ladder (26 consumers depend on it) of dropping trace context, because its comment says *"Preserve correlation and trace context"* while only copying `CorrelationId`/`MessageId`. **It is fine.** Both the retry path (line 135) and the DLQ path (line ~217) copy the incoming headers wholesale via `new Dictionary<string, object?>(eventArgs.BasicProperties.Headers ?? ...)`, so `traceparent` survives. No action needed. - **`ScheduledTaskPublisher`** — #575's fix is present and correct in master. - The two remaining `autoAck: true` sites (`LessonRegradeClient`, `RabbitMqMessageBusPublisher`) are on **Direct-Reply-To** pseudo-queues, where RabbitMQ *requires* `noAck`. Correct as written — **not** a repeat of #573. ## Fix Apply #575's pattern to each origin publisher: start a producer `Activity`, then `ActivityHelper.InjectTraceContext(properties, activity)` before publishing. **Suggest a guard so this class cannot regress again** — the same reasoning as #596. A CI check, or better, funnel all publishing through a single helper that injects unconditionally, so it is impossible to publish without trace context rather than merely discouraged. ## Related - **#575** (closed) — same bug, fixed in one file only. - **#588** (open) — telemetry misregistration (`.AddService` positional-arg bug) in `EventHandlers.Infrastructure`. Same subsystem. - **#594** (open) — Serilog level hardcoded, appsettings ignored. Also observability, also in the shared host builder.
Author
Owner

Fix up in spikersoft-backend PR #296 (open, awaiting merge). Good ticket — and your instinct to "funnel all publishing through a single helper... so it is impossible to publish without trace context rather than merely discouraged" was the right call. That's what shipped.

Your audit was right, and it undercounted. Checking every BasicPublishAsync against master: 10 trace-blind origin publishers, and 4 of the 5 you flagged as "needs an owner's eye rather than my grep" are genuinely broken (LeaseManagerService:797 is fine — the one you weren't sure about).

Two things the audit couldn't see, which changed the shape of the fix:

  1. Hand-calling ActivityHelper.InjectTraceContext(properties) — the obvious fix — propagates nothing from a timer loop. Its first act is activity ??= Activity.Current; if (activity == null) return;. StalenessDetectorService and NotificationEventPublisher publish from timer loops with no ambient activity, so "apply #575's pattern" to those would have injected nothing while looking completely correct at the call site — and passed any test that asserts inject was called.

  2. Two publishers are already "fixed" that way and are silently propagating nothing right now. SharedGpuLeaseService (3 sites) and RabbitMqGpuHeartbeatPublisher call InjectTraceContext(props) with no activity argument, from background paths. They read as instrumented in any grep. They emit no traceparent. They were not on anyone's list, including mine, until I stopped counting calls and started asserting headers.

So: PublishTracedAsync is now the only way to publish. It starts a producer span on TraceSources.MessagePublishing first, so there is always context to inject — and that source is registered by the API and every worker, because an ActivitySource with no listener returns null from StartActivity and puts you right back to injecting nothing. Fourth sighting of that exact silent no-op (#458, #575, #588), so it's asserted, not trusted. All 35 publish sites migrated; PublishersUseTheTracedHelperTests fails the build on a raw BasicPublishAsync outside a justified allow-list.

RPC reply legs deliberately excluded (and annotated): the caller's span is still open and correlates by CorrelationId, and no reply consumer reads traceparent, so injecting one would propagate to nobody. Including them would have made the allow-list meaningless.

Tests assert a traceparent actually reaches the wire, including the no-ambient-activity case — never that inject was called, since that's the assertion that goes green on the bug itself. 9,759 tests pass. AGENTS.md #1 and the telemetry rule now flag the old advice as the trap.

Leaving open until #296 merges.

Fix up in spikersoft-backend PR #296 (open, awaiting merge). Good ticket — and your instinct to *"funnel all publishing through a single helper... so it is impossible to publish without trace context rather than merely discouraged"* was the right call. That's what shipped. **Your audit was right, and it undercounted.** Checking every `BasicPublishAsync` against master: **10 trace-blind origin publishers**, and 4 of the 5 you flagged as *"needs an owner's eye rather than my grep"* are genuinely broken (`LeaseManagerService:797` is fine — the one you weren't sure about). **Two things the audit couldn't see, which changed the shape of the fix:** 1. **Hand-calling `ActivityHelper.InjectTraceContext(properties)` — the obvious fix — propagates nothing from a timer loop.** Its first act is `activity ??= Activity.Current; if (activity == null) return;`. `StalenessDetectorService` and `NotificationEventPublisher` publish from timer loops with no ambient activity, so "apply #575's pattern" to those would have injected nothing while looking completely correct at the call site — and passed any test that asserts inject was *called*. 2. **Two publishers are already "fixed" that way and are silently propagating nothing right now.** `SharedGpuLeaseService` (3 sites) and `RabbitMqGpuHeartbeatPublisher` call `InjectTraceContext(props)` with no activity argument, from background paths. They read as instrumented in any grep. They emit no `traceparent`. They were not on anyone's list, including mine, until I stopped counting calls and started asserting headers. **So:** `PublishTracedAsync` is now the only way to publish. It starts a producer span on `TraceSources.MessagePublishing` *first*, so there is always context to inject — and that source is registered by the API and every worker, because an `ActivitySource` with no listener returns null from `StartActivity` and puts you right back to injecting nothing. Fourth sighting of that exact silent no-op (#458, #575, #588), so it's asserted, not trusted. All 35 publish sites migrated; `PublishersUseTheTracedHelperTests` fails the build on a raw `BasicPublishAsync` outside a justified allow-list. **RPC reply legs deliberately excluded** (and annotated): the caller's span is still open and correlates by `CorrelationId`, and no reply consumer reads `traceparent`, so injecting one would propagate to nobody. Including them would have made the allow-list meaningless. Tests assert a `traceparent` **actually reaches the wire**, including the no-ambient-activity case — never that inject was called, since that's the assertion that goes green on the bug itself. 9,759 tests pass. AGENTS.md #1 and the telemetry rule now flag the old advice as the trap. Leaving open until #296 merges.
Author
Owner

Resolved in spikersoft-backend PR #296 (merged to master).

The fix went wider than the ticket, because the ticket's premise was incomplete in two ways:

  1. The scope was understated. The ticket listed 4 files; the audit found 10 origin publishers across 35 publish call sites.
  2. The suggested fix would not have worked. Hand-calling ActivityHelper.InjectTraceContext(properties) at each site looks correct but is a silent no-op from a background/timer path: InjectTraceContext does activity ??= Activity.Current; if (activity == null) return;. Timer loops have no ambient activity, so the call injects nothing and still returns cleanly. SharedGpuLeaseService (3 sites) and RabbitMqGpuHeartbeatPublisher were already calling it that way and propagating nothing in production.

So instead of patching call sites, publishing now goes through a single choke point: IChannel.PublishTracedAsync(...) in SpikerSoft.Common/Messaging/RabbitMqPublishExtensions.cs. It starts a Producer activity from a registered ActivitySource (TraceSources.MessagePublishing, registered in both the API and worker infrastructure — an unregistered source returns null from StartActivity, which is this same bug's fourth sighting after #458/#575/#588) and injects the resulting context. All 35 sites migrated; the signature mirrors BasicPublishAsync so it was a pure rename.

Guard tests: PublishTracedAsyncTests asserts traceparent actually lands in the headers (including Publish_FromATimerLoopWithNoAmbientActivity_StillCarriesTraceContext, which fails against the old hand-call approach), and PublishersUseTheTracedHelperTests is a source scan that fails the build if a raw BasicPublishAsync reappears outside the allow-list (helper + 3 RPC reply legs, which correctly must not start a new trace).

Closing.

Resolved in spikersoft-backend PR #296 (merged to `master`). The fix went wider than the ticket, because the ticket's premise was incomplete in two ways: 1. **The scope was understated.** The ticket listed 4 files; the audit found **10 origin publishers** across 35 publish call sites. 2. **The suggested fix would not have worked.** Hand-calling `ActivityHelper.InjectTraceContext(properties)` at each site looks correct but is a *silent no-op* from a background/timer path: `InjectTraceContext` does `activity ??= Activity.Current; if (activity == null) return;`. Timer loops have no ambient activity, so the call injects nothing and still returns cleanly. `SharedGpuLeaseService` (3 sites) and `RabbitMqGpuHeartbeatPublisher` were *already* calling it that way and propagating nothing in production. So instead of patching call sites, publishing now goes through a single choke point: `IChannel.PublishTracedAsync(...)` in `SpikerSoft.Common/Messaging/RabbitMqPublishExtensions.cs`. It starts a Producer activity from a registered `ActivitySource` (`TraceSources.MessagePublishing`, registered in both the API and worker infrastructure — an unregistered source returns `null` from `StartActivity`, which is this same bug's fourth sighting after #458/#575/#588) and injects the resulting context. All 35 sites migrated; the signature mirrors `BasicPublishAsync` so it was a pure rename. Guard tests: `PublishTracedAsyncTests` asserts `traceparent` actually lands in the headers (including `Publish_FromATimerLoopWithNoAmbientActivity_StillCarriesTraceContext`, which fails against the old hand-call approach), and `PublishersUseTheTracedHelperTests` is a source scan that fails the build if a raw `BasicPublishAsync` reappears outside the allow-list (helper + 3 RPC reply legs, which correctly must not start a new trace). Closing.
Sign in to join this conversation.