Просмотр исходного кода

Give a no-3MF archive the timelapse baseline it never took (issue #2957)

_capture_timelapse_baseline_at_start says in its own docstring that it must
be called from every on_print_start path that proceeds to a real print, and
what breaks otherwise: the completion scan falls back to snapshotting the
card after the printer has written the video, so the new file lands inside
the baseline and no diff can ever match. There are three such paths. The
fallback branch was not calling it, and nothing else covered the gap --
on_print_running_observed is restart-recovery only and is suppressed
whenever on_print_start fires. Every no-3MF archive therefore reached
completion with no baseline in memory and none on the row, and kept its
timelapse only by accident.

Not confined to the reported cool-off. The same branch serves the
internal-storage verdict, so every H2C/H2D/P2S print that Bambu Studio's
Print button sends to eMMC lost its timelapse the same way, off a card that
was holding it the whole time. Measured on a live install: 0 of 9 fallback
archives had a baseline, against 73 of 275 normal ones.

The branch now takes one like the other two, and last like they are: it
lists the printer's timelapse directory, so a slow card must not delay the
active-print registration, the energy reading, the archive-created event or
the start notification ahead of it.

The other half is a print shorter than the five-minute cool-off, where the
card is still unreadable at the one moment a baseline has to be taken.
list_files_async answers [] when its connect fails rather than raising, so
that is indistinguishable from a card holding no videos. When the cool-off
expired inside the 900-second poll window every video on the card read as
new, the first in listing order won, and a stale unclaimed video was
attached to the print and then deleted off the printer.

The empty baseline is still recorded rather than refused. Bambuddy deletes
each video once it is attached, so the usual card holds exactly one at
completion and an empty baseline resolves it correctly; refusing outright
would lose that common case to protect a rare one, and persisting NULL
instead would send completion to snapshot a card that by then has this
print's video on it. Instead the scan marks such a baseline untrusted and
the attach step declines to choose between several candidates, leaving them
for the manual Scan for Timelapse button. require_unambiguous defaults to
off, so the only caller whose behaviour changes is that scan.
maziggy 1 неделя назад
Родитель
Сommit
59d2713acf
3 измененных файлов с 375 добавлено и 1 удалено
  1. 0 0
      CHANGELOG.md
  2. 107 1
      backend/app/main.py
  3. 268 0
      backend/tests/unit/test_fallback_timelapse_baseline_2957.py

Разница между файлами не показана из-за своего большого размера
+ 0 - 0
CHANGELOG.md


+ 107 - 1
backend/app/main.py

@@ -4440,6 +4440,28 @@ async def on_print_start(printer_id: int, data: dict):
                 # Send notification without archive data (file not found)
                 if not notification_sent:
                     await _send_print_start_notification(printer_id, data, logger=logger)
+
+                # The same baseline the other two on_print_start branches take
+                # (#2704), and last for the same reason they are: it lists the
+                # printer's timelapse directory, so a slow card must not delay
+                # the _active_prints registration, the energy reading, the
+                # archive-created event or the start notification above it.
+                #
+                # This branch never took one, so every no-3MF archive reached
+                # completion with no baseline in memory and none on the row, and
+                # the completion scan fell into its "snapshot now" fallback --
+                # which runs after the printer has written the video, so the new
+                # file landed inside the baseline and no diff ever matched
+                # (#2957 follow-up).
+                #
+                # Skipped when the FTPS cool-off is what produced this fallback:
+                # the listing needs the same connection that just failed, so it
+                # could only record that the card was unreadable. The scan
+                # handles that case by refusing to choose between candidates.
+                if not blocked_by_ftps_cooloff:
+                    await _capture_timelapse_baseline_at_start(
+                        printer, printer_id, logger, archive_id=fallback_archive.id
+                    )
                 return
             except Exception as e:
                 logger.error("Failed to create fallback archive: %s", e)
@@ -4614,12 +4636,38 @@ async def _claimed_timelapse_names(db, printer_id: int, exclude_archive_id: int)
     return {Path(p).stem for p in rows.scalars().all() if p}
 
 
+def _timelapse_listing_is_trustworthy(printer) -> bool:
+    """Whether an *empty* timelapse listing for *printer* can be believed.
+
+    ``list_files_async`` answers ``[]`` when its connect fails rather than
+    raising, so a card behind the FTPS handshake cool-off is indistinguishable
+    from one holding no videos. Everywhere that only wants to know "is there a
+    video yet" the difference does not matter — both mean "not yet, retry".
+
+    It matters where an empty listing is recorded as a *baseline*. Recording
+    "the card held nothing" for a card that was never read means every video on
+    it counts as new once the cool-off expires, and the completion scan then
+    attaches a stale video to this print and deletes it from the printer
+    (#2957 follow-up). Those two callers ask this first.
+    """
+    from backend.app.services.bambu_ftp import ftps_handshake_blocked
+
+    ip_address = getattr(printer, "ip_address", None)
+    if not ip_address:
+        return True
+    return not ftps_handshake_blocked(ip_address)
+
+
 async def _list_timelapse_videos(printer) -> tuple[list[dict], str | None]:
     """List video files from printer's timelapse directory.
 
     Finds MP4 (X1/A1 series) and AVI (P1 series) timelapse files.
     Returns (video_files, found_path) where video_files is a list of file dicts
     and found_path is the directory where they were found, or ([], None).
+
+    An empty return does not distinguish "no videos" from "could not read the
+    card" — see :func:`_timelapse_listing_is_trustworthy`, which the two
+    baseline callers consult before believing one.
     """
     from backend.app.services.bambu_ftp import list_files_async
 
@@ -4682,6 +4730,21 @@ async def _capture_timelapse_baseline_at_start(
     """
     names: set[str] | None = None
     try:
+        if not _timelapse_listing_is_trustworthy(printer):
+            # Recorded anyway, deliberately. An empty baseline taken off a card
+            # we could not read is not authoritative, but it is still the right
+            # *default*: Bambuddy deletes each video from the printer once it is
+            # attached, so the usual card holds exactly one video at completion
+            # and an empty baseline resolves it correctly. Persisting NULL
+            # instead would send completion to take its own snapshot, by which
+            # point this print's video is on the card and would be swallowed by
+            # it. The ambiguity is handled where it actually bites — see
+            # ``require_unambiguous`` in the scan (#2957 follow-up).
+            logger.warning(
+                "[TIMELAPSE] Baseline for printer %s taken while its file service is in the FTPS "
+                "handshake cool-off, so the card could not be read — treating it as empty",
+                printer_id,
+            )
         baseline_files, _ = await _list_timelapse_videos(printer)
         names = {f.get("name", "") for f in baseline_files}
         _timelapse_baselines[printer_id] = names
@@ -4735,6 +4798,10 @@ async def _scan_for_timelapse_with_retries(archive_id: int, baseline_names: set[
     """
     logger = logging.getLogger(__name__)
 
+    # Cleared when the baseline had to be taken off a card we could not read, so
+    # the attach step refuses to choose between several candidates (#2957).
+    baseline_trusted = True
+
     # --- Phase 1: establish the baseline -------------------------------------
     try:
         async with async_session() as db:
@@ -4774,6 +4841,23 @@ async def _scan_for_timelapse_with_retries(archive_id: int, baseline_names: set[
                     logger.warning("[TIMELAPSE] Printer not found for archive %s, aborting", archive_id)
                     return
 
+                if not _timelapse_listing_is_trustworthy(printer):
+                    # The card is unreadable at the one moment a baseline has to
+                    # be taken, so the empty listing below means "we never
+                    # looked", not "these are all new". Carry on with it anyway
+                    # — the usual card holds exactly one video, which resolves
+                    # correctly — but stop the poll from *choosing* between
+                    # several, which is how a stale video got attached to this
+                    # print and then deleted off the printer (#2957 follow-up).
+                    baseline_trusted = False
+                    logger.warning(
+                        "[TIMELAPSE] Baseline for archive %s taken while printer %s is in the FTPS "
+                        "handshake cool-off. A single new video still resolves; several will not be "
+                        "guessed between — use Scan for Timelapse to pick one by hand",
+                        archive_id,
+                        archive.printer_id,
+                    )
+
                 baseline_files, _ = await _list_timelapse_videos(printer)
                 baseline_names = {f.get("name", "") for f in baseline_files}
                 logger.info(
@@ -4842,7 +4926,15 @@ async def _scan_for_timelapse_with_retries(archive_id: int, baseline_names: set[
                         logger.info("[TIMELAPSE]   - %s", f.get("name"))
 
                 attached = await _attach_first_unclaimed_timelapse(
-                    archive_id, printer, video_files, baseline_names, claimed, attempt, logger, quiet=not changed
+                    archive_id,
+                    printer,
+                    video_files,
+                    baseline_names,
+                    claimed,
+                    attempt,
+                    logger,
+                    quiet=not changed,
+                    require_unambiguous=not baseline_trusted,
                 )
                 if attached:
                     return
@@ -4876,6 +4968,7 @@ async def _attach_first_unclaimed_timelapse(
     logger: logging.Logger,
     *,
     quiet: bool = False,
+    require_unambiguous: bool = False,
 ) -> bool:
     """Download and attach the one video that belongs to this print.
 
@@ -4915,6 +5008,19 @@ async def _attach_first_unclaimed_timelapse(
         )
         return False
     if len(candidates) > 1:
+        if require_unambiguous:
+            # The baseline is not evidence -- it was taken off a card that could
+            # not be read -- so "new since the baseline" does not narrow these
+            # down at all. Taking the first would attach an arbitrary video to
+            # this print and then delete it from the printer.
+            logger.warning(
+                "[TIMELAPSE] Attempt %s: %s unclaimed videos (%s) and no baseline to tell them apart — "
+                "leaving all of them on the printer for manual selection",
+                attempt,
+                len(candidates),
+                ", ".join(str(f.get("name")) for f in candidates),
+            )
+            return False
         logger.warning(
             "[TIMELAPSE] Attempt %s: %s unclaimed new files (%s) — taking the first; "
             "the rest stay on the printer for manual selection",

+ 268 - 0
backend/tests/unit/test_fallback_timelapse_baseline_2957.py

@@ -0,0 +1,268 @@
+"""Does a no-3MF fallback archive ever get its timelapse? (#2957 follow-up)
+
+The reporter of #2957 confirmed the archive recovery works and then noticed the
+timelapse is not recovered with it, "even though it's there".
+
+``_capture_timelapse_baseline_at_start`` says in its own docstring that it must
+be called from every ``on_print_start`` path that proceeds to a real print, and
+what breaks when it is not: the completion scan falls back to snapshotting the
+card *after* the video has landed, so the new file ends up inside the baseline
+and no diff can ever match. ``on_print_start`` has three such paths. The
+new-archive and expected-archive branches call it. The fallback-archive branch
+does not, and nothing else covers it -- ``on_print_running_observed`` is
+restart-recovery only and is suppressed whenever ``on_print_start`` fires.
+
+So a fallback archive reaches completion with no baseline in memory and none on
+the row. These tests pin what happens then. Both drive the scan the way
+``on_print_complete`` does for such an archive: ``_timelapse_baselines.pop``
+misses, so ``baseline_names`` is None.
+
+Two cases, split by whether the five-minute FTPS cool-off that caused the
+fallback has expired by the time the print ends:
+
+  * Longer than the cool-off -- the card is readable at completion, and the
+    self-taken baseline swallows the new video.
+  * Shorter than the cool-off -- the card is *not* readable, so the baseline is
+    empty rather than merely late, and every video on the card reads as new once
+    the cool-off clears inside the poll window.
+
+The fix is two parts. The fallback branch now takes the same baseline as the
+other two whenever the card is readable, and an *empty* listing taken while the
+card is unreadable is no longer believed -- ``list_files_async`` answers [] when
+its connect fails rather than raising, so it looks exactly like an empty card.
+"""
+
+from __future__ import annotations
+
+import time
+from unittest.mock import AsyncMock, patch
+
+import pytest
+from sqlalchemy.ext.asyncio import AsyncSession, async_sessionmaker
+
+from backend.app.models.archive import PrintArchive
+from backend.app.models.printer import Printer
+
+pytestmark = pytest.mark.asyncio
+
+PRINTER_IP = "172.25.12.149"
+OLD_VIDEO = "video_2019-01-01_00-00-00.mp4"
+NEW_VIDEO = "video_2026-08-27_01-30-00.mp4"
+
+
+def _entry(name: str) -> dict:
+    return {"name": name, "size": 1024, "is_directory": False, "path": f"/timelapse/{name}"}
+
+
+async def _seed(engine) -> tuple[async_sessionmaker, int, int]:
+    """A printer plus the empty fallback archive, exactly as the cool-off
+    branch of ``on_print_start`` writes it -- note ``timelapse_baseline`` is
+    never set there, which is the whole point."""
+    maker = async_sessionmaker(engine, class_=AsyncSession, expire_on_commit=False)
+    async with maker() as db:
+        printer = Printer(
+            name="P1S",
+            serial_number="01P00A3B1200579",
+            ip_address=PRINTER_IP,
+            access_code="12345678",
+            model="P1S",
+        )
+        db.add(printer)
+        await db.commit()
+        await db.refresh(printer)
+
+        archive = PrintArchive(
+            printer_id=printer.id,
+            filename="Desktop_Goose.gcode.3mf",
+            file_path="",
+            file_size=0,
+            print_name="Desktop_Goose",
+            status="completed",
+            extra_data={"no_3mf_available": True, "no_3mf_reason": "ftps_cooloff"},
+        )
+        db.add(archive)
+        await db.commit()
+        await db.refresh(archive)
+        assert archive.timelapse_baseline is None, "the fallback branch never captures one"
+        return maker, printer.id, archive.id
+
+
+def _patches(main_module, maker, monkeypatch, tmp_path, listing):
+    """Shrink the poll to test speed and stand in for the FTP layer.
+
+    ``listing`` is called per request and returns what ``/timelapse`` holds at
+    that moment, so a test can let the cool-off expire mid-poll.
+    """
+    from backend.app.core.config import settings as app_config
+    from backend.app.services import bambu_ftp
+
+    # archive_dir is its own setting rather than derived, so both have to move
+    # or attach_timelapse writes under the real one and then fails its
+    # relative_to(base_dir).
+    monkeypatch.setattr(app_config, "base_dir", tmp_path)
+    monkeypatch.setattr(app_config, "archive_dir", tmp_path / "archive")
+    monkeypatch.setattr(main_module, "_TIMELAPSE_SCAN_FIRST_DELAY_SECONDS", 0.05)
+    monkeypatch.setattr(main_module, "_TIMELAPSE_SCAN_POLL_INTERVAL_SECONDS", 0.05)
+    monkeypatch.setattr(main_module, "_TIMELAPSE_SCAN_TIMEOUT_SECONDS", 3.0)
+
+    async def _list(ip, code, path, printer_model=None):
+        if path != "/timelapse":
+            return []
+        return listing()
+
+    monkeypatch.setattr(bambu_ftp, "list_files_async", _list)
+    monkeypatch.setattr(bambu_ftp, "download_file_bytes_async", AsyncMock(return_value=b"x" * 1024))
+    monkeypatch.setattr(bambu_ftp, "remote_file_settled", AsyncMock(return_value=True))
+    monkeypatch.setattr(bambu_ftp, "delete_archived_timelapse", AsyncMock(return_value=True))
+    return patch.object(main_module, "async_session", maker)
+
+
+class TestTheCooloffOutlastsThePrint:
+    """Print shorter than the five-minute cool-off, so the card is still
+    unreadable when the scan takes its baseline."""
+
+    async def test_an_unclaimed_old_video_is_attached_to_this_print(self, test_engine, tmp_path, monkeypatch):
+        from backend.app import main as main_module
+        from backend.app.services.bambu_ftp import BambuFTPClient as BambuFTP
+
+        maker, printer_id, archive_id = await _seed(test_engine)
+
+        # The real cool-off, armed the way a failed TLS handshake arms it.
+        # Short enough to expire inside the poll window, as it does on a print
+        # that ends before the five minutes are up.
+        BambuFTP._handshake_blocked_until[PRINTER_IP] = time.monotonic() + 0.25
+
+        def listing():
+            if BambuFTP.handshake_blocked(PRINTER_IP):
+                # What the real path yields while blocked: list_files_async
+                # returns [] when its connect fails rather than raising, so this
+                # is indistinguishable from a card holding no videos.
+                return []
+            # The printer wrote this print's video at completion; the older one
+            # was already there and belongs to no archive.
+            return [_entry(OLD_VIDEO), _entry(NEW_VIDEO)]
+
+        try:
+            with _patches(main_module, maker, monkeypatch, tmp_path, listing):
+                await main_module._scan_for_timelapse_with_retries(archive_id, None)
+        finally:
+            BambuFTP._handshake_blocked_until.pop(PRINTER_IP, None)
+
+        async with maker() as db:
+            archive = await db.get(PrintArchive, archive_id)
+            attached = archive.timelapse_path
+
+        # Before the fix the empty baseline licensed both videos as "new", the
+        # first in listing order won, and the stale video was attached to this
+        # print and then deleted off the printer. With no baseline to tell them
+        # apart, both now stay on the printer for manual selection.
+        assert attached is None, f"expected no attach, got {attached!r}"
+
+    async def test_a_lone_video_still_resolves(self, test_engine, tmp_path, monkeypatch):
+        """The steady state, and why the scan must not simply abort here:
+        Bambuddy deletes each video from the printer once it is attached, so the
+        usual card holds exactly this print's video and nothing else. One
+        unclaimed candidate is unambiguous with or without a readable baseline,
+        and aborting would lose the common case to protect the rare one."""
+        from backend.app import main as main_module
+        from backend.app.services.bambu_ftp import BambuFTPClient as BambuFTP
+
+        maker, printer_id, archive_id = await _seed(test_engine)
+        BambuFTP._handshake_blocked_until[PRINTER_IP] = time.monotonic() + 0.25
+
+        def listing():
+            if BambuFTP.handshake_blocked(PRINTER_IP):
+                return []
+            return [_entry(NEW_VIDEO)]
+
+        try:
+            with _patches(main_module, maker, monkeypatch, tmp_path, listing):
+                await main_module._scan_for_timelapse_with_retries(archive_id, None)
+        finally:
+            BambuFTP._handshake_blocked_until.pop(PRINTER_IP, None)
+
+        async with maker() as db:
+            attached = (await db.get(PrintArchive, archive_id)).timelapse_path
+
+        assert attached is not None, "one unclaimed video needs no baseline to disambiguate"
+        assert NEW_VIDEO in attached, f"expected this print's video, got {attached!r}"
+
+
+class TestTheCardWasReadableAtPrintStart:
+    """The reporter's case, and every fallback archive on an H2/P2S: FTPS is
+    healthy, so the fallback branch now takes a baseline like the other two."""
+
+    async def test_the_persisted_baseline_picks_this_prints_video(self, test_engine, tmp_path, monkeypatch):
+        from backend.app import main as main_module
+
+        maker, printer_id, archive_id = await _seed(test_engine)
+
+        # What the fallback branch now writes at print start: the card as it was
+        # before this print, holding only the older video.
+        async with maker() as db:
+            archive = await db.get(PrintArchive, archive_id)
+            archive.timelapse_baseline = [OLD_VIDEO]
+            await db.commit()
+
+        # By completion the printer has written this print's video alongside it.
+        def listing():
+            return [_entry(OLD_VIDEO), _entry(NEW_VIDEO)]
+
+        with _patches(main_module, maker, monkeypatch, tmp_path, listing):
+            await main_module._scan_for_timelapse_with_retries(archive_id, None)
+
+        async with maker() as db:
+            attached = (await db.get(PrintArchive, archive_id)).timelapse_path
+
+        assert attached is not None, "the baseline makes this print's video the only new one"
+        assert NEW_VIDEO in attached, f"expected this print's video, got {attached!r}"
+
+
+class TestTheBaselineCaptureItself:
+    """Part one, at the source: what the fallback branch calls."""
+
+    async def test_an_unreadable_card_still_records_the_empty_baseline(self, test_engine, tmp_path, monkeypatch):
+        """Deliberately ``[]`` rather than NULL. NULL sends completion off to
+        take its own snapshot, by which point this print's video is on the card
+        and gets swallowed by the very baseline meant to exclude it. The
+        ambiguity an unread card creates is handled at the attach step."""
+        from backend.app import main as main_module
+        from backend.app.services.bambu_ftp import BambuFTPClient as BambuFTP
+
+        maker, printer_id, archive_id = await _seed(test_engine)
+        BambuFTP._handshake_blocked_until[PRINTER_IP] = time.monotonic() + 60
+
+        async with maker() as db:
+            printer = await db.get(Printer, printer_id)
+
+        try:
+            with _patches(main_module, maker, monkeypatch, tmp_path, lambda: []):
+                await main_module._capture_timelapse_baseline_at_start(
+                    printer, printer_id, main_module.logging.getLogger(__name__), archive_id=archive_id
+                )
+        finally:
+            BambuFTP._handshake_blocked_until.pop(PRINTER_IP, None)
+
+        async with maker() as db:
+            assert (await db.get(PrintArchive, archive_id)).timelapse_baseline == []
+        assert main_module._timelapse_baselines[printer_id] == set()
+        main_module._timelapse_baselines.pop(printer_id, None)
+
+    async def test_a_readable_card_is_captured_and_persisted(self, test_engine, tmp_path, monkeypatch):
+        from backend.app import main as main_module
+
+        maker, printer_id, archive_id = await _seed(test_engine)
+        async with maker() as db:
+            printer = await db.get(Printer, printer_id)
+
+        try:
+            with _patches(main_module, maker, monkeypatch, tmp_path, lambda: [_entry(OLD_VIDEO)]):
+                await main_module._capture_timelapse_baseline_at_start(
+                    printer, printer_id, main_module.logging.getLogger(__name__), archive_id=archive_id
+                )
+
+            async with maker() as db:
+                assert (await db.get(PrintArchive, archive_id)).timelapse_baseline == [OLD_VIDEO]
+            assert main_module._timelapse_baselines[printer_id] == {OLD_VIDEO}
+        finally:
+            main_module._timelapse_baselines.pop(printer_id, None)

Некоторые файлы не были показаны из-за большого количества измененных файлов