fix(transport): no stale protocol error, no connect task outliving its entry, honest banners (t20)

The t19 review's findings on the protocol transport, all of them closed here.

O1 (MEDIUM, FIRST). `_note_protocol_state(PROTOCOL_CONNECTED, None)` only assigned
`last_error` when its argument was non-None, so a failure kept being published
after the transport recovered: the review measured
`protocol_last_error == "connect: Net: boom"` beside `protocol_connected: true` —
a contradiction on the exact attributes the diagnostic surface was built for, so
the user could not answer "is the protocol working?" without a device test.

The pair now has ONE stated meaning, in the code that owns it and in the remote's
attribute docs: `protocol_state`/`protocol_connected` is the transport's CURRENT
condition, and `protocol_last_error` is the failure the current state has NOT
recovered from. A session becoming proven CLEARS it — and a session becomes proven
in BOTH places that can prove one, so the connect success and the transport's own
availability push now take the same route (the push previously assigned the state
directly and would have left the stale error again). `protocol_failures` keeps
counting, so a recovery stays visible as history rather than as a stale message.
A failure that happens AFTER the session came up is still kept: that one is
current, not stale, and a test pins that distinction so a future "just clear it
everywhere" refactor cannot make failures invisible.

O4 + O5 (the lifecycle leaks, now real tests instead of observations). The connect
attempt was never in the manager's task collection, so `async_stop` never cancelled
it — a reconnect loop could outlive its entry, and since every options save reloads
the entry those loops could accumulate across saves. `async_stop` also only
SCHEDULED its cancellations. The attempt is now tracked, `async_stop` cancels AND
awaits every tracked task, and the stop path refuses to start anything new. A
double start is deterministic instead of orphaning the first: a live attempt is
reused, an already-handed-over session (connected or disconnected — the library's
keep_reconnecting owns it) starts nothing, and only a FINISHED attempt that never
got a session may be replaced. The guard sits before the push callbacks are
registered, so a second start cannot double-register them either.

O2 (LOW). The connect banner claimed liveliness a successful `async_connect()`
cannot know. It now says exactly what it proved (the client accepted a session)
and hands liveness to what can actually report it (the transport's own
availability push). STALE is defined where the fixes live: a banner is stale when a
later state change never followed it up, so the log's last word contradicts the
entity. Every transition therefore announces itself with both states — INFO for
the two a user acts on, DEBUG otherwise — which is what makes the last transport
line always match the published state.

O3 (LOW). The drift floors now carry an explicit MARGIN POLICY instead of leaving
a 2-margin unexplained: a floor is a vacuity-and-blindness alarm, not a size
ratchet (it must fail when the walk stops COVERING something, not when a
legitimate change removes code). Owner-counters keep a 2 margin (the project's own
t62 canary, now stated once), statement_blocks moves to a ~2% band (28 blocks —
the t19 complaint was that a 23-statement refactor could trip it), relative_imports
~2.5%, and the awaited-calls floor is called out plainly as the weakest one because
a percentage margin on six sites is meaningless. The rule for changing any floor is
written down with it. The walk is now 1648 blocks, so the floor is re-derived:
1615.

EVIDENCE THAT THE TESTS PIN THE FIX (not merely pass): the same test file was run
against the PRE-fix source (`git archive HEAD`, a throwaway copy under /tmp) and 13
of the 15 new tests FAIL there. The two that pass pre-fix are the deliberate
anti-overcorrection pins: a failure that is still current keeps its message, and a
terminal (auth-rejected) attempt may still be replaced.

No regressions: 889 passed / 5 skipped, 890 / 4 with androidtvremote2, the real-HA
pattern (3 files) 74 passed with no skips, ruff clean, drift exit 0.

NOT VERIFIED HERE: no real Shield and no paired device, so no real TLS session,
certificate or push was ever received — the connect path runs against doubles plus
the installed library's real source, and the *timing* of a cancellation during a
live handshake is inferred from the awaited-cancel path, not observed on hardware.
This commit is contained in:
James Mackay committed 2026-10-12 13:08:54 +01:00
1 parent 66846b2f82
commit 6b866019ef
5 files changed
+543 -11

No files matched your search

+343
View File
@@ -23,6 +23,7 @@ from nsh.connection import (
FIELD_RUNNING_APPS,
FIELD_SESSIONS,
FIELD_VOLUME_INFO,
PROTOCOL_CONNECTED,
ShieldConnectionManager,
StateStore,
volume_tuple,
@@ -740,3 +741,345 @@ class TestVolumeTuple:
androidtvremote2 = pytest.importorskip("androidtvremote2")
info = androidtvremote2.VolumeInfo(level=3, max=15, muted=True)
assert volume_tuple(info) == (3.0, 15.0, True)
# ── t20: the t19 review's protocol findings ──
class HangingProtocolClient(FakeProtocolClient):
"""``async_connect()`` that never returns until the test says so (t20).
The lifecycle findings are about what happens WHILE an attempt is in flight,
so the fake has to be able to sit inside ``async_connect``: it parks on an
event, records how many times it was cancelled, and only then - if it is ever
released - becomes a session.
"""
def __init__(self):
super().__init__()
self.entered = asyncio.Event()
self.release = asyncio.Event()
self.cancelled = 0
async def async_connect(self):
self.connect_calls += 1
self.entered.set()
try:
await self.release.wait()
except asyncio.CancelledError:
self.cancelled += 1
raise
self._remote_message_protocol = object()
class OnceFailingProtocolClient(FakeProtocolClient):
"""Fails its first attempts, then connects - the RECOVERY sequence (t20/O1)."""
def __init__(self, failures: int = 1, error: Exception | None = None):
super().__init__()
self._failures_left = failures
self._error = error or CannotConnect("Net: boom")
async def async_connect(self):
self.connect_calls += 1
if self._failures_left > 0:
self._failures_left -= 1
raise self._error
self._remote_message_protocol = object()
class TestRecoveredErrorsAreNotStale:
"""t20/O1: the published pair can never contradict itself.
``protocol_state``/``protocol_connected`` is the transport's CURRENT
condition; ``protocol_last_error`` is the failure the CURRENT state has not
recovered from. It is cleared whenever a session becomes proven and kept while
the transport is still down (and, deliberately, kept for a failure that
happened AFTER the session came up - that one is current, not stale).
"""
async def test_failure_then_recovery_publishes_no_stale_error(self):
"""The measured defect: 'connect: Net: boom' beside connected: true."""
client = OnceFailingProtocolClient()
manager = _protocol_manager(client)
_fast_backoff(manager)
await manager._start_protocol()
for _ in range(200): # the failure is recorded while it is still down
if manager.protocol_last_error:
break
await asyncio.sleep(0.005)
assert manager.protocol_state == "never_connected"
assert manager.protocol_connected is False
assert "CannotConnect" in (manager.protocol_last_error or "")
for _ in range(400): # the retry succeeds
if manager.protocol_connected:
break
await asyncio.sleep(0.005)
assert manager.protocol_connected is True
assert manager.protocol_last_error is None, (
"a recovered failure must not be published beside connected: true"
)
assert manager.protocol_failures == 0, "a connect failure is not a SEND failure"
await manager.async_stop()
async def test_failure_then_still_disconnected_keeps_the_error(self):
"""The other direction: a failure that still describes the transport stays."""
client = FakeProtocolClient(connect_error=CannotConnect("Net: boom"))
manager = _protocol_manager(client)
manager._jitter = lambda delay: 60.0 # one attempt, then sleep past the test
await manager._start_protocol()
await _connect(manager, client)
assert manager.protocol_state == "never_connected"
assert manager.protocol_connected is False
assert "Net: boom" in (manager.protocol_last_error or "")
await manager.async_stop()
async def test_a_send_failure_before_a_session_is_cleared_by_the_connect(self):
"""The review's exact sequence, driven through public calls."""
client = FakeProtocolClient()
manager = _protocol_manager(client)
assert await manager.send_protocol_key("POWER") is False # no session yet
assert manager.protocol_last_error, "the current failure is recorded"
await manager._start_protocol()
await _connect(manager, client)
assert manager.protocol_connected is True
assert manager.protocol_last_error is None, "recovery clears it"
assert manager.protocol_failures == 1, "history stays in the counter"
await manager.async_stop()
async def test_an_availability_push_also_clears_a_recovered_error(self):
"""A push is the OTHER proof of a live session, so it clears it too."""
client = FakeProtocolClient(connect_error=CannotConnect("Net: boom"))
manager = _protocol_manager(client)
manager._jitter = lambda delay: 60.0 # the retry cannot race this assertion
await manager._start_protocol()
await _connect(manager, client)
assert manager.protocol_last_error
client.push_is_available(True)
await _drain_loop()
assert manager.protocol_state == "connected"
assert manager.protocol_last_error is None
await manager.async_stop()
async def test_a_send_failure_after_the_session_came_up_is_current(self):
"""Not the same thing as stale: the session failed just now."""
client = FakeProtocolClient()
manager = _protocol_manager(client)
await manager._start_protocol()
await _connect(manager, client)
assert manager.protocol_last_error is None
client._remote_message_protocol = None # the session is gone
assert await manager.send_protocol_key("POWER") is False
assert "POWER" in (manager.protocol_last_error or "")
# ...and a session proven again clears it
client._remote_message_protocol = object()
client.push_is_available(True)
await _drain_loop()
assert manager.protocol_last_error is None
await manager.async_stop()
async def test_recovery_notifies_listeners_because_a_published_value_changed(self):
"""The error is an attribute: clearing it is a state change to publish."""
manager = _protocol_manager(FakeProtocolClient())
notified = []
manager.register_listener(lambda: notified.append(manager.protocol_last_error))
await manager.send_protocol_key("POWER") # records an error
assert manager.protocol_last_error
before = len(notified)
manager._note_protocol_state(PROTOCOL_CONNECTED, None)
assert len(notified) > before, "listeners were told the error went away"
assert manager.protocol_last_error is None
class TestConnectAttemptLifecycle:
"""t20/O4 + O5: the connect attempt is tracked, and a second start is defined.
Both findings interact with the options UI: every save reloads the entry, so an
attempt that survives its entry (or a start that orphans an earlier one) can
accumulate reconnect loops across saves.
"""
async def test_unload_during_a_connect_attempt_cancels_and_awaits_it(self):
"""The proof for O4: no live task, and no further connect attempts."""
client = HangingProtocolClient()
manager = _protocol_manager(client)
_fast_backoff(manager)
await manager._start_protocol()
await asyncio.wait_for(client.entered.wait(), 1)
task = manager._protocol_connect_task
assert task is not None and not task.done()
assert task in manager._tasks, "tracked, so unload can cancel it (O4)"
assert client.connect_calls == 1
await manager.async_stop()
assert task.done(), "the unload AWAITED the attempt"
assert task.cancelled()
assert client.cancelled == 1, "the in-flight connect was cancelled"
assert manager._tasks == [], "nothing is left to leak into the next reload"
calls = client.connect_calls
for _ in range(20):
await asyncio.sleep(0.01)
assert client.connect_calls == calls, "no attempt survives the entry"
async def test_async_start_tracks_every_loop_and_stop_reaps_them(self):
client = HangingProtocolClient()
manager = _protocol_manager(client)
_fast_backoff(manager)
await manager.async_start() # the watchdog (passive here) + the connect
await asyncio.wait_for(client.entered.wait(), 1)
tracked = list(manager._tasks)
assert len(tracked) == 2, [t.get_name() for t in tracked]
await manager.async_stop()
assert manager._tasks == []
assert all(task.done() for task in tracked), "both were awaited"
async def test_a_second_start_reuses_the_live_attempt(self):
"""The proof for O5: starting twice leaves exactly ONE live attempt."""
client = HangingProtocolClient()
manager = _protocol_manager(client)
await manager._start_protocol()
await asyncio.wait_for(client.entered.wait(), 1)
first = manager._protocol_connect_task
await manager._start_protocol()
assert manager._protocol_connect_task is first, "reused, never orphaned"
assert client.connect_calls == 1, "exactly one attempt was made"
assert [t for t in manager._tasks if not t.done()] == [first]
assert manager._tasks.count(first) == 1, "registered once, not once per start"
assert client._is_on_callbacks == [manager._on_is_on], (
"the push callbacks are not registered twice either"
)
await manager.async_stop()
async def test_a_second_start_after_a_session_does_not_build_a_second_loop(self):
"""The library owns the session; a second keep_reconnecting would be a leak."""
client = FakeProtocolClient()
manager = _protocol_manager(client)
await manager._start_protocol()
await _connect(manager, client)
first = manager._protocol_connect_task
assert manager.protocol_connected is True
await manager._start_protocol()
assert manager._protocol_connect_task is first
assert client.connect_calls == 1
assert client.keep_reconnecting_calls == 1, "one owner for the session"
await manager.async_stop()
async def test_a_second_start_after_a_terminal_failure_tries_again(self):
"""Deterministic in BOTH directions: a finished attempt may be replaced."""
client = FakeProtocolClient(connect_error=InvalidAuth("Need to pair"))
manager = _protocol_manager(client, invalid_auth_callback=lambda: None)
await manager._start_protocol()
await _connect(manager, client)
first = manager._protocol_connect_task
assert first.done(), "the auth path is terminal: the loop returned"
assert manager.protocol_state == "auth_rejected"
await manager._start_protocol()
assert manager._protocol_connect_task is not first, "a FRESH attempt replaces it"
for _ in range(200): # the fresh task needs a turn to make its attempt
if client.connect_calls == 2:
break
await asyncio.sleep(0.005)
assert client.connect_calls == 2, "a restart really retries"
await manager.async_stop()
async def test_a_stopped_manager_is_not_restarted_by_a_late_call(self):
client = FakeProtocolClient()
manager = _protocol_manager(client)
await manager.async_stop()
await manager._start_protocol()
assert manager._protocol_connect_task is None
assert manager._tasks == []
class TestTransportBannersAreNotStale:
"""t20/O2: define stale, then make it impossible.
A STALE banner is one whose transport claim a later state change never followed
up on, so the log's last word contradicts the entity. The rules that remove it:
the affirmative banner states only what the attempt proved, and EVERY state
change announces itself with both the old and the new state.
"""
@staticmethod
def _state_lines(records):
return [r for r in records if "transport state:" in r.getMessage()]
async def test_the_connected_banner_claims_no_liveliness(self, caplog):
client = FakeProtocolClient()
manager = _protocol_manager(client)
with caplog.at_level("INFO"):
await manager._start_protocol()
await _connect(manager, client)
opened = [r for r in caplog.records if "session opened" in r.getMessage()]
assert opened, "connecting is announced"
text = opened[0].getMessage()
assert "what this proves" in text, "it names its own limit"
assert "availability push" in text, "and who maintains the session from there"
assert "paired" not in text.lower(), "a connect attempt cannot prove pairing"
lines = self._state_lines(caplog.records)
assert lines, "the transition is announced"
assert lines[-1].getMessage().endswith(manager.protocol_state)
await manager.async_stop()
async def test_a_later_state_change_announces_itself(self, caplog):
client = FakeProtocolClient()
manager = _protocol_manager(client)
await manager._start_protocol()
await _connect(manager, client)
with caplog.at_level("INFO"):
client.push_is_available(False) # the device reports the session down
await _drain_loop()
lines = self._state_lines(caplog.records)
assert lines, "a session going down is announced"
assert lines[-1].getMessage().endswith("disconnected")
assert manager.protocol_state == "disconnected", "the banner matches the entity"
await manager.async_stop()
async def test_the_open_banner_and_the_transition_agree(self, caplog):
"""No two lines about the same moment may name different states."""
client = FakeProtocolClient()
manager = _protocol_manager(client)
with caplog.at_level("INFO"):
await manager._start_protocol()
await _connect(manager, client)
opened = [r for r in caplog.records if "session opened" in r.getMessage()]
lines = self._state_lines(caplog.records)
assert opened and lines
assert "connected" in opened[0].getMessage()
assert lines[-1].getMessage().endswith("connected")
await manager.async_stop()