diff --git a/backend/app/api/routes/printers.py b/backend/app/api/routes/printers.py index f1569ae1d..8bdf0c9f0 100644 --- a/backend/app/api/routes/printers.py +++ b/backend/app/api/routes/printers.py @@ -4296,7 +4296,7 @@ async def refresh_ams_slot( if not client: raise HTTPException(400, "Printer not connected") - success, message = client.ams_refresh_tray(ams_id, slot_id) + success, message = await client.ams_refresh_tray(ams_id, slot_id) if not success: raise HTTPException(400, message) diff --git a/backend/app/services/bambu_mqtt.py b/backend/app/services/bambu_mqtt.py index e1dd0fcda..8ecf3e90a 100644 --- a/backend/app/services/bambu_mqtt.py +++ b/backend/app/services/bambu_mqtt.py @@ -1432,6 +1432,9 @@ class BambuMQTTClient: # on both an X1C and an H2D (#2718). Filled by the MQTT thread, drained # by await_cali_ack. self._pending_cali_acks: dict[str, dict | None] = {} + # Acks for RFID re-reads (ams_get_rfid, and the M620 R gcode_line + # fallback), keyed the same way. Drained by ams_refresh_tray (#3206). + self._pending_rfid_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 @@ -2449,6 +2452,25 @@ class BambuMQTTClient: # INFO level so the body lands in support bundles by default. elif cmd == "ams_filament_drying": logger.info("[%s] ams_filament_drying response: %s", self.serial_number, print_data) + # RFID re-reads are user-initiated and rare, and a refusal was + # invisible until #3206 (X1Plus answering FAIL / ERROR STATE). + # gcode_line acks are only of interest when they answer our + # M620 R fallback, so those are matched by sequence_id alone. + ack_seq = str(print_data.get("sequence_id", "")) + if ( + cmd in ("ams_get_rfid", "gcode_line") + and ack_seq in self._pending_rfid_acks + and "result" in print_data + ): + logger.info( + "[%s] %s response: result=%s reason=%s seq=%s", + self.serial_number, + cmd, + print_data.get("result"), + print_data.get("reason", ""), + ack_seq, + ) + self._pending_rfid_acks[ack_seq] = print_data # Check for developer mode probe response if ( cmd == "ams_filament_setting" @@ -7715,9 +7737,19 @@ class BambuMQTTClient: logger.info("[%s] AMS control: %s", self.serial_number, action) return True - def ams_refresh_tray(self, ams_id: int, tray_id: int) -> tuple[bool, str]: + async def ams_refresh_tray(self, ams_id: int, tray_id: int) -> tuple[bool, str]: """Trigger RFID re-read for a specific AMS tray. + Sends ``ams_get_rfid`` and waits for the printer's answer. Firmware + that refuses it (#3206: X1Plus on base 01.08.02.00 answers ``FAIL`` / + ``ERROR STATE``) gets the legacy ``M620 R`` gcode instead, + which is what Bambu Studio sends to printers without the new protocol. + The fallback only follows an explicit refusal, so firmware that takes + ``ams_get_rfid`` never sees it. + + Success means the printer accepted the request, not that the tag was + read: the slot updating in the next push is the only proof of that. + Args: ams_id: AMS unit ID (0-3, or 128 for H2D external tray) tray_id: Tray ID within the AMS (0-3) @@ -7750,15 +7782,71 @@ class BambuMQTTClient: if (_a2l := a2l_lite_wire_ids(ams_id, tray_id)) is not None: wire_ams_id, wire_slot_id, _ = _a2l - # Use ams_get_rfid command to trigger RFID re-read - # This command is used by Bambu Studio to re-read the RFID tag - command = { - "print": {"command": "ams_get_rfid", "ams_id": wire_ams_id, "slot_id": wire_slot_id, "sequence_id": "0"} - } - self._client.publish(self.topic_publish, json.dumps(command), qos=1) logger.info("[%s] Triggering RFID re-read: AMS %s, slot %s", self.serial_number, ams_id, tray_id) + refused = await self._send_rfid_command( + {"command": "ams_get_rfid", "ams_id": wire_ams_id, "slot_id": wire_slot_id} + ) + if refused is None: + return True, f"Refreshing AMS {ams_id} tray {tray_id}" - return True, f"Refreshing AMS {ams_id} tray {tray_id}" + # M620 R only for what Bambu Studio sends it to: a model older than the + # newer protocol, on one of the four regular AMS units (the only ones + # with a legacy global tray index). Never during a job either: a + # gcode_line would be executed inside the running print. + from backend.app.utils.printer_models import uses_legacy_rfid_refresh + + if ( + not 0 <= wire_ams_id <= 3 + or not uses_legacy_rfid_refresh(self.model) + or self.state.state in _ACTIVE_PRINT_STATES + ): + return False, f"Printer refused the RFID refresh: {refused}" + + logger.info( + "[%s] ams_get_rfid refused (%s), falling back to M620 R%s", + self.serial_number, + refused, + wire_ams_id * 4 + wire_slot_id, + ) + legacy_refused = await self._send_rfid_command( + {"command": "gcode_line", "param": f"M620 R{wire_ams_id * 4 + wire_slot_id}\n"} + ) + if legacy_refused is None: + return True, f"Refreshing AMS {ams_id} tray {tray_id} (legacy command)" + return False, f"Printer refused the RFID refresh: {legacy_refused}" + + # The answer to ams_get_rfid was measured at 11ms in #3206's capture. + _rfid_ack_timeout: float = 3.0 + + async def _send_rfid_command(self, print_command: dict) -> str | None: + """Publish one RFID refresh command and wait for the printer's answer. + + Returns the printer's reason when it answered ``FAIL``, else None. + No answer within ``_rfid_ack_timeout`` counts as accepted, because + silence is not evidence of refusal and older firmware may not answer + at all. + """ + timeout = self._rfid_ack_timeout + self._sequence_id += 1 + seq_id = str(self._sequence_id) + command = {"print": {**print_command, "sequence_id": seq_id}} + self._pending_rfid_acks[seq_id] = None + try: + self._client.publish(self.topic_publish, json.dumps(command), qos=1) + deadline = time.monotonic() + timeout + while time.monotonic() < deadline: + ack = self._pending_rfid_acks.get(seq_id) + if ack is not None: + if str(ack.get("result", "")).lower() == "fail": + return str(ack.get("reason", "") or "") or "printer reported failure" + return None + await asyncio.sleep(0.05) + finally: + self._pending_rfid_acks.pop(seq_id, None) + logger.info( + "[%s] No answer to %s seq=%s within %.1fs", self.serial_number, print_command["command"], seq_id, timeout + ) + return None def ams_set_filament_setting( self, diff --git a/backend/app/utils/printer_models.py b/backend/app/utils/printer_models.py index 670b7668a..260014a1f 100644 --- a/backend/app/utils/printer_models.py +++ b/backend/app/utils/printer_models.py @@ -399,6 +399,20 @@ def supports_nozzle_flow_type(model: str | None) -> bool: return normalized not in SINGLE_NOZZLE_FLOW_MODELS +# Models whose firmware predates Bambu's newer MQTT protocol, so Bambu Studio +# re-reads an AMS tag on them with the M620 R gcode rather than ams_get_rfid +# (#3206). Short display names (uppercase, no spaces). +LEGACY_RFID_REFRESH_MODELS = frozenset(["X1", "X1C", "X1E", "P1P", "P1S", "A1", "A1MINI"]) + + +def uses_legacy_rfid_refresh(model: str | None) -> bool: + """True for models that may need M620 R instead of ams_get_rfid (#3206).""" + if not model: + return False + short = PRINTER_MODEL_ID_MAP.get(model.strip(), model) + return short.strip().upper().replace(" ", "") in LEGACY_RFID_REFRESH_MODELS + + def get_rod_type(model: str | None) -> str | None: """Return the rod/rail type for a printer model. diff --git a/backend/tests/integration/test_printers_api.py b/backend/tests/integration/test_printers_api.py index f7957d472..1025242e9 100644 --- a/backend/tests/integration/test_printers_api.py +++ b/backend/tests/integration/test_printers_api.py @@ -1310,7 +1310,7 @@ class TestAMSRefreshAPI: printer = await printer_factory(name="Printer with AMS") mock_client = MagicMock() - mock_client.ams_refresh_tray.return_value = (True, "Refreshing AMS 0 tray 1") + mock_client.ams_refresh_tray = AsyncMock(return_value=(True, "Refreshing AMS 0 tray 1")) with patch("backend.app.api.routes.printers.printer_manager") as mock_pm: mock_pm.get_client.return_value = mock_client @@ -1329,7 +1329,7 @@ class TestAMSRefreshAPI: printer = await printer_factory(name="Printer with AMS") mock_client = MagicMock() - mock_client.ams_refresh_tray.return_value = (False, "Please unload filament first") + mock_client.ams_refresh_tray = AsyncMock(return_value=(False, "Please unload filament first")) with patch("backend.app.api.routes.printers.printer_manager") as mock_pm: mock_pm.get_client.return_value = mock_client diff --git a/backend/tests/unit/test_a2l_ams_lite_2619.py b/backend/tests/unit/test_a2l_ams_lite_2619.py index 7f4857da0..90fabf09b 100644 --- a/backend/tests/unit/test_a2l_ams_lite_2619.py +++ b/backend/tests/unit/test_a2l_ams_lite_2619.py @@ -14,6 +14,8 @@ printing physical slot 3. import json from unittest.mock import MagicMock +import pytest + from backend.app.services.bambu_mqtt import ( A2L_LITE_GLOBAL_BASE, A2L_LITE_NORMALIZED_AMS_ID, @@ -262,10 +264,17 @@ class TestOutboundTranslation: assert client.ams_unload_filament() assert _last_payload(client)["ams_id"] == A2L_LITE_PHYSICAL_AMS_ID - def test_refresh_tray_uses_physical_16(self): + @pytest.mark.asyncio + async def test_refresh_tray_uses_physical_16(self): client = _wired(_client()) client.state.tray_now = 255 # nothing loaded, so refresh is allowed - ok, _ = client.ams_refresh_tray(ams_id=6, tray_id=2) + + def accept(_topic, body, **_kw): + sent = json.loads(body)["print"] + client._process_message({"print": {**sent, "result": "SUCCESS", "reason": ""}}) + + client._client.publish.side_effect = accept + ok, _ = await client.ams_refresh_tray(ams_id=6, tray_id=2) assert ok p = _last_payload(client) assert p["ams_id"] == A2L_LITE_PHYSICAL_AMS_ID diff --git a/backend/tests/unit/test_rfid_refresh_ack_3206.py b/backend/tests/unit/test_rfid_refresh_ack_3206.py new file mode 100644 index 000000000..a2dfde5ef --- /dev/null +++ b/backend/tests/unit/test_rfid_refresh_ack_3206.py @@ -0,0 +1,173 @@ +"""RFID refresh reports what the printer said, and falls back to M620 R (#3206). + +An X1C on X1Plus (base 01.08.02.00) answers ams_get_rfid with +``result: FAIL, reason: ERROR STATE``, yet the refresh returned success and +scheduled the K-profile re-apply. The refresh now waits for the answer, sends +the legacy ``M620 R`` gcode Bambu Studio uses for printers without +the new protocol when ams_get_rfid is refused, and reports a refusal of both. +""" + +import json +from unittest.mock import MagicMock, patch + +import pytest + +from backend.app.services.bambu_mqtt import BambuMQTTClient +from backend.app.utils.printer_models import uses_legacy_rfid_refresh + + +def _client(answers: dict[str, dict | None], model: str = "X1C") -> tuple[BambuMQTTClient, list[dict]]: + """A connected, idle client whose printer answers each command per ``answers``. + + ``answers`` maps a command name to the result fields the printer sends + back, or None for no answer at all. Returns the client and the list of + commands it published. + """ + client = BambuMQTTClient(ip_address="10.0.0.1", serial_number="X1C", access_code="c", model=model) + client._client = MagicMock() + client.state.connected = True + client.state.tray_now = 255 + sent: list[dict] = [] + + def publish(_topic, body, **_kw): + command = json.loads(body)["print"] + sent.append(command) + answer = answers.get(command["command"]) + if answer is not None: + client._process_message({"print": {**command, **answer}}) + + client._client.publish.side_effect = publish + return client, sent + + +ACCEPT = {"result": "SUCCESS", "reason": "SUCCESS"} +REFUSE = {"result": "FAIL", "reason": "ERROR STATE"} + + +class TestRfidRefreshAck: + @pytest.mark.asyncio + async def test_accepted_sends_only_ams_get_rfid(self): + client, sent = _client({"ams_get_rfid": ACCEPT}) + + ok, message = await client.ams_refresh_tray(0, 3) + + assert ok + assert message == "Refreshing AMS 0 tray 3" + assert [c["command"] for c in sent] == ["ams_get_rfid"] + assert sent[0]["ams_id"] == 0 and sent[0]["slot_id"] == 3 + + @pytest.mark.asyncio + async def test_refused_falls_back_to_m620_with_the_global_tray(self): + client, sent = _client({"ams_get_rfid": REFUSE, "gcode_line": ACCEPT}) + + ok, message = await client.ams_refresh_tray(2, 1) + + assert ok + assert "legacy" in message + assert [c["command"] for c in sent] == ["ams_get_rfid", "gcode_line"] + assert sent[1]["param"] == "M620 R9\n" + + @pytest.mark.asyncio + async def test_both_refused_reports_the_printer_reason(self): + client, _ = _client({"ams_get_rfid": REFUSE, "gcode_line": REFUSE}) + + ok, message = await client.ams_refresh_tray(0, 3) + + assert not ok + assert "ERROR STATE" in message + + @pytest.mark.asyncio + async def test_no_fallback_for_units_without_a_legacy_index(self): + # AMS-HT (128+) has no M620 R index; only firmware with ams_get_rfid has one. + client, sent = _client({"ams_get_rfid": REFUSE}) + + ok, message = await client.ams_refresh_tray(128, 0) + + assert not ok + assert "ERROR STATE" in message + assert [c["command"] for c in sent] == ["ams_get_rfid"] + + @pytest.mark.asyncio + async def test_no_fallback_on_a_newer_protocol_model(self): + # Bambu Studio never sends M620 R to these; a refusal there is reported. + client, sent = _client({"ams_get_rfid": REFUSE}, model="H2D") + + ok, message = await client.ams_refresh_tray(0, 1) + + assert not ok + assert "ERROR STATE" in message + assert [c["command"] for c in sent] == ["ams_get_rfid"] + + @pytest.mark.asyncio + @pytest.mark.parametrize("state", ["RUNNING", "PAUSE", "PREPARE", "SLICING"]) + async def test_no_fallback_during_a_job(self, state): + # A gcode_line would be executed inside the running print. + client, sent = _client({"ams_get_rfid": REFUSE}) + client.state.state = state + + ok, _ = await client.ams_refresh_tray(0, 1) + + assert not ok + assert [c["command"] for c in sent] == ["ams_get_rfid"] + + @pytest.mark.asyncio + async def test_no_answer_counts_as_accepted(self): + client, sent = _client({}) + + client._rfid_ack_timeout = 0.1 + ok, _ = await client.ams_refresh_tray(0, 0) + + assert ok + assert [c["command"] for c in sent] == ["ams_get_rfid"] + assert client._pending_rfid_acks == {} + + @pytest.mark.asyncio + async def test_unrelated_gcode_line_ack_is_not_taken_for_ours(self): + client, _ = _client({"ams_get_rfid": REFUSE}) + client._process_message({"print": {"command": "gcode_line", "sequence_id": "0", **REFUSE}}) + + client._rfid_ack_timeout = 0.1 + ok, _ = await client.ams_refresh_tray(0, 0) + + # ams_get_rfid refused, M620 R sent but unanswered -> accepted. + assert ok + + +class TestRefreshRoute: + @pytest.mark.asyncio + async def test_refused_refresh_is_400_and_schedules_no_pa_reapply(self): + from fastapi import HTTPException + + from backend.app.api.routes import printers as printers_routes + + client, _ = _client({"ams_get_rfid": REFUSE, "gcode_line": REFUSE}) + db = MagicMock() + result = MagicMock() + result.scalar_one_or_none.return_value = MagicMock(id=1) + + async def execute(*_a, **_kw): + return result + + db.execute = execute + + with ( + patch.object(printers_routes, "printer_manager") as pm, + patch.object(printers_routes, "spawn_background_task") as spawn, + ): + pm.get_client.return_value = client + with pytest.raises(HTTPException) as exc: + await printers_routes.refresh_ams_slot(1, 0, 3, None, db) + + assert exc.value.status_code == 400 + assert "ERROR STATE" in exc.value.detail + spawn.assert_not_called() + + +class TestLegacyRfidModels: + @pytest.mark.parametrize("model", ["X1C", "X1", "X1E", "P1P", "P1S", "A1", "A1 Mini", "BL-P001", "C12", "N1"]) + def test_legacy(self, model): + assert uses_legacy_rfid_refresh(model) + + @pytest.mark.parametrize("model", ["H2D", "H2C", "H2S", "P2S", "A2L", "X2D", "O1D", "N7", "", None]) + def test_not_legacy(self, model): + assert not uses_legacy_rfid_refresh(model)