diff --git a/CHANGELOG.md b/CHANGELOG.md index 734966f3..15f5e219 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -45,6 +45,29 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 died before any of this existed, and no route reaches them that is not the pattern above. `docs/cleanup.md` carries the whole of it. +- **`dl --ls` now tells you when the background cache sweep hit trouble.** The + hourly sweep that keeps your bare clones fresh runs as a detached child with + nothing attached to its output, so everything it ever had to complain about went + straight to `/dev/null`: a fetch that could not reach the remote, a clone deleted + underneath its record, a `git pack-refs` refused by a permissions problem. The + sweep now writes what happened into `metadata.json` beside that repository's + freshness stamp, and `dl --ls` prints it under the table: + + ``` + Last cache sweep of blooop/devlaunch: could not pack the refs it fetched: fatal: unable to create 'packed-refs.lock': Permission denied + ``` + + One note per repository, overwritten on every pass that acts on it, so nothing + accumulates and there is no log to rotate. A pass that goes cleanly clears the + note, so a machine you have fixed stops complaining on its own; a pass that + attempted nothing, because the interval had not elapsed or another `dl` run held + the lock, leaves the last note where it was rather than claiming a sweep it never + ran. `dl --ls --json` carries the same thing as a `lastSweep` object on the rows + whose repository has one, added alongside the existing fields and absent + entirely when there is nothing outstanding. Nothing new is printed on the launch + path, and a `metadata.json` written by an older `dl` reads exactly as it did. + [docs/cleanup.md](docs/cleanup.md) has the detail. + ### Fixed - **Sixty-six citations that pointed at nothing now point at something, and a diff --git a/docs/cleanup.md b/docs/cleanup.md index 7fd09ff0..2f4ebd33 100644 --- a/docs/cleanup.md +++ b/docs/cleanup.md @@ -438,12 +438,28 @@ lands, and the next sweep tries again. Withholding the stamp would make every later pass re-fetch the whole repository forever on account of a representation change that did not come off. -That notice reaches nobody today, and the honest reading of why is that the sweep -runs detached with its output discarded, so every notice it raises goes to a null -descriptor and this is simply the first one that anybody would want to read. What -a refusal costs while it stays unread is bounded: loose refs are one file per ref -rewritten in place rather than appended, so a pack that keeps failing holds the -ref count flat at what one sweep writes instead of growing it. +The notice itself still reaches nobody, and it never will: the sweep runs +detached with its output discarded, so every line it raises goes to a null +descriptor. What reaches somebody is the **record**. A pass that refuses a pack +writes the repository and git's own words into `metadata.json` beside that +repository's freshness stamp, and `dl --ls` prints them under its table: + +``` +Last cache sweep of blooop/devlaunch: could not pack the refs it fetched: fatal: unable to create 'packed-refs.lock': Permission denied +``` + +`dl --ls --json` carries the same thing as a `lastSweep` object on every row +whose repository has one. Three things bound what that costs. The note is +overwritten on every pass that acts on a repository, so a cache holds at most one +per repository and there is no rotation and no second file. A pass that goes +cleanly clears it, so a machine whose permissions have been fixed stops +complaining on its own. And a pass that attempted nothing, because the interval +had not elapsed or another run held the lock, leaves the last note standing +rather than reporting a clean sweep it never ran. + +What a refusal costs while nobody has yet acted on it is bounded too: loose refs +are one file per ref rewritten in place rather than appended, so a pack that keeps +failing holds the ref count flat at what one sweep writes instead of growing it. **Packing does not change what a later prune may delete.** A ref the remote retracts is removed whether it was loose or packed: git rewrites `packed-refs` diff --git a/rust/devlaunch-core/public-api.rest.txt b/rust/devlaunch-core/public-api.rest.txt index d67e4328..b6a07018 100644 --- a/rust/devlaunch-core/public-api.rest.txt +++ b/rust/devlaunch-core/public-api.rest.txt @@ -507,6 +507,40 @@ impl core::fmt::Debug for devlaunch_core::domain::metadata::OsFailure pub fn devlaunch_core::domain::metadata::OsFailure::fmt(&self, &mut core::fmt::Formatter<'_>) -> core::fmt::Result impl core::marker::StructuralPartialEq for devlaunch_core::domain::metadata::OsFailure pub mod devlaunch_core::domain::model +pub enum devlaunch_core::domain::model::SweepTrouble +pub devlaunch_core::domain::model::SweepTrouble::CloneMissing +pub devlaunch_core::domain::model::SweepTrouble::FetchRefused +pub devlaunch_core::domain::model::SweepTrouble::FetchTimedOut +pub devlaunch_core::domain::model::SweepTrouble::NotRecorded +pub devlaunch_core::domain::model::SweepTrouble::RefsNotPacked +impl core::clone::Clone for devlaunch_core::domain::model::SweepTrouble +pub fn devlaunch_core::domain::model::SweepTrouble::clone(&self) -> devlaunch_core::domain::model::SweepTrouble +impl core::cmp::Eq for devlaunch_core::domain::model::SweepTrouble +impl core::cmp::PartialEq for devlaunch_core::domain::model::SweepTrouble +pub fn devlaunch_core::domain::model::SweepTrouble::eq(&self, &devlaunch_core::domain::model::SweepTrouble) -> bool +impl core::fmt::Debug for devlaunch_core::domain::model::SweepTrouble +pub fn devlaunch_core::domain::model::SweepTrouble::fmt(&self, &mut core::fmt::Formatter<'_>) -> core::fmt::Result +impl core::marker::Copy for devlaunch_core::domain::model::SweepTrouble +impl core::marker::StructuralPartialEq for devlaunch_core::domain::model::SweepTrouble +impl serde_core::ser::Serialize for devlaunch_core::domain::model::SweepTrouble +pub fn devlaunch_core::domain::model::SweepTrouble::serialize<__S>(&self, __S) -> core::result::Result<<__S as serde_core::ser::Serializer>::Ok, <__S as serde_core::ser::Serializer>::Error> where __S: serde_core::ser::Serializer +impl<'de> serde_core::de::Deserialize<'de> for devlaunch_core::domain::model::SweepTrouble +pub fn devlaunch_core::domain::model::SweepTrouble::deserialize<__D>(__D) -> core::result::Result::Error> where __D: serde_core::de::Deserializer<'de> +pub struct devlaunch_core::domain::model::SweepNote +pub devlaunch_core::domain::model::SweepNote::said: core::option::Option +pub devlaunch_core::domain::model::SweepNote::trouble: devlaunch_core::domain::model::SweepTrouble +impl core::clone::Clone for devlaunch_core::domain::model::SweepNote +pub fn devlaunch_core::domain::model::SweepNote::clone(&self) -> devlaunch_core::domain::model::SweepNote +impl core::cmp::Eq for devlaunch_core::domain::model::SweepNote +impl core::cmp::PartialEq for devlaunch_core::domain::model::SweepNote +pub fn devlaunch_core::domain::model::SweepNote::eq(&self, &devlaunch_core::domain::model::SweepNote) -> bool +impl core::fmt::Debug for devlaunch_core::domain::model::SweepNote +pub fn devlaunch_core::domain::model::SweepNote::fmt(&self, &mut core::fmt::Formatter<'_>) -> core::fmt::Result +impl core::marker::StructuralPartialEq for devlaunch_core::domain::model::SweepNote +impl serde_core::ser::Serialize for devlaunch_core::domain::model::SweepNote +pub fn devlaunch_core::domain::model::SweepNote::serialize<__S>(&self, __S) -> core::result::Result<<__S as serde_core::ser::Serializer>::Ok, <__S as serde_core::ser::Serializer>::Error> where __S: serde_core::ser::Serializer +impl<'de> serde_core::de::Deserialize<'de> for devlaunch_core::domain::model::SweepNote +pub fn devlaunch_core::domain::model::SweepNote::deserialize<__D>(__D) -> core::result::Result::Error> where __D: serde_core::de::Deserializer<'de> pub struct devlaunch_core::domain::model::WorktreeInfo impl core::clone::Clone for devlaunch_core::domain::model::WorktreeInfo pub fn devlaunch_core::domain::model::WorktreeInfo::clone(&self) -> devlaunch_core::domain::model::WorktreeInfo @@ -1979,6 +2013,20 @@ pub fn devlaunch_core::flows::listing::SourceDescription::eq(&self, &devlaunch_c impl core::fmt::Debug for devlaunch_core::flows::listing::SourceDescription pub fn devlaunch_core::flows::listing::SourceDescription::fmt(&self, &mut core::fmt::Formatter<'_>) -> core::fmt::Result impl core::marker::StructuralPartialEq for devlaunch_core::flows::listing::SourceDescription +pub struct devlaunch_core::flows::listing::SweptRepoNote +pub devlaunch_core::flows::listing::SweptRepoNote::note: devlaunch_core::domain::model::SweepNote +pub devlaunch_core::flows::listing::SweptRepoNote::owner: alloc::string::String +pub devlaunch_core::flows::listing::SweptRepoNote::repo: alloc::string::String +impl devlaunch_core::flows::listing::SweptRepoNote +pub fn devlaunch_core::flows::listing::SweptRepoNote::slug(&self) -> alloc::string::String +impl core::clone::Clone for devlaunch_core::flows::listing::SweptRepoNote +pub fn devlaunch_core::flows::listing::SweptRepoNote::clone(&self) -> devlaunch_core::flows::listing::SweptRepoNote +impl core::cmp::Eq for devlaunch_core::flows::listing::SweptRepoNote +impl core::cmp::PartialEq for devlaunch_core::flows::listing::SweptRepoNote +pub fn devlaunch_core::flows::listing::SweptRepoNote::eq(&self, &devlaunch_core::flows::listing::SweptRepoNote) -> bool +impl core::fmt::Debug for devlaunch_core::flows::listing::SweptRepoNote +pub fn devlaunch_core::flows::listing::SweptRepoNote::fmt(&self, &mut core::fmt::Formatter<'_>) -> core::fmt::Result +impl core::marker::StructuralPartialEq for devlaunch_core::flows::listing::SweptRepoNote pub struct devlaunch_core::flows::listing::TableRow pub devlaunch_core::flows::listing::TableRow::id: alloc::string::String pub devlaunch_core::flows::listing::TableRow::last_used: devlaunch_core::flows::listing::LastUsed @@ -2026,6 +2074,7 @@ pub fn devlaunch_core::flows::listing::enriched_listing(&mut devlaunch_core::flo pub fn devlaunch_core::flows::listing::flatten_repos(&indexmap::map::IndexMap>) -> alloc::vec::Vec pub fn devlaunch_core::flows::listing::head_branch_of(&devlaunch_core::clients::devpod::Workspace, &std::path::Path) -> core::option::Option pub fn devlaunch_core::flows::listing::json_document(&[devlaunch_core::flows::listing::ListedWorkspace]) -> serde_json::value::Value +pub fn devlaunch_core::flows::listing::outstanding_sweep_notes(&devlaunch_core::domain::metadata::MetadataStorage) -> alloc::vec::Vec pub fn devlaunch_core::flows::listing::owner_of(&devlaunch_core::clients::devpod::Workspace, &std::path::Path) -> core::option::Option pub fn devlaunch_core::flows::listing::repo_of(&devlaunch_core::clients::devpod::Workspace, &std::path::Path) -> core::option::Option pub fn devlaunch_core::flows::listing::workspace_table(&mut devlaunch_core::flows::listing::CommandContext<'_>, &std::path::Path, devlaunch_core::flows::listing::Sizes) -> core::result::Result diff --git a/rust/devlaunch-core/src/domain/model.rs b/rust/devlaunch-core/src/domain/model.rs index 450b694b..36c3c592 100644 --- a/rust/devlaunch-core/src/domain/model.rs +++ b/rust/devlaunch-core/src/domain/model.rs @@ -212,6 +212,77 @@ pub(crate) struct BaseRepository { /// §4). Out of reach of `flows`, so a caller with one field to change has /// to say which field, and cannot carry a stale copy of this one along. pub(super) worktrees: Vec, + /// What the last background sweep of this repository had to say — see + /// [`SweepNote`]. + /// + /// Last in the record rather than beside `last_fetched`, which is where it + /// belongs by meaning: the two are written by the same pass, but a key + /// appended is a key every older reader already ignores, where a key + /// inserted moves `worktrees` and rewrites the file for every repository + /// that never had a note. + /// + /// Omitted from the file entirely when there is none, so a clean cache's + /// `metadata.json` is byte for byte the one this build wrote before the + /// field existed. + #[serde(skip_serializing_if = "Option::is_none")] + pub(crate) last_sweep: Option, +} + +/// What one background sweep had to say about one repository. +/// +/// The sweep is a detached child with all three descriptors on `/dev/null` +/// (`ProcessRunner::detach`), so every notice it raises has always gone +/// nowhere. This is the one that survives to be read: `dl --ls` prints it and +/// `dl --ls --json` carries it, which is the whole of devlaunch#480. +/// +/// **Overwritten, never accumulated.** Each pass that actually acts on a +/// repository replaces this outright — a pass that fetched cleanly clears it — +/// so one repository holds at most one note and the record needs no rotation +/// and no second file. A pass that attempted nothing (the interval had not +/// elapsed, another run held the lock, the lock would not open) leaves the last +/// pass's note standing, because clearing it there would report a clean sweep +/// that never ran. +/// +/// **Absent rather than empty when there is nothing to say.** The key is left +/// out of the file, so "the last sweep was clean" is one state, "a note is +/// here" is another, and a stored value this build cannot read is a third — +/// a [`NotRebuilt`], exactly as an unparsable `last_fetched` is. A bare string +/// would have spelled the first two the same way. +#[derive(Debug, Clone, PartialEq, Eq, Serialize, Deserialize)] +pub struct SweepNote { + /// Which of the sweep's troubles this was. + pub trouble: SweepTrouble, + /// The words of whatever refused, verbatim — git's own stderr where git is + /// what refused. + /// + /// `None` where nothing said anything: a fetch killed at the bound and a + /// clone that is not on disk are conditions dl observed rather than + /// sentences anything wrote, and an empty string for them would be a + /// refusal that said nothing dressed up as one that did. + pub said: Option, +} + +/// What went wrong for a sweep, in the arms the sweep itself can tell apart. +/// +/// Not a rendering: the words are the `dl` binary's (#251 §5), and what travels +/// here is which condition it was plus whatever git said about it. Snake case +/// on the wire in both places it appears, because it is a token rather than a +/// sentence — the same way devpod's `Running` is. +#[derive(Debug, Clone, Copy, PartialEq, Eq, Serialize, Deserialize)] +#[serde(rename_all = "snake_case")] +pub enum SweepTrouble { + /// The fetch worked and `git pack-refs --all` would not collapse the loose + /// refs it wrote. The cache is fresh either way; see docs/cleanup.md. + RefsNotPacked, + /// git refused the fetch. + FetchRefused, + /// The fetch ran past the sweep's own time bound and the child was killed. + FetchTimedOut, + /// The record names a bare clone that is not on disk, so there was nothing + /// to fetch into. + CloneMissing, + /// The fetch worked and the freshness stamp could not be written. + NotRecorded, } /// A workspace clone of one branch. @@ -271,6 +342,7 @@ impl BaseRepository { default_branch: RecordedDefaultBranch::Named(DEFAULT_BRANCH.to_owned()), last_fetched: None, worktrees: Vec::new(), + last_sweep: None, } } @@ -286,6 +358,7 @@ impl BaseRepository { default_branch: RecordedDefaultBranch::from_stored(stored.default_branch), last_fetched: read_optional_timestamp(stored.last_fetched)?, worktrees: stored.worktrees, + last_sweep: read_optional_sweep_note(stored.last_sweep)?, }, unknown_fields: stored.unknown.into_keys().collect(), }) @@ -357,6 +430,8 @@ struct StoredRepository { last_fetched: Option, #[serde(default)] worktrees: Vec, + #[serde(default)] + last_sweep: Option, #[serde(flatten)] unknown: BTreeMap, } @@ -406,6 +481,35 @@ fn read_optional_timestamp( } } +/// `last_sweep` as the sweep writes it: absent and null both mean the last sweep +/// left nothing to say, an object is a note, anything else is unreadable. +/// +/// No empty-string arm, where [`read_optional_timestamp`] has one: that arm is +/// bug-compatibility with a Python `last_fetched` this field has no history with, +/// and an empty note that reads as no note is the exact conflation the field was +/// shaped to avoid. +/// +/// A note whose *object* this build cannot read costs the entry, the way an +/// unparsable `last_fetched` does — the load reports it and storage preserves the +/// original before any rewrite. A key inside the note that this build has no +/// field for costs only that key, which is the module's other rule and the reason +/// a newer devlaunch's extra detail cannot take a repository out of the listing. +fn read_optional_sweep_note( + stored: Option, +) -> Result, NotRebuilt> { + match stored { + None | Some(serde_json::Value::Null) => Ok(None), + Some(object @ serde_json::Value::Object(_)) => serde_json::from_value(object) + .map(Some) + .map_err(|error| NotRebuilt { + reason: format!("last_sweep is unreadable: {error}"), + }), + Some(other) => Err(NotRebuilt { + reason: format!("last_sweep is {}", json_kind(&other)), + }), + } +} + /// The JSON type of a value, as data for a report. fn json_kind(value: &serde_json::Value) -> &'static str { match value { @@ -472,6 +576,9 @@ mod tests { 2024, 1, 1, 12, 0, 0, 0, ))), worktrees: vec!["feature-1".to_owned(), "feature-2".to_owned()], + // The golden below is Python's, from before this field existed, and + // it still is: a record with no note writes no key. + last_sweep: None, } } @@ -660,6 +767,109 @@ mod tests { BaseRepository::from_json(stored).expect_err("not rebuilt"); } + // --- the last sweep's note (devlaunch#480) ---------------------------- + + #[test] + fn a_record_written_before_the_field_existed_still_loads_and_says_nothing() { + // Every `metadata.json` on every machine dl has ever run on. The key is not + // there, and "the last sweep left nothing to say" is the right reading of + // that: a record cannot be made unloadable by a field it predates. + let stored = json_of(PYTHON_REPOSITORY); + + let rebuilt = BaseRepository::from_json(stored).expect("rebuilt"); + + assert_eq!(rebuilt.entry.last_sweep, None); + assert!( + rebuilt.unknown_fields.is_empty(), + "an absent key is not an unknown one" + ); + } + + #[test] + fn a_record_with_no_note_writes_no_key_at_all() { + // What keeps the upgrade silent: a cache whose sweeps all went cleanly + // rewrites byte for byte the file this build wrote before the field + // existed, so nothing about `metadata.json` moves for anybody who has no + // trouble to report. + let written = serde_json::to_string(&python_repository()).expect("serializable"); + + assert!( + !written.contains("last_sweep"), + "absent, not null: {written}" + ); + } + + #[test] + fn a_note_round_trips_through_the_record() { + let mut repository = python_repository(); + repository.last_sweep = Some(SweepNote { + trouble: SweepTrouble::RefsNotPacked, + said: Some("fatal: unable to create 'packed-refs.lock'".to_owned()), + }); + + let written = serde_json::to_string(&repository).expect("serializable"); + let rebuilt = BaseRepository::from_json(json_of(&written)).expect("rebuilt"); + + assert!( + written.contains(r#""last_sweep":{"trouble":"refs_not_packed","said":"#), + "the tokens are the record's own spelling: {written}" + ); + assert_eq!(rebuilt.entry, repository); + } + + #[test] + fn a_null_note_reads_as_no_note_rather_than_as_damage() { + let stored = json_of( + r#"{"owner":"o","repo":"r","remote_url":"u","local_path":"/p","last_sweep":null}"#, + ); + + let rebuilt = BaseRepository::from_json(stored).expect("rebuilt"); + + assert_eq!(rebuilt.entry.last_sweep, None); + } + + #[test] + fn a_note_this_build_cannot_read_costs_the_entry_the_way_a_bad_stamp_does() { + // Absence, a note, and a stored value that is not one are three states and + // not two: the third goes the way `last_fetched` already goes — the entry is + // reported unusable and storage preserves the original before any rewrite — + // rather than being quietly read as "nothing to say". + for stored in [ + r#"{"owner":"o","repo":"r","remote_url":"u","local_path":"/p","last_sweep":""}"#, + r#"{"owner":"o","repo":"r","remote_url":"u","local_path":"/p","last_sweep":3}"#, + r#"{"owner":"o","repo":"r","remote_url":"u","local_path":"/p", + "last_sweep":{"trouble":"a_trouble_this_build_has_no_arm_for"}}"#, + ] { + let failed = BaseRepository::from_json(json_of(stored)).expect_err("not rebuilt"); + assert!( + failed.reason.contains("last_sweep"), + "the reason names the field: {:?}", + failed.reason + ); + } + } + + #[test] + fn a_key_inside_a_note_that_this_build_has_no_field_for_costs_only_that_key() { + // The module's other rule, and the reason a newer devlaunch's extra detail + // cannot take a repository out of somebody's listing. The note itself is + // overwritten wholesale by the next sweep anyway. + let stored = json_of( + r#"{"owner":"o","repo":"r","remote_url":"u","local_path":"/p", + "last_sweep":{"trouble":"fetch_timed_out","said":null,"after":"30s"}}"#, + ); + + let rebuilt = BaseRepository::from_json(stored).expect("rebuilt"); + + assert_eq!( + rebuilt.entry.last_sweep, + Some(SweepNote { + trouble: SweepTrouble::FetchTimedOut, + said: None, + }) + ); + } + #[test] fn a_repository_key_this_build_does_not_declare_is_reported_and_dropped() { let stored = json_of( diff --git a/rust/devlaunch-core/src/flows/lifecycle.rs b/rust/devlaunch-core/src/flows/lifecycle.rs index 5914d4e4..a728caf5 100644 --- a/rust/devlaunch-core/src/flows/lifecycle.rs +++ b/rust/devlaunch-core/src/flows/lifecycle.rs @@ -79,7 +79,7 @@ use crate::clients::docker; use crate::clients::git::Git; use crate::domain::locks::{self, LockError}; use crate::domain::metadata::{self, MetadataStorage, RecordUpdate, WorktreeFilter}; -use crate::domain::model::WorktreeInfo; +use crate::domain::model::{SweepNote, SweepTrouble, WorktreeInfo}; use crate::domain::workspace_state::{self, CouldNotTell, Losses, NonEmpty, Unsaved}; use crate::flows::completion_cache; use crate::flows::disk_usage::{self, DiskUsage}; @@ -88,8 +88,8 @@ use crate::flows::listing::{ self, ClonePathResolver, CommandContext, WorkspaceOwnership, json_as_python_writes_it, }; use crate::flows::repo_manager::{ - BACKGROUND_FETCH_TIMEOUT, CacheNotice, Fetched, LazyFetchError, Refusal, Removal, - RepositoryManager, present, remove_tree_as_far_as_it_goes, + BACKGROUND_FETCH_TIMEOUT, CacheNotice, FetchRepoError, Fetched, LazyFetchError, Refusal, + Removal, RepositoryManager, present, remove_tree_as_far_as_it_goes, }; use crate::flows::workspace_clone::{RemoveWorkspaceError, Removed, WorkspaceCloneManager}; use crate::notices::{Notices, Wrapped}; @@ -502,7 +502,15 @@ pub fn sweep_repo_fetches( &mut cache_notices, ) }); + // Read off the same two values the arm below is built from, before either + // is moved: the note and the counted arm have to be two readings of one + // pass, which is the mistake `disk` and `unsaved` each made in turn in the + // listing. + let left_behind = last_sweep_note(&swept, &cache_notices); extend_with_cache(&mut report.notices, cache_notices); + if let LastSweep::Wrote(note) = left_behind { + record_sweep_note(storage, &owner, &repo, note, &mut report.notices); + } report.repos.push(match swept { Err(refusal) => SweptRepo::LockUnavailable { owner, @@ -518,6 +526,113 @@ pub fn sweep_repo_fetches( report } +/// What one pass of the sweep leaves in one repository's record. +/// +/// Two arms rather than a bare `Option`, because there are three +/// outcomes and only two of them are notes: a pass can leave a note, clear the +/// last one, or have no standing to touch the field at all. Collapsing the last +/// two would have a contended repository report a clean sweep that never ran. +#[derive(Debug, Clone, PartialEq, Eq)] +enum LastSweep { + /// The pass acted on the repository. `None` clears whatever the pass before + /// it left, which is what makes a cache that has been fixed stop complaining. + Wrote(Option), + /// Nothing was attempted — the interval had not elapsed, another dl run held + /// the lock, or the lock would not open — so the last pass's note stands. + Untouched, +} + +/// What the record should say about one repository after this pass. +/// +/// The pack refusal is read out of the notices the fetch raised rather than out of +/// its return value, because a refused pack is deliberately *not* a failed fetch +/// (docs/cleanup.md): `fetch_repo` returns `Ok` and says so in a +/// [`CacheNotice::RefsNotPacked`], which until now went to the detached child's +/// null stderr and nowhere else. +fn last_sweep_note( + swept: &Result>, LockError>, + raised: &[CacheNotice], +) -> LastSweep { + match swept { + Ok(Some(Ok(Fetched::Fetched))) => LastSweep::Wrote(refs_not_packed(raised)), + // The repository left the store between the listing above and the fetch, + // so there is no record to annotate. `update_repository` would answer + // `Absent`; saying so here keeps the write off a path with nothing to + // write to. + Ok(Some(Err(LazyFetchError::NotInMetadata { .. }))) => LastSweep::Untouched, + Ok(Some(Err(LazyFetchError::Fetch(refused)))) => { + LastSweep::Wrote(Some(fetch_trouble(refused))) + } + Ok(Some(Ok(Fetched::Skipped))) | Ok(None) | Err(_) => LastSweep::Untouched, + } +} + +/// The pack refusal this pass raised, if it raised one. +fn refs_not_packed(raised: &[CacheNotice]) -> Option { + raised.iter().find_map(|notice| match notice { + CacheNotice::RefsNotPacked { reason, .. } => Some(SweepNote { + trouble: SweepTrouble::RefsNotPacked, + said: Some(reason.clone()), + }), + _ => None, + }) +} + +/// A failed fetch as the record carries it. +/// +/// Every arm keeps git's words where git is what refused, and `None` where nothing +/// spoke — a child killed at the bound and a directory that is not there are +/// conditions dl observed, and inventing a sentence for them here would be core +/// writing English (#251 §5). Which condition it was is the arm, and the `dl` +/// binary spells it. +fn fetch_trouble(refused: &FetchRepoError) -> SweepNote { + match refused { + FetchRepoError::NoLocalClone { .. } => SweepNote { + trouble: SweepTrouble::CloneMissing, + said: None, + }, + FetchRepoError::TimedOut { .. } => SweepNote { + trouble: SweepTrouble::FetchTimedOut, + said: None, + }, + FetchRepoError::Refused { reason } => SweepNote { + trouble: SweepTrouble::FetchRefused, + said: Some(reason.clone()), + }, + FetchRepoError::NotRecorded(_) => SweepNote { + trouble: SweepTrouble::NotRecorded, + said: None, + }, + } +} + +/// Put the note in the record, outside the repo lock the fetch held. +/// +/// Outside on purpose: the metadata lock is its own, `update_repository` reloads +/// the record under it and moves one field, and holding the repository's lock +/// across that write would put every sibling launch behind a second file lock for +/// a field no launch reads. +fn record_sweep_note( + storage: &mut MetadataStorage, + owner: &str, + repo: &str, + note: Option, + notices: &mut dyn Notices, +) { + match storage.update_repository(owner, repo, |recorded| recorded.last_sweep = note) { + // `Absent` is the record removed by another run while this pass was in it. + // Nothing was written, which is right — a store that inserted would undo + // that delete — and it is not news about the sweep. + Ok((RecordUpdate::Applied | RecordUpdate::Absent, store_notices)) => { + extend_with_store(notices, store_notices); + } + // The sweep never complains, and here it could not if it wanted to: a note + // that cannot be written is the very condition it would have reported, and + // there is nowhere left to put it. The next pass writes the same note. + Err(_nowhere_to_put_it) => {} + } +} + // =========================================================================== // which workspace, and what state // =========================================================================== @@ -6024,6 +6139,15 @@ mod tests { .clone() } + /// What the record says the last sweep of this repository had to say. + fn last_sweep(&self, owner: &str, repo: &str) -> Option { + self.storage + .get_repository(owner, repo) + .expect("a record") + .last_sweep + .clone() + } + fn fetches(&self) -> Vec { self.fake .calls() @@ -6276,6 +6400,182 @@ mod tests { assert_eq!(cache.fetches().len(), 0); } + // ----------------------------------------------------------------------- + // what the sweep leaves in the record (devlaunch#480) + // ----------------------------------------------------------------------- + + #[test] + fn a_pack_that_refused_is_left_in_the_record_in_gits_own_words() { + // The notice this reads was already raised (#470) and already went nowhere: + // the sweep is a detached child with all three descriptors on /dev/null. The + // record is where it survives to be read. + let mut cache = a_sweeping_cache(); + cache.recorded(OWNER, REPO, Some(hours_ago(2))); + cache.fake.script( + ["git", "pack-refs"], + Response::failed( + 1, + "fatal: unable to create 'packed-refs.lock': Permission denied\n", + ), + ); + let manager = RepositoryManager::new(&cache.repos_dir, Git::new(&cache.fake)); + + let report = sweep_repo_fetches(&manager, &mut cache.storage); + + assert_eq!( + report.repos, + [SweptRepo::Fetched { + owner: OWNER.to_owned(), + repo: REPO.to_owned() + }], + "a pack that refused is not a fetch that failed" + ); + assert_eq!( + cache.last_sweep(OWNER, REPO), + Some(SweepNote { + trouble: SweepTrouble::RefsNotPacked, + said: Some( + "fatal: unable to create 'packed-refs.lock': Permission denied".to_owned() + ), + }) + ); + assert!( + cache.last_fetched(OWNER, REPO).is_some(), + "the stamp is about the fetch, and the fetch happened" + ); + } + + #[test] + fn a_sweep_that_went_cleanly_takes_the_last_ones_note_away() { + // Overwritten, not accumulated: one note per repository is what makes the + // record able to hold this at all, and a cache whose trouble has been fixed + // has to stop complaining without anybody clearing it by hand. + let mut cache = a_sweeping_cache(); + cache.recorded(OWNER, REPO, Some(hours_ago(2))); + let (_written, _) = cache + .storage + .update_repository(OWNER, REPO, |recorded| { + recorded.last_sweep = Some(SweepNote { + trouble: SweepTrouble::RefsNotPacked, + said: Some("something that no longer happens".to_owned()), + }); + }) + .expect("a note from the pass before"); + let manager = RepositoryManager::new(&cache.repos_dir, Git::new(&cache.fake)); + + sweep_repo_fetches(&manager, &mut cache.storage); + + assert_eq!(cache.last_sweep(OWNER, REPO), None); + } + + #[test] + fn a_pass_that_attempted_nothing_leaves_the_last_note_standing() { + // Three ways to attempt nothing and one rule for all of them: silence about + // a repository this pass never touched must not read as a clean sweep of it. + // Here the interval has not elapsed; contended and lock-unavailable take the + // same arm. + let mut cache = a_sweeping_cache(); + cache.recorded(OWNER, REPO, Some(Timestamp::now())); + let outstanding = SweepNote { + trouble: SweepTrouble::FetchRefused, + said: Some("fatal: no route to host".to_owned()), + }; + let (_written, _) = cache + .storage + .update_repository(OWNER, REPO, |recorded| { + recorded.last_sweep = Some(outstanding.clone()); + }) + .expect("a note from the pass before"); + let manager = RepositoryManager::new(&cache.repos_dir, Git::new(&cache.fake)); + + let report = sweep_repo_fetches(&manager, &mut cache.storage); + + assert_eq!( + report.repos, + [SweptRepo::NotDue { + owner: OWNER.to_owned(), + repo: REPO.to_owned() + }] + ); + assert_eq!(cache.last_sweep(OWNER, REPO), Some(outstanding)); + } + + #[test] + fn a_fetch_that_failed_leaves_what_git_said_about_it() { + let mut cache = a_sweeping_cache(); + cache.recorded(OWNER, REPO, Some(hours_ago(2))); + cache.fake.script( + ["git", "fetch"], + Response::failed(128, "fatal: no route to host\n"), + ); + let manager = RepositoryManager::new(&cache.repos_dir, Git::new(&cache.fake)); + + sweep_repo_fetches(&manager, &mut cache.storage); + + assert_eq!( + cache.last_sweep(OWNER, REPO), + Some(SweepNote { + trouble: SweepTrouble::FetchRefused, + said: Some("fatal: no route to host".to_owned()), + }) + ); + } + + #[test] + fn a_fetch_killed_at_the_bound_says_so_and_quotes_nobody() { + // Nothing spoke: the child was killed by dl, so `said` is None rather than + // an empty string standing in for words that were never written. + let mut cache = a_sweeping_cache(); + cache.recorded(OWNER, REPO, Some(hours_ago(2))); + cache.fake.script(["git", "fetch"], Response::TimedOut); + let manager = RepositoryManager::new(&cache.repos_dir, Git::new(&cache.fake)); + + sweep_repo_fetches(&manager, &mut cache.storage); + + assert_eq!( + cache.last_sweep(OWNER, REPO), + Some(SweepNote { + trouble: SweepTrouble::FetchTimedOut, + said: None, + }) + ); + } + + #[test] + fn each_repository_gets_its_own_note_out_of_the_one_pass() { + // The sweep walks a whole cache in one detached pass, so a note that landed + // on the wrong record would be worse than none: it would name a repository + // that is fine and clear the one that is not. Two repositories, two + // different troubles, one pass. + let mut cache = a_sweeping_cache(); + cache.recorded(OWNER, "first", Some(hours_ago(2))); + let gone = cache.recorded(OWNER, "second", Some(hours_ago(2))); + std::fs::remove_dir_all(&gone).expect("the second clone is deleted under the record"); + cache.fake.script( + ["git", "pack-refs"], + Response::failed(1, "fatal: refusing to pack\n"), + ); + let manager = RepositoryManager::new(&cache.repos_dir, Git::new(&cache.fake)); + + sweep_repo_fetches(&manager, &mut cache.storage); + + assert_eq!( + cache.last_sweep(OWNER, "first"), + Some(SweepNote { + trouble: SweepTrouble::RefsNotPacked, + said: Some("fatal: refusing to pack".to_owned()), + }) + ); + assert_eq!( + cache.last_sweep(OWNER, "second"), + Some(SweepNote { + trouble: SweepTrouble::CloneMissing, + said: None, + }), + "the repository whose clone is gone never reached a pack to refuse" + ); + } + // ======================================================================= // which workspace a triple is (devlaunch#88, #145) // ======================================================================= diff --git a/rust/devlaunch-core/src/flows/listing.rs b/rust/devlaunch-core/src/flows/listing.rs index 4126f6b3..af29a8f6 100644 --- a/rust/devlaunch-core/src/flows/listing.rs +++ b/rust/devlaunch-core/src/flows/listing.rs @@ -64,7 +64,7 @@ use crate::clients::devpod::{ }; use crate::clients::git::{Git, GitAnswer}; use crate::domain::metadata::MetadataStorage; -use crate::domain::model::WorktreeInfo; +use crate::domain::model::{SweepNote, WorktreeInfo}; use crate::domain::workspace_state::{self, CloneState, CouldNotTell, NonEmpty, Unsaved}; use crate::flows::disk_usage::{self, DiskUsage}; use crate::runner::Runner; @@ -903,6 +903,16 @@ pub struct ListedWorkspace { /// checkout to find one. pub(crate) clone: Option, pub(crate) disk: DiskField, + /// What the last background sweep of this row's repository had to say, from + /// the record. `None` covers both the row that is not dl's and the repository + /// whose last sweep was clean, which are one thing to a reader of this row: + /// there is no complaint outstanding about the cache behind it. + /// + /// The note is per *repository* and the row is per *workspace*, so several + /// rows can carry the same note and a repository with no workspace has no row + /// to carry it at all. [`outstanding_sweep_notes`] is the reading that misses + /// none of them, and is what `dl --ls` prints under the table. + pub(crate) sweep: Option, } /// The enriched listing: one row per workspace devpod lists, in devpod's order. @@ -956,12 +966,66 @@ fn enriched_row( recorded: record.map(Recorded::of), } }); + // Off the recorded triple and not off the source, so the note a row carries is + // about the repository dl really cloned for it. A workspace with no record has + // no repository to ask about, which is the same `None` a clean sweep leaves. + let sweep = clone + .as_ref() + .and_then(|clone| clone.recorded.as_ref()) + .and_then(|recorded| view.storage.get_repository(&recorded.owner, &recorded.repo)) + .and_then(|repository| repository.last_sweep.clone()); ListedWorkspace { id: workspace.id.clone(), last_used: workspace.last_used.clone(), state: container_state(runner, &workspace.id), clone, disk: DiskField::of(sizes, measurable.as_deref()), + sweep, + } +} + +/// Every repository whose last background sweep left something to say, in the +/// order the record holds them. +/// +/// The reading behind the line `dl --ls` prints under its table. Per repository +/// rather than per row, because that is what the note is: a repository with three +/// workspaces has one note and a repository with none still has one, and a listing +/// that only ever spoke through rows would say the first three times and the +/// second never. +/// +/// binary surface — not part of the frozen wf API (#251 §7) +pub fn outstanding_sweep_notes(storage: &MetadataStorage) -> Vec { + storage + .list_repositories() + .into_iter() + .filter_map(|repository| { + repository.last_sweep.clone().map(|note| SweptRepoNote { + owner: repository.owner.clone(), + repo: repository.repo.clone(), + note, + }) + }) + .collect() +} + +/// One repository's outstanding sweep note, with the repository it is about. +/// +/// The sweep walks a whole cache in one detached pass, so a note that did not say +/// which repository it was about would be unactionable — the same reason +/// [`CacheNotice::RefsNotPacked`](crate::flows::repo_manager::CacheNotice) names +/// one. +#[derive(Clone, Debug, PartialEq, Eq)] +// binary surface — not part of the frozen wf API (#251 §7) +pub struct SweptRepoNote { + pub owner: String, + pub repo: String, + pub note: SweepNote, +} + +impl SweptRepoNote { + /// The `owner/repo` slug a line names it by. + pub fn slug(&self) -> String { + format!("{}/{}", self.owner, self.repo) } } @@ -1098,9 +1162,26 @@ fn json_row(row: &ListedWorkspace) -> serde_json::Value { DiskField::NothingOfOurs => insert(&mut value, "disk", serde_json::Value::Null), DiskField::Freed(usage) => insert(&mut value, "disk", disk_usage::usage_as_json(usage)), } + // Appended, and absent unless there is a note. Both halves are the contract + // (#251 §7): `wf` parses this document, so every key it already reads keeps + // its name, its spelling and its place, and a cache with nothing outstanding + // produces the byte-for-byte document it produced before this field existed. + // Absent rather than null for the reason `disk` is absent unless asked — + // there is then one thing the key's presence means and only one. + if let Some(note) = &row.sweep { + insert(&mut value, "lastSweep", sweep_as_json(note)); + } value } +/// One sweep note as the wire carries it: which trouble, and what git said. +/// +/// `said` is `null` rather than absent where nothing spoke, because that is a fact +/// about the refusal and every reader of this key already has the note itself. +fn sweep_as_json(note: &SweepNote) -> serde_json::Value { + serde_json::to_value(note).unwrap_or_else(|_| serde_json::json!({})) +} + fn insert(object: &mut serde_json::Value, key: &str, field: serde_json::Value) { if let Some(map) = object.as_object_mut() { map.insert(key.to_owned(), field); @@ -2302,6 +2383,138 @@ mod tests { fn id(&self, which: &str) -> &str { &self.ids[which] } + + /// Record `blooop/` — which the two dl-made rows are clones of, when + /// it is `demo` — with whatever the last sweep of it left behind. + fn given_a_swept_repository(&mut self, repo: &str, note: Option) { + let mut repository = crate::domain::model::BaseRepository::new( + "blooop", + repo, + &format!("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/blooop/{repo}.git"), + self.cache.join("repos").join("blooop").join(repo), + ); + repository.last_sweep = note; + self.storage + .add_repository(repository) + .expect("a repository record"); + } + } + + /// The rows of a document, by workspace id. + fn rows_by_id(document: &serde_json::Value) -> BTreeMap { + document + .as_array() + .expect("an array") + .iter() + .map(|row| (row["id"].as_str().expect("an id").to_owned(), row.clone())) + .collect() + } + + #[test] + fn a_row_carries_the_note_the_last_sweep_left_on_its_repository() { + // The other half of devlaunch#480: the sweep writes the note into the + // record from a detached child nobody can see, and this is where `wf` and + // anybody reading `--ls --json` can see it. + let mut scene = Scene::build(); + scene.given_a_swept_repository( + "demo", + Some(SweepNote { + trouble: crate::domain::model::SweepTrouble::RefsNotPacked, + said: Some( + "fatal: unable to create 'packed-refs.lock': Permission denied".to_owned(), + ), + }), + ); + + let document = json_document(&scene.rows(Sizes::Skip)); + let rows = rows_by_id(&document); + + let expected = serde_json::json!({ + "trouble": "refs_not_packed", + "said": "fatal: unable to create 'packed-refs.lock': Permission denied", + }); + assert_eq!(rows[scene.id("clean")]["lastSweep"], expected); + assert_eq!( + rows[scene.id("dirty")]["lastSweep"], + expected, + "one repository, two workspaces, one note" + ); + // A dl clone with no record has no repository to ask about, and neither has + // a workspace dl did not make. Absent, not null: the key means one thing. + for row in [scene.id("unrecorded"), "someone-elses", "from-an-image"] { + assert!( + rows[row].get("lastSweep").is_none(), + "{row} carries a note about a repository it has none of: {}", + rows[row] + ); + } + } + + #[test] + fn a_cache_with_nothing_outstanding_writes_the_document_it_always_wrote() { + // The field is additive on the wire `wf` parses (#251 §7): a repository + // whose last sweep went cleanly adds no key at all, so the document below + // is byte for byte the one pinned in the golden above. + let mut scene = Scene::build(); + scene.given_a_swept_repository("demo", None); + + let document = json_document(&scene.rows(Sizes::Skip)); + + assert!(!document.to_string().contains("lastSweep"), "{document}"); + assert!(outstanding_sweep_notes(&scene.storage).is_empty()); + } + + #[test] + fn a_note_with_nothing_quoted_still_says_which_trouble_it_was() { + // `said: null` rather than an absent key or an empty string: a fetch killed + // at the bound is a refusal nothing wrote words for, and the reader still + // has to be told which refusal it was. + let mut scene = Scene::build(); + scene.given_a_swept_repository( + "demo", + Some(SweepNote { + trouble: crate::domain::model::SweepTrouble::FetchTimedOut, + said: None, + }), + ); + + let document = json_document(&scene.rows(Sizes::Skip)); + + assert_eq!( + rows_by_id(&document)[scene.id("clean")]["lastSweep"], + serde_json::json!({ "trouble": "fetch_timed_out", "said": null }) + ); + } + + #[test] + fn the_notes_under_the_table_are_per_repository_and_reach_the_ones_with_no_workspace() { + // Why the table's line is not a column: a note is about a bare clone, and a + // repository nobody has a workspace for still has one to report. A reading + // that only ever spoke through rows would never say this one. + let mut scene = Scene::build(); + scene.given_a_swept_repository("demo", None); + scene.given_a_swept_repository( + "no-workspace-of-its-own", + Some(SweepNote { + trouble: crate::domain::model::SweepTrouble::CloneMissing, + said: None, + }), + ); + + let outstanding = outstanding_sweep_notes(&scene.storage); + + assert_eq!(outstanding.len(), 1, "{outstanding:?}"); + assert_eq!(outstanding[0].slug(), "blooop/no-workspace-of-its-own"); + assert_eq!( + outstanding[0].note.trouble, + crate::domain::model::SweepTrouble::CloneMissing + ); + assert!( + !json_document(&scene.rows(Sizes::Skip)) + .to_string() + .contains("lastSweep"), + "no row is a clone of it, so no row says anything about it" + ); } #[test] diff --git a/rust/dl/src/commands.rs b/rust/dl/src/commands.rs index dc47493f..01bcfadc 100644 --- a/rust/dl/src/commands.rs +++ b/rust/dl/src/commands.rs @@ -197,17 +197,40 @@ fn render_list( } } -/// The human table. Reads devpod and nothing else — no config, no records, no -/// migration, which is what keeps a listing one round trip. +/// The human table, and whatever the last background sweep left in the record. +/// +/// Still one devpod round trip, still no config and no cache migration — the one +/// thing it reads besides devpod is `metadata.json`, and only for the sweep notes +/// under the table. That read is the point of devlaunch#480: the sweep is a +/// detached child whose stderr is `/dev/null`, so the record is the only place a +/// complaint of its can be left, and `--ls` is the only surface anybody reads. fn render_table(context: &mut CommandContext<'_>, cache: &Path, sizes: Sizes) -> Ending { - match listing::workspace_table(context, cache, sizes) { - Err(refused) => refuse_listing(&refused), - Ok(table) => { - for line in render::table_lines(&table, sizes) { - println!("{line}"); - } - Ending::Done - } + let table = match listing::workspace_table(context, cache, sizes) { + Err(refused) => return refuse_listing(&refused), + Ok(table) => table, + }; + for line in render::table_lines(&table, sizes) { + println!("{line}"); + } + say_sweep_notes(); + Ending::Done +} + +/// The lines under the table, on stderr where every other notice goes. +/// +/// A record that will not open costs the notes and nothing else: `--ls` answers +/// out of devpod, and a listing that refused because a note could not be fetched +/// would be the tail wagging the dog. The load's own notices are said, so a +/// `metadata.json` this run quarantines is never moved aside in silence. +fn say_sweep_notes() { + let Ok((storage, notices)) = session::open_storage() else { + return; + }; + for line in render::metadata_notices(¬ices) { + eprintln!("{line}"); + } + for line in render::sweep_notes(&listing::outstanding_sweep_notes(&storage)) { + eprintln!("{line}"); } } diff --git a/rust/dl/src/render.rs b/rust/dl/src/render.rs index 23c9f189..bda90964 100644 --- a/rust/dl/src/render.rs +++ b/rust/dl/src/render.rs @@ -17,6 +17,7 @@ use devlaunch_core::clients::ssh::{NotRun as SshNotRun, UnsafeRequest}; use devlaunch_core::domain::config; use devlaunch_core::domain::locks::LockError; use devlaunch_core::domain::metadata; +use devlaunch_core::domain::model::SweepTrouble; use devlaunch_core::domain::workspace_id::{NamePart, UnsafeName}; use devlaunch_core::domain::workspace_state::NonEmpty; use devlaunch_core::domain::xdg; @@ -35,7 +36,9 @@ use devlaunch_core::flows::lifecycle::{ PruneReport, PurgeOutcome, PurgePlan, PurgeStep, ReconcilePlan, RemovalRefused, SweepOccasion, Unlocatable, VolumeRefusal, VolumesKeptBecause, }; -use devlaunch_core::flows::listing::{LastUsed, SizeCell, Sizes, TableRow, WorkspaceTable}; +use devlaunch_core::flows::listing::{ + LastUsed, SizeCell, Sizes, SweptRepoNote, TableRow, WorkspaceTable, +}; use devlaunch_core::flows::migration::{Listing, MigrationReport}; use devlaunch_core::flows::provision::{BundleFailed, FailureLevel, ProvisionEvent}; use devlaunch_core::flows::repo_manager::{ @@ -137,6 +140,49 @@ pub(crate) fn table_lines(table: &WorkspaceTable, sizes: Sizes) -> Vec { lines } +/// The lines `dl --ls` writes under its table for the repositories whose last +/// background sweep left something to say. +/// +/// The sweep runs detached with all three descriptors on `/dev/null`, so until +/// now every complaint it had went nowhere (devlaunch#480). It writes them into +/// the record instead, and this is the reading: one line per repository, said +/// once, under the table a person was already looking at. +/// +/// Per repository and not per row, because a note is about a bare clone rather +/// than about a workspace — several rows can share one, and a repository with no +/// workspace at all still has one to report. +pub(crate) fn sweep_notes(notes: &[SweptRepoNote]) -> Vec { + notes + .iter() + .map(|outstanding| { + let mut line = format!( + "Last cache sweep of {}: {}", + outstanding.slug(), + sweep_trouble(outstanding.note.trouble) + ); + // Only where something spoke. A trailing `: ` over nothing would read + // as a refusal whose words were lost, which is a different fact. + if let Some(said) = &outstanding.note.said { + line.push_str(": "); + line.push_str(said); + } + line + }) + .collect() +} + +/// What one sweep trouble reads as. The words are the binary's (#251 §5); what +/// travels in the record is the arm. +fn sweep_trouble(trouble: SweepTrouble) -> &'static str { + match trouble { + SweepTrouble::RefsNotPacked => "could not pack the refs it fetched", + SweepTrouble::FetchRefused => "could not fetch", + SweepTrouble::FetchTimedOut => "ran out of time fetching", + SweepTrouble::CloneMissing => "found no bare clone to fetch into", + SweepTrouble::NotRecorded => "fetched, and could not write the record", + } +} + /// One row's `SIZE` cell. /// /// Total over both facts: whether the column exists at all (the table's), and @@ -3618,6 +3664,61 @@ mod tests { ); } + #[test] + fn the_last_sweeps_note_reads_as_one_line_naming_the_repository() { + // The same refusal as the notice above, a run later. The notice went to the + // detached child's null stderr; this is what somebody actually reads, so it + // has to name the repository on its own — nothing around it does. + use devlaunch_core::domain::model::SweepNote; + + let note = |trouble, said: Option<&str>| SweptRepoNote { + owner: "blooop".to_owned(), + repo: "devlaunch".to_owned(), + note: SweepNote { + trouble, + said: said.map(str::to_owned), + }, + }; + + assert_eq!( + sweep_notes(&[note( + SweepTrouble::RefsNotPacked, + Some("fatal: unable to create 'packed-refs.lock': Permission denied"), + )]), + [ + "Last cache sweep of blooop/devlaunch: could not pack the refs it fetched: \ + fatal: unable to create 'packed-refs.lock': Permission denied" + ] + ); + // Nothing spoke, so nothing is quoted: a line ending in a bare colon would + // read as a refusal whose words were lost. + assert_eq!( + sweep_notes(&[note(SweepTrouble::FetchTimedOut, None)]), + ["Last cache sweep of blooop/devlaunch: ran out of time fetching"] + ); + assert!(sweep_notes(&[]).is_empty(), "a clean cache says nothing"); + } + + #[test] + fn every_sweep_trouble_has_words_of_its_own() { + // Five arms, five sentences, and no two the same: which condition it was is + // the whole of what the record carries when git said nothing. + let words = [ + SweepTrouble::RefsNotPacked, + SweepTrouble::FetchRefused, + SweepTrouble::FetchTimedOut, + SweepTrouble::CloneMissing, + SweepTrouble::NotRecorded, + ] + .map(sweep_trouble); + let mut sorted = words.to_vec(); + sorted.sort_unstable(); + sorted.dedup(); + + assert_eq!(sorted.len(), words.len(), "{words:?}"); + assert!(words.iter().all(|line| !line.is_empty())); + } + #[test] fn the_branch_decision_reads_as_the_four_lines_python_logged() { // `worktree/branch_manager.py` 49/56/62/67. Which of the four happened is an diff --git a/rust/dl/src/session.rs b/rust/dl/src/session.rs index 97545471..7a8ab98f 100644 --- a/rust/dl/src/session.rs +++ b/rust/dl/src/session.rs @@ -151,6 +151,24 @@ pub(crate) struct Records<'r> { pub(crate) migration_refused: Option, } +/// Open `metadata.json` and nothing else: no config, no clone manager, no cache +/// migration. +/// +/// What a command reaches for when it has one field of the record to read and no +/// business writing anything. [`open_records`] is still the construction point for +/// everything that mutates — this is the same load without the three things that +/// make that call expensive and consequential, and it is deliberately not a way +/// around it: a caller that wants a record's *clone* wants the migration, because +/// the directory it is about may not have been renamed yet. +/// +/// The load is not a pure read. A `metadata.json` that cannot be parsed is +/// quarantined by it, which is exactly what every other command does to the same +/// file, and the notices come back so a caller can say so rather than letting a +/// record be moved aside in silence. +pub(crate) fn open_storage() -> Result<(MetadataStorage, Vec), StartupError> { + Ok(MetadataStorage::open(MetadataStorage::default_path()?)?) +} + /// Open dl's records, migrating the cache if it has not been migrated yet. /// /// The one construction point, so nothing can reach a stale clone path before the @@ -159,7 +177,7 @@ pub(crate) struct Records<'r> { pub(crate) fn open_records<'r>(runner: &'r dyn Runner) -> Result, StartupError> { let (config, retired_keys) = worktree_config()?; let cache_dir = cache_dir()?; - let (mut storage, notices) = MetadataStorage::open(MetadataStorage::default_path()?)?; + let (mut storage, notices) = open_storage()?; // The report is kept and rendered by the caller. Python's `migrate_cache` // announces inside itself (migration.py `_announce`); core renders no English // (#251), so the report travels up and the binary writes the sentences — the diff --git a/rust/dl/tests/lifecycle.rs b/rust/dl/tests/lifecycle.rs index ddb01b98..14e3237b 100644 --- a/rust/dl/tests/lifecycle.rs +++ b/rust/dl/tests/lifecycle.rs @@ -265,6 +265,62 @@ impl World { } } + /// Put a `git` first on the run's PATH that refuses `pack-refs` and is the + /// real git for everything else. + /// + /// The one failure in this file that has to come from a *subprocess* rather + /// than from a fixture flag: what the sweep records is git's own words, and a + /// world that supplied them itself would be pinning the test's spelling of a + /// refusal instead of git's. + fn given_a_git_that_will_not_pack_refs(&self) { + let real = ["/usr/bin/git", "/bin/git"] + .into_iter() + .map(Path::new) + .find(|candidate| candidate.exists()) + .expect("git is installed"); + let shim = self.path("bin/git"); + std::fs::write( + &shim, + format!( + "#!/bin/sh\n\ + for argument in \"$@\"; do\n\ + \x20 if [ \"$argument\" = pack-refs ]; then\n\ + \x20 echo \"{REFUSED_PACK}\" >&2\n\ + \x20 exit 1\n\ + \x20 fi\n\ + done\n\ + exec {} \"$@\"\n", + real.display() + ), + ) + .expect("a git that will not pack"); + use std::os::unix::fs::PermissionsExt as _; + std::fs::set_permissions(&shim, std::fs::Permissions::from_mode(0o755)) + .expect("an executable fake"); + } + + /// Wind every repository's fetch clock back to before the interval. + /// + /// The sweep is interval-gated on `last_fetched`, which the pass before it just + /// moved, so a second pass in the same test would find nothing due and step over + /// the very repository the test is about. + fn restale_the_fetch_clock(&self) { + let mut record: serde_json::Value = + serde_json::from_str(&self.read("cache/devlaunch/metadata.json")).expect("a record"); + for repository in record["repositories"] + .as_object_mut() + .expect("the repositories") + .values_mut() + { + repository["last_fetched"] = serde_json::json!("2020-01-01T00:00:00"); + } + std::fs::write( + self.path("cache/devlaunch/metadata.json"), + record.to_string(), + ) + .expect("a record with a stale clock"); + } + /// The whole cache, contents included, as a listing two runs can be compared by. /// /// The instrument for a command that must leave the cache **alone** — one @@ -1552,6 +1608,92 @@ fn the_child_migrates_the_cache_like_every_other_run() { ); } +/// What the fake git writes when it refuses to pack, and what the record must +/// come to hold: git's words, not dl's. +const REFUSED_PACK: &str = "fatal: unable to create 'packed-refs.lock': Permission denied"; + +#[test] +fn a_pack_the_sweep_could_not_do_is_readable_when_somebody_next_lists() { + // devlaunch#480, end to end and in that order: the refusal is raised inside a + // detached child whose three descriptors are `/dev/null`, so the only way it + // reaches anybody is the record. Before this, no test could tell the notice + // being raised from the notice being read, because nothing read it. + let world = World::base(); + world.given_a_git_that_will_not_pack_refs(); + + world.dl(&["--update-cache", "--force"]).exited(0); + + let record = world.read("cache/devlaunch/metadata.json"); + assert!( + record.contains("\"refs_not_packed\"") && record.contains(REFUSED_PACK), + "the sweep's refusal is not in the record: {record}" + ); + + let listed = world.dl(&["--ls"]); + listed.exited(0); + assert!( + listed.err.contains(&format!( + "Last cache sweep of blooop/devlaunch: could not pack the refs it fetched: \ + {REFUSED_PACK}" + )), + "--ls did not read the note back: {}", + listed.err + ); + + let document = world.dl(&["--ls", "--json"]); + document.exited(0); + let rows: serde_json::Value = serde_json::from_str(&document.out).expect("the wire document"); + let notes: Vec<&serde_json::Value> = rows + .as_array() + .expect("an array") + .iter() + .filter_map(|row| row.get("lastSweep")) + .collect(); + assert!( + !notes.is_empty() + && notes.iter().all(|note| { + note["trouble"] == "refs_not_packed" && note["said"] == REFUSED_PACK + }), + "the wire document does not carry the note verbatim: {}", + document.out + ); +} + +#[test] +fn a_later_sweep_that_went_fine_takes_the_complaint_back_out() { + // Overwritten on every pass that acts, which is what lets the record hold this + // at all: no rotation, no second file, and a cache whose trouble has been fixed + // stops complaining without anybody clearing it by hand. + let world = World::base(); + world.given_a_git_that_will_not_pack_refs(); + world.dl(&["--update-cache", "--force"]).exited(0); + assert!( + world + .read("cache/devlaunch/metadata.json") + .contains("refs_not_packed"), + "the first pass left nothing to clear" + ); + + std::fs::remove_file(world.path("bin/git")).expect("the real git is back on PATH"); + world.restale_the_fetch_clock(); + world.dl(&["--update-cache", "--force"]).exited(0); + + assert!( + !world + .read("cache/devlaunch/metadata.json") + .contains("last_sweep"), + "a clean pass left the last one's complaint standing: {}", + world.read("cache/devlaunch/metadata.json") + ); + let listed = world.dl(&["--ls"]); + listed.exited(0); + assert!( + !listed.err.contains("Last cache sweep"), + "--ls is still reading a note nothing is complaining about: {}", + listed.err + ); +} + #[test] fn a_fresh_cache_stops_the_child_before_it_sweeps() { // The TTL is re-checked in the child as well as in the parent that spawned it: