diff --git a/src/prune.rs b/src/prune.rs index 91d72b3..6c86ced 100644 --- a/src/prune.rs +++ b/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-` under the system temp directory), used by //! mmdebstrap runs. -//! - **Build logs** (`~/.cache/pkh/logs/deb-*.log`) written by `pkh deb`. By -//! default only logs beyond a small retention window (the newest -//! [`KEEP_LOGS`] are kept) are removed; pass [`PruneOptions::all`] to remove +//! - **Build logs** under `~/.cache/pkh/logs/` written by `pkh deb`: +//! `deb---.log` (binary builds), +//! `build---.log` (source builds) and the +//! pre-identity placeholder `pkh-.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 +/// `.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 { + 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) -> Vec) -> Vec 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( - logs_dir.join(format!("deb-pkg-20260101T{:06}.log", i)), - "log", - ) - .unwrap(); + let ts = format!("20260101T{:06}", i); + let name = match i % 3 { + 0 => format!("deb-pkg-1.0-{ts}.log"), + 1 => format!("build-src-2.0-{ts}.log"), + _ => 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 = report .removed .iter() .filter(|p| p.starts_with(&logs_dir)) - .count(); - assert_eq!(removed_logs, 3); + .map(|p| p.file_name().unwrap().to_string_lossy().into_owned()) + .collect(); + removed_logs.sort(); + + // Exactly the three oldest logs (i = 0, 1, 2) were removed. + let mut expected: Vec = 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 = 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