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 <noreply@anthropic.com>
This commit is contained in:
@@ -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 |
|
| 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-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`) | yes, tagged `resource.deployment.environment.name="production"` | `job="ipx"`, its `/metrics` |
|
| `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`) | none | none |
|
| `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
|
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
|
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:
|
Prometheus publish no query port to this machine, so use the script beside this file:
|
||||||
|
|
||||||
```sh
|
```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
|
`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
|
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.
|
`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" && duration > 5s}'
|
||||||
$Q traces '{resource.deployment.environment.name="production" && status = error}'
|
$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
|
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.
|
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
|
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
|
(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
|
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
|
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
|
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
|
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
|
```sh
|
||||||
D='{container="ipx-directory"} | json | __error__=""'
|
D='{container="ipx-directory"} | json | __error__=""'
|
||||||
|
|||||||
@@ -9,6 +9,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
|
|||||||
|
|
||||||
### Added
|
### 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).
|
- 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).
|
- 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).
|
- `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).
|
||||||
|
|||||||
6
Cargo.lock
generated
6
Cargo.lock
generated
@@ -1835,8 +1835,6 @@ dependencies = [
|
|||||||
"jsonwebtoken",
|
"jsonwebtoken",
|
||||||
"librqbit",
|
"librqbit",
|
||||||
"opentelemetry",
|
"opentelemetry",
|
||||||
"opentelemetry-otlp",
|
|
||||||
"opentelemetry_sdk",
|
|
||||||
"opml",
|
"opml",
|
||||||
"percent-encoding",
|
"percent-encoding",
|
||||||
"quick-xml 0.42.0",
|
"quick-xml 0.42.0",
|
||||||
@@ -1864,6 +1862,9 @@ dependencies = [
|
|||||||
"axum",
|
"axum",
|
||||||
"clap",
|
"clap",
|
||||||
"ipx-feed",
|
"ipx-feed",
|
||||||
|
"opentelemetry",
|
||||||
|
"opentelemetry-otlp",
|
||||||
|
"opentelemetry_sdk",
|
||||||
"reqwest",
|
"reqwest",
|
||||||
"sea-orm",
|
"sea-orm",
|
||||||
"serde",
|
"serde",
|
||||||
@@ -1873,6 +1874,7 @@ dependencies = [
|
|||||||
"toml",
|
"toml",
|
||||||
"tower",
|
"tower",
|
||||||
"tracing",
|
"tracing",
|
||||||
|
"tracing-opentelemetry",
|
||||||
"tracing-subscriber",
|
"tracing-subscriber",
|
||||||
"url",
|
"url",
|
||||||
]
|
]
|
||||||
|
|||||||
@@ -12,6 +12,9 @@ anyhow.workspace = true
|
|||||||
axum.workspace = true
|
axum.workspace = true
|
||||||
clap.workspace = true
|
clap.workspace = true
|
||||||
ipx-feed.workspace = true
|
ipx-feed.workspace = true
|
||||||
|
opentelemetry.workspace = true
|
||||||
|
opentelemetry-otlp.workspace = true
|
||||||
|
opentelemetry_sdk.workspace = true
|
||||||
reqwest.workspace = true
|
reqwest.workspace = true
|
||||||
sea-orm.workspace = true
|
sea-orm.workspace = true
|
||||||
serde.workspace = true
|
serde.workspace = true
|
||||||
@@ -20,6 +23,7 @@ sha2.workspace = true
|
|||||||
tokio.workspace = true
|
tokio.workspace = true
|
||||||
toml.workspace = true
|
toml.workspace = true
|
||||||
tracing.workspace = true
|
tracing.workspace = true
|
||||||
|
tracing-opentelemetry.workspace = true
|
||||||
tracing-subscriber.workspace = true
|
tracing-subscriber.workspace = true
|
||||||
url.workspace = true
|
url.workspace = true
|
||||||
|
|
||||||
|
|||||||
@@ -8,6 +8,7 @@
|
|||||||
//! people's behalf.
|
//! people's behalf.
|
||||||
|
|
||||||
pub mod config;
|
pub mod config;
|
||||||
|
pub mod otel;
|
||||||
pub mod store;
|
pub mod store;
|
||||||
|
|
||||||
use std::sync::{Arc, RwLock};
|
use std::sync::{Arc, RwLock};
|
||||||
@@ -177,14 +178,23 @@ pub async fn refresher(dir: Shared) {
|
|||||||
loop {
|
loop {
|
||||||
match dir.store.due(REFRESH_EVERY, 25).await {
|
match dir.store.due(REFRESH_EVERY, 25).await {
|
||||||
Ok(due) => {
|
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() {
|
if !due.is_empty() {
|
||||||
// One line a round, for the dashboard's refresher panel (#210); failures have their own.
|
// A round is a trace, each feed's check a span in it (#213).
|
||||||
tracing::info!(checked = due.len(), "feeds checked");
|
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;
|
continue;
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
@@ -264,7 +274,26 @@ struct Who(String);
|
|||||||
async fn access_log(req: Request, next: Next) -> Response {
|
async fn access_log(req: Request, next: Next) -> Response {
|
||||||
let (method, path) = (req.method().clone(), req.uri().path().to_owned());
|
let (method, path) = (req.method().clone(), req.uri().path().to_owned());
|
||||||
let start = Instant::now();
|
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::<Who>().map_or("", |w| w.0.as_str()).to_owned();
|
let who = resp.extensions().get::<Who>().map_or("", |w| w.0.as_str()).to_owned();
|
||||||
let status = resp.status().as_u16();
|
let status = resp.status().as_u16();
|
||||||
if path != "/healthz" {
|
if path != "/healthz" {
|
||||||
|
|||||||
@@ -75,11 +75,16 @@ async fn main() -> Result<()> {
|
|||||||
async fn serve(path: &std::path::Path) -> 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.
|
// 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 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()
|
tracing_subscriber::registry()
|
||||||
.with(filter)
|
.with((!json).then(|| tracing_subscriber::fmt::layer().with_writer(std::io::stderr).with_filter(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_filter(filter())))
|
||||||
.with(json.then(|| tracing_subscriber::fmt::layer().json().flatten_event(true).with_writer(std::io::stderr)))
|
.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();
|
.init();
|
||||||
|
|
||||||
let cfg = config::Config::load(path)?;
|
let cfg = config::Config::load(path)?;
|
||||||
@@ -105,5 +110,9 @@ async fn serve(path: &std::path::Path) -> Result<()> {
|
|||||||
}
|
}
|
||||||
})
|
})
|
||||||
.await?;
|
.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(())
|
Ok(())
|
||||||
}
|
}
|
||||||
|
|||||||
83
crates/directory/src/otel.rs
Normal file
83
crates/directory/src/otel.rs
Normal file
@@ -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<Option<opentelemetry_sdk::trace::SdkTracerProvider>> {
|
||||||
|
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<opentelemetry::Context> {
|
||||||
|
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<String> {
|
||||||
|
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());
|
||||||
|
}
|
||||||
|
}
|
||||||
@@ -17,8 +17,6 @@ futures-util.workspace = true
|
|||||||
jsonwebtoken.workspace = true
|
jsonwebtoken.workspace = true
|
||||||
librqbit.workspace = true
|
librqbit.workspace = true
|
||||||
opentelemetry.workspace = true
|
opentelemetry.workspace = true
|
||||||
opentelemetry-otlp.workspace = true
|
|
||||||
opentelemetry_sdk.workspace = true
|
|
||||||
opml.workspace = true
|
opml.workspace = true
|
||||||
percent-encoding.workspace = true
|
percent-encoding.workspace = true
|
||||||
quick-xml.workspace = true
|
quick-xml.workspace = true
|
||||||
|
|||||||
@@ -58,6 +58,10 @@ pub fn configured(cfg: &config::Config) -> bool {
|
|||||||
async fn call<T: DeserializeOwned>(ctx: &Ctx, method: reqwest::Method, path: &str, body: Option<&[SnapshotEntry]>) -> Result<T, DirError> {
|
async fn call<T: DeserializeOwned>(ctx: &Ctx, method: reqwest::Method, path: &str, body: Option<&[SnapshotEntry]>) -> Result<T, DirError> {
|
||||||
let (base, token) = target(&ctx.cfg()).ok_or(DirError::NotConfigured)?;
|
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));
|
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 {
|
if let Some(b) = body {
|
||||||
req = req.json(b);
|
req = req.json(b);
|
||||||
}
|
}
|
||||||
@@ -147,7 +151,8 @@ pub async fn run(ctx: std::sync::Arc<Ctx>, mut stop: tokio::sync::watch::Receive
|
|||||||
Ok(entries) => {
|
Ok(entries) => {
|
||||||
let key = serde_json::to_vec(&(target(&cfg), &entries)).unwrap_or_default();
|
let key = serde_json::to_vec(&(target(&cfg), &entries)).unwrap_or_default();
|
||||||
if resend(last.as_ref(), &key) {
|
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() {
|
if got.is_ok() {
|
||||||
last = Some((key, std::time::Instant::now()));
|
last = Some((key, std::time::Instant::now()));
|
||||||
}
|
}
|
||||||
|
|||||||
@@ -254,7 +254,7 @@ async fn main() -> Result<()> {
|
|||||||
// The daemon only: `ipx status` runs every half minute as the healthcheck, and a trace
|
// The daemon only: `ipx status` runs every half minute as the healthcheck, and a trace
|
||||||
// for each would bury the ones worth looking at.
|
// for each would bury the ones worth looking at.
|
||||||
let otel = match cli.command {
|
let otel = match cli.command {
|
||||||
Command::Daemon { .. } => otel_provider()?,
|
Command::Daemon { .. } => ipx_directory::otel::provider("ipx")?,
|
||||||
_ => None,
|
_ => None,
|
||||||
};
|
};
|
||||||
// Everything goes to stderr as before, and is mirrored into a ring the UI can read.
|
// 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<Option<opentelemetry_sdk::trace::SdkTracerProvider>> {
|
|
||||||
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`
|
/// Accounts. Passwords come in on stdin so they never reach a shell history or a `ps`
|
||||||
/// listing.
|
/// listing.
|
||||||
async fn user_cmd(ctx: &Arc<Ctx>, cmd: UserCmd) -> Result<()> {
|
async fn user_cmd(ctx: &Arc<Ctx>, cmd: UserCmd) -> Result<()> {
|
||||||
|
|||||||
@@ -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]
|
#[tokio::test]
|
||||||
async fn the_page_reports_only_what_it_is_meant_to() {
|
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<ClientEvent>) -> Stat
|
|||||||
StatusCode::NO_CONTENT
|
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<opentelemetry::Context> {
|
|
||||||
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
|
/// 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
|
/// 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,
|
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;
|
use tracing_opentelemetry::OpenTelemetrySpanExt;
|
||||||
let _ = span.set_parent(parent);
|
let _ = span.set_parent(parent);
|
||||||
}
|
}
|
||||||
|
|||||||
@@ -25,7 +25,9 @@ EV = SEL + ' |= "\\"ev\\":\\"" | json | __error__="" | ev != ""'
|
|||||||
HTTP = SEL + ' |= "\\"target\\":\\"ipx::http\\"" | json | __error__="" | path != "/api/events"'
|
HTTP = SEL + ' |= "\\"target\\":\\"ipx::http\\"" | json | __error__="" | path != "/api/events"'
|
||||||
BAD = SEL + ' | json | __error__="" | level =~ "WARN|ERROR"'
|
BAD = SEL + ' | json | __error__="" | level =~ "WARN|ERROR"'
|
||||||
TEXT = ' | line_format "{{.level}} {{.target}}: {{.message}}"'
|
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
|
# 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
|
# line a snapshot (instance, accepted, refused_*), a line a refresher round (checked) and one a
|
||||||
# failed feed check (feed, error).
|
# 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}])
|
12, rename={"instance": "Token", "Value": "Snapshots"}, sort=[{"displayName": "Snapshots", "desc": True}])
|
||||||
y += 8
|
y += 8
|
||||||
|
|
||||||
# ---- Traces: ipx's, to Tempo; ipx-web and the directory send none
|
# ---- Traces: all three send them to Tempo (#213)
|
||||||
row("ipx: traces")
|
row("Traces")
|
||||||
for x, title, q in [(0, "Recent traces", TRACES + "}"),
|
for x, title, q in [(0, "Recent", TRACES + "}"),
|
||||||
(12, "Slow traces (over 2s)", TRACES + " && duration > 2s}")]:
|
(8, "Slow (over 2s)", TRACES + " && duration > 2s}"),
|
||||||
panel("table", title, 12, 10, x,
|
(16, "Failed", TRACES + " && status = error}")]:
|
||||||
|
panel("table", title, 8, 10, x,
|
||||||
[{"refId": "A", "datasource": TEMPO, "queryType": "traceql", "query": q, "limit": 50,
|
[{"refId": "A", "datasource": TEMPO, "queryType": "traceql", "query": q, "limit": 50,
|
||||||
"tableType": "traces"}],
|
"tableType": "traces"}],
|
||||||
fieldConfig={"defaults": {}, "overrides": []})
|
fieldConfig={"defaults": {}, "overrides": []})
|
||||||
|
|||||||
Reference in New Issue
Block a user