Directory requests traced whole: the call, its answer's size, the matching (#250)

A Directory page took 983 ms during a scan with 19 ms under spans: the directory's own span ends
when it has answered, and ipx's reading of the 458 KB answer, its subscriptions and catalogue,
and the matching of 1,471 listings had none. call() is a span now, directory_call, with the
answer's size; rows_for has subscriptions, catalogue and match steps.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
This commit is contained in:
2026-10-16 13:50:30 +00:00
parent cd7a9b8530
commit 3d94bce4f5
3 changed files with 9 additions and 1 deletions

View File

@@ -22,6 +22,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
### Added
- A Directory request's trace shows the call to the directory whole, with the size of its answer, and the steps that match it against your subscriptions (#250).
- The page's report of how long a list took to show after a click (`list_shown`, with the view and filter) is logged under that click's trace (#246).
## [1.2.0] - 2026-10-15

View File

@@ -55,6 +55,9 @@ pub fn configured(cfg: &config::Config) -> bool {
target(cfg).is_some()
}
/// A span the whole call, its answer read and parsed included: the directory's own span ends when it
/// has answered, so a slow read of a large answer showed under no span (#250).
#[tracing::instrument(name = "directory_call", skip_all, fields(http.request.method = %method, url.path = %path.split('?').next().unwrap_or(path), http.response.body.size))]
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 mut req = ctx.client.request(method, format!("{base}{path}")).bearer_auth(token).timeout(std::time::Duration::from_secs(20));
@@ -73,6 +76,7 @@ async fn call<T: DeserializeOwned>(ctx: &Ctx, method: reqwest::Method, path: &st
}
// A removal or an unblock answers 204, with nothing to read: that reads as null, which is ().
let body = resp.bytes().await.map_err(|e| DirError::Unreachable(format!("{e:#}")))?;
tracing::Span::current().record("http.response.body.size", body.len());
serde_json::from_slice(if body.is_empty() { b"null" } else { &body }).map_err(|e| DirError::Unreachable(format!("its answer did not read: {e:#}")))
}

View File

@@ -831,14 +831,17 @@ fn dir_error(e: crate::directory::DirError) -> ApiError {
/// The directory's listings as this person sees them: which are theirs already, matched by
/// address, since the directory and this server name a feed differently.
async fn rows_for(state: &WebState, user_id: i64, listed: Vec<ipx_directory::Listing>) -> Result<Vec<PopularRow>> {
// A step each, as the feed list has: a Directory page of 983 ms showed 19 under spans (#250).
let mine: std::collections::HashSet<String> =
state.ctx.db.subscriptions_for(user_id).await?.into_iter().map(|s| s.feed_id).collect();
state.ctx.db.subscriptions_for(user_id).instrument(step("subscriptions")).await?.into_iter().map(|s| s.feed_id).collect();
let here: std::collections::HashMap<String, String> = crate::subscriptions(&state.ctx)
.instrument(step("catalogue"))
.await?
.into_iter()
.filter(|s| mine.contains(&s.id))
.filter_map(|s| ipx_directory::store::normalise(&s.cfg.url).map(|u| (u, s.id)))
.collect();
let _matching = step("match").entered();
Ok(listed
.into_iter()
.map(|l| {