From 44e75df99ee444c791d08ad268d1057ed04dc944 Mon Sep 17 00:00:00 2001 From: rays Date: Mon, 12 Oct 2026 16:19:32 +0000 Subject: [PATCH] ipx-directory traces, and ipx's trace follows its calls there (#213) The exporter setup and the traceparent parser move from ipx into ipx_directory::otel, which ipx already depends on, so both binaries share them. The directory makes a span a request, a child of the caller's traceparent, and a trace a refresher round with a span a feed; ipx sends the current span's traceparent on every call to the directory and wraps each share in a span. The dashboard's Traces row and the prod-check skill cover all three services. Co-Authored-By: Claude Opus 5.5 --- .claude/skills/ipx-prod-check/SKILL.md | 35 +++++++++-- CHANGELOG.md | 1 + Cargo.lock | 6 +- crates/directory/Cargo.toml | 4 ++ crates/directory/src/lib.rs | 45 +++++++++++--- crates/directory/src/main.rs | 17 ++++-- crates/directory/src/otel.rs | 83 ++++++++++++++++++++++++++ crates/ipx/Cargo.toml | 2 - crates/ipx/src/directory.rs | 7 ++- crates/ipx/src/main.rs | 19 +----- crates/ipx/src/web.rs | 48 +-------------- grafana/dashboard.py | 15 +++-- 12 files changed, 188 insertions(+), 94 deletions(-) create mode 100644 crates/directory/src/otel.rs diff --git a/.claude/skills/ipx-prod-check/SKILL.md b/.claude/skills/ipx-prod-check/SKILL.md index cb6bd36..3ae6806 100644 --- a/.claude/skills/ipx-prod-check/SKILL.md +++ b/.claude/skills/ipx-prod-check/SKILL.md @@ -10,13 +10,15 @@ Production is three containers in the Arcane project `ipx` on Tower | container | what | logs, in Loki | traces, in Tempo | metrics, in Prometheus | |---|---|---|---|---| -| `ipx-web` | Caddy: serves the page, passes `/api` and `/media` to ipx (#203). Port 8099, the LAN and the tunnel | `{container="ipx-web"}`, JSON: a line a request (`http.log.access`), its own errors | none | none | -| `iPX` | the daemon: API, scans, downloads, DeadAir | `{container="iPX"}`, JSON (`IPX_LOG_FORMAT=json`) | yes, tagged `resource.deployment.environment.name="production"` | `job="ipx"`, its `/metrics` | -| `ipx-directory` | the directory of public podcasts, `ipx-dir.sdf1.net` (#204) | `{container="ipx-directory"}`, JSON (`DIRECTORY_LOG_FORMAT=json`) | none | none | +| `ipx-web` | Caddy: serves the page, passes `/api` and `/media` to ipx (#203). Port 8099, the LAN and the tunnel | `{container="ipx-web"}`, JSON: a line a request (`http.log.access`), its own errors | service `ipx-web`: a span a request, passing `traceparent` on to ipx (#213) | none | +| `iPX` | the daemon: API, scans, downloads, DeadAir | `{container="iPX"}`, JSON (`IPX_LOG_FORMAT=json`) | service `ipx`; passes `traceparent` to the directory | `job="ipx"`, its `/metrics` | +| `ipx-directory` | the directory of public podcasts, `ipx-dir.sdf1.net` (#204) | `{container="ipx-directory"}`, JSON (`DIRECTORY_LOG_FORMAT=json`) | service `ipx-directory`: a span a request, joining ipx's trace when ipx called; a trace a refresher round (#213) | none | Under them, Tower itself: `job="node"` (the node exporter: load, CPU, memory, disks). The Grafana dashboard `iPX` draws all of it in that order (`grafana/dashboard.py`). A trace without the -production tag is a daemon run by hand, not production. Alloy ships the logs; Loki, Tempo and +production tag (`resource.deployment.environment.name="production"`, on all three) is a daemon run +by hand, not production. Since #213 a request is one trace across the services it touched: a +Directory page is ipx-web, then ipx, then the directory, so start from the trace, not the logs. Alloy ships the logs; Loki, Tempo and Prometheus publish no query port to this machine, so use the script beside this file: ```sh @@ -151,7 +153,7 @@ a count says something happened, the lines and traces say why. `feeds` above 0; none at all for over 10 minutes means the worker is stuck. And `pending` is the real queue (#113): files a scan will download on its own. Back-catalogue files are `held`, listed but not counted, so it is usually 0 or a handful. -5. **Slow and failed traces.** +5. **Slow and failed traces.** All three services' (filter by `resource.service.name` for one). ``` $Q traces '{resource.deployment.environment.name="production" && duration > 5s}' $Q traces '{resource.deployment.environment.name="production" && status = error}' @@ -243,6 +245,15 @@ up in ipx's access log. 401 and 303 on `/` are people signed out being sent to ` problem. Caddy's own notices at each start (no admin endpoint, no HTTPS or HTTP/3, its goodbye on SIGTERM) are by design and filtered out above. +Each access line carries the request's `traceID` (`| json` gives `traceID`): give it to `$Q trace` +to see where the time went, Caddy's span with ipx's inside it. A slow page with ipx's span short is +Caddy or the network; a long one is ipx. + +```sh +$Q traces '{resource.service.name="ipx-web" && duration > 2s}' +$Q traces '{resource.service.name="ipx-web" && status = error}' +``` + Who reaches it: `request_remote_ip` is `192.168.64.1` for the tunnel and anything else on Tower (Docker's gateway), `192.168.1.130` for Tower itself, a LAN address for the LAN. Caddy passes Cloudflare Access's headers on only from `192.168.64.1` (`TUNNEL_PEER`), and ipx trusts them only @@ -257,7 +268,19 @@ It logs a line a request (`target` `ipx_directory::http`: `method`, `path`, `sta line a refresher round (`feeds checked`: `checked`), a line a failed feed check (`feed check failed`: `feed`, the directory's id, and `error`), the admin's actions (`feed removed and blocked`, `feed unblocked`, `snapshot dropped`, each with `by`), and `config read again` when its -token file changes. It sends no traces and has no metrics. +token file changes. It has no metrics. Its traces (#213): a span a request (`http`), a child of +ipx's when ipx called with a `traceparent`, and a trace a refresher round (`refresh`, `feeds`) +with a `feed` span for each check. Its log lines carry no trace id; find the trace by time or by +the feed. + +```sh +$Q traces '{resource.service.name="ipx-directory" && duration > 2s}' +$Q traces '{resource.service.name="ipx-directory" && name="feed" && duration > 10s}' +$Q traces '{resource.service.name="ipx" && name="directory_share"}' +``` + +A slow Directory page in ipx is usually its `http` span in the directory: the trace says whether. +A refresher round far over a minute is one publisher's feed holding it, the slow `feed` span. ```sh D='{container="ipx-directory"} | json | __error__=""' diff --git a/CHANGELOG.md b/CHANGELOG.md index 0998085..7c74b5e 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -9,6 +9,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ### Added +- ipx-directory sends traces, and ipx passes its trace on when it calls the directory, so a Directory page is one trace from the browser through ipx-web and ipx to the directory; each refresher round is a trace too (#213). - ipx-web sends a trace span for each request when `WEB_TRACING=on`, continuing the page's trace into ipx, so one trace runs from the browser through Caddy to ipx (#213). - The Grafana dashboard is laid out by container: an overview of all three, Tower's load, CPU, memory and disks, then ipx-web (from its new request log), ipx's API, worker and process, and the directory, each with its own warnings (#210). - `ipx-directory`, a directory of public podcasts that ipx servers share: each sends the public feeds its people subscribe to, and any server with a token browses them. Tokens are in its config file, each read-only, read-write or admin, and revoked one at a time (#204). diff --git a/Cargo.lock b/Cargo.lock index 44bd3f0..479ee92 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -1835,8 +1835,6 @@ dependencies = [ "jsonwebtoken", "librqbit", "opentelemetry", - "opentelemetry-otlp", - "opentelemetry_sdk", "opml", "percent-encoding", "quick-xml 0.42.0", @@ -1864,6 +1862,9 @@ dependencies = [ "axum", "clap", "ipx-feed", + "opentelemetry", + "opentelemetry-otlp", + "opentelemetry_sdk", "reqwest", "sea-orm", "serde", @@ -1873,6 +1874,7 @@ dependencies = [ "toml", "tower", "tracing", + "tracing-opentelemetry", "tracing-subscriber", "url", ] diff --git a/crates/directory/Cargo.toml b/crates/directory/Cargo.toml index 31544c0..4b4cd78 100644 --- a/crates/directory/Cargo.toml +++ b/crates/directory/Cargo.toml @@ -12,6 +12,9 @@ anyhow.workspace = true axum.workspace = true clap.workspace = true ipx-feed.workspace = true +opentelemetry.workspace = true +opentelemetry-otlp.workspace = true +opentelemetry_sdk.workspace = true reqwest.workspace = true sea-orm.workspace = true serde.workspace = true @@ -20,6 +23,7 @@ sha2.workspace = true tokio.workspace = true toml.workspace = true tracing.workspace = true +tracing-opentelemetry.workspace = true tracing-subscriber.workspace = true url.workspace = true diff --git a/crates/directory/src/lib.rs b/crates/directory/src/lib.rs index 23846da..a6c6f07 100644 --- a/crates/directory/src/lib.rs +++ b/crates/directory/src/lib.rs @@ -8,6 +8,7 @@ //! people's behalf. pub mod config; +pub mod otel; pub mod store; use std::sync::{Arc, RwLock}; @@ -177,14 +178,23 @@ pub async fn refresher(dir: Shared) { loop { match dir.store.due(REFRESH_EVERY, 25).await { Ok(due) => { - for d in &due { - if let Err(e) = dir.refresh(d).await { - tracing::warn!(feed = %d.id, error = %format!("{e:#}"), "could not store a feed check"); - } - } if !due.is_empty() { - // One line a round, for the dashboard's refresher panel (#210); failures have their own. - tracing::info!(checked = due.len(), "feeds checked"); + // A round is a trace, each feed's check a span in it (#213). + let round = tracing::info_span!("refresh", feeds = due.len()); + tracing::Instrument::instrument( + async { + for d in &due { + let check = tracing::info_span!("feed", feed = %d.id); + if let Err(e) = tracing::Instrument::instrument(dir.refresh(d), check).await { + tracing::warn!(feed = %d.id, error = %format!("{e:#}"), "could not store a feed check"); + } + } + // One line a round, for the dashboard's refresher panel (#210); failures have their own. + tracing::info!(checked = due.len(), "feeds checked"); + }, + round, + ) + .await; continue; } } @@ -264,7 +274,26 @@ struct Who(String); async fn access_log(req: Request, next: Next) -> Response { let (method, path) = (req.method().clone(), req.uri().path().to_owned()); let start = Instant::now(); - let resp = next.run(req).await; + // A span for each request but the healthcheck's, a child of the caller's when it sent a + // traceparent, as ipx does on its calls here (#213). + let span = if path == "/healthz" { + tracing::Span::none() + } else { + tracing::info_span!( + "http", + otel.name = %format!("{method} {path}"), + http.request.method = %method, + url.path = %path, + http.response.status_code = tracing::field::Empty, + ) + }; + if let Some(parent) = otel::remote_parent(req.headers(), None) { + use tracing_opentelemetry::OpenTelemetrySpanExt; + let _ = span.set_parent(parent); + } + let resp = tracing::Instrument::instrument(next.run(req), span.clone()).await; + span.record("http.response.status_code", resp.status().as_u16()); + let _in = span.enter(); let who = resp.extensions().get::().map_or("", |w| w.0.as_str()).to_owned(); let status = resp.status().as_u16(); if path != "/healthz" { diff --git a/crates/directory/src/main.rs b/crates/directory/src/main.rs index 19ede82..d7c1e67 100644 --- a/crates/directory/src/main.rs +++ b/crates/directory/src/main.rs @@ -75,11 +75,16 @@ async fn main() -> Result<()> { async fn serve(path: &std::path::Path) -> Result<()> { // One JSON object a line for Loki when DIRECTORY_LOG_FORMAT=json, as ipx does; text otherwise. let json = std::env::var("DIRECTORY_LOG_FORMAT").is_ok_and(|f| f.eq_ignore_ascii_case("json")); - let filter = tracing_subscriber::EnvFilter::try_from_env("DIRECTORY_LOG").unwrap_or_else(|_| "ipx_directory=info".into()); + let filter = || tracing_subscriber::EnvFilter::try_from_env("DIRECTORY_LOG").unwrap_or_else(|_| "ipx_directory=info".into()); + // Traces to Tempo when OTEL_EXPORTER_OTLP_ENDPOINT is set, joining ipx's (#213). + let otel = ipx_directory::otel::provider("ipx-directory")?; tracing_subscriber::registry() - .with(filter) - .with((!json).then(|| tracing_subscriber::fmt::layer().with_writer(std::io::stderr))) - .with(json.then(|| tracing_subscriber::fmt::layer().json().flatten_event(true).with_writer(std::io::stderr))) + .with((!json).then(|| tracing_subscriber::fmt::layer().with_writer(std::io::stderr).with_filter(filter()))) + .with(json.then(|| tracing_subscriber::fmt::layer().json().flatten_event(true).with_writer(std::io::stderr).with_filter(filter()))) + .with(otel.as_ref().map(|p| { + use opentelemetry::trace::TracerProvider; + tracing_opentelemetry::layer().with_tracer(p.tracer("ipx-directory")).with_filter(tracing_subscriber::EnvFilter::new("ipx_directory=info")) + })) .init(); let cfg = config::Config::load(path)?; @@ -105,5 +110,9 @@ async fn serve(path: &std::path::Path) -> Result<()> { } }) .await?; + // The batch exporter holds the last few seconds of spans; without this they are lost. + if let Some(p) = otel { + let _ = p.shutdown(); + } Ok(()) } diff --git a/crates/directory/src/otel.rs b/crates/directory/src/otel.rs new file mode 100644 index 0000000..deb31cb --- /dev/null +++ b/crates/directory/src/otel.rs @@ -0,0 +1,83 @@ +//! Traces, for ipx and the directory both (#213): the exporter, and W3C `traceparent` in from a +//! caller and out to a callee, so one trace follows a request from the browser through ipx-web +//! and ipx into the directory. + +/// Traces over OTLP, to Tempo for one, when OTEL_EXPORTER_OTLP_ENDPOINT names a collector +/// (`http://host:4318`: the exporter speaks OTLP over HTTP and adds `/v1/traces`). The exporter +/// reads that and the other `OTEL_` variables itself. +pub fn provider(service: &'static str) -> anyhow::Result> { + if std::env::var("OTEL_EXPORTER_OTLP_ENDPOINT").unwrap_or_default().is_empty() { + return Ok(None); + } + let exporter = opentelemetry_otlp::SpanExporter::builder().with_http().build()?; + let resource = opentelemetry_sdk::Resource::builder().with_service_name(service).build(); + Ok(Some( + opentelemetry_sdk::trace::SdkTracerProvider::builder() + .with_batch_exporter(exporter) + .with_resource(resource) + .build(), + )) +} + +/// The trace a request from the page belongs to, from its `traceparent` (#190), so the requests +/// one action sets off are one trace. None for a missing or malformed one. In the query where no +/// header can be set: a position saved by sendBeacon, and the playlist Safari's player fetches +/// itself (#192). +pub fn remote_parent(headers: &axum::http::HeaderMap, query: Option<&str>) -> Option { + use opentelemetry::trace::{SpanContext, SpanId, TraceContextExt, TraceFlags, TraceId, TraceState}; + let v = match headers.get("traceparent") { + Some(h) => h.to_str().ok()?, + None => query?.split('&').find_map(|kv| kv.strip_prefix("traceparent="))?, + }; + let mut parts = v.split('-'); + let (version, trace, span) = (parts.next()?, parts.next()?, parts.next()?); + if version != "00" || trace.len() != 32 || span.len() != 16 { + return None; + } + let sc = SpanContext::new( + TraceId::from_hex(trace).ok()?, + SpanId::from_hex(span).ok()?, + TraceFlags::SAMPLED, + true, + TraceState::default(), + ); + sc.is_valid().then(|| opentelemetry::Context::new().with_remote_span_context(sc)) +} + +/// The current span as a `traceparent`, for a request to another service, so its spans join +/// this trace. None outside a traced span. +pub fn traceparent() -> Option { + use opentelemetry::trace::TraceContextExt; + use tracing_opentelemetry::OpenTelemetrySpanExt; + let cx = tracing::Span::current().context(); + let sc = cx.span().span_context().clone(); + sc.is_valid().then(|| format!("00-{}-{}-{:02x}", sc.trace_id(), sc.span_id(), sc.trace_flags().to_u8())) +} + +#[cfg(test)] +mod tests { + use super::*; + + #[test] + fn a_requests_trace_is_the_pages_from_its_traceparent() { + use opentelemetry::trace::TraceContextExt; + let with = |v: &str| { + let mut h = axum::http::HeaderMap::new(); + h.insert("traceparent", v.parse().unwrap()); + remote_parent(&h, None) + }; + let cx = with("00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01").expect("parsed"); + assert_eq!(cx.span().span_context().trace_id().to_string(), "4bf92f3577b34da6a3ce929d0e0e4736"); + assert!(cx.span().span_context().is_remote()); + // Anything else from the browser starts a trace of its own. + for bad in ["", "00-xyz-00f067aa0ba902b7-01", "01-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01", + "00-00000000000000000000000000000000-00f067aa0ba902b7-01", "00-4bf92f3577b34da6a3ce929d0e0e4736"] { + assert!(with(bad).is_none(), "{bad}"); + } + assert!(remote_parent(&axum::http::HeaderMap::new(), None).is_none()); + // From the query, where a beacon or Safari's player cannot send a header (#192). + let q = remote_parent(&axum::http::HeaderMap::new(), Some("x=1&traceparent=00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01")); + assert_eq!(q.unwrap().span().span_context().trace_id().to_string(), "4bf92f3577b34da6a3ce929d0e0e4736"); + assert!(remote_parent(&axum::http::HeaderMap::new(), Some("traceparent=nonsense")).is_none()); + } +} diff --git a/crates/ipx/Cargo.toml b/crates/ipx/Cargo.toml index 135bade..52b0b22 100644 --- a/crates/ipx/Cargo.toml +++ b/crates/ipx/Cargo.toml @@ -17,8 +17,6 @@ futures-util.workspace = true jsonwebtoken.workspace = true librqbit.workspace = true opentelemetry.workspace = true -opentelemetry-otlp.workspace = true -opentelemetry_sdk.workspace = true opml.workspace = true percent-encoding.workspace = true quick-xml.workspace = true diff --git a/crates/ipx/src/directory.rs b/crates/ipx/src/directory.rs index f5c53f3..e0c623c 100644 --- a/crates/ipx/src/directory.rs +++ b/crates/ipx/src/directory.rs @@ -58,6 +58,10 @@ pub fn configured(cfg: &config::Config) -> bool { async fn call(ctx: &Ctx, method: reqwest::Method, path: &str, body: Option<&[SnapshotEntry]>) -> Result { let (base, token) = target(&ctx.cfg()).ok_or(DirError::NotConfigured)?; let mut req = ctx.client.request(method, format!("{base}{path}")).bearer_auth(token).timeout(std::time::Duration::from_secs(20)); + // The directory's spans join this request's trace (#213). + if let Some(tp) = ipx_directory::otel::traceparent() { + req = req.header("traceparent", tp); + } if let Some(b) = body { req = req.json(b); } @@ -147,7 +151,8 @@ pub async fn run(ctx: std::sync::Arc, mut stop: tokio::sync::watch::Receive Ok(entries) => { let key = serde_json::to_vec(&(target(&cfg), &entries)).unwrap_or_default(); if resend(last.as_ref(), &key) { - let got = share(&ctx, &entries).await; + let span = tracing::info_span!(target: "ipx::directory", "directory_share", feeds = entries.len()); + let got = tracing::Instrument::instrument(share(&ctx, &entries), span).await; if got.is_ok() { last = Some((key, std::time::Instant::now())); } diff --git a/crates/ipx/src/main.rs b/crates/ipx/src/main.rs index 5f9ec76..23a125b 100644 --- a/crates/ipx/src/main.rs +++ b/crates/ipx/src/main.rs @@ -254,7 +254,7 @@ async fn main() -> Result<()> { // The daemon only: `ipx status` runs every half minute as the healthcheck, and a trace // for each would bury the ones worth looking at. let otel = match cli.command { - Command::Daemon { .. } => otel_provider()?, + Command::Daemon { .. } => ipx_directory::otel::provider("ipx")?, _ => None, }; // Everything goes to stderr as before, and is mirrored into a ring the UI can read. @@ -424,23 +424,6 @@ where } } -/// Traces over OTLP, to Tempo for one, when OTEL_EXPORTER_OTLP_ENDPOINT names a collector -/// (`http://host:4318`: the exporter speaks OTLP over HTTP and adds `/v1/traces`). The exporter -/// reads that and the other `OTEL_` variables itself. -fn otel_provider() -> Result> { - if std::env::var("OTEL_EXPORTER_OTLP_ENDPOINT").unwrap_or_default().is_empty() { - return Ok(None); - } - let exporter = opentelemetry_otlp::SpanExporter::builder().with_http().build()?; - let resource = opentelemetry_sdk::Resource::builder().with_service_name("ipx").build(); - Ok(Some( - opentelemetry_sdk::trace::SdkTracerProvider::builder() - .with_batch_exporter(exporter) - .with_resource(resource) - .build(), - )) -} - /// Accounts. Passwords come in on stdin so they never reach a shell history or a `ps` /// listing. async fn user_cmd(ctx: &Arc, cmd: UserCmd) -> Result<()> { diff --git a/crates/ipx/src/web.rs b/crates/ipx/src/web.rs index a8b3dc0..81ecca5 100644 --- a/crates/ipx/src/web.rs +++ b/crates/ipx/src/web.rs @@ -1039,28 +1039,6 @@ mod tests { } - #[test] - fn a_requests_trace_is_the_pages_from_its_traceparent() { - use opentelemetry::trace::TraceContextExt; - let with = |v: &str| { - let mut h = HeaderMap::new(); - h.insert("traceparent", v.parse().unwrap()); - remote_parent(&h, None) - }; - let cx = with("00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01").expect("parsed"); - assert_eq!(cx.span().span_context().trace_id().to_string(), "4bf92f3577b34da6a3ce929d0e0e4736"); - assert!(cx.span().span_context().is_remote()); - // Anything else from the browser starts a trace of its own. - for bad in ["", "00-xyz-00f067aa0ba902b7-01", "01-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01", - "00-00000000000000000000000000000000-00f067aa0ba902b7-01", "00-4bf92f3577b34da6a3ce929d0e0e4736"] { - assert!(with(bad).is_none(), "{bad}"); - } - assert!(remote_parent(&HeaderMap::new(), None).is_none()); - // From the query, where a beacon or Safari's player cannot send a header (#192). - let q = remote_parent(&HeaderMap::new(), Some("x=1&traceparent=00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01")); - assert_eq!(q.unwrap().span().span_context().trace_id().to_string(), "4bf92f3577b34da6a3ce929d0e0e4736"); - assert!(remote_parent(&HeaderMap::new(), Some("traceparent=nonsense")).is_none()); - } #[tokio::test] async fn the_page_reports_only_what_it_is_meant_to() { @@ -2231,30 +2209,6 @@ async fn client_event(user: crate::db::User, Json(e): Json) -> Stat StatusCode::NO_CONTENT } -/// The trace a request from the page belongs to, from its `traceparent` (#190), so the requests -/// one action sets off are one trace. None for a missing or malformed one. In the query where no -/// header can be set: a position saved by sendBeacon, and the playlist Safari's player fetches -/// itself (#192). -fn remote_parent(headers: &HeaderMap, query: Option<&str>) -> Option { - use opentelemetry::trace::{SpanContext, SpanId, TraceContextExt, TraceFlags, TraceId, TraceState}; - let v = match headers.get("traceparent") { - Some(h) => h.to_str().ok()?, - None => query?.split('&').find_map(|kv| kv.strip_prefix("traceparent="))?, - }; - let mut parts = v.split('-'); - let (version, trace, span) = (parts.next()?, parts.next()?, parts.next()?); - if version != "00" || trace.len() != 32 || span.len() != 16 { - return None; - } - let sc = SpanContext::new( - TraceId::from_hex(trace).ok()?, - SpanId::from_hex(span).ok()?, - TraceFlags::SAMPLED, - true, - TraceState::default(), - ); - sc.is_valid().then(|| opentelemetry::Context::new().with_remote_span_context(sc)) -} /// Names a request's trace by its route, `POST /api/entries/{feed_id}/{guid}/flags`, once routing /// has found it. Named by the path `access_log` sees, every item's GUID was a trace name of its @@ -2295,7 +2249,7 @@ async fn access_log(req: Request, next: Next) -> Response { http.response.status_code = tracing::field::Empty, ) }; - if let Some(parent) = remote_parent(req.headers(), req.uri().query()) { + if let Some(parent) = ipx_directory::otel::remote_parent(req.headers(), req.uri().query()) { use tracing_opentelemetry::OpenTelemetrySpanExt; let _ = span.set_parent(parent); } diff --git a/grafana/dashboard.py b/grafana/dashboard.py index 4385bd6..254bfff 100644 --- a/grafana/dashboard.py +++ b/grafana/dashboard.py @@ -25,7 +25,9 @@ EV = SEL + ' |= "\\"ev\\":\\"" | json | __error__="" | ev != ""' HTTP = SEL + ' |= "\\"target\\":\\"ipx::http\\"" | json | __error__="" | path != "/api/events"' BAD = SEL + ' | json | __error__="" | level =~ "WARN|ERROR"' TEXT = ' | line_format "{{.level}} {{.target}}: {{.message}}"' -TRACES = '{resource.service.name="ipx" && resource.deployment.environment.name="production"' +# Every production span: ipx-web's, ipx's and the directory's, one trace from the page to the +# directory where a request goes that far (#213). A daemon run by hand has no such tag. +TRACES = '{resource.deployment.environment.name="production"' # The directory's JSON log (#204): a line a request (method, path, status, duration_ms, token), a # line a snapshot (instance, accepted, refused_*), a line a refresher round (checked) and one a # failed feed check (feed, error). @@ -294,11 +296,12 @@ table("Snapshots by server", [loki(f'sum by (instance) (count_over_time({DIR} | 12, rename={"instance": "Token", "Value": "Snapshots"}, sort=[{"displayName": "Snapshots", "desc": True}]) y += 8 -# ---- Traces: ipx's, to Tempo; ipx-web and the directory send none -row("ipx: traces") -for x, title, q in [(0, "Recent traces", TRACES + "}"), - (12, "Slow traces (over 2s)", TRACES + " && duration > 2s}")]: - panel("table", title, 12, 10, x, +# ---- Traces: all three send them to Tempo (#213) +row("Traces") +for x, title, q in [(0, "Recent", TRACES + "}"), + (8, "Slow (over 2s)", TRACES + " && duration > 2s}"), + (16, "Failed", TRACES + " && status = error}")]: + panel("table", title, 8, 10, x, [{"refId": "A", "datasource": TEMPO, "queryType": "traceql", "query": q, "limit": 50, "tableType": "traces"}], fieldConfig={"defaults": {}, "overrides": []})