fix(stats): don't bank the disconnect gap as print time on reconnect (#2592)

reconcile_stale_active_prints closes out stale status="printing" archives by
synthesising an aborted on_print_complete, which logged a PrintLogEntry whose
duration was completed_at - started_at — the whole multi-day disconnect gap,
since a reconciled archive's real end time is unknown. Across a farm of stale
rows this inflated Total Print Time by hundreds of hours, and the Stats total
recomputed the same value from the timestamps even when duration was NULL/0.

Reconciled completions now log duration_seconds=0, the two Stats time paths
trust a stored 0 instead of recomputing, and reconciled aborts get an honest
"Stale - reconciled ..." failure_reason instead of "User cancelled". Genuine
long prints are untouched (no cap; still-running >24h prints aren't stale).

backend/app/api/routes/archives.py

@@ -593,8 +593,12 @@ async def list_archives_slim(
                 # print_time_seconds (slicer estimate) for non-completed
                 # events would diverge from Quick Stats — so expose the
                 # measured value here unconditionally.
+                #
+                # Trust an explicit 0 (reconciled aborts store it deliberately;
+                # their real end time is unknown) instead of recomputing the
+                # multi-day disconnect gap from the timestamps (#2592).
                 r.duration_seconds
-                if r.duration_seconds and r.duration_seconds > 0
+                if r.duration_seconds is not None
                 else (
                     int((r.completed_at - r.started_at).total_seconds())
                     if r.started_at and r.completed_at and (r.completed_at - r.started_at).total_seconds() > 0
@@ -1071,7 +1075,12 @@ async def get_archive_stats(
     )
     total_seconds = 0
     for duration_seconds, started_at, completed_at in time_rows.all():
-        if duration_seconds:
+        # Trust an explicitly stored duration, INCLUDING 0: a reconciled abort
+        # stores 0 on purpose because its real end time is unknown, and the
+        # started_at→completed_at fallback would otherwise bank the whole
+        # multi-day disconnect gap as print time (#2592). Only rows with a NULL
+        # duration (legacy entries that never recorded one) fall back.
+        if duration_seconds is not None:
             total_seconds += duration_seconds
         elif started_at and completed_at:
             elapsed = (completed_at - started_at).total_seconds()

backend/app/main.py

@@ -4718,6 +4718,13 @@ async def on_print_complete(printer_id: int, data: dict):
             if hms_errors:
                 logger.info("[ARCHIVE] HMS errors at failure: %s", hms_errors)
             failure_reason = derive_failure_reason(status, hms_errors)
+            if data.get("_reconciled"):
+                # A reconciled completion closes out a stale archive at
+                # reconnect — it is not a user action, so don't mislabel it
+                # "User cancelled". The "Stale" prefix matches the existing
+                # stale-cleanup convention and records that the real end time
+                # is unknown, which is also why its logged duration is 0 (#2592).
+                failure_reason = "Stale - reconciled after reconnect, end time unknown"
             if failure_reason:
                 logger.info("[ARCHIVE] failure_reason=%r (status=%s)", failure_reason, status)
             elif status == "failed" and hms_errors:
@@ -4818,6 +4825,9 @@ async def on_print_complete(printer_id: int, data: dict):
                     thumbnail_path=archive.thumbnail_path,
                     created_by_id=archive.created_by_id,
                     created_by_username=_print_user_info.get("username") if _print_user_info else None,
+                    # Reconciled completions have an unknown real end time —
+                    # log 0 duration instead of the whole disconnect gap (#2592).
+                    reconciled=bool(data.get("_reconciled")),
                 )
                 await db.commit()
                 logger.info("[PRINT_LOG] Log entry written for archive %s", archive_id)

backend/app/services/print_log.py

@@ -33,11 +33,26 @@ async def write_log_entry(
     thumbnail_path: str | None = None,
     created_by_id: int | None = None,
     created_by_username: str | None = None,
+    reconciled: bool = False,
 ) -> PrintLogEntry:
-    """Write a print log entry."""
-    duration = None
-    if started_at and completed_at:
+    """Write a print log entry.
+
+    ``reconciled`` marks a synthetic completion written when a stale
+    ``status="printing"`` archive is closed out at reconnect. Its real end time
+    is unknown — the print stopped somewhere during the disconnect and
+    ``completed_at`` is only the reconnect moment — so ``completed_at -
+    started_at`` would bank the entire disconnect gap as print time, adding
+    hundreds of fictitious hours across a farm of stale rows (#2592). For those
+    entries we store an explicit ``0`` ("no measured runtime") rather than a
+    fabricated duration; the stats total trusts a stored 0 instead of
+    recomputing from the stale timestamps.
+    """
+    if reconciled:
+        duration: int | None = 0
+    elif started_at and completed_at:
         duration = int((completed_at - started_at).total_seconds())
+    else:
+        duration = None
 
     entry = PrintLogEntry(
         archive_id=archive_id,

backend/tests/integration/test_stats_reconciled_duration_2592.py

@@ -0,0 +1,66 @@
+"""Regression test for reconnect-reconciliation inflating Total Print Time (#2592).
+
+On a farm, a connected-edge reconcile closes out every stale ``status="printing"``
+archive as an aborted run whose duration was computed ``completed_at - started_at``
+— i.e. the whole multi-day disconnect gap — and the Stats endpoint's fallback
+recomputed the same value even when the stored duration was 0/NULL. A single
+reconnect could add hundreds of fictitious print hours (reporter @Jostxxl saw
+Total Print Time jump from ~1,500h to 3,215h).
+
+The fix stores an explicit 0 for reconciled entries and makes the Stats total
+trust that 0 instead of recomputing from the stale timestamps. This test drives
+the ``/archives/stats`` endpoint with hand-crafted rows covering the reporter's
+scenarios.
+"""
+
+from __future__ import annotations
+
+from datetime import datetime, timedelta
+
+import pytest
+from httpx import AsyncClient
+
+from backend.app.models.print_log import PrintLogEntry
+
+
+@pytest.mark.asyncio
+@pytest.mark.integration
+async def test_stats_total_time_ignores_reconciled_but_keeps_real_runtime(async_client: AsyncClient, db_session):
+    base = datetime(2026, 7, 15, 10, 0, 0)
+    reconnect = base + timedelta(days=2, hours=4)  # multi-day gap → ~52h each if recomputed
+
+    rows = [
+        # Two reconciled aborts for the same printer: duration logged as 0 on
+        # purpose (unknown real end time). Their timestamps span days, so the
+        # bug would have banked ~52h each (~104h total) via the fallback.
+        PrintLogEntry(printer_id=1, status="aborted", started_at=base, completed_at=reconnect, duration_seconds=0),
+        PrintLogEntry(printer_id=1, status="aborted", started_at=base, completed_at=reconnect, duration_seconds=0),
+        # A genuine >24h print — must be retained in full (no cap, no zeroing).
+        PrintLogEntry(
+            printer_id=1,
+            status="completed",
+            started_at=base,
+            completed_at=base + timedelta(hours=30),
+            duration_seconds=30 * 3600,
+        ),
+        # A legacy row that never stored a duration — must still fall back to
+        # its own (short, legitimate) 2h span.
+        PrintLogEntry(
+            printer_id=1,
+            status="completed",
+            started_at=base,
+            completed_at=base + timedelta(hours=2),
+            duration_seconds=None,
+        ),
+    ]
+    for r in rows:
+        db_session.add(r)
+    await db_session.commit()
+
+    resp = await async_client.get("/api/v1/archives/stats")
+    assert resp.status_code == 200, resp.text
+    data = resp.json()
+
+    # 30h (genuine) + 2h (legacy fallback) + 0 + 0 (reconciled) = 32.0h.
+    # Pre-fix the two reconciled rows would have added ~104h from their stamps.
+    assert data["total_print_time_hours"] == 32.0

backend/tests/unit/test_print_log.py

@@ -1,10 +1,12 @@
 """Unit tests for print log service and schema."""
 
 from datetime import datetime, timedelta
+from unittest.mock import AsyncMock, MagicMock
 
 import pytest
 
 from backend.app.schemas.print_log import PrintLogEntrySchema, PrintLogResponse
+from backend.app.services.print_log import write_log_entry
 
 
 class TestPrintLogEntrySchema:
@@ -102,3 +104,44 @@ class TestWriteLogEntry:
         if started_at and completed:
             duration = int((completed - started_at).total_seconds())
         assert duration is None
+
+
+class TestWriteLogEntryReconciledDuration:
+    """write_log_entry duration handling for reconciled (synthetic) completions (#2592).
+
+    A reconciled abort closes out a stale ``status="printing"`` archive at
+    reconnect; its real end time is unknown, so ``completed_at - started_at``
+    would bank the whole disconnect gap as print time. Those entries must log
+    0, while genuine prints (including >24h ones) keep their real duration.
+    """
+
+    @staticmethod
+    async def _write(**kwargs):
+        db = MagicMock()
+        db.flush = AsyncMock()
+        return await write_log_entry(db, **kwargs)
+
+    @pytest.mark.asyncio
+    async def test_reconciled_logs_zero_despite_multiday_gap(self):
+        started = datetime(2026, 7, 15, 10, 0, 0)
+        completed = started + timedelta(days=2, hours=4)  # the reconnect moment, not the real end
+        entry = await self._write(status="aborted", started_at=started, completed_at=completed, reconciled=True)
+        assert entry.duration_seconds == 0
+
+    @pytest.mark.asyncio
+    async def test_reconciled_logs_zero_even_without_timestamps(self):
+        entry = await self._write(status="aborted", reconciled=True)
+        assert entry.duration_seconds == 0
+
+    @pytest.mark.asyncio
+    async def test_genuine_long_print_retains_full_duration(self):
+        """A legitimate >24h print keeps its real duration — no cap, no zeroing."""
+        started = datetime(2026, 7, 15, 10, 0, 0)
+        completed = started + timedelta(hours=30)
+        entry = await self._write(status="completed", started_at=started, completed_at=completed)
+        assert entry.duration_seconds == 30 * 3600
+
+    @pytest.mark.asyncio
+    async def test_non_reconciled_missing_times_is_none(self):
+        entry = await self._write(status="completed", started_at=datetime(2026, 7, 15, 10, 0, 0))
+        assert entry.duration_seconds is None