Read the printer's own slot mapping when Spoolman has none (#2768)

A sliced file numbers its filaments 1..4; which AMS tray each came from is
a separate decision made when the job is sent. store_print_data learns it
from one of two sources, both of which require the print command to pass
through us: the mapping Bambuddy chose itself, or the one it intercepted
on the printer's local request topic. A job dispatched from Bambu Studio
while the printer is cloud-bound satisfies neither -- the command travels
through Bambu's broker and never reaches the topic we subscribe to.

slot_to_tray is then NULL and _resolve_global_tray_id guesses by position:
filament 1 from the first loaded tray, filament 2 from the second. The
reporter's X1C was loaded in the order 2, 4, 1, AMS-HT, so all four slots
were charged to the wrong spool. Their log carries the printer's own
answer, mapping=[1, 3, 0, 32768], sitting unread.

usage_tracker has consulted that field since it started resolving mappings
at completion, along with a colour match against the loaded trays for the
models that never publish it (A1, A1 Mini, P1S, P2S). Only the Spoolman
writer, which resolves at print start, never learned to -- and main.py
gates usage_tracker behind Spoolman being off, so enabling Spoolman is
what costs you the better resolver.

_resolve_slot_to_tray_fallback gives it both, at completion rather than at
print start: a printer keeps publishing the last job's mapping while it
sits idle, so reading it early would risk stamping the previous print's
mapping onto this one. A mapping we or the slicer actually recorded is
never second-guessed.

Applied in _report_partial_usage too. Cancelled and failed prints feed the
same slot_to_tray to the same resolver and mis-charged just as readily.

The resolved mapping and its source are now logged at print start and at
completion. "source: none" at start is the signal that completion will
have to fall back, and it was the one line that would have turned this
report into a five-minute triage.

Not addressed: editing the mapping after the fact, which the reporter also
asked for. ArchiveUpdate exposes neither filament field and there is no way
to re-run an attribution, so that is a feature rather than a fix.
This commit is contained in:
maziggy
2026-08-05 11:04:59 +02:00
parent fce7ea0200
commit 6fb6b845e7
3 changed files with 338 additions and 2 deletions
+1
View File
@@ -14,6 +14,7 @@ All notable changes to Bambuddy will be documented in this file.
- **Error and warning toasts now stay up twice as long** — Every pop-up notification disappeared after three seconds regardless of what it said. That is about right for "Settings saved", which confirms something you just did and is skimmed rather than read, but errors and warnings are a different kind of message: they carry a reason, often one relayed from the printer or the backend, and they run to a couple of lines. Three seconds was not long enough to finish reading one, and a missed error message is gone for good — there is no notification history to go back to. Errors and warnings now hold for six seconds. Success and informational toasts keep the three-second default, so the common case of clicking something and seeing it confirmed is unchanged, and the close button and the manual dismiss work exactly as before on all of them. The background print-dispatch toast is unaffected: it stays up while it has work in progress and clears itself shortly after the last job settles. Covered by frontend tests.
### Fixed
- **Spoolman no longer charges a Bambu Studio print to the wrong spool (#2768)** — A sliced file numbers its filaments 1, 2, 3, 4, and which AMS tray each of those came from is a separate decision made when the job is sent. Bambuddy learns that decision one of two ways: it made the choice itself, for a print started from Bambuddy, or it read the print command as it crossed the local network, for a print sent from a slicer. A job dispatched from Bambu Studio while the printer is signed in to Bambu's cloud satisfies neither — the command travels through Bambu's own broker and never appears on the network Bambuddy is listening to. With nothing recorded, the Spoolman writer fell back to assuming the AMS was loaded in slicer order: filament 1 from the first loaded tray, filament 2 from the second. The reporter's X1C was loaded in the order 2, 4, 1, AMS-HT, so every one of the four was deducted from the wrong spool. It also changed what the print looked like afterwards: on completion Bambuddy stamps the archive with the material and colour of the spools it charged, so the print showed the right filament while it ran and switched to a different one the moment it finished — which is how the reporter noticed. The printer knew the answer all along. It publishes the running job's slot-to-tray assignment in its own status, and Bambuddy's built-in filament inventory has read that field for as long as it has resolved mappings at completion; only the Spoolman writer, which resolves at print start instead, never learned to. It now consults the same two fallbacks at the same moment: the printer's report first, and failing that a colour match of the sliced filaments against the loaded trays, which covers the A1, A1 Mini, P1S and P2S — those models publish no such field, so their owners were on the positional guess no matter how the print was sent. Reading the field at completion rather than at print start is deliberate: a printer keeps publishing the last job's mapping while it sits idle, so consulting it early risks stamping the previous print's mapping onto this one. A mapping Bambuddy or the slicer actually recorded is never second-guessed, so nothing changes for prints started from Bambuddy, from the queue, or over LAN. Cancelled and failed prints take the same correction, since partial usage is charged through the same mapping. The resolved mapping and where it came from are now logged at both print start and completion, so the next report of a wrong deduction can be read straight out of a support bundle. Wiki updated. Covered by backend tests.
- **A drying cycle no longer reports itself finished a minute after it starts (#2759)** — Starting the dryer on an AMS 2 Pro holding two PETG and two PLA spools and picking PLA showed "PLA @ 45°C" for about a minute, then switched to "PETG @ 65°C" for the remaining twelve hours. Bambu never echoes back which filament or temperature a cycle is running, so the badge reads the target Bambuddy cached when it sent the command — and that cache had been thrown away. Between accepting the command and settling its countdown the firmware publishes one update with the remaining time at zero while the unit is still in its Checking phase; the reporter's log caught 720 minutes, then 0, then 719. Bambuddy read the zero as the cycle ending. Losing the cached target left the badge to guess the filament from the first loaded slot, which happened to be PETG, and its RFID-recommended 65°C — a confident wrong answer for a cycle running PLA at 45. The same false ending also armed smart-plug auto-off-after-drying, so anyone with that switched on had power scheduled to cut one minute into a twelve-hour dry. A remaining time of zero is now only treated as the end of a cycle when the AMS also reports an idle phase, which the firmware already publishes alongside it; stopping a dry early still ends it immediately, and a unit that reports no phase at all still ends its cycles as before. The fallback guess has been tightened to match, in both directions. It names a filament only when every loaded spool agrees on one — on a mixed unit the badge shows the countdown alone rather than naming a spool the cycle isn't drying — and it no longer guesses a temperature at all. A unit loaded entirely with PLA does tell you what is being dried, but not at what temperature: that is picked freely when the cycle is started, so the spools' RFID-recommended value is never evidence of it, and a second AMS loaded only with PLA and drying at 45°C still read "PLA @ 55°C" whenever the cached target went missing. The badge now names a temperature only when Bambuddy sent it, and shows the filament and countdown without one otherwise. Covered by backend and frontend tests.
- **A print that never starts now says AMS drying was running, instead of blaming the SD card (#2758)** — Sending a job to an X2D with two AMS units mid-drying failed silently: the file uploaded, the printer accepted it and then simply stayed idle. Bambuddy waited out the start watchdog, re-uploaded the whole 3MF, waited again, and after three attempts gave up with advice to check the printer's screen and the SD card — while Bambu Studio, asked directly, said it could not start the job because of the drying. Bambuddy now watches the AMS drying telemetry it already receives across the dispatch window and, when a job never starts while a unit was drying, names the units in the failure message and records the correlation in the log from the first attempt rather than only after the retries are spent. This is deliberately a diagnosis and not a rule: the printers concerned support drying *continuing* through a print, so drying and printing are not in conflict as such, and the report also involved one AMS drying without its external power supply — which would make the start-of-print calibration a power problem rather than a drying one. Stopping the cycle automatically would therefore be acting on a guess, and could tear down drying the hardware was happy to continue. Until it is known which of the two is the real obstacle, Bambuddy tells you what it saw and leaves the call to you. The message for a stalled dispatch with no drying involved is unchanged. Wiki updated. Covered by backend tests.
- **A hand-written systemd service left the Virtual Printer unable to start, with nothing obvious to blame (#2549, reporter @Ru3ck3)** — The Virtual Printer binds ports 990 and 322, both below 1024, which a service running as a normal user may not do without the `CAP_NET_BIND_SERVICE` capability. Without it the rest of Bambuddy works perfectly and only the Virtual Printer is dead: its sockets never open, the slicer never finds the printer, and the sole trace is one line in the journal. The reporter lost days to this before someone on Discord spotted the missing line. The install script has carried it since March, but the three other places that define the same service did not — the manual-install template, the combined Bambuddy plus SpoolBuddy installer, and the unit the wiki tells you to paste. All three have it now, and the wiki no longer claims the capability is always included when its own instructions omitted it. Bambuddy also diagnoses this itself: **Diagnose** on the virtual printer card previously reported only that nothing was listening on port 990, which reads identically to an ordinary port conflict. It now checks whether the process actually holds the capability and, when that is what is wrong, says so and gives the line to add. The check stays quiet when the port is answering, since fronting it another way (an iptables redirect is the documented alternative) is a legitimate setup, and it stays quiet when the capability is held, so a port that failed for some other reason is not misattributed. Existing installs are unaffected until reinstalled; the diagnostic tells you whether yours needs the line. Translated in all locales; wiki updated. Covered by backend tests.
+94 -2
View File
@@ -150,6 +150,62 @@ 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]:
"""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
``ams_mapping`` Bambuddy intercepts on the printer's local request topic, and
a queue item's stored mapping. Neither exists for a print dispatched from
Bambu Studio while the printer is cloud-bound — the command travels through
Bambu's broker and never appears on the local topic we subscribe to. With
``slot_to_tray`` left NULL, ``_resolve_global_tray_id`` guesses by position:
slicer slot 1 to the first loaded tray, slot 2 to the second, and so on. An
AMS that isn't loaded in slicer order then charges every slot to the wrong
spool, and the archive's filament is rewritten to match, so the print
silently changes colour when it finishes (#2768).
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.
Deliberately at completion rather than inside ``store_print_data``: the
printer keeps publishing ``mapping`` long after a job ends — it is still in
the status payload while the printer sits idle — so reading it at print start
risks stamping the *previous* job's mapping onto this one before the printer
has pushed the update. At completion the field unambiguously describes the
job that just ran.
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.
Returns:
``(mapping, source)``, or ``(None, "none")`` when neither 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"
matched = _match_slots_by_color(filament_usage, raw_data.get("ams"))
if matched:
return matched, "color_match"
return None, "none"
def build_ams_tray_lookup(raw_data: dict) -> dict[int, dict]:
"""Build lookup of global_tray_id -> tray info from printer state.
@@ -327,9 +383,11 @@ async def store_print_data(
# Prefer the explicit mapping captured from the print command, then fall back
# to any queue mapping stored for scheduled/reprint jobs.
slot_to_tray = ams_mapping if ams_mapping is not None else None
mapping_source = "print_cmd" if slot_to_tray else None
if not slot_to_tray and queue_item and queue_item.ams_mapping:
try:
slot_to_tray = json.loads(queue_item.ams_mapping)
mapping_source = "queue"
except json.JSONDecodeError:
pass # Ignore malformed AMS mapping; fall back to default slot assignment
@@ -364,8 +422,15 @@ async def store_print_data(
)
logger.debug("[SPOOLMAN] Filament usage: %s", filament_usage)
logger.debug("[SPOOLMAN] AMS trays: %s", list(ams_trays.keys()))
if slot_to_tray:
logger.debug("[SPOOLMAN] Custom slot mapping: %s", slot_to_tray)
# Logged at info even when there is no mapping: "source: none" here is the
# signal that completion will have to fall back, which is the single most
# useful line in the log when a print is charged to the wrong spool (#2768).
logger.info(
"[SPOOLMAN] Print start: archive %s slot_to_tray=%s (source: %s)",
archive_id,
slot_to_tray,
mapping_source or "none",
)
if layer_usage_json:
logger.debug("[SPOOLMAN] Layer usage data available for partial tracking")
@@ -819,6 +884,19 @@ async def _report_partial_usage(
)
return
# Same recovery the completion path does, for the same reason: a print
# dispatched from Studio over the cloud left print start with no mapping to
# store, and both paths below feed ``slot_to_tray`` to
# ``_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)
logger.info(
"[SPOOLMAN] Partial usage: slot_to_tray=%s (source: %s)",
slot_to_tray,
_partial_mapping_source,
)
# Try to use accurate G-code parsed data
if layer_usage:
layer_usage_int = {
@@ -1000,6 +1078,20 @@ async def report_usage(printer_id: int, archive_id: int):
# is the print's last valid layer.
_layer_denom_hint = _total_layers or _current_layer
# Recover the mapping when print start had nothing to store — the
# cloud-dispatched Studio print of #2768. Only the 3MF path consumes
# ``slot_to_tray``; the remain-delta path below resolves spools from the
# 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)
logger.info(
"[SPOOLMAN] Archive %s: slot_to_tray=%s (source: %s)",
archive_id,
slot_to_tray,
mapping_source,
)
slot_colors: dict[int, str] = {}
slot_materials: dict[int, str] = {}
handled_global_tray_ids: set[int] = set()
@@ -0,0 +1,243 @@
"""Slot-to-tray mapping fallbacks on the Spoolman path (#2768).
Bambuddy only learns a print's slot-to-tray mapping at print start when it can
intercept the command on the printer's local MQTT request topic, or when the
print came from its own queue. A print dispatched from Bambu Studio while the
printer is cloud-bound satisfies neither: the command travels through Bambu's
broker, so ``ActivePrintSpoolman.slot_to_tray`` is NULL and every slot falls
through to a positional guess (slicer slot 1 to the first loaded tray, and so
on). The reporter's X1C was loaded out of slicer order, so all four slots were
charged to the wrong spool and the archive's filament was rewritten to match.
The internal-inventory writer never had this problem because it resolves the
mapping at completion, where it can read the printer's own ``mapping`` field or
colour-match the 3MF slots against the loaded trays. These tests cover giving
the Spoolman writer the same two fallbacks.
"""
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
class _AsyncCtx:
"""Minimal async context manager yielding a stub db session."""
def __init__(self, db):
self._db = db
async def __aenter__(self):
return self._db
async def __aexit__(self, *exc):
return False
def _state(**raw):
return SimpleNamespace(raw_data=raw, layer_num=0, total_layers=0, tray_change_log=[])
def _patched_pm(state):
pm = MagicMock()
pm.get_status.return_value = state
return pm
class TestResolveSlotToTrayFallback:
def test_decodes_the_printers_own_mapping_field(self):
"""The reporter's X1C published mapping=[1, 3, 0, 32768] while their
AMS was loaded out of slicer order. Snow-encoded, that is AMS 0 slot 2,
AMS 0 slot 4, AMS 0 slot 1, and the AMS-HT — nothing like the
positional [0, 1, 2, 3] the fallback-free path assumed."""
pm = _patched_pm(_state(mapping=[1, 3, 0, 32768]))
with patch("backend.app.services.printer_manager.printer_manager", pm):
mapping, source = _resolve_slot_to_tray_fallback(1, [{"slot_id": 1, "color": "#FF0000"}])
assert mapping == [1, 3, 0, 128]
assert source == "mqtt"
def test_colour_matches_when_the_printer_publishes_no_mapping(self):
"""A1/P1S/P2S never publish the mapping field. The 3MF's per-slot
colours still identify the trays when each one is unambiguous."""
pm = _patched_pm(
_state(
ams=[
{
"id": 0,
"tray": [
{"id": 0, "tray_color": "00FF00FF", "tray_type": "PLA"},
{"id": 1, "tray_color": "FF0000FF", "tray_type": "PLA"},
],
}
]
)
)
usage = [{"slot_id": 1, "color": "#FF0000"}, {"slot_id": 2, "color": "#00FF00"}]
with patch("backend.app.services.printer_manager.printer_manager", pm):
mapping, source = _resolve_slot_to_tray_fallback(1, usage)
assert mapping == [1, 0]
assert source == "color_match"
def test_mapping_field_wins_over_colour_matching(self):
"""The printer's own field is direct evidence; colour matching is
inference. When both are available the field decides."""
pm = _patched_pm(
_state(
mapping=[3],
ams=[{"id": 0, "tray": [{"id": 0, "tray_color": "FF0000FF", "tray_type": "PLA"}]}],
)
)
with patch("backend.app.services.printer_manager.printer_manager", pm):
mapping, source = _resolve_slot_to_tray_fallback(1, [{"slot_id": 1, "color": "#FF0000"}])
assert mapping == [3]
assert source == "mqtt"
def test_reports_none_when_neither_fallback_answers(self):
"""Ambiguous colours and no mapping field: say so rather than invent
one. The caller keeps the positional default, which is no worse than
before, and the log names the reason."""
pm = _patched_pm(
_state(
ams=[
{
"id": 0,
"tray": [
{"id": 0, "tray_color": "FF0000FF", "tray_type": "PLA"},
{"id": 1, "tray_color": "FF0000FF", "tray_type": "PLA"},
],
}
]
)
)
with patch("backend.app.services.printer_manager.printer_manager", pm):
mapping, source = _resolve_slot_to_tray_fallback(1, [{"slot_id": 1, "color": "#FF0000"}])
assert mapping is None
assert source == "none"
def test_reports_none_when_the_printer_is_offline(self):
"""No live state at completion — the printer dropped off after the
print. Nothing to read, and no crash."""
with patch("backend.app.services.printer_manager.printer_manager", _patched_pm(None)):
mapping, source = _resolve_slot_to_tray_fallback(1, [{"slot_id": 1, "color": "#FF0000"}])
assert mapping is None
assert source == "none"
class TestReportUsageUsesTheFallback:
"""End-to-end through report_usage: the fallback has to reach
``_resolve_global_tray_id`` and change which spool is charged."""
@staticmethod
def _run(tracking, state, spool_by_tag, archive):
# The first SELECT fetches the tracking row; every later one fetches the
# archive for the colour / type rewrites (#1494, #2563).
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=42)
return _go, client
@pytest.mark.asyncio
async def test_mqtt_mapping_charges_the_tray_the_printer_named(self):
"""One-slot print whose filament actually came from AMS slot 4
(global tray 3). With no stored mapping the positional default charges
global tray 0 — the wrong spool, and the archive is then rewritten to
that spool's colour. The printer's mapping field says otherwise."""
tracking = SimpleNamespace(
filament_usage=[{"slot_id": 1, "used_g": 25.0, "type": "PLA", "color": "#FF0000"}],
ams_trays={
"0": {"tray_uuid": "TRAY0UUID", "tag_uid": "", "tray_type": "PLA"},
"3": {"tray_uuid": "TRAY3UUID", "tag_uid": "", "tray_type": "PLA"},
},
slot_to_tray=None,
tray_remain_start=None,
layer_usage=None,
filament_properties=None,
)
state = _state(mapping=[3])
spools = {
"TRAY0UUID": {"id": 100, "filament": {"color_hex": "FFFFFF", "material": "PLA"}},
"TRAY3UUID": {"id": 300, "filament": {"color_hex": "FF0000", "material": "PLA"}},
}
archive = SimpleNamespace(filament_color="#FF0000", filament_type="PLA")
run, client = self._run(tracking, state, spools, archive)
await run()
client.use_spool.assert_awaited_once_with(300, 25.0)
# And the visible half of the bug: the archive keeps the red it was
# printed in instead of being rewritten to the wrong spool's white.
assert archive.filament_color == "#FF0000"
@pytest.mark.asyncio
async def test_a_stored_mapping_is_never_second_guessed(self):
"""Print start captured the real ams_mapping (LAN print, or a Bambuddy
queue job). That is the slicer's own instruction and outranks anything
read back off the printer, whose mapping field may still describe an
earlier job."""
tracking = SimpleNamespace(
filament_usage=[{"slot_id": 1, "used_g": 25.0, "type": "PLA", "color": "#FF0000"}],
ams_trays={
"0": {"tray_uuid": "TRAY0UUID", "tag_uid": "", "tray_type": "PLA"},
"3": {"tray_uuid": "TRAY3UUID", "tag_uid": "", "tray_type": "PLA"},
},
slot_to_tray=[0],
tray_remain_start=None,
layer_usage=None,
filament_properties=None,
)
state = _state(mapping=[3])
spools = {
"TRAY0UUID": {"id": 100, "filament": {"color_hex": "FFFFFF", "material": "PLA"}},
"TRAY3UUID": {"id": 300, "filament": {"color_hex": "FF0000", "material": "PLA"}},
}
archive = SimpleNamespace(filament_color="#FF0000", filament_type="PLA")
run, client = self._run(tracking, state, spools, archive)
await run()
client.use_spool.assert_awaited_once_with(100, 25.0)