From 4df03493103404d666e1c5ecdb597676b0735a04 Mon Sep 17 00:00:00 2001 From: maziggy Date: Tue, 7 Apr 2026 08:31:14 +0200 Subject: [PATCH] Fix spool weight tracking when auto-archive is disabled (#839) When auto-archive was off, archive_id was None at print completion so the entire 3MF tracking path was skipped. AMS remain% fallback also failed on printers reporting remain=-1. Now searches library files and previous archives by filename to locate the 3MF without an archive, and captures the AMS slot-to-tray mapping at print start so it's available at completion regardless of archive state. --- CHANGELOG.md | 2 +- backend/app/services/usage_tracker.py | 132 ++++++++-- .../tests/unit/services/test_usage_tracker.py | 17 +- backend/tests/unit/test_cost_tracking.py | 9 +- backend/tests/unit/test_usage_tracker.py | 240 +++++++++++++++++- 5 files changed, 370 insertions(+), 30 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index d2b860f5a..d8809a896 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -25,7 +25,7 @@ All notable changes to Bambuddy will be documented in this file. - **Camera Snapshot Temp Files World-Readable** — Camera snapshot and plate detection endpoints created temporary JPEG files in `/tmp` with default 0644 permissions, making them readable by any local user. Switched from `NamedTemporaryFile(delete=False)` to `mkstemp` with explicit 0600 permissions so only the application user can read them. Cleanup was already handled via `finally` blocks. Reported responsibly by Sacha Vaudey via security@bambuddy.cool. ### Fixed -- **Spool Weight Not Updated After Print** ([#839](https://github.com/maziggy/bambuddy/issues/839)) — Filament usage tracking failed silently in several scenarios: (1) when FTP download failed and a fallback archive was created without a 3MF file, the primary tracking path was skipped entirely — now falls back to matching the 3MF from the library or a previous archive of the same file; (2) external/VT tray spools were never tracked by the AMS remain% fallback because it only iterated AMS unit trays — now captures and tracks VT tray remain% deltas; (3) notifications showed "Unknown" for time and filament on fallback archives — now enriches notifications with usage tracker results and captures estimated print time from MQTT at archive creation. +- **Spool Weight Not Updated After Print** ([#839](https://github.com/maziggy/bambuddy/issues/839)) — Filament usage tracking failed silently in several scenarios: (1) when FTP download failed and a fallback archive was created without a 3MF file, the primary tracking path was skipped entirely — now falls back to matching the 3MF from the library or a previous archive of the same file; (2) external/VT tray spools were never tracked by the AMS remain% fallback because it only iterated AMS unit trays — now captures and tracks VT tray remain% deltas; (3) notifications showed "Unknown" for time and filament on fallback archives — now enriches notifications with usage tracker results and captures estimated print time from MQTT at archive creation; (4) when auto-archive was disabled, `archive_id` was None at print completion so the entire 3MF tracking path was skipped — now searches library files and previous archives by filename to find the 3MF even without an archive, and captures the AMS slot-to-tray mapping at print start so it's available at completion regardless of archive state. - **File Manager Stale UI After Deleting Folders/Files** — Deleting a folder, file, or bulk-deleting items in the file manager appeared to succeed (toast shown) but the UI didn't update until a page reload. The delete endpoints (`delete_folder`, `delete_file`, `bulk_delete`) relied on FastAPI's dependency cleanup auto-commit which runs after the response is sent — the frontend received the success response, refetched the folder/file list, but the delete hadn't been committed yet. Added explicit `db.commit()` before returning in all three endpoints. - **Spool Manager Deducts Double the Filament Used** ([#880](https://github.com/maziggy/bambuddy/issues/880)) — After a print completed, the built-in spool manager subtracted twice the actual filament consumption. The printer's MQTT status message contains both updated AMS remain percentages and the `FINISH` state, which triggered two independent deduction paths in the same event loop cycle: the AMS weight sync (absolute SET from remain%) and the usage tracker (additive delta from 3MF data). The AMS weight sync now skips updates while a print session is active, letting the usage tracker handle deductions precisely via 3MF slicer data. - **Thumbnails Broken After Backend Restart** — Archive and library thumbnails returned 401 Unauthorized after a backend restart because stream tokens are stored in memory and lost on restart. The frontend now detects failed token-protected image loads and automatically refreshes the stream token, so thumbnails recover without a page reload. diff --git a/backend/app/services/usage_tracker.py b/backend/app/services/usage_tracker.py index a0577a1ed..c01e6f5b0 100644 --- a/backend/app/services/usage_tracker.py +++ b/backend/app/services/usage_tracker.py @@ -158,6 +158,8 @@ class PrintSession: # Snapshot of spool assignments at print start: {(ams_id, tray_id): spool_id} # Prevents usage loss when on_ams_change unlinks a spool mid-print spool_assignments: dict[tuple[int, int], int] = field(default_factory=dict) + # AMS mapping from print command (captured at start, needed when auto-archive is off) + ams_mapping: list[int] | None = None # Module-level storage, keyed by printer_id @@ -333,6 +335,7 @@ async def on_print_start(printer_id: int, data: dict, printer_manager, db: Async tray_remain_start=tray_remain_start, tray_now_at_start=tray_now_at_start, spool_assignments=spool_assignments, + ams_mapping=data.get("ams_mapping"), ) _active_sessions[printer_id] = session @@ -377,6 +380,11 @@ async def on_print_complete( default_cost_str = await get_setting(db, "default_filament_cost") default_filament_cost = float(default_cost_str) if default_cost_str else 0.0 + # Fall back to ams_mapping captured at print start (needed when auto-archive is off + # and the caller can't retrieve the mapping from _print_ams_mappings without archive_id) + if not ams_mapping and session and session.ams_mapping: + ams_mapping = session.ams_mapping + logger.info( "[UsageTracker] on_print_complete: printer=%d, archive=%s, session=%s, ams_mapping=%s", printer_id, @@ -397,10 +405,21 @@ async def on_print_complete( ) # --- Path 1 (PRIMARY): 3MF per-filament estimates --- - if archive_id: - print_name = ( - (session.print_name if session else None) or data.get("subtask_name", "") or data.get("filename", "unknown") - ) + print_name = ( + (session.print_name if session else None) or data.get("subtask_name", "") or data.get("filename", "unknown") + ) + + # When auto-archive is disabled (archive_id=None), try to find a 3MF by filename + # from the library or previous archives so we can still track filament usage. + threemf_path = None + if not archive_id: + from backend.app.core.config import settings as app_settings + + search_filename = data.get("filename") or data.get("subtask_name") or (session.print_name if session else "") + if search_filename: + threemf_path = await _find_3mf_by_filename(printer_id, search_filename, db, app_settings.base_dir) + + if archive_id or threemf_path: threemf_results = await _track_from_3mf( printer_id, archive_id, @@ -416,6 +435,7 @@ async def on_print_complete( default_filament_cost=default_filament_cost, spool_assignments=session.spool_assignments if session else None, print_started_at=session.started_at if session else None, + threemf_path=threemf_path, ) results.extend(threemf_results) @@ -635,9 +655,76 @@ async def _resolve_3mf_fallback(archive, db: AsyncSession, base_dir): return None +async def _find_3mf_by_filename( + printer_id: int, + filename: str, + db: AsyncSession, + base_dir, +): + """Find a 3MF file by filename from library or previous archives. + + Used when auto-archive is disabled and there's no archive_id, but we still + need the 3MF slicer data for filament usage tracking. + """ + from pathlib import Path + + from backend.app.models.archive import PrintArchive + from backend.app.models.library import LibraryFile + + search_name = filename.split("/")[-1] if "/" in filename else filename + search_base = search_name.replace(".gcode.3mf", "").replace(".gcode", "").replace(".3mf", "") + if not search_base: + return None + + # 1. Try library files matching the name + try: + lib_result = await db.execute( + select(LibraryFile) + .where(LibraryFile.file_path.ilike(f"%/{search_base}.%") | LibraryFile.file_path.ilike(f"{search_base}.%")) + .where(LibraryFile.file_path.ilike("%.3mf")) + .order_by(LibraryFile.created_at.desc()) + .limit(3) + ) + for lib_file in lib_result.scalars().all(): + lib_path = Path(lib_file.file_path) + candidate = lib_path if lib_path.is_absolute() else base_dir / lib_file.file_path + if candidate.exists() and candidate.suffix == ".3mf": + logger.info("[UsageTracker] 3MF (no-archive): found library file %s for '%s'", candidate, filename) + return candidate + except Exception as e: + logger.debug("[UsageTracker] 3MF (no-archive): library lookup failed: %s", e) + + # 2. Try previous archives with a valid 3MF file_path + try: + prev_result = await db.execute( + select(PrintArchive) + .where(PrintArchive.printer_id == printer_id) + .where(PrintArchive.file_path != "") + .where(PrintArchive.file_path.isnot(None)) + .where( + PrintArchive.filename.ilike(f"%{search_base}.%") | PrintArchive.filename.ilike(f"{search_base}.%"), + ) + .order_by(PrintArchive.created_at.desc()) + .limit(3) + ) + for prev_archive in prev_result.scalars().all(): + candidate = base_dir / prev_archive.file_path + if candidate.exists() and candidate.suffix == ".3mf": + logger.info( + "[UsageTracker] 3MF (no-archive): found previous archive %s file for '%s'", + prev_archive.id, + filename, + ) + return candidate + except Exception as e: + logger.debug("[UsageTracker] 3MF (no-archive): previous archive lookup failed: %s", e) + + return None + + async def _track_from_3mf( printer_id: int, - archive_id: int, + archive_id: int | None, status: str, print_name: str, handled_trays: set[tuple[int, int]], @@ -650,6 +737,7 @@ async def _track_from_3mf( default_filament_cost: float = 0.0, spool_assignments: dict[tuple[int, int], int] | None = None, print_started_at: datetime | None = None, + threemf_path=None, ) -> list[dict]: """Track usage from 3MF per-filament slicer data (primary path). @@ -657,6 +745,9 @@ async def _track_from_3mf( For partial prints (failed/aborted), tries per-layer gcode data first, then falls back to linear scaling by progress. + When archive_id is None (auto-archive disabled), a pre-resolved threemf_path + can be provided to still track filament usage from slicer data. + Slot-to-tray mapping priority: 1. Stored ams_mapping from print command (reprints/direct prints) 2. MQTT mapping field from printer state (universal, all print sources) @@ -672,23 +763,24 @@ async def _track_from_3mf( from backend.app.models.print_queue import PrintQueueItem from backend.app.utils.threemf_tools import extract_filament_usage_from_3mf - result = await db.execute(select(PrintArchive).where(PrintArchive.id == archive_id)) - archive = result.scalar_one_or_none() - if not archive: - logger.info("[UsageTracker] 3MF: archive %s not found, skipping", archive_id) - return [] + file_path: Path | None = threemf_path - file_path: Path | None = None + if file_path is None and archive_id: + result = await db.execute(select(PrintArchive).where(PrintArchive.id == archive_id)) + archive = result.scalar_one_or_none() + if not archive: + logger.info("[UsageTracker] 3MF: archive %s not found, skipping", archive_id) + return [] - # Try archive's own file_path first - if archive.file_path: - candidate = app_settings.base_dir / archive.file_path - if candidate.exists(): - file_path = candidate + # Try archive's own file_path first + if archive.file_path: + candidate = app_settings.base_dir / archive.file_path + if candidate.exists(): + file_path = candidate - # Fallback: find 3MF from library or a previous archive with the same filename - if file_path is None: - file_path = await _resolve_3mf_fallback(archive, db, app_settings.base_dir) + # Fallback: find 3MF from library or a previous archive with the same filename + if file_path is None: + file_path = await _resolve_3mf_fallback(archive, db, app_settings.base_dir) if file_path is None: logger.info("[UsageTracker] 3MF: no file available for archive %s, skipping", archive_id) @@ -721,7 +813,7 @@ async def _track_from_3mf( mapping_source = "mqtt" # 3. Try queue item ams_mapping (queue-initiated prints store the exact mapping) - if not slot_to_tray: + if not slot_to_tray and archive_id: queue_result = await db.execute( select(PrintQueueItem) .where(PrintQueueItem.archive_id == archive_id) diff --git a/backend/tests/unit/services/test_usage_tracker.py b/backend/tests/unit/services/test_usage_tracker.py index 8f14dfe12..a5d04f0c8 100644 --- a/backend/tests/unit/services/test_usage_tracker.py +++ b/backend/tests/unit/services/test_usage_tracker.py @@ -143,9 +143,12 @@ class TestOnPrintCompleteAMSDelta: assignment = _make_assignment() db = AsyncMock() - # First execute → assignment, second → spool + # First 2 executes → _find_3mf_by_filename (library + archive search, uses scalars().all()), + # then assignment, then spool for the AMS fallback path db.execute = AsyncMock( side_effect=[ + MagicMock(), # _find_3mf_by_filename: library search + MagicMock(), # _find_3mf_by_filename: archive search MagicMock(scalar_one_or_none=MagicMock(return_value=assignment)), MagicMock(scalar_one_or_none=MagicMock(return_value=spool)), ] @@ -571,11 +574,14 @@ class TestSpoolAssignmentSnapshot: ams_data = [{"id": 0, "tray": [{"id": 0, "remain": 70}]}] pm = _make_printer_manager(_make_printer_state(ams_data)) - # db returns no live assignment, then spool from snapshot spool_id + # First 2 executes → _find_3mf_by_filename (library + archive search), + # then live assignment check (returns None), then spool lookup by snapshot spool_id db = AsyncMock() db.execute = AsyncMock( side_effect=[ - MagicMock(scalar_one_or_none=MagicMock(return_value=None)), + MagicMock(), # _find_3mf_by_filename: library search + MagicMock(), # _find_3mf_by_filename: archive search + MagicMock(scalar_one_or_none=MagicMock(return_value=None)), # live assignment MagicMock(scalar_one_or_none=MagicMock(return_value=spool)), ] ) @@ -609,10 +615,13 @@ class TestSpoolAssignmentSnapshot: ams_data = [{"id": 0, "tray": [{"id": 0, "remain": 70}]}] pm = _make_printer_manager(_make_printer_state(ams_data)) - # db returns assignment then spool + # First 2 executes → _find_3mf_by_filename (library + archive search), + # then assignment and spool for the AMS fallback path db = AsyncMock() db.execute = AsyncMock( side_effect=[ + MagicMock(), # _find_3mf_by_filename: library search + MagicMock(), # _find_3mf_by_filename: archive search MagicMock(scalar_one_or_none=MagicMock(return_value=assignment)), MagicMock(scalar_one_or_none=MagicMock(return_value=spool)), ] diff --git a/backend/tests/unit/test_cost_tracking.py b/backend/tests/unit/test_cost_tracking.py index 5f2f3ea51..e47b090ca 100644 --- a/backend/tests/unit/test_cost_tracking.py +++ b/backend/tests/unit/test_cost_tracking.py @@ -401,8 +401,9 @@ class TestCostCalculation: last_loaded_tray=-1, ) - # db returns assignment then spool (no archive, AMS fallback path) - db = _mock_db_sequential([assignment, spool]) + # Pad 2 Nones for _find_3mf_by_filename DB queries (library + archive search), + # then assignment and spool for the AMS fallback path + db = _mock_db_sequential([None, None, assignment, spool]) with patch("backend.app.api.routes.settings.get_setting", return_value="15.0"): results = await on_print_complete( @@ -751,7 +752,9 @@ class TestCostAggregation: tray_now=0, ) - db = _mock_db_sequential([assignment_old, spool_old]) + # Pad 2 Nones for _find_3mf_by_filename DB queries (library + archive search), + # then assignment and spool for the AMS fallback path + db = _mock_db_sequential([None, None, assignment_old, spool_old]) with ( patch("backend.app.core.config.settings") as mock_settings, diff --git a/backend/tests/unit/test_usage_tracker.py b/backend/tests/unit/test_usage_tracker.py index 1d057efa9..231064757 100644 --- a/backend/tests/unit/test_usage_tracker.py +++ b/backend/tests/unit/test_usage_tracker.py @@ -15,6 +15,7 @@ from backend.app.services.usage_tracker import ( PrintSession, _active_sessions, _decode_mqtt_mapping, + _find_3mf_by_filename, _match_slots_by_color, _track_from_3mf, on_print_complete, @@ -254,8 +255,9 @@ class TestOnPrintComplete: last_loaded_tray=-1, ) - # db returns assignment then spool - db = _mock_db_sequential([assignment, spool]) + # Pad 2 Nones for _find_3mf_by_filename DB queries (library + archive search), + # then assignment and spool for the AMS fallback path + db = _mock_db_sequential([None, None, assignment, spool]) results = await on_print_complete( printer_id=1, @@ -1739,3 +1741,237 @@ class TestNotificationVariables: scaled_slots = [{**s, "used_g": round(s["used_g"] * scale, 1)} for s in slots] assert scaled_slots[0]["used_g"] == 6.0 assert scaled_slots[1]["used_g"] == 3.0 + + +class TestOnPrintStartAmsMapping: + """Tests for ams_mapping capture in on_print_start().""" + + @pytest.fixture(autouse=True) + def _clear_sessions(self): + _active_sessions.clear() + yield + _active_sessions.clear() + + @pytest.mark.asyncio + async def test_captures_ams_mapping_from_data(self): + """on_print_start captures ams_mapping from the data dict into the session.""" + printer_manager = MagicMock() + printer_manager.get_status.return_value = SimpleNamespace( + raw_data={"ams": [{"id": 0, "tray": [{"id": 0, "remain": 80}]}]}, + tray_now=0, + ) + + await on_print_start(1, {"subtask_name": "Test", "ams_mapping": [3, -1, -1, 2]}, printer_manager) + + assert _active_sessions[1].ams_mapping == [3, -1, -1, 2] + + @pytest.mark.asyncio + async def test_ams_mapping_none_when_not_in_data(self): + """Session ams_mapping is None when data dict has no ams_mapping.""" + printer_manager = MagicMock() + printer_manager.get_status.return_value = SimpleNamespace( + raw_data={"ams": [{"id": 0, "tray": [{"id": 0, "remain": 80}]}]}, + tray_now=0, + ) + + await on_print_start(1, {"subtask_name": "Test"}, printer_manager) + + assert _active_sessions[1].ams_mapping is None + + +class TestFindThreemfByFilename: + """Tests for _find_3mf_by_filename() — library/archive search without archive_id.""" + + @pytest.mark.asyncio + async def test_finds_library_file(self): + """Finds a 3MF from library files matching filename.""" + from pathlib import Path + from unittest.mock import MagicMock + + lib_file = MagicMock() + lib_file.file_path = "library/BMCU-BADGE.3mf" + + mock_result = MagicMock() + mock_result.scalars.return_value.all.return_value = [lib_file] + + db = AsyncMock() + db.execute = AsyncMock(return_value=mock_result) + + base_dir = MagicMock(spec=Path) + candidate = MagicMock(spec=Path) + candidate.exists.return_value = True + candidate.suffix = ".3mf" + base_dir.__truediv__ = MagicMock(return_value=candidate) + + result = await _find_3mf_by_filename(1, "BMCU-BADGE.3mf", db, base_dir) + + assert result == candidate + + @pytest.mark.asyncio + async def test_returns_none_for_empty_filename(self): + """Returns None when filename is empty or just extensions.""" + db = AsyncMock() + base_dir = MagicMock() + + result = await _find_3mf_by_filename(1, ".3mf", db, base_dir) + assert result is None + + result = await _find_3mf_by_filename(1, "", db, base_dir) + assert result is None + + @pytest.mark.asyncio + async def test_falls_through_to_archive_search(self): + """Falls back to previous archives when library search returns no results.""" + from pathlib import Path + + # Library returns nothing + empty_result = MagicMock() + empty_result.scalars.return_value.all.return_value = [] + + # Archive returns a match + archive = MagicMock() + archive.id = 35 + archive.file_path = "archives/35/BMCU-BADGE.3mf" + archive_result = MagicMock() + archive_result.scalars.return_value.all.return_value = [archive] + + db = AsyncMock() + db.execute = AsyncMock(side_effect=[empty_result, archive_result]) + + base_dir = MagicMock(spec=Path) + candidate = MagicMock(spec=Path) + candidate.exists.return_value = True + candidate.suffix = ".3mf" + base_dir.__truediv__ = MagicMock(return_value=candidate) + + result = await _find_3mf_by_filename(1, "BMCU-BADGE.3mf", db, base_dir) + + assert result == candidate + assert db.execute.call_count == 2 + + @pytest.mark.asyncio + async def test_returns_none_when_nothing_found(self): + """Returns None when neither library nor archives have a matching 3MF.""" + empty_result = MagicMock() + empty_result.scalars.return_value.all.return_value = [] + + db = AsyncMock() + db.execute = AsyncMock(return_value=empty_result) + + base_dir = MagicMock() + + result = await _find_3mf_by_filename(1, "nonexistent.3mf", db, base_dir) + + assert result is None + + @pytest.mark.asyncio + async def test_strips_path_and_extensions(self): + """Correctly strips path components and extensions for search.""" + empty_result = MagicMock() + empty_result.scalars.return_value.all.return_value = [] + + db = AsyncMock() + db.execute = AsyncMock(return_value=empty_result) + + base_dir = MagicMock() + + # Should search for "BMCU-BADGE" base name even with path and .gcode.3mf + await _find_3mf_by_filename(1, "/sdcard/BMCU-BADGE.gcode.3mf", db, base_dir) + + # Verify the execute was called (search was attempted with stripped name) + assert db.execute.call_count == 2 # library + archive search + + +class TestTrackFrom3mfWithPreresolvedPath: + """Tests for _track_from_3mf() with threemf_path (no archive needed).""" + + @pytest.mark.asyncio + async def test_uses_preresolved_path_without_archive(self): + """When threemf_path is provided with archive_id=None, uses the path directly.""" + spool = _make_spool(spool_id=1, label_weight=1000) + assignment = _make_assignment(spool_id=1, ams_id=0, tray_id=3) + + # DB: 1st call = assignment lookup (live), 2nd = spool lookup + db = _mock_db_sequential([assignment, spool]) + + printer_manager = MagicMock() + printer_manager.get_status.return_value = SimpleNamespace( + raw_data={"ams": [{"id": 0, "tray": []}]}, + tray_now=255, + last_loaded_tray=3, + tray_change_log=[], + ) + + filament_usage = [{"slot_id": 1, "used_g": 5.0, "type": "PETG", "color": "#FFFFFF"}] + + with ( + patch( + "backend.app.utils.threemf_tools.extract_filament_usage_from_3mf", + return_value=filament_usage, + ), + patch("backend.app.core.config.settings") as mock_settings, + ): + mock_settings.base_dir = MagicMock() + mock_path = MagicMock() + mock_path.exists.return_value = True + + results = await _track_from_3mf( + printer_id=1, + archive_id=None, + status="completed", + print_name="BMCU-BADGE", + handled_trays=set(), + printer_manager=printer_manager, + db=db, + ams_mapping=[3, -1, -1, -1], + threemf_path=mock_path, + ) + + assert len(results) == 1 + assert results[0]["spool_id"] == 1 + assert results[0]["weight_used"] == 5.0 + + @pytest.mark.asyncio + async def test_skips_queue_lookup_without_archive_id(self): + """When archive_id is None, queue item lookup is skipped.""" + spool = _make_spool(spool_id=1, label_weight=1000) + assignment = _make_assignment(spool_id=1, ams_id=0, tray_id=0) + + db = _mock_db_sequential([assignment, spool]) + + printer_manager = MagicMock() + printer_manager.get_status.return_value = SimpleNamespace( + raw_data={"ams": [{"id": 0, "tray": []}]}, + tray_now=0, + last_loaded_tray=0, + tray_change_log=[], + ) + + filament_usage = [{"slot_id": 1, "used_g": 2.0, "type": "PLA", "color": "#FF0000"}] + + with ( + patch( + "backend.app.utils.threemf_tools.extract_filament_usage_from_3mf", + return_value=filament_usage, + ), + patch("backend.app.core.config.settings") as mock_settings, + ): + mock_settings.base_dir = MagicMock() + mock_path = MagicMock() + mock_path.exists.return_value = True + + # Should NOT fail even though there's no archive_id for queue lookup + results = await _track_from_3mf( + printer_id=1, + archive_id=None, + status="completed", + print_name="Test", + handled_trays=set(), + printer_manager=printer_manager, + db=db, + tray_now_at_start=0, + threemf_path=mock_path, + ) + + assert len(results) == 1 + assert results[0]["weight_used"] == 2.0