fix(console): stop the message list livelocking under sustained refresh (BACKLOG #17)

harness/_console_widgets.py

@@ -44,12 +44,11 @@
     QWidget,
 )
 
+from harness._async import AsyncRunner
 from messagefoundry.api.models import MessageDetail, MessageSummary
 from messagefoundry.apiclient import ApiError, EngineClient
 from messagefoundry.parsing import HL7PeekError, parse_tree
 
-from harness._async import AsyncRunner
-
 #: Shared "error red" for inline error text — the message-detail error, the auth dialogs'
 #: error labels, and the heart's stopped state — so the palette can't drift across modules.
 #: Carried over from the retired console theme so there is a single source of truth for this colour.
@@ -506,12 +505,9 @@ def _fetch(
     def _apply(self, snap: _MessagesSnapshot, *, autosize: bool = False) -> None:
         """Runs on the main thread (result slot) — safe to touch widgets."""
         self._loading = False
-        # A refresh was requested mid-flight (e.g. the filter changed) — re-fire it and skip rendering
-        # this now-superseded snapshot, so the list always reflects the latest filter.
-        if self._drain_pending():
-            return
         if snap.error is not None:
             self.error.emit(snap.error)
+            self._drain_pending()
             return
         messages = snap.messages
         assert messages is not None
@@ -541,6 +537,14 @@ def _apply(self, snap: _MessagesSnapshot, *, autosize: bool = False) -> None:
             # The selected message rolled off the list (deleted / filtered / aged past the 200-row
             # limit); tell the detail pane to clear so it stops showing a now-absent message (M2).
             self.selection_cleared.emit()
+        # LAST, and only after rendering: re-fire a refresh that was latched while this one was in
+        # flight. This used to run FIRST and `return` early, discarding the snapshot as "superseded"
+        # — which livelocked the panel (BACKLOG #17). Under sustained refresh pressure there is ALWAYS
+        # a latched request when a fetch lands, so every snapshot was discarded and the table never
+        # updated: not slow, permanently stuck. Rendering first costs at most one fetch of staleness
+        # (the drained refresh re-reads the current filters and renders again immediately), and the
+        # list still converges on the latest filter — but it can no longer starve itself.
+        self._drain_pending()
 
     def _on_select(self) -> None:
         message_id = self._selected_id()

tests/test_console_messages_refresh.py

@@ -0,0 +1,103 @@
+# SPDX-License-Identifier: AGPL-3.0-or-later
+# Copyright (C) 2026 MessageFoundry Organization and contributors
+"""MessagesPanel refresh convergence — the BACKLOG #17 livelock.
+
+``refresh()`` reads the message list off the main thread and guards against pile-up with ``_loading``;
+a refresh requested mid-flight is latched in ``_pending`` and re-fired when the read lands. ``_apply``
+used to drain that latch FIRST and ``return`` early, discarding the snapshot as "superseded".
+
+That is a livelock, not an optimisation. Whenever a caller refreshes faster than a fetch completes
+there is ALWAYS a latched request when the fetch lands, so EVERY snapshot was discarded and the table
+never rendered — permanently, not slowly. It surfaced as a flaky harness-monitor test on loaded CI
+runners (which lose the race the local machine wins), but the same wedge is reachable in the real GUI.
+
+These tests would both fail against the old ordering.
+"""
+
+from __future__ import annotations
+
+import time
+from types import SimpleNamespace
+from typing import Any
+
+import pytest
+
+pytest.importorskip("PySide6")
+
+from harness._console_widgets import MessagesPanel, _MessagesSnapshot  # noqa: E402
+
+
+@pytest.fixture(scope="module")
+def qapp() -> Any:
+    from PySide6.QtWidgets import QApplication
+
+    return QApplication.instance() or QApplication([])
+
+
+def _msg(mid: str) -> Any:
+    return SimpleNamespace(
+        id=mid,
+        received_at=1_780_000_000.0,
+        channel_id="ch",
+        event="ADT^A01",
+        message_type="ADT",
+        status="delivered",
+        control_id=mid,
+        summary="",
+        metadata="",
+    )
+
+
+class _FakeClient:
+    """Only the surface MessagesPanel._fetch touches. ``delay`` makes the read slower than the caller's
+    refresh cadence, which is precisely the condition that used to wedge the panel."""
+
+    def __init__(self, *, delay: float = 0.0) -> None:
+        self._delay = delay
+        self.calls = 0
+
+    def list_messages(self, **_kw: Any) -> Any:
+        self.calls += 1
+        if self._delay:
+            time.sleep(self._delay)
+        return SimpleNamespace(messages=[_msg("m1")], total=1)
+
+    def search_messages(self, **_kw: Any) -> Any:  # pragma: no cover - no filters are set here
+        raise AssertionError("content search should not be reached without a content/field filter")
+
+
+def test_a_latched_refresh_no_longer_discards_the_snapshot(qapp: Any) -> None:
+    """The unit form: _apply must RENDER even when another refresh is already latched behind it."""
+    panel = MessagesPanel(_FakeClient())  # type: ignore[arg-type]
+    try:
+        panel._loading = True  # a read is in flight...
+        panel._pending = False  # ...and a second refresh was latched behind it
+        panel._apply(_MessagesSnapshot([_msg("m1")], "1 shown of 1", False, None))
+
+        assert panel._table.rowCount() == 1, (
+            "snapshot discarded as 'superseded' — this is the BACKLOG #17 livelock"
+        )
+        # Dropping the render must not come back as dropping the re-fire either.
+        assert panel._pending is None, "the latched refresh was never drained"
+    finally:
+        panel.stop()
+
+
+def test_sustained_refresh_pressure_still_converges(qapp: Any) -> None:
+    """The integration form, and the shape the harness-monitor test actually hits: a caller polling
+    refresh() faster than the read completes. Every _apply lands with a latch set, so under the old
+    ordering the table stayed empty forever and this loop ran to its deadline."""
+    panel = MessagesPanel(_FakeClient(delay=0.05))  # type: ignore[arg-type]
+    deadline = time.time() + 15
+    try:
+        while panel._table.rowCount() == 0 and time.time() < deadline:
+            panel.refresh()  # 5ms cadence vs a 50ms read — always latches
+            qapp.processEvents()
+            time.sleep(0.005)
+
+        assert panel._table.rowCount() > 0, (
+            f"table never rendered in 15s under sustained refresh (livelock); "
+            f"the fake engine served {panel._client.calls} reads, every one discarded"  # type: ignore[attr-defined]
+        )
+    finally:
+        panel.stop()

tests/test_harness_monitor.py

@@ -88,18 +88,29 @@ def qapp() -> Any:
     return QApplication.instance() or QApplication([])
 
 
-def _spin(qapp: Any, predicate: Any, timeout: float = 30.0) -> None:
-    # 30s (was 10s): the predicate just needs the off-thread poller + file-poll + engine
-    # processing + API round-trips + a Qt event-loop turn to complete. That's a few seconds
-    # locally, but a loaded Windows CI runner intermittently overran 10s — a timing flake
-    # (BACKLOG #17), not a real failure. The generous deadline only ever extends a SLOW pass;
-    # a genuine hang still fails fast (predicate never true) well within the per-test watchdog.
-    deadline = time.time() + timeout
+def _spin(qapp: Any, predicate: Any, what: str, deadline: float, context: Any = None) -> None:
+    """Pump the Qt event loop until ``predicate()`` holds, or the SHARED ``deadline`` passes.
+
+    Takes an absolute deadline rather than a per-call timeout because this test makes two sequential
+    waits, and two independent budgets fail where one shared budget would not: a first wait that eats
+    25s of its own 30s allowance still hands the second a full fresh 30s, so the pair can blow the
+    watchdog with most of it unspent — while a single budget simply absorbs the slow stage.
+
+    ``what`` names the condition and ``context`` (called only on failure) reports live panel state,
+    including the status label — which carries ``poll failed: …`` when the background poller is
+    erroring. Both waits used to raise the same bare "condition not met within timeout", so four CI
+    failures never revealed which stage stalled, and the diagnosis had to start from nothing.
+    """
+    start = time.time()
     while not predicate():
+        if time.time() > deadline:
+            detail = f" | {context()}" if context is not None else ""
+            raise AssertionError(
+                f"{what}: still false after {time.time() - start:.1f}s "
+                f"(shared budget exhausted){detail}"
+            )
         qapp.processEvents()
         time.sleep(0.05)
-        if time.time() > deadline:
-            raise AssertionError("condition not met within timeout")
 
 
 def test_poller_cancel_abandons_remaining_calls(qapp: Any) -> None:
@@ -148,14 +159,16 @@ def test_monitor_panel_builds_disconnected(qapp: Any) -> None:
     panel.shutdown()  # safe to call when never connected
 
 
-# Override the global 60s per-test watchdog: this test makes two sequential _spin waits (30s each
-# worst case) plus fixture/engine startup, so a slow-but-passing CI run could otherwise brush the
-# 60s cap. 120s keeps an ample backstop without the watchdog itself becoming the flake.
-# In-run auto-retry for the residual timing flake (BACKLOG #17): even with the 30s _spin + 120s
-# watchdog, a heavily-loaded Windows runner still intermittently overran the _spin deadline. reruns=2
-# lets a single flake occurrence self-heal within the SAME CI run (up to 3 attempts) instead of reding
-# the matrix and blocking the auto-merge pipeline; a genuine break still fails all attempts.
-@pytest.mark.flaky(reruns=2)
+# Override the global 60s per-test watchdog: the two waits share a 60s budget, and fixture/engine
+# startup sits outside it, so a slow-but-passing CI run could otherwise brush the 60s cap.
+#
+# NO reruns=2 here any more, deliberately. It was added to let BACKLOG #17 "self-heal" within a run,
+# on the theory that this was a residual timing flake on loaded Windows runners. It was not: the
+# message list was livelocking (MessagesPanel._apply discarded every snapshot as superseded while this
+# test polled refresh() at 50ms — see tests/test_console_messages_refresh.py), which is why neither
+# 10s→30s nor the reruns ever fixed it. That is now fixed at the source. Keeping the retry would only
+# hide the next real defect the same way it hid this one, and would make the fix unmeasurable — a
+# masked failure looks exactly like a working one.
 @pytest.mark.timeout(120)
 def test_monitor_observes_engine(qapp: Any, server: tuple[str, Path]) -> None:
     url, inbox = server
@@ -164,17 +177,62 @@ def test_monitor_observes_engine(qapp: Any, server: tuple[str, Path]) -> None:
     panel = MonitorPanel()
     panel._url.setText(url)
     panel._connect_btn.click()  # connects (auth disabled) and starts the off-thread poller
+    deadline = time.time() + 60  # ONE budget spanning both waits, not 30s each
     try:
         assert panel._client is not None
+
+        def ctx() -> str:
+            """Failure-path only. The status label carries 'poll failed: …' when the background
+            poller is erroring, which is otherwise invisible to this test."""
+            return f"live_rows={_live_rows(panel)} status={panel._status.text()!r}"
+
         # The poller runs on its own thread; processEvents() delivers its queued snapshot.
-        _spin(qapp, lambda: _live_rows(panel) > 0)
+        _spin(
+            qapp, lambda: _live_rows(panel) > 0, "live connections table populated", deadline, ctx
+        )
         # The reused message list shows the delivered message with a disposition.
-        _spin(qapp, lambda: _has_message(panel, qapp))
+        _spin(qapp, lambda: _has_message(panel, qapp), "delivered message in list", deadline, ctx)
     finally:
         panel.shutdown()
     assert panel._client is None
 
 
+@pytest.mark.timeout(120)
+def test_monitor_observes_a_message_that_arrives_after_connect(
+    qapp: Any, server: tuple[str, Path]
+) -> None:
+    """The deterministic form of what CI kept hitting, and the reason BACKLOG #17 looked like a flake.
+
+    The sibling test writes the message BEFORE the panel connects, so the single initial ``refresh()``
+    in ``_build_inner`` normally renders it and the polling path below is never exercised at all. That
+    race is the whole difference between local and CI: a fast machine wins it every time, a loaded
+    runner lost it about a third of the time and then hit a livelock no timeout could escape.
+
+    Connecting first makes the initial snapshot empty by construction, so the message can ONLY appear
+    via the 50ms ``refresh()`` polling — exercising the path that used to discard every snapshot.
+    """
+    url, inbox = server
+    panel = MonitorPanel()
+    panel._url.setText(url)
+    panel._connect_btn.click()
+    (inbox / "a.hl7").write_bytes(
+        ADT.encode("utf-8")
+    )  # only AFTER the initial refresh has gone out
+
+    deadline = time.time() + 60
+    try:
+        assert panel._client is not None
+        _spin(
+            qapp,
+            lambda: _has_message(panel, qapp),
+            "message arriving after connect appears in list",
+            deadline,
+            lambda: f"status={panel._status.text()!r}",
+        )
+    finally:
+        panel.shutdown()
+
+
 def _live_rows(panel: MonitorPanel) -> int:
     return panel._live_table.rowCount() if panel._live_table is not None else 0