Ver Fonte

fix(stats): scope per-run filament to the printed plate, not the whole 3MF (#2614)

A single plate dispatched from a multi-plate 3MF could log the entire file's
filament against that one plate. When the AMS tracker measured nothing, a
completed run's PrintLogEntry.filament_used_grams fell back to
PrintArchive.filament_used_grams -- the sum over every plate (correct for the
archive card / project rollup, #1593) -- ignoring the archive's plate_id. So
each printed plate of a 22-plate file logged the full ~12 kg; cost inherited
the same whole-file value.

Forward: when the archive has a plate_id and its 3MF is on disk, the completed-
run fallback uses that plate's own slicer estimate (extract_plate_metadata_from_3mf)
and scales cost by the plate's share of the whole. Tracker-measured runs and
single-plate archives are unchanged.

Backfill: a startup migration repairs rows already written -- completed entries
whose stored grams exactly equal the archive's whole-file value, with a plate_id
and an on-disk 3MF, get recomputed to plate-scoped grams + cost. The exact-match
guard never touches tracker-measured or partial rows; idempotent, data-only,
identical on SQLite and Postgres, and logs the correction.
maziggy há 1 mês atrás
pai
commit
4436349a03

Diff do ficheiro suprimidas por serem muito extensas
+ 0 - 0
CHANGELOG.md


+ 115 - 0
backend/app/core/database.py

@@ -586,6 +586,116 @@ async def _migrate_scope_force_color_overrides_to_plate(conn) -> None:
         )
 
 
+async def _migrate_scope_run_filament_to_plate(conn) -> None:
+    """Repair completed print-log rows that stored a multi-plate 3MF's whole-file
+    filament (and cost) instead of the printed plate's (#2614).
+
+    When the AMS tracker measured nothing for a completed run, the per-run filament
+    fell back to ``PrintArchive.filament_used_grams`` — the sum over EVERY plate of
+    the source 3MF (right for the archive card / project rollup, wrong for one
+    printed plate). So each printed plate of a 22-plate file logged the full ~12 kg,
+    inflating lifetime / user / project / filament stats by the plate count. The
+    forward fix scopes new rows; this repairs the rows already written.
+
+    Only completed rows whose stored grams EXACTLY equal the archive's whole-file
+    value are touched — that is the mis-copy signature. Tracker-measured rows (a
+    rounded spool-delta sum) and partial-progress rows (scaled to progress) never
+    match, so they are never clobbered. Cost is scaled by the plate's share of the
+    whole so it stays consistent with the corrected grams. Runs AFTER the #2603
+    archive plate_id backfill so ``print_archives.plate_id`` is populated.
+
+    Gated to run **exactly once** via a settings flag. This is not merely for
+    idempotency: a genuine single-plate print carries a ``plate_id`` too (the UI
+    always sends one), and for it the plate estimate legitimately equals the
+    whole-file value — so those rows match the signature on every boot. Without
+    the one-shot gate we would re-parse every single-plate 3MF on the print log at
+    each startup, a cost that grows without bound with print history. One pass is
+    enough: the forward fix keeps all new rows correct.
+    """
+    from pathlib import Path
+
+    from sqlalchemy import text
+
+    from backend.app.utils.threemf_tools import extract_plate_metadata_from_3mf
+
+    flag = "_backfill_2614_plate_filament_done"
+
+    async with conn.begin_nested():
+        already = (
+            await conn.execute(text('SELECT value FROM settings WHERE "key" = :k'), {"k": flag})
+        ).scalar_one_or_none()
+        if already:
+            return
+
+        rows = (
+            await conn.execute(
+                text(
+                    "SELECT ple.id AS entry_id, ple.filament_used_grams AS grams, ple.cost AS cost, "
+                    "a.plate_id AS plate_id, a.filament_used_grams AS whole_grams, a.file_path AS file_path "
+                    "FROM print_log_entries ple "
+                    "JOIN print_archives a ON a.id = ple.archive_id "
+                    "WHERE ple.status = 'completed' "
+                    "AND a.plate_id IS NOT NULL "
+                    "AND a.file_path IS NOT NULL "
+                    "AND a.filament_used_grams IS NOT NULL "
+                    "AND ple.filament_used_grams IS NOT NULL "
+                    "AND ple.filament_used_grams = a.filament_used_grams"
+                )
+            )
+        ).fetchall()
+
+        corrected = 0
+        grams_removed = 0.0
+        for row in rows:
+            path = Path(row.file_path)
+            if not path.is_absolute():
+                path = settings.base_dir / row.file_path
+            if not path.exists():
+                continue
+            try:
+                plate_grams = extract_plate_metadata_from_3mf(path, row.plate_id).filament_used_grams
+            except Exception as exc:
+                logger.warning(
+                    "[#2614] could not read plate %s of %s for log entry %s: %s",
+                    row.plate_id,
+                    row.file_path,
+                    row.entry_id,
+                    exc,
+                )
+                continue
+            if not plate_grams or plate_grams <= 0:
+                continue
+            new_grams = round(plate_grams, 2)
+            if abs(new_grams - (row.grams or 0)) < 0.01:
+                continue  # nothing to change (e.g. a genuine single-plate file)
+            new_cost = row.cost
+            whole = row.whole_grams or 0
+            if row.cost and whole > 0:
+                new_cost = round(row.cost * (plate_grams / whole), 2)
+            await conn.execute(
+                text("UPDATE print_log_entries SET filament_used_grams = :g, cost = :c WHERE id = :id"),
+                {"g": new_grams, "c": new_cost, "id": row.entry_id},
+            )
+            corrected += 1
+            grams_removed += (row.grams or 0) - new_grams
+
+        if corrected:
+            logger.info(
+                "[#2614] Re-scoped %d completed print-log row(s) from whole-file to plate filament "
+                "(removed %.0f g of over-counted usage from statistics)",
+                corrected,
+                grams_removed,
+            )
+
+        # Mark done unconditionally (even when nothing matched) so this one-shot
+        # never re-scans the print log on subsequent boots. id/timestamps come
+        # from the table's own defaults; "key" is quoted as it's a keyword.
+        await conn.execute(
+            text('INSERT INTO settings ("key", value) VALUES (:k, :v)'),
+            {"k": flag, "v": "true"},
+        )
+
+
 async def _migrate_drop_library_print_name(conn) -> None:
     """Strip the embedded 3MF Title (``print_name``) from library file metadata (#1489).
 
@@ -3566,6 +3676,11 @@ async def run_migrations(conn):
                 )
             )
 
+    # Migration: repair completed print-log rows that stored a multi-plate 3MF's
+    # whole-file filament instead of the printed plate's (#2614). Runs AFTER the
+    # #2603 archive plate_id backfill above so print_archives.plate_id is populated.
+    await _migrate_scope_run_filament_to_plate(conn)
+
     # Migration: Disambiguate the four ``user_print_*`` notification template
     # names by appending " Email" (#1792). See ``_migrate_rename_user_print_template_names``.
     await _migrate_rename_user_print_template_names(conn)

+ 47 - 2
backend/app/main.py

@@ -772,6 +772,41 @@ def _compute_run_filament_grams(
     return None
 
 
+def _plate_scoped_run_estimate(archive, full_path) -> tuple[float | None, float | None]:
+    """Per-run (grams, cost) scoped to the plate this run actually printed (#2614).
+
+    ``PrintArchive.filament_used_grams`` / ``.cost`` are the sum over EVERY plate of
+    the source 3MF — correct for the archive card and project rollup, but wrong for a
+    single plate dispatched from a multi-plate file: without scoping, each printed
+    plate of a 22-plate file logs the whole ~12 kg and inflates every statistic. When
+    the archive carries a ``plate_id`` and its 3MF is on disk, return that plate's
+    slicer estimate instead; cost is scaled by the plate's share of the whole so it
+    stays consistent with the scoped grams without re-doing the filament price lookup.
+    Falls back to the archive's whole-file values when there's no plate to scope to.
+    """
+    whole_grams = archive.filament_used_grams
+    if archive.plate_id is None or full_path is None or not full_path.exists():
+        return whole_grams, archive.cost
+    try:
+        from backend.app.utils.threemf_tools import extract_plate_metadata_from_3mf
+
+        plate_grams = extract_plate_metadata_from_3mf(full_path, archive.plate_id).filament_used_grams
+    except Exception as exc:
+        logging.getLogger(__name__).debug(
+            "[#2614] plate-scoped estimate failed for archive %s (plate %s): %s",
+            archive.id,
+            archive.plate_id,
+            exc,
+        )
+        return whole_grams, archive.cost
+    if not plate_grams or plate_grams <= 0:
+        return whole_grams, archive.cost
+    plate_cost = archive.cost
+    if archive.cost and whole_grams and whole_grams > 0:
+        plate_cost = round(archive.cost * (plate_grams / whole_grams), 2)
+    return round(plate_grams, 2), plate_cost
+
+
 def _get_start_ams_mapping(data: dict, archive_id: int | None) -> list[int] | None:
     """Resolve AMS mapping for print start without consuming stored queue/reprint state."""
     stored_ams_mapping = data.get("ams_mapping")
@@ -4791,9 +4826,19 @@ async def on_print_complete(printer_id: int, data: dict):
                 # math (failed / cancelled / stopped get scaled to progress
                 # or to tracked spool deltas).
                 _run_status = data.get("status", "completed")
+                # #2614: scope the per-run estimate to the printed plate. For a
+                # multi-plate 3MF dispatched one plate at a time, the archive's
+                # filament/cost are the whole-file totals; the PrintLogEntry must
+                # reflect only this plate. No effect on single-plate archives (the
+                # plate estimate equals the whole-file value) or on the tracker
+                # path (measured spool deltas win in _compute_run_filament_grams).
+                _est_full_path = (
+                    app_settings.base_dir / archive.file_path if archive.file_path else None
+                )  # SEC-PATH-OK: archive.file_path is DB-stored, internally generated
+                _est_grams, _est_cost = _plate_scoped_run_estimate(archive, _est_full_path)
                 _run_grams = _compute_run_filament_grams(
                     _run_status,
-                    archive.filament_used_grams,
+                    _est_grams,
                     data.get("progress"),
                     usage_results,
                 )
@@ -4806,7 +4851,7 @@ async def on_print_complete(printer_id: int, data: dict):
                 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 = archive.cost
+                    _run_cost = _est_cost
 
                 await write_log_entry(
                     db,

+ 75 - 1
backend/tests/unit/test_run_filament_helper.py

@@ -6,7 +6,10 @@ don't inflate stats with the full slicer estimate, and tracker-aware so
 completed prints agree with the per-spool counter on the Inventory page.
 """
 
-from backend.app.main import _compute_run_filament_grams
+from types import SimpleNamespace
+
+import backend.app.utils.threemf_tools as threemf_tools
+from backend.app.main import _compute_run_filament_grams, _plate_scoped_run_estimate
 
 
 class TestComputeRunFilamentGrams:
@@ -69,3 +72,74 @@ class TestComputeRunFilamentGrams:
     def test_completed_with_none_estimate_returns_none(self):
         # Archive somehow has no estimate (rare; archive_print parsed nothing).
         assert _compute_run_filament_grams("completed", None, 100, []) is None
+
+
+class TestPlateScopedRunEstimate:
+    """#2614: a plate dispatched from a multi-plate 3MF must log only that plate's
+    filament/cost, not the archive's whole-file totals."""
+
+    def _archive(self, **kw):
+        return SimpleNamespace(
+            id=1,
+            plate_id=kw.get("plate_id", 3),
+            filament_used_grams=kw.get("filament_used_grams", 12006.49),
+            cost=kw.get("cost", 240.13),
+            file_path=kw.get("file_path", "archive/1/heart.gcode.3mf"),
+        )
+
+    def _patch_plate_grams(self, monkeypatch, grams):
+        monkeypatch.setattr(
+            threemf_tools,
+            "extract_plate_metadata_from_3mf",
+            lambda path, plate_id: SimpleNamespace(filament_used_grams=grams),
+        )
+
+    def test_scopes_grams_and_scales_cost_to_plate(self, monkeypatch, tmp_path):
+        f = tmp_path / "heart.gcode.3mf"
+        f.write_bytes(b"stub")
+        self._patch_plate_grams(monkeypatch, 350.0)
+        grams, cost = _plate_scoped_run_estimate(self._archive(), f)
+        assert grams == 350.0
+        # cost scaled by the plate's share of the whole-file grams.
+        assert cost == round(240.13 * (350.0 / 12006.49), 2)
+
+    def test_no_plate_id_returns_whole_file_values(self, monkeypatch, tmp_path):
+        f = tmp_path / "heart.gcode.3mf"
+        f.write_bytes(b"stub")
+        # Extractor must not even be consulted.
+        self._patch_plate_grams(monkeypatch, 350.0)
+        grams, cost = _plate_scoped_run_estimate(self._archive(plate_id=None), f)
+        assert (grams, cost) == (12006.49, 240.13)
+
+    def test_missing_file_returns_whole_file_values(self, monkeypatch):
+        from pathlib import Path
+
+        self._patch_plate_grams(monkeypatch, 350.0)
+        grams, cost = _plate_scoped_run_estimate(self._archive(), Path("/nope/gone.3mf"))
+        assert (grams, cost) == (12006.49, 240.13)
+
+    def test_zero_plate_estimate_falls_back(self, monkeypatch, tmp_path):
+        f = tmp_path / "heart.gcode.3mf"
+        f.write_bytes(b"stub")
+        self._patch_plate_grams(monkeypatch, 0.0)
+        grams, cost = _plate_scoped_run_estimate(self._archive(), f)
+        assert (grams, cost) == (12006.49, 240.13)
+
+    def test_extractor_error_falls_back(self, monkeypatch, tmp_path):
+        f = tmp_path / "heart.gcode.3mf"
+        f.write_bytes(b"stub")
+
+        def _boom(path, plate_id):
+            raise ValueError("corrupt 3mf")
+
+        monkeypatch.setattr(threemf_tools, "extract_plate_metadata_from_3mf", _boom)
+        grams, cost = _plate_scoped_run_estimate(self._archive(), f)
+        assert (grams, cost) == (12006.49, 240.13)
+
+    def test_no_archive_cost_keeps_cost_none(self, monkeypatch, tmp_path):
+        f = tmp_path / "heart.gcode.3mf"
+        f.write_bytes(b"stub")
+        self._patch_plate_grams(monkeypatch, 350.0)
+        grams, cost = _plate_scoped_run_estimate(self._archive(cost=None), f)
+        assert grams == 350.0
+        assert cost is None

+ 217 - 0
backend/tests/unit/test_run_filament_plate_scope_2614.py

@@ -0,0 +1,217 @@
+"""Backfill for whole-file filament mis-copied onto per-plate print-log rows (#2614).
+
+A plate dispatched from a multi-plate 3MF, when the AMS tracker measured nothing,
+logged the archive's whole-file filament (the sum over every plate) into
+PrintLogEntry.filament_used_grams — inflating stats by the plate count. The
+forward fix scopes new rows; _migrate_scope_run_filament_to_plate repairs the
+rows already written, touching only the exact whole-file mis-copies.
+"""
+
+from types import SimpleNamespace
+
+import pytest
+from sqlalchemy.ext.asyncio import async_sessionmaker, create_async_engine
+
+import backend.app.models  # noqa: F401 - populate Base.metadata
+import backend.app.utils.threemf_tools as threemf_tools
+from backend.app.core import database as database_module
+from backend.app.core.database import Base, _migrate_scope_run_filament_to_plate
+from backend.app.models.archive import PrintArchive
+from backend.app.models.print_log import PrintLogEntry
+from backend.app.models.printer import Printer
+
+WHOLE = 12006.49  # 22-plate file total
+PLATE = 350.0  # the printed plate's own estimate
+COST = 240.13  # whole-file cost
+
+
+@pytest.fixture
+async def engine(tmp_path):
+    eng = create_async_engine(f"sqlite+aiosqlite:///{tmp_path}/t.db")
+    async with eng.begin() as conn:
+        await conn.run_sync(Base.metadata.create_all)
+    try:
+        yield eng
+    finally:
+        await eng.dispose()
+
+
+@pytest.fixture
+def stub_3mf(tmp_path, monkeypatch):
+    """A stub file on disk + a patched extractor returning the plate estimate."""
+    monkeypatch.setattr(database_module.settings, "base_dir", tmp_path)
+    fp = tmp_path / "archive" / "1" / "heart.gcode.3mf"
+    fp.parent.mkdir(parents=True)
+    fp.write_bytes(b"stub")
+    monkeypatch.setattr(
+        threemf_tools,
+        "extract_plate_metadata_from_3mf",
+        lambda path, plate_id: SimpleNamespace(filament_used_grams=PLATE),
+    )
+    return "archive/1/heart.gcode.3mf"
+
+
+async def _archive(db, file_path, *, plate_id=3, whole=WHOLE, cost=COST):
+    p = Printer(name="P", serial_number="S", ip_address="1.1.1.1", access_code="c", model="X1C")
+    db.add(p)
+    await db.flush()
+    a = PrintArchive(
+        filename="heart.gcode.3mf",
+        file_path=file_path,
+        file_size=1,
+        status="completed",
+        plate_id=plate_id,
+        filament_used_grams=whole,
+        cost=cost,
+    )
+    db.add(a)
+    await db.flush()
+    return a
+
+
+@pytest.mark.asyncio
+async def test_rescopes_miscopied_row_and_scales_cost(engine, stub_3mf):
+    sm = async_sessionmaker(engine, expire_on_commit=False)
+    async with sm() as db:
+        a = await _archive(db, stub_3mf)
+        mis = PrintLogEntry(archive_id=a.id, status="completed", filament_used_grams=WHOLE, cost=COST)
+        db.add(mis)
+        await db.commit()
+        mis_id = mis.id
+
+    async with engine.begin() as conn:
+        await _migrate_scope_run_filament_to_plate(conn)
+
+    async with sm() as db:
+        fixed = await db.get(PrintLogEntry, mis_id)
+        assert fixed.filament_used_grams == PLATE
+        assert fixed.cost == round(COST * (PLATE / WHOLE), 2)
+
+
+@pytest.mark.asyncio
+async def test_leaves_tracker_measured_and_partial_rows_alone(engine, stub_3mf):
+    sm = async_sessionmaker(engine, expire_on_commit=False)
+    async with sm() as db:
+        a = await _archive(db, stub_3mf)
+        # Measured spool delta (rounded), != whole-file → must be untouched.
+        tracked = PrintLogEntry(archive_id=a.id, status="completed", filament_used_grams=96.5, cost=2.0)
+        # A partial (failed) run scaled to progress, != whole-file → untouched.
+        partial = PrintLogEntry(archive_id=a.id, status="failed", filament_used_grams=1200.6, cost=24.0)
+        db.add_all([tracked, partial])
+        await db.commit()
+        tracked_id, partial_id = tracked.id, partial.id
+
+    async with engine.begin() as conn:
+        await _migrate_scope_run_filament_to_plate(conn)
+
+    async with sm() as db:
+        assert (await db.get(PrintLogEntry, tracked_id)).filament_used_grams == 96.5
+        assert (await db.get(PrintLogEntry, partial_id)).filament_used_grams == 1200.6
+
+
+@pytest.mark.asyncio
+async def test_idempotent_second_run_is_a_noop(engine, stub_3mf):
+    sm = async_sessionmaker(engine, expire_on_commit=False)
+    async with sm() as db:
+        a = await _archive(db, stub_3mf)
+        mis = PrintLogEntry(archive_id=a.id, status="completed", filament_used_grams=WHOLE, cost=COST)
+        db.add(mis)
+        await db.commit()
+        mis_id = mis.id
+
+    async with engine.begin() as conn:
+        await _migrate_scope_run_filament_to_plate(conn)
+    async with engine.begin() as conn:
+        await _migrate_scope_run_filament_to_plate(conn)
+
+    async with sm() as db:
+        assert (await db.get(PrintLogEntry, mis_id)).filament_used_grams == PLATE
+
+
+@pytest.mark.asyncio
+async def test_one_shot_gate_prevents_rescan_on_later_boots(engine, stub_3mf):
+    """After the first pass writes its settings flag, a later boot does no work —
+    the migration must never re-scan the print log every startup (single-plate rows
+    legitimately match the whole-file==plate signature forever, so an ungated
+    version would re-parse every single-plate 3MF on each boot)."""
+    sm = async_sessionmaker(engine, expire_on_commit=False)
+    async with sm() as db:
+        a = await _archive(db, stub_3mf)
+        first = PrintLogEntry(archive_id=a.id, status="completed", filament_used_grams=WHOLE, cost=COST)
+        db.add(first)
+        await db.commit()
+        first_id, archive_id = first.id, a.id
+
+    async with engine.begin() as conn:
+        await _migrate_scope_run_filament_to_plate(conn)  # fixes `first`, writes the flag
+
+    # A fresh mis-copy appears after the one-shot already ran.
+    async with sm() as db:
+        later = PrintLogEntry(archive_id=archive_id, status="completed", filament_used_grams=WHOLE, cost=COST)
+        db.add(later)
+        await db.commit()
+        later_id = later.id
+
+    async with engine.begin() as conn:
+        await _migrate_scope_run_filament_to_plate(conn)  # gate short-circuits; no scan
+
+    async with sm() as db:
+        assert (await db.get(PrintLogEntry, first_id)).filament_used_grams == PLATE
+        # Deliberately untouched: the gate skipped the whole pass. New mis-copies
+        # can't occur anyway — the forward fix scopes every row at write time.
+        assert (await db.get(PrintLogEntry, later_id)).filament_used_grams == WHOLE
+
+
+@pytest.mark.asyncio
+async def test_skips_row_when_3mf_missing(engine, tmp_path, monkeypatch):
+    # base_dir set, but the archive's file was never on disk → row is left alone
+    # (can't compute a plate value; don't guess).
+    monkeypatch.setattr(database_module.settings, "base_dir", tmp_path)
+    monkeypatch.setattr(
+        threemf_tools,
+        "extract_plate_metadata_from_3mf",
+        lambda path, plate_id: SimpleNamespace(filament_used_grams=PLATE),
+    )
+    sm = async_sessionmaker(engine, expire_on_commit=False)
+    async with sm() as db:
+        a = await _archive(db, "archive/1/gone.gcode.3mf")
+        mis = PrintLogEntry(archive_id=a.id, status="completed", filament_used_grams=WHOLE, cost=COST)
+        db.add(mis)
+        await db.commit()
+        mis_id = mis.id
+
+    async with engine.begin() as conn:
+        await _migrate_scope_run_filament_to_plate(conn)
+
+    async with sm() as db:
+        assert (await db.get(PrintLogEntry, mis_id)).filament_used_grams == WHOLE
+
+
+@pytest.mark.asyncio
+async def test_single_plate_archive_not_relabelled(engine, tmp_path, monkeypatch):
+    # A genuine single-plate archive whose plate estimate equals the whole-file
+    # value must not be rewritten (no-op guard on unchanged grams).
+    monkeypatch.setattr(database_module.settings, "base_dir", tmp_path)
+    fp = tmp_path / "archive" / "1" / "heart.gcode.3mf"
+    fp.parent.mkdir(parents=True)
+    fp.write_bytes(b"stub")
+    monkeypatch.setattr(
+        threemf_tools,
+        "extract_plate_metadata_from_3mf",
+        lambda path, plate_id: SimpleNamespace(filament_used_grams=WHOLE),
+    )
+    sm = async_sessionmaker(engine, expire_on_commit=False)
+    async with sm() as db:
+        a = await _archive(db, "archive/1/heart.gcode.3mf", plate_id=1)
+        row = PrintLogEntry(archive_id=a.id, status="completed", filament_used_grams=WHOLE, cost=COST)
+        db.add(row)
+        await db.commit()
+        row_id = row.id
+
+    async with engine.begin() as conn:
+        await _migrate_scope_run_filament_to_plate(conn)
+
+    async with sm() as db:
+        fixed = await db.get(PrintLogEntry, row_id)
+        assert fixed.filament_used_grams == WHOLE
+        assert fixed.cost == COST

Alguns ficheiros não foram mostrados porque muitos ficheiros mudaram neste diff