Find the file of a print started from the printer's screen on the first try (#3009)

CHANGELOG.md

@@ -138,6 +138,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 started from the printer's screen took about six seconds longer to archive (#3009, reported by @bdwilson)** — A job started on the printer's own screen reports its file's full name, extension included (`Part.3mf`), where a job Bambuddy sends reports the bare name. Bambuddy added the extensions to it anyway and asked the printer for `Part.3mf.gcode.3mf` and `Part.3mf.3mf` first, six connections that could not succeed, before trying the real file. The check that reattaches a running print after a Bambuddy restart compared against the same doubled name, so it could not find such a print. When the printer reports the same full name as both the job and its file, that name is now taken as the file itself: it is the only name tried, and the restart check also matches that exact file. Prints Bambuddy dispatches are looked up as before.
 - **A queue job stayed "printing" for five minutes when its file name ended in a space (#3241, reported by @Thomansky)** — A file saved as `Part .gcode.3mf` is sent to the printer as `Part `, and the printer reports it back as `Part_`, turning that space into an underscore like every other. Bambuddy dropped the space from its own side before comparing, so the names differed, the finish was ignored as belonging to another print, and the job showed "printing" until the stale-job cleanup closed it about five minutes later, holding up the printer's next job. The finish photo's plate restore skipped these prints for the same reason. A space at the start of the name had the same effect. Both are now matched.
 - **The finish photo never raised the plate back into view (#3240, reported by @Thomansky)** — Since 1.2.5.2, Bambuddy is meant to raise the build plate back to just above the finished print before the finish photo, then lower it again, because the printer's end G-code drops the plate about 100 mm. It never did, on any printer: the lookup for the print's height failed every time and logged nothing above debug level. It read the archived file from a setting that does not exist, and it matched the archive by exact name, while the printer reports a name with its spaces turned into underscores. Both are fixed, so the plate now really moves after a print when **Restore plate for finish photo** is on, which it is by default. Turn it off under **Settings** > **General** to keep the photo where the plate stops. Because the plate now really moves, the print's height is taken only from the archive Bambuddy linked to that print when it started, and from the plate that was sent, never from another archive that merely has the same name: every plate of a multi-plate file shares one name, and support bundles showed the old lookup picking another plate's archive, stopped only by its layer count. That archive must also match the print's name exactly, never part of it or a shortened version; its layer count must agree with the printer's; and the plate stays put when another job is queued for the printer or the print was not linked to an archive.
 - **An "Any model" job was held for too little filament on one printer while another idle printer of that model had plenty (#3137, reported by @RambachTJ)** — The queue gave a job queued for **Any H2D Pro** (or any model) to the first idle printer with the right filament type, and only then checked whether its spools held enough. When they did not, the job waited on that printer for a manual start, even though another idle printer of the same model could run it; the only way out was to move it by hand. The queue now passes over a printer that would run short and gives the job to one that has enough. If every idle printer would run short, the job still waits on the first, where **Print Anyway** works as before, and moves by itself once another idle printer of its model has enough filament, on record in Inventory or Spoolman.

backend/app/main.py

@@ -4594,6 +4594,12 @@ async def on_print_start(printer_id: int, data: dict):
         # subtask_id is missing ("0" / local / non-cloud prints).
         if existing_archive is None:
             check_name = subtask_name or filename.split("/")[-1].replace(".gcode", "").replace(".3mf", "")
+            archive_filenames = [f"{check_name}.3mf", f"{check_name}.gcode.3mf"]
+            # A print started from the printer's screen names its file in full,
+            # so the forms above double its extension. The file itself is the
+            # one exact match, and nothing looser is added (#3009).
+            if _subtask_is_the_file(subtask_name, filename):
+                archive_filenames.append(subtask_name)
             existing = await db.execute(
                 select(PrintArchive)
                 .where(PrintArchive.printer_id == printer_id)
@@ -4601,12 +4607,7 @@ async def on_print_start(printer_id: int, data: dict):
                 .where(
                     or_(
                         PrintArchive.print_name == check_name,
-                        PrintArchive.filename.in_(
-                            [
-                                f"{check_name}.3mf",
-                                f"{check_name}.gcode.3mf",
-                            ]
-                        ),
+                        PrintArchive.filename.in_(archive_filenames),
                     )
                 )
                 .order_by(PrintArchive.created_at.desc())
@@ -4707,9 +4708,15 @@ async def on_print_start(printer_id: int, data: dict):
         # Bambu printers typically store files as "Name.gcode.3mf"
         # The subtask_name is usually the best source for the filename
         if subtask_name:
-            # Try common Bambu naming patterns
-            possible_names.append(f"{subtask_name}.gcode.3mf")
-            possible_names.append(f"{subtask_name}.3mf")
+            if _subtask_is_the_file(subtask_name, filename):
+                # A print started from the printer's own screen reports the
+                # file's full name, extension included. That is the file, so
+                # no extension is appended to it (#3009).
+                possible_names.append(subtask_name)
+            else:
+                # Try common Bambu naming patterns
+                possible_names.append(f"{subtask_name}.gcode.3mf")
+                possible_names.append(f"{subtask_name}.3mf")
 
         # Try original filename with .3mf extension
         if filename:
@@ -7058,6 +7065,19 @@ def _subtask_name_from_filename(filename: str) -> str:
     return name
 
 
+def _subtask_is_the_file(subtask_name: str, filename: str) -> bool:
+    """Whether the subtask name is the printed 3MF's own file name.
+
+    A print started from the printer's screen reports the same full name, with
+    its extension, as both subtask and file (#3009). A dispatched print reports
+    a bare subtask name; one that merely ends in ".3mf" can be a model named
+    that, whose file is ``Foo.3mf.gcode.3mf``, so it does not count.
+    """
+    if not subtask_name or not subtask_name.lower().endswith(".3mf"):
+        return False
+    return PurePosixPath((filename or "").split("://", 1)[-1]).name == subtask_name
+
+
 # How the printer marks a subtask name it had to cut short. Observed on real
 # hardware at ~100 characters, but the cut-off is not a fixed character count
 # (a name with multibyte characters came back at 98), so match the marker

backend/tests/unit/test_print_start_subtask_with_extension_3009.py

@@ -0,0 +1,251 @@
+"""A print started from the printer's own screen names its file in full (#3009).
+
+A job Bambuddy dispatches carries a bare subtask name, and the 3MF lookup
+appends the extensions to it. A job started on the printer's touchscreen
+reports the file's own name, extension included, so the lookup asked for
+``X.3mf.gcode.3mf`` and ``X.3mf.3mf`` first -- six connections, about six
+seconds, that could not succeed -- and the existing-archive check compared
+against ``X.3mf.3mf`` and could never reattach such a print after a restart.
+The name is from a reporter's A1 log.
+"""
+
+import re
+from unittest.mock import AsyncMock, MagicMock, patch
+
+import pytest
+
+from backend.app.main import (
+    _active_prints,
+    _expected_print_creators,
+    _expected_print_registered_at,
+    _expected_prints,
+    _print_ams_mappings,
+    _timelapse_baselines,
+)
+
+pytestmark = pytest.mark.unit
+
+NAME = "A1-Siraya_Tech_TPU-64D-18JAN26"
+
+
+@pytest.fixture(autouse=True)
+def _clear_dicts():
+    dicts = (
+        _expected_prints,
+        _expected_print_registered_at,
+        _expected_print_creators,
+        _print_ams_mappings,
+        _active_prints,
+        _timelapse_baselines,
+    )
+    for d in dicts:
+        d.clear()
+    yield
+    for d in dicts:
+        d.clear()
+
+
+def _printer():
+    printer = MagicMock()
+    printer.id = 1
+    printer.auto_archive = True
+    printer.external_camera_enabled = False
+    printer.external_camera_url = None
+    printer.plate_detection_enabled = False
+    printer.name = "A1"
+    printer.model = "A1"
+    printer.ip_address = "192.168.1.117"
+    printer.access_code = "12345678"
+    return printer
+
+
+async def _run_print_start(subtask_name, filename):
+    """Drive on_print_start with every FTP path answering 550, and return the
+    remote paths it tried, in order, and the SQL it ran."""
+    printer = _printer()
+    statements = []
+
+    def execute_router(stmt, *args, **kwargs):
+        statements.append(stmt)
+        sql = str(stmt).lower()
+        if "from printers" in sql or "from printer " in sql:
+            return MagicMock(
+                scalar_one_or_none=MagicMock(return_value=printer),
+                scalars=MagicMock(return_value=MagicMock(all=MagicMock(return_value=[printer]))),
+            )
+        return MagicMock(
+            scalar_one_or_none=MagicMock(return_value=None),
+            scalars=MagicMock(return_value=MagicMock(all=MagicMock(return_value=[]))),
+        )
+
+    session = AsyncMock()
+    session.__aenter__ = AsyncMock(return_value=session)
+    session.__aexit__ = AsyncMock()
+    session.execute = AsyncMock(side_effect=execute_router)
+    session.commit = AsyncMock()
+    session.refresh = AsyncMock()
+    session.add = MagicMock()
+
+    from backend.app.services.bambu_ftp import FileNotOnPrinterError
+
+    download = AsyncMock(side_effect=FileNotOnPrinterError("550"))
+    state = MagicMock(current_project_url=f"ftp://{filename}", sdcard=True, sdcard_reported=True)
+
+    with (
+        patch("backend.app.main.async_session") as session_maker,
+        patch("backend.app.main.notification_service") as notif,
+        patch("backend.app.main.smart_plug_manager") as plug,
+        patch("backend.app.main.ws_manager") as ws,
+        patch("backend.app.main.mqtt_relay") as relay,
+        patch("backend.app.main.printer_manager") as pm,
+        patch("backend.app.main.download_file_async", new=download),
+        patch("backend.app.main.download_file_try_paths_async", new=AsyncMock(return_value=None)),
+        patch("backend.app.main.with_ftp_retry", new=AsyncMock(return_value=False)),
+        patch("backend.app.main.get_cached_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", new=MagicMock()),
+    ):
+        session_maker.return_value = session
+        notif.on_print_start = AsyncMock()
+        plug.on_print_start = AsyncMock()
+        ws.send_print_start = AsyncMock()
+        ws.send_archive_updated = AsyncMock()
+        ws.send_archive_created = AsyncMock()
+        relay.on_print_start = AsyncMock()
+        pm.get_status = MagicMock(return_value=state)
+        pm.get_printer = MagicMock(return_value=MagicMock(serial_number="TEST3009"))
+
+        from backend.app.main import on_print_start
+
+        await on_print_start(1, {"filename": filename, "subtask_name": subtask_name})
+
+    tried = [call.args[2] for call in download.await_args_list]
+    return tried, statements
+
+
+def _existing_archive_lookup(statements):
+    """The literal SQL of the name-based check for a printing archive to reattach."""
+    for stmt in statements:
+        try:
+            sql = str(stmt.compile(compile_kwargs={"literal_binds": True}))
+        except Exception:
+            continue
+        if "print_archives" in sql and "print_name" in sql and "printing" in sql:
+            return sql
+    return None
+
+
+@pytest.mark.asyncio
+async def test_a_subtask_with_its_extension_is_tried_as_the_file_itself_first():
+    tried, _ = await _run_print_start(f"{NAME}.3mf", f"{NAME}.3mf")
+
+    assert tried[0] == f"/{NAME}.3mf"
+
+
+@pytest.mark.asyncio
+async def test_no_second_extension_is_appended_to_it():
+    tried, _ = await _run_print_start(f"{NAME}.3mf", f"{NAME}.3mf")
+
+    assert not [p for p in tried if ".3mf.gcode.3mf" in p or ".3mf.3mf" in p]
+
+
+@pytest.mark.asyncio
+async def test_only_the_reported_file_is_tried():
+    """The printer named the file, so no other name is guessed at -- the list
+    is the old one minus the two that could not exist."""
+    tried, _ = await _run_print_start(f"{NAME}.3mf", f"{NAME}.3mf")
+
+    assert {p.rsplit("/", 1)[-1] for p in tried} == {f"{NAME}.3mf"}
+
+
+def _archive_filenames(sql):
+    """The file names the existing-archive check accepts."""
+    match = re.search(r"filename IN \(([^)]*)\)", sql)
+    assert match, sql
+    return {name.strip().strip("'") for name in match.group(1).split(",")}
+
+
+@pytest.mark.asyncio
+async def test_the_existing_archive_check_also_accepts_the_file_itself():
+    _, statements = await _run_print_start(f"{NAME}.3mf", f"{NAME}.3mf")
+
+    assert f"{NAME}.3mf" in _archive_filenames(_existing_archive_lookup(statements))
+
+
+@pytest.mark.asyncio
+async def test_the_existing_archive_check_gets_nothing_looser():
+    """A leftover 'printing' archive of another file with the same base name
+    must not swallow this print: a match with progress is taken as the same
+    print and no new archive is made."""
+    _, statements = await _run_print_start(f"{NAME}.3mf", f"{NAME}.3mf")
+
+    sql = _existing_archive_lookup(statements)
+    assert f"{NAME}.gcode.3mf" not in _archive_filenames(sql)
+    assert f"print_archives.print_name = '{NAME}.3mf'" in sql
+
+
+@pytest.mark.asyncio
+async def test_a_bare_subtask_is_looked_up_exactly_as_before():
+    """The dispatched case, which is every queue and slicer print."""
+    tried, _ = await _run_print_start(NAME, f"{NAME}.gcode.3mf")
+
+    assert tried[0] == f"/{NAME}.gcode.3mf"
+    assert f"/{NAME}.3mf" in tried
+
+
+@pytest.mark.asyncio
+async def test_a_dot_inside_the_model_name_is_kept():
+    tried, _ = await _run_print_start("My.Model", "My.Model.gcode.3mf")
+
+    assert tried[0] == "/My.Model.gcode.3mf"
+
+
+@pytest.mark.asyncio
+async def test_a_dispatched_model_named_with_3mf_keeps_the_old_order():
+    """A model can be named "Foo.3mf"; its file is then Foo.3mf.gcode.3mf. The
+    printer reports a different file than the subtask, so nothing about the
+    name says the extension is the file's own, and a stale Foo.3mf on the card
+    must not be tried first."""
+    tried, statements = await _run_print_start("Foo.3mf", "/data/Metadata/plate_1.gcode")
+
+    assert tried[0] == "/Foo.3mf.gcode.3mf"
+    assert "/Foo.gcode.3mf" not in tried
+    assert _archive_filenames(_existing_archive_lookup(statements)) == {"Foo.3mf.3mf", "Foo.3mf.gcode.3mf"}
+
+
+class TestSubtaskIsTheFile:
+    @pytest.mark.parametrize(
+        "subtask,filename",
+        [
+            (f"{NAME}.3mf", f"{NAME}.3mf"),
+            (f"{NAME}.gcode.3mf", f"{NAME}.gcode.3mf"),
+            ("Part.3mf", "/sdcard/Part.3mf"),
+            ("Part.3mf", "ftp://Part.3mf"),
+        ],
+    )
+    def test_the_same_name_as_the_file(self, subtask, filename):
+        from backend.app.main import _subtask_is_the_file
+
+        assert _subtask_is_the_file(subtask, filename)
+
+    @pytest.mark.parametrize(
+        "subtask,filename",
+        [
+            (NAME, f"{NAME}.gcode.3mf"),
+            ("Foo.3mf", "/data/Metadata/plate_1.gcode"),
+            ("Foo.3mf", "Bar.3mf"),
+            ("Part.gcode", "Part.gcode"),
+            ("", ""),
+            ("Part.3mf", None),
+        ],
+    )
+    def test_anything_else(self, subtask, filename):
+        from backend.app.main import _subtask_is_the_file
+
+        assert not _subtask_is_the_file(subtask, filename)