From 28c888bf08d4e03294b0384cdfb645b32a461a97 Mon Sep 17 00:00:00 2001 From: Jens Holdgaard Pedersen Date: Sat, 25 Jul 2026 01:18:40 +0200 Subject: [PATCH 1/3] docs(rfc): specify RFC 0039 (inbound trace propagation) + 0040 (DataFusion operators) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Two traces-completeness RFCs, at `specified` after maintainer design sign-off (§5 criteria written, scenarios numbered). RFC 0039 — inbound trace-context propagation: a global TraceContextPropagator + per-ingress extract/set_parent so the ingest/query/MCP SERVER spans continue the caller's trace instead of starting roots. Notable: the ingest span is born after a tokio::spawn, so the extracted Context is carried across (the RFC0038.3 boundary, for the parent this time); and the trace OTel crates promote from dev- to prod-dependencies in ingester/server. RFC 0040 — DataFusion operator instrumentation: per-ExecutionPlan-node child spans under POST /v1/query, reconstructed post-hoc from the finished plan. DataFusion 54's BaselineMetrics records real wall-clock Start/EndTimestamp per operator, so the spans carry genuine bounds (not synthetic). A new datafusion+opentelemetry-only crate (ourios-df-otel) designed to lift to datafusion-contrib as datafusion-opentelemetry. Honours RFC0038.2 (O(plan), never per-record); zero cost when unsampled. Signed-off-by: Jens Holdgaard Pedersen --- docs/SUMMARY.md | 2 + .../0039-inbound-trace-context-propagation.md | 282 ++++++++++++++++ ...040-datafusion-operator-instrumentation.md | 305 ++++++++++++++++++ 3 files changed, 589 insertions(+) create mode 100644 docs/rfcs/0039-inbound-trace-context-propagation.md create mode 100644 docs/rfcs/0040-datafusion-operator-instrumentation.md diff --git a/docs/SUMMARY.md b/docs/SUMMARY.md index ab34744e3..44cc8e477 100644 --- a/docs/SUMMARY.md +++ b/docs/SUMMARY.md @@ -65,6 +65,8 @@ - [RFC 0036 — Write-side layout](./rfcs/0036-write-side-layout.md) - [RFC 0037 — GenAI / structured-event logs](./rfcs/0037-genai-structured-log-events.md) - [RFC 0038 — Self-tracing](./rfcs/0038-self-tracing.md) +- [RFC 0039 — Inbound trace-context propagation](./rfcs/0039-inbound-trace-context-propagation.md) +- [RFC 0040 — DataFusion operator instrumentation](./rfcs/0040-datafusion-operator-instrumentation.md) # Talks diff --git a/docs/rfcs/0039-inbound-trace-context-propagation.md b/docs/rfcs/0039-inbound-trace-context-propagation.md new file mode 100644 index 000000000..3fab3014d --- /dev/null +++ b/docs/rfcs/0039-inbound-trace-context-propagation.md @@ -0,0 +1,282 @@ +--- +rfc: 0039 +title: Inbound trace-context propagation — SERVER spans continue the caller's trace +status: specified +author: Jens Holdgaard Pedersen +drafting-assistance: Claude +created: 2026-07-25 +supersedes: — +superseded-by: — +--- + +# RFC 0039 — Inbound trace-context propagation + +## 1. Summary + +Ourios's request-scoped SERVER spans (RFC 0038) are currently created as trace +**roots**: they never read the incoming W3C `traceparent`/`tracestate`, so a +caller's trace stops at the Ourios boundary. This RFC installs a global +`TraceContextPropagator` and, at each ingress, extracts the caller's +`opentelemetry::Context` from the request carrier (HTTP headers / gRPC metadata) +and attaches it as the span's parent via `OpenTelemetrySpanExt::set_parent`. The +observable result: the `ingest logs`, `POST /v1/query`, and MCP tool spans join +the caller's distributed trace instead of starting a disconnected one, and a +`parentbased` sampler honours the caller's sampling decision. No new signal, no +schema change — this completes the traces pillar that RFC 0038 established. + +## 2. Motivation + +The point of a `SERVER`-kind span is to be the server half of a client's +request: linked to the caller's `CLIENT`/`PRODUCER` span through propagated +context, so an operator can follow one trace from the application that emitted a +log, through the OTLP exporter, into Ourios's ingest path — or from a query +client into Ourios's querier. RFC 0038 built the spans but not the propagation, +so today every Ourios span is a root. For a telemetry backend that sits *inside* +someone else's distributed system, that is the most consequential remaining gap +in the traces signal: correlation-within-Ourios works (RFC 0038), but +correlation-across-the-boundary does not. + +This is deliberately a small, bounded change at the ingress layer. It touches +the traces pillar (hence an RFC), but it adds no new spans, no new attributes of +consequence, and no on-disk change — it only sets the *parent* of spans that +already exist. + +## 3. Proposed design + +### 3.1 The one global: a W3C propagator + +Install the W3C Trace Context propagator once, in `ourios-telemetry`'s `init()`, +alongside the existing provider installation: + +```rust +opentelemetry::global::set_text_map_propagator( + opentelemetry_sdk::propagation::TraceContextPropagator::new(), +); +``` + +This is unconditional (cheap, stateless) and independent of whether the traces +pipeline is enabled — extraction is a no-op when no exporter is installed, and +installing the propagator regardless keeps the ingress code uniform. `baggage` +propagation is out of scope (§7). + +### 3.2 The ingress map + +Five span sites open on the request path. The carrier — where the incoming +`traceparent` lives — is not always co-located with the span: + +| # | Span | Site (file:line) | Carrier & where it is reachable | +|---|---|---|---| +| A | `ingest logs` (gRPC) | span in `ingest_bound` (`pipeline.rs:291`); entry `LogsReceiver::export` (`grpc.rs:152`) | tonic `MetadataMap` via `request.metadata()` (`grpc.rs:159`), or raw `http::HeaderMap` in the tower auth layer `AuthService::call` (`grpc.rs:102`) | +| B | `ingest logs` (HTTP) | span in `ingest_bound`; entry `handle_logs` (`http.rs:95`) | axum `HeaderMap` (`http.rs:95`) | +| C | `POST /v1/query` | `handle_query` (`querier.rs:421`) | axum `HeaderMap` (`querier.rs:423`) — same fn as the span | +| D | `execute_tool ` | the three `_traced` fns (`mcp.rs:333/416/488`) | `ctx.extensions.get::()?.headers` (as `mcp_session_id` already reads, `mcp.rs:223`) | + +For **C** and **D** the carrier and the span live in the same function: +extract and `set_parent` at the top of the instrumented fn. + +### 3.3 The `tokio::spawn` boundary (ingest) + +The ingest span is the hard case. For **A** and **B** the `ingest logs` span is +created inside `ingest_bound`, which runs inside a freshly `tokio::spawn`ed task +(`grpc.rs:167`, `http.rs:146`) — the same spawn boundary RFC 0038.3 is about. +The carrier is only reachable in the handler **before** the spawn; the span is +born **after** it, in a different task. Ambient current-context does not cross +`tokio::spawn`. + +Therefore the fix cannot rely on context flow. The handler must: + +1. Extract `let cx = propagator.extract(&carrier);` **before** the spawn (where + the `MetadataMap`/`HeaderMap` is in scope). +2. Move `cx` into the spawned closure and hand it to `ingest_bound` as an + explicit parameter (`parent: opentelemetry::Context`). +3. Inside `ingest_bound`, after the span is entered, call + `tracing::Span::current().set_parent(cx)`. + +This mirrors how RFC 0038.3 already moves *span* context across the same +boundary via `.instrument(Span::current())`; here it is the extracted *parent* +context that is moved. `ingest_bound`'s signature gains one parameter; the two +call sites (`grpc.rs`, `http.rs`) each extract before spawning. + +### 3.4 The extractor shims + +`opentelemetry::propagation::Extractor` is a two-method trait (`get`, `keys`). +Two thin adapters are needed: + +- **axum `HeaderMap`** — `opentelemetry-http` provides `HeaderExtractor`, but to + avoid a new dependency a ~10-line local `struct HeaderExtractor<'a>(&'a + HeaderMap)` is equivalent (the C/D sites and the HTTP ingest site B). +- **tonic `MetadataMap`** — a `struct MetadataExtractor<'a>(&'a MetadataMap)` + reading ASCII metadata keys (site A, if extracting from gRPC metadata rather + than the raw HTTP headers at the tower layer). + +Both live in `ourios-ingester`'s receiver module (and re-used by +`ourios-server`), or in a small shared helper. The RFC prefers extracting site A +from the **tower auth layer's raw `http::HeaderMap`** (`grpc.rs:102`), so a +single `HeaderExtractor` covers A/B/C/D and no tonic-metadata adapter is needed — +the auth layer already reads `request.headers()` and inserts into extensions, so +the extracted `Context` can ride the same request-extensions channel the auth +binding uses (`grpc.rs:119`), reaching `ingest_bound` without a signature change. +This is the preferred shape; §7 leaves the exact carry-channel (explicit +parameter vs. request extension) to implementation review. + +### 3.5 Dependency promotion (the non-obvious cost) + +Today the trace-capable OTel crates are `[dev-dependencies]` only in +`ourios-ingester` and `ourios-server` — their production `[dependencies]` carry +`opentelemetry` with the **`metrics`** feature alone. The `otel.kind` string +fields on the instrument macros work without them because the tracing→OTel +bridge lives in `ourios-telemetry`. Propagation needs real types in production +code (`TraceContextPropagator`, `Context`, `OpenTelemetrySpanExt::set_parent`), +so this RFC promotes to `[dependencies]` in both crates: + +- `opentelemetry` (add the `trace` feature), +- `opentelemetry_sdk` (`trace` feature, for `TraceContextPropagator`), +- `tracing-opentelemetry` (for `OpenTelemetrySpanExt`). + +This is a real compile-surface and build-time cost and is called out here so it +is a conscious choice, not a surprise in the diff. + +### 3.6 Sampling interplay + +With a parent context attached, the SDK's default `parentbased_always_on` +sampler (RFC 0038 §3.4, resolved from `OTEL_TRACES_SAMPLER`) honours the +caller's sampled flag: a caller who sampled the trace propagates `sampled=1` and +Ourios records/exports its spans within that trace; a caller who did not +propagates `sampled=0` and Ourios's spans are dropped, keeping the trace +consistent end-to-end. This is desirable and is the reason to prefer a +`parentbased` sampler as the default — it is what makes propagation meaningful. +A request with no incoming context falls back to the root sampling rule +unchanged (backward-compatible). + +### 3.7 `set_parent`'s `Result` + +`tracing-opentelemetry` 0.33's `set_parent` returns `Result<(), +SetParentError>`. A failure means the span had no OTel layer (traces disabled) — +expected and non-fatal. The call ignores the error (`let _ = …`) or matches it +away; it is never a request-affecting error (no `unwrap`/`expect`, per +`CLAUDE.md`). + +## 4. Alternatives considered + +**Do nothing (status quo — roots).** Correlation within Ourios works; the cost +is that no operator can follow a trace across the Ourios boundary. For a +telemetry backend this is precisely the interesting join, so the gap is not +acceptable long-term. + +**Extract at the shared `ingest_bound` span only, via ambient context.** Fails: +the carrier does not reach `ingest_bound` (its signature has no request), and +`tokio::spawn` severs ambient context (§3.3). Extraction must happen in the +handler. + +**A tower/tonic middleware layer that extracts and injects context for all +routes.** Cleaner in principle (one layer, no per-handler code), and worth +revisiting — but the ingest span is born *after* the spawn inside `ingest_bound`, +so a middleware that sets the current context still would not reach that span +without the same explicit hand-off. A layer would help sites B/C/D but not the +hard site A/ingest; this RFC does the explicit extraction uniformly and leaves a +middleware refactor as a follow-up once the pattern is proven. + +**Adopt `opentelemetry-http`'s `HeaderExtractor` as a dependency.** Reasonable, +but it is one more crate for a ~10-line shim; the RFC inlines the extractor. If +a tonic-metadata extractor is later needed, revisit. + +## 5. Acceptance criteria + +> **Scenario RFC0039.1 — a SERVER span continues an incoming trace.** +> **Given** the traces pipeline enabled and the global `TraceContextPropagator` +> installed, +> **When** a `POST /v1/query` request and an OTLP `Export` (both gRPC and HTTP) +> each arrive carrying a valid W3C `traceparent` for trace `T` span `S`, +> **Then** the resulting `POST /v1/query` and `ingest logs` spans each have +> `trace_id == T` and parent span id `== S` (they are children of the caller's +> span, not roots). + +> **Scenario RFC0039.2 — no incoming context is a fresh root, unchanged.** +> **Given** the same setup, +> **When** a request arrives with **no** `traceparent`, +> **Then** the span is a fresh root with a newly minted `trace_id` and no +> parent — identical to pre-RFC behaviour, and no error is raised. + +> **Scenario RFC0039.3 — the extracted context survives the ingest spawn.** +> **Given** the gRPC and HTTP OTLP receivers, whose `ingest logs` span is created +> inside a `tokio::spawn`ed `ingest_bound`, +> **When** a batch arrives carrying `traceparent` for trace `T`, +> **Then** the `ingest logs` span (and its `commit wal` child) resolve to +> `trace_id == T` — proving the parent context was extracted before the spawn and +> applied to the post-spawn span (the RFC 0038.3 boundary, for the parent +> context this time). + +> **Scenario RFC0039.4 — the caller's sampling decision is honoured.** +> **Given** the default `parentbased` sampler, +> **When** a request carries `traceparent` with the sampled flag **unset** +> (`-00`), and separately with it **set** (`-01`), +> **Then** the unset case produces **no** exported span (the trace was not +> sampled upstream), and the set case exports the span within trace `T` — the +> parent decision governs, end to end. + +> **Scenario RFC0039.5 — a malformed carrier is treated as absent.** +> **Given** the propagator, +> **When** a request carries a syntactically invalid `traceparent`, +> **Then** extraction yields an empty context, the span becomes a fresh root +> (as RFC0039.2), and no panic or request error occurs. + +> **Scenario RFC0039.6 — the MCP tool span joins the caller's trace.** +> **Given** an MCP `tools/call` over `/mcp` carrying `traceparent` for trace `T`, +> **When** the tool executes, +> **Then** the `execute_tool ` span resolves to `trace_id == T`, parented +> to the caller — so an agent driving Ourios's tools sees the tool execution +> inside its own trace. + +## 6. Testing strategy + +Mapped to `CLAUDE.md` §6.2: + +- **RFC0039.1 / .2 / .5 / .6** — integration tests in `ourios-server` / + `ourios-ingester` using the RFC 0038 scoped-`InMemorySpanExporter` harness: + drive `handle_query`, `handle_logs`, and (global-tracer binary, per RFC0038.1 + MCP arm) an MCP `tools/call`, each with an injected `traceparent` header, then + assert `SpanData.span_context.trace_id()` / `.parent_span_id()`. The + no-context and malformed-context cases assert a fresh, valid root and no error. +- **RFC0039.3** — extends the RFC0038.3 spawn-boundary harness + (`rfc0038_3_spawn_boundary.rs`, global tracer): call `LogsReceiver::export` + directly with a `traceparent` in the request metadata/headers and assert the + `ingest logs` + `commit wal` spans carry the injected `trace_id`. +- **RFC0039.4** — a sampler test: with `OTEL_TRACES_SAMPLER=parentbased_always_on` + (default), inject `-00` vs `-01` traceparents and assert exported-span presence. + The parent-based resolution itself is upstream SDK behaviour; the test covers + Ourios's wiring (that the extracted context reaches the sampler). +- The extractor shims get a unit test (round-trip a `traceparent` through a + `HeaderMap` and back to a `SpanContext`). + +## 7. Open questions + +- [ ] Carry-channel for the ingest parent context: explicit `ingest_bound` + parameter vs. a request-extension (the auth layer already inserts into + `request.extensions_mut()`; the extracted `Context` could ride the same + channel with no signature change). §3.4 prefers the extension; confirm on + review. +- [ ] Should site A extract from the tower auth layer's raw `http::HeaderMap` + (one `HeaderExtractor` for all sites, no tonic-metadata adapter) or from + tonic's `MetadataMap` in `export`? The former is preferred (§3.4). +- [ ] MCP tool spans are `otel.kind = "internal"` and lack an enclosing Ourios + SERVER span for `/mcp` (rmcp's `serve_inner` is muted by the `rmcp=off` + loop-guard, RFC0038.7). An INTERNAL span continuing a *remote* parent is + valid but slightly unusual — is a dedicated `/mcp` SERVER span warranted + instead? Deferred; RFC0039.6 parents the INTERNAL span directly for now. +- [ ] `tracestate` and `baggage`: `tracestate` rides along with `TraceContext` + automatically; `baggage` propagation is explicitly out of scope here. +- [ ] Response-side **injection** (Ourios as a client to object storage / a + downstream) is a separate concern — not in this RFC (inbound only). + +## 8. References + +- RFC 0038 (self-tracing) — the spans this RFC gives parents to; §3.3 (the + `tokio::spawn` boundary), §3.4 (the sampler), RFC0038.3 (spawn-boundary test + harness), RFC0038.7 (`rmcp=off` loop-guard). +- `CLAUDE.md` §6.3 (observability of ourselves), §2 (the traces pillar via + RFC 0038), §6.1 (no `unwrap`/`expect` in non-test code). +- W3C Trace Context — . +- OpenTelemetry — [context propagation](https://opentelemetry.io/docs/specs/otel/context/api-propagators/); + [`OpenTelemetrySpanExt::set_parent`](https://docs.rs/tracing-opentelemetry/0.33.0/tracing_opentelemetry/trait.OpenTelemetrySpanExt.html). +- Pinned: `opentelemetry` 0.32.0, `opentelemetry_sdk` 0.32.1, + `tracing-opentelemetry` 0.33.0. diff --git a/docs/rfcs/0040-datafusion-operator-instrumentation.md b/docs/rfcs/0040-datafusion-operator-instrumentation.md new file mode 100644 index 000000000..142faf388 --- /dev/null +++ b/docs/rfcs/0040-datafusion-operator-instrumentation.md @@ -0,0 +1,305 @@ +--- +rfc: 0040 +title: DataFusion → OTel operator instrumentation — the query span as an operator tree +status: specified +author: Jens Holdgaard Pedersen +drafting-assistance: Claude +created: 2026-07-25 +supersedes: — +superseded-by: — +--- + +# RFC 0040 — DataFusion → OTel operator instrumentation + +## 1. Summary + +The `POST /v1/query` span (RFC 0038) is flat: it times the whole query but shows +nothing of *where* the time went. This RFC deepens it into an operator tree by +emitting one OTel child span per `ExecutionPlan` node, reconstructed post-hoc +from the finished physical plan. DataFusion 54 records genuine wall-clock +`StartTimestamp`/`EndTimestamp` on every `BaselineMetrics`-backed operator, so +the spans carry **real** bounds (not synthetic timings), with `output_rows`, +`elapsed_compute`, `output_bytes`, and pruning counts as attributes. The logic +lives in a new, dependency-light crate (`ourios-df-otel`) whose only deps are +`datafusion` and `opentelemetry` — so it lifts cleanly to a standalone +`datafusion-opentelemetry` for `datafusion-contrib`, the dogfood-then-give-back +path RFC 0038 §7 named. This is a new crate (hence an RFC per `CLAUDE.md` §7) and +extends the traces pillar (§5.1). + +## 2. Motivation + +Ask "why was this query slow?" and today's trace answers only "it took 340 ms." +Every mature database instrumentation — the postgres client span with +`db.query.text` and per-statement timing is the canonical example — lets an +operator see the work *decomposed*. For a query engine, the natural +decomposition is the physical plan: which operator scanned how many row groups, +where pruning helped, which node dominated the wall clock. Ourios already reads +this per-operator data (`scan_stats`/`fold_metrics`) but only rolls it up into +aggregate `QueryStats` **metrics** — the per-node structure is discarded. This +RFC keeps that structure as **spans**, turning the flat query span into the +operator tree an engine's trace should be. + +It is also strategic. RFC 0038 §7 committed to building a reusable +`datafusion-opentelemetry` component for `datafusion-contrib` — "built for +Ourios's own query span first and then extracted upstream." This RFC is that +build. Keeping the crate's dependencies to `datafusion` + `opentelemetry` (no +Ourios types) is what makes the extraction a lift, not a rewrite. + +## 3. Proposed design + +### 3.1 The timing source (the finding that shapes everything) + +DataFusion 54 operators built on `BaselineMetrics` record a real +`StartTimestamp` at stream construction and a real `EndTimestamp` on +drain/`Drop` (`datafusion-physical-plan-54/src/metrics/baseline.rs:75,135,175`). +These surface as `MetricValue::StartTimestamp` / `EndTimestamp` in the node's +`MetricsSet`, and `MetricsSet::aggregate_by_name()` reduces per-partition +instances to **earliest start** / **latest end** +(`metrics/value.rs:915`) — exactly the wall-clock interval a span needs. This is +the crux: because the timestamps are genuine, the operator spans are truthful, +not derived. `ElapsedCompute` (CPU-busy time) becomes an *attribute*, never the +span's timeline. + +Two residual constraints, both benign for Ourios: + +1. **Post-hoc.** Metrics populate only after `collect()` returns. Every Ourios + query path fully buffers via `datafusion::physical_plan::collect` + (`lib.rs:73`; never `execute_stream`), so the plan is finished and its + timestamps final when we read them. Spans are therefore built *after* the + query, with explicit start/end — not opened live. +2. **Opt-in metrics.** `ExecutionPlan::metrics()` returns `None` for operators + that do not use `BaselineMetrics` (`execution_plan.rs:492`). A node with no + timestamps is **skipped** (no span), so the tree shows the operators that + actually carry timing; children of a skipped node re-parent to the nearest + timed ancestor (or the query span). + +### 3.2 The walk — reuse what already exists + +`accumulate_scan_stats` (`lib.rs:703`) already recurses the physical plan tree: +for each node it reads `plan.metrics()` and recurses over `plan.children()`. The +span reconstruction is the same walk with a different fold — for each timed +node emit a span instead of (in addition to) accumulating stats. The retained +`plan: Arc` is available at exactly the sites `scan_stats` is +called today, before the `Arc` drops: `lib.rs:1355` (count scan), `:1422` +(aggregate), `:1492` (row materialize), `drift.rs:191`. The new crate exposes a +single entry point: + +```rust +// ourios-df-otel +pub fn record_plan_spans( + plan: &dyn ExecutionPlan, + parent: &opentelemetry::Context, + tracer: &dyn opentelemetry::trace::Tracer, +); +``` + +It walks `plan`, and for each node with `StartTimestamp`+`EndTimestamp` builds a +child span (parent = its plan-parent's span, root = `parent`) named by +`ExecutionPlan::name()` (e.g. `DataSourceExec`, `FilterExec`, `AggregateExec` — +low-cardinality, the operator kind). + +### 3.3 Span emission — the raw OTel span builder (not `#[instrument]`) + +Backdated spans cannot come from `#[tracing::instrument]` (it starts "now"). The +crate uses the OTel SDK span builder directly: + +```rust +let span = tracer + .span_builder(node.name().to_string()) + .with_kind(SpanKind::Internal) + .with_start_time(start) // real StartTimestamp + .with_attributes(node_attributes(metrics)) // rows, elapsed, bytes, pruning + .start_with_context(tracer, &parent_cx); +// … recurse into children with this span's context as their parent … +span.end_with_timestamp(end); // real EndTimestamp +``` + +Attributes are drawn from the same `MetricValue` variants `fold_metrics` reads, +plus the general ones: `output_rows`, `elapsed_compute` (as a duration/ns), +`output_bytes`, and the pruning ratio (`row_groups_pruned`/`matched`). Names +follow OTel conventions where one exists and an `ourios.query.operator.*` / +`datafusion.*` namespace otherwise — **the exact attribute names go through the +OTel MCP + weaver registry** (`CLAUDE.md` OTel-alignment rule) before landing; +§7 tracks it. + +### 3.4 Parenting into the query span + +The operator spans must nest under `POST /v1/query`. That span is a *tracing* +span (in `ourios-server`); the plan executes in *`ourios-querier`*. The parent +`opentelemetry::Context` is obtained inside the querier via +`tracing::Span::current().context()` (`OpenTelemetrySpanExt`) — the query span is +current throughout `run_query`, including the post-`collect` reconstruction. This +adds `tracing-opentelemetry` + `opentelemetry`(trace) as `ourios-querier` +dependencies (parallel to RFC 0039's promotion, and called out likewise). The +querier then calls `ourios_df_otel::record_plan_spans(&plan, &cx, &tracer)` at +the `scan_stats` sites. + +No DataFusion type crosses any Ourios public boundary (H6): `record_plan_spans` +is an internal side-effect on the retained plan; the query *response* and *error* +surfaces are unchanged. + +### 3.5 The new crate + +`crates/ourios-df-otel/` — deps `datafusion` (the pinned 54) and `opentelemetry` +(trace) **only**, no `ourios-*` deps. `#![deny(unsafe_code)]`. This isolation is +deliberate: it is what lets the crate lift to a standalone +`datafusion-opentelemetry` for `datafusion-contrib` with no un-picking. The +Ourios-specific wiring (getting the parent context, the call sites) stays in +`ourios-querier`; the crate is pure "`ExecutionPlan` tree + parent context → +spans." + +### 3.6 Cost discipline (RFC 0038's boundary, honoured) + +The reconstruction is **O(plan nodes)** — a handful per query — and runs **once +per query**, after execution. It is not per-record and not per-batch (RFC +0038.2's invariant). It is gated on traces being enabled *and* the query span +being sampled: an unsampled query skips the walk entirely (check the parent +context's `is_sampled()` before walking), so the cost is zero on the sampled-out +path and bounded-tiny on the sampled path. A `criterion` guard confirms no +query-latency regression on the sampled-out path (the default). + +## 4. Alternatives considered + +**(b) True live spans by wrapping `ExecutionPlan`/`RecordBatchStream`.** Insert a +wrapping operator via a `PhysicalOptimizerRule` +(`SessionStateBuilder::with_physical_optimizer_rule`) that opens a span in +`execute()` and ends it when the stream drains. This captures true intra-operator +concurrency/overlap that the post-hoc min/max bounds flatten. But it adds a +per-poll wrapper to the hot execution path, complicates the `collect`-based flow, +and re-derives timing DataFusion already records — all for concurrency detail +few will read. Deferred: it is the natural *next* increment of the extractable +crate, not the first cut. Post-hoc (a) already yields real bounds. + +**(c) One query span, plan as an attribute/event.** Attach +`displayable(plan).indent()` plus rolled-up metrics as attributes on the existing +query span. Cheapest, and a fine fallback when traces are off — but it is a +string blob, not a navigable operator tree, and defeats the "where did time go" +goal (no per-operator timeline). Rejected as the primary design; the plan-text +*may* still ride the query span as a supplementary attribute (§7). + +**Do nothing (flat query span).** The query span still gives end-to-end latency +and the aggregate pruning metrics. But the per-operator structure — already +computed and thrown away — stays invisible, and the `datafusion-contrib` +give-back never happens. + +**A module inside `ourios-querier` instead of a crate.** Simpler in the tree, but +couples the logic to Ourios and forfeits the extraction. The whole value is a +`datafusion`+`opentelemetry`-only component; a crate is what encodes that. + +**Adopt an existing `datafusion-contrib` OTel crate if one now exists.** None is +referenced in-repo, and RFC 0038 treated this as greenfield — but the ecosystem +moves. §7 makes "check `datafusion-contrib` for a current crate" a gate before +building, to adopt-or-align rather than duplicate. + +## 5. Acceptance criteria + +> **Scenario RFC0040.1 — a query emits an operator span tree under its query +> span.** +> **Given** traces enabled, the query span sampled, and a logs query that scans +> at least one Parquet file, +> **When** the query executes, +> **Then** at least one child span is emitted whose parent (transitively) is the +> `POST /v1/query` span, one per timed `ExecutionPlan` node, each named by the +> operator kind (`DataSourceExec`, `FilterExec`, …), forming the plan tree. + +> **Scenario RFC0040.2 — operator spans carry real wall-clock bounds.** +> **Given** the same, +> **When** the tree is reconstructed, +> **Then** each operator span's start/end equals the node's aggregated +> `StartTimestamp`/`EndTimestamp` (earliest-start / latest-end across +> partitions) — genuine wall-clock, within the parent query span's interval, not +> derived from `ElapsedCompute`. + +> **Scenario RFC0040.3 — the metric attributes are present and correct.** +> **Given** an operator reporting `output_rows`, `elapsed_compute`, +> `output_bytes`, and (for the scan) pruning counts, +> **Then** its span carries those as attributes, equal to the values +> `fold_metrics`/`aggregate_by_name` reads for the same node — the span and the +> `QueryStats` metric never disagree about the same operator. + +> **Scenario RFC0040.4 — nodes without metrics are skipped, not faked.** +> **Given** an `ExecutionPlan` node whose `metrics()` is `None` (no +> `BaselineMetrics`), +> **Then** no span is emitted for it, and its children re-parent to the nearest +> timed ancestor (or the query span) — the tree never invents a timeline. + +> **Scenario RFC0040.5 — O(plan), once per query; never per-record.** +> **Given** a query returning N records, +> **When** it executes, +> **Then** the number of operator spans is bounded by the plan node count and is +> **independent of N** (RFC 0038.2's invariant), and the reconstruction runs once +> after `collect`, not per batch or per row. + +> **Scenario RFC0040.6 — zero cost when unsampled / traces off.** +> **Given** traces disabled, or the query span not sampled, +> **When** a query executes, +> **Then** the plan walk does not run, no operator span is emitted, and the +> query-latency benchmark shows no regression attributable to this feature (the +> default, sampled-out path). + +## 6. Testing strategy + +Mapped to `CLAUDE.md` §6.2: + +- **RFC0040.1 / .2 / .3 / .4** — integration tests in `ourios-querier` (or a + `ourios-df-otel` test) over the scoped-`InMemorySpanExporter` harness: run a + real query against a small fixture Parquet set with the query span current, + then assert the exported spans' names, parent linkage, start/end (against the + plan's own `aggregate_by_name` timestamps, read independently in the test so + the assertion is not self-referential), and attributes. A synthetic plan with + a `metrics()`-`None` node covers .4. +- **RFC0040.5** — a span-count assertion parameterised over N (records) asserting + operator-span count is constant in N (the RFC 0038.2 shape), and a check that + the walk is invoked once per query (a counter/mock). +- **RFC0040.6** — a `criterion` guard on the `Parquet → query result` hot-path + benchmark confirming no regression on the traces-off / unsampled path; a unit + test that the walk is skipped when the parent context is not sampled. +- Attribute-name conformance rides the existing `weaver registry live-check` + gate once the `ourios.query.operator.*` / `datafusion.*` names are registered + (§3.3, §7). +- `ourios-df-otel` unit tests over hand-built `MetricsSet`s: the + `MetricValue → attribute` mapping, and the timestamp reduction. + +## 7. Open questions + +- [ ] **Attribute names.** `output_rows`/`elapsed_compute`/`output_bytes`/pruning + — which map to existing OTel semconv (there is a nascent `db.*` / + query-engine convention to check via the OTel MCP), which become an + `ourios.query.operator.*` registry namespace, and which a neutral + `datafusion.*` set for the extractable crate. Must clear the OTel MCP + + weaver registry before implementation (`CLAUDE.md` OTel-alignment rule). +- [ ] **Crate name / extraction.** `ourios-df-otel` in-repo, targeting + `datafusion-opentelemetry` upstream — confirm no such crate already exists + in `datafusion-contrib` (adopt/align if so). Keep the public surface + (`record_plan_spans`) Ourios-free from day one. +- [ ] **Querier OTel deps.** §3.4 adds `tracing-opentelemetry` + + `opentelemetry`(trace) to `ourios-querier`. Acceptable (mirrors RFC 0039), + or should the parent context be threaded from `ourios-server` to keep the + querier trace-dep-free? Trade-off: threading a `Context` param vs. a dep. +- [ ] **The "show the query" attribute.** Separately from the operator tree, + should the query span carry the DSL statement (scrubbed, H6) and/or the + `displayable(plan)` text as a supplementary attribute — the direct + `db.query.text` analogue? It interacts with the `skip_all` PII decision + (RFC 0038 §3.5) and deserves its own note; possibly a small follow-up + rather than part of this RFC. +- [ ] **Live spans (option b).** Left as the next increment of the extractable + crate if intra-operator concurrency detail is ever needed. + +## 8. References + +- RFC 0038 (self-tracing) §3.1 (the `POST /v1/query` span this nests under), §7 + (the `datafusion-opentelemetry` future-work commitment), RFC0038.2 (the + O(1)-in-records span-count invariant this RFC honours). +- RFC 0021 (DataFusion/arrow upgrade) — the pinned DataFusion 54 whose + `BaselineMetrics` timestamps make option (a) truthful. +- RFC 0039 (inbound propagation) — the sibling traces-completeness RFC; the same + dep-promotion pattern. +- `CLAUDE.md` §7 (new crate = architectural commitment → RFC), §3 (H6: no + DataFusion type crosses the query boundary), §6.3 (observability of + ourselves), OTel-alignment rule (signal names via the OTel MCP + weaver). +- DataFusion — `ExecutionPlan::{name, children, metrics}` + (`datafusion-physical-plan-54`), `MetricsSet::aggregate_by_name`, + `MetricValue::{StartTimestamp, EndTimestamp, OutputRows, ElapsedCompute, + OutputBytes, PruningMetrics}`, `BaselineMetrics`. +- OpenTelemetry — span builder `with_start_time` / `end_with_timestamp` (backdated + spans); pinned `opentelemetry` 0.32 / `tracing-opentelemetry` 0.33. From 2452213f1fef05e47b72ef41bc810ab4b50a58d8 Mon Sep 17 00:00:00 2001 From: Jens Holdgaard Pedersen Date: Sat, 25 Jul 2026 01:33:23 +0200 Subject: [PATCH 2/3] =?UTF-8?q?docs(rfc):=20address=20review=20=E2=80=94?= =?UTF-8?q?=20with=5Fcontext=20propagation,=20normative=20operator=20attrs?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit RFC 0039: the biggest correction — set_parent returns AlreadyStarted on an entered #[instrument] span, so the parent would be silently dropped. Switch the whole mechanism to attaching the extracted context as current around the span future (opentelemetry::trace::FutureExt::with_context), so the root span inherits it. This also unifies the ingest carry-channel (one contract: extract + with_context across the spawn, no ingest_bound signature change) and shrinks the dep change to a single `trace` feature flag (tracing-opentelemetry no longer needed in the ingress crates). Ingress count corrected to four categories / six functions. RFC 0040: correct the span-emission example to the 0.32 API — generic `T: Tracer` (Tracer isn't object-safe: associated Span type), SystemTime timestamps via `SystemTime::from(DateTime)`, `end_with_timestamp(&mut self)`. Make operator attributes normative (types + units; elapsed_compute in ns) and emit pruning as two counts (row_groups_pruned/matched) rather than a ratio undefined at matched==0. Specify the sampled gate as `parent.span().span_context().is_sampled()`. Signed-off-by: Jens Holdgaard Pedersen --- .../0039-inbound-trace-context-propagation.md | 194 +++++++++--------- ...040-datafusion-operator-instrumentation.md | 66 ++++-- 2 files changed, 147 insertions(+), 113 deletions(-) diff --git a/docs/rfcs/0039-inbound-trace-context-propagation.md b/docs/rfcs/0039-inbound-trace-context-propagation.md index 3fab3014d..e46d36a21 100644 --- a/docs/rfcs/0039-inbound-trace-context-propagation.md +++ b/docs/rfcs/0039-inbound-trace-context-propagation.md @@ -18,8 +18,10 @@ Ourios's request-scoped SERVER spans (RFC 0038) are currently created as trace caller's trace stops at the Ourios boundary. This RFC installs a global `TraceContextPropagator` and, at each ingress, extracts the caller's `opentelemetry::Context` from the request carrier (HTTP headers / gRPC metadata) -and attaches it as the span's parent via `OpenTelemetrySpanExt::set_parent`. The -observable result: the `ingest logs`, `POST /v1/query`, and MCP tool spans join +and attaches it as the **current** context around the span-producing future +(`FutureExt::with_context`), so the root span inherits it as parent — not via +`set_parent`, which fails on an already-entered `#[tracing::instrument]` span. +The observable result: the `ingest logs`, `POST /v1/query`, and MCP tool spans join the caller's distributed trace instead of starting a disconnected one, and a `parentbased` sampler honours the caller's sampling decision. No new signal, no schema change — this completes the traces pillar that RFC 0038 established. @@ -61,80 +63,82 @@ propagation is out of scope (§7). ### 3.2 The ingress map -Five span sites open on the request path. The carrier — where the incoming -`traceparent` lives — is not always co-located with the span: +**Four** ingress categories open a span on the request path — six span-producing +functions in all, since the MCP category is three tool functions. The count is +stated so test coverage (RFC0039.1/.3/.6) omits no site. The carrier — where the +incoming `traceparent` lives — is not always co-located with the span: | # | Span | Site (file:line) | Carrier & where it is reachable | |---|---|---|---| -| A | `ingest logs` (gRPC) | span in `ingest_bound` (`pipeline.rs:291`); entry `LogsReceiver::export` (`grpc.rs:152`) | tonic `MetadataMap` via `request.metadata()` (`grpc.rs:159`), or raw `http::HeaderMap` in the tower auth layer `AuthService::call` (`grpc.rs:102`) | +| A | `ingest logs` (gRPC) | span in `ingest_bound` (`pipeline.rs:291`); entry `LogsReceiver::export` (`grpc.rs:152`) | raw `http::HeaderMap` in the tower auth layer `AuthService::call` (`grpc.rs:102`, already reads `request.headers()`) | | B | `ingest logs` (HTTP) | span in `ingest_bound`; entry `handle_logs` (`http.rs:95`) | axum `HeaderMap` (`http.rs:95`) | -| C | `POST /v1/query` | `handle_query` (`querier.rs:421`) | axum `HeaderMap` (`querier.rs:423`) — same fn as the span | -| D | `execute_tool ` | the three `_traced` fns (`mcp.rs:333/416/488`) | `ctx.extensions.get::()?.headers` (as `mcp_session_id` already reads, `mcp.rs:223`) | - -For **C** and **D** the carrier and the span live in the same function: -extract and `set_parent` at the top of the instrumented fn. - -### 3.3 The `tokio::spawn` boundary (ingest) - -The ingest span is the hard case. For **A** and **B** the `ingest logs` span is -created inside `ingest_bound`, which runs inside a freshly `tokio::spawn`ed task -(`grpc.rs:167`, `http.rs:146`) — the same spawn boundary RFC 0038.3 is about. -The carrier is only reachable in the handler **before** the spawn; the span is -born **after** it, in a different task. Ambient current-context does not cross -`tokio::spawn`. - -Therefore the fix cannot rely on context flow. The handler must: - -1. Extract `let cx = propagator.extract(&carrier);` **before** the spawn (where - the `MetadataMap`/`HeaderMap` is in scope). -2. Move `cx` into the spawned closure and hand it to `ingest_bound` as an - explicit parameter (`parent: opentelemetry::Context`). -3. Inside `ingest_bound`, after the span is entered, call - `tracing::Span::current().set_parent(cx)`. - -This mirrors how RFC 0038.3 already moves *span* context across the same -boundary via `.instrument(Span::current())`; here it is the extracted *parent* -context that is moved. `ingest_bound`'s signature gains one parameter; the two -call sites (`grpc.rs`, `http.rs`) each extract before spawning. - -### 3.4 The extractor shims +| C | `POST /v1/query` | `handle_query` (`querier.rs:421`) | axum `HeaderMap` (`querier.rs:423`) | +| D | `execute_tool ` (×3) | the three `_traced` fns (`mcp.rs:333/416/488`), each via a thin `#[tool]` delegate | `ctx.extensions.get::()?.headers` (as `mcp_session_id` reads, `mcp.rs:223`) | + +The mechanism is uniform (§3.3): extract the caller's `opentelemetry::Context` +and make it the **current** context around the span-producing future, so the +span — a tracing root — inherits it as its OTel parent. + +### 3.3 The mechanism: attach the context, do not `set_parent` + +`OpenTelemetrySpanExt::set_parent` must be called *before* the span is entered. +On an already-entered span — which every `#[tracing::instrument]` span is, for +its whole body — it returns `SetParentError::AlreadyStarted` and the parent is +**silently not set**. So propagation cannot `set_parent` from inside an +instrumented fn. Instead it makes the extracted context **current** *before* the +span is built; `tracing-opentelemetry` then parents a root span to +`Context::current()`. The idiom is +`opentelemetry::trace::FutureExt::with_context(future, cx)` — run the +span-producing future under the extracted context. One contract, every site: + +- **Query (C) and HTTP ingest (B):** a tower `PropagationLayer` on the axum + router extracts `cx` from the request `HeaderMap` and runs the downstream as + `next.run(req).with_context(cx)`. `handle_query`'s root span inherits `cx`; the + handler is unchanged. +- **gRPC ingest (A):** the same extraction in the existing tower auth layer + (`AuthService::call`, `grpc.rs:102`), stashing `cx` in the request extensions + beside the auth binding. +- **The `tokio::spawn` boundary (A/B):** the `ingest logs` span is born inside + `ingest_bound`, *after* the spawn (`grpc.rs:167`, `http.rs:146`), which a + layer's `with_context` does not cross. So the handler reads `cx` (from the + extension for A, extracts directly for B), moves it into the spawned closure, + and runs `ingest_bound(...).with_context(cx).await`. The span, first polled + under `cx`, inherits it — **no `ingest_bound` signature change, no + `set_parent`.** +- **MCP (D):** the un-instrumented `#[tool]` delegate extracts `cx` from `ctx`'s + forwarded headers and runs `self._traced(...).with_context(cx).await`; + the `_traced` span inherits `cx` across rmcp's own dispatch spawn. + +This is the same discipline RFC 0038.3 uses to carry work across `tokio::spawn`, +applied here to the parent context — and it is one uniform contract, resolving +the earlier draft's split between an explicit parameter and a request extension. + +### 3.4 The extractor shim `opentelemetry::propagation::Extractor` is a two-method trait (`get`, `keys`). -Two thin adapters are needed: - -- **axum `HeaderMap`** — `opentelemetry-http` provides `HeaderExtractor`, but to - avoid a new dependency a ~10-line local `struct HeaderExtractor<'a>(&'a - HeaderMap)` is equivalent (the C/D sites and the HTTP ingest site B). -- **tonic `MetadataMap`** — a `struct MetadataExtractor<'a>(&'a MetadataMap)` - reading ASCII metadata keys (site A, if extracting from gRPC metadata rather - than the raw HTTP headers at the tower layer). - -Both live in `ourios-ingester`'s receiver module (and re-used by -`ourios-server`), or in a small shared helper. The RFC prefers extracting site A -from the **tower auth layer's raw `http::HeaderMap`** (`grpc.rs:102`), so a -single `HeaderExtractor` covers A/B/C/D and no tonic-metadata adapter is needed — -the auth layer already reads `request.headers()` and inserts into extensions, so -the extracted `Context` can ride the same request-extensions channel the auth -binding uses (`grpc.rs:119`), reaching `ingest_bound` without a signature change. -This is the preferred shape; §7 leaves the exact carry-channel (explicit -parameter vs. request extension) to implementation review. - -### 3.5 Dependency promotion (the non-obvious cost) - -Today the trace-capable OTel crates are `[dev-dependencies]` only in -`ourios-ingester` and `ourios-server` — their production `[dependencies]` carry -`opentelemetry` with the **`metrics`** feature alone. The `otel.kind` string -fields on the instrument macros work without them because the tracing→OTel -bridge lives in `ourios-telemetry`. Propagation needs real types in production -code (`TraceContextPropagator`, `Context`, `OpenTelemetrySpanExt::set_parent`), -so this RFC promotes to `[dependencies]` in both crates: - -- `opentelemetry` (add the `trace` feature), -- `opentelemetry_sdk` (`trace` feature, for `TraceContextPropagator`), -- `tracing-opentelemetry` (for `OpenTelemetrySpanExt`). - -This is a real compile-surface and build-time cost and is called out here so it -is a conscious choice, not a surprise in the diff. +One adapter suffices: `struct HeaderExtractor<'a>(&'a http::HeaderMap)`, since +`http::HeaderMap` is the carrier for **every** site — the gRPC path extracts from +the raw HTTP headers at the tower auth layer (`grpc.rs:102`), so no tonic +`MetadataMap` adapter is needed. Extraction goes through the propagator installed +in §3.1: `global::get_text_map_propagator(|p| p.extract(&HeaderExtractor(headers)))`. +`opentelemetry-http` ships an equivalent `HeaderExtractor`; the ~10-line local +one avoids a dependency (revisit if a metadata extractor is ever needed). + +### 3.5 Dependency promotion (the one production-surface change) + +The ingress code needs `opentelemetry` types in production +(`Context`, `propagation::Extractor`, `trace::FutureExt::with_context`, +`global::get_text_map_propagator`), but `opentelemetry` is a production +dependency of `ourios-ingester`/`ourios-server` today only with the +**`metrics`** feature. This RFC adds the **`trace`** feature to that existing +dependency in both crates. The propagator *install* +(`opentelemetry_sdk::propagation::TraceContextPropagator`, §3.1) stays in +`ourios-telemetry`, which already depends on `opentelemetry_sdk`; and because the +parenting is via the current-context bridge the `tracing-opentelemetry` layer +already provides (not a `set_parent` call), **`tracing-opentelemetry` is not +needed in the ingress crates at all**. So the whole production-surface cost is +one added feature flag on a crate already depended on — smaller than a +`set_parent` design would have required. ### 3.6 Sampling interplay @@ -148,13 +152,14 @@ consistent end-to-end. This is desirable and is the reason to prefer a A request with no incoming context falls back to the root sampling rule unchanged (backward-compatible). -### 3.7 `set_parent`'s `Result` +### 3.7 Traces disabled -`tracing-opentelemetry` 0.33's `set_parent` returns `Result<(), -SetParentError>`. A failure means the span had no OTel layer (traces disabled) — -expected and non-fatal. The call ignores the error (`let _ = …`) or matches it -away; it is never a request-affecting error (no `unwrap`/`expect`, per -`CLAUDE.md`). +`with_context` merely attaches an `opentelemetry::Context` for the duration of a +future; it has no fallible surface and no `Result` to handle (contrast the +`set_parent` design, which returned `SetParentError` — one reason to prefer the +attach idiom). When traces are disabled the span carries no OTel layer, the +attached context is inert, and nothing is exported — a no-op, not an error. No +`unwrap`/`expect` is introduced (`CLAUDE.md` §6.1). ## 4. Alternatives considered @@ -168,13 +173,18 @@ the carrier does not reach `ingest_bound` (its signature has no request), and `tokio::spawn` severs ambient context (§3.3). Extraction must happen in the handler. -**A tower/tonic middleware layer that extracts and injects context for all -routes.** Cleaner in principle (one layer, no per-handler code), and worth -revisiting — but the ingest span is born *after* the spawn inside `ingest_bound`, -so a middleware that sets the current context still would not reach that span -without the same explicit hand-off. A layer would help sites B/C/D but not the -hard site A/ingest; this RFC does the explicit extraction uniformly and leaves a -middleware refactor as a follow-up once the pattern is proven. +**A single `set_parent` call inside each instrumented fn.** The obvious first +design, and what an earlier draft proposed — but it does not work: +`OpenTelemetrySpanExt::set_parent` returns `AlreadyStarted` on an entered span, +and every `#[tracing::instrument]` span is entered for its body, so the parent is +silently dropped (§3.3). The attach-the-context idiom (`with_context`) is the +correct primitive and is what §3.3 adopts. + +**Per-handler extraction with no shared layer.** Workable but repetitive: each +handler would extract and wrap. The `PropagationLayer` (§3.3) centralises the +request-local sites (B/C); only the spawn-crossed span (A/B's `ingest_bound`) and +MCP (D, behind rmcp's dispatch) need the explicit `with_context` hand-off, which +no layer can do for them anyway. **Adopt `opentelemetry-http`'s `HeaderExtractor` as a dependency.** Reasonable, but it is one more crate for a ~10-line shim; the RFC inlines the extractor. If @@ -250,14 +260,12 @@ Mapped to `CLAUDE.md` §6.2: ## 7. Open questions -- [ ] Carry-channel for the ingest parent context: explicit `ingest_bound` - parameter vs. a request-extension (the auth layer already inserts into - `request.extensions_mut()`; the extracted `Context` could ride the same - channel with no signature change). §3.4 prefers the extension; confirm on - review. -- [ ] Should site A extract from the tower auth layer's raw `http::HeaderMap` - (one `HeaderExtractor` for all sites, no tonic-metadata adapter) or from - tonic's `MetadataMap` in `export`? The former is preferred (§3.4). +- [ ] Confirm `FutureExt::with_context` correctly re-attaches the extracted + context inside the spawned `ingest_bound` task (§3.3) — the spawn-boundary + test (RFC0039.3) is the check. (The carry-channel and site-A/metadata-vs- + header questions the earlier draft left open are now settled by §3.3/§3.4: + one `HeaderExtractor` over the raw `http::HeaderMap`, `cx` in the request + extension across the spawn, no `ingest_bound` signature change.) - [ ] MCP tool spans are `otel.kind = "internal"` and lack an enclosing Ourios SERVER span for `/mcp` (rmcp's `serve_inner` is muted by the `rmcp=off` loop-guard, RFC0038.7). An INTERNAL span continuing a *remote* parent is @@ -277,6 +285,8 @@ Mapped to `CLAUDE.md` §6.2: RFC 0038), §6.1 (no `unwrap`/`expect` in non-test code). - W3C Trace Context — . - OpenTelemetry — [context propagation](https://opentelemetry.io/docs/specs/otel/context/api-propagators/); - [`OpenTelemetrySpanExt::set_parent`](https://docs.rs/tracing-opentelemetry/0.33.0/tracing_opentelemetry/trait.OpenTelemetrySpanExt.html). + [`FutureExt::with_context`](https://docs.rs/opentelemetry/0.32.0/opentelemetry/trace/trait.FutureExt.html) + (the attach idiom this RFC uses; note `OpenTelemetrySpanExt::set_parent` + returns `AlreadyStarted` on an entered span, which is why it is *not* used). - Pinned: `opentelemetry` 0.32.0, `opentelemetry_sdk` 0.32.1, `tracing-opentelemetry` 0.33.0. diff --git a/docs/rfcs/0040-datafusion-operator-instrumentation.md b/docs/rfcs/0040-datafusion-operator-instrumentation.md index 142faf388..9de420998 100644 --- a/docs/rfcs/0040-datafusion-operator-instrumentation.md +++ b/docs/rfcs/0040-datafusion-operator-instrumentation.md @@ -86,13 +86,18 @@ single entry point: ```rust // ourios-df-otel -pub fn record_plan_spans( +pub fn record_plan_spans( plan: &dyn ExecutionPlan, parent: &opentelemetry::Context, - tracer: &dyn opentelemetry::trace::Tracer, + tracer: &T, ); ``` +The tracer is a generic `T: Tracer`, not `&dyn Tracer`: the `Tracer` trait has an +associated `Span` type and is not object-safe as a bare trait object. Callers pass +the global tracer (`opentelemetry::global::tracer("ourios-df-otel")`, a +`BoxedTracer`) or any concrete tracer. + It walks `plan`, and for each node with `StartTimestamp`+`EndTimestamp` builds a child span (parent = its plan-parent's span, root = `parent`) named by `ExecutionPlan::name()` (e.g. `DataSourceExec`, `FilterExec`, `AggregateExec` — @@ -101,26 +106,42 @@ low-cardinality, the operator kind). ### 3.3 Span emission — the raw OTel span builder (not `#[instrument]`) Backdated spans cannot come from `#[tracing::instrument]` (it starts "now"). The -crate uses the OTel SDK span builder directly: +crate uses the OTel SDK span builder directly. `with_start_time` and +`end_with_timestamp` take `std::time::SystemTime`, so the node's +`DateTime` timestamps convert via `SystemTime::from`; `end_with_timestamp` +takes `&mut self`: ```rust -let span = tracer +let start: SystemTime = node_start.into(); // DateTime -> SystemTime +let end: SystemTime = node_end.into(); +let mut span = tracer .span_builder(node.name().to_string()) .with_kind(SpanKind::Internal) - .with_start_time(start) // real StartTimestamp - .with_attributes(node_attributes(metrics)) // rows, elapsed, bytes, pruning - .start_with_context(tracer, &parent_cx); -// … recurse into children with this span's context as their parent … -span.end_with_timestamp(end); // real EndTimestamp + .with_start_time(start) + .with_attributes(node_attributes(&metrics)) + .start_with_context(tracer, parent_cx); // parent_cx = this node's parent span's context +// … recurse into children, passing this span's context as their parent … +span.end_with_timestamp(end); // &mut self; real EndTimestamp ``` -Attributes are drawn from the same `MetricValue` variants `fold_metrics` reads, -plus the general ones: `output_rows`, `elapsed_compute` (as a duration/ns), -`output_bytes`, and the pruning ratio (`row_groups_pruned`/`matched`). Names -follow OTel conventions where one exists and an `ourios.query.operator.*` / -`datafusion.*` namespace otherwise — **the exact attribute names go through the -OTel MCP + weaver registry** (`CLAUDE.md` OTel-alignment rule) before landing; -§7 tracks it. +**Attributes are normative** — the span contract is deterministic (types, units, +and the no-match representation are fixed): + +| Attribute | Type / unit | Source (`MetricValue`) | +|---|---|---| +| `…output_rows` | int, rows | `OutputRows` | +| `…elapsed_compute` | int, **nanoseconds** | `ElapsedCompute` (`Time::value()` is ns) | +| `…output_bytes` | int, bytes | `OutputBytes` | +| `…row_groups_pruned` | int, count | scan `PruningMetrics::pruned()` | +| `…row_groups_matched` | int, count | scan `PruningMetrics::matched()` | + +Pruning is emitted as the two **counts**, never a ratio — a ratio is undefined +when `matched == 0` (a fully-pruned or non-scanning node); a consumer derives the +ratio if it wants one. An attribute whose metric a node does not report is +**omitted**, not zero-filled, so presence is meaningful. Names follow an existing +OTel convention where one applies, else an `ourios.query.operator.*` / +`datafusion.*` namespace — **the exact names clear the OTel MCP + weaver +registry** (`CLAUDE.md` alignment rule) before landing; §7 tracks it. ### 3.4 Parenting into the query span @@ -152,11 +173,14 @@ spans." The reconstruction is **O(plan nodes)** — a handful per query — and runs **once per query**, after execution. It is not per-record and not per-batch (RFC -0038.2's invariant). It is gated on traces being enabled *and* the query span -being sampled: an unsampled query skips the walk entirely (check the parent -context's `is_sampled()` before walking), so the cost is zero on the sampled-out -path and bounded-tiny on the sampled path. A `criterion` guard confirms no -query-latency regression on the sampled-out path (the default). +0038.2's invariant). It is gated on the query span being **recording and +sampled**: before walking, check +`parent.span().span_context().is_sampled()` (the parent `Context`'s active span's +`SpanContext`), which is `false` both when traces are disabled (no OTel layer → +an invalid, unsampled `SpanContext`) and when the sampler dropped this trace. An +unsampled query skips the walk entirely, so the cost is zero on the sampled-out +path (the default) and bounded-tiny on the sampled path. A `criterion` guard +confirms no query-latency regression on the sampled-out path. ## 4. Alternatives considered From 4ab715ae5120f4d009ae8bd9cc7b25e1b3425c04 Mon Sep 17 00:00:00 2001 From: Jens Holdgaard Pedersen Date: Sat, 25 Jul 2026 01:39:53 +0200 Subject: [PATCH 3/3] docs(rfc): settle RFC 0040 attribute names via the OTel MCP MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Consulted the OpenTelemetry semantic conventions (the project's consult-before-any-signal-naming rule) rather than leaving the names to implementation time. Findings: OTel defines NO convention for query-plan / per-operator spans — the whole db.* span convention describes database *client* spans (one app->DB operation). Reusing db.response.returned_rows for a plan node's output rows would collide with its normative meaning ("rows returned by the database operation ... at the time the span ends"), so the operator attributes take a distinct namespace. Namespace is `datafusion.operator.*`, not `ourios.*`: the semantics are DataFusion's and the crate is built to be extracted (an ourios-prefixed attribute would be wrong the moment another project uses it). The five names are fixed in §3.3 and still go through semconv/registry/ + weaver so live-check validates them. Also records the naming for the deferred "show the query" question: db.query.text (stable, carries a normative sanitization requirement) and db.query.summary (stable, explicitly a low-cardinality grouping key) — noting both are defined on client spans while ours is SERVER, and that the DSL's user literals tie it to the §3.5 PII decision. Stays out of this RFC. Signed-off-by: Jens Holdgaard Pedersen --- ...040-datafusion-operator-instrumentation.md | 72 +++++++++++++------ 1 file changed, 51 insertions(+), 21 deletions(-) diff --git a/docs/rfcs/0040-datafusion-operator-instrumentation.md b/docs/rfcs/0040-datafusion-operator-instrumentation.md index 9de420998..6da7eddc5 100644 --- a/docs/rfcs/0040-datafusion-operator-instrumentation.md +++ b/docs/rfcs/0040-datafusion-operator-instrumentation.md @@ -129,19 +129,37 @@ and the no-match representation are fixed): | Attribute | Type / unit | Source (`MetricValue`) | |---|---|---| -| `…output_rows` | int, rows | `OutputRows` | -| `…elapsed_compute` | int, **nanoseconds** | `ElapsedCompute` (`Time::value()` is ns) | -| `…output_bytes` | int, bytes | `OutputBytes` | -| `…row_groups_pruned` | int, count | scan `PruningMetrics::pruned()` | -| `…row_groups_matched` | int, count | scan `PruningMetrics::matched()` | +| `datafusion.operator.output_rows` | int, rows | `OutputRows` | +| `datafusion.operator.elapsed_compute` | int, **nanoseconds** | `ElapsedCompute` (`Time::value()` is ns) | +| `datafusion.operator.output_bytes` | int, bytes | `OutputBytes` | +| `datafusion.operator.row_groups_pruned` | int, count | scan `PruningMetrics::pruned()` | +| `datafusion.operator.row_groups_matched` | int, count | scan `PruningMetrics::matched()` | Pruning is emitted as the two **counts**, never a ratio — a ratio is undefined when `matched == 0` (a fully-pruned or non-scanning node); a consumer derives the ratio if it wants one. An attribute whose metric a node does not report is -**omitted**, not zero-filled, so presence is meaningful. Names follow an existing -OTel convention where one applies, else an `ourios.query.operator.*` / -`datafusion.*` namespace — **the exact names clear the OTel MCP + weaver -registry** (`CLAUDE.md` alignment rule) before landing; §7 tracks it. +**omitted**, not zero-filled, so presence is meaningful. + +**Why a `datafusion.*` namespace and not `db.*` (OTel MCP consultation, +2026-07-25).** The OTel semantic conventions define **no** convention for +query-plan or per-operator spans: the whole `db.*` span convention describes a +**database client** span — one application→database operation — not +sub-operations inside an engine. Two consequences: + +- Reusing `db.response.returned_rows` for a plan node's output rows would + **collide** with its normative meaning ("the number of rows returned by the + database operation as observed at the time the span ends") — an operator's + output rows are not the operation's returned rows. Per the project's + no-collision rule, these attributes take a distinct namespace. +- `datafusion.operator.*` (not `ourios.*`) because the semantics are + DataFusion's, not Ourios's — the crate is built to be extracted + (§3.5), and an `ourios.`-prefixed attribute would be wrong the moment another + project uses it. The prefix is the instrumented library, per OTel's guidance on + naming for third-party/library-specific attributes. + +Ourios-side attributes (e.g. `ourios.tenant`) stay in the Ourios registry on the +Ourios-owned spans, not on these. The `datafusion.operator.*` names still go +through the weaver registry before landing (§7) so live-check validates them. ### 3.4 Parenting into the query span @@ -279,19 +297,23 @@ Mapped to `CLAUDE.md` §6.2: benchmark confirming no regression on the traces-off / unsampled path; a unit test that the walk is skipped when the parent context is not sampled. - Attribute-name conformance rides the existing `weaver registry live-check` - gate once the `ourios.query.operator.*` / `datafusion.*` names are registered + gate once the five `datafusion.operator.*` names are registered (§3.3, §7). - `ourios-df-otel` unit tests over hand-built `MetricsSet`s: the `MetricValue → attribute` mapping, and the timestamp reduction. ## 7. Open questions -- [ ] **Attribute names.** `output_rows`/`elapsed_compute`/`output_bytes`/pruning - — which map to existing OTel semconv (there is a nascent `db.*` / - query-engine convention to check via the OTel MCP), which become an - `ourios.query.operator.*` registry namespace, and which a neutral - `datafusion.*` set for the extractable crate. Must clear the OTel MCP + - weaver registry before implementation (`CLAUDE.md` OTel-alignment rule). +- [x] **Attribute names — SETTLED via the OTel MCP (2026-07-25).** There is no + OTel convention for query-plan / per-operator spans; `db.*` describes + database **client** spans (one app→DB operation). Reusing + `db.response.returned_rows` per plan node would collide with its normative + meaning, so the operator attributes take the `datafusion.operator.*` + namespace (the instrumented library, not `ourios.*` — the crate is built to + be extracted). Fixed in §3.3. Remaining mechanical step: register the five + names in `semconv/registry/` + weaver generate, so live-check validates + them (see the RFC0038.7 precedent for how out-of-registry attributes fail + the gate). - [ ] **Crate name / extraction.** `ourios-df-otel` in-repo, targeting `datafusion-opentelemetry` upstream — confirm no such crate already exists in `datafusion-contrib` (adopt/align if so). Keep the public surface @@ -301,11 +323,19 @@ Mapped to `CLAUDE.md` §6.2: or should the parent context be threaded from `ourios-server` to keep the querier trace-dep-free? Trade-off: threading a `Context` param vs. a dep. - [ ] **The "show the query" attribute.** Separately from the operator tree, - should the query span carry the DSL statement (scrubbed, H6) and/or the - `displayable(plan)` text as a supplementary attribute — the direct - `db.query.text` analogue? It interacts with the `skip_all` PII decision - (RFC 0038 §3.5) and deserves its own note; possibly a small follow-up - rather than part of this RFC. + should the query span carry the DSL statement and/or the + `displayable(plan)` text? The OTel MCP consultation settles the *naming* if + we do: `db.query.text` (stable) for the statement — carrying an explicit + normative **sanitization** requirement ("non-parameterized query text + SHOULD NOT be collected by default unless there is sanitization that + excludes sensitive data, e.g. redacting literal values") — and + `db.query.summary` (stable, explicitly a *low-cardinality grouping key*) + for a redacted shape. Note these are defined on database **client** spans + while ours is a SERVER span, so the fit needs a deliberate call. Because + the DSL can carry user literals, this interacts directly with the + `skip_all` PII decision (RFC 0038 §3.5) and the H6 scrubbing rule — it + stays **out** of this RFC and deserves its own (a sanitizing + `db.query.summary` is the likely shape). - [ ] **Live spans (option b).** Left as the next increment of the extractable crate if intra-operator concurrency detail is ever needed.