Migrate spans from raw OTel SDK to tracing + tracing-opentelemetry #134

Closed
opened 2026-09-29 02:27:08 +00:00 by cameron · 1 comment
Owner

Goal

Retire the manual OTel context threading by moving span creation from the raw OTel SDK onto tracing + tracing-opentelemetry. This eliminates the cx: &Context first parameter on every DAO/LLM method, the Context::current_with_span(span) line in every handler, and the entire Context::current() orphan-span bug class — replacing hand-threading with #[instrument] + tracing's span propagation (automatic across .await; explicit carry across tokio::spawn — see the spike finding below).

Gated on

Spike #133 is complete — verdict: ADJUST (proceed). The mechanism is validated and the migration is viable, with one hard requirement the original plan under-specified: a bare #[instrument] does NOT propagate across tokio::spawn, so every spawn boundary must carry the parent span explicitly. See "Spike finding" below. No further gating.

Spike #133 finding (ADJUST — read before starting)

The spike proved it (regression test tests/otel_propagation.rs, all assertions passing):

  • #[instrument] on an async fn creates its span at first poll, not at call time. For a tokio::spawn-ed task the first poll is on a worker thread where the parent was never entered (tracing span context is thread-local) → the child exports as an orphan (fresh trace_id, parent_span_id=0000…).
  • The production shape — chat_turn_stream_inner's tokio::spawn(async move { run_streaming_turn(...).await }) — orphans (scenario S2). Same-task .await (S5) and same-thread (S1) cases propagate, so the OpenTelemetryLayer wiring is sound; the failure is specifically the spawn/thread boundary.
  • The fix is validated (S6 and S7 both propagate): capture tracing::Span::current() in the parent scope and carry it into the spawned future via .instrument(parent) or a span.enter() guard.
let parent = tracing::Span::current();
tokio::spawn(async move { run_streaming_turn(...).await }.instrument(parent)); // S6

Consequences for this migration:

  • Install the tracing subscriber process-globally (try_init(), not set_default() — the latter is thread-local and silently drops worker-thread spans).
  • #[instrument] is necessary but not sufficient at spawn sites; the explicit carry is required.
  • Keep tests/otel_propagation.rs (from the #133 patch) as the regression test.

Version pin (verified)

tracing-opentelemetry = "0.32" (resolves to 0.32.1; depends on opentelemetry 0.31.0 / opentelemetry_sdk 0.31.0) + tracing, tracing-subscriber, tracing-log. No otel bump. Enable the opentelemetry_sdk testing feature only for the regression test.

Scope

  1. Rewire init_tracing (src/otel.rs): keep the existing SdkTracerProvider (batch OTLP exporter + resource), and add a tracing_subscriber::Registry + OpenTelemetryLayer::new(tracer), installed globally via try_init() (not set_default()). Keep the log bridge.
  2. Convert raw span sites — global_tracer().start_with_context(...) → tracing spans (#[instrument] / info_span!). Includes the llm.request helpers and trace_db_call in src/otel.rs.
  3. Add #[instrument] to HTTP handlers, DAO methods, LLM client methods (openrouter/llamacpp/ollama), and the streaming fns.
  4. Carry the parent span across every tokio::spawn boundary (the ADJUST requirement): capture tracing::Span::current() before the spawn and .instrument(parent) the future (or a span.enter() guard). insight_chat::chat_turn_stream_inner is the critical site; audit for all other tokio::spawn / spawn_blocking sites too.
  5. Drop the cx: &Context first param from the LlmClient trait + impls, DAO traits + impls, and inherent helpers — context is ambient via the tracing span tree.
  6. Replace Context::current_with_span(span) in handlers with the tracing equivalent (or opentelemetry-instrumentation-actix-web::RequestTracing if it's a clean fit on otel 0.31).
  7. Keep log working via tracing-log (or migrate log:: → tracing:: macros as a separate pass).

Resolved as a byproduct

  • Issue #132 (remaining ambient Context::current()): its Bucket 1/2 request-driven sites become #[instrument] or drop the param; Bucket 3 background/watch jobs get a job-root info_span! + #[instrument] on the per-item fns. #132 is subsumed by this issue.

Non-goals / risks

  • Export parity: span names, attributes, and status must match what the raw-SDK path produces, or downstream dashboards/queries break. Verify against Jaeger/Tempo before and after.
  • Background jobs (no HTTP request): need an explicit job-root span so per-item spans group instead of scattering as roots.
  • Large diff: this touches nearly every span call site. Stage it (e.g. init_tracing + one module, verify in Jaeger/Tempo, then roll out) rather than one mega-commit.

References

## Goal Retire the manual OTel context threading by moving span creation from the raw OTel SDK onto **`tracing` + `tracing-opentelemetry`**. This eliminates the `cx: &Context` first parameter on every DAO/LLM method, the `Context::current_with_span(span)` line in every handler, and the entire `Context::current()` orphan-span bug class — replacing hand-threading with `#[instrument]` + `tracing`'s span propagation (automatic across `.await`; **explicit carry across `tokio::spawn`** — see the spike finding below). ## Gated on **Spike #133 is complete — verdict: ADJUST (proceed).** The mechanism is validated and the migration is viable, with one hard requirement the original plan under-specified: **a bare `#[instrument]` does NOT propagate across `tokio::spawn`**, so every spawn boundary must carry the parent span explicitly. See "Spike finding" below. No further gating. ## Spike #133 finding (ADJUST — read before starting) The spike proved it (regression test `tests/otel_propagation.rs`, all assertions passing): - `#[instrument]` on an **async** fn creates its span at **first poll**, not at call time. For a `tokio::spawn`-ed task the first poll is on a worker thread where the parent was never entered (tracing span context is thread-local) → the child exports as an **orphan** (fresh `trace_id`, `parent_span_id=0000…`). - The production shape — `chat_turn_stream_inner`'s `tokio::spawn(async move { run_streaming_turn(...).await })` — **orphans** (scenario S2). Same-task `.await` (S5) and same-thread (S1) cases propagate, so the `OpenTelemetryLayer` wiring is sound; the failure is specifically the spawn/thread boundary. - **The fix is validated** (S6 and S7 both propagate): capture `tracing::Span::current()` in the parent scope and carry it into the spawned future via `.instrument(parent)` **or** a `span.enter()` guard. ```rust let parent = tracing::Span::current(); tokio::spawn(async move { run_streaming_turn(...).await }.instrument(parent)); // S6 ``` Consequences for this migration: - Install the tracing subscriber **process-globally** (`try_init()`, **not** `set_default()` — the latter is thread-local and silently drops worker-thread spans). - `#[instrument]` is necessary but **not sufficient** at spawn sites; the explicit carry is required. - Keep `tests/otel_propagation.rs` (from the #133 patch) as the regression test. ## Version pin (verified) `tracing-opentelemetry = "0.32"` (resolves to 0.32.1; depends on `opentelemetry 0.31.0` / `opentelemetry_sdk 0.31.0`) + `tracing`, `tracing-subscriber`, `tracing-log`. No otel bump. Enable the `opentelemetry_sdk` `testing` feature only for the regression test. ## Scope 1. **Rewire `init_tracing`** (`src/otel.rs`): keep the existing `SdkTracerProvider` (batch OTLP exporter + resource), and add a `tracing_subscriber::Registry` + `OpenTelemetryLayer::new(tracer)`, installed **globally** via `try_init()` (not `set_default()`). Keep the log bridge. 2. **Convert raw span sites** — `global_tracer().start_with_context(...)` → `tracing` spans (`#[instrument]` / `info_span!`). Includes the `llm.request` helpers and `trace_db_call` in `src/otel.rs`. 3. **Add `#[instrument]`** to HTTP handlers, DAO methods, LLM client methods (`openrouter`/`llamacpp`/`ollama`), and the streaming fns. 4. **Carry the parent span across every `tokio::spawn` boundary** (the ADJUST requirement): capture `tracing::Span::current()` before the spawn and `.instrument(parent)` the future (or a `span.enter()` guard). `insight_chat::chat_turn_stream_inner` is the critical site; audit for all other `tokio::spawn` / `spawn_blocking` sites too. 5. **Drop the `cx: &Context` first param** from the `LlmClient` trait + impls, DAO traits + impls, and inherent helpers — context is ambient via the tracing span tree. 6. **Replace `Context::current_with_span(span)`** in handlers with the tracing equivalent (or `opentelemetry-instrumentation-actix-web::RequestTracing` if it's a clean fit on otel 0.31). 7. **Keep `log` working** via `tracing-log` (or migrate `log::` → `tracing::` macros as a separate pass). ## Resolved as a byproduct - **Issue #132** (remaining ambient `Context::current()`): its Bucket 1/2 request-driven sites become `#[instrument]` or drop the param; Bucket 3 background/watch jobs get a job-root `info_span!` + `#[instrument]` on the per-item fns. #132 is subsumed by this issue. ## Non-goals / risks - **Export parity**: span names, attributes, and status must match what the raw-SDK path produces, or downstream dashboards/queries break. Verify against Jaeger/Tempo before and after. - **Background jobs** (no HTTP request): need an explicit job-root span so per-item spans group instead of scattering as roots. - **Large diff**: this touches nearly every span call site. Stage it (e.g. `init_tracing` + one module, verify in Jaeger/Tempo, then roll out) rather than one mega-commit. ## References - Spike: **#133 — done, verdict ADJUST.** Cliff notes posted to #133 (comment 1839, 2026-09-28); regression test + patch in the #133 run artifacts. - Subsumes: #132 - Retires the manual threading introduced/fixed in PR #129 / `f850c53`
Author
Owner

Done: shipped as PR #148 (merged, e0c6c69), planned and executed via map #135. Every raw-OTel span is now a tracing span in both builds. No cx / ctx / context param remains. Every tokio::spawn (including the nested panic-isolation spawns) carries its parent span. Parity with the pre-migration baseline is confirmed (#143, branch baseline/span-parity-143). The conventions are in CLAUDE.md "Tracing". The logging follow-up is #147.

Done: shipped as PR #148 (merged, `e0c6c69`), planned and executed via map #135. Every raw-OTel span is now a `tracing` span in both builds. No `cx` / `ctx` / `context` param remains. Every `tokio::spawn` (including the nested panic-isolation spawns) carries its parent span. Parity with the pre-migration baseline is confirmed (#143, branch `baseline/span-parity-143`). The conventions are in CLAUDE.md "Tracing". The logging follow-up is #147.
Sign in to join this conversation.