From 2799704d30ec33099a23bdbd15f4feaeb18c1ea2 Mon Sep 17 00:00:00 2001 From: rays Date: Tue, 29 Sep 2026 17:27:31 +0000 Subject: [PATCH] Look at a feed's artwork only when it may have changed, and trace a scan's database work (#95, #96) A feed read in full checked its own artwork and, without one, asked its website for an icon, every time; a feed without validators is read in full every scan, so looking-for-group spent 2 s of every scan loading lfg.co's home page. Now the check runs when the feed names different artwork from what is stored, or the scan was asked for, which keeps #80's point: a refresh still picks up an icon the site changes or fixes. Feed spans ran seconds past their fetch with nothing to say where (#96). The artwork lookup, the loop that stores each item, and the per-feed database calls (feed_summary, record_feed, subscribers, adopt, skipped_by_filter, rehide, pending) now have spans of their own. Co-Authored-By: Claude Opus 5.5 --- CHANGELOG.md | 2 ++ src/db.rs | 7 +++++ src/main.rs | 86 +++++++++++++++++++++++++++++----------------------- 3 files changed, 57 insertions(+), 38 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index bbb213e..ab03ab4 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -23,6 +23,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ### Changed +- A scan's trace shows the time a feed spends on its artwork and in the database after the fetch. - The JSON log carries each line's `trace_id` and `span_id`, logs each scan event once instead of twice, names a failure's kind in `error.type` (and its HTTP status in `http.response.status_code`), and calls a request's time `duration_ms` instead of `ms`. @@ -47,6 +48,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ### Fixed +- A scan no longer asks a feed's website for its icon every time; it asks again when the artwork changes or you refresh the feed. - The feed list loads several times faster: it was asking the database six questions per feed. - Artwork a feed offers only over plain http shows on the https site too. - A failing feed is easy to spot in any theme: a mark on its artwork, what is wrong in place of diff --git a/src/db.rs b/src/db.rs index 8fb54f9..d1a5dc9 100644 --- a/src/db.rs +++ b/src/db.rs @@ -313,6 +313,7 @@ impl Db { Ok(()) } + #[tracing::instrument(skip_all)] pub async fn feed_summary(&self, feed_id: &str) -> Result { let mut sum = feeds::Entity::find_by_id(feed_id.to_owned()) .one(&self.orm) @@ -432,6 +433,7 @@ impl Db { /// Upsert after a successful poll. Clears any previous error. #[allow(clippy::too_many_arguments)] + #[tracing::instrument(skip_all)] pub async fn record_feed( &self, feed_id: &str, @@ -623,6 +625,7 @@ pub struct Pending { impl Db { /// The download queue is the table, not the parse result: an enclosure held back by /// `max_new_per_check` is simply picked up by the next scan, in feed order. + #[tracing::instrument(skip_all)] pub async fn pending(&self, feed_id: &str, limit: usize) -> Result> { // Newest first: a cap of 3 should mean the three latest episodes, not the three that // happen to have been recorded first. @@ -1191,6 +1194,7 @@ impl Db { /// and downloads, since one file serves the lot. /// In a group, whatever someone has not set on the feed itself comes from their /// subscription to the group, as the group's settings dialog has always said it does. + #[tracing::instrument(skip_all)] pub async fn subscribers(&self, feed_id: &str, group: Option<&str>) -> Result> { let rows = self .rows( @@ -1324,6 +1328,7 @@ impl Db { /// ponytail: every item of the feed for every subscriber, each time the feed is scanned with /// something new or a list changes. Fine at hundreds of items a feed; look only at new items /// on a scan if a feed with thousands makes scans slow. + #[tracing::instrument(skip_all)] pub async fn rehide(&self, feed_id: &str) -> Result<()> { let lists: Vec<(i64, Vec)> = self .rows( @@ -1730,6 +1735,7 @@ impl Db { /// read state for them. A Patreon creator read as one feed before it was split into shows /// owns every show's files, and `enclosures.url` is unique, so without this each show would /// list its items with nothing to play. + #[tracing::instrument(skip_all)] pub async fn adopt(&self, parent: &str, child: &str, listed: &[(&str, &str)]) -> Result<()> { use sea_orm::TransactionTrait; let holds = enclosures::Entity::find() @@ -1773,6 +1779,7 @@ impl Db { /// A feed's enclosures skipped by one of its filters, by URL, with the reason: the verdicts a /// change of settings can overturn. A torrent held back while torrents are off is not a /// filter's call. + #[tracing::instrument(skip_all)] pub async fn skipped_by_filter(&self, feed_id: &str) -> Result> { self.rows( "SELECT url, last_error FROM enclosures diff --git a/src/main.rs b/src/main.rs index 04950e7..f4b33a3 100644 --- a/src/main.rs +++ b/src/main.rs @@ -993,7 +993,7 @@ async fn fetch(ctx: &Arc, only: Option<&str>, force: bool, scope: &[String] scanned += 1; ctx.out.emit(Event::FeedStart { feed: id.clone() }); - match scan_one(ctx, id, feed_cfg, &state).await { + match scan_one(ctx, id, feed_cfg, &state, force).await { Ok(Outcome::Feed(s)) => ctx.out.emit(Event::FeedDone { feed: id.clone(), new: s.new_entries, @@ -1039,7 +1039,7 @@ async fn fetch(ctx: &Arc, only: Option<&str>, force: bool, scope: &[String] scanned += 1; ctx.out.emit(Event::FeedStart { feed: id.clone() }); let state = ctx.db.http_state(id).await?; - match scan_one(ctx, id, feed_cfg, &state).await { + match scan_one(ctx, id, feed_cfg, &state, force).await { Ok(Outcome::Feed(s)) => ctx.out.emit(Event::FeedDone { feed: id.clone(), new: s.new_entries, @@ -1199,6 +1199,7 @@ async fn scan_one( id: &str, feed_cfg: &config::Feed, state: &db::HttpState, + force: bool, ) -> Result { // A Patreon creator with more than one show is a list of feeds, like an OPML. if feed::is_patreon_creator(&feed_cfg.url) { @@ -1266,25 +1267,30 @@ async fn scan_one( } let mut parsed = feed::parse(&bytes)?; - // Looked for again whenever the feed is read in full, which is when it has changed or - // someone asked for a refresh, so an icon the site changes or fixes follows it (#80). A miss - // is stored as "", which the page draws as no art, and which stops the refetch above. - // ponytail: a feed without validators is read in full every scan and asks its site each - // time too; keep a checked-at time per feed if that shows up in anyone's logs. + // Artwork is looked at when it may have changed: the feed names different artwork from what + // is stored, or someone asked for a refresh, so an icon the site changes or fixes still + // follows it (#80). Looked at on every full read, a feed without validators asked its site + // on every scan: 2 s a scan for lfg.co (#95). A miss is stored as "", which the page draws + // as no art, and which stops the refetch above. // A feed's own artwork has to be there too: Ken and Robin's names a 404, and stored unasked // it stood in the way of the site's icon, which works (#89). - if let Some(art) = &parsed.image - && !feed::is_image(&ctx.client, art).await - { - tracing::info!(feed = id, art = %art, "the feed's artwork is not an image; trying its site's icon"); - parsed.image = None; - } - if parsed.image.is_none() { - parsed.image = Some(match &parsed.site { - Some(site) => feed::site_icon(&ctx.client, site).await.unwrap_or_default(), - None => String::new(), - }); - } + let art_span = tracing::info_span!("artwork"); + tracing::Instrument::instrument(async { + if let Some(art) = &parsed.image + && stored.image.as_deref() != Some(art.as_str()) + && !feed::is_image(&ctx.client, art).await + { + tracing::info!(feed = id, art = %art, "the feed's artwork is not an image; trying its site's icon"); + parsed.image = None; + } + if parsed.image.is_none() { + parsed.image = Some(match (&stored.image, &parsed.site) { + (Some(known), _) if !force => known.clone(), + (_, Some(site)) => feed::site_icon(&ctx.client, site).await.unwrap_or_default(), + (_, None) => String::new(), + }); + } + }, art_span).await; ctx.db.record_feed( id, &feed_cfg.url, @@ -1311,28 +1317,32 @@ async fn scan_one( // changed nothing however often the feed was scanned. let skipped = ctx.db.skipped_by_filter(id).await?; let mut scan = Scan::default(); - for entry in &parsed.entries { - if ctx.db.record_entry(id, entry).await? { - scan.new_entries += 1; - } - for enc in &entry.enclosures { - let was = if ctx.db.record_enclosure(id, &entry.guid, enc).await? { - None - } else if let Some(reason) = skipped.get(&enc.url) { - Some(reason.as_str()) - } else { - continue; // Settled: queued, downloaded, reaped, or another feed's file. - }; - let now = reject(&ctx.cfg(), feed_cfg, &policy, entry, enc); - if now != was { - match now { - Some(reason) => ctx.db.mark_enclosure(&enc.url, "skipped", Some(reason)).await?, - None => ctx.db.mark_enclosure(&enc.url, "pending", None).await?, + // Its own span: the time a feed spends after its fetch was untraced (#96). + let store = tracing::info_span!("store", items = parsed.entries.len()); + tracing::Instrument::instrument(async { + for entry in &parsed.entries { + if ctx.db.record_entry(id, entry).await? { + scan.new_entries += 1; + } + for enc in &entry.enclosures { + let was = if ctx.db.record_enclosure(id, &entry.guid, enc).await? { + None + } else if let Some(reason) = skipped.get(&enc.url) { + Some(reason.as_str()) + } else { + continue; // Settled: queued, downloaded, reaped, or another feed's file. + }; + let now = reject(&ctx.cfg(), feed_cfg, &policy, entry, enc); + if now != was { + match now { + Some(reason) => ctx.db.mark_enclosure(&enc.url, "skipped", Some(reason)).await?, + None => ctx.db.mark_enclosure(&enc.url, "pending", None).await?, + } } } } - } - + anyhow::Ok(()) + }, store).await?; if scan.new_entries > 0 { ctx.db.rehide(id).await?; // what is new may hold someone's blocked words }