Tracing: migrate spans from raw OTel SDK to tracing + tracing-opentelemetry (#135) #148

Merged
cameron merged 8 commits from feature/tracing-migration into master 2026-09-29 21:52:02 +00:00
Owner

Summary

Spans now come from tracing + tracing-opentelemetry in both dev and release builds. The hand-threaded OTel Context is gone: no cx / ctx / context parameter is left anywhere. Spans parent on the ambient span and are carried across every tokio::spawn. Map: #135.

 request
-  handler opens its own root span (from a parsed traceparent)
-    dao.get_exif(&cx, …)             # most DB spans ended up as their own trace
-  tokio::spawn(job)                  # job = a separate trace
+  GET /…  (tracing-actix-web root; honors incoming traceparent)
+    #[instrument] handler span
+      dao.get_exif(…)                # db.* span on the ambient span
+      llm.request                    # sends traceparent downstream
+    tokio::spawn(job.instrument(span))   # same trace
Commit Ticket What
e93f6b6 #138 One subscriber in both builds; OTLP export gated on OTLP_OTLS_ENDPOINT; W3C propagator
7a59afc #139 TracingLogger per-request root span
1c508cd #140 LLM clients + src/ai spans on tracing; .instrument at the chat / insight / TTS spawns
b6deca2 #141 trace_db_call on tracing; all Context params dropped (DAOs, handlers, drains, bins, tests)
26115b3 #142 Background job roots (watcher.tick / .library, thumbnails, video actors, reels)
f510940 #143 Parity fixes: nested panic-isolation spawn, watcher boot probe
517d1d4 — Docs: RUST_LOG also gates span export

The conventions are in CLAUDE.md under "Tracing".

Evidence

  • Before (#137 baseline, da3901c): most DB spans were single-span traces. The agentic 202 and its background job were two traces. The streaming chat had no handler span and its LLM / DB spans were loose.
    After (#143, same Jaeger / request set / DB snapshot):

    • operation names and semantic attribute keys are identical;
    • traceparent is intact (GET /photos is CHILD_OF the caller's 2222… in trace 1111…);
    • zero orphans: the agentic job is one 52-span trace, and the stream chat is one trace (POST /insights/chat/stream → ai.chat.turn.stream → llm.request(chat_stream)).

    Full diff: branch baseline/span-parity-143 → docs/tracing-baseline/post-migration/README.md.

  • Regression tests (new):

    otel_propagation   span in tokio::spawn nests only when the parent is carried (.instrument)
    otel_traceparent   incoming traceparent → root span → #[instrument] handler, one trace
    otel_llm_spans     llm.request (chat + chat_stream) nests under the caller across a spawn,
                       and sends its own span as traceparent  (fails if .instrument is removed)
    otel_db_spans      db.<type>.<op> name / attrs / status, nested under the ambient span
    otel_background    std-thread tick → block_on → spawn, and rayon explicit-parent shapes
    
  • cargo build ✅, cargo clippy --all-targets 0 warnings ✅, cargo fmt --check ✅, cargo test ✅ (690 lib + 775 integration + 5 OTel + 4 doc).

Merge Danger

Door: two-way

It's plain code with no migrations and no data changes. A revert restores the old span production.

Blast Radius: telemetry

  • SigNoz traces change shape, deliberately:

    • new per-request root spans;
    • deeper trees, since DB, background and streaming spans now nest;
    • DB spans come from the image-server tracer scope instead of db;
    • extra code.* / thread.* metadata on every span.

    Dashboards or queries keyed on "root span = operation name" or on scope db would need an update.

  • RUST_LOG now gates span export. One EnvFilter sits in front of the OTel layer too. At info/debug (the normal range) everything exports; warn turns span export and traceparent injection off.

  • Logs are unchanged: still env_logger in dev and opentelemetry-appender-log in release, and still not trace-correlated. That's tracked in #147.

  • Wide diff (~60 files), but it's mechanical: signature removals plus span-creation swaps. It rebases cleanly on master 8284509 (e2e #145).

🤖 Generated with Claude Code

## Summary Spans now come from `tracing` + `tracing-opentelemetry` in both dev and release builds. The hand-threaded OTel `Context` is gone: no `cx` / `ctx` / `context` parameter is left anywhere. Spans parent on the ambient span and are carried across every `tokio::spawn`. Map: #135. ```diff request - handler opens its own root span (from a parsed traceparent) - dao.get_exif(&cx, …) # most DB spans ended up as their own trace - tokio::spawn(job) # job = a separate trace + GET /… (tracing-actix-web root; honors incoming traceparent) + #[instrument] handler span + dao.get_exif(…) # db.* span on the ambient span + llm.request # sends traceparent downstream + tokio::spawn(job.instrument(span)) # same trace ``` | Commit | Ticket | What | |---|---|---| | `e93f6b6` | #138 | One subscriber in both builds; OTLP export gated on `OTLP_OTLS_ENDPOINT`; W3C propagator | | `7a59afc` | #139 | `TracingLogger` per-request root span | | `1c508cd` | #140 | LLM clients + `src/ai` spans on tracing; `.instrument` at the chat / insight / TTS spawns | | `b6deca2` | #141 | `trace_db_call` on tracing; all `Context` params dropped (DAOs, handlers, drains, bins, tests) | | `26115b3` | #142 | Background job roots (`watcher.tick` / `.library`, thumbnails, video actors, reels) | | `f510940` | #143 | Parity fixes: nested panic-isolation spawn, watcher boot probe | | `517d1d4` | — | Docs: `RUST_LOG` also gates span export | The conventions are in CLAUDE.md under "Tracing". ## Evidence - **Before (#137 baseline, `da3901c`):** most DB spans were single-span traces. The agentic 202 and its background job were **two traces**. The streaming chat had no handler span and its LLM / DB spans were loose. **After (#143, same Jaeger / request set / DB snapshot):** - operation names and semantic attribute keys are identical; - `traceparent` is intact (`GET /photos` is CHILD_OF the caller's `2222…` in trace `1111…`); - **zero orphans**: the agentic job is one 52-span trace, and the stream chat is one trace (`POST /insights/chat/stream → ai.chat.turn.stream → llm.request(chat_stream)`). Full diff: branch `baseline/span-parity-143` → `docs/tracing-baseline/post-migration/README.md`. - **Regression tests** (new): ```text otel_propagation span in tokio::spawn nests only when the parent is carried (.instrument) otel_traceparent incoming traceparent → root span → #[instrument] handler, one trace otel_llm_spans llm.request (chat + chat_stream) nests under the caller across a spawn, and sends its own span as traceparent (fails if .instrument is removed) otel_db_spans db.<type>.<op> name / attrs / status, nested under the ambient span otel_background std-thread tick → block_on → spawn, and rayon explicit-parent shapes ``` - `cargo build` ✅, `cargo clippy --all-targets` 0 warnings ✅, `cargo fmt --check` ✅, `cargo test` ✅ (690 lib + 775 integration + 5 OTel + 4 doc). ## Merge Danger **Door:** two-way It's plain code with no migrations and no data changes. A revert restores the old span production. **Blast Radius:** telemetry - **SigNoz traces change shape, deliberately:** - new per-request root spans; - deeper trees, since DB, background and streaming spans now nest; - DB spans come from the `image-server` tracer scope instead of `db`; - extra `code.*` / `thread.*` metadata on every span. Dashboards or queries keyed on "root span = operation name" or on scope `db` would need an update. - **`RUST_LOG` now gates span export.** One `EnvFilter` sits in front of the OTel layer too. At info/debug (the normal range) everything exports; `warn` turns span export and `traceparent` injection off. - **Logs are unchanged:** still `env_logger` in dev and `opentelemetry-appender-log` in release, and still not trace-correlated. That's tracked in #147. - **Wide diff** (~60 files), but it's mechanical: signature removals plus span-creation swaps. It rebases cleanly on master `8284509` (e2e #145). 🤖 Generated with [Claude Code](https://claude.com/claude-code)
cameron added 8 commits 2026-09-29 21:42:14 +00:00
Install ONE `tracing` subscriber in both build profiles via
`otel::init_tracing()` (previously release-only, so spans were a no-op in
dev). Behaviour is now environment-driven, not build-profile-driven:

- OTLP span export happens only when `OTLP_OTLS_ENDPOINT` is set
  (release / staging). Unset -> spans are still created with valid
  contexts (so outgoing `traceparent` injection keeps working) but export
  nowhere; the console `fmt` layer is what shows them.
- `tracing_subscriber::registry()` + `EnvFilter` (RUST_LOG) +
  `OpenTelemetryLayer` + console `fmt` layer, installed in both builds.
- Set the global W3C `TraceContextPropagator`: required by the
  `tracing-actix-web` request middleware (#139) and by the outgoing
  traceparent helpers, both of which read the *global* propagator.
- `tracing-log` bridge stays OFF (`default-features = false`) so the console
  fmt layer prints tracing spans only; `log` records keep their existing
  path (env_logger in debug, OTel logs in release) without double-printing.

Deps: + tracing, tracing-subscriber (env-filter/fmt/ansi), tracing-opentelemetry
0.32 (pins opentelemetry 0.31 + otel_sdk 0.31, no version bump); opentelemetry_sdk
gains the `testing` feature.

Add `tests/otel_propagation.rs`: the regression matrix from spike #133, pinning
the invariant the whole migration rests on -- an OTel context does NOT cross a
bare `tokio::spawn` on a multi-thread runtime (S2/S4 orphan onto a fresh trace)
but DOES with an explicit parent carry across the spawn (S6 `.instrument()`,
S7 `span.enter()`). This is why every spawn in the codebase must carry the parent.

clippy --all-targets clean; 690 lib + 775 integration + regression + 4 doc-tests pass.
Add a conventional per-request OTel server span using the standard
tracing-actix-web middleware (TracingLogger) as the outermost middleware,
so the whole request lives under one root span and an incoming W3C
traceparent is extracted onto it via the global text-map propagator
(installed in #138).

extract_context_from_request now sources the operation span's parent from
that root span (tracing::Span::current().context()) instead of re-parsing
the header, so per-handler operation spans nest under the root span as
one trace tree rather than duplicating it as a sibling. Header parsing
remains as a fallback for handlers invoked without the middleware (tests).

The literal per-handler span boilerplate is intentionally NOT removed here;
it becomes #[instrument] in the LLM (#140) and DAO (#141) migrations, where
the &Context threading disappears entirely.

tests/otel_traceparent.rs pins the behavior end-to-end: an incoming
traceparent's trace_id propagates to the request, the root span is parented
on the caller's (remote) span, and the operation span nests under the root
span rather than alongside it.
LlmClient methods no longer take an OpenTelemetry Context. llm.request is
now a tracing span (otel.kind=client, llm.provider/operation/model) that
parents on the caller's ambient span; traceparent injection reads the
span's OTel context via OpenTelemetrySpanExt.

The src/ai feature spans (handlers, insight generation, chat, persona
chat, daily summaries, TTS) move to #[instrument] / info_span!, and every
LLM-bearing tokio::spawn carries its parent span with .instrument(): the
streaming chat turn (chat_turn_stream_inner), async chat / persona turns,
background insight jobs and TTS jobs. Sub-spans in the agentic loops
(ai.chat.loop, ai.agentic.loop) instrument each LLM / tool await.

DAO calls keep their explicit Context (derived from the tracing span)
until the DAO migration (#141).

tests/otel_llm_spans.rs pins nesting + traceparent for the blocking and
streaming paths across a spawn on a multi-thread runtime.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
trace_db_call no longer takes an OpenTelemetry Context: it opens a
db.<query_type>.<operation> span (same name via otel.name, same
db.query_type / db.operation attrs) on the caller's ambient tracing span
and runs the DAO body inside it. The cx / ctx / context parameter is gone
from every DAO trait method, impl and call site, and from the helpers and
background drains that only threaded it.

The remaining request-handler spans (files, tags, faces, image, video,
favorites, duplicates, memories) move to #[instrument]; the
Context::current_with_span / with_remote_span_context plumbing is gone, as
is extract_context_from_request (the tracing-actix-web root span covers
it). otel::set_span_attributes replaces BoxedSpan::set_attributes.

Background-job raw spans (thumbnails, video actors) are left for #142.

tests/otel_db_spans.rs pins name, attributes, status and nesting (across
an instrumented spawn); otel_traceparent now uses an #[instrument]
handler. CLAUDE.md documents the tracing conventions.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Background work has no request parent, so each job now opens a named
tracing root and carries it into its fan-out:

- watcher: `watcher.tick` (scan=quick|full) entered per tick on the
  watcher's std thread, `watcher.library` per library, and
  `watcher.playlist_cleanup` per orphaned-HLS pass. face_watch /
  clip_watch carry the ambient span into every per-candidate
  tokio::spawn and give each call its own `face_watch.detect` /
  `clip_watch.encode` span.
- thumbnails: `creating thumbnails` via #[instrument]; per-video spans on
  rayon workers name their parent explicitly.
- video actors: `playlistgenerator.generate_playlist` and
  `preview_clip.generate` are tracing roots that instrument their futures.
- reels: `reel.job` (created before the spawn, so on-demand jobs stay in
  the request trace), `reel.pregen_batch`, `reel.cache_sweep`.
- RefreshThumbnailsMessage and the dead-code GIF job move to tracing.

No raw OpenTelemetry span creation is left outside otel.rs;
`global_tracer` is removed.

tests/otel_background.rs pins the std-thread tick -> block_on -> spawn
shape and the rayon explicit-parent shape.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Found by the parity capture: both insight-generation handlers run the
generation inside a nested tokio::task::spawn (panic isolation) that was
not instrumented, so the background ai.insight.* trace still split off
from its 202 request. The watcher's boot-time availability probe ran
before the first tick span, leaving its count_for_library DB spans as
roots; it now opens `watcher.initial_probe`.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
The subscriber's single EnvFilter fronts both the console and the OTel
layer, so RUST_LOG decides which spans exist for export. Documented in
CLAUDE.md (supported range info/debug) and at the filter in init_tracing.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
cameron merged commit e0c6c696f2 into master 2026-09-29 21:52:02 +00:00
cameron deleted branch feature/tracing-migration 2026-09-29 21:52:02 +00:00
Sign in to join this conversation.