Просмотр исходного кода

fix(spoolman): failed print is charged only for what it used (issue #3317)

- Right after a print starts, an H2S can send one frame still carrying
  the previous print's last layer_num (357 at mc_percent 0), then 0.
  The 0 saved 357 as this print's last layer, so a print failing at
  layer 0 got partial usage for the whole print. The layer held at
  print start is now ignored (layer parse and end-of-print probe)
  until the new print reports another layer above 0. Armed only above
  layer 1, so a reprint of a one-layer job keeps its own layer 1.
- parse_gcode_layer_filament_usage counted only positive E. Bambu
  G-code is relative (M83), so every un-retract counted and no
  retract did, putting partial usage 1.1-1.7x above the slicer
  weight. Now the net length per filament, never below 0 per layer.
- Tests replay the reported frame sequences (same and smaller total),
  the one-layer reprint, a normal cancel and the probe; parser tests
  cover retract pairs, layer boundaries, filament changes and the
  zero floor. Each fix hunk was seen to fail its tests when removed.
maziggy 16 часов назад
Родитель
Сommit
a8dd164c71

+ 3 - 0
CHANGELOG.md

@@ -174,6 +174,9 @@ All notable changes to Bambuddy will be documented in this file.
 - **The frontend build no longer warns about `path` and `crypto` being externalized for the STEP previewer (#2976)** — `occt-import-js`, the Emscripten build behind STEP previews, requires both modules, but only inside its `ENVIRONMENT_IS_NODE` branches; in the browser it loads its `.wasm` from the URL the preview worker passes and draws randomness from `crypto.getRandomValues`. Vite still externalized both and printed two warnings on every build. `vite.config.ts` now drops exactly those two warnings for that one package through `build.rolldownOptions.onLog`, so an externalization anywhere else, or of any other module, still shows.
 
 ### Fixed
+- **A print that fails or is cancelled early is charged only for the filament it used (#3317, reported by @ojimpo)** — Two errors added up to a failed print being charged to Spoolman as if it had finished, sometimes for more than the finished print would have used.
+  - **The previous print's layer:** right after a print starts, the printer can send one update that still carries the layer the previous print ended on (seen on an H2S: layer 357 of 357 at 0 %). Bambuddy took it as this print's last layer, so a print that failed before its first layer was charged up to layer 357. That value is now ignored until the new print reports a layer of its own. It also no longer counts as a layer change, so it no longer adds a layer-timelapse frame at print start.
+  - **Retractions:** partial usage is worked out from the extrusion in the file's G-code, which counted each un-retract but never the retract before it. Every retraction added to the total, putting partial usage up to 1.7x above the slicer's weight. Retractions are now subtracted. The split between spools after an AMS switch to a backup spool mid-print uses the same figures.
 - **Writing a SpoolBuddy tag takes it off the spool that held it before (#3312, reported by @sgiffhorn)** — With Spoolman, writing a tag that another spool already carried was meant to clear it from that spool first, but Spoolman refused the empty value Bambuddy sent. Both spools kept the tag, and the next scan could show the old spool. The tag is now cleared properly, from every other spool that carries it, including when the spool being written already held it as a Spoolman 0.27 tag.
 - **A large 3MF that times out at print start is not downloaded a second time (#3308, reported by @elizabethburg)** — On a slow link, such as an A1 in its start-up routine, a 3MF too large to finish in time was downloaded twice: once by name, and again when the folder listing found the same file. Each attempt took up to 5 minutes, holding the printer's only file connection with the cover images queued behind it. It is now tried once. The archive starts without the 3MF and the recovery retry fills it in, with up to 15 minutes for a large file.
 - **"Print again" on the printer's screen is archived with its 3MF (#3307, reported by @elizabethburg)** — A print that archived in full the first time got an empty archive (no 3MF, thumbnail or filament) when started again with **Print again** on the printer. On a reprint the printer doesn't name the file on the card: it reports its own internal copy under a generic name, plus the model's title from inside the 3MF. When that title differs from the file name, as with a project saved under another name, Bambuddy couldn't find the file.

+ 35 - 1
backend/app/services/bambu_mqtt.py

@@ -1456,6 +1456,13 @@ class BambuMQTTClient:
         self._eop_probe_last: dict = {}
         self._last_valid_progress: float = 0.0  # Last non-zero progress (firmware resets on cancel)
         self._last_valid_layer_num: int = 0  # Last non-zero layer (firmware resets on cancel)
+        # #3317: the layer the previous print ended on. Right after a print
+        # starts, the printer can send one frame that still carries it (H2S:
+        # `layer_num` 357 with `mc_percent` 0, then 0 a second later). Taken at
+        # face value, the 0 that follows saved 357 as this print's last layer,
+        # and a print failing at layer 0 was charged as finished. Frames with
+        # this value are ignored until the new print reports another layer.
+        self._stale_layer_num: int = 0
         # The subtask_id minted for the most recent start_print() command. The
         # printer echoes it back in status, but often not within the first few
         # seconds — so on_print_start uses this as the id source when the
@@ -4343,7 +4350,10 @@ class BambuMQTTClient:
             # Open on any end-of-print signal. Read from the raw frame first so
             # the frame that *carries* the signal is itself captured — state
             # fields are only updated further down this same call.
-            layer = self._probe_number(data.get("layer_num"), self.state.layer_num) or 0
+            frame_layer = data.get("layer_num")
+            if self._is_stale_layer(frame_layer):
+                frame_layer = None
+            layer = self._probe_number(frame_layer, self.state.layer_num) or 0
             total = self._probe_number(data.get("total_layer_num"), self.state.total_layers) or 0
             percent = self._probe_number(data.get("mc_percent"), self.state.progress) or 0
             remaining = self._probe_number(data.get("mc_remaining_time"), self.state.remaining_time)
@@ -4396,6 +4406,15 @@ class BambuMQTTClient:
             self._eop_probe_armed = False
             self._eop_probe_last = {}
 
+    def _is_stale_layer(self, value) -> bool:
+        """Whether a frame's `layer_num` is the previous print's last layer (#3317)."""
+        if not self._stale_layer_num:
+            return False
+        try:
+            return int(value) == self._stale_layer_num
+        except (TypeError, ValueError):
+            return False
+
     def _update_state(self, data: dict):
         """Update printer state from message data."""
         _previous_state = self.state.state
@@ -4497,6 +4516,17 @@ class BambuMQTTClient:
                     data["layer_num"],
                 )
                 new_layer = self.state.layer_num
+            if self._is_stale_layer(new_layer):
+                logger.debug(
+                    "[%s] ignoring layer_num %s: last layer of the previous print",
+                    self.serial_number,
+                    new_layer,
+                )
+                new_layer = self.state.layer_num
+            elif new_layer > 0:
+                # The new print reports a layer of its own; from here on the
+                # previous print's value is a layer this print can reach.
+                self._stale_layer_num = 0
             old_layer = self.state.layer_num
             # Save last non-zero layer for usage tracking (firmware resets to 0 on cancel)
             if old_layer > 0:
@@ -5712,6 +5742,10 @@ class BambuMQTTClient:
             # Clear any old HMS errors when a new print starts
             self.state.hms_errors = []
             # Reset layer tracking for new print (needed for layer-based timelapse)
+            # #3317: only above 1. Every print reports layer 1 first, which
+            # clears a higher value; a previous print that ended on layer 1
+            # would make this print's own first layer look stale.
+            self._stale_layer_num = self.state.layer_num if self.state.layer_num > 1 else 0
             self.state.layer_num = 0
             # Reset total_layers so the previous print's value can't bleed into
             # this print's usage-tracker split (#1771 follow-on to the

+ 20 - 7
backend/app/utils/threemf_tools.py

@@ -54,7 +54,8 @@ def parse_gcode_layer_filament_usage(gcode_content: str) -> dict[int, dict[int,
     G-code commands parsed:
         - M73 L<layer>: Layer change marker
         - M620 S<filament>: Filament/tool change (S255 = unload)
-        - G0/G1/G2/G3 E<amount>: Extrusion moves
+        - G0/G1/G2/G3 E<amount>: Extrusion moves (relative E; retractions
+          are subtracted, so each layer holds the net length fed)
     """
     layer_filaments: dict[int, dict[int, float]] = {}
     current_layer = 0
@@ -92,7 +93,7 @@ def parse_gcode_layer_filament_usage(gcode_content: str) -> dict[int, dict[int,
                         new_layer = int(part[1:])
                         # Save current state before layer change
                         if cumulative_extrusion:
-                            layer_filaments[current_layer] = cumulative_extrusion.copy()
+                            layer_filaments[current_layer] = _snapshot(cumulative_extrusion)
                         current_layer = new_layer
                     except ValueError:
                         pass  # Skip G-code lines with unparseable layer numbers
@@ -127,20 +128,32 @@ def parse_gcode_layer_filament_usage(gcode_content: str) -> dict[int, dict[int,
                 if part_upper.startswith("E"):
                     try:
                         extrusion = float(part[1:])
-                        # Only count positive extrusion (not retractions)
-                        if extrusion > 0:
-                            current = cumulative_extrusion.get(active_filament, 0)
-                            cumulative_extrusion[active_filament] = current + extrusion
+                        # Net sum, retractions included (#3317). Bambu G-code is
+                        # relative (M83): every retract is followed by an
+                        # un-retract of the same length, so counting only the
+                        # positive half added each pair to the total and put a
+                        # print 1.1-1.7x above the slicer's weight.
+                        current = cumulative_extrusion.get(active_filament, 0)
+                        cumulative_extrusion[active_filament] = current + extrusion
                     except ValueError:
                         pass  # Skip G-code lines with unparseable extrusion values
 
     # Save final layer state
     if cumulative_extrusion:
-        layer_filaments[current_layer] = cumulative_extrusion.copy()
+        layer_filaments[current_layer] = _snapshot(cumulative_extrusion)
 
     return layer_filaments
 
 
+def _snapshot(cumulative_extrusion: dict[int, float]) -> dict[int, float]:
+    """Copy the running totals for one layer, never below zero.
+
+    A filament retracted before it has extruded anything would otherwise read
+    as negative usage at that layer.
+    """
+    return {filament: max(mm, 0.0) for filament, mm in cumulative_extrusion.items()}
+
+
 def mm_to_grams(
     length_mm: float,
     diameter_mm: float = DEFAULT_FILAMENT_DIAMETER,

+ 110 - 0
backend/tests/unit/services/test_bambu_mqtt.py

@@ -7069,6 +7069,116 @@ class TestPrintRunningObservedCallback:
         }
 
 
+class TestPreviousPrintLayerIgnored:
+    """#3317: right after a print starts, an H2S sent one frame carrying the
+    previous print's last layer (`layer_num` 357, `mc_percent` 0), then 0. The
+    0 saved 357 as the new print's last layer, so a print failing at layer 0
+    was charged to Spoolman as if it had finished.
+    """
+
+    FILE = "/data/Metadata/plate_1.gcode"
+
+    @pytest.fixture
+    def mqtt_client(self):
+        from backend.app.services.bambu_mqtt import BambuMQTTClient
+
+        client = BambuMQTTClient(
+            ip_address="192.168.1.100",
+            serial_number="TEST123",
+            access_code="12345678",
+        )
+        client.on_print_start = lambda data: None
+        client.layer_changes = []
+        client.on_layer_change = client.layer_changes.append
+        client.completions = []
+        client.on_print_complete = client.completions.append
+        return client
+
+    def _finished_previous_print(self, client, layers: int):
+        client._previous_gcode_state = "FINISH"
+        client._previous_gcode_file = self.FILE
+        client._was_running = False
+        client.state.state = "FINISH"
+        client.state.gcode_file = self.FILE
+        client.state.layer_num = layers
+        client.state.total_layers = layers
+
+    def _start(self, client):
+        client._process_message({"print": {"gcode_state": "RUNNING", "gcode_file": self.FILE, "subtask_name": "t"}})
+
+    def _fail(self, client) -> dict:
+        client._process_message({"print": {"gcode_state": "FAILED", "gcode_file": self.FILE}})
+        assert len(client.completions) == 1
+        return client.completions[0]
+
+    def test_failure_before_first_layer_reports_layer_zero(self, mqtt_client):
+        # The 2026-10-14 sequence from the report: same layer count as before.
+        self._finished_previous_print(mqtt_client, 357)
+        self._start(mqtt_client)
+        mqtt_client._process_message({"print": {"layer_num": 357, "total_layer_num": 357, "mc_percent": 0}})
+        assert mqtt_client.state.layer_num == 0
+        mqtt_client._process_message({"print": {"layer_num": 0}})
+
+        assert self._fail(mqtt_client)["last_layer_num"] == 0
+        assert mqtt_client.layer_changes == []
+
+    def test_stale_layer_above_new_total_is_ignored(self, mqtt_client):
+        # The 2026-10-13 sequence: 357 from the previous print, 55 for this one.
+        self._finished_previous_print(mqtt_client, 357)
+        self._start(mqtt_client)
+        mqtt_client._process_message({"print": {"layer_num": 357, "total_layer_num": 55, "mc_percent": 0}})
+        mqtt_client._process_message({"print": {"layer_num": 0}})
+
+        assert mqtt_client.state.layer_num == 0
+        assert mqtt_client.state.total_layers == 55
+        assert self._fail(mqtt_client)["last_layer_num"] == 0
+
+    def test_new_print_can_reach_the_previous_last_layer(self, mqtt_client):
+        # Once the print reports a layer of its own, the old value is just a
+        # layer number again.
+        self._finished_previous_print(mqtt_client, 3)
+        self._start(mqtt_client)
+        for layer in (3, 0, 1, 2, 3, 4):
+            mqtt_client._process_message({"print": {"layer_num": layer}})
+        assert mqtt_client.state.layer_num == 4
+        mqtt_client._process_message({"print": {"layer_num": 0}})
+
+        assert self._fail(mqtt_client)["last_layer_num"] == 4
+        assert mqtt_client.layer_changes == [1, 2, 3, 4]
+
+    def test_previous_print_ending_on_layer_one_does_not_hide_layer_one(self, mqtt_client):
+        # A one-layer print printed again: its own layer 1 is the only layer it
+        # reports, so it must not be taken for the previous print's.
+        self._finished_previous_print(mqtt_client, 1)
+        self._start(mqtt_client)
+        mqtt_client._process_message({"print": {"layer_num": 1, "total_layer_num": 1}})
+        assert mqtt_client.state.layer_num == 1
+        mqtt_client._process_message({"print": {"layer_num": 0}})
+
+        assert self._fail(mqtt_client)["last_layer_num"] == 1
+        assert mqtt_client.layer_changes == [1]
+
+    def test_cancel_mid_print_still_keeps_last_layer(self, mqtt_client):
+        # The firmware's reset-to-0 on cancel is what `_last_valid_layer_num`
+        # exists for; the guard must not get in its way.
+        self._finished_previous_print(mqtt_client, 0)
+        self._start(mqtt_client)
+        for layer in (1, 2, 50):
+            mqtt_client._process_message({"print": {"layer_num": layer}})
+        mqtt_client._process_message({"print": {"layer_num": 0}})
+
+        assert self._fail(mqtt_client)["last_layer_num"] == 50
+
+    def test_stale_layer_does_not_open_end_of_print_probe(self, mqtt_client, caplog):
+        self._finished_previous_print(mqtt_client, 357)
+        self._start(mqtt_client)
+        with caplog.at_level(logging.DEBUG, logger="backend.app.services.bambu_mqtt"):
+            mqtt_client._process_message({"print": {"layer_num": 357, "total_layer_num": 357, "mc_percent": 0}})
+
+        assert "EOP-PROBE open" not in caplog.text
+        assert mqtt_client._eop_probe_open is False
+
+
 class TestTotalLayersPreservation:
     """#1771: P1S firmware resets `total_layer_num` to 0 at print end. Without
     this guard, the usage tracker's split path saw `state.total_layers = 0` at

+ 47 - 2
backend/tests/unit/test_threemf_tools.py

@@ -86,17 +86,62 @@ G1 E2.0
         # Layer 2: filament 0 = 15mm (13+2)
         assert result[2] == {0: 15.0, 1: 5.0}
 
-    def test_retractions_ignored(self):
-        """Negative E values (retractions) should be ignored."""
+    def test_retractions_subtracted(self):
+        """#3317: a retract and its un-retract cancel out (relative E, M83).
+
+        Counting only the positive half added every pair to the total and put
+        a failed print's partial usage 1.7x above the slicer's weight.
+        """
         gcode = """
 M620 S0
 G1 E10.0
 G1 E-2.0
+G1 E2.0
 G1 E5.0
 """
         result = parse_gcode_layer_filament_usage(gcode)
         assert result == {0: {0: 15.0}}
 
+    def test_retraction_across_layer_change(self):
+        """A retract before the layer change is part of the layer it ends."""
+        gcode = """
+M620 S0
+G1 E10.0
+G1 E-0.8
+M73 L1
+G1 E0.8
+G1 E4.0
+"""
+        result = parse_gcode_layer_filament_usage(gcode)
+        assert result[0] == {0: pytest.approx(9.2)}
+        assert result[1] == {0: pytest.approx(14.0)}
+
+    def test_retractions_kept_per_filament(self):
+        """A filament's retract before a change stays on that filament."""
+        gcode = """
+M620 S0
+G1 E10.0
+G1 E-2.0
+M620 S1
+G1 E6.0
+G1 E-1.0
+G1 E1.0
+"""
+        result = parse_gcode_layer_filament_usage(gcode)
+        assert result == {0: {0: 8.0, 1: 6.0}}
+
+    def test_net_usage_never_negative(self):
+        """A filament retracted before it has extruded reads 0, not negative."""
+        gcode = """
+M620 S1
+G1 E-3.0
+M73 L1
+G1 E5.0
+"""
+        result = parse_gcode_layer_filament_usage(gcode)
+        assert result[0] == {1: 0.0}
+        assert result[1] == {1: 2.0}
+
     def test_m620_s255_unloads(self):
         """M620 S255 means unload - extrusion after should be ignored."""
         gcode = """