Bladeren bron

Stop auto K-profile calibration leaving an archive behind

With flow dynamics calibration on, the printer lays down a
pressure-advance line before the print itself and announces it over MQTT
through the same print-start event a real print uses. Bambuddy archived
it: a row named auto_pa_line_calib_mode marked as having no 3MF, sitting
in among the user's actual prints, with a Print Started and a Print
Completed notification for each one.

The printer's other internal jobs were already skipped, but only by the
/usr/ path they carry -- bed levelling reports as
/usr/etc/print/auto_cali_for_user.gcode. The pressure-advance line
carries no path at all. It arrives as a bare subtask name, so a rule
that only ever looked at the filename could not see it. Falling past the
guard it reached the no-3MF fallback, where print_name is subtask_name
or filename, and named the row after the calibration.

Internal jobs are now recognised by name as well as by path, from either
field, in one place both callbacks share. The match is exact after
normalising away the directory, one print-file suffix and case, rather
than a prefix or substring rule: "auto" and "calib" are ordinary words in
a user's own filenames, and a rule loose enough to catch some unnamed
future calibration would quietly swallow somebody's print.

The completion is suppressed too, and that half matters more than the
noise. With no archive to close, the completion falls into the
no-archive notification path -- which attributes an unmatched completion
to any queue item the printer finished in the last five minutes and
emails its owner. This calibration runs alongside a real print, so
silencing only the start would have told that print's owner their job
was done, early, and again for real later. The guard sits inside the
no-archive branch, so the plate-clear gate, the queue reconciliation and
the SD-card cleanup all still run; only the notification is skipped.

Skipping the run early also drops the FTP sweep that preceded the
fallback -- six candidate names across five directories with retries,
around a hundred connections looking for a file that cannot exist, aimed
at a printer that is in the middle of calibrating.

auto_cali_for_user no longer sends a Print Started notification either.
It is the same event about the same kind of job, and the archive was
never the only thing wrong with treating it as a user's print.
maziggy 3 weken geleden
bovenliggende
commit
9c93884397

+ 1 - 0
CHANGELOG.md

@@ -5,6 +5,7 @@ All notable changes to Bambuddy will be documented in this file.
 ## [1.2.6b1] - Unreleased
 
 ### Fixed
+- **Auto K-profile calibration no longer leaves an archive behind** — When flow dynamics calibration is on, the printer lays down a pressure-advance line before the print itself. It announces that over MQTT through the same print-start event a real print uses, so Bambuddy archived it: a row named `auto_pa_line_calib_mode`, marked as having no 3MF, in among your actual prints, plus a "Print started" and a "Print completed" notification for each one. Bambuddy has always skipped the printer's other internal jobs, but only by spotting the `/usr/` path they carry — and this one arrives as a bare subtask name with no path at all, so it went straight past. It is now recognised by name, from either field the printer might report it in, and matched exactly so that a file you have deliberately named after the calibration is still your file. The completion is quiet too, which matters more than the noise: with no archive to close, it would have fallen into the path that attributes an unmatched completion to any job the printer finished in the last five minutes — and a calibration that runs alongside a real print would have told that print's owner it was done, early. Skipping the run early also saves the pointless FTP sweep for a 3MF that cannot exist, roughly a hundred connections to a printer that is mid-calibration. Covered by backend tests.
 - **A printer being busy or offline no longer blocks printing from its card (#2849)** — Dragging a sliced file onto a printer card refused the drop unless the printer was connected and neither printing nor paused, showing a red "Printer busy" and discarding the file; the card's **Print** button disappeared under the same condition. The workaround was to upload to the File Manager and queue it from there by hand, which is the same thing with more steps. It was never a real restriction: every print Bambuddy sends becomes a queue item, and dropping onto an idle printer only looks instant because the scheduler dispatches it right away. Both routes now work whatever the printer is doing, and a busy one simply queues the job. Offline printers are included, so you can queue work for a machine that is powered down and have it dispatch when it reconnects. The overlay says which you are getting — "Drop to print" when the job would start immediately, "Drop to queue" when it would wait, covering a print in progress, a paused job, an AMS mid-drying and a plate not yet cleared. That wording comes from the same check the Print Modal uses for its own "will start later" notice, so the card and the modal cannot disagree. The drop is also now gated on the permissions the flow actually uses, **Library Upload** and **Queue Create**, matching the Print button beside it; it previously checked Printer Control, which meant someone holding that but neither of the others got the file uploaded and then rejected by the queue, leaving it stranded in the library. Translated in all locales; wiki updated. Covered by frontend tests.
 - **Drying an AMS no longer sends an hourly "temperature high" alert for the whole cycle (#1802)** — The AMS temperature alert compares against the same threshold that colours the printer card, which defaults to 35 C, while drying deliberately runs at 45 C for PLA, 65 C for PETG and up to 85 C on an AMS-HT. The alert repeats once an hour for as long as the condition holds, so a twelve-hour dry sent twelve notifications about a temperature you asked for, and then kept sending them while the unit cooled back down. The alert is now held back for the length of a cycle and through the cool-down that follows it, using the drying state the firmware already reports rather than anything you have to configure. Suppression lifts as soon as the unit reads back at or below your threshold, so a 65 C cycle in a cold basement and a 45 C one in a warm room each get exactly the cool-down they need instead of a fixed guess. Two things are deliberately left alone: the humidity alert, which is the one you want during drying because the number falling is the point, and a unit reporting `HeatOutOfControl`, where an AMS that has lost thermal control is precisely when the alert should still reach you. Because a cycle plus its cool-down can outlast a restart, the suppression is stored rather than held in memory. No new setting — the alert simply stops firing for heat you asked for. Wiki updated. Covered by backend tests.
 - **Closing the bug-report panel no longer throws the capture away and leaves the logs running (#2847)** — Step 2 of the report flow asks you to reproduce the problem, and the panel sits over the part of the app you have to reach to do it. Closing it was the obvious move and it was the wrong one twice over. Reopening put you back on an empty step 1 — while the server was still logging at DEBUG, with nothing left in the flow that could stop it, because only **Stop & Submit** ever did. Leave it closed instead and the five-minute cap eventually fired behind your back: logging stopped and the report was filed with no window open and no confirmation that it had happened. Which of the two you got depended only on whether you reopened the panel inside five minutes. A capture is now a thing that outlives the panel. Closing keeps it running and says so — the bug button turns amber for as long as a capture is going, and clicking it returns you to step 2 with your description, your screenshot and the elapsed timer where you left them. If the cap does fire while the panel is closed, the panel reopens so the submission happens in front of you rather than behind you. The timer is measured against the capture's start time rather than counted in ticks, so a background tab, where browsers throttle timers hard, no longer stretches five minutes into something else. A capture also survives a page reload, which matters because reloading is a perfectly ordinary step in reproducing a bug: the report picks it back up where it was. One that outlived the cap while nobody was watching is not resumed and not filed — a description written an hour ago is not a report you are still expecting — but the log level is put back, which is the part that previously stayed wrong indefinitely. Translated in all locales; wiki updated. Covered by frontend tests.

+ 33 - 6
backend/app/main.py

@@ -129,6 +129,7 @@ from backend.app.services.spoolman_tracking import (
 )
 from backend.app.services.tasmota import tasmota_service
 from backend.app.utils.ams_drying import is_drying_active, temperature_alarm_suppressed
+from backend.app.utils.print_jobs import is_internal_printer_job
 
 
 # =============================================================================
@@ -3043,12 +3044,21 @@ async def on_print_start(printer_id: int, data: dict):
 
         logger.info("[CALLBACK] Print start detected - filename: %s, subtask: %s", filename, subtask_name)
 
-        # Skip calibration prints — internal printer files should not be archived
-        # Bambu calibration gcode lives under /usr/ (e.g. /usr/etc/print/auto_cali_for_user.gcode)
-        if filename and filename.startswith("/usr/"):
-            logger.info("[CALLBACK] Skipping archive — internal printer file detected: %s", filename)
-            if not notification_sent:
-                await _send_print_start_notification(printer_id, data, logger=logger)
+        # Skip the printer's own jobs — a calibration run is not a user's print.
+        # See is_internal_printer_job for what counts and why both fields are
+        # tested; the pressure-advance line reports as a subtask name with no
+        # /usr/ path, which the old prefix-only test here missed entirely.
+        #
+        # No notification either. The event describes the printer calibrating
+        # itself, so "Print started" is as wrong as the archive was, and the
+        # matching completion is suppressed in on_print_complete for the same
+        # reason.
+        if is_internal_printer_job(filename, subtask_name):
+            logger.info(
+                "[CALLBACK] Skipping archive — internal printer job detected: filename=%s, subtask=%s",
+                filename,
+                subtask_name,
+            )
             return
 
         if not filename and not subtask_name:
@@ -5875,6 +5885,23 @@ async def on_print_complete(printer_id: int, data: dict):
     log_timing("Filament usage tracking")
 
     if not archive_id:
+        # The printer's own calibration run has no archive by design, so this
+        # arrives here every time one finishes. Returning before the no-archive
+        # notification is not just noise control: that path attributes an
+        # unmatched completion to any queue item this printer finished in the
+        # last five minutes, which for a calibration that runs alongside a real
+        # print means emailing its owner that their print is done, twice and
+        # early. Everything above this point has already run — the plate-clear
+        # gate, the queue reconciliation, the SD-card cleanup — so only the
+        # notification is skipped.
+        if is_internal_printer_job(filename, subtask_name):
+            logger.info(
+                "[CALLBACK] Internal printer job completed, no notification: filename=%s, subtask=%s",
+                filename,
+                subtask_name,
+            )
+            return
+
         logger.warning("Could not find archive for print complete: filename=%s, subtask=%s", filename, subtask_name)
 
         # Still send print-complete/failed/stopped notifications even without an archive.

+ 72 - 0
backend/app/utils/print_jobs.py

@@ -0,0 +1,72 @@
+"""Telling the printer's own internal jobs apart from a user's print.
+
+Bambu firmware runs jobs on its own behalf -- bed levelling, vibration
+compensation, the pressure-advance line it lays down before a print when flow
+dynamics calibration is on -- and reports them over MQTT through exactly the
+same print-start and print-complete events a real print uses. Nothing about the
+event says "this one is mine": Bambuddy has to recognise the job by name.
+
+Getting that wrong is not free. An unrecognised calibration run has no 3MF
+anywhere on the printer, so the archive path sweeps FTP for a file that cannot
+exist -- six candidate names across five directories, with retries -- and then
+writes a no-3MF archive named after the calibration, on a printer that is in
+the middle of calibrating.
+
+Kept as a leaf module with no imports of its own so both the print-start and
+print-complete callbacks can share one answer.
+"""
+
+# Job names the printer runs for itself. Matched exactly (after normalising),
+# not by prefix or substring: "auto" and "calib" are ordinary words in a user's
+# own filenames, and a rule loose enough to catch an unnamed future calibration
+# would silently swallow somebody's print.
+#
+# ``auto_cali_for_user`` is the bed-levelling / vibration run, normally reported
+# with a ``/usr/etc/print/`` path that the rule below catches on its own; it is
+# listed anyway because the path is not guaranteed and a name-only report of it
+# would otherwise slip through.
+#
+# ``auto_pa_line_calib_mode`` is the pressure-advance (K profile) line. This one
+# is reported as a *subtask name* with no ``/usr/`` path at all, which is why
+# the path rule alone was never enough.
+INTERNAL_JOB_NAMES = frozenset(
+    {
+        "auto_cali_for_user",
+        "auto_pa_line_calib_mode",
+    }
+)
+
+# Longest first: ``.gcode.3mf`` has to be stripped whole, or ``.3mf`` would
+# match first and leave a trailing ``.gcode`` behind.
+_PRINT_SUFFIXES = (".gcode.3mf", ".gcode", ".3mf")
+
+
+def _normalize_job_name(value: str) -> str:
+    """Reduce a reported name to something comparable against the set above.
+
+    Drops any directory part, one print-file suffix, and case. The printer is
+    not consistent about which of these it includes -- the same calibration
+    reports as a bare name in ``subtask_name`` and, when it appears at all, as
+    a full path in ``gcode_file``.
+    """
+    name = value.rsplit("/", 1)[-1].rsplit("\\", 1)[-1].strip().casefold()
+    for suffix in _PRINT_SUFFIXES:
+        if name.endswith(suffix):
+            return name[: -len(suffix)]
+    return name
+
+
+def is_internal_printer_job(filename: str | None, subtask_name: str | None = None) -> bool:
+    """True when this print event belongs to the printer, not to a user.
+
+    Both fields are tested because neither is reliably populated: the
+    pressure-advance line arrives as a subtask name with no filename, while the
+    levelling run arrives as a ``/usr/etc/print/...`` path. A job is internal if
+    *either* field says so.
+    """
+    if filename and filename.startswith("/usr/"):
+        # Bambu keeps its own calibration gcode on the read-only system
+        # partition. Nothing a user can print ever lives there, so the whole
+        # prefix is safe to treat as internal without naming each file.
+        return True
+    return any(_normalize_job_name(value) in INTERNAL_JOB_NAMES for value in (filename, subtask_name) if value)

+ 8 - 5
backend/tests/unit/test_archive_filtering.py

@@ -59,13 +59,16 @@ class TestCalibrationPrintFiltering:
                     },
                 )
 
-                # Notification should still be sent
-                mock_notif_send.assert_called_once()
+                # And no notification. The event describes the printer
+                # calibrating itself, so "Print started: auto_cali_for_user" is
+                # as wrong as the archive would have been. This assertion used
+                # to demand the opposite.
+                mock_notif_send.assert_not_called()
 
         # Verify the skip was logged
         info_messages = [r.message for r in capture_logs.records if r.levelno >= 20]
-        skip_msgs = [m for m in info_messages if "internal printer file" in str(m)]
-        assert skip_msgs, "Should log that internal printer file was skipped"
+        skip_msgs = [m for m in info_messages if "internal printer job" in str(m)]
+        assert skip_msgs, "Should log that an internal printer job was skipped"
 
     @pytest.mark.asyncio
     async def test_usr_prefix_various_paths(self, capture_logs):
@@ -108,7 +111,7 @@ class TestCalibrationPrintFiltering:
 
                 await on_print_start(1, {"filename": path, "subtask_name": "test"})
 
-            skip_msgs = [r for r in capture_logs.records if "internal printer file" in str(r.message)]
+            skip_msgs = [r for r in capture_logs.records if "internal printer job" in str(r.message)]
             assert skip_msgs, f"Path {path} should be skipped"
             capture_logs.clear()
 

+ 212 - 0
backend/tests/unit/test_internal_printer_jobs.py

@@ -0,0 +1,212 @@
+"""The printer's own calibration runs leave no archive and send no notification.
+
+Auto pressure-advance calibration -- the K-profile line the printer lays down
+before a print when flow dynamics calibration is on -- reports over MQTT through
+the same print-start event a real print uses, as the subtask name
+``auto_pa_line_calib_mode`` with no ``/usr/`` path attached. The only guard
+Bambuddy had tested ``filename.startswith("/usr/")``, so the calibration sailed
+past it, found no 3MF anywhere on the printer (there is none to find), and left
+a no-3MF archive named after itself in the user's history.
+
+The same name is already known to the completion guard: #2829's capture of
+queue item 649 has ``auto_pa_line_calib_mode`` arriving as the subtask name of a
+completion that had to be refused against a running job.
+"""
+
+from unittest.mock import AsyncMock, MagicMock, patch
+
+import pytest
+
+from backend.app.utils.print_jobs import is_internal_printer_job
+
+
+class TestTheCalibrationIsRecognised:
+    def test_the_pressure_advance_line_by_subtask_name(self):
+        """How it actually arrives: a bare subtask name, no filename at all."""
+        assert is_internal_printer_job("", "auto_pa_line_calib_mode")
+
+    def test_the_pressure_advance_line_by_filename(self):
+        """Both fields are tested, because which one carries it is not fixed."""
+        assert is_internal_printer_job("auto_pa_line_calib_mode", None)
+
+    def test_the_levelling_run_by_its_system_path(self):
+        assert is_internal_printer_job("/usr/etc/print/auto_cali_for_user.gcode", "auto_cali_for_user")
+
+    def test_the_levelling_run_by_name_alone(self):
+        """The /usr/ path is not guaranteed, so the name is listed too."""
+        assert is_internal_printer_job(None, "auto_cali_for_user")
+
+    @pytest.mark.parametrize(
+        "reported",
+        [
+            "auto_pa_line_calib_mode",
+            "auto_pa_line_calib_mode.gcode",
+            "auto_pa_line_calib_mode.3mf",
+            "auto_pa_line_calib_mode.gcode.3mf",
+            "AUTO_PA_LINE_CALIB_MODE",
+            "/data/auto_pa_line_calib_mode.gcode.3mf",
+        ],
+    )
+    def test_however_the_name_is_dressed_up(self, reported):
+        """Path, suffix and case all vary between the fields and firmwares."""
+        assert is_internal_printer_job(reported, None)
+
+    def test_anything_under_usr_counts(self):
+        """Nothing a user can print lives on the read-only system partition."""
+        assert is_internal_printer_job("/usr/bin/firmware_test.gcode", "test")
+
+
+class TestItLeavesRealPrintsAlone:
+    """The failure that matters: swallowing somebody's actual print."""
+
+    def test_an_ordinary_print(self):
+        assert not is_internal_printer_job("Benchy.gcode.3mf", "Benchy")
+
+    def test_nothing_reported_at_all(self):
+        assert not is_internal_printer_job(None, None)
+        assert not is_internal_printer_job("", "")
+
+    @pytest.mark.parametrize(
+        "reported",
+        [
+            "auto_pa_line_calib_mode_v2.3mf",
+            "my_auto_pa_line_calib_mode.3mf",
+            "auto_cali_for_user_test.gcode.3mf",
+        ],
+    )
+    def test_a_users_file_that_merely_contains_the_name(self, reported):
+        """Exact match after normalising, so no prefix or substring rule can
+        eat a file somebody deliberately named after the calibration."""
+        assert not is_internal_printer_job(reported, None)
+
+    def test_a_calibration_cube(self):
+        """The obvious false positive for any rule built on the word 'calib'."""
+        assert not is_internal_printer_job("Calibration_Cube.gcode.3mf", "Calibration Cube")
+
+
+def _mocked_print_start():
+    """Patch set for driving on_print_start without a printer or database."""
+    return (
+        patch("backend.app.main.async_session"),
+        patch("backend.app.main.notification_service"),
+        patch("backend.app.main.smart_plug_manager"),
+        patch("backend.app.main.ws_manager"),
+        patch("backend.app.main.printer_manager"),
+        patch("backend.app.main.mqtt_relay"),
+    )
+
+
+class TestPrintStartSkipsTheCalibration:
+    @pytest.mark.asyncio
+    async def test_no_archive_and_no_notification(self, capture_logs):
+        sess, notif, plug, ws, pm, relay = _mocked_print_start()
+        with sess as mock_session_maker, notif as mock_notif, plug as mock_plug, ws as mock_ws, pm as mock_pm, relay:
+            mock_notif.on_print_start = AsyncMock()
+            mock_plug.on_print_start = AsyncMock()
+            mock_ws.send_print_start = AsyncMock()
+            mock_pm.get_printer = MagicMock(return_value=MagicMock(name="Test", serial_number="TEST123"))
+
+            mock_printer = MagicMock()
+            mock_printer.auto_archive = True
+            mock_printer.id = 1
+
+            mock_session = AsyncMock()
+            mock_session.__aenter__ = AsyncMock(return_value=mock_session)
+            mock_session.__aexit__ = AsyncMock()
+            mock_session.execute = AsyncMock(
+                return_value=MagicMock(scalar_one_or_none=MagicMock(return_value=mock_printer))
+            )
+            mock_session_maker.return_value = mock_session
+
+            with patch("backend.app.main._send_print_start_notification", new_callable=AsyncMock) as mock_notify:
+                from backend.app.main import on_print_start
+
+                # No filename: exactly what the printer reports for this run,
+                # and the reason the old /usr/ prefix test never fired.
+                await on_print_start(1, {"filename": "", "subtask_name": "auto_pa_line_calib_mode"})
+
+                mock_notify.assert_not_called()
+
+        skipped = [r for r in capture_logs.records if "internal printer job" in str(r.message)]
+        assert skipped, "Should log that the calibration run was skipped"
+
+
+class TestPrintCompleteStaysQuiet:
+    @pytest.mark.asyncio
+    async def test_no_orphan_notification_when_the_calibration_finishes(self):
+        """With no archive to close, the completion would otherwise fall into
+        the no-archive notification path -- which attributes an unmatched
+        completion to any queue item this printer finished in the last five
+        minutes. For a calibration running alongside a real print that means
+        telling its owner their print is done, early and twice.
+        """
+        with (
+            patch("backend.app.main.async_session") as mock_session_maker,
+            patch("backend.app.main.ws_manager") as mock_ws,
+            patch("backend.app.main.printer_manager") as mock_pm,
+            patch("backend.app.main.mqtt_relay") as mock_relay,
+            patch("backend.app.main.spawn_background_task") as mock_spawn,
+            patch("backend.app.main.clear_3mf_cache"),
+        ):
+            mock_ws.send_print_complete = AsyncMock()
+            mock_relay.on_print_complete = AsyncMock()
+            mock_pm.get_printer = MagicMock(return_value=MagicMock(name="Test", serial_number="TEST123"))
+            mock_pm.get_current_print_user = MagicMock(return_value=None)
+            mock_pm.clear_current_print_user = MagicMock()
+            mock_pm.set_awaiting_plate_clear = MagicMock()
+
+            mock_session = AsyncMock()
+            mock_session.__aenter__ = AsyncMock(return_value=mock_session)
+            mock_session.__aexit__ = AsyncMock()
+            mock_session.execute = AsyncMock(
+                return_value=MagicMock(scalar_one_or_none=MagicMock(return_value=None), scalars=MagicMock())
+            )
+            mock_session_maker.return_value = mock_session
+
+            from backend.app.main import on_print_complete
+
+            await on_print_complete(
+                1,
+                {"filename": "", "subtask_name": "auto_pa_line_calib_mode", "status": "completed"},
+            )
+
+            spawned = [c for c in mock_spawn.call_args_list if "notify-no-archive" in str(c)]
+            assert not spawned, "No completion notification should be spawned for a calibration run"
+
+    @pytest.mark.asyncio
+    async def test_a_real_orphan_print_still_notifies(self):
+        """The no-archive path exists for prints started outside Bambuddy. The
+        guard must not take those down with it.
+        """
+        with (
+            patch("backend.app.main.async_session") as mock_session_maker,
+            patch("backend.app.main.ws_manager") as mock_ws,
+            patch("backend.app.main.printer_manager") as mock_pm,
+            patch("backend.app.main.mqtt_relay") as mock_relay,
+            patch("backend.app.main.spawn_background_task") as mock_spawn,
+            patch("backend.app.main.clear_3mf_cache"),
+        ):
+            mock_ws.send_print_complete = AsyncMock()
+            mock_relay.on_print_complete = AsyncMock()
+            mock_pm.get_printer = MagicMock(return_value=MagicMock(name="Test", serial_number="TEST123"))
+            mock_pm.get_current_print_user = MagicMock(return_value=None)
+            mock_pm.clear_current_print_user = MagicMock()
+            mock_pm.set_awaiting_plate_clear = MagicMock()
+
+            mock_session = AsyncMock()
+            mock_session.__aenter__ = AsyncMock(return_value=mock_session)
+            mock_session.__aexit__ = AsyncMock()
+            mock_session.execute = AsyncMock(
+                return_value=MagicMock(scalar_one_or_none=MagicMock(return_value=None), scalars=MagicMock())
+            )
+            mock_session_maker.return_value = mock_session
+
+            from backend.app.main import on_print_complete
+
+            await on_print_complete(
+                1,
+                {"filename": "", "subtask_name": "Benchy", "status": "completed"},
+            )
+
+            spawned = [c for c in mock_spawn.call_args_list if "notify-no-archive" in str(c)]
+            assert spawned, "An unmatched real print must still notify"