The page reports its errors and playback timings, and its requests carry a trace (#190)

Nothing the page did in the browser reached the logs: a DeadAir playback
failure on the phone was a toast and nothing more. POST /api/client takes
page errors, unhandled rejections, hls.js and media errors, the time from
play to sound and the length of a stall, and logs them as ev lines under
ipx::client, inside the request's span. Only those kinds are taken, the
text cut to 500 characters, and the page sends each at most once a minute.

The page's API requests send traceparent, a new trace id for each tap or
key, and the server's request span takes it as its parent, so one action's
requests are one trace in Tempo, the report included. The stub DOM the
smoke and native-bridge tests run in gains crypto and performance, which
every browser the page runs in has.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
This commit is contained in:
2026-10-11 14:15:20 +00:00
parent 9648a79f3f
commit 6c931d0485
7 changed files with 138 additions and 3 deletions

View File

@@ -67,6 +67,7 @@ pub fn router(state: WebState) -> Router {
.route("/api/users", get(list_users).post(add_user))
.route("/api/users/{id}", patch(patch_user).delete(remove_user))
.route("/api/logs", get(logs))
.route("/api/client", post(client_event))
.route("/api/events", get(events))
.route("/admin", get(admin_page))
.route("/admin.js", get(admin_js))
@@ -1322,6 +1323,37 @@ mod tests {
assert_eq!(got, ["kid", "plain"], "the OPML as its feeds; a private feed and its shows never");
}
#[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)
};
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()).is_none());
}
#[tokio::test]
async fn the_page_reports_only_what_it_is_meant_to() {
let u = crate::db::User { id: 1, name: "dee".into(), pass_hash: None, is_admin: false, created: None, last_login: None };
let e = |ev: &str| ClientEvent {
ev: ev.into(), msg: Some("x".repeat(10_000)), src: None, line: None, feed: None, enclosure: None, deadair: None, ms: Some(5),
};
for ev in ["page_error", "rejection", "player_error", "play_start", "stall"] {
assert_eq!(client_event(u.clone(), Json(e(ev))).await, StatusCode::NO_CONTENT, "{ev}");
}
assert_eq!(client_event(u, Json(e("anything"))).await, StatusCode::BAD_REQUEST);
}
#[test]
fn only_the_last_admin_is_protected() {
let u = |id, is_admin| crate::db::User {
@@ -2389,6 +2421,60 @@ async fn logs(user: crate::db::User, Query(q): Query<LogQuery>) -> Result<Json<L
Ok(Json(LogPage { lines, latest }))
}
/// What the page reports from the browser (#190): its errors and its player's, and how long play
/// took to start or stalled for. Logged as `ev` lines under `ipx::client`, inside the request's
/// span, so a line carries the trace of the action that led to it.
#[derive(Deserialize)]
struct ClientEvent {
ev: String,
msg: Option<String>,
src: Option<String>,
line: Option<u32>,
feed: Option<String>,
enclosure: Option<i64>,
deadair: Option<bool>,
ms: Option<u64>,
}
async fn client_event(user: crate::db::User, Json(e): Json<ClientEvent>) -> StatusCode {
// From the browser: only the kinds the page sends, and nothing long enough to fill the log.
let cut = |s: &Option<String>| s.as_deref().map(|s| s.chars().take(500).collect::<String>());
let (msg, src, feed) = (cut(&e.msg), cut(&e.src), cut(&e.feed));
let (ev, line, enclosure, deadair, ms, user) = (e.ev.as_str(), e.line, e.enclosure, e.deadair, e.ms, user.name.as_str());
match ev {
"page_error" | "rejection" | "player_error" => tracing::warn!(
target: "ipx::client", ev, msg, src, line, feed, enclosure, deadair, user,
"{user}'s page: {ev}: {}", msg.as_deref().unwrap_or("")
),
"play_start" | "stall" => tracing::info!(
target: "ipx::client", ev, ms, feed, enclosure, deadair, user,
"{user}'s page: {ev} {} ms", ms.unwrap_or(0)
),
_ => return StatusCode::BAD_REQUEST,
}
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.
fn remote_parent(headers: &HeaderMap) -> Option<opentelemetry::Context> {
use opentelemetry::trace::{SpanContext, SpanId, TraceContextExt, TraceFlags, TraceId, TraceState};
let v = headers.get("traceparent")?.to_str().ok()?;
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
/// own, and nothing grouped. A route layer, because only one runs after routing. Renamed on the
@@ -2428,6 +2514,10 @@ async fn access_log(req: Request, next: Next) -> Response {
http.response.status_code = tracing::field::Empty,
)
};
if let Some(parent) = remote_parent(req.headers()) {
use tracing_opentelemetry::OpenTelemetrySpanExt;
let _ = span.set_parent(parent);
}
let started = std::time::Instant::now();
let resp = tracing::Instrument::instrument(next.run(req), span.clone()).await;
span.record("http.response.status_code", resp.status().as_u16());