Skip to content

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

Merged
wshallwshall merged 1 commit into
mainfrom
flake-monitor-spin
Jul 27, 2026
Merged

fix(console): stop the message list livelocking under sustained refresh (BACKLOG #17)#5
wshallwshall merged 1 commit into
mainfrom
flake-monitor-spin

Conversation

@wshallwshall

Copy link
Copy Markdown
Collaborator

Fixes BACKLOG #17 — the flaky test_monitor_observes_engine on Windows CI. It was never a timing flake.

Root cause

MessagesPanel._apply() cleared the in-flight guard, re-fired any refresh latched during the read, and returned before rendering — discarding the snapshot as "superseded":

self._loading = False
if self._drain_pending():
    return              # <-- snapshot thrown away

Whenever a caller refreshes faster than a read completes there is always a latch waiting when the read lands, so every snapshot was discarded and the table never rendered. Permanently stuck, not slow.

Measured with a probe: 391 reads served, 0 rendered, over 20s.

Why the previous two fixes couldn't work

Both assumed a timing flake. No deadline escapes a livelock, so neither 10s → 30s nor reruns=2 could ever have helped.

It passes locally because the engine processes the message before the panel connects, so the single initial refresh() in _build_inner renders it and the polling path never runs at all. A loaded runner lost that race about a third of the time.

The fix

Render first, then drain. Costs at most one read of staleness — the drained refresh re-reads the current filters and renders again immediately, so the list still converges on the latest filter — but it can no longer starve itself.

This is a real GUI defect, not just a test problem: sustained refresh pressure wedges the message list in the harness too.

Tests

  • tests/test_console_messages_refresh.py (new). MessagesPanel had no test file at all, which is how this shipped. A unit form (a latched refresh must not discard the render) and a sustained-pressure form.
  • test_monitor_observes_a_message_that_arrives_after_connect (new). Writes the message after connect so the initial snapshot is empty by construction — exercising the livelocked path deterministically instead of depending on losing a race.
  • _spin now takes one deadline shared across both waits instead of two independent 30s budgets, names the condition, and reports elapsed plus the status label (which carries poll failed: …). Four CI failures produced only condition not met within timeout, identical from either wait, and revealed nothing.
  • reruns=2 removed. It was added for this bug, would now only mask the next one, and makes this fix unmeasurable — a masked failure looks exactly like a working one.

All three new tests were verified to fail against the previous ordering.

Note on what is not evidence

CPU saturation does not reproduce this — the old code passes 3/3 under full-core load. Load stress is not a valid gate for it; the after-connect ordering is. Recording that so it isn't reached for next time.

Local: 300 passed, 15 skipped across the harness/console suites; ruff check/format clean in CI's scope.

🤖 Generated with Claude Code

MessagesPanel._apply cleared the in-flight guard, then re-fired any refresh latched during
the read and returned early, discarding the snapshot as "superseded". Whenever a caller
refreshes faster than a read completes there is ALWAYS a latch waiting when the read lands,
so every snapshot was discarded and the table never rendered -- permanently stuck, not slow.

This is BACKLOG #17, which presented as a flaky harness-monitor test on Windows CI. It was
never a timing flake: the test polls refresh() every 50ms, so once it entered the loop no
deadline could escape it. That is why 10s->30s and reruns=2 both failed. Locally the engine
processes the message before the panel connects, so the single initial refresh in
_build_inner renders it and the polling path is never exercised at all; a loaded runner lost
that race about a third of the time. A 20s probe measured 391 reads served, 0 rendered.

Render first, then drain. Costs at most one read of staleness -- the drained refresh
re-reads the current filters and renders again immediately, so the list still converges on
the latest filter -- but it can no longer starve itself.

Tests:
- tests/test_console_messages_refresh.py, new. MessagesPanel had no test file at all, which
  is how this shipped: a unit form (a latched refresh must not discard the render) and a
  sustained-pressure form.
- test_monitor_observes_a_message_that_arrives_after_connect, new. Writes the message AFTER
  connect so the initial snapshot is empty by construction, exercising the livelocked path
  deterministically rather than depending on losing a race.
- _spin now takes one deadline shared across both waits instead of two independent 30s
  budgets, names the condition, and reports elapsed plus the status label (which carries
  "poll failed: ..."). Four CI failures produced only "condition not met within timeout",
  identical from either wait, and revealed nothing.
- reruns=2 removed. It was added for this bug, would now only mask the next one, and makes
  the fix unmeasurable -- a masked failure looks exactly like a working one.

All three new tests were verified to FAIL against the previous ordering. Note that CPU
saturation does NOT reproduce this (the old code passes 3/3 under full-core load), so load
stress is not a valid gate for it; the after-connect ordering is.
@wshallwshall
wshallwshall enabled auto-merge (squash) July 27, 2026 13:14
@wshallwshall
wshallwshall merged commit cf4a34c into main Jul 27, 2026
30 checks passed
wshallwshall added a commit that referenced this pull request Jul 27, 2026
…, and record the fix

(Subject deliberately avoids the literal "BACKLOG #N" token: the claim gate reads that in a
code-touching commit's SUBJECT as "this commit implements item N" and demands the number be claimed
first. This commit REMOVES a wrong citation rather than implementing anything, so claiming would be
the wrong signal. The body below names the item freely.)

BACKLOG #17 is the py3.11 pytest/aiosqlite cancellation deadlock, closed OBSOLETE at the 3.14-only
migration. It is cited correctly in tee/relay.py, the webconsole conftest and test_smart_backend.py.

It is NOT the harness message-list livelock. A pre-existing comment on the flaky monitor test blamed
"#17" for that, and while fixing the livelock I copied the wrong citation into four more places --
two test docstrings, an assertion message and the push-guard header -- plus the commit messages and PR
bodies that went with them. Anyone following it lands on a closed item about an unrelated bug, which is
a slower and more confusing dead end than no citation at all.

Removed from the livelock sites; each now says plainly what the defect was, and notes what the wrong
citation used to claim so the next person does not re-derive it. The legitimate #17 references are
untouched.

Also records the livelock itself in CHANGELOG 0.3.1, where it shipped: PR #5 merged before the tag was
cut, but no changelog line went with it, so the release notes are silent on a user-visible fix to the
harness message list. Filed under Fixed with the measurement that identified it (391 reads served, 0
rendered) rather than a vague "fixed a refresh bug".

And corrects the push guard's rationale for leaving enforce_admins off. It cited the "known flaky test"
as the reason an admin override must stay available; that failure was a livelock, not a flake, and it
is fixed -- so the argument is weaker now than when it was written. Said so rather than leaving a stale
justification standing for a security-relevant setting.
wshallwshall added a commit that referenced this pull request Jul 27, 2026
…, and record the fix (#16)

(Subject deliberately avoids the literal "BACKLOG #N" token: the claim gate reads that in a
code-touching commit's SUBJECT as "this commit implements item N" and demands the number be claimed
first. This commit REMOVES a wrong citation rather than implementing anything, so claiming would be
the wrong signal. The body below names the item freely.)

BACKLOG #17 is the py3.11 pytest/aiosqlite cancellation deadlock, closed OBSOLETE at the 3.14-only
migration. It is cited correctly in tee/relay.py, the webconsole conftest and test_smart_backend.py.

It is NOT the harness message-list livelock. A pre-existing comment on the flaky monitor test blamed
"#17" for that, and while fixing the livelock I copied the wrong citation into four more places --
two test docstrings, an assertion message and the push-guard header -- plus the commit messages and PR
bodies that went with them. Anyone following it lands on a closed item about an unrelated bug, which is
a slower and more confusing dead end than no citation at all.

Removed from the livelock sites; each now says plainly what the defect was, and notes what the wrong
citation used to claim so the next person does not re-derive it. The legitimate #17 references are
untouched.

Also records the livelock itself in CHANGELOG 0.3.1, where it shipped: PR #5 merged before the tag was
cut, but no changelog line went with it, so the release notes are silent on a user-visible fix to the
harness message list. Filed under Fixed with the measurement that identified it (391 reads served, 0
rendered) rather than a vague "fixed a refresh bug".

And corrects the push guard's rationale for leaving enforce_admins off. It cited the "known flaky test"
as the reason an admin override must stay available; that failure was a livelock, not a flake, and it
is fixed -- so the argument is weaker now than when it was written. Said so rather than leaving a stale
justification standing for a security-relevant setting.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant