Files
bambuddy/backend/tests/unit/test_request_topic_probe_2953.py
maziggy 935d4b5bbf Charge the tray the printer said it used, not the first one loaded (issue #2953)
A sliced file numbers its filaments 1..4; which AMS tray each came from is
decided when the job is sent. #2768 gave the Spoolman writer two ways to
recover that decision when the print did not come through Bambuddy: the
printer's own mapping field, and a colour match of the 3MF's slots against the
loaded trays. An A1 satisfies neither. It publishes no mapping field, and it
drops the MQTT connection when we subscribe to its request topic, so the
slicer's instruction never arrives either. That leaves the colour match, and it
compares hex strings exactly.

The reporter sliced with a generic black profile against a tray they had set to
charged slot 1 to whatever sat in the first tray -- 2.17 g onto a grey PLA+
spool, while the print was fed from tray 3. Their bundle carries the printer's
own answer: "Tray change during print: tray=3 at layer=0", recorded 90 seconds
in, and read further down the same completion pass by _print_used_tray_keys to
decide which slots the print had touched. The same pass then charged tray 0 on
a guess, and logged "AMS0-T3: remain% did not fall over the print" about the
tray that had actually done the work.

_single_slot_tray_from_state adds the third rung. For a print with exactly one
slot carrying usage, the one slot came from the one tray, so the printer's tray
reporting answers the question directly: the mid-print tray-change log, then
the tray loaded at print start, then the current one, then the last real tray
seen. That is the ladder usage_tracker.on_print_complete has consulted since it
started resolving mappings at completion -- Spoolman users were the only ones
not getting it, which is why an install running the built-in inventory has
never shown this. On this printer only the first and last rungs can fire:
tray_now_at_start is 255 because print start runs before the filament is
loaded, and the A1 parks tray_now back at 255 the moment a print ends.

Gated on exactly one slot with usage, like the internal writer: a multi-colour
print moves tray_now on every change, so one reading cannot then be attributed
to one slot. It also declines when the log holds more than one switch, because
an AMS-backup runout is split per segment (#1793) and a single-tray mapping
would land the whole print on one spool.

That gate needed the guess warning to exclude the split path too. The split
never reads slot_to_tray at all -- it charges each segment to the tray the
printer announced switching to, which is the same evidence this fallback is
built on -- so a declined mapping there is not a guess, and calling it one
suppressed the archive rewrite for exactly the prints whose attribution is best
supported. Nothing covered that combination; a test does now.

Where nothing names a tray the positional default still stands, because it is
right for an AMS loaded in slicer order. It now says so at warning level so a
support bundle carries the reason, and it no longer restamps the archive's
filament colour and material from a spool it picked by position. That restamp
is what made the fault read as data loss: the grams can be put back, whereas
overwriting what the slicer recorded leaves nothing to compare against, and the
reporter's archive had already been rewritten from #000000 to the wrong spool's
grey. A slot that consumed nothing also stops claiming a tray in the handled
set -- it was never charged, so the remain-delta path should stay free to cover
it rather than be suppressed by an estimate of zero.

The request-topic probe is the same failure reached from the other side. A
printer that refuses kills the TCP connection instead of returning a SUBACK
failure, so the only signal is "we subscribed, then got disconnected", and that
was believed the first time it happened. Every other reason a connection drops
inside the same window looks identical -- a network blip, the printer
rebooting, the container stopped mid-probe -- and the verdict was cached per
serial with no re-probe anywhere, so on a printer that supports the topic one
unlucky drop cost mapping capture for the rest of the process and every slicer
print after it was charged by tray position. It now takes two consecutive
drops, and a disconnect we asked for is not counted. A printer that genuinely
refuses answers the same way every time and pays one extra reconnect; one
already known to refuse still skips the subscription outright rather than
reopening a reconnect loop.
2026-08-25 16:22:43 +02:00

132 lines
4.5 KiB
Python

"""The request-topic probe must not latch on a single unexplained drop (#2953).
Bambuddy subscribes to the printer's own request topic to intercept the
``ams_mapping`` a slicer sends with a print. A1-class printers refuse: their
broker kills the TCP connection instead of returning a SUBACK failure, so the
only signal is "we subscribed and then got disconnected". That signal is
circumstantial. Every other reason a connection can drop inside the same few
seconds -- a network blip, the printer rebooting, the container being stopped
mid-probe -- looks exactly the same.
Latching on the first one costs ams_mapping capture for the rest of the
process on a printer that supports the topic perfectly well, and every Studio
print after that is charged to a spool picked by tray position. Requiring the
drop to repeat costs a printer that genuinely refuses one extra reconnect.
"""
from types import SimpleNamespace
import pytest
from backend.app.services.bambu_mqtt import BambuMQTTClient
@pytest.fixture(autouse=True)
def _clear_class_state():
BambuMQTTClient._request_topic_cache.clear()
BambuMQTTClient._request_topic_probe_failures.clear()
yield
BambuMQTTClient._request_topic_cache.clear()
BambuMQTTClient._request_topic_probe_failures.clear()
def _client(serial="SER2953"):
client = BambuMQTTClient(ip_address="10.0.0.9", serial_number=serial, access_code="12345678")
client._stale_reconnecting = False
client._last_message_time = 0.0
client.last_connect_error = None
return client
def _mid_probe(client):
"""Put the client where it is right after subscribing to the request topic."""
import time
client._request_topic_sub_mid = 7
client._request_topic_sub_time = time.time()
client._request_topic_confirmed = False
def _drop(client):
client._on_disconnect(None, None, disconnect_flags=None, rc=SimpleNamespace(is_failure=True))
def test_one_drop_keeps_the_request_topic_enabled():
"""A blip, as far as we can tell. Try again on the next connection."""
client = _client()
_mid_probe(client)
_drop(client)
assert client._request_topic_supported is True
assert BambuMQTTClient._request_topic_cache.get("SER2953") is None
assert BambuMQTTClient._request_topic_probe_failures["SER2953"] == 1
def test_a_second_drop_disables_it():
"""The A1's answer: same response every time. Stop asking, and stop
causing a reconnect on every connection."""
client = _client()
_mid_probe(client)
_drop(client)
_mid_probe(client)
_drop(client)
assert client._request_topic_supported is False
assert BambuMQTTClient._request_topic_cache["SER2953"] is False
def test_a_new_client_for_a_disabled_printer_does_not_re_probe():
"""Unchanged: once disabled, later instances skip the subscription
entirely rather than reopening the reconnect loop."""
client = _client()
_mid_probe(client)
_drop(client)
_mid_probe(client)
_drop(client)
assert _client()._request_topic_supported is False
def test_a_successful_suback_clears_the_count():
"""A printer that answered once has answered. A later isolated drop must
start from zero, not from a half-spent budget."""
client = _client()
_mid_probe(client)
_drop(client)
assert BambuMQTTClient._request_topic_probe_failures["SER2953"] == 1
client._request_topic_sub_mid = 7
client._on_subscribe(None, None, 7, [SimpleNamespace(is_failure=False, value=0, getName=lambda: "ok")])
assert BambuMQTTClient._request_topic_cache["SER2953"] is True
assert "SER2953" not in BambuMQTTClient._request_topic_probe_failures
def test_a_suback_rejection_still_disables_immediately():
"""A SUBACK failure is the broker answering the question, not evidence
about it. One is enough."""
client = _client()
client._request_topic_sub_mid = 7
client._on_subscribe(None, None, 7, [SimpleNamespace(is_failure=True, value=135, getName=lambda: "Not authorized")])
assert client._request_topic_supported is False
assert BambuMQTTClient._request_topic_cache["SER2953"] is False
def test_a_disconnect_we_asked_for_is_not_evidence():
"""Shutting the container down mid-probe used to count against the
printer. ``disconnect()`` sets the event before closing the socket."""
import threading
client = _client()
_mid_probe(client)
client._disconnection_event = threading.Event()
_drop(client)
assert client._request_topic_supported is True
assert "SER2953" not in BambuMQTTClient._request_topic_probe_failures