Report a refused RFID refresh, and fall back to M620 R (#3206)

ams_get_rfid was published and reported as success without reading the
    printer's answer. X1Plus on base 01.08.02.00 answers FAIL / ERROR STATE,
    so the user saw "Refreshing" and the K profile was re-applied to a slot
    that was never read.

    - Wait for the ams_get_rfid answer (matched by sequence_id).
    - On a refusal from an idle X1/P1/A1, send the legacy M620 R<ams*4+slot>
      gcode Bambu Studio uses for those models, AMS units 0-3 only. Never
      during a job, never on newer-protocol models; printers that accept
      ams_get_rfid never see it.
    - Refused: the route returns 400 with the printer's reason and no PA
      re-apply is scheduled. No answer still counts as accepted.
    - Log the answers at INFO so refusals reach support bundles.

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)
 

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<global tray>`` 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,

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.
 

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

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

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<global tray>`` 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)