Browse Source

fix(maintenance): paused prints no longer accumulate runtime hours (#1521)

  PAUSE counted toward runtime_seconds equally with RUNNING, inflating
  hours-based maintenance thresholds (rod lube, belt check, nozzle clean)
  by however long overnight or extended pauses lasted. Maintenance items
  track mechanical wear, which is zero while paused, so the predicate
  now excludes PAUSE. Field-comment and docstring trail across main.py /
  models/printer.py / maintenance.py updated to match. Existing
  runtime_seconds values cannot be retroactively split — only future
  accumulation is fixed.

  Adds 3 regression tests pinning PAUSE non-accumulation, RUNNING
  accumulation, and the FINISH state's last_runtime_update clear
  (prevents idle-time back-bill when the printer next goes RUNNING).
maziggy 2 days ago
parent
commit
554a73070f

File diff suppressed because it is too large
+ 0 - 0
CHANGELOG.md


+ 3 - 2
backend/app/api/routes/maintenance.py

@@ -126,7 +126,8 @@ async def get_printer_total_hours(db: AsyncSession, printer_id: int) -> float:
     """Calculate total active hours for a printer from runtime counter plus offset.
 
     Uses the runtime_seconds counter which tracks actual machine active time
-    (RUNNING and PAUSE states), including calibration, heating, and printing.
+    (RUNNING state only — paused time is excluded since maintenance intervals
+    measure mechanical wear, not wall-clock active time, see #1521).
     """
     # Get printer runtime and offset
     result = await db.execute(
@@ -714,7 +715,7 @@ async def set_printer_hours(
 
     The offset is calculated as: offset = total_hours - runtime_hours
     Where runtime_hours comes from the runtime_seconds counter that tracks
-    actual machine active time (RUNNING/PAUSE states).
+    actual machine active time (RUNNING state only — paused time excluded, #1521).
     """
     # Get printer
     result = await db.execute(select(Printer).where(Printer.id == printer_id))

+ 8 - 2
backend/app/main.py

@@ -4380,7 +4380,13 @@ RUNTIME_TRACKING_INTERVAL = 30  # Update every 30 seconds
 
 
 async def track_printer_runtime():
-    """Background task to track printer active runtime (RUNNING/PAUSE states)."""
+    """Background task to track printer active runtime (RUNNING state only).
+
+    PAUSE is intentionally excluded — the runtime counter feeds hours-based
+    maintenance intervals (rod lubrication, belt checks, nozzle cleaning)
+    which track mechanical wear. Pause time has no motion and no wear, so
+    counting it inflates maintenance warnings (#1521).
+    """
     logger = logging.getLogger(__name__)
 
     # Wait for MQTT connections to establish on startup
@@ -4418,7 +4424,7 @@ async def track_printer_runtime():
                 new_runtime = runtime_secs
                 new_last_update = last_update
 
-                if state.state in ("RUNNING", "PAUSE"):
+                if state.state == "RUNNING":
                     if last_update:
                         lu = last_update if last_update.tzinfo else last_update.replace(tzinfo=timezone.utc)
                         elapsed = (now - lu).total_seconds()

+ 3 - 1
backend/app/models/printer.py

@@ -20,7 +20,9 @@ class Printer(Base):
     is_active: Mapped[bool] = mapped_column(Boolean, default=True)
     auto_archive: Mapped[bool] = mapped_column(Boolean, default=True)
     print_hours_offset: Mapped[float] = mapped_column(Float, default=0.0)  # Baseline hours to add
-    runtime_seconds: Mapped[int] = mapped_column(default=0)  # Accumulated active runtime (RUNNING/PAUSE states)
+    runtime_seconds: Mapped[int] = mapped_column(
+        default=0
+    )  # Accumulated active runtime (RUNNING state only — see #1521)
     last_runtime_update: Mapped[datetime | None] = mapped_column(
         DateTime, nullable=True
     )  # Last time runtime was updated

+ 155 - 0
backend/tests/unit/test_runtime_tracking_pause.py

@@ -0,0 +1,155 @@
+"""Regression tests for the runtime-tracking task (#1521).
+
+The ``runtime_seconds`` counter on each printer feeds hours-based maintenance
+intervals (rod lubrication, belt checks, nozzle cleaning). It was accumulating
+elapsed time whenever ``state.state`` was ``RUNNING`` *or* ``PAUSE``, which
+meant a print paused for hours (e.g. overnight) inflated the maintenance
+clock without any actual mechanical wear. Fix excludes PAUSE; these tests
+pin the new contract.
+"""
+
+from __future__ import annotations
+
+import asyncio
+from datetime import datetime, timedelta, timezone
+from types import SimpleNamespace
+from unittest.mock import patch
+
+import pytest
+from sqlalchemy import select
+from sqlalchemy.ext.asyncio import AsyncSession, async_sessionmaker, create_async_engine
+
+
+async def _build_db_with_printer(*, runtime_seconds: int, last_runtime_update: datetime | None):
+    """Spin up an in-memory DB with one active printer in the requested state."""
+    import backend.app.models  # noqa: F401  -- register all models on Base.metadata
+    from backend.app.core.database import Base
+    from backend.app.models.printer import Printer
+
+    engine = create_async_engine("sqlite+aiosqlite:///:memory:", echo=False)
+    async with engine.begin() as conn:
+        await conn.run_sync(Base.metadata.create_all)
+    session_maker = async_sessionmaker(engine, class_=AsyncSession, expire_on_commit=False)
+
+    async with session_maker() as db:
+        db.add(
+            Printer(
+                id=1,
+                name="P1",
+                serial_number="S1",
+                ip_address="1.1.1.1",
+                access_code="x",
+                is_active=True,
+                runtime_seconds=runtime_seconds,
+                last_runtime_update=last_runtime_update,
+            )
+        )
+        await db.commit()
+    return engine, session_maker
+
+
+async def _run_one_iteration(session_maker, state_value: str):
+    """Run a single iteration of track_printer_runtime() against a mocked state.
+
+    Patches ``asyncio.sleep`` to skip the startup wait and cancel after the
+    first loop tick. Patches ``printer_manager.get_status`` to return a fake
+    state with the requested ``.state`` value. Points the module-level
+    ``async_session`` at the test DB so the loop's queries hit it.
+    """
+    from backend.app import main as app_main
+
+    sleep_calls = {"count": 0}
+    real_sleep = asyncio.sleep
+
+    async def fake_sleep(seconds, *args, **kwargs):
+        sleep_calls["count"] += 1
+        # First sleep = the 15s startup wait. Second sleep = end-of-iteration
+        # tick; raise here so the loop exits cleanly via its CancelledError
+        # handler after exactly one work cycle.
+        if sleep_calls["count"] >= 2:
+            raise asyncio.CancelledError()
+        # Yield control to keep the event loop healthy without blocking.
+        await real_sleep(0)
+
+    fake_state = SimpleNamespace(state=state_value, connected=True)
+
+    # The loop's tail-of-iteration sleep is OUTSIDE its try/except, so the
+    # CancelledError raised from fake_sleep propagates out of the function
+    # rather than triggering the inner break — catch it at the test boundary.
+    with (
+        patch.object(app_main, "async_session", session_maker),
+        patch.object(app_main.printer_manager, "get_status", return_value=fake_state),
+        patch.object(app_main.asyncio, "sleep", fake_sleep),
+        pytest.raises(asyncio.CancelledError),
+    ):
+        await app_main.track_printer_runtime()
+
+
+@pytest.mark.asyncio
+async def test_pause_state_does_not_accumulate_runtime():
+    """PAUSE must NOT add to runtime_seconds — paused = no motion = no wear (#1521)."""
+    seeded_runtime = 1000  # 1000s already accumulated
+    seeded_last_update = datetime.now(timezone.utc) - timedelta(seconds=300)  # 5min ago
+    engine, session_maker = await _build_db_with_printer(
+        runtime_seconds=seeded_runtime, last_runtime_update=seeded_last_update
+    )
+
+    await _run_one_iteration(session_maker, state_value="PAUSE")
+
+    from backend.app.models.printer import Printer
+
+    async with session_maker() as db:
+        row = (await db.execute(select(Printer).where(Printer.id == 1))).scalar_one()
+        # Runtime counter unchanged — the 5 minutes paused contributed nothing.
+        assert row.runtime_seconds == seeded_runtime
+        # last_runtime_update cleared on the non-running branch so the next
+        # transition to RUNNING starts fresh and doesn't back-bill paused time.
+        assert row.last_runtime_update is None
+
+    await engine.dispose()
+
+
+@pytest.mark.asyncio
+async def test_running_state_still_accumulates_runtime():
+    """RUNNING must continue to accumulate — the bug was scope, not the whole feature."""
+    seeded_runtime = 1000
+    seeded_last_update = datetime.now(timezone.utc) - timedelta(seconds=60)
+    engine, session_maker = await _build_db_with_printer(
+        runtime_seconds=seeded_runtime, last_runtime_update=seeded_last_update
+    )
+
+    await _run_one_iteration(session_maker, state_value="RUNNING")
+
+    from backend.app.models.printer import Printer
+
+    async with session_maker() as db:
+        row = (await db.execute(select(Printer).where(Printer.id == 1))).scalar_one()
+        # Wall-clock elapsed since seeded_last_update should now be added.
+        # Allow a generous lower bound (≥30s) — actual elapsed depends on
+        # how fast the test runs, but it MUST have grown past the seed.
+        assert row.runtime_seconds > seeded_runtime
+        assert row.runtime_seconds >= seeded_runtime + 30
+        assert row.last_runtime_update is not None
+
+    await engine.dispose()
+
+
+@pytest.mark.asyncio
+async def test_idle_state_clears_last_update_without_accumulating():
+    """A non-active state (FINISH/IDLE/PREPARE/etc.) must clear last_runtime_update
+    so a later RUNNING transition doesn't retroactively back-bill all the idle time."""
+    seeded_runtime = 1000
+    seeded_last_update = datetime.now(timezone.utc) - timedelta(seconds=3600)  # 1h ago
+    engine, session_maker = await _build_db_with_printer(
+        runtime_seconds=seeded_runtime, last_runtime_update=seeded_last_update
+    )
+
+    await _run_one_iteration(session_maker, state_value="FINISH")
+
+    from backend.app.models.printer import Printer
+
+    async with session_maker() as db:
+        row = (await db.execute(select(Printer).where(Printer.id == 1))).scalar_one()
+        assert row.runtime_seconds == seeded_runtime  # no accumulation
+        assert row.last_runtime_update is None  # cleared, prevents back-bill
+    await engine.dispose()

Some files were not shown because too many files changed in this diff