feat(telemetry): request-scoped spans on ingest, query, mcp, sweep (RFC 0038 slice 2)

crates/ourios-ingester/Cargo.toml

@@ -151,8 +151,19 @@ ourios-testgen = { path = "../ourios-testgen" }
 # Stand up an in-memory MeterProvider to assert the compaction metric
 # stream; `testing` exposes `init_in_memory`.
 ourios-telemetry = { path = "../ourios-telemetry", features = ["testing"] }
-# The SDK data types (`ResourceMetrics` etc.) the metrics test reads.
-opentelemetry_sdk = { version = "=0.32.1", default-features = false, features = ["metrics", "testing"] }
+# The SDK data types (`ResourceMetrics` etc.) the metrics test reads;
+# `trace` adds the `InMemorySpanExporter`/`SdkTracerProvider` the RFC0038.2
+# request-span test collects the ingest batch span through.
+opentelemetry_sdk = { version = "=0.32.1", default-features = false, features = ["metrics", "trace", "testing"] }
+# RFC0038.2: the `TracerProvider::tracer` trait method + `SpanId`/`TraceId`
+# the batch-span assertions read (the crate's non-dev dep is metrics-only).
+opentelemetry = { version = "0.32", default-features = false, features = ["trace"] }
+# RFC0038.2: bridge the ingest path's `#[tracing::instrument]` spans onto
+# the in-memory span exporter — matches ourios-telemetry's pinned layer.
+tracing-opentelemetry = { version = "0.33", default-features = false }
+# The scoped `registry().with(layer)` subscriber the batch-span test drives
+# ingest under (`WithSubscriber`), so no process-global tracer is installed.
+tracing-subscriber = { version = "0.3", default-features = false, features = ["registry", "std"] }
 # The metrics test collects via the in-memory reader's periodic-export
 # path, which needs a multi-thread runtime; `test-util` gives the RFC0008.8
 # latency test a paused virtual clock for deterministic, jitter-free timing.

crates/ourios-ingester/src/compactor.rs

@@ -172,6 +172,14 @@ pub fn run_sweep(
 /// # Errors
 ///
 /// See [`run_sweep`].
+// RFC 0038: one span per compaction sweep — coarse and periodic. Opened inside
+// the callee (the tick `spawn_blocking`s this), and the per-tenant / per-file
+// loops below stay span-free.
+#[tracing::instrument(
+    skip_all,
+    name = "ourios.compaction.sweep",
+    fields(otel.kind = "internal")
+)]
 pub fn run_sweep_with_promoted(
     store: &Store,
     now_unix_nanos: u64,

crates/ourios-ingester/src/receiver/pipeline.rs

@@ -25,6 +25,7 @@ use opentelemetry_proto::tonic::collector::logs::v1::ExportLogsServiceRequest;
 use ourios_miner::cluster::MinerCluster;
 use ourios_wal::{FrameKind, Wal, WalOffset};
 use prost::Message;
+use tracing::Instrument as _;
 
 use crate::metrics::IngestMetrics;
 use crate::receiver::commit::CommitCoordinator;
@@ -281,6 +282,22 @@ impl IngestPipeline {
     ///   write (RFC0003.4).
     /// - [`ReceiveError::WalAppend`] / [`ReceiveError::WalSync`] if
     ///   persistence fails; the batch is **not** acked.
+    // RFC 0038: one span per OTLP `Export` batch — the correct coarse
+    // granularity (never per record; the miner/encode/sink loops below stay
+    // span-free). Opened *inside* this callee, not at the `tokio::spawn` site
+    // in the gRPC/HTTP handlers, so the span is created within the spawned task
+    // (span context does not cross `tokio::spawn` — RFC0038.3). `skip_all`
+    // keeps the whole `ExportLogsServiceRequest` off the span.
+    #[tracing::instrument(
+        skip_all,
+        name = "ourios.ingest.batch",
+        fields(otel.kind = "server")
+    )]
+    // The linear ingest orchestrator (authz → encode → fan-out → commit → miner
+    // hand-off → metrics); the RFC 0038 batch + wal.commit spans nudged it one
+    // step over 100. Splitting a straight-line sequence to satisfy the lint
+    // would hurt readability more than the length does.
+    #[allow(clippy::too_many_lines)]
     pub async fn ingest_bound(
         &self,
         request: ExportLogsServiceRequest,
@@ -333,7 +350,18 @@ impl IngestPipeline {
         // fsync (RFC0008.8). The frame's append `seq` orders the miner
         // hand-off below.
         let commit_start = Instant::now();
-        let outcome = self.coordinator.commit(&payload).await;
+        // RFC 0038: a child span for the WAL group-commit — the one genuinely
+        // I/O-bound, latency-bearing step (a durationful op is a span, not an
+        // event). Nests under the batch span; `.instrument` (not an entered
+        // guard) carries it across the await cleanly.
+        let outcome = self
+            .coordinator
+            .commit(&payload)
+            .instrument(tracing::info_span!(
+                "ourios.wal.commit",
+                otel.kind = "internal"
+            ))
+            .await;
         // The WAL-before-ack latency: time until the batch is durable
         // (includes the group-commit window + fsync). Recorded below only
         // on a successful, acked commit.

crates/ourios-ingester/tests/it/main.rs

@@ -47,3 +47,4 @@ mod rfc0035_2_encode_barrier;
 mod rfc0035_2_sweep_crash;
 mod rfc0035_5_on_disk_equivalence;
 mod rfc0035_f2_miner_panic_salvage;
+mod rfc0038_2_ingest_batch_span;

crates/ourios-ingester/tests/it/rfc0038_2_ingest_batch_span.rs

@@ -0,0 +1,110 @@
+//! RFC0038.2 — request-scope spans are O(1) in record count.
+//!
+//! The ingest hot path must never mint a span per record: that would both
+//! strangle throughput and flood the trace backend, defeating the whole
+//! sampling discipline of RFC 0038 §3. One OTLP Export batch yields exactly
+//! one `ourios.ingest.batch` span with a single `ourios.wal.commit` child,
+//! whether the batch carries one record or many. See `docs/rfcs/0038-self-tracing.md`.
+//!
+//! The subscriber is installed *scoped* to the driven future
+//! (`WithSubscriber`) over an in-memory span exporter — no process-global
+//! tracer provider, so this stays inside the consolidated harness (see
+//! `tests/README.md` on the global-installer exclusions).
+
+use crate::ingest_support::{open_pipeline, request, resource_logs};
+use opentelemetry::trace::{SpanId, TracerProvider as _};
+use opentelemetry_sdk::trace::{InMemorySpanExporter, SdkTracerProvider, SpanData};
+use tracing::instrument::WithSubscriber as _;
+use tracing_subscriber::prelude::*;
+
+/// Structurally distinct bodies so the miner mints a fresh `template_id`
+/// per record — the per-record loop that RFC0038.2 forbids from spawning
+/// spans is fully exercised.
+fn distinct_bodies(n: usize) -> Vec<String> {
+    (0..n)
+        .map(|i| format!("event kind {i} completed status=ok"))
+        .collect()
+}
+
+/// Drive one `ingest_bound` of `record_count` records under a scoped
+/// tracer and return every finished span.
+async fn ingest_and_collect_spans(record_count: usize) -> Vec<SpanData> {
+    let tmp = tempfile::TempDir::new().expect("temp");
+    let pipeline = open_pipeline(tmp.path());
+
+    let exporter = InMemorySpanExporter::default();
+    let provider = SdkTracerProvider::builder()
+        .with_simple_exporter(exporter.clone())
+        .build();
+    let subscriber = tracing_subscriber::registry()
+        .with(tracing_opentelemetry::layer().with_tracer(provider.tracer("ourios-test")));
+
+    let bodies = distinct_bodies(record_count);
+    let body_refs: Vec<&str> = bodies.iter().map(String::as_str).collect();
+    let export = request(vec![resource_logs("checkout", &body_refs)]);
+
+    let acked = pipeline
+        .ingest_bound(export, None, false)
+        .with_subscriber(subscriber)
+        .await
+        .expect("ingest acks");
+    assert_eq!(acked, record_count, "every record acked");
+
+    provider.force_flush().expect("spans flush");
+    exporter.get_finished_spans().expect("spans exported")
+}
+
+fn spans_named<'a>(spans: &'a [SpanData], name: &str) -> Vec<&'a SpanData> {
+    spans.iter().filter(|s| s.name.as_ref() == name).collect()
+}
+
+#[tokio::test(flavor = "multi_thread", worker_threads = 1)]
+async fn rfc0038_2_ingest_batch_emits_one_span_with_a_wal_commit_child() {
+    let spans = ingest_and_collect_spans(1).await;
+
+    let batch = spans_named(&spans, "ourios.ingest.batch");
+    let commit = spans_named(&spans, "ourios.wal.commit");
+    assert_eq!(
+        batch.len(),
+        1,
+        "exactly one ingest.batch span, got {spans:?}"
+    );
+    assert_eq!(
+        commit.len(),
+        1,
+        "exactly one wal.commit span, got {spans:?}"
+    );
+
+    assert_ne!(
+        batch[0].span_context.span_id(),
+        SpanId::INVALID,
+        "the batch span has a real span id",
+    );
+    assert_eq!(
+        commit[0].parent_span_id,
+        batch[0].span_context.span_id(),
+        "wal.commit nests under ingest.batch",
+    );
+}
+
+#[tokio::test(flavor = "multi_thread", worker_threads = 1)]
+async fn rfc0038_2_span_count_is_constant_in_record_count() {
+    let one = ingest_and_collect_spans(1).await;
+    let many = ingest_and_collect_spans(64).await;
+
+    assert_eq!(
+        one.len(),
+        many.len(),
+        "span count must not grow with record count (no per-record spans): \
+         1 record -> {} spans, 64 records -> {} spans",
+        one.len(),
+        many.len(),
+    );
+    // The two request-scope spans, and nothing per-record.
+    assert_eq!(
+        many.len(),
+        2,
+        "batch + wal.commit only, got {:?}",
+        many.iter().map(|s| s.name.clone()).collect::<Vec<_>>(),
+    );
+}

crates/ourios-server/src/mcp.rs

@@ -297,6 +297,19 @@ impl OuriosMcp {
         &self,
         Parameters(args): Parameters<QueryLogsArgs>,
         ctx: rmcp::service::RequestContext<rmcp::RoleServer>,
+    ) -> Result<CallToolResult, ErrorData> {
+        // RFC 0038: the span lives on a private delegate, not here —
+        // `#[tracing::instrument]` on a `#[tool]` method drops the doc-comment
+        // tool description the rmcp macro derives (RFC0027.7 / RFC0032.5). The
+        // span is still a child of rmcp's `serve_inner`, one per tool call.
+        self.query_logs_traced(Parameters(args), ctx).await
+    }
+
+    #[tracing::instrument(skip_all, name = "ourios.mcp.query_logs", fields(otel.kind = "internal"))]
+    async fn query_logs_traced(
+        &self,
+        Parameters(args): Parameters<QueryLogsArgs>,
+        ctx: rmcp::service::RequestContext<rmcp::RoleServer>,
     ) -> Result<CallToolResult, ErrorData> {
         let tenant_arg = normalize_tenant(&args.tenant)?;
         self.check_tenant(&ctx, tenant_arg)?;
@@ -357,6 +370,16 @@ impl OuriosMcp {
         &self,
         Parameters(args): Parameters<ListTemplatesArgs>,
         ctx: rmcp::service::RequestContext<rmcp::RoleServer>,
+    ) -> Result<CallToolResult, ErrorData> {
+        // RFC 0038: span on the private delegate — see `query_logs`.
+        self.list_templates_traced(Parameters(args), ctx).await
+    }
+
+    #[tracing::instrument(skip_all, name = "ourios.mcp.list_templates", fields(otel.kind = "internal"))]
+    async fn list_templates_traced(
+        &self,
+        Parameters(args): Parameters<ListTemplatesArgs>,
+        ctx: rmcp::service::RequestContext<rmcp::RoleServer>,
     ) -> Result<CallToolResult, ErrorData> {
         let tenant_arg = normalize_tenant(&args.tenant)?;
         self.check_tenant(&ctx, tenant_arg)?;
@@ -406,6 +429,16 @@ impl OuriosMcp {
         &self,
         Parameters(args): Parameters<TemplateDriftArgs>,
         ctx: rmcp::service::RequestContext<rmcp::RoleServer>,
+    ) -> Result<CallToolResult, ErrorData> {
+        // RFC 0038: span on the private delegate — see `query_logs`.
+        self.template_drift_traced(Parameters(args), ctx).await
+    }
+
+    #[tracing::instrument(skip_all, name = "ourios.mcp.template_drift", fields(otel.kind = "internal"))]
+    async fn template_drift_traced(
+        &self,
+        Parameters(args): Parameters<TemplateDriftArgs>,
+        ctx: rmcp::service::RequestContext<rmcp::RoleServer>,
     ) -> Result<CallToolResult, ErrorData> {
         let tenant_arg = normalize_tenant(&args.tenant)?;
         self.check_tenant(&ctx, tenant_arg)?;

crates/ourios-server/src/querier.rs

@@ -405,6 +405,9 @@ pub async fn serve(config: QuerierConfig) -> Result<QuerierHandle, String> {
 }
 
 /// `POST /v1/query` handler (RFC 0016 §3.3–§3.5).
+// RFC 0038: one request-scoped server span per query (low frequency, an ideal
+// span root). `skip_all` keeps the headers/body off the span.
+#[tracing::instrument(skip_all, name = "POST /v1/query", fields(otel.kind = "server"))]
 async fn handle_query(
     State(state): State<QuerierState>,
     headers: HeaderMap,

crates/ourios-telemetry/src/lib.rs

@@ -317,8 +317,19 @@ pub fn init(config: &TelemetryConfig) -> Result<TelemetryGuard, TelemetryError>
                 .with_sampler(sampler)
                 .with_resource(resource)
                 .build();
+            // Strip `tracing`'s synthetic per-span attributes: `busy_ns`/`idle_ns`
+            // (tracked inactivity) and `target` carry no semconv namespace, and
+            // `with_location` emits `code.module.name`, which collides with the
+            // upstream `code` namespace — all four fail `weaver registry
+            // live-check`. They are instrumentation-source metadata, not domain
+            // telemetry; our spans carry their identity in the span name plus the
+            // attributes we add deliberately. `thread.{id,name}` are valid semconv
+            // (kept by leaving `with_threads` at its default).
             let layer = tracing_opentelemetry::layer()
                 .with_tracer(tracer_provider.tracer(TRACER_SCOPE))
+                .with_tracked_inactivity(false)
+                .with_location(false)
+                .with_target(false)
                 .with_filter(guarded_env_filter())
                 .boxed();
             (Some(tracer_provider), Some(layer))