Преглед изворни кода

fix(camera): protect an in-progress stitch from the orphan sweep, and only sweep this feature's own files

Review follow-ups on the orphaned timelapse session cleanup.

The sweep's own docstring said min_age_seconds made it safe to call mid-run.
It did not. on_print_complete drops the session from _active_sessions before
handing frames_dir to ffmpeg, so for the length of a stitch the directory
matches no active session, and its mtime is the last layer's frame write -
which on a tall print's final layer is easily older than the margin. The
default margin is 300s and the stitch timeout is also 300s, so the two were
tied with no headroom at all: a sweep landing in that window deleted ffmpeg's
input from under it. _finalizing_sessions now covers the stitch, set as the
session leaves _active_sessions and cleared in a finally so a failed stitch
cannot leak the marker and make that printer's leftovers permanently
un-sweepable. The docstring names all three guards and which gap each covers,
including that the margin does have real headroom for the two cases it suits -
a session mid-creation, and the freshly written .mp4 awaiting attach.

The file branch now requires the timelapse_<session_id>.mp4 shape its own
comment describes. It previously deleted any file under
timelapse_frames/<printer_id>/ past the margin; nothing else writes there
today, but age alone is not a reason to delete a file this feature did not
create.

Dropped ignore_errors=True from the rmtree. It made the surrounding
except OSError unreachable, so a read-only mount or a permissions problem was
counted and logged as a successful removal - and that log is the only evidence
an operator has of what was deleted.

Tests 5 -> 9: sparing a session mid-stitch, the finalizing marker cleared even
when the stitch raises, unrelated files left alone, and a failed removal not
counted. The failure test's rmtree stub honours the real contract and returns
silently when ignore_errors=True, because that silent no-op is exactly what the
old call could never observe; a stub that raised unconditionally would have
passed against both versions and proved nothing.

main.py is unchanged: it has no module-level logger, and the inline
logging.getLogger(__name__) the sweep uses is the idiom throughout lifespan.
maziggy пре 1 месец
родитељ
комит
08c9ec6749

Разлика између датотеке није приказан због своје велике величине
+ 0 - 1
CHANGELOG.md


+ 50 - 7
backend/app/services/layer_timelapse.py

@@ -19,6 +19,15 @@ logger = logging.getLogger(__name__)
 # Active timelapse sessions: {printer_id: TimelapseSession}
 _active_sessions: dict[int, "TimelapseSession"] = {}
 
+# Sessions whose frames are being stitched right now: {printer_id: session_id}.
+# on_print_complete removes the session from _active_sessions *before* handing
+# frames_dir to ffmpeg, so for the length of a stitch (up to 300s) nothing in
+# _active_sessions marks that directory as in use. Without this second registry
+# the only thing standing between an in-progress stitch and
+# cleanup_orphaned_timelapse_sessions() is the age margin — whose default is
+# exactly the stitch timeout, so there is no headroom at all.
+_finalizing_sessions: dict[int, str] = {}
+
 
 def get_ffmpeg_path() -> str | None:
     """Get the path to ffmpeg executable."""
@@ -274,6 +283,12 @@ async def on_print_complete(printer_id: int) -> Path | None:
     # Create output path in parent of frames dir
     output_path = session.frames_dir.parent / f"timelapse_{session.session_id}.mp4"
 
+    # The session is already out of _active_sessions, so mark it finalizing for
+    # the length of the stitch — otherwise a sweep running now sees a frames
+    # directory that matches no session and whose mtime is the last layer's
+    # write, which on a tall print's final layer is easily older than the age
+    # margin, and deletes ffmpeg's input from under it.
+    _finalizing_sessions[printer_id] = session.session_id
     try:
         success = await session.stitch(output_path)
         if success:
@@ -287,6 +302,8 @@ async def on_print_complete(printer_id: int) -> Path | None:
         logger.error("Timelapse completion failed: %s", e)
         session.cleanup()
         return None
+    finally:
+        _finalizing_sessions.pop(printer_id, None)
 
 
 def cancel_session(printer_id: int):
@@ -322,8 +339,21 @@ def cleanup_orphaned_timelapse_sessions(min_age_seconds: float = 300) -> int:
     process - and a restart-recovered print doesn't get a new timelapse
     session either (`_maybe_start_layer_timelapse` is only wired into fresh
     PRINT_START events, see #1353), so an orphaned directory can never be
-    resumed. `min_age_seconds` is just a defensive margin against reordering
-    if this is ever also called mid-run.
+    resumed.
+
+    Also safe to call mid-run, which needs all three guards rather than the
+    age margin alone:
+
+    * `_active_sessions` covers a session that is still capturing.
+    * `_finalizing_sessions` covers the stitch window. on_print_complete drops
+      the session from `_active_sessions` before handing frames_dir to ffmpeg,
+      so without this the directory matches no session for up to 300s while
+      being actively read.
+    * `min_age_seconds` covers the remaining gap - a session in the middle of
+      being created, and the stitched `.mp4` between ffmpeg finishing it and
+      the caller attaching and unlinking it. Both are freshly written, so the
+      margin has real headroom there; it did NOT have any for the stitch
+      window, whose length is bounded by the same 300s.
 
     Returns the number of orphaned directories/files removed.
     """
@@ -342,14 +372,24 @@ def cleanup_orphaned_timelapse_sessions(min_age_seconds: float = 300) -> int:
             continue
 
         active_session = _active_sessions.get(printer_id)
-        active_session_id = active_session.session_id if active_session else None
+        in_use_session_ids = {
+            active_session.session_id if active_session else None,
+            _finalizing_sessions.get(printer_id),
+        } - {None}
 
         for entry in printer_dir.iterdir():
             # Frame dirs are named "<session_id>/"; stitched-but-not-yet-
             # attached output files are "timelapse_<session_id>.mp4" (see
-            # on_print_complete's output_path).
-            entry_session_id = entry.name.removeprefix("timelapse_").removesuffix(".mp4") if entry.is_file() else entry.name
-            if entry_session_id == active_session_id:
+            # on_print_complete's output_path). Anything else under here was
+            # not written by this module, so leave it alone rather than
+            # deleting a file on the strength of its age.
+            if entry.is_dir():
+                entry_session_id = entry.name
+            elif entry.name.startswith("timelapse_") and entry.name.endswith(".mp4"):
+                entry_session_id = entry.name[len("timelapse_") : -len(".mp4")]
+            else:
+                continue
+            if entry_session_id in in_use_session_ids:
                 continue
             try:
                 if now - entry.stat().st_mtime < min_age_seconds:
@@ -357,8 +397,11 @@ def cleanup_orphaned_timelapse_sessions(min_age_seconds: float = 300) -> int:
             except OSError:
                 continue
             try:
+                # No ignore_errors: it would swallow a failed removal while the
+                # count and the log line below still claimed success, and that
+                # log is the only evidence an operator has of what was deleted.
                 if entry.is_dir():
-                    shutil.rmtree(entry, ignore_errors=True)
+                    shutil.rmtree(entry)
                 else:
                     entry.unlink(missing_ok=True)
                 removed += 1

+ 119 - 1
backend/tests/unit/services/test_layer_timelapse.py

@@ -369,7 +369,6 @@ class TestCleanupOrphanedTimelapseSessions:
         )
 
         _active_sessions.clear()
-        printer_dir = tmp_path / "timelapse_frames" / "1"
 
         with patch("backend.app.services.layer_timelapse.settings") as mock_settings:
             mock_settings.base_dir = tmp_path
@@ -433,3 +432,122 @@ class TestCleanupOrphanedTimelapseSessions:
             removed = cleanup_orphaned_timelapse_sessions()
 
         assert removed == 0
+
+    def test_spares_a_session_that_is_mid_stitch(self, tmp_path):
+        """on_print_complete drops the session from _active_sessions before it
+        hands frames_dir to ffmpeg, so for the length of a stitch (up to 300s)
+        the directory matches no active session. Its mtime is the last layer's
+        frame write, which on a tall print's final layer is easily older than
+        the age margin — and the margin's default IS the stitch timeout, so it
+        offers no headroom here. _finalizing_sessions covers that window."""
+        import os
+
+        from backend.app.services.layer_timelapse import (
+            TimelapseSession,
+            _active_sessions,
+            _finalizing_sessions,
+            cleanup_orphaned_timelapse_sessions,
+        )
+
+        _active_sessions.clear()
+        _finalizing_sessions.clear()
+
+        with patch("backend.app.services.layer_timelapse.settings") as mock_settings:
+            mock_settings.base_dir = tmp_path
+            session = TimelapseSession(1, 100, "/dev/video1", "usb")
+            (session.frames_dir / "layer_00001.jpg").write_bytes(b"x")
+            old = time.time() - 600
+            os.utime(session.frames_dir, (old, old))
+
+            # Exactly the state on_print_complete is in while ffmpeg runs.
+            _active_sessions.pop(1, None)
+            _finalizing_sessions[1] = session.session_id
+
+            removed = cleanup_orphaned_timelapse_sessions(min_age_seconds=300)
+
+        assert removed == 0
+        assert session.frames_dir.exists(), "ffmpeg's input was deleted mid-stitch"
+        _finalizing_sessions.clear()
+
+    @pytest.mark.asyncio
+    async def test_on_print_complete_clears_the_finalizing_marker(self, tmp_path):
+        """Including when the stitch fails — a leaked marker would make the
+        sweep skip that printer's leftovers forever."""
+        from backend.app.services.layer_timelapse import (
+            TimelapseSession,
+            _active_sessions,
+            _finalizing_sessions,
+            on_print_complete,
+        )
+
+        _active_sessions.clear()
+        _finalizing_sessions.clear()
+
+        with patch("backend.app.services.layer_timelapse.settings") as mock_settings:
+            mock_settings.base_dir = tmp_path
+            session = TimelapseSession(1, 100, "/dev/video1", "usb")
+            session.frame_count = 3
+            _active_sessions[1] = session
+
+            with patch.object(TimelapseSession, "stitch", AsyncMock(side_effect=RuntimeError("ffmpeg died"))):
+                result = await on_print_complete(1)
+
+        assert result is None
+        assert 1 not in _finalizing_sessions
+
+    def test_leaves_unrelated_files_alone(self, tmp_path):
+        """Only this module's own artifacts are swept. A file that is neither a
+        session directory nor timelapse_<id>.mp4 was put there by something
+        else, and age is not a reason to delete it."""
+        from backend.app.services.layer_timelapse import (
+            _active_sessions,
+            cleanup_orphaned_timelapse_sessions,
+        )
+
+        _active_sessions.clear()
+        printer_dir = tmp_path / "timelapse_frames" / "1"
+        printer_dir.mkdir(parents=True)
+        stranger = printer_dir / "notes.txt"
+        self._touch_old(stranger)
+        self._touch_old(printer_dir / "timelapse_20260101_000000.mp4")
+
+        with patch("backend.app.services.layer_timelapse.settings") as mock_settings:
+            mock_settings.base_dir = tmp_path
+            removed = cleanup_orphaned_timelapse_sessions(min_age_seconds=300)
+
+        assert removed == 1
+        assert stranger.exists()
+        assert not (printer_dir / "timelapse_20260101_000000.mp4").exists()
+
+    def test_a_removal_that_fails_is_not_counted_as_removed(self, tmp_path):
+        """The count and the log line are the only evidence an operator has of
+        what was deleted, so a failed rmtree must not be reported as a success.
+
+        The stub honours rmtree's real contract — ignore_errors=True swallows
+        the failure and returns normally — because that is the whole point: a
+        caller passing it gets a silent no-op that the surrounding
+        ``except OSError`` can never see, and would still count and log the
+        directory as removed. A stub that raised unconditionally would pass
+        either way and prove nothing.
+        """
+        from backend.app.services.layer_timelapse import (
+            _active_sessions,
+            cleanup_orphaned_timelapse_sessions,
+        )
+
+        _active_sessions.clear()
+        printer_dir = tmp_path / "timelapse_frames" / "1"
+        self._mkdir_old(printer_dir / "20260101_000000")
+
+        def rmtree_on_read_only_fs(path, ignore_errors=False, **kwargs):
+            if ignore_errors:
+                return  # silently does nothing, exactly like the real thing
+            raise OSError("read-only fs")
+
+        with patch("backend.app.services.layer_timelapse.settings") as mock_settings:
+            mock_settings.base_dir = tmp_path
+            with patch("backend.app.services.layer_timelapse.shutil.rmtree", rmtree_on_read_only_fs):
+                removed = cleanup_orphaned_timelapse_sessions(min_age_seconds=300)
+
+        assert removed == 0, "a directory that is still on disk was reported as removed"
+        assert (printer_dir / "20260101_000000").exists()

Неке датотеке нису приказане због велике количине промена