diff --git a/CHANGELOG.md b/CHANGELOG.md index 5435fe34c..bf6e11c73 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -5,6 +5,7 @@ All notable changes to Bambuddy will be documented in this file. ## [1.2.6b1] - Unreleased ### Fixed +- **Prints sent from a slicer were sometimes logged as though Bambuddy had sent them (#2843 follow-up)** — Bambuddy records the dispatch behind every print so a support bundle shows where the sliced file went, and it told its own dispatches apart from a slicer's by a sequence number it believed was unique to it. It is not: that number is the slicer convention Bambuddy adopted, and measured on the wire OrcaSlicer counts from it while Bambu Studio counts from the same base a few higher. Whichever dispatch happened to land on the shared value was filed as Bambuddy's own and never recorded — after a slicer restart, that is the first print you send. Bambuddy now recognises its own dispatch by the job it actually sent. Nothing about printing or archiving changed; the entry was diagnostic, but it is the entry that tells you whether a printer stores your files somewhere Bambuddy can read them. Covered by backend tests. - **A print with no 3MF could take its filament figures from an unrelated model (#2843, reported by @gyrene2083)** — H2-series and P2S firmware keeps a slicer-sent file on the printer's internal storage, which Bambuddy cannot read, so those prints archive without a 3MF. Bambuddy then looks for the same model in your Library or among earlier prints, which is how a reprint still gets its filament accounted for. The name it searched on was the wrong one. A running print reports the file it is executing — always `Metadata/plate_1.gcode` — and with no 3MF to correct it, that path became the archive's name and `plate_1` became the search term. Every Bambu print has a plate 1, so the search matched on nothing meaningful and took whatever came back: on the maintainer's H2D a 1.6 g Cube was costed from a 207 g four-colour ABS print whose file happened to be named `lid_plate_1.3mf`. The match now uses the model name the printer reports alongside the plate path, a plate name on its own is refused rather than searched for, and a name must match a whole filename instead of merely appearing inside one. A print that cannot be identified is left untracked, which is the honest answer — the previous behaviour was to charge your spools for a model you did not print. Covered by backend tests, including the exact collision measured on the H2D. - **Timelapses were lost, and written outside the data directory, for any print archived without a 3MF (#2843)** — Every H2-series and P2S print sent from the slicer, so not a rare case. The video downloaded from the printer correctly and was then written next to the data directory rather than inside it, because an archive with no 3MF has no directory of its own and the destination was derived from the missing file's path. In Docker that meant a permission error, retried and discarded twenty-five times over twelve minutes, roughly a hundred connections to the printer for a video that was thrown away each round. Where that location happened to be writable it was worse: the file landed beside the installation, the attach failed anyway, and the stray video stayed there. Bambuddy has had a shared helper for exactly this since #1820 and this was the one place still deriving the path by hand. Timelapses now land in the archive's own folder and attach normally. Covered by backend tests. - **A slot that could not be charged now says so (#2843)** — When a print's filament cannot be read from a 3MF, Bambuddy falls back to the drop in the AMS's own remaining-filament percentage. That needs a reading when the print starts, and a spool without RFID has none until you set a remaining amount by hand — so those slots were skipped in silence. Nothing was deducted and nothing said why, which is indistinguishable from having nothing to deduct. Every other reason for skipping a slot was already logged; this one now is too. diff --git a/backend/app/services/bambu_mqtt.py b/backend/app/services/bambu_mqtt.py index 2dd9a36b5..194327722 100644 --- a/backend/app/services/bambu_mqtt.py +++ b/backend/app/services/bambu_mqtt.py @@ -1267,6 +1267,11 @@ class BambuMQTTClient: # by await_cali_ack. self._pending_cali_acks: dict[str, dict | None] = {} + # Identifies the one project_file *we* dispatched, so its echo on the + # topic can be told apart from a slicer's. One-shot: consumed by the + # first frame that matches. See _project_file_key. + self._own_project_file_key: str | None = None + # Xcam hold timers - OrcaSlicer pattern: ignore incoming data for 3 seconds after command # Key: module_name, Value: timestamp when command was sent self._xcam_hold_start: dict[str, float] = {} @@ -1857,16 +1862,35 @@ class BambuMQTTClient: # Diagnostic for #1162 follow-up (X2D + FTS routing): when a # slicer-launched project_file passes through the request topic, # log the full payload so we can diff Studio's field set against - # ours. We pin our own sequence_id to "20000" (line ~3195), so - # any other value means the command came from Studio/Orca, not - # from us. - if print_data.get("sequence_id") != "20000": + # ours. + # + # This used to read `sequence_id != "20000"`, on the belief that + # 20000 was ours alone. It is not: 20000 is the slicer convention + # Bambuddy adopted -- bind_server documents the slicer sending it + # during detect, and measured on the wire OrcaSlicer dispatched + # 20000 then 20001 while BambuStudio was on 20009/20010, both + # counting up from the same base. So the test swallowed whichever + # slicer dispatch happened to land on 20000, which on a fresh + # slicer start is the first one. Match our own dispatch instead. + if self._project_file_key(print_data) == self._own_project_file_key: + self._own_project_file_key = None + else: logger.info( "[%s] External project_file payload: %s", self.serial_number, json.dumps(print_data), ) + @staticmethod + def _project_file_key(print_data: dict) -> str: + """Identity of a project_file dispatch, for telling ours from a slicer's. + + Sequence id alone cannot do it -- every slicer counts up from the same + 20000 -- so this also carries the file and its destination, which differ + between any two real dispatches. + """ + return "|".join(str(print_data.get(field, "")) for field in ("sequence_id", "file", "url", "subtask_name")) + def _debug_on_change(self, key: str, value: object, msg: str, *args: object) -> None: """``logger.debug``, but only when ``value`` differs from the last call for ``key``. @@ -5844,6 +5868,9 @@ class BambuMQTTClient: command["print"]["nozzle_mapping"] = resolved logger.info("[%s] Sending print command: %s", self.serial_number, json.dumps(command)) + # Remember this dispatch so its echo on the topic is recognised as + # ours rather than logged as a slicer's. + self._own_project_file_key = self._project_file_key(command["print"]) self._client.publish(self.topic_publish, json.dumps(command), qos=1) # Record what we dispatched so /cover can pick the right plate # thumbnail even when the printer's gcode_file echo is just the diff --git a/backend/tests/unit/test_external_dispatch_detection.py b/backend/tests/unit/test_external_dispatch_detection.py new file mode 100644 index 000000000..8a4a0136d --- /dev/null +++ b/backend/tests/unit/test_external_dispatch_detection.py @@ -0,0 +1,116 @@ +"""Telling our own print dispatch from a slicer's (#2843 follow-up). + +The old test was ``sequence_id != "20000"``, on the belief that 20000 was +Bambuddy's alone. Measured on the wire 2026-08-17: OrcaSlicer dispatched +``20000`` and then ``20001``, while BambuStudio was on ``20009`` / ``20010`` -- +both counting up from the same base, which is also the value +``virtual_printer/bind_server`` documents the slicer sending during detect. So +the check swallowed whichever slicer dispatch landed on 20000, which after a +slicer restart is the first one. + +It matters beyond the log line: counting Studio-versus-Orca dispatches across +support bundles is how the size of the internal-storage problem gets measured, +and an undercount there is silent. +""" + +import json +import logging + +import pytest + +from backend.app.services.bambu_mqtt import BambuMQTTClient + + +@pytest.fixture +def client(): + return BambuMQTTClient(ip_address="192.168.1.100", serial_number="TEST123", access_code="12345678") + + +def _project_file(sequence_id, file="Cube.gcode.3mf", url="ftp://Cube.gcode.3mf", subtask="Cube"): + return { + "print": { + "sequence_id": sequence_id, + "command": "project_file", + "file": file, + "url": url, + "subtask_name": subtask, + "ams_mapping": [0], + } + } + + +def _external_lines(caplog): + return [r for r in caplog.records if "External project_file payload" in r.getMessage()] + + +class TestSlicerDispatchIsReported: + @pytest.mark.parametrize("seq", ["20000", "20001", "20009", "20010"]) + def test_every_slicer_sequence_id_is_logged(self, client, caplog, seq): + """20000 included -- that is the one the old check threw away.""" + with caplog.at_level(logging.INFO, logger="backend.app.services.bambu_mqtt"): + client._handle_request_message(_project_file(seq)) + + assert len(_external_lines(caplog)) == 1 + + def test_the_payload_is_logged_verbatim(self, client, caplog): + """It exists to be diffed against ours, so it has to be complete.""" + with caplog.at_level(logging.INFO, logger="backend.app.services.bambu_mqtt"): + client._handle_request_message(_project_file("20000")) + + logged = json.loads(_external_lines(caplog)[0].getMessage().split("payload: ", 1)[1]) + assert logged["url"] == "ftp://Cube.gcode.3mf" + assert logged["sequence_id"] == "20000" + + +class TestOwnDispatchIsNotReported: + def test_our_own_echo_is_recognised(self, client, caplog): + """Bambuddy publishes to the topic it subscribes to, so it sees its own + dispatch come back.""" + ours = _project_file("20000", url="ftp://MyPrint.3mf", file="MyPrint.3mf", subtask="MyPrint") + client._own_project_file_key = client._project_file_key(ours["print"]) + + with caplog.at_level(logging.INFO, logger="backend.app.services.bambu_mqtt"): + client._handle_request_message(ours) + + assert _external_lines(caplog) == [] + + def test_the_marker_is_consumed(self, client, caplog): + """One-shot. A second identical dispatch is somebody else's -- a reprint + from the slicer of the same file must not hide behind our last one.""" + ours = _project_file("20000") + client._own_project_file_key = client._project_file_key(ours["print"]) + + with caplog.at_level(logging.INFO, logger="backend.app.services.bambu_mqtt"): + client._handle_request_message(ours) + client._handle_request_message(ours) + + assert len(_external_lines(caplog)) == 1 + + def test_a_slicer_sharing_our_sequence_id_is_still_reported(self, client, caplog): + """The exact collision that motivated this: same 20000, different file.""" + ours = _project_file("20000", file="Ours.3mf", url="ftp://Ours.3mf", subtask="Ours") + client._own_project_file_key = client._project_file_key(ours["print"]) + + with caplog.at_level(logging.INFO, logger="backend.app.services.bambu_mqtt"): + client._handle_request_message(_project_file("20000", file="Theirs.3mf", url="brtc://emmc/Theirs.3mf")) + + assert len(_external_lines(caplog)) == 1 + + +class TestUnaffectedBehaviour: + def test_the_project_url_is_captured_either_way(self, client): + """The storage verdict must not depend on who dispatched -- it is read + before the ours/theirs test and drives whether the FTPS sweep runs.""" + ours = _project_file("20000", url="ftp://Ours.3mf", file="Ours.3mf", subtask="Ours") + client._own_project_file_key = client._project_file_key(ours["print"]) + client._handle_request_message(ours) + assert client.state.current_project_url == "ftp://Ours.3mf" + + client._handle_request_message(_project_file("20009", url="brtc://emmc/Theirs.3mf")) + assert client.state.current_project_url == "brtc://emmc/Theirs.3mf" + + def test_ams_mapping_is_captured_either_way(self, client): + ours = _project_file("20000") + client._own_project_file_key = client._project_file_key(ours["print"]) + client._handle_request_message(ours) + assert client._captured_ams_mapping == [0]