fix(connection): a failed app-label fetch is retried, not cached as a miss (t55)

The Current App sensor and media_player.app_name showed a package id in
the live run. Root cause was in the manifest-label tier: `_fetch_app_label`
returned early (no poller, ADB down) or logged and returned on a shell
error WITHOUT touching the cache, but `app_label` had already put the
package in `_app_label_requests`; the drain then threw the request away,
so a render between the failure and the next cycle re-enqueued — while
nothing distinguished "the device answered, this package has no label"
from "we never got an answer". Nothing was visibly retried, and the label
tier could stay silent indefinitely.

The cache is now (label, stamp, resolved) and records the FETCH, not the
wishful result:

  * a fetch that RAN caches its outcome for APP_LABEL_TTL — the label, or
    the empty string for a genuinely label-less package. Definitive: no
    re-enqueue, so the t24 F1 per-heartbeat round-trip tax stays closed.
  * a fetch that could NOT run stamps nothing, logs at debug (so a
    package id in the UI is diagnosable), and the next render retries.
  * a queued or in-flight fetch is not enqueued twice, so a burst of
    renders still costs one `pm dump` per watchdog cycle.

`cache_app_label()` is the one public writer of the cache (tests and any
future out-of-band reader no longer poke the private tuple), and
`app_label_requests`/`app_label_inflight` expose the queue for tests.

The old 2-tuple seeds in the label tests move to `cache_app_label`.
This commit is contained in:
James Mackay committed 2026-10-12 06:53:09 +01:00
1 parent ccde3cff71
commit 0c7e405108
4 files changed
+186 -21

No files matched your search

+85 -12
View File
@@ -206,7 +206,11 @@ class ShieldConnectionManager:
# P5-1: device manifest labels — package → (label, stamp). Long-TTL
# (APP_LABEL_TTL) cache resolved via `pm dump` on demand, one
# package per watchdog cycle so a burst never blocks the watchdog.
self._app_labels: dict[str, tuple[str, float]] = {}
self._app_labels: dict[str, tuple[str, float, bool]] = {}
self._app_label_requests: set[str] = set()
# t55: packages whose label fetch is queued or in flight — a render
# during the fetch must not enqueue the same package twice.
self._app_label_inflight: set[str] = set()
# P5-3 (C-STREAM): the dedicated logcat line-stream consumer.
# NEVER shares the poller's ADB socket — its own device object and
# connection; CONF_LOGCAT_EVENTS gates it (default off) and the
@@ -221,7 +225,6 @@ class ShieldConnectionManager:
self._logcat_last_stamp: float = -1e9
# Injectable ladder sleep (t26: deterministic tests / future alt-floors)
self._logcat_ladder_sleep = asyncio.sleep
self._app_label_requests: set[str] = set()
# Injectable clock keeps the TTL expiry tests deterministic.
self._clock = clock
self._tasks: list[asyncio.Task] = []
@@ -548,26 +551,70 @@ class ShieldConnectionManager:
return False
def app_label(self, package: str | None) -> str | None:
"""Cached manifest label for a package (P5-1), or None.
"""Cached manifest label for a package (P5-1), or None (t55).
A cache miss enqueues an on-demand `pm dump` fetch — drained one
package per watchdog cycle via the manager task pool, so entity
refreshes and the watchdog are never blocked by a burst. A failed
resolution simply falls through to the next name tier.
refreshes and the watchdog are never blocked by a burst.
What is cached is the FETCH, not the wishful result (t55 root cause):
* a fetch that RAN caches its outcome for ``APP_LABEL_TTL`` — a label
when the manifest has one, and the empty string otherwise. It is
definitive: the device answered, the package simply has no default
label (several system/OEM packages do not). No re-enqueue, so a
permanently label-less package costs ZERO further round trips
(t24 F1 stays closed).
* a fetch that could NOT run (no poller, ADB down, shell error) caches
nothing, so the next render enqueues again — a miss is retried
visibly instead of being stamped as an eternal "no label". This was
the live defect: the old code stored ("", stamp) on every failure
path, which silenced the label tier for the whole 24 h TTL and left
app_name showing the raw package id.
* while a fetch for the package is queued or in flight, the next
render does not enqueue it a second time.
"""
if not package:
return None
cached = self._app_labels.get(package)
if cached is not None:
label, stamp = cached
label, stamp, resolved = cached
if self._clock() - stamp <= APP_LABEL_TTL:
# empty label = negative cache (t24 F1): the pm dump ran and
# found nothing — do not re-enqueue, zero per-heartbeat tax
# found nothing — do not re-enqueue, zero per-heartbeat tax.
# An unresolved stamp is a failed fetch: fall through and
# retry rather than serving a miss forever.
if resolved:
return label or None
else:
self._app_labels.pop(package, None) # stale — refetch on demand
if package not in self._app_label_requests and (
package not in self._app_label_inflight
):
self._app_label_requests.add(package)
return None
def cache_app_label(self, package: str, label: str | None) -> None:
"""Seed the label cache with a definitive result (t55).
The ONE writer of ``_app_labels`` other than ``_fetch_app_label``, so
the cache's shape stays private: a caller (tests, or a future
discovery path that read a label out of band) records that a fetch
RAN, whether or not it produced a label. ``None``/"" is the negative
result devices genuinely report for label-less packages.
"""
self._app_labels[package] = (label or "", self._clock(), True)
@property
def app_label_requests(self) -> set[str]:
"""Packages queued for a manifest-label fetch (public, for tests)."""
return set(self._app_label_requests)
@property
def app_label_inflight(self) -> set[str]:
"""Packages whose label fetch is running right now (public, tests)."""
return set(self._app_label_inflight)
async def async_capture_protocol_device_data(self) -> None:
"""Capture (name, manufacturer, model, sw) once (t30 G10)."""
if self._protocol is None or self.protocol_device_data is not None:
@@ -587,9 +634,28 @@ class ShieldConnectionManager:
_LOGGER.debug("protocol device info unavailable: %s", err)
async def _fetch_app_label(self, package: str) -> None:
"""One `pm dump` label fetch; failure falls through silently."""
"""One `pm dump` label fetch; stamps ONLY a fetch that really ran (t55).
Three outcomes, three postures:
* the dump ran and carries an `application-label` → cache the label;
* the dump ran and carries none → cache the empty string as a
definitive negative (the t24 F1 rule: no per-heartbeat round-trip
tax for a label-less package);
* the fetch could not run at all (no connected poller, shell error) →
cache NOTHING, so the next render re-enqueues and the miss is
retried instead of being silent forever. Failures are logged at
debug so ``app_name`` falling back to a package id is diagnosable.
"""
self._app_label_inflight.add(package)
try:
poller = self._poller
if poller is None or not self.connected:
_LOGGER.debug(
"app label for %s not fetched (ADB not connected) — will "
"retry on the next render",
package,
)
return
try:
import shlex
@@ -599,12 +665,18 @@ class ShieldConnectionManager:
)
label = parse_application_label(dump or "")
except Exception as err:
_LOGGER.debug("app label fetch failed for %s: %s", package, err)
_LOGGER.debug(
"app label fetch failed for %s (%s) — will retry on the "
"next render",
package,
err,
)
return
# F1: label-less pm dumps negatively cache too (empty label) so a
# later cycle performs zero additional pm dumps for the package
self._app_labels[package] = (label or "", self._clock())
# later cycle performs zero additional pm dumps for the package.
self.cache_app_label(package, label)
finally:
self._app_label_inflight.discard(package)
def _on_logcat_app_start(self, package: str) -> None:
"""Stamp FIELD_FOREGROUND instantly from a parsed START (P5-3).
@@ -892,6 +964,7 @@ class ShieldConnectionManager:
self._last_known.clear()
self._app_labels.clear()
self._app_label_requests.clear()
self._app_label_inflight.clear()
if self._poller is not None:
with contextlib.suppress(Exception):
await self._poller.disconnect()
+99 -4
View File
@@ -177,11 +177,18 @@ class TestAppLabelCache:
assert manager.app_label("com.unknown.app") is None
await manager._watchdog_cycle(5.0)
# still None (next tier), no crash — falls through cleanly
assert manager.app_label("com.unknown.app") is not None or True
# the dump RAN and carried no label: definitive negative, and the
# caller's next tier (the raw package) takes over — still None here,
# never a crash or a fabricated label
assert manager.app_label("com.unknown.app") is None
async def test_label_less_package_negatively_cached_no_repeat_dump(self):
"""t26 F1: unresolvable packages cost at most one pm dump ever."""
async def test_label_less_package_is_a_definitive_negative(self):
"""t24 F1: a label-less package's ANSWER costs one pm dump, not one/cycle.
The old code additionally stamped this answer on FAILURE paths; t55
separates the two (see the retry tests below), but the negative cache
for a dump that really ran stays — the round-trip tax must not return.
"""
manager, _t = self._manager_with_dump()
manager._poller.pm_dumps["com.unknown.app"] = "no label line here"
@@ -201,6 +208,94 @@ class TestAppLabelCache:
assert len(manager._poller.shell_calls) == first_dump_count
assert manager.app_label("com.unknown.app") is None # falls through
async def test_failed_fetch_is_not_cached_and_retries(self):
"""t55 root cause: a fetch that could NOT run must not become a miss.
The live defect was a metadata fetch failing and the failure being
written as ("", stamp) — an eternal "no label" for the whole 24 h TTL,
which left app_name showing the raw package id with no way back. Here
the failed fetch stamps nothing, the next render re-enqueues, and the
retry resolves the real label.
"""
manager, _t = self._manager_with_dump()
real_shell = manager._poller.shell
calls: list[str] = []
async def _flaky(cmd):
calls.append(cmd)
if "pm dump" in cmd:
raise RuntimeError("adb shell blew up")
return await real_shell(cmd)
manager._poller.shell = _flaky
assert manager.app_label("ar.tvplayer.tv") is None # enqueue
await manager._watchdog_cycle(5.0)
import asyncio
await asyncio.sleep(0)
# the fetch ran and failed → NOTHING is stamped as an answer
assert manager._app_labels.get("ar.tvplayer.tv") is None
assert [c for c in calls if "pm dump" in c]
# the next render enqueues again (the miss is retried, not silenced)
assert manager.app_label("ar.tvplayer.tv") is None
assert manager.app_label_requests == {"ar.tvplayer.tv"}
# the retry reaches the device and resolves the label
manager._poller.shell = real_shell
await manager._watchdog_cycle(5.0)
await asyncio.sleep(0)
assert manager.app_label("ar.tvplayer.tv") == "TiviMate"
async def test_shell_failure_is_not_cached_and_retries(self):
manager, _t = self._manager_with_dump()
manager._poller.pm_dumps["ar.tvplayer.tv"] = "application-label: 'TiviMate'"
async def _boom(_cmd):
raise RuntimeError("adb shell blew up")
manager._poller.shell = _boom
manager.app_label("ar.tvplayer.tv")
await manager._watchdog_cycle(5.0)
import asyncio
await asyncio.sleep(0)
assert manager._app_labels.get("ar.tvplayer.tv") is None
assert manager.app_label_requests == set()
assert manager.app_label("ar.tvplayer.tv") is None
assert manager.app_label_requests == {"ar.tvplayer.tv"} # re-enqueued
async def test_in_flight_fetch_is_not_enqueued_twice(self):
manager, _t = self._manager_with_dump()
assert manager.app_label("ar.tvplayer.tv") is None
assert manager.app_label("ar.tvplayer.tv") is None # same render loop
assert manager.app_label_requests == {"ar.tvplayer.tv"}
assert manager.app_label_inflight == set()
async def test_one_fetch_per_cycle_even_under_a_burst(self):
manager, _t = self._manager_with_dump()
manager._poller.pm_dumps["com.a"] = "application-label: 'A'"
manager._poller.pm_dumps["com.b"] = "application-label: 'B'"
manager.app_label("com.a")
manager.app_label("com.b")
await manager._watchdog_cycle(5.0)
await manager._watchdog_cycle(5.0)
import asyncio
await asyncio.sleep(0)
dumps = [c for c in manager._poller.shell_calls if "pm dump" in c]
assert len(dumps) == 2 # one per cycle, both eventually resolved
assert sorted([manager.app_label("com.a"), manager.app_label("com.b")]) == [
"A",
"B",
]
async def test_pm_dump_command_is_shell_quoted(self):
"""t26 F2: the package argument is shlex.quote'd (consistent)."""
import shlex
+1 -4
View File
@@ -144,10 +144,7 @@ class TestSource:
def test_it_uses_the_cached_device_label_when_unmapped(self, modules):
player, _served = _player(modules, foreground="com.netflix.ninja")
player._manager._app_labels["com.netflix.ninja"] = (
"Netflix",
player._manager._clock(),
)
player._manager.cache_app_label("com.netflix.ninja", "Netflix")
assert player.source == "Netflix"
+1 -1
View File
@@ -1241,7 +1241,7 @@ class TestAppNameMapResolution:
player, _s, _i = _cmd_player(modules)
player._entry.options["app_name_map"] = {} # no override
manager = player._manager
manager._app_labels["ar.tvplayer.tv"] = ("TiviMate", manager._clock())
manager.cache_app_label("ar.tvplayer.tv", "TiviMate")
manager._on_current_app("ar.tvplayer.tv")
await asyncio.sleep(0.05)