fix(doors): verify and reconcile stale Open Longest door states #196

New issue

Open

opened 2026-09-30 18:04:03 +00:00 by gabogg · 2 comments

gabogg commented

2026-09-30 18:04:03 +00:00

Owner

Production symptom

The operator reports that Doors Open the Longest includes doors shown as closed in the HikCentral UI at 10.10.1.251. This is an operationally misleading live status and needs prompt investigation.

Live check (2026-09-30)

Production app at http://10.10.1.251:8888 responded; authenticated GET /api/doors/status returned five Open Longest entries.
A direct authenticated Artemis POST /artemis/api/resource/v1/acsDoor/acsDoorList returned 115 doors. All five ranked door IDs (1703, 1673, 45, 1684, 1690) had doorState: 2 (open) there and in the app response. The reported UI disagreement was not independently reproduced at this snapshot.
The repo's alternative catalog entry GET /ISAPI/AccessControl/Door/status returned HTTP 404 after a successful Bumblebee login, so it is not currently a usable second source as documented.
background_monitor() calls sync_doors_async() every loop and reconcile_door_states_with_upstream_async() every 60 seconds. Both read the same Artemis acsDoorList endpoint (app/services/monitor_service.py, app/services/door_service.py). The timed reconciliation can repair missed WebSocket/webhook updates only if this endpoint has the correct current state; it cannot detect an endpoint that lags or disagrees with HikCentral's UI.

Investigation required

Capture one door ID and timestamp while HikCentral UI says closed but the ranking says open; compare the app status, acsDoorList, and the actual API/request that supplies HikCentral UI's live state at the same time. Redact credentials, session IDs, and personal data from artifacts.
Establish the authoritative status source and freshness guarantee for physical door contact state. Check pagination, device/controller availability, and possible stale catalog values. Do not assume the undocumented ISAPI catalog entry is supported.
Trace the app's poll → reconciliation → persisted state → WebSocket snapshot → Open Longest path for that door. Confirm whether frontend caching can retain a door after the server removed it.
Add a regression test reproducing the verified failure mode and an operational freshness signal or quality indicator when state cannot be confirmed.

Acceptance criteria

A ranked door disappears promptly after the authoritative live source reports it closed, including when no webhook arrives.
If the authoritative source is unavailable or stale, the UI does not present an old OPEN observation as confirmed current status without an explicit freshness warning.
The source and age of a door status are visible enough to diagnose future disagreements; polling and reconciliation failures are observable.

Related: #191 covers explicitly time-limited human status records for unreliable hardware reports; it does not replace this synchronization diagnosis. Keep this bug distinct from the Supervisor feature milestone unless triage establishes it as a prerequisite.

## Production symptom The operator reports that **Doors Open the Longest** includes doors shown as closed in the HikCentral UI at `10.10.1.251`. This is an operationally misleading live status and needs prompt investigation. ## Live check (2026-09-30) - Production app at `http://10.10.1.251:8888` responded; authenticated `GET /api/doors/status` returned five Open Longest entries. - A direct authenticated Artemis `POST /artemis/api/resource/v1/acsDoor/acsDoorList` returned 115 doors. All five ranked door IDs (1703, 1673, 45, 1684, 1690) had `doorState: 2` (open) there and in the app response. The reported UI disagreement was **not independently reproduced** at this snapshot. - The repo's alternative catalog entry `GET /ISAPI/AccessControl/Door/status` returned HTTP 404 after a successful Bumblebee login, so it is not currently a usable second source as documented. - `background_monitor()` calls `sync_doors_async()` every loop and `reconcile_door_states_with_upstream_async()` every 60 seconds. Both read the **same** Artemis `acsDoorList` endpoint (`app/services/monitor_service.py`, `app/services/door_service.py`). The timed reconciliation can repair missed WebSocket/webhook updates only if this endpoint has the correct current state; it cannot detect an endpoint that lags or disagrees with HikCentral's UI. ## Investigation required 1. Capture one door ID and timestamp while HikCentral UI says closed but the ranking says open; compare the app status, `acsDoorList`, and the actual API/request that supplies HikCentral UI's live state at the same time. Redact credentials, session IDs, and personal data from artifacts. 2. Establish the authoritative status source and freshness guarantee for physical door contact state. Check pagination, device/controller availability, and possible stale catalog values. Do not assume the undocumented ISAPI catalog entry is supported. 3. Trace the app's poll → reconciliation → persisted state → WebSocket snapshot → Open Longest path for that door. Confirm whether frontend caching can retain a door after the server removed it. 4. Add a regression test reproducing the verified failure mode and an operational freshness signal or quality indicator when state cannot be confirmed. ## Acceptance criteria - A ranked door disappears promptly after the authoritative live source reports it closed, including when no webhook arrives. - If the authoritative source is unavailable or stale, the UI does not present an old OPEN observation as confirmed current status without an explicit freshness warning. - The source and age of a door status are visible enough to diagnose future disagreements; polling and reconciliation failures are observable. Related: #191 covers explicitly time-limited human status records for unreliable hardware reports; it does not replace this synchronization diagnosis. Keep this bug distinct from the Supervisor feature milestone unless triage establishes it as a prerequisite.

gabogg added the

high-priority

needs-triage

labels

2026-09-30 18:04:03 +00:00

gabogg commented

2026-09-30 18:35:18 +00:00

Author

Owner

Local reproduction of a stale-state path:

Send a doors_update overview with door D open at timestamp T: Open Longest count = 1.
Send a door_transitions close for D at T+20: count = 0.
Send an older doors_update overview with D still open at T: count returns to 1.

The local Node harness printed {"afterOpen":1,"afterClose":0,"afterStalePoll":1}. TelemetryEngine._ingestDoorTransitions() checks transition age before applying it (app/static/js/src/telemetry/telemetry_engine.js:697-712), but _ingestDoors() applies each subsequent overview without rejecting an older door state (:771-895). The existing test at tests/frontend/test_telemetry_engine.test.js:713 checks only a newer overview superseding a transition. The focused frontend test files pass, so this older-overview case lacks coverage.

There is a corresponding backend risk: sync_doors_async() accepts the latest acsDoorList state on each poll; its last_observed_activity > poll_start_time guard only protects a webhook that arrived during that poll. If a webhook closes a door and a later catalog poll still says open, the later poll can reopen it. The 60-second reconciler consults the same catalog endpoint.

This proves a code path that can make a closed door reappear, but does not prove it occurred for the production doors sampled earlier. A simultaneous capture of HikCentral UI status, Artemis catalog status, app API status, and browser snapshot for one affected door remains necessary to identify the production source of stale data.

Local reproduction of a stale-state path: 1. Send a `doors_update` overview with door D open at timestamp T: Open Longest count = 1. 2. Send a `door_transitions` close for D at T+20: count = 0. 3. Send an older `doors_update` overview with D still open at T: count returns to 1. The local Node harness printed `{"afterOpen":1,"afterClose":0,"afterStalePoll":1}`. `TelemetryEngine._ingestDoorTransitions()` checks transition age before applying it (`app/static/js/src/telemetry/telemetry_engine.js:697-712`), but `_ingestDoors()` applies each subsequent overview without rejecting an older door state (`:771-895`). The existing test at `tests/frontend/test_telemetry_engine.test.js:713` checks only a newer overview superseding a transition. The focused frontend test files pass, so this older-overview case lacks coverage. There is a corresponding backend risk: `sync_doors_async()` accepts the latest `acsDoorList` state on each poll; its `last_observed_activity > poll_start_time` guard only protects a webhook that arrived during that poll. If a webhook closes a door and a later catalog poll still says open, the later poll can reopen it. The 60-second reconciler consults the same catalog endpoint. This proves a code path that can make a closed door reappear, but does not prove it occurred for the production doors sampled earlier. A simultaneous capture of HikCentral UI status, Artemis catalog status, app API status, and browser snapshot for one affected door remains necessary to identify the production source of stale data.

gabogg commented

2026-09-30 18:48:42 +00:00

Author

Owner

Read-only agm code investigation reviewed locally. Full path: Artemis acsDoorList → sync_doors_async() → SQLite/in-memory doors → get_door_overview().open_longest → HTTP/WebSocket overview → TelemetryEngine._ingestDoors() / _buildSnapshot() → CommandDeckAdapter.renderOpenLongest(). The browser recomputes the ranking from its door cache; it does not render the server open_longest array directly. The previously posted 1 → 0 → 1 stale-overview reproduction is confirmed by a local Node harness. Focused frontend tests pass but do not cover this ordering case.

Additional verified code risks:

door_classifier.classify_door() requires prev_transitions == 0 to classify a long-standing non-utility OPEN reading as SENSORLESS_OPEN. After recorded transitions, that branch cannot classify it sensorless; determine_door_exclusion() can clear a prior AUTO exclusion when category becomes VERIFIED_SENSOR. This may admit unreliable open circuits to the ranking, but requires physical sensor/wiring evidence for each affected door.
The periodic events fetch queries 198914 (opening) only. Reconciliation queries 198915 (closing) only after acsDoorList already reports a closed state. If the catalog keeps reporting OPEN and a close webhook was missed, the event history cannot repair the state under the current logic.
Both regular poll and 60-second reconciliation read only page 1 of acsDoorList; this is a capacity risk, but not the observed installation's immediate cause because the live response contained 115 doors.

Production follow-up: ranked doors sampled after the worker report were VERIFIED_SENSOR with nonzero observed transitions, consistent with the classifier condition but insufficient to prove sensorless wiring. Direct read-only closing-event queries for door IDs 1703 and 45 over the preceding eight hours returned no 198915 records. The HikCentral UI's data source and physical status of these doors remain unverified. Do not treat a relay/status semantic mismatch as established without a simultaneous UI/API capture.

Worker made no project code edits. I independently re-ran the two focused frontend test files successfully. Local backend test rerun was inconclusive because the available pytest command did not complete promptly; the worker reported its focused backend suite passing, but that result has not been independently reproduced here.

Read-only agm code investigation reviewed locally. Full path: Artemis `acsDoorList` → `sync_doors_async()` → SQLite/in-memory doors → `get_door_overview().open_longest` → HTTP/WebSocket overview → `TelemetryEngine._ingestDoors()` / `_buildSnapshot()` → `CommandDeckAdapter.renderOpenLongest()`. The browser recomputes the ranking from its door cache; it does not render the server `open_longest` array directly. The previously posted 1 → 0 → 1 stale-overview reproduction is confirmed by a local Node harness. Focused frontend tests pass but do not cover this ordering case. Additional verified code risks: - `door_classifier.classify_door()` requires `prev_transitions == 0` to classify a long-standing non-utility OPEN reading as `SENSORLESS_OPEN`. After recorded transitions, that branch cannot classify it sensorless; `determine_door_exclusion()` can clear a prior AUTO exclusion when category becomes `VERIFIED_SENSOR`. This may admit unreliable open circuits to the ranking, but requires physical sensor/wiring evidence for each affected door. - The periodic events fetch queries `198914` (opening) only. Reconciliation queries `198915` (closing) only after `acsDoorList` already reports a closed state. If the catalog keeps reporting OPEN and a close webhook was missed, the event history cannot repair the state under the current logic. - Both regular poll and 60-second reconciliation read only page 1 of `acsDoorList`; this is a capacity risk, but not the observed installation's immediate cause because the live response contained 115 doors. Production follow-up: ranked doors sampled after the worker report were `VERIFIED_SENSOR` with nonzero observed transitions, consistent with the classifier condition but insufficient to prove sensorless wiring. Direct read-only closing-event queries for door IDs 1703 and 45 over the preceding eight hours returned no `198915` records. The HikCentral UI's data source and physical status of these doors remain unverified. Do not treat a relay/status semantic mismatch as established without a simultaneous UI/API capture. Worker made no project code edits. I independently re-ran the two focused frontend test files successfully. Local backend test rerun was inconclusive because the available pytest command did not complete promptly; the worker reported its focused backend suite passing, but that result has not been independently reproduced here.

gabogg referenced this issue

2026-10-01 19:30:59 +00:00

fix(doors): investigate doors reported opening twice #198