prune: match real log names, order retention by time, spare fresh locks

Log retention only matched 'deb-*' logs, so source-build ('build-*')
and placeholder ('pkh-*') logs accumulated forever, and the 'keep the
newest' sort was lexicographic on names that sort by package/version
first, so arbitrary logs were kept. All three log shapes are matched
now and retention orders by the timestamp embedded in the name (mtime
fallback). Stale-lockfile pruning no longer deletes lockfiles younger
than 24h: a fresh <tarball>.lock is the mutual-exclusion signal of a
concurrent download and deleting it could corrupt the shared tarball
cache.

src/prune.rs

@@ -10,13 +10,18 @@
 //!   bind-mounted `/proc` and overlay filesystems, so they require careful
 //!   unmounting before they can be removed.
 //! - **Cached chroot tarballs** (`~/.cache/pkh/*-buildd.tar.xz`) and their
-//!   **stale download lockfiles** (`~/.cache/pkh/*.lock`).
+//!   **stale download lockfiles** (`~/.cache/pkh/*.lock` untouched for longer
+//!   than [`LOCK_STALE_AFTER`]; younger lockfiles may belong to a concurrent
+//!   `pkh` run and are left alone).
 //! - **The apt keyring cache directories** (`pkh-keyrings` and the per-uid
 //!   `pkh-keyrings-<uid>` under the system temp directory), used by
 //!   mmdebstrap runs.
-//! - **Build logs** (`~/.cache/pkh/logs/deb-*.log`) written by `pkh deb`. By
+//! - **Build logs** under `~/.cache/pkh/logs/` written by `pkh deb`:
-//!   default only logs beyond a small retention window (the newest
+//!   `deb-<package>-<version>-<timestamp>.log` (binary builds),
-//!   [`KEEP_LOGS`] are kept) are removed; pass [`PruneOptions::all`] to remove
+//!   `build-<package>-<version>-<timestamp>.log` (source builds) and the
+//!   pre-identity placeholder `pkh-<timestamp>.log`. By default only logs
+//!   beyond a small retention window (the newest [`KEEP_LOGS`] by embedded
+//!   timestamp are kept) are removed; pass [`PruneOptions::all`] to remove
 //!   them all.
 //!
 //! The [`prune()`] function discovers and removes all of the above. By
@@ -28,7 +33,9 @@
 use std::fs;
 use std::path::{Path, PathBuf};
 use std::process::Command;
+use std::time::{Duration, SystemTime};
 
+use chrono::NaiveDateTime;
 use directories::ProjectDirs;
 
 /// Options controlling the prune operation.
@@ -63,6 +70,14 @@ impl PruneReport {
 /// Number of newest build logs kept when `--all` is not passed.
 pub(crate) const KEEP_LOGS: usize = 10;
 
+/// Lockfiles younger than this are not pruned: a recently touched
+/// `<tarball>.lock` may belong to a concurrent `pkh` run, whose chroot
+/// tarball download uses the lockfile's mere existence as a mutual-exclusion
+/// signal (see `deb::ephemeral`). Deleting such a lockfile mid-download would
+/// let two builds corrupt the shared tarball cache. Only lockfiles untouched
+/// for at least this long are considered stale.
+const LOCK_STALE_AFTER: Duration = Duration::from_secs(24 * 60 * 60);
+
 /// One discovered artifact that prune can act on.
 #[derive(Debug, Clone)]
 enum Artifact {
@@ -140,6 +155,68 @@ fn is_residual_temp_dir(name: &str) -> bool {
     }
 }
 
+/// Check whether a file name is a pkh build log, i.e. it ends in `.log` and
+/// starts with one of the prefixes used by `pkh deb` logging: `deb-` (binary
+/// builds), `build-` (source builds) or `pkh-` (the pre-identity placeholder
+/// log that is renamed once the build identity is known).
+fn is_log_file_name(name: &str) -> bool {
+    name.ends_with(".log")
+        && (name.starts_with("deb-") || name.starts_with("build-") || name.starts_with("pkh-"))
+}
+
+/// Length of the `YYYYMMDDTHHMMSS` UTC timestamp embedded in log file names.
+const LOG_TIMESTAMP_LEN: usize = 15;
+
+/// Parse the UTC timestamp embedded in a build log file name.
+///
+/// Log names embed the timestamp as their final dash-separated component
+/// (e.g. `deb-pkg-1.0-20260101T000000.log`, `build-src-1.0-20260101T000000.log`,
+/// `pkh-20260101T000000.log`). Returns `None` when the name carries no
+/// parseable timestamp.
+fn embedded_log_timestamp(path: &Path) -> Option<SystemTime> {
+    let name = path.file_name()?.to_str()?;
+    let stem = name.strip_suffix(".log")?;
+    let candidate = stem.rsplit_once('-')?.1;
+    if candidate.len() != LOG_TIMESTAMP_LEN {
+        return None;
+    }
+    let ts = NaiveDateTime::parse_from_str(candidate, "%Y%m%dT%H%M%S").ok()?;
+    Some(ts.and_utc().into())
+}
+
+/// Recency of a build log, used to order logs for retention: later values are
+/// more recent.
+///
+/// The timestamp embedded in the file name is authoritative. When the name
+/// carries no parseable timestamp the file's modification time is used
+/// instead, and finally the Unix epoch, so that undateable logs sort as the
+/// oldest ones.
+fn log_recency(path: &Path) -> SystemTime {
+    if let Some(ts) = embedded_log_timestamp(path) {
+        return ts;
+    }
+    fs::metadata(path)
+        .and_then(|m| m.modified())
+        .unwrap_or(SystemTime::UNIX_EPOCH)
+}
+
+/// Check whether a lockfile is safe to prune, i.e. it has not been modified
+/// for at least [`LOCK_STALE_AFTER`].
+///
+/// A freshly touched lockfile may belong to a live concurrent `pkh` run, so
+/// it must be left alone. If the modification time cannot be read the lock is
+/// treated as ancient and pruned (best-effort cleanup of an unreadable
+/// leftover); a modification time in the future (clock skew) counts as fresh.
+fn is_stale_lock(path: &Path) -> bool {
+    let mtime = fs::metadata(path)
+        .and_then(|m| m.modified())
+        .unwrap_or(SystemTime::UNIX_EPOCH);
+    match mtime.elapsed() {
+        Ok(age) => age >= LOCK_STALE_AFTER,
+        Err(_) => false,
+    }
+}
+
 /// Unescape the octal escape sequences used in `/proc/mounts` mount points
 /// (e.g. `\040` for space, `\011` for tab, `\012` for newline, `\134` for
 /// backslash).
@@ -217,7 +294,11 @@ fn discover_artifacts(temp_dir: &Path, cache_dir: Option<&Path>) -> Vec<Artifact
             let path = entry.path();
             let name = entry.file_name().to_string_lossy().into_owned();
             if name.ends_with(".lock") {
-                artifacts.push(Artifact::LockFile(path));
+                // Only stale lockfiles are prune-able; a fresh one may belong
+                // to a live concurrent pkh run (see [`is_stale_lock`]).
+                if is_stale_lock(&path) {
+                    artifacts.push(Artifact::LockFile(path));
+                }
             } else if name.ends_with("-buildd.tar.xz") {
                 artifacts.push(Artifact::Tarball(path));
             }
@@ -231,7 +312,7 @@ fn discover_artifacts(temp_dir: &Path, cache_dir: Option<&Path>) -> Vec<Artifact
             for entry in entries.flatten() {
                 let path = entry.path();
                 let name = entry.file_name().to_string_lossy().into_owned();
-                if path.is_file() && name.starts_with("deb-") && name.ends_with(".log") {
+                if path.is_file() && is_log_file_name(&name) {
                     artifacts.push(Artifact::LogFile(path));
                 }
             }
@@ -243,8 +324,12 @@ fn discover_artifacts(temp_dir: &Path, cache_dir: Option<&Path>) -> Vec<Artifact
 
 /// Compute the set of build log paths that should be removed for the given
 /// options: all of them with `--all`, otherwise every log except the
-/// [`KEEP_LOGS`] newest ones (filenames embed timestamps, so lexicographic
+/// [`KEEP_LOGS`] newest ones.
-/// order is chronological).
+///
+/// Recency is the timestamp embedded in each log's file name (falling back to
+/// the file modification time when the name cannot be parsed; see
+/// [`log_recency()`]). Log names sort by package and version first, so plain
+/// lexicographic order is *not* chronological and must not be used here.
 fn removable_logs(artifacts: &[Artifact], all: bool) -> std::collections::HashSet<&Path> {
     let mut logs: Vec<&Path> = artifacts
         .iter()
@@ -253,7 +338,7 @@ fn removable_logs(artifacts: &[Artifact], all: bool) -> std::collections::HashSe
             _ => None,
         })
         .collect();
-    logs.sort_unstable();
+    logs.sort_by_key(|p| log_recency(p));
 
     if all {
         return logs.into_iter().collect();
@@ -411,6 +496,18 @@ mod tests {
     use std::fs;
     use tempfile::tempdir;
 
+    /// Set a file's modification time (test helper).
+    fn set_mtime(path: &Path, mtime: SystemTime) {
+        let f = fs::OpenOptions::new().write(true).open(path).unwrap();
+        f.set_times(std::fs::FileTimes::new().set_modified(mtime))
+            .unwrap();
+    }
+
+    /// A modification time safely older than [`LOCK_STALE_AFTER`].
+    fn old_mtime() -> SystemTime {
+        SystemTime::now() - LOCK_STALE_AFTER - Duration::from_secs(3600)
+    }
+
     #[test]
     fn test_is_residual_temp_dir() {
         assert!(is_residual_temp_dir("pkh-1700000000"));
@@ -446,6 +543,68 @@ mod tests {
         assert!(!is_keyring_dir_name("pkh-1000"));
     }
 
+    #[test]
+    fn test_is_log_file_name() {
+        // The three naming shapes produced by ui/deb.rs.
+        assert!(is_log_file_name("deb-hello-1.0-20260101T000000.log"));
+        assert!(is_log_file_name("build-src-1.0-20260101T000000.log"));
+        assert!(is_log_file_name("pkh-20260101T000000.log"));
+
+        // Everything else is not.
+        assert!(!is_log_file_name("deb-hello-1.0-20260101T000000.log.gz"));
+        assert!(!is_log_file_name("not-a-build.txt"));
+        assert!(!is_log_file_name("deb.txt"));
+        assert!(!is_log_file_name("logs.txt"));
+        assert!(!is_log_file_name("deb-"));
+        assert!(!is_log_file_name("other-thing.log"));
+    }
+
+    #[test]
+    fn test_log_recency_orders_by_embedded_timestamp() {
+        // The embedded timestamp decides, even when it disagrees with
+        // lexicographic order (zzz sorts after aaa).
+        let old = Path::new("/logs/deb-zzz-1.0-20200101T000000.log");
+        let new = Path::new("/logs/deb-aaa-2.0-20260101T000000.log");
+        assert!(log_recency(old) < log_recency(new));
+
+        // All three prefixes participate in the same timeline.
+        let build = Path::new("/logs/build-src-3.0-20230101T000000.log");
+        let placeholder = Path::new("/logs/pkh-20250101T000000.log");
+        assert!(log_recency(old) < log_recency(build));
+        assert!(log_recency(build) < log_recency(placeholder));
+        assert!(log_recency(placeholder) < log_recency(new));
+    }
+
+    #[test]
+    fn test_log_recency_falls_back_to_mtime() {
+        let temp = tempdir().unwrap();
+        // No parseable timestamp in the name, so the mtime decides.
+        let path = temp.path().join("deb-weird-name.log");
+        fs::write(&path, "log").unwrap();
+        let mtime = SystemTime::UNIX_EPOCH + Duration::from_secs(1_700_000_000);
+        set_mtime(&path, mtime);
+        assert_eq!(log_recency(&path), mtime);
+
+        // A missing file with an unparseable name sorts as the oldest.
+        assert_eq!(
+            log_recency(&PathBuf::from("/logs/deb-nope-nope.log")),
+            SystemTime::UNIX_EPOCH
+        );
+    }
+
+    #[test]
+    fn test_is_stale_lock() {
+        let temp = tempdir().unwrap();
+        let fresh = temp.path().join("fresh.tar.lock");
+        let stale = temp.path().join("stale.tar.lock");
+        fs::write(&fresh, "lock").unwrap();
+        fs::write(&stale, "lock").unwrap();
+        set_mtime(&stale, old_mtime());
+
+        assert!(!is_stale_lock(&fresh));
+        assert!(is_stale_lock(&stale));
+    }
+
     #[test]
     fn test_unescape_mountpath() {
         assert_eq!(unescape_mountpath("/tmp/simple"), "/tmp/simple");
@@ -497,13 +656,19 @@ none /tmp/other proc rw 0 0
         // Cache entries.
         fs::write(cache_path.join("noble-buildd.tar.xz"), "tarball").unwrap();
         fs::write(cache_path.join("noble-amd64-buildd.tar.xz"), "tarball").unwrap();
+        // Only a stale lockfile is discovered; a fresh one could belong to a
+        // live concurrent run and must be ignored.
         fs::write(cache_path.join("noble-buildd.tar.lock"), "lock").unwrap();
+        set_mtime(&cache_path.join("noble-buildd.tar.lock"), old_mtime());
+        fs::write(cache_path.join("noble-fresh.tar.lock"), "lock").unwrap();
         fs::write(cache_path.join("stray.txt"), "ignore me").unwrap();
 
-        // Build logs.
+        // Build logs: binary, source, and the pre-identity placeholder.
         let logs_dir = cache_path.join("logs");
         fs::create_dir_all(&logs_dir).unwrap();
-        fs::write(logs_dir.join("deb-hello-20260101T000000.log"), "log").unwrap();
+        fs::write(logs_dir.join("deb-hello-1.0-20260101T000000.log"), "log").unwrap();
+        fs::write(logs_dir.join("build-src-1.0-20260101T000000.log"), "log").unwrap();
+        fs::write(logs_dir.join("pkh-20260101T000000.log"), "log").unwrap();
         fs::write(logs_dir.join("not-a-build.txt"), "ignore me").unwrap();
 
         let artifacts = discover_artifacts(temp_path, Some(cache_path));
@@ -526,7 +691,7 @@ none /tmp/other proc rw 0 0
         assert_eq!(keyring_dirs, 2);
         assert_eq!(locks, 1);
         assert_eq!(tarballs, 2);
-        assert_eq!(logs, 1);
+        assert_eq!(logs, 3);
     }
 
     #[test]
@@ -537,14 +702,19 @@ none /tmp/other proc rw 0 0
         let logs_dir = cache_path.join("logs");
         fs::create_dir_all(&logs_dir).unwrap();
 
-        // Create KEEP_LOGS + 3 logs; the 3 oldest should be pruned by default
+        // Create KEEP_LOGS + 3 logs across all naming shapes; the 3 oldest
+        // (by embedded timestamp) should be pruned by default.
         let total = KEEP_LOGS + 3;
+        let mut names = Vec::new();
         for i in 0..total {
-            fs::write(
+            let ts = format!("20260101T{:06}", i);
-                logs_dir.join(format!("deb-pkg-20260101T{:06}.log", i)),
+            let name = match i % 3 {
-                "log",
+                0 => format!("deb-pkg-1.0-{ts}.log"),
-            )
+                1 => format!("build-src-2.0-{ts}.log"),
-            .unwrap();
+                _ => format!("pkh-{ts}.log"),
+            };
+            fs::write(logs_dir.join(&name), "log").unwrap();
+            names.push(name);
         }
 
         let report = prune_in(
@@ -557,12 +727,18 @@ none /tmp/other proc rw 0 0
         )
         .unwrap();
 
-        let removed_logs = report
+        let mut removed_logs: Vec<String> = report
             .removed
             .iter()
             .filter(|p| p.starts_with(&logs_dir))
-            .count();
+            .map(|p| p.file_name().unwrap().to_string_lossy().into_owned())
-        assert_eq!(removed_logs, 3);
+            .collect();
+        removed_logs.sort();
+
+        // Exactly the three oldest logs (i = 0, 1, 2) were removed.
+        let mut expected: Vec<String> = names[..3].to_vec();
+        expected.sort();
+        assert_eq!(removed_logs, expected);
 
         let remaining = fs::read_dir(&logs_dir).unwrap().count();
         assert_eq!(remaining, KEEP_LOGS);
@@ -586,6 +762,68 @@ none /tmp/other proc rw 0 0
         assert_eq!(fs::read_dir(&logs_dir).unwrap().count(), 0);
     }
 
+    #[test]
+    fn test_prune_log_retention_orders_by_timestamp_not_name() {
+        let temp = tempdir().unwrap();
+        let cache = tempdir().unwrap();
+        let cache_path = cache.path();
+        let logs_dir = cache_path.join("logs");
+        fs::create_dir_all(&logs_dir).unwrap();
+
+        // KEEP_LOGS new logs whose names sort lexicographically FIRST
+        // (package "aaa"), and older logs whose names sort LAST ("zzz" and a
+        // pkh- placeholder). Retention must follow the embedded timestamps:
+        // the aaa logs are kept and the lexicographically-later old logs are
+        // pruned, the opposite of what name ordering would do.
+        for i in 0..KEEP_LOGS {
+            fs::write(
+                logs_dir.join(format!("deb-aaa-1.0-20210101T{:06}.log", i)),
+                "log",
+            )
+            .unwrap();
+        }
+        let old_names = [
+            "deb-zzz-2.0-20200101T000000.log".to_string(),
+            "deb-zzz-2.0-20200101T000001.log".to_string(),
+            "build-zzz-3.0-20200101T000000.log".to_string(),
+            "pkh-20200101T000000.log".to_string(),
+        ];
+        for name in &old_names {
+            fs::write(logs_dir.join(name), "log").unwrap();
+        }
+
+        let report = prune_in(
+            temp.path(),
+            Some(cache_path),
+            PruneOptions {
+                dry_run: false,
+                all: false,
+            },
+        )
+        .unwrap();
+
+        let removed_logs: Vec<String> = report
+            .removed
+            .iter()
+            .filter(|p| p.starts_with(&logs_dir))
+            .map(|p| p.file_name().unwrap().to_string_lossy().into_owned())
+            .collect();
+        let mut removed_sorted = removed_logs.clone();
+        removed_sorted.sort();
+        let mut expected = old_names.clone();
+        expected.sort();
+        assert_eq!(removed_sorted, expected);
+
+        for i in 0..KEEP_LOGS {
+            assert!(
+                logs_dir
+                    .join(format!("deb-aaa-1.0-20210101T{:06}.log", i))
+                    .exists()
+            );
+        }
+        assert_eq!(fs::read_dir(&logs_dir).unwrap().count(), KEEP_LOGS);
+    }
+
     #[test]
     fn test_prune_dry_run_keeps_artifacts() {
         let temp = tempdir().unwrap();
@@ -598,7 +836,11 @@ none /tmp/other proc rw 0 0
         fs::create_dir_all(temp_path.join("pkh-keyrings")).unwrap();
         fs::create_dir_all(temp_path.join("pkh-keyrings-1000")).unwrap();
         fs::write(cache_path.join("noble-buildd.tar.xz"), "tarball").unwrap();
+        // A stale lockfile is reported; a fresh one may belong to a live
+        // concurrent run and is left out entirely.
         fs::write(cache_path.join("noble-buildd.tar.lock"), "lock").unwrap();
+        set_mtime(&cache_path.join("noble-buildd.tar.lock"), old_mtime());
+        fs::write(cache_path.join("noble-live.tar.lock"), "lock").unwrap();
 
         let report = prune_in(
             temp_path,
@@ -632,6 +874,13 @@ none /tmp/other proc rw 0 0
                 .iter()
                 .any(|p| p == &cache_path.join("noble-buildd.tar.lock"))
         );
+        // The fresh lockfile is not reported and survives the dry run.
+        assert!(
+            !report
+                .removed
+                .iter()
+                .any(|p| p == &cache_path.join("noble-live.tar.lock"))
+        );
         // Tarballs require --all, so not reported here.
         assert!(
             !report
@@ -646,6 +895,7 @@ none /tmp/other proc rw 0 0
         assert!(temp_path.join("pkh-keyrings-1000").exists());
         assert!(cache_path.join("noble-buildd.tar.xz").exists());
         assert!(cache_path.join("noble-buildd.tar.lock").exists());
+        assert!(cache_path.join("noble-live.tar.lock").exists());
     }
 
     #[test]
@@ -661,6 +911,8 @@ none /tmp/other proc rw 0 0
         fs::create_dir_all(temp_path.join("pkh-keyrings")).unwrap();
         fs::create_dir_all(temp_path.join("pkh-keyrings-1000")).unwrap();
         fs::write(cache_path.join("noble-buildd.tar.lock"), "lock").unwrap();
+        set_mtime(&cache_path.join("noble-buildd.tar.lock"), old_mtime());
+        fs::write(cache_path.join("noble-fresh.tar.lock"), "lock").unwrap();
         fs::write(cache_path.join("noble-buildd.tar.xz"), "tarball").unwrap();
 
         let report = prune_in(
@@ -696,6 +948,8 @@ none /tmp/other proc rw 0 0
         assert!(!temp_path.join("pkh-keyrings").exists());
         assert!(!temp_path.join("pkh-keyrings-1000").exists());
         assert!(!cache_path.join("noble-buildd.tar.lock").exists());
+        // The fresh lockfile may belong to a live run and is preserved.
+        assert!(cache_path.join("noble-fresh.tar.lock").exists());
         // Tarball is preserved when --all is not set.
         assert!(cache_path.join("noble-buildd.tar.xz").exists());
     }
@@ -709,6 +963,7 @@ none /tmp/other proc rw 0 0
         fs::write(cache_path.join("noble-buildd.tar.xz"), "tarball").unwrap();
         fs::write(cache_path.join("noble-amd64-buildd.tar.xz"), "tarball").unwrap();
         fs::write(cache_path.join("noble-buildd.tar.lock"), "lock").unwrap();
+        set_mtime(&cache_path.join("noble-buildd.tar.lock"), old_mtime());
 
         let report = prune_in(
             temp.path(),
@@ -744,6 +999,54 @@ none /tmp/other proc rw 0 0
         assert!(!cache_path.join("noble-buildd.tar.lock").exists());
     }
 
+    #[test]
+    fn test_prune_keeps_fresh_lockfile_removes_stale_one() {
+        // The chroot tarball download uses the lockfile's existence as a
+        // mutual-exclusion signal, so a lockfile fresh enough to belong to a
+        // live concurrent pkh run must survive pruning.
+        let temp = tempdir().unwrap();
+        let cache = tempdir().unwrap();
+        let cache_path = cache.path();
+
+        let fresh = cache_path.join("noble-live.tar.lock");
+        let stale = cache_path.join("noble-abandoned.tar.lock");
+        fs::write(&fresh, "lock").unwrap();
+        fs::write(&stale, "lock").unwrap();
+        set_mtime(&stale, old_mtime());
+
+        let report = prune_in(
+            temp.path(),
+            Some(cache_path),
+            PruneOptions {
+                dry_run: false,
+                all: false,
+            },
+        )
+        .unwrap();
+
+        assert!(report.removed.iter().any(|p| p == &stale));
+        assert!(!report.removed.iter().any(|p| p == &fresh));
+        assert!(fresh.exists());
+        assert!(!stale.exists());
+
+        // Dry-run reports the same: only the stale lockfile.
+        fs::write(&stale, "lock").unwrap();
+        set_mtime(&stale, old_mtime());
+        let report = prune_in(
+            temp.path(),
+            Some(cache_path),
+            PruneOptions {
+                dry_run: true,
+                all: false,
+            },
+        )
+        .unwrap();
+        assert!(report.removed.iter().any(|p| p == &stale));
+        assert!(!report.removed.iter().any(|p| p == &fresh));
+        assert!(fresh.exists());
+        assert!(stale.exists());
+    }
+
     #[test]
     fn test_prune_removes_user_writable_temp_dirs() {
         // Residual build dirs created by the tests are user-writable, so the