fix(spoolman): failed prints are logged with their spool cost, queue estimates use Spoolman prices

CHANGELOG.md

@@ -164,6 +164,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
+- **Spoolman costs** —
+  - A failed or stopped print in Spoolman mode is logged in Print History with what its Spoolman spools cost for the filament it used, as with the built-in inventory. It was logged with no cost.
+  - The estimated cost of a queued library file is priced from the Spoolman spools in the trays it maps to. Every slot was priced at the default filament cost.
 - **Spoolman usage** —
   - Two copies of the same archive printing at once on two printers are both charged to Spoolman. The second print's start failed on the shared archive and that print was never deducted.
   - A filament slot the print does not feed is no longer charged to the external spool, or to whichever AMS tray sits at that position, as with the built-in inventory.

backend/app/main.py

@@ -8166,6 +8166,9 @@ async def on_print_complete(printer_id: int, data: dict):
         logger.warning("Failed to clear persisted print session for printer %s: %s", printer_id, e)
 
     # Spoolman: report filament usage (requires archive_id for tracking data lookup)
+    # A partial run's cost from the Spoolman spools it was charged to; the
+    # built-in inventory's comes in usage_results.
+    spoolman_run_cost: float | None = None
     if archive_id:
         if data.get("status") == "completed":
             try:
@@ -8177,7 +8180,7 @@ async def on_print_complete(printer_id: int, data: dict):
             # Report partial usage if tracking data exists (only stored when weight sync is disabled)
             try:
                 async with async_session() as db:
-                    await _cleanup_spoolman_tracking(
+                    spoolman_run_cost = await _cleanup_spoolman_tracking(
                         printer_id,
                         archive_id,
                         db,
@@ -8507,6 +8510,8 @@ async def on_print_complete(printer_id: int, data: dict):
                 _run_cost: float | None = None
                 if usage_results:
                     _run_cost = sum(r.get("cost") or 0 for r in usage_results) or None
+                if _run_cost is None and _run_status != "completed":
+                    _run_cost = spoolman_run_cost
                 if _run_cost is None and _run_status == "completed":
                     _run_cost = _est_cost
 

backend/app/services/print_cost_estimate.py

@@ -70,7 +70,7 @@ def _parse_mapping(mapping: list[int] | str | None) -> list[int] | None:
     return None
 
 
-def _global_tray_id(assignment: SpoolAssignment) -> int:
+def _global_tray_id(assignment) -> int:
     if assignment.ams_id == 255:
         return 254 + assignment.tray_id
     if assignment.ams_id >= 128:
@@ -78,6 +78,39 @@ def _global_tray_id(assignment: SpoolAssignment) -> int:
     return assignment.ams_id * 4 + assignment.tray_id
 
 
+async def _spoolman_cost_by_tray(db: AsyncSession, printer_id: int, trays: set[int]) -> dict[int, float | None]:
+    """Per-kg price of the Spoolman spool in each of ``trays``, from the spool's
+    own price or its filament's. Only those spools are fetched, after a health
+    check: this runs on queue add and at dispatch. Empty when Spoolman cannot
+    be asked, and the estimate uses the default rate, as for an unpriced spool.
+    """
+    from backend.app.models.spoolman_slot_assignment import SpoolmanSlotAssignment
+    from backend.app.services.spoolman_tracking import _get_spoolman_client_with_fallback, _spool_cost_per_gram
+
+    rows = [
+        row
+        for row in (
+            await db.execute(select(SpoolmanSlotAssignment).where(SpoolmanSlotAssignment.printer_id == printer_id))
+        )
+        .scalars()
+        .all()
+        if _global_tray_id(row) in trays
+    ]
+    if not rows:
+        return {}
+    by_tray: dict[int, float | None] = {}
+    try:
+        client = await _get_spoolman_client_with_fallback()
+        if client is None:
+            return {}
+        for row in rows:
+            per_gram = _spool_cost_per_gram(await client.get_spool(row.spoolman_spool_id))
+            by_tray[_global_tray_id(row)] = per_gram * 1000.0 if per_gram is not None else None
+    except Exception as exc:  # noqa: BLE001 — an estimate falls back to the default rate
+        logger.debug("Spoolman prices unavailable for the queue estimate: %s", exc)
+    return by_tray
+
+
 async def default_cost_per_kg(db: AsyncSession) -> float:
     """The default filament price per kg, as the Settings page shows it: 25
     when it was never saved."""
@@ -172,11 +205,14 @@ async def estimate_queue_source_cost(
     default_cost = await default_cost_per_kg(db)
     cost_by_tray: dict[int, float | None] = {}
     mapping = _parse_mapping(ams_mapping)
-    # Built-in spool prices only. In Spoolman mode the built-in table may still
-    # hold rows from before the user switched -- nothing clears it since #2812 --
-    # and pricing an estimate from a spool the printer is not drawing on would
-    # be worse than the default rate this falls back to.
-    if printer_id is not None and mapping and not await spoolman_owns_assignments(db):
+    # The prices of the spools the mode's own table puts in those trays. The
+    # built-in table may still hold rows from before a switch to Spoolman --
+    # nothing clears it since #2812 -- and pricing from a spool the printer is
+    # not drawing on would be worse than the default rate this falls back to.
+    spoolman_mode = await spoolman_owns_assignments(db)
+    if printer_id is not None and mapping and spoolman_mode:
+        cost_by_tray = await _spoolman_cost_by_tray(db, printer_id, {t for t in mapping if t >= 0})
+    if printer_id is not None and mapping and not spoolman_mode:
         assignments = (
             (
                 await db.execute(

backend/app/services/spoolman_tracking.py

@@ -592,8 +592,11 @@ async def cleanup_tracking(
     db,
     last_layer_num: int | None = None,
     last_progress: int | None = None,
-):
-    """Report partial usage and clean up Spoolman tracking data for failed/aborted prints."""
+) -> float | None:
+    """Report partial usage and clean up Spoolman tracking data for failed/aborted prints.
+
+    Returns what the charged spools' prices make the run cost, or None when
+    none of them carries a price (or nothing was tracked)."""
     from backend.app.models.active_print_spoolman import ActivePrintSpoolman
 
     # Get tracking data first (needed for partial usage reporting)
@@ -606,15 +609,18 @@ async def cleanup_tracking(
 
     if not tracking:
         logger.debug("[SPOOLMAN] No tracking data to clean up for printer=%s, archive=%s", printer_id, archive_id)
-        return
+        return None
 
-    # Try to report partial usage before cleanup
+    # Try to report partial usage before cleanup, pricing each charge as it
+    # is made: the run's own cost, as the built-in inventory logs it.
+    print_cost = _PrintCost()
     try:
         await _report_partial_usage(
             printer_id,
             tracking,
             last_layer_num=last_layer_num,
             last_progress=last_progress,
+            cost_out=print_cost,
         )
     except Exception as e:
         logger.warning("[SPOOLMAN] Partial usage report failed: %s", e)
@@ -627,6 +633,14 @@ async def cleanup_tracking(
     )
     await db.commit()
     logger.debug("[SPOOLMAN] Cleaned up tracking data for printer=%s, archive=%s", printer_id, archive_id)
+    # A charged spool without a price at the default rate, as the built-in
+    # inventory prices its own (usage_tracker's cost_per_kg fallback).
+    run_cost = print_cost.cost
+    if print_cost.unpriced_grams > 0:
+        from backend.app.services.print_cost_estimate import default_cost_per_kg
+
+        run_cost += print_cost.unpriced_grams / 1000.0 * await default_cost_per_kg(db)
+    return round(run_cost, 2) or None
 
 
 async def release_archived_slot_rows(printer_id: int) -> None:
@@ -825,6 +839,7 @@ class _PrintCost:
 
     cost: float = 0.0
     priced_grams: float = 0.0
+    unpriced_grams: float = 0.0
     priced: int = 0
     unpriced: int = 0
 
@@ -835,6 +850,7 @@ class _PrintCost:
         rate = _spool_cost_per_gram(spool)
         if rate is None:
             self.unpriced += 1
+            self.unpriced_grams += grams
             logger.debug("[SPOOLMAN] %s: spool has no usable price, will fall back to the default rate", label)
             return
         self.cost += grams * rate
@@ -1127,6 +1143,7 @@ async def _report_partial_usage(
     tracking,
     last_layer_num: int | None = None,
     last_progress: int | None = None,
+    cost_out: _PrintCost | None = None,
 ):
     """Report partial filament usage based on actual G-code layer data.
 
@@ -1218,6 +1235,7 @@ async def _report_partial_usage(
             handled_global_tray_ids=set(),
             archive_id=getattr(tracking, "archive_id", -1),
             print_used_keys=_print_used_tray_keys(slot_to_tray, getattr(tracking, "tray_now_at_start", None), state),
+            cost_out=cost_out,
         )
         return
 
@@ -1284,6 +1302,7 @@ async def _report_partial_usage(
                 "Partial (G-code)",
                 printer_serial,
                 printer_id=printer_id,
+                cost_out=cost_out,
             )
             if spools_updated > 0:
                 logger.info("[SPOOLMAN] Reported partial usage to %s spool(s) using G-code data", spools_updated)
@@ -1322,6 +1341,7 @@ async def _report_partial_usage(
         "Partial (linear)",
         printer_serial,
         printer_id=printer_id,
+        cost_out=cost_out,
     )
     if spools_updated > 0:
         logger.info("[SPOOLMAN] Reported partial usage to %s spool(s) using linear interpolation", spools_updated)

backend/tests/integration/test_queue_estimate_spoolman_prices.py

@@ -0,0 +1,79 @@
+"""The queue's cost estimate prices a library file from the Spoolman spools in
+its trays, as it does from built-in spools. Every slot used to be priced at
+the default rate in Spoolman mode."""
+
+from pathlib import Path
+from unittest.mock import AsyncMock, MagicMock, patch
+
+import pytest
+
+from backend.app.models.settings import Settings
+from backend.app.models.spoolman_slot_assignment import SpoolmanSlotAssignment
+from backend.app.services import print_cost_estimate as pce
+
+
+@pytest.mark.asyncio
+@pytest.mark.integration
+@pytest.mark.parametrize("price,expected", [(60.0, 6.0), (None, 2.5)])
+async def test_a_slot_is_priced_from_its_spoolman_spool(db_session, printer_factory, price, expected):
+    """100 g from a 60/kg Spoolman spool is 6.00; an unpriced one falls back to the 25/kg default."""
+    db_session.add(Settings(key="spoolman_enabled", value="true"))
+    printer = await printer_factory()
+    db_session.add(SpoolmanSlotAssignment(printer_id=printer.id, ams_id=0, tray_id=2, spoolman_spool_id=42))
+    await db_session.commit()
+    client = MagicMock()
+    client.get_spool = AsyncMock(
+        return_value={"id": 42, "price": price, "initial_weight": 1000.0, "filament": {"weight": 1000.0}}
+    )
+    library_file = MagicMock(file_metadata={"filament_used_grams": 100.0})
+
+    with (
+        patch(
+            "backend.app.services.spoolman_tracking._get_spoolman_client_with_fallback",
+            AsyncMock(return_value=client),
+        ),
+        patch("backend.app.services.print_cost_estimate._source_path", return_value=Path("/nonexistent.3mf")),
+    ):
+        cost = await pce.estimate_queue_source_cost(
+            db_session, library_file=library_file, ams_mapping=[2], printer_id=printer.id
+        )
+
+    assert cost == expected
+
+
+@pytest.mark.asyncio
+@pytest.mark.integration
+async def test_only_the_spools_the_job_uses_are_asked_for(db_session, printer_factory):
+    """Runs on queue add and at dispatch: no spool outside the mapped trays,
+    and an unreachable Spoolman falls back to the default rate at once."""
+    db_session.add(Settings(key="spoolman_enabled", value="true"))
+    printer = await printer_factory()
+    db_session.add(SpoolmanSlotAssignment(printer_id=printer.id, ams_id=0, tray_id=2, spoolman_spool_id=42))
+    db_session.add(SpoolmanSlotAssignment(printer_id=printer.id, ams_id=0, tray_id=3, spoolman_spool_id=43))
+    await db_session.commit()
+    client = MagicMock()
+    client.get_spool = AsyncMock(return_value={"id": 42, "price": 60.0, "initial_weight": 1000.0})
+    library_file = MagicMock(file_metadata={"filament_used_grams": 100.0})
+
+    with (
+        patch(
+            "backend.app.services.spoolman_tracking._get_spoolman_client_with_fallback",
+            AsyncMock(return_value=client),
+        ),
+        patch("backend.app.services.print_cost_estimate._source_path", return_value=Path("/nonexistent.3mf")),
+    ):
+        await pce.estimate_queue_source_cost(
+            db_session, library_file=library_file, ams_mapping=[2], printer_id=printer.id
+        )
+    client.get_spool.assert_awaited_once_with(42)
+
+    with (
+        patch(
+            "backend.app.services.spoolman_tracking._get_spoolman_client_with_fallback", AsyncMock(return_value=None)
+        ),
+        patch("backend.app.services.print_cost_estimate._source_path", return_value=Path("/nonexistent.3mf")),
+    ):
+        cost = await pce.estimate_queue_source_cost(
+            db_session, library_file=library_file, ams_mapping=[2], printer_id=printer.id
+        )
+    assert cost == 2.5

backend/tests/unit/services/test_mode_toggle_keeps_assignments_2812.py

@@ -137,6 +137,12 @@ class TestCostEstimateIgnoresTheInactiveModesTable:
                 "backend.app.services.print_cost_estimate._source_path",
                 return_value=__import__("pathlib").Path("/nonexistent/never.3mf"),
             ),
+            # Spoolman's own slot table answers in Spoolman mode, here with no price.
+            patch(
+                "backend.app.services.print_cost_estimate._spoolman_cost_by_tray",
+                new_callable=AsyncMock,
+                return_value={},
+            ),
         ):
             return await pce.estimate_queue_source_cost(
                 db,

backend/tests/unit/test_spoolman_failed_run_cost.py

@@ -0,0 +1,94 @@
+"""A failed or stopped print in Spoolman mode is logged with its own cost.
+
+The run's cost came only from the built-in tracker's results, or from the
+estimate for a completed print, so a failed Spoolman print had none in Print
+History. Its Spoolman charges are priced as they are made, and that is the
+run's cost, as with the built-in inventory.
+"""
+
+import asyncio
+from types import SimpleNamespace
+from unittest.mock import AsyncMock, MagicMock, patch
+
+import pytest
+from sqlalchemy.ext.asyncio import AsyncSession, async_sessionmaker
+
+from backend.app import main as main_module
+from backend.app.services.bambu_ftp import DeleteResult
+
+
+@pytest.fixture(autouse=True)
+def _clean_state():
+    main_module._active_prints.clear()
+    main_module._print_plate_ids.clear()
+    yield
+    main_module._active_prints.clear()
+    main_module._print_plate_ids.clear()
+
+
+async def _complete(test_engine, printer_id: int) -> list:
+    """Run on_print_complete against the test database; return the plates the
+    estimates were asked for (billing first, then the print log)."""
+    real_db = async_sessionmaker(test_engine, class_=AsyncSession, expire_on_commit=False)
+    asked: list = []
+
+    def _estimate(archive, full_path, plate_id=None):
+        asked.append(plate_id)
+        return None, None
+
+    tasks_before = set(asyncio.all_tasks())
+    with (
+        patch("backend.app.main.async_session", real_db),
+        patch("backend.app.core.database.async_session", real_db),
+        patch("backend.app.main._plate_scoped_run_estimate", side_effect=_estimate),
+        patch("backend.app.main.ws_manager") as mock_ws,
+        patch("backend.app.main.printer_manager") as mock_pm,
+        patch("backend.app.main.mqtt_relay") as mock_relay,
+        patch("backend.app.main.notification_service") as mock_notif,
+        patch("backend.app.main.smart_plug_manager") as mock_plug,
+        patch("backend.app.main.clear_3mf_cache"),
+        patch("backend.app.services.bambu_ftp.delete_file_async", new=AsyncMock(return_value=DeleteResult.DELETED)),
+    ):
+        mock_ws.send_print_complete = AsyncMock()
+        mock_ws.broadcast = AsyncMock()
+        mock_relay.on_print_complete = AsyncMock()
+        mock_relay.on_queue_job_completed = AsyncMock()
+        mock_notif.on_print_complete = AsyncMock()
+        mock_plug.on_print_complete = AsyncMock()
+        mock_pm.get_printer = MagicMock(return_value=SimpleNamespace(name="Test", serial_number="TEST123"))
+        mock_pm.get_current_print_user = MagicMock(return_value=None)
+        mock_pm.clear_current_print_user = MagicMock()
+        mock_pm.set_awaiting_plate_clear = MagicMock()
+
+        await main_module.on_print_complete(
+            printer_id,
+            {"status": "failed", "filename": "multi.gcode.3mf", "subtask_name": "multi", "progress": 40},
+        )
+
+        for task in asyncio.all_tasks() - tasks_before:
+            task.cancel()
+            try:
+                await task
+            except (asyncio.CancelledError, Exception):
+                pass
+    return asked
+
+
+@pytest.mark.asyncio
+async def test_a_failed_spoolman_print_is_logged_with_what_its_spools_cost(
+    test_engine, db_session, printer_factory, archive_factory
+):
+    printer = await printer_factory()
+    archive = await archive_factory(printer.id, filename="multi.gcode.3mf", status="printing", with_run=False)
+    archive_id = archive.id
+    main_module._active_prints[(printer.id, "multi.gcode.3mf")] = archive_id
+
+    with (
+        patch("backend.app.main._cleanup_spoolman_tracking", AsyncMock(return_value=3.5)),
+        patch("backend.app.services.print_log.write_log_entry", new_callable=AsyncMock) as logged,
+        patch("backend.app.services.print_log.record_archive_wear", new_callable=AsyncMock),
+    ):
+        await _complete(test_engine, printer.id)
+
+    logged.assert_awaited_once()
+    assert (logged.await_args.kwargs["archive_id"], logged.await_args.kwargs["cost"]) == (archive_id, 3.5)

backend/tests/unit/test_spoolman_no3mf_remain_fallback.py

@@ -13,6 +13,7 @@ from unittest.mock import AsyncMock, MagicMock, patch
 
 import pytest
 
+from backend.app.models import active_print_spoolman  # noqa: F401  (registers its table)
 from backend.app.services.spoolman_tracking import (
     _snapshot_tray_remain,
     store_print_data,
@@ -538,6 +539,107 @@ class TestPartialUsageRemainDelta:
         client.use_spool.assert_awaited_once_with(7, 50.0)
 
 
+class TestPartialUsageCost:
+    """A failed or stopped print's charges are priced as they are made, so the
+    run is logged with its own cost, as in the built-in inventory."""
+
+    @pytest.mark.asyncio
+    async def test_the_remain_delta_charge_is_priced(self):
+        from backend.app.services.spoolman_tracking import _PrintCost, _report_partial_usage
+
+        tracking = SimpleNamespace(
+            archive_id=99,
+            filament_usage=None,
+            layer_usage=None,
+            filament_properties=None,
+            ams_trays={"0": {"tray_uuid": "AAAA"}},
+            slot_to_tray=None,
+            tray_remain_start={"0-0": {"remain": 90, "tray_uuid": "AAAA"}},
+        )
+        client = AsyncMock()
+        # 20 for the 1000 g spool: 0.02 a gram.
+        client.get_spool = AsyncMock(
+            return_value={"id": 7, "price": 20.0, "initial_weight": 1000.0, "filament": {"weight": 1000.0}}
+        )
+        client.use_spool = AsyncMock()
+        printer_manager = MagicMock()
+        printer_manager.get_status.return_value = SimpleNamespace(
+            raw_data={"ams": [{"id": 0, "tray": [{"id": 0, "tray_uuid": "AAAA", "remain": 70}]}]},
+            layer_num=42,
+            total_layers=100,
+        )
+        cost = _PrintCost()
+
+        with (
+            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="serial")),
+            patch(
+                "backend.app.services.spoolman_tracking._resolve_spool_id_via_slot_assignment",
+                AsyncMock(return_value=7),
+            ),
+            patch("backend.app.services.printer_manager.printer_manager", printer_manager),
+        ):
+            await _report_partial_usage(printer_id=1, tracking=tracking, cost_out=cost)
+
+        assert round(cost.cost, 2) == 4.0
+
+    @pytest.mark.asyncio
+    async def test_cleanup_returns_the_runs_cost(self, db_session, printer_factory, archive_factory):
+        from backend.app.models.active_print_spoolman import ActivePrintSpoolman
+        from backend.app.services.spoolman_tracking import cleanup_tracking
+
+        printer = await printer_factory()
+        archive = await archive_factory(printer.id, status="printing", with_run=False)
+        db_session.add(ActivePrintSpoolman(printer_id=printer.id, archive_id=archive.id, ams_trays={}))
+        await db_session.commit()
+
+        async def _charge(printer_id, tracking, last_layer_num=None, last_progress=None, cost_out=None):
+            cost_out.add(50.0, {"price": 20.0, "initial_weight": 1000.0}, "Slot 1")
+
+        with patch("backend.app.services.spoolman_tracking._report_partial_usage", side_effect=_charge):
+            run_cost = await cleanup_tracking(printer.id, archive.id, db_session, last_progress=50)
+
+        assert run_cost == 1.0
+
+    @pytest.mark.asyncio
+    async def test_a_charged_spool_without_a_price_is_costed_at_the_default(
+        self, db_session, printer_factory, archive_factory
+    ):
+        """20 g at 60/kg plus 30 g off an unpriced spool at the 25/kg default,
+        as the built-in inventory prices it."""
+        from backend.app.models.active_print_spoolman import ActivePrintSpoolman
+        from backend.app.services.spoolman_tracking import cleanup_tracking
+
+        printer = await printer_factory()
+        archive = await archive_factory(printer.id, status="printing", with_run=False)
+        db_session.add(ActivePrintSpoolman(printer_id=printer.id, archive_id=archive.id, ams_trays={}))
+        await db_session.commit()
+
+        async def _charge(printer_id, tracking, last_layer_num=None, last_progress=None, cost_out=None):
+            cost_out.add(20.0, {"price": 60.0, "initial_weight": 1000.0}, "Slot 1")
+            cost_out.add(30.0, {"price": None}, "Slot 2")
+
+        with patch("backend.app.services.spoolman_tracking._report_partial_usage", side_effect=_charge):
+            assert await cleanup_tracking(printer.id, archive.id, db_session) == 1.95
+
+    @pytest.mark.asyncio
+    async def test_cleanup_without_a_priced_spool_reports_no_cost(self, db_session, printer_factory, archive_factory):
+        from backend.app.models.active_print_spoolman import ActivePrintSpoolman
+        from backend.app.services.spoolman_tracking import cleanup_tracking
+
+        printer = await printer_factory()
+        archive = await archive_factory(printer.id, status="printing", with_run=False)
+        db_session.add(ActivePrintSpoolman(printer_id=printer.id, archive_id=archive.id, ams_trays={}))
+        await db_session.commit()
+
+        with patch("backend.app.services.spoolman_tracking._report_partial_usage", AsyncMock()):
+            assert await cleanup_tracking(printer.id, archive.id, db_session) is None
+
+
 class _AsyncCtx:
     """Tiny async-context shim returning a pre-built db mock; mirrors
     async_session()'s ``async with`` interface."""