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 <noreply@anthropic.com>

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

src/db.rs

@@ -313,6 +313,7 @@ impl Db {
         Ok(())
     }
 
+    #[tracing::instrument(skip_all)]
     pub async fn feed_summary(&self, feed_id: &str) -> Result<FeedSummary> {
         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<Vec<Pending>> {
         // 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<Vec<Sub>> {
         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<String>)> = 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<std::collections::HashMap<String, String>> {
         self.rows(
             "SELECT url, last_error FROM enclosures

src/main.rs

@@ -993,7 +993,7 @@ async fn fetch(ctx: &Arc<Ctx>, 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<Ctx>, 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<Outcome> {
     // 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
+    // Artwork is looked at when it may have changed: the feed names different artwork from what
-    // someone asked for a refresh, so an icon the site changes or fixes follows it (#80). A miss
+    // is stored, or someone asked for a refresh, so an icon the site changes or fixes still
-    // is stored as "", which the page draws as no art, and which stops the refetch above.
+    // follows it (#80). Looked at on every full read, a feed without validators asked its site
-    // ponytail: a feed without validators is read in full every scan and asks its site each
+    // on every scan: 2 s a scan for lfg.co (#95). A miss is stored as "", which the page draws
-    // time too; keep a checked-at time per feed if that shows up in anyone's logs.
+    // 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
+    let art_span = tracing::info_span!("artwork");
-        && !feed::is_image(&ctx.client, art).await
+    tracing::Instrument::instrument(async {
-    {
+        if let Some(art) = &parsed.image
-        tracing::info!(feed = id, art = %art, "the feed's artwork is not an image; trying its site's icon");
+            && stored.image.as_deref() != Some(art.as_str())
-        parsed.image = None;
+            && !feed::is_image(&ctx.client, art).await
-    }
+        {
-    if parsed.image.is_none() {
+            tracing::info!(feed = id, art = %art, "the feed's artwork is not an image; trying its site's icon");
-        parsed.image = Some(match &parsed.site {
+            parsed.image = None;
-            Some(site) => feed::site_icon(&ctx.client, site).await.unwrap_or_default(),
+        }
-            None => String::new(),
+        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 {
+    // Its own span: the time a feed spends after its fetch was untraced (#96).
-        if ctx.db.record_entry(id, entry).await? {
+    let store = tracing::info_span!("store", items = parsed.entries.len());
-            scan.new_entries += 1;
+    tracing::Instrument::instrument(async {
-        }
+        for entry in &parsed.entries {
-        for enc in &entry.enclosures {
+            if ctx.db.record_entry(id, entry).await? {
-            let was = if ctx.db.record_enclosure(id, &entry.guid, enc).await? {
+                scan.new_entries += 1;
-                None
+            }
-            } else if let Some(reason) = skipped.get(&enc.url) {
+            for enc in &entry.enclosures {
-                Some(reason.as_str())
+                let was = if ctx.db.record_enclosure(id, &entry.guid, enc).await? {
-            } else {
+                    None
-                continue; // Settled: queued, downloaded, reaped, or another feed's file.
+                } else if let Some(reason) = skipped.get(&enc.url) {
-            };
+                    Some(reason.as_str())
-            let now = reject(&ctx.cfg(), feed_cfg, &policy, entry, enc);
+                } else {
-            if now != was {
+                    continue; // Settled: queued, downloaded, reaped, or another feed's file.
-                match now {
+                };
-                    Some(reason) => ctx.db.mark_enclosure(&enc.url, "skipped", Some(reason)).await?,
+                let now = reject(&ctx.cfg(), feed_cfg, &policy, entry, enc);
-                    None => ctx.db.mark_enclosure(&enc.url, "pending", None).await?,
+                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
     }