From 175d4e8792e01b3105bf952b4bb9ca0692c74a85 Mon Sep 17 00:00:00 2001 From: wshallwshall Date: Tue, 18 Aug 2026 11:15:24 -0500 Subject: [PATCH] fix(worktree): read the reflog by content, so a gc stops vetoing every worktree Signal 2 took the newest MTIME of seven metadata files, one of which is logs/HEAD. A `git gc` rewrites every reflog in place while appending nothing, so it moves all of them at once. MEASURED 2026-08-18 on this repository. A gc ran at 08:15:34-08:16:05 -- packed-refs rewritten at 08:15:34, the packs at 08:16:02-08:16:05 -- and 48 of 50 worktree logs/HEAD files came out carrying the IDENTICAL mtime 2026-08-18 08:15:42, to the second, while their contents were days older: one worktree's last entry is 2026-08-14 12:55:35, four days before its own mtime. The pruner then skipped 11 of 14 candidates as "recently active" and removed nothing. With 50 worktrees and 9 live sessions producing loose objects, gc is frequent enough that the veto can sit permanently on -- and a veto that always fires carries no more information than one that never fires, which is the failure class ADR 0158 names. So logs/HEAD is now read by CONTENT: the epoch on its last entry, stamped by the operation that appended it, which nothing can move without appending. The other six files keep their mtimes; gc does not touch them. Two states that are not the same fact no longer act alike. A non-empty reflog that will not parse FALLS BACK to the mtime -- a shape this does not recognise is a reason to keep vetoing, never a reason to stop, because idle is the direction that removes a worktree. A zero-length reflog contributes NOTHING and is not an error: every entry has expired, so it holds no evidence either way and the six mtimes still speak. Reading its mtime there would reinstate the bug on the oldest worktrees in the repository, which are the ones most likely to be prunable. Re-measured over the 15 live siblings: the old probe reported 2.98 h for twelve of them (all the same gc stamp); the real ages span 11.80 h to 184.65 h. Six cross the 36 h window. ZERO worktrees move the other way -- the change can only ever reveal an age, never manufacture one. Of those six, two stay skipped on their own merits (one dirty, one carrying untracked files), which is the point: this restores the other checks' ability to speak, it does not overrule them. Four tests, and each is killed by a different mutation. Reinstating the mtime read kills the gc test and the empty-reflog test; removing the reflog read kills the fresh-entry test and the unparseable test. The fresh-entry test is the one that stops this from being a deletion of signal 2: every mtime says 100 h idle and only the content says otherwise, so a script that had merely stopped reading logs/HEAD would prune a worktree somebody is working in. The fixture ages the reflog's entries now, not just its mtime -- and restores the mtime after rewriting, because the write itself moved it to now, which is the gc's own signature. Without that, _backdate silently stopped setting the field it appears to set; found by mutating the script and watching the CONTROL line fail instead of the assertion under test. Co-Authored-By: Claude Opus 5 --- scripts/worktree/prune-merged.ps1 | 83 +++++++++++++-- tests/test_worktree_prune_merged.py | 158 +++++++++++++++++++++++++++- 2 files changed, 228 insertions(+), 13 deletions(-) diff --git a/scripts/worktree/prune-merged.ps1 b/scripts/worktree/prune-merged.ps1 index a3aa64a9..db20c41f 100644 --- a/scripts/worktree/prune-merged.ps1 +++ b/scripts/worktree/prune-merged.ps1 @@ -48,11 +48,15 @@ fences it on pid + process start time. Only LIVE / UNVERIFIED / UNREADABLE veto, for the veto-only reason above. A session in a NESTED worktree vetoes its ancestor too. 2. RECENT ACTIVITY (-IdleHours, default 36). Newest mtime of the worktree's PRIVATE git metadata - (index, HEAD, logs/HEAD, ...). This is the signal that does NOT depend on a recorded cwd, and - it is what covers the fence's biggest blind spot -- so it is not a nicety, it is the load- - bearing one for the class of worktree this tool actually prunes. If it cannot be read, that is - a veto too. Confirm a specific worktree past this veto with -Name ; -Name never - overrides signal 1, a nested worktree, or a lock. + (index, HEAD, ORIG_HEAD, FETCH_HEAD, COMMIT_EDITMSG, MERGE_MSG) crossed with the timestamp of + the LAST ENTRY IN logs/HEAD -- the reflog is read by CONTENT, never by mtime, because a + `git gc` rewrites every reflog in place and moved all 48 of them to one identical mtime on + 2026-08-18, vetoing the whole repository at once (Get-ReflogLastEntry has the measurement). + This is the signal that does NOT depend on a recorded cwd, and it is what covers the fence's + biggest blind spot -- so it is not a nicety, it is the load-bearing one for the class of + worktree this tool actually prunes. If it cannot be read, that is a veto too. Confirm a + specific worktree past this veto with -Name ; -Name never overrides signal 1, a nested + worktree, or a lock. WHAT THE FENCE CANNOT SEE (printed on every run, because a fence believed to be wider than it is is worse than no fence): @@ -65,8 +69,13 @@ * a cwd recorded as a UNC (\\host\C$\...) or 8.3 short path -- the match is a normalised string compare, and neither spelling normalises to the worktree's own path; * a session that never registered; - * a session that only Writes/Edits files and runs no git command: it touches none of the seven - metadata files, so signal 2 goes quiet on it as well. + * a session that only Writes/Edits files and runs no git command: it touches none of the metadata + signal 2 reads, so signal 2 goes quiet on it as well; + * a session whose ONLY git command rewrites the reflog without appending to it -- in practice + `git gc` or `git reflog expire`. Signal 2 stopped counting that on 2026-08-18 and this is the + price: the same write that used to veto the entire repository for 36 hours now vetoes nothing. + It is a deliberate trade and the cheap half of it, because a session doing real work runs + commands that DO append, and every one of those is still seen. It DOES see VS Code sessions: the file registry carries every surface, and the match is purely path-based (the Desktop app's own session tooling only lists what it spawned). @@ -409,6 +418,47 @@ function Test-Merged { } # --- Occupancy signal 2: recent activity, which does not depend on a recorded cwd ---------------- + +#: Metadata whose MTIME is the activity reading. `logs/HEAD` is deliberately NOT in this list; it is +#: read by content instead, for the reason written out over Get-ReflogLastEntry. +$ACTIVITY_MTIME_FILES = @('index', 'HEAD', 'ORIG_HEAD', 'FETCH_HEAD', 'COMMIT_EDITMSG', 'MERGE_MSG') + +function Get-ReflogLastEntry { + param([string]$LogPath) + # THE REFLOG IS READ BY CONTENT, NOT BY MTIME, AND THAT IS THE WHOLE POINT. + # + # A reflog line is: <> \t + # The epoch is stamped by the operation that APPENDED the entry. Nothing which rewrites the file + # without appending to it can move that number. The file's mtime is exactly the opposite: it + # moves for any write at all, including one that changes nothing. + # + # MEASURED 2026-08-18 on this repository. A `git gc` ran at 08:15:34-08:16:05 -- packed-refs + # rewritten at 08:15:34, the packs at 08:16:02-08:16:05 -- and its reflog expiry rewrote every + # reflog in place. **48 of 50** worktree `logs/HEAD` files came out carrying the IDENTICAL mtime + # `2026-08-18 08:15:42`, to the second, while their contents were days older: one worktree's last + # entry is `2026-08-14 12:55:35`, four days before its own mtime. + # + # Signal 2 took the newest mtime, so that single gc made EVERY worktree in the repository read + # "recently active -- someone may be working here" for the next -IdleHours. On the run that found + # it, 11 of 14 candidates were vetoed on that basis alone and the tool removed nothing. With 50 + # worktrees and 9 live sessions producing loose objects, gc is frequent enough that the veto can + # sit permanently on -- and a veto that always fires carries no more information than one that + # never fires, which is the failure class docs/adr/0158 names. + # + # Returns $null when there is no entry to read. The CALLER decides what that means, because "the + # file is empty" and "the file would not parse" are not the same fact and must not act alike. + try { $last = Get-Content -LiteralPath $LogPath -Tail 1 -ErrorAction Stop } catch { return $null } + if (-not $last) { return $null } + # Split at the tab FIRST, so a committer name containing '>' cannot be mistaken for the closing + # bracket of the email. What remains ends with " ", and anchoring the match on that end + # is what makes it exact rather than merely plausible. + $head = ([string]$last -split "`t", 2)[0] + $m = [regex]::Match($head, '(\d{9,11})\s+[+-]\d{4}\s*$') + if (-not $m.Success) { return $null } + try { return [DateTimeOffset]::FromUnixTimeSeconds([long]$m.Groups[1].Value).LocalDateTime } + catch { return $null } +} + function Get-WorktreeActivity { param([string]$Path) # The worktree's PRIVATE git metadata only. Deliberately NOT the working files: a venv install or a @@ -421,13 +471,30 @@ function Get-WorktreeActivity { $gitdir = ([string]$gitdir).Trim() if (-not (Test-Path -LiteralPath $gitdir)) { return $null } $newest = $null - foreach ($rel in @('index', 'HEAD', 'ORIG_HEAD', 'FETCH_HEAD', 'COMMIT_EDITMSG', 'MERGE_MSG', 'logs/HEAD')) { + foreach ($rel in $ACTIVITY_MTIME_FILES) { $f = Join-Path $gitdir $rel if (Test-Path -LiteralPath $f) { $t = (Get-Item -LiteralPath $f -Force).LastWriteTime if ($null -eq $newest -or $t -gt $newest) { $newest = $t } } } + $log = Join-Path $gitdir 'logs/HEAD' + if (Test-Path -LiteralPath $log) { + $item = Get-Item -LiteralPath $log -Force + $t = Get-ReflogLastEntry -LogPath $log + if ($null -eq $t -and $item.Length -gt 0) { + # Non-empty, and it would not parse. FALL BACK TO THE MTIME, which is the reading this + # had before. A parse failure must never be the thing that makes a worktree look idle, + # because idle is the direction that REMOVES one: a reflog shape this does not recognise + # is a reason to keep vetoing, not a reason to stop. + $t = $item.LastWriteTime + } + # A zero-length logs/HEAD contributes NOTHING, and that is not an error: every entry has + # expired, so the reflog holds no evidence in either direction and the six mtimes above still + # speak. Reading its mtime here would reinstate the exact bug this function exists to remove, + # on the oldest worktrees in the repository -- which are the ones most likely to be prunable. + if ($null -ne $t -and ($null -eq $newest -or $t -gt $newest)) { $newest = $t } + } return $newest } diff --git a/tests/test_worktree_prune_merged.py b/tests/test_worktree_prune_merged.py index a0b3c90d..108b60a4 100644 --- a/tests/test_worktree_prune_merged.py +++ b/tests/test_worktree_prune_merged.py @@ -82,9 +82,8 @@ def _add_worktree(primary: Path, path: Path, branch: str) -> None: _git(primary, "worktree", "add", "-q", "-b", branch, str(path)) -def _backdate(primary: Path, worktree: Path, hours: float) -> None: - """Age a worktree's PRIVATE git metadata so the activity veto releases it.""" - gitdir = Path( +def _gitdir(worktree: Path) -> Path: + return Path( subprocess.run( ["git", "-C", str(worktree), "rev-parse", "--absolute-git-dir"], check=True, @@ -92,11 +91,45 @@ def _backdate(primary: Path, worktree: Path, hours: float) -> None: text=True, ).stdout.strip() ) + + +def _age_reflog(gitdir: Path, when: float) -> None: + """Rewrite every ``logs/HEAD`` entry's epoch, which is what actually ages a reflog now. + + Signal 2 reads the reflog by CONTENT, not by mtime, because a ``git gc`` rewrites the file in + place and used to move all of them to one identical mtime. So a fixture that only calls + ``os.utime`` on ``logs/HEAD`` is no longer aging anything the script looks at -- it would be + setting a field that is read only as a fallback. + """ + log = gitdir / "logs" / "HEAD" + if not log.exists(): + return + lines = log.read_text(encoding="utf-8").splitlines() + out = [] + for line in lines: + head, tab, msg = line.partition("\t") + # " <> " -- replace the epoch, keep the offset. + head = re.sub(r"\d{9,11}(?=\s+[+-]\d{4}\s*$)", str(int(when)), head) + out.append(head + tab + msg) + log.write_text("\n".join(out) + ("\n" if out else ""), encoding="utf-8") + # Put the mtime back where the caller asked for it. Writing the file moved it to NOW -- which is + # the gc's own signature -- so without this the fixture ages the CONTENT while leaving the + # timestamp fresh, and `_backdate` silently stops setting the field it appears to set. That is + # harmless only while the script reads content, and becomes a fixture that lies the moment anyone + # reads the mtime again. Found by mutating the script: the CONTROL line failed instead of the + # assertion under test, which is the tell. + os.utime(log, (when, when)) + + +def _backdate(primary: Path, worktree: Path, hours: float) -> None: + """Age a worktree's PRIVATE git metadata so the activity veto releases it.""" + gitdir = _gitdir(worktree) when = time.time() - hours * 3600 for rel in (*_GITDIR_FILES, "logs/HEAD"): f = gitdir / rel if f.exists(): os.utime(f, (when, when)) + _age_reflog(gitdir, when) class Fixture: @@ -258,8 +291,11 @@ def _clone(template: Path, dest: Path) -> Fixture: name the template, so it reports the paths we are trying to correct. Mtimes are preserved (``copytree`` uses ``copy2``), which is load-bearing -- the activity veto - reads the newest mtime of the private git metadata, and ``_backdate`` moves it. The template ages - by at most the file's own runtime, minutes against a 36h window, and no test asserts an exact age. + reads the newest mtime of the private git metadata, and ``_backdate`` moves it. The reflog is + carried by CONTENT for the same reason: since 2026-08-18 the veto reads ``logs/HEAD``'s last + ENTRY rather than its mtime, so a copy that preserved only the timestamp would age nothing the + script actually looks at. The template ages by at most the file's own runtime, minutes against a + 36h window, and no test asserts an exact age. """ shutil.copytree(template, dest, symlinks=True, dirs_exist_ok=True) fx = Fixture(dest) @@ -1826,3 +1862,115 @@ def test_an_empty_registry_reports_SCANNED(fx: Fixture, sleeper: int) -> None: assert res["claims"]["scanned"] is True assert res["claims"]["unreadable"] == [] + + +# -------------------------------------------------------------------------------------------------- +# Signal 2 reads the reflog by CONTENT, not by mtime +# +# MEASURED 2026-08-18 on the real repository: a `git gc` rewrote every reflog in place and left 48 of +# 50 worktree `logs/HEAD` files carrying the IDENTICAL mtime, to the second, while their contents were +# days older. Signal 2 took the newest mtime, so one gc made the entire repository read "recently +# active" for the next 36 hours -- 11 of 14 candidates were vetoed on that basis alone and the tool +# removed nothing. +# +# The pair that matters is the first two tests below. Reading the entry instead of the mtime is only +# correct if it still SEES a real session, so the gc test is worthless without the one directly after +# it, which proves the signal was narrowed rather than deleted. +# -------------------------------------------------------------------------------------------------- + + +def _reflog(worktree: Path) -> Path: + return _gitdir(worktree) / "logs" / "HEAD" + + +def _set_mtime(path: Path, when: float) -> None: + os.utime(path, (when, when)) + + +def test_a_gc_touching_every_reflog_does_not_veto(fx: Fixture, sleeper: int) -> None: + """The bug, reproduced: a write that appends NOTHING must not read as activity.""" + live_record(fx, sleeper, fx.primary) + _backdate(fx.primary, fx.sibling("gone"), hours=100) + _backdate(fx.primary, fx.sibling("clean"), hours=100) + assert by_leaf(run(fx), "clean")["Decision"] == "PRUNE", "control: released before the gc" + + # Exactly what `git gc` does to a reflog it expires: same bytes, new mtime. + before = _reflog(fx.sibling("clean")).read_bytes() + _set_mtime(_reflog(fx.sibling("clean")), time.time()) + assert _reflog(fx.sibling("clean")).read_bytes() == before, "the fixture must change no content" + + res = run(fx) + assert by_leaf(res, "clean")["Decision"] == "PRUNE", by_leaf(res, "clean")["Reason"] + assert by_leaf(res, "gone")["Decision"] == "PRUNE", "anti-vacuity: the pass still prunes" + + +def test_a_fresh_reflog_entry_vetoes_even_when_every_mtime_is_old( + fx: Fixture, sleeper: int +) -> None: + """The other direction, and the one that stops the fix from being a deletion of signal 2. + + A session that ran a real git command appended an entry stamped now. Here every mtime says the + worktree is 100 hours idle and ONLY the reflog's content says otherwise -- so a script that had + simply stopped reading `logs/HEAD` would prune a worktree somebody is working in, and pass the + gc test above while doing it. + """ + live_record(fx, sleeper, fx.primary) + _backdate(fx.primary, fx.sibling("gone"), hours=100) + _backdate(fx.primary, fx.sibling("clean"), hours=100) + assert by_leaf(run(fx), "clean")["Decision"] == "PRUNE", "control: released before the entry" + + log = _reflog(fx.sibling("clean")) + _age_reflog(_gitdir(fx.sibling("clean")), time.time()) # the entry says: used just now + _set_mtime(log, time.time() - 100 * 3600) # ...while every timestamp still says old + + res = run(fx) + d = by_leaf(res, "clean") + assert d["Decision"] == "SKIP" + assert d["Reason"].startswith("recently active") + assert by_leaf(res, "gone")["Decision"] == "PRUNE", "anti-vacuity: the pass still prunes" + + +def test_an_unparseable_reflog_falls_back_to_the_mtime_and_keeps_vetoing( + fx: Fixture, sleeper: int +) -> None: + """A shape this does not recognise is a reason to keep vetoing, never a reason to stop. + + A parse failure that returned "no signal" would make an unreadable reflog the QUIETEST possible + state -- the one input that removes a worktree instead of protecting it. + """ + live_record(fx, sleeper, fx.primary) + _backdate(fx.primary, fx.sibling("gone"), hours=100) + _backdate(fx.primary, fx.sibling("clean"), hours=100) + assert by_leaf(run(fx), "clean")["Decision"] == "PRUNE", "control: released before the damage" + + log = _reflog(fx.sibling("clean")) + log.write_text("this line is not a reflog entry\n", encoding="utf-8") + _set_mtime(log, time.time()) + + res = run(fx) + d = by_leaf(res, "clean") + assert d["Decision"] == "SKIP" + assert d["Reason"].startswith("recently active") + assert by_leaf(res, "gone")["Decision"] == "PRUNE", "anti-vacuity: the pass still prunes" + + +def test_an_empty_reflog_contributes_nothing_rather_than_its_mtime( + fx: Fixture, sleeper: int +) -> None: + """Every entry expired: the reflog holds no evidence either way, and the six mtimes still speak. + + Reading its mtime here would reinstate the bug on the OLDEST worktrees in the repository -- the + ones whose entries a gc has already expired, which are exactly the ones most likely to be + prunable. + """ + live_record(fx, sleeper, fx.primary) + _backdate(fx.primary, fx.sibling("gone"), hours=100) + _backdate(fx.primary, fx.sibling("clean"), hours=100) + + log = _reflog(fx.sibling("clean")) + log.write_text("", encoding="utf-8") + _set_mtime(log, time.time()) + + res = run(fx) + assert by_leaf(res, "clean")["Decision"] == "PRUNE", by_leaf(res, "clean")["Reason"] + assert by_leaf(res, "gone")["Decision"] == "PRUNE", "anti-vacuity: the pass still prunes"