From 935d4b5bbffb1f3ed2a0b978f8dc0010b2f8c61e Mon Sep 17 00:00:00 2001 From: maziggy Date: Tue, 25 Aug 2026 16:22:43 +0200 Subject: [PATCH] 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. --- CHANGELOG.md | 2 + backend/app/services/bambu_mqtt.py | 41 +- backend/app/services/spoolman_tracking.py | 187 ++++++++- .../tests/unit/services/test_bambu_mqtt.py | 24 +- .../test_spoolman_tray_state_fallback_2953.py | 388 ++++++++++++++++++ .../unit/test_request_topic_probe_2953.py | 131 ++++++ 6 files changed, 741 insertions(+), 32 deletions(-) create mode 100644 backend/tests/unit/services/test_spoolman_tray_state_fallback_2953.py create mode 100644 backend/tests/unit/test_request_topic_probe_2953.py diff --git a/CHANGELOG.md b/CHANGELOG.md index 05794f93e..d9933bc5d 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -19,6 +19,8 @@ All notable changes to Bambuddy will be documented in this file. - **The Windows installer build is split in two so a signing request can wait for a human (SignPath Foundation)** — Release tags are Authenticode-signed through the SignPath Foundation OSS programme, and the production certificate does not sign on demand the way the self-signed test certificate does: every request has to be approved by hand in the SignPath UI, because the Foundation verifies what is being signed and which build it came from. The submitting action waits for that approval with a default timeout of 600 seconds, which is ample when the test policy approves automatically in seconds and far too short once the wait is a person noticing a tag went out. A tag pushed at night would have failed the run ten minutes later with the installer already compiled and thrown away. The compile now ends in its own job that uploads the unsigned artifact and stops; a second job downloads it, signs it, and does the release-facing work, with the wait raised to an hour. Because the artifact is uploaded before the wait begins and is addressed by id, a missed approval window is recovered by re-running the second job alone rather than rebuilding the installer — which is the reason to separate them rather than simply raise the timeout in place. The second job runs for unsigned builds too, so the daily prereleases that are deliberately left unsigned to preserve the signing quota keep going out through exactly one set of alias, artifact and release steps. The property that matters is unchanged and now recorded next to the steps that depend on it: none of the alias, upload or release-attach steps carry `always()`, so GitHub skips all three when signing fails or times out, and an unsigned `.exe` cannot reach a release. Nothing about the signed output changes, and the restructure behaves identically under the test policy — the request simply completes immediately instead of waiting — so it can be proven green before the production certificate arrives. ### Fixed +- **A print sent from Bambu Studio charged the wrong Spoolman spool, and rewrote the archive to match (#2953, reported by @bitelvl1)** — A sliced file numbers its filaments 1..4; which AMS tray each came from is decided when the job is sent, and #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 can satisfy neither. It publishes no `mapping` field, and it drops the MQTT connection when Bambuddy subscribes to its request topic, so the slicer's instruction never arrives either — which leaves the colour match, and that compares hex strings exactly. The reporter sliced with a generic black profile against a tray they had set to #111111. No match, so every print fell through to the positional default and 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. The printer had already said so. `Tray change during print: tray=3 at layer=0` is in their log, recorded 90 seconds in, and read further down the same completion pass to decide which slots the print had touched — the same pass then charged tray 0 on a guess. A single-slot print is now pinned to the tray the printer reported feeding from, using the ladder the built-in inventory writer has consulted all along: the mid-print tray-change log, then the tray loaded at print start, then the current one, then the last real tray seen. Spoolman users were the only ones not getting it, which is why an install with the internal inventory in use never showed this. Gated on exactly one slot with usage, because a multi-colour print moves `tray_now` on every change and one reading cannot then be attributed to one slot; and it declines when the log holds more than one switch, so an AMS-backup runout still splits per segment (#1793) rather than landing whole on one spool. Where nothing at all names a tray the positional default still stands — it is right for an AMS loaded in slicer order — but it now says so at warning level, and no longer restamps the archive's filament colour and material from a spool it picked by position. That restamp is what made the fault look like 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. +- **One unexplained disconnect could stop a printer reporting slicer print mappings for good** — Bambuddy subscribes to the printer's request topic to intercept the mapping a slicer sends with a print. Printers that refuse kill 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 few seconds looks identical — a network blip, the printer rebooting, the container being stopped mid-probe — and the verdict was cached per serial with no re-probe anywhere, so on a printer that supports the topic perfectly well a single unlucky drop cost mapping capture for the rest of the process, and every Studio print after it was charged to a spool picked by tray position. The subscription is now retried once before being written off, and a disconnect Bambuddy asked for is not counted at all. A printer that genuinely refuses answers the same way every time and pays one extra reconnect; nothing changes for one already known to refuse, which still skips the subscription outright rather than reopening a reconnect loop. - **The AMS temperature alarm fired hourly on ambient room heat, and silencing it cost the colour band (#2905, reported and contributed by @ojimpo in #2943)** — `ams_temp_fair` decides when the AMS card turns amber, and it decided when a notification was sent as well. 35 °C is a reasonable place to change a colour and a low place to page someone: an AMS in a room without air conditioning sits above it on ambient heat alone, so the alarm repeated every hour for as long as the weather lasted — with every heater target at zero and humidity inside the good band — and the only way to stop it was to raise the display band and lose the red that says the unit is warm. "Red above 35 °C, notify above 45 °C" was not expressible. A new **Alarm above** field under Settings → AMS Display Thresholds separates the two. It is nullable and unset resolves to the fair value, so an install that never touches it behaves exactly as it did and there is no migration — the field is a row in the existing key/value settings table, not a column. Deliberately not a per-filament map like the humidity thresholds: that map exists because humidity also decides when a drying cycle starts and PLA, PETG and PA want different targets, whereas ambient heat does not care what is loaded, so a per-type map would only help someone who set every type to the same number. Three call sites take the new value, not one. The comparison is the obvious one; the second is the drying latch, which releases once the unit reads back at or below the threshold it was given, so handing it the display band stranded the latch on any unit that settles above it — an AMS resting at 37.7 °C never returns under a 35 °C band, so the hold placed during a cycle could only expire on its grace cap instead of releasing when the unit had actually cooled. The third is the number the notification quotes, or the message reads "> 35 °C" while firing at 45. A non-positive or non-finite value is refused rather than honoured, which matters more than it looks: nothing is ever greater than NaN, so a value that failed to parse as a real number would have silenced the alarm permanently — the failure mode that looks exactly like a working configuration. The field shows the fair threshold as its placeholder so the fallback is visible without reading docs, says so when a value it cannot use is entered, and the temperature block gains the disclosure line the humidity block has had all along: only the alarm threshold notifies, Good and Fair colour the display, and leaving it empty alarms where it always did. The background task that dispatches these alarms is a no-arg infinite loop and had never been covered by a test; it is now driven end to end, pinning that an install with no value set still fires and quotes 35, that a stored 45 is both what fires and what the message says, and that 37.7 °C in a warm room sends nothing. - **A clear spool synced to Spoolman as pure black (#2912, reported and contributed by @ojimpo in #2924)** — The AMS reports a translucent roll as `00000000`, and every write to Spoolman truncated that to six characters before storing it, so a PETG Translucent spool arrived as opaque black and the external catalogue then named it "Black". Spoolman's own schema accepts eight characters, so the value Bambuddy was discarding was one the backend would have taken verbatim. #1545 fixed exactly this for the built-in inventory and left the Spoolman path behind, which is why internal mode has been storing the alpha correctly for months. The read side was the matching half: it rejected anything that was not exactly six characters, so fixing the writes alone would have turned clear spools grey instead of black. Eight characters are stored only when the alpha byte says the filament is genuinely translucent — passing everything through would rewrite the colour of every opaque spool on its next touch, churning records in people's Spoolman for no benefit. Colour comparisons now key on the shape a value would be stored as, so two colours match exactly when storing them would produce the same value. That is what keeps the widening safe in both directions: an opaque tray still finds the six-character filaments every existing instance is full of, so no upgrade mints a duplicate for every spool on the next sync, while a clear roll gets its own record instead of being conflated with the black one of the same RGB. The edit route compares the same way, so a no-op edit no longer PATCHes the filament on every save and an alpha-only edit still reaches Spoolman. One consequence is worth stating: a filament already stored wrongly-opaque by this bug gets a second, correct record the next time that roll is auto-added, rather than the old one silently capturing every clear spool that follows. - **Translucent spools showed as an empty circle or as solid black in four more places** — The swatch helper had two answers, the transparency checkerboard for a fully clear colour and a flat fill for everything else, so a half-translucent spool rendered identically to an opaque one. The AMS tray swatches never reached that helper at all: Assign Spool painted the reported colour directly, so a clear tray was an invisible circle, and Configure AMS Slot cut the alpha off first, so a clear tray was solid black — the same symptom as the sync bug above, in the UI, and present regardless of which inventory mode is in use. All of them now draw through one helper, which lays a partly translucent colour over the checkerboard so the swatch shows both the tint and that it is see-through. diff --git a/backend/app/services/bambu_mqtt.py b/backend/app/services/bambu_mqtt.py index 51707ae39..5577221cc 100644 --- a/backend/app/services/bambu_mqtt.py +++ b/backend/app/services/bambu_mqtt.py @@ -1085,6 +1085,17 @@ class BambuMQTTClient: # Class-level cache: serial_number -> False when request topic is known unsupported. # Persists across client instances so reconnects don't re-trigger failed subscriptions. _request_topic_cache: dict[str, bool] = {} + # serial_number -> consecutive disconnects seen shortly after subscribing to + # the request topic. A SUBACK failure is the broker answering the question; + # a disconnect is only circumstantial, and any drop inside the window looks + # identical -- a network blip, the printer rebooting, the container being + # stopped mid-probe. Latching on the first one costs ams_mapping capture for + # the rest of the process on a printer that supports it perfectly well + # (#2953). Require the drop to repeat before believing it; a printer that + # really does refuse the topic answers the same way every time and pays one + # extra reconnect for it. + _request_topic_probe_failures: dict[str, int] = {} + _REQUEST_TOPIC_PROBE_LIMIT: int = 2 # Counter for generating unique MQTT client IDs across instances. _client_instance_counter: int = 0 @@ -1698,6 +1709,7 @@ class BambuMQTTClient: ) self._request_topic_confirmed = True BambuMQTTClient._request_topic_cache[self.serial_number] = True + BambuMQTTClient._request_topic_probe_failures.pop(self.serial_number, None) self._request_topic_sub_mid = None self._request_topic_sub_time = 0.0 @@ -1754,13 +1766,30 @@ class BambuMQTTClient: self._request_topic_sub_time > 0 and not self._request_topic_confirmed and time.time() - self._request_topic_sub_time < 10.0 + # A disconnect we asked for says nothing about the subscription. + and self._disconnection_event is None ): - logger.warning( - "[%s] Disconnected shortly after request topic subscription. Disabling request topic for this printer.", - self.serial_number, - ) - self._request_topic_supported = False - BambuMQTTClient._request_topic_cache[self.serial_number] = False + failures = BambuMQTTClient._request_topic_probe_failures.get(self.serial_number, 0) + 1 + BambuMQTTClient._request_topic_probe_failures[self.serial_number] = failures + if failures >= BambuMQTTClient._REQUEST_TOPIC_PROBE_LIMIT: + logger.warning( + "[%s] Disconnected shortly after request topic subscription %d times. " + "Disabling request topic for this printer — ams_mapping capture from " + "slicer-initiated prints is unavailable, and their filament will be " + "attributed from the printer's own tray reporting instead.", + self.serial_number, + failures, + ) + self._request_topic_supported = False + BambuMQTTClient._request_topic_cache[self.serial_number] = False + else: + logger.info( + "[%s] Disconnected shortly after request topic subscription (%d/%d). " + "Retrying it on the next connection before giving up.", + self.serial_number, + failures, + BambuMQTTClient._REQUEST_TOPIC_PROBE_LIMIT, + ) self._request_topic_sub_mid = None self._request_topic_sub_time = 0.0 diff --git a/backend/app/services/spoolman_tracking.py b/backend/app/services/spoolman_tracking.py index fe87f0097..b752095e8 100644 --- a/backend/app/services/spoolman_tracking.py +++ b/backend/app/services/spoolman_tracking.py @@ -40,6 +40,11 @@ _ZERO_TAG_UID = "0000000000000000" _MAX_REAL_TRAY_ID = 254 +def _is_real_tray_id(value) -> bool: + """True when ``value`` names a physical slot rather than "nothing loaded".""" + return isinstance(value, int) and not isinstance(value, bool) and 0 <= value <= _MAX_REAL_TRAY_ID + + def _is_non_zero_identifier(value: str) -> bool: """Return True when identifier is non-empty and not all zeros.""" if not value: @@ -163,7 +168,73 @@ def _resolve_global_tray_id(slot_id: int, slot_to_tray: list | None, ams_trays: return slot_id - 1 -def _resolve_slot_to_tray_fallback(printer_id: int, filament_usage: list[dict]) -> tuple[list[int] | None, str]: +def _single_slot_tray_from_state( + state, + filament_usage: list[dict], + tray_now_at_start: int | None = None, +) -> tuple[int, int] | None: + """The tray a single-slot print actually drew from, read off the printer. + + A1, A1 mini, P1S and P2S publish no ``mapping`` field and drop the MQTT + connection when we subscribe to their request topic, so neither of the + other two fallbacks can answer for them. What they do report is which tray + the extruder is fed from, and for a print that uses exactly one filament + slot that is the same question: the one slot came from the one tray. + + The ladder mirrors ``usage_tracker.on_print_complete`` step 5, which has + consulted these same fields since it started resolving mappings at + completion. Spoolman users were the only ones not getting them (#2953). + + Gated on exactly one slot with usage, like the internal writer: on a + multi-colour print every filament change moves ``tray_now``, so a single + tray reading says nothing about which slot it belongs to. + + More than one tray-change entry means the print switched trays mid-run + (AMS backup on runout, #957). ``report_usage`` splits those per segment + and must not be handed a single-tray mapping instead, so this declines. + + Returns ``(slot_id, global_tray_id)``, or None when the printer offered no + usable reading and the positional default stands. + """ + nonzero = [u for u in filament_usage or [] if u.get("used_g", 0) > 0] + if len(nonzero) != 1: + return None + slot_id = nonzero[0].get("slot_id", 0) + if slot_id <= 0: + return None + + changes = list(getattr(state, "tray_change_log", None) or []) + if len(changes) > 1: + return None + if len(changes) == 1: + entry = changes[0] + if isinstance(entry, (tuple, list)) and entry and _is_real_tray_id(entry[0]): + # Strongest evidence there is: the printer announced this switch + # while the job was running, so it describes this print and no + # other. On the reporter's A1 it read (3, 0) -- tray 3 at layer 0 + # -- while the positional default was charging tray 0. + return slot_id, entry[0] + + # No mid-print switch recorded. Fall back to the standing tray readings, + # newest evidence first. ``tray_now`` is 255 both at rest and while + # nothing is loaded, which is why _MAX_REAL_TRAY_ID excludes it; A1 + # firmware parks there the moment a print ends, leaving last_loaded_tray + # as the only survivor. + for candidate in ( + tray_now_at_start, + getattr(state, "tray_now", None), + getattr(state, "last_loaded_tray", None), + ): + if _is_real_tray_id(candidate): + return slot_id, candidate + return None + + +def _resolve_slot_to_tray_fallback( + printer_id: int, + filament_usage: list[dict], + tray_now_at_start: int | None = None, +) -> tuple[list[int] | None, str]: """Recover a slot-to-tray mapping at completion when print start captured none. ``store_print_data`` can only learn the mapping from two sources: the @@ -180,9 +251,17 @@ def _resolve_slot_to_tray_fallback(printer_id: int, filament_usage: list[dict]) The printer knows the real answer. Its ``mapping`` field carries the actual slot-to-tray assignment for the running job, and for the models that never publish it (A1, P1S, P2S) the 3MF's per-slot colours can be matched against - the loaded trays instead. The built-in inventory writer has consulted both - for as long as it has resolved mappings at completion; this gives the - Spoolman writer the same two fallbacks at the same moment. + the loaded trays instead. Failing both, a print that used a single filament + slot can be pinned to the tray the printer reported feeding from + (``_single_slot_tray_from_state``). + + The built-in inventory writer has consulted all three for as long as it has + resolved mappings at completion. The first version of this function offered + only the first two, which left A1-class printers -- no ``mapping`` field, no + request topic -- with nothing but the colour match, and that needs the + slicer's filament colour to equal the tray's exactly. A generic black + profile against a tray set to #111111 does not match, and the print is + charged to whichever spool happens to sit in the first tray (#2953). Deliberately at completion rather than inside ``store_print_data``: the printer keeps publishing ``mapping`` long after a job ends — it is still in @@ -193,28 +272,46 @@ def _resolve_slot_to_tray_fallback(printer_id: int, filament_usage: list[dict]) Args: printer_id: Printer whose live state is consulted. - filament_usage: The 3MF's per-slot estimates, needed by the colour - match. Only the ``slot_id``/``color`` keys are read. + filament_usage: The 3MF's per-slot estimates. The colour match reads + ``slot_id``/``color``; the tray-state fallback reads + ``slot_id``/``used_g``. + tray_now_at_start: The tray the printer was feeding from when the print + began, as captured by ``store_print_data``. Only consulted by the + tray-state fallback. Returns: - ``(mapping, source)``, or ``(None, "none")`` when neither fallback - produced anything and the positional default stands. + ``(mapping, source)``, or ``(None, "none")`` when no fallback produced + anything and the positional default stands. """ from backend.app.services.printer_manager import printer_manager from backend.app.services.usage_tracker import _decode_mqtt_mapping, _match_slots_by_color state = printer_manager.get_status(printer_id) raw_data = getattr(state, "raw_data", None) if state else None - if not raw_data: - return None, "none" - decoded = _decode_mqtt_mapping(raw_data.get("mapping")) - if decoded: - return decoded, "mqtt" + # Both of the first two fallbacks read the status payload; the third reads + # fields ``bambu_mqtt`` maintains on the state object itself, so an empty + # payload must not short-circuit past it. + if raw_data: + decoded = _decode_mqtt_mapping(raw_data.get("mapping")) + if decoded: + return decoded, "mqtt" - matched = _match_slots_by_color(filament_usage, raw_data.get("ams")) - if matched: - return matched, "color_match" + matched = _match_slots_by_color(filament_usage, raw_data.get("ams")) + if matched: + return matched, "color_match" + + single = _single_slot_tray_from_state(state, filament_usage, tray_now_at_start) + if single is not None: + slot_id, global_tray_id = single + # Only the one slot is claimed. The -1 padding is the array's existing + # "not an AMS tray" value, and the slots carrying it consumed nothing, + # so no caller resolves them: ``_report_spool_usage_for_slots`` skips + # zero-gram slots before resolving, ``_print_used_tray_keys`` skips + # negatives, and report_usage's handled-set skips them too. + mapping = [-1] * slot_id + mapping[slot_id - 1] = global_tray_id + return mapping, "tray_state" return None, "none" @@ -929,7 +1026,11 @@ async def _report_partial_usage( # ``_resolve_global_tray_id`` (#2768). An aborted print charges the wrong # spool just as readily as a finished one. if not slot_to_tray: - slot_to_tray, _partial_mapping_source = _resolve_slot_to_tray_fallback(printer_id, filament_usage) + slot_to_tray, _partial_mapping_source = _resolve_slot_to_tray_fallback( + printer_id, + filament_usage, + getattr(tracking, "tray_now_at_start", None), + ) logger.info( "[SPOOLMAN] Partial usage: slot_to_tray=%s (source: %s)", slot_to_tray, @@ -1124,13 +1225,34 @@ async def report_usage(printer_id: int, archive_id: int): # AMS slot directly, so there is nothing to recover for it. mapping_source = "stored" if slot_to_tray else "none" if filament_usage and not slot_to_tray: - slot_to_tray, mapping_source = _resolve_slot_to_tray_fallback(printer_id, filament_usage) + slot_to_tray, mapping_source = _resolve_slot_to_tray_fallback(printer_id, filament_usage, tray_now_at_start) logger.info( "[SPOOLMAN] Archive %s: slot_to_tray=%s (source: %s)", archive_id, slot_to_tray, mapping_source, ) + # Nothing named a tray for this print and no fallback could recover + # one, so every slot is about to be resolved by position -- slicer slot + # 1 to the first loaded tray, and so on. That guess is right for an AMS + # loaded in slicer order and wrong for any other, and the caller has no + # way to tell which it got. Say so at a level that survives the default + # log filter, so a support bundle carries the reason (#2953). + # + # Excludes the tray-split path. It never reads ``slot_to_tray`` at all: + # it charges each segment to the tray the printer announced switching + # to, which is the same evidence the tray-state fallback is built on and + # is not a guess. Calling it one would suppress the archive rewrite for + # exactly the prints -- an AMS-backup runout on a Studio job (#1793 in + # #2768's conditions) -- whose attribution is best supported. + mapping_is_guess = bool(filament_usage) and mapping_source == "none" and len(tray_changes) <= 1 + if mapping_is_guess: + logger.warning( + "[SPOOLMAN] Archive %s: no slot-to-tray mapping from any source -- " + "charging by tray position, which is a guess. Verify the spool weights " + "if the AMS is not loaded in slicer order.", + archive_id, + ) slot_colors: dict[int, str] = {} slot_materials: dict[int, str] = {} @@ -1199,6 +1321,13 @@ async def report_usage(printer_id: int, archive_id: int): # Track which physical slots the 3MF path already covered so # Path 2 doesn't double-charge them. for u in filament_usage: + if u.get("used_g", 0) <= 0: + # ``_report_spool_usage_for_slots`` skipped this slot + # before resolving a tray for it, so nothing was + # charged and Path 2 is free to cover the slot from + # remain% -- claiming it here would suppress a real + # drop on the strength of a zero-gram estimate. + continue slot_id = u.get("slot_id", 0) handled_global_tray_ids.add(_resolve_global_tray_id(slot_id, slot_to_tray, ams_trays)) @@ -1231,11 +1360,25 @@ async def report_usage(printer_id: int, archive_id: int): # Stamp the archive's filament colour from the matched Spoolman spools # so it reflects the curated inventory colour, not the slicer's 3MF # value (#1494) — mirrors the built-in inventory path in usage_tracker. - await _apply_spool_colors_to_archive(db, archive_id, filament_usage, slot_colors) + # + # Skipped when the mapping was a positional guess. Charging the wrong + # spool costs grams the owner can put back; rewriting the archive's + # colour and material on top of it overwrites what the slicer actually + # recorded, and the print then reads as a different filament than the + # one that made it, with nothing left to compare against (#2953). + if mapping_is_guess: + if slot_colors or slot_materials: + logger.info( + "[SPOOLMAN] Archive %s: leaving filament colour/type as sliced — " + "the spools were matched by position, not by a known mapping", + archive_id, + ) + else: + await _apply_spool_colors_to_archive(db, archive_id, filament_usage, slot_colors) - # Same for the material: a slot mapped to a differently-typed spool than - # it was sliced for otherwise records the sliced type (#2563). - await _apply_spool_types_to_archive(db, archive_id, filament_usage, slot_materials) + # Same for the material: a slot mapped to a differently-typed spool + # than it was sliced for otherwise records the sliced type (#2563). + await _apply_spool_types_to_archive(db, archive_id, filament_usage, slot_materials) def _print_used_tray_keys( diff --git a/backend/tests/unit/services/test_bambu_mqtt.py b/backend/tests/unit/services/test_bambu_mqtt.py index 5619ac3e8..5bee3f04f 100644 --- a/backend/tests/unit/services/test_bambu_mqtt.py +++ b/backend/tests/unit/services/test_bambu_mqtt.py @@ -1805,6 +1805,7 @@ class TestRequestTopicFailSafe: from backend.app.services.bambu_mqtt import BambuMQTTClient BambuMQTTClient._request_topic_cache.clear() + BambuMQTTClient._request_topic_probe_failures.clear() @pytest.fixture def mqtt_client(self): @@ -1858,7 +1859,14 @@ class TestRequestTopicFailSafe: assert mqtt_client._request_topic_supported is True def test_disconnect_after_subscription_disables_topic(self, mqtt_client): - """Disconnect within 10s of subscription attempt disables request topic.""" + """Repeated disconnects within 10s of a subscription attempt disable the + request topic. + + One is not enough (#2953). Any drop inside the window looks the same as + the broker refusing the topic, so the first is treated as circumstantial + and the subscription is retried on the next connection. A printer that + really does refuse answers the same way every time. + """ import time mqtt_client._request_topic_sub_time = time.time() @@ -1867,6 +1875,12 @@ class TestRequestTopicFailSafe: mqtt_client._on_disconnect(None, None) + assert mqtt_client._request_topic_supported is True + assert mqtt_client._request_topic_sub_time == 0.0 + + mqtt_client._request_topic_sub_time = time.time() + mqtt_client._on_disconnect(None, None) + assert mqtt_client._request_topic_supported is False assert mqtt_client._request_topic_sub_time == 0.0 @@ -1924,11 +1938,13 @@ class TestRequestTopicFailSafe: ) assert client1._request_topic_supported is True - # Simulate disconnect-after-subscribe disabling the topic - client1._request_topic_sub_time = __import__("time").time() + # Simulate disconnect-after-subscribe disabling the topic. Takes two + # (#2953) — the first drop is not treated as an answer. client1._request_topic_confirmed = False client1._last_message_time = 0.0 - client1._on_disconnect(None, None) + for _ in range(BambuMQTTClient._REQUEST_TOPIC_PROBE_LIMIT): + client1._request_topic_sub_time = __import__("time").time() + client1._on_disconnect(None, None) assert client1._request_topic_supported is False # New instance for same serial should inherit the cached state diff --git a/backend/tests/unit/services/test_spoolman_tray_state_fallback_2953.py b/backend/tests/unit/services/test_spoolman_tray_state_fallback_2953.py new file mode 100644 index 000000000..523364f30 --- /dev/null +++ b/backend/tests/unit/services/test_spoolman_tray_state_fallback_2953.py @@ -0,0 +1,388 @@ +"""Tray-state slot mapping for printers that can answer no other way (#2953). + +#2768 gave the Spoolman writer two ways to recover a print's slot-to-tray +mapping when print start captured none: the printer's ``mapping`` field, and a +colour match of the 3MF's slots against the loaded trays. An A1 can satisfy +neither. It publishes no ``mapping`` field, and it drops the MQTT connection +when Bambuddy subscribes to its request topic, so the slicer's own instruction +never arrives either. That leaves the colour match, which compares hex strings +exactly. + +The reporter sliced with a generic black profile (``#000000``) against a tray +they had set to ``#111111``. No match, so every print fell through to the +positional default and charged slot 1 to the first loaded tray -- the grey PLA+ +in tray 0 -- while the print was actually fed from tray 3. Their log carries +the printer's own answer, ``Tray change during print: tray=3 at layer=0``, +recorded 90 seconds into the print and already read by ``_print_used_tray_keys`` +further down the same completion pass. + +Values throughout are the ones from archive 12 of the reporter's support +bundle. +""" + +from types import SimpleNamespace +from unittest.mock import AsyncMock, MagicMock, patch + +import pytest + +from backend.app.services.spoolman_tracking import ( + _resolve_slot_to_tray_fallback, + _single_slot_tray_from_state, +) + +# The reporter's AMS at completion: tray 1 is empty, and no tray is #000000. +REPORTER_AMS = [ + { + "id": 0, + "tray": [ + {"id": 0, "tray_color": "888888FF", "tray_type": "PLA+"}, + {"id": 1, "tray_color": None, "tray_type": None}, + {"id": 2, "tray_color": "5F4036FF", "tray_type": "PLA"}, + {"id": 3, "tray_color": "111111FF", "tray_type": "PLA+"}, + ], + } +] +REPORTER_USAGE = [{"slot_id": 1, "used_g": 2.17, "type": "PLA+", "color": "#000000"}] + + +class _AsyncCtx: + def __init__(self, db): + self._db = db + + async def __aenter__(self): + return self._db + + async def __aexit__(self, *exc): + return False + + +def _state(tray_change_log=None, tray_now=255, last_loaded_tray=-1, **raw): + """An A1 as it looks at completion: no mapping field, nothing loaded.""" + return SimpleNamespace( + raw_data=raw, + layer_num=0, + total_layers=0, + tray_change_log=list(tray_change_log or []), + tray_now=tray_now, + last_loaded_tray=last_loaded_tray, + ) + + +def _patched_pm(state): + pm = MagicMock() + pm.get_status.return_value = state + return pm + + +class TestSingleSlotTrayFromState: + def test_the_mid_print_tray_change_is_the_answer(self): + """``Tray change during print: tray=3 at layer=0``. The printer + announced the switch while the job was running, so it describes this + print and no other.""" + state = _state(tray_change_log=[(3, 0)]) + assert _single_slot_tray_from_state(state, REPORTER_USAGE, 255) == (1, 3) + + def test_declines_a_multi_slot_print(self): + """Every colour change moves ``tray_now``, so one tray reading can't be + attributed to one slot. Same gate the internal writer uses.""" + usage = [ + {"slot_id": 1, "used_g": 10.0, "color": "#000000"}, + {"slot_id": 2, "used_g": 5.0, "color": "#FFFFFF"}, + ] + assert _single_slot_tray_from_state(_state(tray_change_log=[(3, 0)]), usage, None) is None + + def test_declines_when_the_print_switched_trays(self): + """Two entries means AMS backup swapped a spool mid-print (#957). + ``report_usage`` splits those per segment; handing it a single-tray + mapping instead would charge the whole print to one of them.""" + state = _state(tray_change_log=[(3, 0), (0, 120)]) + assert _single_slot_tray_from_state(state, REPORTER_USAGE, None) is None + + def test_slots_that_consumed_nothing_do_not_count_as_a_second_slot(self): + """A purge-only slot is in the 3MF with zero grams. It is not a second + filament and must not disqualify the print.""" + usage = [ + {"slot_id": 1, "used_g": 2.17, "color": "#000000"}, + {"slot_id": 2, "used_g": 0.0, "color": "#FFFFFF"}, + ] + assert _single_slot_tray_from_state(_state(tray_change_log=[(3, 0)]), usage, None) == (1, 3) + + def test_falls_back_to_tray_now_at_start(self): + state = _state(tray_change_log=[]) + assert _single_slot_tray_from_state(state, REPORTER_USAGE, 2) == (1, 2) + + def test_falls_back_to_current_tray_now(self): + state = _state(tray_change_log=[], tray_now=2) + assert _single_slot_tray_from_state(state, REPORTER_USAGE, 255) == (1, 2) + + def test_falls_back_to_last_loaded_tray(self): + """The reporter's A1 parks ``tray_now`` at 255 the moment the print + ends, and their ``tray_now_at_start`` was 255 too because print start + fires before the filament is loaded. ``last_loaded_tray`` only ever + latches real trays, so it is the one still holding the answer.""" + state = _state(tray_change_log=[], tray_now=255, last_loaded_tray=3) + assert _single_slot_tray_from_state(state, REPORTER_USAGE, 255) == (1, 3) + + def test_255_is_not_a_tray(self): + """255 is ``tray_now`` at rest and what an unparseable reading falls + back to. Reading it as a slot would charge a spool on no evidence.""" + state = _state(tray_change_log=[], tray_now=255, last_loaded_tray=255) + assert _single_slot_tray_from_state(state, REPORTER_USAGE, 255) is None + + def test_no_state_at_all(self): + assert _single_slot_tray_from_state(None, REPORTER_USAGE, None) is None + + +class TestResolveSlotToTrayFallbackRung: + def test_the_reporters_print_resolves_to_tray_3(self): + """End of the chain: no mapping field, colours don't match, and the + tray-change log settles it.""" + pm = _patched_pm(_state(tray_change_log=[(3, 0)], ams=REPORTER_AMS)) + + with patch("backend.app.services.printer_manager.printer_manager", pm): + mapping, source = _resolve_slot_to_tray_fallback(1, REPORTER_USAGE, 255) + + assert mapping == [3] + assert source == "tray_state" + + def test_colour_match_still_wins(self): + """When the slicer colour does equal a tray's, that is a direct + statement about this slot and outranks a tray reading.""" + usage = [{"slot_id": 1, "used_g": 2.17, "color": "#5F4036"}] + pm = _patched_pm(_state(tray_change_log=[(3, 0)], ams=REPORTER_AMS)) + + with patch("backend.app.services.printer_manager.printer_manager", pm): + mapping, source = _resolve_slot_to_tray_fallback(1, usage, 255) + + assert mapping == [2] + assert source == "color_match" + + def test_mapping_field_still_wins(self): + pm = _patched_pm(_state(tray_change_log=[(3, 0)], mapping=[0], ams=REPORTER_AMS)) + + with patch("backend.app.services.printer_manager.printer_manager", pm): + mapping, source = _resolve_slot_to_tray_fallback(1, REPORTER_USAGE, 255) + + assert mapping == [0] + assert source == "mqtt" + + def test_an_empty_status_payload_still_reaches_the_tray_rung(self): + """``tray_change_log`` lives on the state object, not in the status + payload, so an empty payload must not short-circuit past it.""" + pm = _patched_pm(_state(tray_change_log=[(3, 0)])) + + with patch("backend.app.services.printer_manager.printer_manager", pm): + mapping, source = _resolve_slot_to_tray_fallback(1, REPORTER_USAGE, None) + + assert mapping == [3] + assert source == "tray_state" + + def test_only_the_used_slot_is_claimed(self): + """A print whose one filament is slot 3 pads the array so the index + lines up. The padding is -1, which no caller resolves: those slots + consumed nothing.""" + usage = [ + {"slot_id": 1, "used_g": 0.0, "color": "#AAAAAA"}, + {"slot_id": 3, "used_g": 2.17, "color": "#000000"}, + ] + pm = _patched_pm(_state(tray_change_log=[(3, 0)])) + + with patch("backend.app.services.printer_manager.printer_manager", pm): + mapping, source = _resolve_slot_to_tray_fallback(1, usage, None) + + assert mapping == [-1, -1, 3] + assert source == "tray_state" + + def test_still_says_none_when_the_printer_offers_nothing(self): + pm = _patched_pm(_state(tray_change_log=[], tray_now=255, last_loaded_tray=-1, ams=REPORTER_AMS)) + + with patch("backend.app.services.printer_manager.printer_manager", pm): + mapping, source = _resolve_slot_to_tray_fallback(1, REPORTER_USAGE, 255) + + assert mapping is None + assert source == "none" + + +class TestReportUsageChargesTheRightSpool: + """The reporter's archive 12, end to end.""" + + @staticmethod + def _run(tracking, state, spool_by_tag, archive): + rows = iter([tracking]) + + def _next_row(*_args, **_kwargs): + result = MagicMock() + result.scalar_one_or_none.return_value = next(rows, archive) + return result + + db = AsyncMock() + db.execute = AsyncMock(side_effect=_next_row) + db.delete = AsyncMock() + db.commit = AsyncMock() + + client = AsyncMock() + client.find_spool_by_tag = AsyncMock(side_effect=lambda tag: spool_by_tag.get(tag)) + client.use_spool = AsyncMock() + + pm = _patched_pm(state) + + async def _go(): + from backend.app.services.spoolman_tracking import report_usage + + with ( + patch("backend.app.services.spoolman_tracking.async_session", lambda: _AsyncCtx(db)), + patch("backend.app.api.routes.settings.get_setting", AsyncMock(return_value="true")), + patch( + "backend.app.services.spoolman_tracking._get_spoolman_client_with_fallback", + AsyncMock(return_value=client), + ), + patch("backend.app.services.spoolman_tracking._get_printer_serial", AsyncMock(return_value="SER")), + patch( + "backend.app.services.spoolman_tracking._resolve_spool_id_via_slot_assignment", + AsyncMock(return_value=None), + ), + patch("backend.app.services.printer_manager.printer_manager", pm), + ): + await report_usage(printer_id=1, archive_id=12) + + return _go, client + + @staticmethod + def _tracking(): + return SimpleNamespace( + filament_usage=list(REPORTER_USAGE), + ams_trays={ + "0": {"tray_uuid": "TRAY0", "tag_uid": "", "tray_type": "PLA+"}, + "2": {"tray_uuid": "TRAY2", "tag_uid": "", "tray_type": "PLA"}, + "3": {"tray_uuid": "TRAY3", "tag_uid": "", "tray_type": "PLA+"}, + }, + slot_to_tray=None, + tray_remain_start=None, + layer_usage=None, + filament_properties=None, + tray_now_at_start=255, + ) + + SPOOLS = { + # Spool 41 is the grey PLA+ that was wrongly charged 2.17 g. + "TRAY0": {"id": 41, "filament": {"color_hex": "888888", "material": "PLA+"}}, + "TRAY2": {"id": 20, "filament": {"color_hex": "5F4036", "material": "PLA"}}, + "TRAY3": {"id": 46, "filament": {"color_hex": "111111", "material": "PLA+"}}, + } + + @pytest.mark.asyncio + async def test_the_tray_the_printer_named_is_charged(self): + archive = SimpleNamespace(filament_color="#000000", filament_type="PLA+") + state = _state(tray_change_log=[(3, 0)], tray_now=255, last_loaded_tray=3, ams=REPORTER_AMS) + + run, client = self._run(self._tracking(), state, self.SPOOLS, archive) + await run() + + client.use_spool.assert_awaited_once_with(46, 2.17) + + @pytest.mark.asyncio + async def test_the_archive_is_not_restamped_from_a_positional_guess(self): + """Nothing named a tray, so slot 1 is charged by position. The grams + can be put back; overwriting what the slicer recorded cannot, so the + archive keeps the colour and material it was printed with.""" + archive = SimpleNamespace(filament_color="#000000", filament_type="PLA+") + state = _state(tray_change_log=[], tray_now=255, last_loaded_tray=-1, ams=REPORTER_AMS) + + run, client = self._run(self._tracking(), state, self.SPOOLS, archive) + await run() + + client.use_spool.assert_awaited_once_with(41, 2.17) + assert archive.filament_color == "#000000" + assert archive.filament_type == "PLA+" + + @pytest.mark.asyncio + async def test_a_resolved_mapping_still_restamps_the_archive(self): + """#1494 and #2563 are unchanged when the mapping is actually known.""" + archive = SimpleNamespace(filament_color="#000000", filament_type="PLA+") + state = _state(tray_change_log=[(3, 0)], tray_now=255, last_loaded_tray=3, ams=REPORTER_AMS) + + run, _client = self._run(self._tracking(), state, self.SPOOLS, archive) + await run() + + assert archive.filament_color == "#111111" + + +class TestTraySplitIsNotAPositionalGuess: + """A print that switched trays mid-run is attributed per segment from the + tray-change log (#1793). That path never reads ``slot_to_tray``, so the + absence of a mapping says nothing about it -- treating it as a positional + guess would suppress the archive rewrite for the prints whose attribution + is best supported, and log a warning naming a mechanism that did not run. + """ + + @pytest.mark.asyncio + async def test_a_runout_switch_without_a_mapping_still_restamps_the_archive(self): + from backend.app.services.spoolman_tracking import report_usage + + tracking = SimpleNamespace( + filament_usage=[{"slot_id": 1, "used_g": 72.56, "type": "PLA+", "color": "#000000"}], + ams_trays={ + "0": {"tray_uuid": "TRAY0", "tag_uid": "", "tray_type": "PLA+"}, + "3": {"tray_uuid": "TRAY3", "tag_uid": "", "tray_type": "PLA+"}, + }, + # The #2768 condition: a Studio print, so print start stored nothing. + slot_to_tray=None, + tray_remain_start=None, + layer_usage={}, + filament_properties={}, + tray_now_at_start=255, + ) + # The #1793 condition: AMS backup switched tray 0 -> tray 3 at layer 50. + state = SimpleNamespace( + raw_data={"ams": REPORTER_AMS}, + tray_change_log=[(0, 0), (3, 50)], + total_layers=100, + layer_num=100, + tray_now=255, + last_loaded_tray=3, + ) + spools = { + "TRAY0": {"id": 41, "filament": {"color_hex": "888888", "material": "PLA+"}}, + "TRAY3": {"id": 46, "filament": {"color_hex": "111111", "material": "PLA+"}}, + } + archive = SimpleNamespace(filament_color="#000000", filament_type="PLA+") + + rows = iter([tracking]) + + def _next_row(*_args, **_kwargs): + result = MagicMock() + result.scalar_one_or_none.return_value = next(rows, archive) + return result + + db = AsyncMock() + db.execute = AsyncMock(side_effect=_next_row) + db.delete = AsyncMock() + db.commit = AsyncMock() + + client = AsyncMock() + client.find_spool_by_tag = AsyncMock(side_effect=lambda tag: spools.get(tag)) + client.use_spool = AsyncMock() + + with ( + patch("backend.app.services.spoolman_tracking.async_session", lambda: _AsyncCtx(db)), + patch("backend.app.api.routes.settings.get_setting", AsyncMock(return_value="true")), + patch( + "backend.app.services.spoolman_tracking._get_spoolman_client_with_fallback", + AsyncMock(return_value=client), + ), + patch("backend.app.services.spoolman_tracking._get_printer_serial", AsyncMock(return_value="SER")), + patch( + "backend.app.services.spoolman_tracking._resolve_spool_id_via_slot_assignment", + AsyncMock(return_value=None), + ), + patch("backend.app.services.printer_manager.printer_manager", _patched_pm(state)), + ): + await report_usage(printer_id=1, archive_id=12) + + # Both segments charged, so the split path is what ran. + charged = {c.args[0] for c in client.use_spool.await_args_list} + assert charged == {41, 46} + + # And the archive was rewritten from the spools the segments named, + # rather than being left alone as a guess would be. + assert archive.filament_color != "#000000" diff --git a/backend/tests/unit/test_request_topic_probe_2953.py b/backend/tests/unit/test_request_topic_probe_2953.py new file mode 100644 index 000000000..b3527d5ec --- /dev/null +++ b/backend/tests/unit/test_request_topic_probe_2953.py @@ -0,0 +1,131 @@ +"""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