fix(archive): a print of a file whose last print was never closed gets its own archive

CHANGELOG.md

@@ -164,6 +164,7 @@ All notable changes to Bambuddy will be documented in this file.
 - **The frontend build no longer warns about `path` and `crypto` being externalized for the STEP previewer (#2976)** — `occt-import-js`, the Emscripten build behind STEP previews, requires both modules, but only inside its `ENVIRONMENT_IS_NODE` branches; in the browser it loads its `.wasm` from the URL the preview worker passes and draws randomness from `crypto.getRandomValues`. Vite still externalized both and printed two warnings on every build. `vite.config.ts` now drops exactly those two warnings for that one package through `build.rolldownOptions.onLog`, so an externalization anywhere else, or of any other module, still shows.
 
 ### Fixed
+- **A print of a file whose last print was never closed gets its own archive** — an archive left on "printing" because its end was missed used to take over the next print of the same file for two hours, so that print got no history entry, timelapse or cost estimate of its own. A different job id from the printer now marks it as a new print, except when it is Bambuddy's own reprint of that archive.
 - **Filament of a print that spans a Bambuddy restart is no longer counted twice** — when the restart found no saved print session, or one of another print, the AMS remaining-% sync raised the spool's used weight during the print, and completion then added the print's full usage on top.
 - **A print whose dispatch failed no longer leaves its cost centre behind** — the next print of the same archive without a cost centre of its own was charged to it, instead of the user or the archive's cost centre.
 - **Which plate of a multi-plate file printed** —

backend/app/main.py

@@ -4914,21 +4914,19 @@ async def on_print_start(printer_id: int, data: dict):
 
         # Preferred match: subtask_id equality. MQTT reports the same subtask_id
         # across a backend restart for the same print, so this is the most
-        # reliable way to reattach. We also accept a previously stale-cancelled
-        # archive here so users upgrading mid-print get revived when the row
-        # their earlier Bambuddy version wrongly cancelled reappears (#972).
+        # reliable way to reattach. Only a row still printing: a cancelled one
+        # has been through completion (usage, history, notifications) already,
+        # and reopening it would count the print twice.
         if subtask_id:
             by_id = await db.execute(
                 select(PrintArchive)
                 .where(PrintArchive.printer_id == printer_id)
                 .where(PrintArchive.subtask_id == subtask_id)
-                .where(PrintArchive.status.in_(["printing", "cancelled"]))
+                .where(PrintArchive.status == "printing")
                 .order_by(PrintArchive.created_at.desc())
                 .limit(1)
             )
-            candidate = by_id.scalar_one_or_none()
-            if candidate and (candidate.status == "printing" or (candidate.failure_reason or "").startswith("Stale")):
-                existing_archive = candidate
+            existing_archive = by_id.scalar_one_or_none()
 
         # Fallback match: name-based lookup. Kept as-is for prints whose
         # subtask_id is missing ("0" / local / non-cloud prints).
@@ -4957,21 +4955,11 @@ async def on_print_start(printer_id: int, data: dict):
 
         if existing_archive:
             # subtask_id match → always resume, regardless of age. Same print,
-            # just a backend restart. Revive if it was previously stale-cancelled.
+            # just a backend restart.
             subtask_match = bool(subtask_id and existing_archive.subtask_id == subtask_id)
 
             if subtask_match:
-                if existing_archive.status == "cancelled":
-                    logger.warning(
-                        "Reviving stale-cancelled archive %s — matching subtask_id %s confirms same print (#972)",
-                        existing_archive.id,
-                        subtask_id,
-                    )
-                    existing_archive.status = "printing"
-                    existing_archive.failure_reason = None
-                    await db.commit()
-                else:
-                    logger.info("Resuming archive %s on subtask_id match (%s)", existing_archive.id, subtask_id)
+                logger.info("Resuming archive %s on subtask_id match (%s)", existing_archive.id, subtask_id)
                 _active_prints[(printer_id, existing_archive.filename)] = existing_archive.id
                 if existing_archive.energy_start_kwh is None:
                     await _record_energy_start(existing_archive, printer_id, db, context="subtask-resume")
@@ -5000,10 +4988,42 @@ async def on_print_start(printer_id: int, data: dict):
             looks_stale = (
                 live_progress is not None and live_progress < 1.0 and archive_age.total_seconds() > 2 * 60 * 60
             )
+            # Two subtask ids are two prints, however young the archive: one
+            # whose completion was missed must not swallow the next print of
+            # the same file. Except Bambuddy's own reprint, which reuses the
+            # row and mints a fresh id (#1807): the id it last sent says so,
+            # and after a restart, which forgets it, this printer's queue job
+            # running the archive.
+            if (
+                not looks_stale
+                and subtask_id
+                and existing_archive.subtask_id
+                and existing_archive.subtask_id != subtask_id
+            ):
+                _client = printer_manager.get_client(printer_id)
+                _dispatched = str(getattr(_client, "last_dispatch_subtask_id", None) or "").strip()
+                if _dispatched:
+                    looks_stale = _dispatched != subtask_id
+                else:
+                    from backend.app.models.print_queue import PrintQueueItem as _PQI
+
+                    queue_run = await db.scalar(
+                        select(_PQI.id)
+                        .where(_PQI.archive_id == existing_archive.id)
+                        .where(_PQI.printer_id == printer_id)
+                        .where(_PQI.status == "printing")
+                        .limit(1)
+                    )
+                    looks_stale = queue_run is None
             if looks_stale:
                 logger.warning(
-                    f"Found stale 'printing' archive {existing_archive.id} (age: {archive_age}, "
-                    f"printer progress {live_progress:.0f}%) — marking cancelled and creating new archive"
+                    "Found stale 'printing' archive %s (age: %s, printer progress %s%%, subtask %s, printer reports %s)"
+                    " — marking cancelled and creating new archive",
+                    existing_archive.id,
+                    archive_age,
+                    live_progress,
+                    existing_archive.subtask_id,
+                    subtask_id,
                 )
                 existing_archive.status = "cancelled"
                 # Canonical key, not a sentence (issue #2974). "No status update
@@ -5014,6 +5034,9 @@ async def on_print_start(printer_id: int, data: dict):
                 # single bucket instead of two untranslatable prose strings.
                 existing_archive.failure_reason = "noStatusUpdate"
                 await db.commit()
+                # Its print keys go with it; the new archive registers its own.
+                for _key in [k for k, v in _active_prints.items() if v == existing_archive.id]:
+                    del _active_prints[_key]
                 # Fall through to create new archive (don't return)
             else:
                 logger.info(

backend/tests/integration/test_print_start_name_match_ap2.py

@@ -0,0 +1,241 @@
+"""A print matched to a 'printing' archive by name only is a new print when
+the subtask ids show it.
+
+An archive can be left in 'printing' when its completion was missed. Started
+again within two hours, the same file used to be folded into that archive:
+no new history entry, no timelapse, no cost estimate. Two different subtask
+ids are two prints, unless a queue job of this printer is running that
+archive: a Bambuddy reprint mints a fresh id for the same row (#1807).
+"""
+
+from contextlib import ExitStack
+from datetime import datetime, timedelta, timezone
+from unittest.mock import AsyncMock, MagicMock, patch
+
+import pytest
+from sqlalchemy import select
+from sqlalchemy.ext.asyncio import AsyncSession, async_sessionmaker
+
+from backend.app.main import (
+    _active_prints,
+    _expected_print_creators,
+    _expected_print_registered_at,
+    _expected_prints,
+    _print_ams_mappings,
+)
+from backend.app.models.archive import PrintArchive
+from backend.app.models.print_queue import PrintQueueItem
+
+DISPATCH = "/data/Metadata/plate_1.gcode"
+SUBTASK = "Bracket_plate_1"
+
+
+@pytest.fixture(autouse=True)
+def _clear_print_state():
+    dicts = (
+        _expected_prints,
+        _expected_print_registered_at,
+        _expected_print_creators,
+        _print_ams_mappings,
+        _active_prints,
+    )
+    for d in dicts:
+        d.clear()
+    yield
+    for d in dicts:
+        d.clear()
+
+
+async def _start(test_engine, printer_id: int, subtask_id: str, last_dispatch: str | None = None) -> None:
+    session_maker = async_sessionmaker(test_engine, class_=AsyncSession, expire_on_commit=False)
+    state = MagicMock(
+        current_project_url=f"ftp://{SUBTASK}.gcode.3mf",
+        sdcard=True,
+        sdcard_reported=True,
+        subtask_id=subtask_id,
+        progress=0.0,
+    )
+    patches = [
+        patch("backend.app.main.async_session", session_maker),
+        patch("backend.app.core.database.async_session", session_maker),
+        patch("backend.app.main.download_file_async", new=AsyncMock(return_value=False)),
+        patch("backend.app.main.download_file_try_paths_async", new=AsyncMock(return_value=None)),
+        patch("backend.app.main.get_cached_3mf", return_value=None),
+        patch("backend.app.main.cache_3mf_download"),
+        patch("backend.app.main.peek_plate_index_in_3mf", return_value=None),
+        patch("backend.app.services.bambu_ftp.list_files_async", new=AsyncMock(return_value=[])),
+        patch("backend.app.main.ftps_handshake_blocked", return_value=False),
+        patch("backend.app.main.get_ftp_retry_settings", new=AsyncMock(return_value=(False, 3, 2.0, 30))),
+        patch("backend.app.main._record_energy_start", new_callable=AsyncMock),
+        patch("backend.app.main._send_print_start_notification", new_callable=AsyncMock),
+        patch("backend.app.main._maybe_start_layer_timelapse"),
+        patch("backend.app.main._capture_timelapse_baseline_at_start", new_callable=AsyncMock),
+        patch("backend.app.main._schedule_fallback_3mf_retry"),
+        patch("backend.app.main._store_spoolman_print_data", new_callable=AsyncMock),
+        patch("backend.app.main._load_objects_from_archive"),
+        patch("backend.app.services.usage_tracker.on_print_start", new_callable=AsyncMock),
+    ]
+    with ExitStack() as stack:
+        for p in patches:
+            stack.enter_context(p)
+        notif = stack.enter_context(patch("backend.app.main.notification_service"))
+        plug = stack.enter_context(patch("backend.app.main.smart_plug_manager"))
+        ws = stack.enter_context(patch("backend.app.main.ws_manager"))
+        relay = stack.enter_context(patch("backend.app.main.mqtt_relay"))
+        pm = stack.enter_context(patch("backend.app.main.printer_manager"))
+        notif.on_print_start = AsyncMock()
+        plug.on_print_start = AsyncMock()
+        ws.send_print_start = AsyncMock()
+        ws.send_archive_created = AsyncMock()
+        ws.send_archive_updated = AsyncMock()
+        relay.on_print_start = AsyncMock()
+        relay.on_archive_created = AsyncMock()
+        pm.get_status = MagicMock(return_value=state)
+        pm.get_printer = MagicMock(return_value=MagicMock(serial_number="TESTAP2"))
+        pm.get_client = MagicMock(
+            return_value=MagicMock(last_dispatch_subtask_id=last_dispatch) if last_dispatch else None
+        )
+
+        from backend.app.main import on_print_start
+
+        await on_print_start(
+            printer_id, {"filename": DISPATCH, "subtask_name": SUBTASK, "raw_data": {"subtask_id": subtask_id}}
+        )
+
+
+async def _stuck_archive(db_session, printer_id: int, subtask_id: str | None) -> int:
+    archive = PrintArchive(
+        printer_id=printer_id,
+        filename=f"{SUBTASK}.gcode.3mf",
+        file_path=f"archives/test/{SUBTASK}.gcode.3mf",
+        file_size=2048,
+        print_name=SUBTASK,
+        status="printing",
+        subtask_id=subtask_id,
+        started_at=datetime.now(timezone.utc) - timedelta(minutes=30),
+    )
+    db_session.add(archive)
+    await db_session.commit()
+    return archive.id
+
+
+async def _archives(db_session, printer_id: int) -> list[PrintArchive]:
+    db_session.expire_all()
+    result = await db_session.execute(
+        select(PrintArchive).where(PrintArchive.printer_id == printer_id).order_by(PrintArchive.id)
+    )
+    return list(result.scalars().all())
+
+
+@pytest.mark.asyncio
+@pytest.mark.integration
+async def test_another_subtask_id_is_a_new_print(test_engine, db_session, printer_factory):
+    printer = await printer_factory()
+    stuck_id = await _stuck_archive(db_session, printer.id, "111")
+    _active_prints[(printer.id, f"{SUBTASK}.gcode.3mf")] = stuck_id
+    _active_prints[(printer.id, "old/plate_1.gcode")] = stuck_id
+
+    await _start(test_engine, printer.id, "222")
+
+    rows = await _archives(db_session, printer.id)
+    stuck = next(a for a in rows if a.id == stuck_id)
+    assert (stuck.status, stuck.failure_reason) == ("cancelled", "noStatusUpdate")
+    new = [a for a in rows if a.id != stuck_id]
+    assert len(new) == 1 and new[0].subtask_id == "222"
+    assert stuck_id not in _active_prints.values()
+
+
+@pytest.mark.asyncio
+@pytest.mark.integration
+async def test_a_queue_reprint_of_the_archive_resumes_it(test_engine, db_session, printer_factory):
+    printer = await printer_factory()
+    stuck_id = await _stuck_archive(db_session, printer.id, "111")
+    db_session.add(PrintQueueItem(printer_id=printer.id, archive_id=stuck_id, status="printing"))
+    await db_session.commit()
+
+    await _start(test_engine, printer.id, "222")
+
+    rows = await _archives(db_session, printer.id)
+    assert [(a.id, a.status, a.subtask_id) for a in rows] == [(stuck_id, "printing", "222")]
+
+
+@pytest.mark.asyncio
+@pytest.mark.integration
+async def test_an_archive_without_a_subtask_id_is_resumed(test_engine, db_session, printer_factory):
+    printer = await printer_factory()
+    stuck_id = await _stuck_archive(db_session, printer.id, None)
+
+    await _start(test_engine, printer.id, "222")
+
+    rows = await _archives(db_session, printer.id)
+    assert [(a.id, a.status, a.subtask_id) for a in rows] == [(stuck_id, "printing", "222")]
+
+
+@pytest.mark.asyncio
+@pytest.mark.integration
+async def test_a_cancelled_archive_with_the_same_subtask_id_is_not_reopened(test_engine, db_session, printer_factory):
+    """Completion already charged and logged it; reopening would do it twice."""
+    printer = await printer_factory()
+    old_id = await _stuck_archive(db_session, printer.id, "333")
+    old = await db_session.get(PrintArchive, old_id)
+    old.status, old.failure_reason = "cancelled", "noStatusUpdate"
+    await db_session.commit()
+
+    await _start(test_engine, printer.id, "333")
+
+    rows = await _archives(db_session, printer.id)
+    assert next(a for a in rows if a.id == old_id).status == "cancelled"
+    assert [a.subtask_id for a in rows if a.id != old_id] == ["333"]
+    assert old_id not in _active_prints.values()
+
+
+async def _queue_item(db_session, printer_id: int, archive_id: int, status: str = "printing") -> None:
+    db_session.add(PrintQueueItem(printer_id=printer_id, archive_id=archive_id, status=status))
+    await db_session.commit()
+
+
+@pytest.mark.asyncio
+@pytest.mark.integration
+async def test_a_queue_job_left_printing_does_not_take_another_print(test_engine, db_session, printer_factory):
+    """The archive's queue job stayed 'printing' with it, but Bambuddy's last
+    dispatch to this printer was another job id: this print is not that run."""
+    printer = await printer_factory()
+    stuck_id = await _stuck_archive(db_session, printer.id, "111")
+    await _queue_item(db_session, printer.id, stuck_id)
+
+    await _start(test_engine, printer.id, "222", last_dispatch="111")
+
+    rows = await _archives(db_session, printer.id)
+    assert next(a for a in rows if a.id == stuck_id).status == "cancelled"
+    assert [a.subtask_id for a in rows if a.id != stuck_id] == ["222"]
+
+
+@pytest.mark.asyncio
+@pytest.mark.integration
+async def test_the_dispatched_job_id_resumes_without_a_queue_lookup(test_engine, db_session, printer_factory):
+    printer = await printer_factory()
+    stuck_id = await _stuck_archive(db_session, printer.id, "111")
+    await _queue_item(db_session, printer.id, stuck_id)
+
+    await _start(test_engine, printer.id, "222", last_dispatch="222")
+
+    rows = await _archives(db_session, printer.id)
+    assert [(a.id, a.status, a.subtask_id) for a in rows] == [(stuck_id, "printing", "222")]
+
+
+@pytest.mark.asyncio
+@pytest.mark.integration
+@pytest.mark.parametrize("elsewhere", ["other_printer", "finished"])
+async def test_only_this_printers_running_queue_job_exempts(test_engine, db_session, printer_factory, elsewhere):
+    printer = await printer_factory()
+    stuck_id = await _stuck_archive(db_session, printer.id, "111")
+    if elsewhere == "other_printer":
+        other = await printer_factory()
+        await _queue_item(db_session, other.id, stuck_id)
+    else:
+        await _queue_item(db_session, printer.id, stuck_id, status="completed")
+
+    await _start(test_engine, printer.id, "222")
+
+    rows = await _archives(db_session, printer.id)
+    assert next(a for a in rows if a.id == stuck_id).status == "cancelled"

backend/tests/unit/test_subtask_archive_resume.py

@@ -114,7 +114,7 @@ class TestSubtaskIdResume:
             select(PrintArchive)
             .where(PrintArchive.printer_id == printer.id)
             .where(PrintArchive.subtask_id == "t-123")
-            .where(PrintArchive.status.in_(["printing", "cancelled"]))
+            .where(PrintArchive.status == "printing")
             .order_by(PrintArchive.created_at.desc())
             .limit(1)
         )
@@ -122,44 +122,6 @@ class TestSubtaskIdResume:
         assert found is not None
         assert found.id == archive.id
 
-    async def test_subtask_id_revives_stale_cancelled_row(self, archive_factory, db_session):
-        """If an older Bambuddy wrongly cancelled the archive (legacy 4h path),
-        the next print-start with the same subtask_id must revive it rather
-        than start a third row."""
-        printer, archive = await archive_factory(
-            subtask_id="t-456",
-            status="cancelled",
-            failure_reason="Stale - print likely cancelled or failed without status update",
-            age_hours=10,
-        )
-
-        result = await db_session.execute(
-            select(PrintArchive)
-            .where(PrintArchive.printer_id == printer.id)
-            .where(PrintArchive.subtask_id == "t-456")
-            .where(PrintArchive.status.in_(["printing", "cancelled"]))
-            .order_by(PrintArchive.created_at.desc())
-            .limit(1)
-        )
-        candidate = result.scalar_one_or_none()
-        assert candidate is not None
-
-        # Revival mirrors the main.py logic: only revive stale-cancelled rows,
-        # not user-cancelled ones. The failure_reason prefix is the signal.
-        is_stale_cancelled = (candidate.failure_reason or "").startswith("Stale")
-        assert is_stale_cancelled
-
-        candidate.status = "printing"
-        candidate.failure_reason = None
-        await db_session.commit()
-        await db_session.refresh(candidate)
-
-        assert candidate.status == "printing"
-        # Crucially, started_at is preserved — this is the whole point of the
-        # fix. A fresh archive would have started_at = now, losing continuity.
-        age_after = datetime.now(timezone.utc) - candidate.started_at.replace(tzinfo=timezone.utc)
-        assert age_after > timedelta(hours=9), "started_at must survive revival"
-
     async def test_subtask_id_null_does_not_match_other_nulls(self, archive_factory, db_session):
         """Two different non-cloud prints both have subtask_id=NULL. They
         must NOT match each other via the subtask_id lookup (which is why
@@ -175,16 +137,18 @@ class TestSubtaskIdResume:
         found = result.scalar_one_or_none()
         assert found is None, "Empty string must not match NULL rows"
 
-    async def test_completed_archive_not_resumed(self, archive_factory, db_session):
-        """A completed archive with the same subtask_id must not be reopened
-        as printing — that subtask's job is done; a new run is a new row."""
-        printer, _ = await archive_factory(subtask_id="t-789", status="completed")
+    @pytest.mark.parametrize("status", ["completed", "cancelled"])
+    async def test_finished_archive_not_resumed(self, archive_factory, db_session, status):
+        """A finished archive with the same subtask_id must not be reopened
+        as printing: completion has already charged and logged it, so a new
+        run is a new row."""
+        printer, _ = await archive_factory(subtask_id="t-789", status=status, failure_reason="noStatusUpdate")
 
         result = await db_session.execute(
             select(PrintArchive)
             .where(PrintArchive.printer_id == printer.id)
             .where(PrintArchive.subtask_id == "t-789")
-            .where(PrintArchive.status.in_(["printing", "cancelled"]))
+            .where(PrintArchive.status == "printing")
         )
         found = result.scalar_one_or_none()
         assert found is None