From 9a60b081171af2d7ea8527082145e017d05b7a83 Mon Sep 17 00:00:00 2001 From: yoyoliuuu Date: Thu, 30 Jul 2026 18:47:27 -0400 Subject: [PATCH] fix: derive activity from observed print state, not equipment_status MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit STATUS_SPEC §2.3 requires `activity` to come from observed hardware state and forbids computing it from `equipment_status` — the v1.2 migration did exactly that (`"idle" if state == "ready" else "unknown"`), so both live printers reported `busy` with `activity: "unknown"` while printing, which also breaks the §2.3 invariant `busy ⇒ running`. Map the printer's own gcode state on its own axis instead. PAUSE counts as running: the job is in flight and the printer cannot take another one, and that keeps `busy ⇒ running` true (the sub-state stays legible in `components["print_job"]` and `message`). FAILED is idle — the job stopped, and §2.3 permits any activity under `error`. MQTT down, telemetry not yet arrived, stale telemetry, and a monitor exception all yield `unknown` rather than a stale idle/running. `activity_since` was `now` on every status build, so it reset on every poll and could never yield a duration. The transition is now detected in the background poll (routes stay pure cache reads, per AGENTS.md), and it is null whenever the transition itself was never observed — a restart mid-print, or telemetry that went stale and recovered. The span began before this service could see it, so stamping first-observation time would report a far-too-short duration for exactly the in-progress operation the field exists to measure. `activity` is evaluated at request time so it cannot contradict `equipment_status` within one response (staleness is the only input that moves between polls); `activity_since` is emitted only when the request-time answer matches the tracked one. README documents the primary operation (running a print job) and the state mapping, closing that §9 v1.2 checklist item. Also fixes the ruff I001 the migration commit left in models.py. Co-Authored-By: Claude Opus 5 (1M context) --- README.md | 39 +++++++++++++- src/bambu_server/models.py | 3 +- src/bambu_server/monitor.py | 74 +++++++++++++++++++++++++- tests/test_api.py | 52 +++++++++++++++++++ tests/test_monitor.py | 100 ++++++++++++++++++++++++++++++++++++ 5 files changed, 263 insertions(+), 5 deletions(-) create mode 100644 tests/test_monitor.py diff --git a/README.md b/README.md index 9ada889..8932375 100644 --- a/README.md +++ b/README.md @@ -3,8 +3,10 @@ A monitoring-only FastAPI gateway for the Bambu Lab printers in the lab. It uses [`bambulabs_api`](https://github.com/BambuTools/bambulabs_api) for local MQTT telemetry and publishes one -[AC lab STATUS_SPEC v1.0](../ac-organic-lab/docs/STATUS_SPEC.md) surface per -printer. +[AC lab STATUS_SPEC v1.2](../ac-organic-lab/docs/STATUS_SPEC.md) surface per +printer. This repo conforms to lab status spec v1.2 on its per-printer +surfaces; the aggregate gateway envelope stays on v1.0 (it fronts printers and +has no primary operation of its own). The service deliberately exposes **no control endpoints** in v0.1. The third-party package supports commands, but those methods are isolated behind a @@ -81,6 +83,39 @@ contract does not yet define a `3d_printer` kind. `details.device_type` carries reporting `FAILED` maps to `error`; missing or stale MQTT telemetry maps to `unknown`, never to a fabricated hardware fault. +### Primary operation and `activity` (spec §2.3) + +The **primary operation** of a printer is running a print job. `activity` is +derived from the printer's observed gcode state alone — never from +`equipment_status`, which answers the independent question of whether the +printer is healthy: + +| observed gcode state | `equipment_status` | `activity` | +|---|---|---| +| `IDLE`, `FINISH` | `ready` | `idle` | +| `PREPARE`, `RUNNING`, `PAUSE` | `busy` | `running` | +| `FAILED` | `error` | `idle` | +| anything else | `unknown` | `unknown` | +| MQTT down / no telemetry / stale | `unknown` | `unknown` | + +`PAUSE` counts as `running`: the job is in flight and the printer cannot accept +another one, which also satisfies the spec's `busy` ⇒ `running` invariant. The +exact sub-state stays visible in `components["print_job"]` and `message`. +`FAILED` is `idle` because the job has stopped — §2.3 permits any activity +under `error`. + +`activity_since` is the instant the value last changed, observed by the +background poll (every `poll_interval_seconds`), not the time the status request +was built. It is `null` whenever the transition itself was never observed — a +service restart mid-print, or telemetry that went stale and recovered — because +the span began before this service could see it and stamping first-observation +time would report a far-too-short duration. Expect `activity: running` with +`activity_since: null` for a job that was already underway when the service +started; it gets a timestamp at the next real transition. + +Print jobs run far longer than the dashboard's 60 s poll, so the sampling caveat +in §2.3.1 does not apply and no `cycles_total` metric is published. + ## Dashboard registration Add one entry per printer to `ac-organic-lab/equipment.yaml` after deploying the diff --git a/src/bambu_server/models.py b/src/bambu_server/models.py index cd530b1..c5e3ebb 100644 --- a/src/bambu_server/models.py +++ b/src/bambu_server/models.py @@ -10,8 +10,8 @@ from typing import Literal from pydantic import BaseModel - from sdl_lab_contract import ( + Activity, ComponentStatus, EquipmentKind, EquipmentState, @@ -42,6 +42,7 @@ class PrinterSummary(BaseModel): __all__ = [ # Re-exported from sdl_lab_contract + "Activity", "ComponentStatus", "EquipmentKind", "EquipmentState", diff --git a/src/bambu_server/monitor.py b/src/bambu_server/monitor.py index 24eb48a..faef238 100644 --- a/src/bambu_server/monitor.py +++ b/src/bambu_server/monitor.py @@ -14,6 +14,7 @@ from .config import PrinterDefinition from .models import ( PROTOCOL_VERSION, + Activity, ComponentStatus, EquipmentStatus, ErrorInfo, @@ -25,6 +26,20 @@ _READY_STATES = {"IDLE", "FINISH"} _BUSY_STATES = {"PREPARE", "RUNNING", "PAUSE"} +# Activity mapping (STATUS_SPEC §2.3). The primary operation of a printer is a +# print job. These sets map the printer's *observed* gcode state, independently +# of the health mapping above -- §2.3 forbids deriving `activity` from +# `equipment_status`, because computing one from the other adds no information. +# +# PAUSE counts as running: the job is in flight and the printer cannot take +# another one. That also keeps the §2.3 invariant `busy => running` true, since +# `_map_state` reports PAUSE as `busy`. The exact sub-state stays visible in +# `components["print_job"]` and in `message`. +_RUNNING_JOB_STATES = {"PREPARE", "RUNNING", "PAUSE"} +# FAILED is *not* running -- the job stopped -- even though health is `error`. +# §2.3 allows any activity under `error`, so the honest answer is `idle`. +_IDLE_JOB_STATES = {"IDLE", "FINISH", "FAILED"} + class PrinterMonitor: def __init__( @@ -43,6 +58,8 @@ def __init__( self._reading: PrinterReading | None = None self._monitor_error_type: str | None = None self._task: asyncio.Task[None] | None = None + self._activity: Activity = "unknown" + self._activity_since: datetime | None = None async def start(self) -> None: await asyncio.to_thread(self._backend.start) @@ -71,6 +88,52 @@ async def _collect_once(self) -> None: except Exception as exc: self._monitor_error_type = type(exc).__name__ logger.exception("Printer monitor failed for %s", self.definition.id) + self._track_activity(datetime.now(UTC)) + + def _track_activity(self, now: datetime) -> None: + """Record the instant ``activity`` last changed value (STATUS_SPEC §2.3). + + Called from the background poll and never from a status request, so the + timestamp marks when the change was *observed* rather than when a reader + happened to ask. + """ + observed = self._observed_activity(now) + if observed == self._activity: + return + + previous = self._activity + self._activity = observed + # Only a transition between two *known* values can be timestamped. + # Coming out of `unknown` -- a cold start mid-print, or telemetry that + # went stale and recovered -- means the span began before this service + # could observe it, so the honest answer is null (§2.3). Stamping the + # first-observation instant would report a wrong, far-too-short duration + # for the very in-progress operation the field exists to measure. + self._activity_since = ( + now if "unknown" not in (previous, observed) else None + ) + + def _observed_activity(self, now: datetime) -> Activity: + """Derive ``activity`` from observed print state only. + + Returns ``unknown`` whenever the observation itself cannot be trusted + (monitor failure, MQTT down, no telemetry yet, stale telemetry) rather + than reporting a stale ``idle``/``running`` as current fact. + """ + reading = self._reading + if ( + self._monitor_error_type is not None + or reading is None + or not reading.connected + or not reading.data_ready + or self._is_stale(reading, now) + ): + return "unknown" + if reading.gcode_state in _RUNNING_JOB_STATES: + return "running" + if reading.gcode_state in _IDLE_JOB_STATES: + return "idle" + return "unknown" def status(self) -> EquipmentStatus: now = datetime.now(UTC) @@ -103,6 +166,13 @@ def status(self) -> EquipmentStatus: last_event_at=reading.data_updated_at if reading else None, ) } + # Evaluated at request time so `activity` cannot contradict the state + # computed above (staleness is the one input that moves between polls). + # `activity_since` is only reported when the request-time answer matches + # the tracked one, so it is never a timestamp for a different value. + activity = self._observed_activity(now) + activity_since = self._activity_since if activity == self._activity else None + metrics = self._metrics(reading) if reading and reading.data_ready else {} details: dict[str, object] = { "device_type": "3d_printer", @@ -134,8 +204,8 @@ def status(self) -> EquipmentStatus: equipment_version=__version__, host=socket.gethostname(), equipment_status=state, - activity=("idle" if state == "ready" else "unknown"), - activity_since=now if state == "ready" else None, + activity=activity, + activity_since=activity_since, message=message, device_time=now, uptime_seconds=monotonic() - self._started_at, diff --git a/tests/test_api.py b/tests/test_api.py index 88315e5..0899e40 100644 --- a/tests/test_api.py +++ b/tests/test_api.py @@ -86,6 +86,55 @@ def test_running_print_is_busy(settings: Settings) -> None: with TestClient(app) as test_client: body = test_client.get("/printers/bambu_test_01/status").json() assert body["equipment_status"] == "busy" + assert body["activity"] == "running" + # Cold start mid-print: the transition was never observed, so it cannot be + # timestamped. See tests/test_monitor.py for the observed-transition case. + assert body["activity_since"] is None + + +def test_activity_comes_from_print_state_not_equipment_status( + settings: Settings, +) -> None: + """STATUS_SPEC §2.3: activity is observed, and the invariants hold.""" + cases = [ + ("IDLE", "ready", "idle"), + ("FINISH", "ready", "idle"), + ("PREPARE", "busy", "running"), + ("RUNNING", "busy", "running"), + # A paused job is still in flight: `busy` requires `running`. + ("PAUSE", "busy", "running"), + # The job stopped, so nothing is running even though health is `error`. + ("FAILED", "error", "idle"), + ("SOMETHING_NEW", "unknown", "unknown"), + ] + for gcode_state, expected_status, expected_activity in cases: + backend = FakeBackend( + PrinterReading( + data_updated_at=datetime.now(UTC), + connected=True, + data_ready=True, + gcode_state=gcode_state, + activity=gcode_state, + ) + ) + app = create_app( + settings=settings, + backend_factory=lambda _definition, _creds, value=backend: value, + ) + with TestClient(app) as test_client: + body = test_client.get("/printers/bambu_test_01/status").json() + assert body["equipment_status"] == expected_status, gcode_state + assert body["activity"] == expected_activity, gcode_state + + +def test_activity_since_does_not_advance_per_request(client: TestClient) -> None: + """`activity_since` must not be rebuilt from the request clock (§2.3).""" + first = client.get("/printers/bambu_test_01/status").json() + second = client.get("/printers/bambu_test_01/status").json() + + assert first["activity"] == second["activity"] == "idle" + assert first["activity_since"] == second["activity_since"] + assert first["device_time"] != second["device_time"] def test_unreachable_and_stale_are_unknown(settings: Settings) -> None: @@ -113,6 +162,9 @@ def test_unreachable_and_stale_are_unknown(settings: Settings) -> None: body = test_client.get("/printers/bambu_test_01/status").json() assert body["equipment_status"] == "unknown" assert body["message"] == expected_message + # Untrustworthy telemetry must not be reported as a stale idle/running. + assert body["activity"] == "unknown" + assert body["activity_since"] is None def test_failed_print_is_error(settings: Settings) -> None: diff --git a/tests/test_monitor.py b/tests/test_monitor.py new file mode 100644 index 0000000..5717ebe --- /dev/null +++ b/tests/test_monitor.py @@ -0,0 +1,100 @@ +"""Activity-axis behaviour of the monitor (STATUS_SPEC §2.3).""" + +from __future__ import annotations + +from datetime import UTC, datetime, timedelta + +from bambu_server.backend import PrinterReading +from bambu_server.config import PrinterDefinition +from bambu_server.monitor import PrinterMonitor + +from .conftest import FakeBackend + + +def _reading(gcode_state: str, *, age_seconds: float = 0.0) -> PrinterReading: + return PrinterReading( + data_updated_at=datetime.now(UTC) - timedelta(seconds=age_seconds), + connected=True, + data_ready=True, + gcode_state=gcode_state, + activity=gcode_state, + ) + + +def _monitor(backend: FakeBackend) -> PrinterMonitor: + return PrinterMonitor( + PrinterDefinition( + id="bambu_test_01", + name="Bambu Test 01", + model="X1 Carbon", + env_prefix="BAMBU_TEST_01", + ), + backend, + poll_interval_seconds=2.0, + stale_after_seconds=20.0, + ) + + +async def test_activity_since_is_null_until_a_transition_is_observed() -> None: + """A cold start mid-print cannot know when the job began.""" + monitor = _monitor(FakeBackend(_reading("RUNNING"))) + await monitor._collect_once() + + status = monitor.status() + assert status.equipment_status == "busy" + assert status.activity == "running" + assert status.activity_since is None + + +async def test_activity_since_marks_the_observed_transition() -> None: + backend = FakeBackend(_reading("IDLE")) + monitor = _monitor(backend) + await monitor._collect_once() + assert monitor.status().activity == "idle" + + backend.reading = _reading("RUNNING") + await monitor._collect_once() + + started = monitor.status().activity_since + assert started is not None + assert monitor.status().activity == "running" + + # A later poll with unchanged activity must not move the timestamp, and + # neither must repeated status builds. + backend.reading = _reading("RUNNING") + await monitor._collect_once() + assert monitor.status().activity_since == started + assert monitor.status().activity_since == started + + +async def test_stale_telemetry_clears_activity_mid_job() -> None: + backend = FakeBackend(_reading("IDLE")) + monitor = _monitor(backend) + await monitor._collect_once() + backend.reading = _reading("RUNNING") + await monitor._collect_once() + assert monitor.status().activity_since is not None + + # Telemetry stops arriving: the printer may well still be printing, but the + # service can no longer observe it. + backend.reading = _reading("RUNNING", age_seconds=600) + await monitor._collect_once() + + status = monitor.status() + assert status.equipment_status == "unknown" + assert status.activity == "unknown" + assert status.activity_since is None + + +async def test_monitor_failure_reports_unknown_activity() -> None: + class BrokenBackend(FakeBackend): + def read(self) -> PrinterReading: + raise RuntimeError("mqtt exploded") + + monitor = _monitor(BrokenBackend(_reading("RUNNING"))) + await monitor._collect_once() + + status = monitor.status() + assert status.equipment_status == "unknown" + assert status.activity == "unknown" + assert status.activity_since is None