From 9fbdd7194136b400d9cc8164e5c29b49a4c1d3db Mon Sep 17 00:00:00 2001 From: Chuck <33324927+ChuckBuilds@users.noreply.github.com> Date: Wed, 12 Aug 2026 08:40:07 -0400 Subject: [PATCH] fix(cache): collect the temp files abandoned writes leave behind (#452) * fix(cache): collect the temp files abandoned writes leave behind DiskCache.set() writes through mkstemp then os.replace, and removes its own temp file in a finally. That covers a write that fails, but not a process that dies between the two -- a SIGKILL, a lost restart race, a power cut, all ordinary on a Pi. Nothing ever collected what was left. The temp names are "..json.", and cleanup_expired_files listed only names ending in .json, so every one of them was invisible to the sweep for as long as the card had been in service. On the dev rig: 76 files, 1,050 MB, 81% of the whole cache directory, the oldest six months old. The startup sweep reported "18/8864 files deleted, 0.01 MB freed" while sitting on top of a gigabyte it could not see. They are removed after an hour. A real write holds its temp file for milliseconds, so that is far outside any in-flight write while still clearing the same day's debris, and it is deliberately not tied to the retention policies: those say how long data stays useful, and a half-written file never was. The predicate is tested harder than the sweep, because a false positive deletes real data. It matches the shape set() creates rather than just a leading dot, so a completed ".json", a stray .gitignore, and a "weather.json.bak" are all left alone -- and one test drives set() itself and asserts the names it produces are matched, so the writer and the predicate cannot drift apart. Co-Authored-By: Claude Opus 5 (1M context) Claude-Session: https://claude.ai/code/session_01Udr6MfaFLUPhX5Fgo67Jf5 * fix(cache): count swept temp files as scanned files_scanned only counted completed .json files, so a sweep that removed orphans reported more deleted than it had looked at -- the summary line renders "/", which came out as "76/1". Co-Authored-By: Claude Opus 5 (1M context) Claude-Session: https://claude.ai/code/session_01Udr6MfaFLUPhX5Fgo67Jf5 --------- Co-authored-by: Claude Opus 5 (1M context) --- src/cache/disk_cache.py | 65 ++++++++- test/test_cache_orphan_temp_sweep.py | 188 +++++++++++++++++++++++++++ 2 files changed, 252 insertions(+), 1 deletion(-) create mode 100644 test/test_cache_orphan_temp_sweep.py diff --git a/src/cache/disk_cache.py b/src/cache/disk_cache.py index e50b3a85..03cfb2f1 100644 --- a/src/cache/disk_cache.py +++ b/src/cache/disk_cache.py @@ -14,6 +14,13 @@ import zlib from typing import Dict, Any, Optional, Protocol from datetime import datetime +# How old an abandoned write's temp file must be before the sweep removes it. +# A real write holds its temp file for milliseconds, so an hour is far beyond +# any in-flight write while still clearing the same day's debris. Deliberately +# not tied to the retention policies: those describe how long data stays +# useful, and a half-written file was never useful. +_ORPHAN_TEMP_MAX_AGE_SECONDS = 3600 + class CacheStrategyProtocol(Protocol): @@ -347,6 +354,23 @@ class DiskCache: """Get the cache directory path.""" return self.cache_dir + @staticmethod + def _is_orphaned_temp(filename: str) -> bool: + """Whether a name is one of set()'s temp files rather than real data. + + Matches only what this class creates: mkstemp with a prefix of + ".." , so ".weather.json.a1b2c3d4". The shape is + checked rather than just the leading dot, because this predicate + deletes things -- a stray dotfile someone left in the cache directory + is not ours to remove, and a completed ".json" never is either. + """ + if not filename.startswith('.') or filename.endswith('.json'): + return False + head, sep, suffix = filename.rpartition('.json.') + # head is the key (non-empty after the leading dot), suffix is + # mkstemp's random component. + return bool(sep) and len(head) > 1 and bool(suffix) + def cleanup_expired_files(self, cache_strategy: CacheStrategyProtocol, retention_policies: Dict[str, int]) -> Dict[str, Any]: """ Clean up expired cache files based on retention policies. @@ -381,11 +405,50 @@ class DiskCache: try: with self._lock: # Get snapshot of files while holding lock briefly - filenames = [f for f in os.listdir(self.cache_dir) if f.endswith('.json')] + entries = os.listdir(self.cache_dir) except OSError as list_error: self.logger.error("Error listing cache directory %s: %s", self.cache_dir, list_error, exc_info=True) stats['errors'] += 1 return stats + + filenames = [f for f in entries if f.endswith('.json')] + + # Sweep temp files abandoned by a write that never finished. set() + # removes its own in a finally, so these are the ones where the + # process died between mkstemp and os.replace -- a SIGKILL, a lost + # restart race, a power cut. Nothing ever collected them: they are + # named "..json.", and the scan above only matches + # names ending in .json, so they accumulated indefinitely. Measured + # on a live rig: 76 files, 1,050 MB, 81% of the whole cache + # directory, the oldest six months old. + stats['orphan_temp_files_deleted'] = 0 + for filename in (f for f in entries if self._is_orphaned_temp(f)): + # Counted as scanned like any other candidate, so files_deleted + # can never exceed files_scanned and the summary line reads + # honestly ("77/8864", not "77/0"). + stats['files_scanned'] += 1 + path = os.path.join(self.cache_dir, filename) + try: + # An in-flight write lives for milliseconds, so anything + # this old is certainly abandoned rather than in progress. + if (current_time - os.path.getmtime(path)) <= _ORPHAN_TEMP_MAX_AGE_SECONDS: + continue + with self._lock: + size = os.path.getsize(path) + os.remove(path) + stats['files_deleted'] += 1 + stats['orphan_temp_files_deleted'] += 1 + stats['space_freed_bytes'] += size + except FileNotFoundError: + continue # another sweep got there first + except OSError as e: + stats['errors'] += 1 + self.logger.warning("Error deleting orphaned temp file %s: %s", filename, e) + + if stats['orphan_temp_files_deleted']: + self.logger.info( + "Removed %d abandoned cache temp file(s)", + stats['orphan_temp_files_deleted']) # Process files outside the lock to avoid blocking get/set operations for filename in filenames: diff --git a/test/test_cache_orphan_temp_sweep.py b/test/test_cache_orphan_temp_sweep.py new file mode 100644 index 00000000..f35579d6 --- /dev/null +++ b/test/test_cache_orphan_temp_sweep.py @@ -0,0 +1,188 @@ +"""Tests that abandoned cache temp files get collected. + +DiskCache.set() writes through tempfile.mkstemp and os.replace, removing its +own temp file in a finally. That covers a failed write, but not a process that +dies between the two -- a SIGKILL, a lost restart race, a power cut, all +ordinary on a Pi. Nothing collected what was left behind: the temp names are +"..json.", and the expiry sweep only listed names ending in +.json, so they accumulated for as long as the card had been in service. + +Measured on a live rig before this fix: 76 orphans totalling 1,050 MB -- 81% +of the entire cache directory -- the oldest six months old. + +The predicate that decides what to delete is tested harder than the sweep +itself, because a false positive here destroys real data. +""" + +import os +import time + +import pytest + +from src.cache.disk_cache import DiskCache, _ORPHAN_TEMP_MAX_AGE_SECONDS + + +class FakeStrategy: + @staticmethod + def get_data_type_from_key(key): + return 'default' + + +POLICIES = {'default': 30} + + +@pytest.fixture +def cache(tmp_path): + return DiskCache(str(tmp_path)) + + +def _age(path, seconds): + old = time.time() - seconds + os.utime(path, (old, old)) + + +def _write(tmp_path, name, body='{}'): + p = tmp_path / name + p.write_text(body, encoding='utf-8') + return p + + +class TestWhatCountsAsAnOrphan: + @pytest.mark.parametrize('name', [ + '.weather.json.a1b2c3d4', + '.odds_espn_football_nfl_401.json.xyz00000', + '.a.json.b', + ]) + def test_our_temp_files_are_orphans(self, name): + assert DiskCache._is_orphaned_temp(name) + + @pytest.mark.parametrize('name', [ + 'weather.json', # real data + '.weather.json', # a dotted key that completed + '.gitignore', # not ours + '.hidden', # not ours + 'weather.json.bak', # no leading dot: someone else's + '.json.abc', # no key between the dot and .json. + '.weather.json.', # no random component + 'notes.txt', + ]) + def test_everything_else_is_left_alone(self, name): + assert not DiskCache._is_orphaned_temp(name) + + def test_the_names_set_actually_creates_are_matched(self, cache, tmp_path): + """Guard against the predicate and the writer drifting apart.""" + created = [] + real = os.replace + + def capture(src, dst): + created.append(os.path.basename(src)) + return real(src, dst) + + import src.cache.disk_cache as mod + mod.os.replace = capture + try: + cache.set('weather', {'v': 1}) + finally: + mod.os.replace = real + + assert created, "set() did not go through the temp-file path" + assert all(DiskCache._is_orphaned_temp(n) for n in created), created + + +class TestTheSweep: + def test_an_old_orphan_is_removed(self, cache, tmp_path): + p = _write(tmp_path, '.weather.json.a1b2c3d4', 'x' * 5000) + _age(p, _ORPHAN_TEMP_MAX_AGE_SECONDS + 60) + + stats = cache.cleanup_expired_files(FakeStrategy(), POLICIES) + + assert not p.exists() + assert stats['orphan_temp_files_deleted'] == 1 + assert stats['space_freed_bytes'] >= 5000 + + def test_an_in_flight_write_is_not_snatched_away(self, cache, tmp_path): + # The whole risk of this sweep: deleting a temp file another thread is + # about to os.replace into place. + p = _write(tmp_path, '.weather.json.inflight') + + cache.cleanup_expired_files(FakeStrategy(), POLICIES) + + assert p.exists() + + def test_real_cache_files_survive(self, cache, tmp_path): + fresh = _write(tmp_path, 'weather.json') + dotted = _write(tmp_path, '.weather.json') + _age(dotted, _ORPHAN_TEMP_MAX_AGE_SECONDS + 60) + + cache.cleanup_expired_files(FakeStrategy(), POLICIES) + + assert fresh.exists() + assert dotted.exists(), "a completed .json was treated as a temp file" + + def test_unrelated_dotfiles_survive(self, cache, tmp_path): + keep = _write(tmp_path, '.gitignore') + _age(keep, 400 * 86400) + + cache.cleanup_expired_files(FakeStrategy(), POLICIES) + + assert keep.exists() + + def test_expiry_still_works_alongside_it(self, cache, tmp_path): + stale = _write(tmp_path, 'old.json') + _age(stale, 40 * 86400) # past the 30-day default + orphan = _write(tmp_path, '.old.json.zz999999') + _age(orphan, _ORPHAN_TEMP_MAX_AGE_SECONDS + 60) + + stats = cache.cleanup_expired_files(FakeStrategy(), POLICIES) + + assert not stale.exists() + assert not orphan.exists() + assert stats['files_deleted'] == 2 + assert stats['orphan_temp_files_deleted'] == 1 + + def test_the_rig_scenario(self, cache, tmp_path): + """76 orphans of assorted ages, none of them reachable before.""" + for i in range(76): + p = _write(tmp_path, '.sched_%d.json.r%06d' % (i, i), 'x' * 1000) + _age(p, (i + 2) * 86400) + keep = _write(tmp_path, 'sched.json') + + stats = cache.cleanup_expired_files(FakeStrategy(), POLICIES) + + assert stats['orphan_temp_files_deleted'] == 76 + assert keep.exists() + assert not list(tmp_path.glob('.sched_*')) + # The summary line is "/", so an orphan that is + # deleted but never counted as scanned renders as "76/1". + assert stats['files_scanned'] == 77 + assert stats['files_deleted'] <= stats['files_scanned'] + + def test_deleted_never_exceeds_scanned(self, cache, tmp_path): + p = _write(tmp_path, '.only.json.a1b2c3d4') + _age(p, _ORPHAN_TEMP_MAX_AGE_SECONDS + 60) + + stats = cache.cleanup_expired_files(FakeStrategy(), POLICIES) + + assert stats['files_deleted'] == 1 + assert stats['files_scanned'] == 1 + + def test_a_missing_file_mid_sweep_is_not_an_error(self, cache, tmp_path): + p = _write(tmp_path, '.weather.json.a1b2c3d4') + _age(p, _ORPHAN_TEMP_MAX_AGE_SECONDS + 60) + + import src.cache.disk_cache as mod + real = mod.os.path.getsize + + def vanish(path): + if path.endswith('.a1b2c3d4'): + os.remove(path) + raise FileNotFoundError(path) + return real(path) + + mod.os.path.getsize = vanish + try: + stats = cache.cleanup_expired_files(FakeStrategy(), POLICIES) + finally: + mod.os.path.getsize = real + + assert stats['errors'] == 0