From a9027e2264472f9ca9e9e1fb63cf8e434cd18e6d Mon Sep 17 00:00:00 2001 From: tcconnally Date: Tue, 14 Jul 2026 20:54:34 -0500 Subject: [PATCH] =?UTF-8?q?feat(playback):=20freeze=20visibility=20+=20cac?= =?UTF-8?q?he-resume=20tuning=20=E2=80=94=20close=20the=20instrumentation?= =?UTF-8?q?=20blind=20spot?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Owner keeps seeing freezes that every counter calls clean. They're right: paused-for-cache episodes (network starvation — greg TCP resets, slow opens) are invisible to the frame-drop counters AND shorter than the 20s stall watchdog. The hour bench logged 5 connection resets that 'recovered' — each one on a young clip is a visible freeze nothing counted. - paused-for-cache is now observed per cell (bare-emit observer per the CLAUDE.md rules): every episode shows a pulsing BUFFERING card on the cell (a freeze now explains itself instead of looking broken), logs a WARNING with measured duration + cache-buffering-state, and rides the stats dump as freezes / freeze_seconds per cell — benches now quantify the exact thing the owner experiences. - cache-pause-wait=3: mpv resumes only with 3s of buffer in hand, so a starvation is one slightly-longer pause instead of a resume/starve flicker loop (probed: accepted + read back). - Track changes bank an open freeze episode (no cross-track leakage). - Seek cap 0.90 → 0.98: the property-driven EOF advance made the clip tail safe; 10% of every video was unreachable for no remaining reason. - Buffering card replaces stale title/loading cards (test-caught: it deferred to them initially). tests/test_freeze_visibility.py pins: episode counting + card lifecycle, startup-fill exclusion, stale-generation guard, track-change banking, and the 0.98 cap. CLAUDE.md gains the freeze-triage rule. Version 10.11.0. Co-Authored-By: Claude Fable 5 --- CLAUDE.md | 10 +++ hyperwall/__init__.py | 2 +- hyperwall/cell.py | 86 ++++++++++++++++++-- hyperwall/constants.py | 7 ++ hyperwall/wall.py | 5 +- tests/run_all.py | 1 + tests/run_repo_guards.py | 4 +- tests/test_freeze_visibility.py | 134 ++++++++++++++++++++++++++++++++ 8 files changed, 237 insertions(+), 12 deletions(-) create mode 100644 tests/test_freeze_visibility.py diff --git a/CLAUDE.md b/CLAUDE.md index fc5b0f3..1f1914a 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -93,6 +93,16 @@ check the rule. Before claiming one of these is fixed, run the probe. clears `_parked` so the next failure runs the retry chain (it used to be swallowed by the parked-guard). The parked card is sticky (no auto-fade). +## Freeze visibility + +- The freeze class users actually see is **paused-for-cache** (network + starvation): invisible to the frame-drop counters and shorter than the + 20s stall watchdog. It is observed per-cell (BUFFERING card + WARNING + log with duration + freezes/freeze_seconds in the stats dump). If a + freeze report arrives with clean drop counters, check the FREEZE lines + first. `cache-pause-wait=3` makes mpv resume only with 3s of buffer — + one longer pause instead of a freeze-flicker loop. + ## Process / repo - The exe at repo root is the **shortcut artifact** and G-Sync isolation diff --git a/hyperwall/__init__.py b/hyperwall/__init__.py index 7aac5f5..c0893bb 100644 --- a/hyperwall/__init__.py +++ b/hyperwall/__init__.py @@ -7,7 +7,7 @@ from __future__ import annotations -__version__ = "10.10.0" +__version__ = "10.11.0" # Short "major.minor" form, derived — used for User-Agent / Emby auth Version / # window titles so a version bump touches exactly ONE line (this file). VERSION_SHORT = ".".join(__version__.split(".")[:2]) diff --git a/hyperwall/cell.py b/hyperwall/cell.py index 79f698a..2d53401 100644 --- a/hyperwall/cell.py +++ b/hyperwall/cell.py @@ -200,6 +200,7 @@ class VideoCell(QWidget): request_prev = pyqtSignal(object) _sig_eof = pyqtSignal(int, str) _sig_track_done = pyqtSignal(int) + _sig_buffering = pyqtSignal(int, bool) def __init__(self, controller: Any): super().__init__() @@ -221,6 +222,13 @@ def __init__(self, controller: Any): self._play_pos = 0.0 self._dragging = False self._paused_before_seek = False + # Freeze visibility: paused-for-cache episodes (network starvation). + # These freezes are invisible to the frame-drop counters AND shorter + # than the 20s stall watchdog — the gap the owner kept seeing. + self._freeze_t0 = 0.0 + self._freeze_count = 0 + self._freeze_total_s = 0.0 + self._buffering_card = False self._retry_count = 0 self._force_transcode = False self._played_anything = False @@ -321,6 +329,9 @@ def __init__(self, controller: Any): self._sig_track_done.connect( self._handle_track_done, Qt.ConnectionType.QueuedConnection ) + self._sig_buffering.connect( + self._handle_buffering, Qt.ConnectionType.QueuedConnection + ) # Stall watchdog: polls for silent freezes (frozen frame / wedged # decoder / network hang that survives reconnect) which never emit an @@ -413,6 +424,13 @@ def _on_eof_reached(_name: str, value: Any) -> None: if value is True and gen == self._mpv_gen: self._sig_track_done.emit(gen) + # Freeze visibility: mpv pauses itself when the demuxer cache + # starves (network stall/reset). Bare emit per the observer rules. + @m.property_observer("paused-for-cache") + def _on_pfc(_name: str, value: Any) -> None: + if value is not None and gen == self._mpv_gen: + self._sig_buffering.emit(gen, bool(value)) + @m.property_observer("time-pos") def _on_time(_name: str, value: float | None) -> None: if value is None or gen != self._mpv_gen: @@ -619,6 +637,7 @@ def _begin_track(self, item: dict[str, Any]) -> None: # The LOADING pulse / error card used to be dismissed by the title # card that popped on every track change; with that chrome gone the # overlay must be dropped explicitly when a new track starts. + self._close_open_freeze() self._hide_overlay() def _hide_overlay(self) -> None: @@ -963,17 +982,16 @@ def _show_title_overlay(self, title: str, sticky: bool = False) -> None: if not sticky: self._overlay_show_timer.start(OVERLAY_SHOW_MS) - def _show_loading(self) -> None: - """Show a pulsing 'LOADING' card until the first frame arrives. - - Unlike the title card this does not auto-fade — it stays (pulsing) - until play() swaps in the real title, so a slow-loading cell still - reads as busy rather than blank. + def _show_loading(self, text: str = "LOADING") -> None: + """Show a pulsing status card (LOADING at startup, BUFFERING during + a cache starvation). Does not auto-fade — it stays (pulsing) until + the condition clears, so a stalled cell reads as busy-with-reason + rather than silently frozen. """ self._overlay_show_timer.stop() self._overlay_anim.stop() self._title_overlay.setStyleSheet(_LOADING_STYLE) - self._title_overlay.setText("LOADING") + self._title_overlay.setText(text) self._title_overlay.adjustSize() self._reposition_overlay() self._title_overlay.show() @@ -1036,7 +1054,10 @@ def _seek_press(self) -> None: def _seek_release(self) -> None: if self._mpv is not None and self._duration_s > 0: try: - frac = min(self.seek_slider.value() / 1000.0, 0.90) + # 0.98, not 0.90: the property-driven EOF advance makes the + # clip tail safe to seek into; 10% of every video was + # unreachable for no remaining reason. + frac = min(self.seek_slider.value() / 1000.0, 0.98) target = frac * self._duration_s self._mpv.seek(target, "absolute") # Restore the PRE-DRAG pause state instead of always @@ -1204,6 +1225,55 @@ def _toggle_fav(self) -> None: # ── EOF / error handling ────────────────────────────────────────────── + def _handle_buffering(self, gen: int, buffering: bool) -> None: + """GUI-thread side of the paused-for-cache observer. + + Turns invisible network-starvation freezes into: a pulsing + BUFFERING card on the cell, a WARNING log with the measured + duration, and per-cell counters that ride the stats dump. + """ + if gen != self._mpv_gen or self._mpv is None: + return + if buffering: + if not self._played_anything: + return # startup fill, not a mid-playback freeze + if self._freeze_t0 == 0.0: + self._freeze_t0 = _time.monotonic() + self._freeze_count += 1 + # Replace whatever card is up (stale title / loading): during a + # freeze the buffering state is the most relevant thing on the + # cell. Parked/error cells never reach here (not playing). + self._buffering_card = True + self._show_loading("BUFFERING") + else: + if self._freeze_t0: + dur = _time.monotonic() - self._freeze_t0 + self._freeze_total_s += dur + self._freeze_t0 = 0.0 + try: + state = self._mpv.cache_buffering_state + except Exception: + state = "?" + logger.warning( + "FREEZE: %.1fs cache starvation on '%s' " + "(buffering-state=%s)", dur, + (self.current_item or {}).get("Name", "?"), state, + ) + if self._buffering_card: + self._buffering_card = False + self._hide_overlay() + + def _close_open_freeze(self) -> None: + """Bank a freeze still open when the track changes underneath it.""" + if self._freeze_t0: + dur = _time.monotonic() - self._freeze_t0 + self._freeze_total_s += dur + self._freeze_t0 = 0.0 + logger.warning( + "FREEZE: %.1fs cache starvation (ended by track change)", dur, + ) + self._buffering_card = False + @traced("cell._handle_track_done") def _handle_track_done(self, gen: int) -> None: """A track finished naturally (eof-reached flipped True). diff --git a/hyperwall/constants.py b/hyperwall/constants.py index 4333cc2..923bf38 100644 --- a/hyperwall/constants.py +++ b/hyperwall/constants.py @@ -139,6 +139,13 @@ def _int_env(name: str, default: int, lo: int, hi: int) -> int: interpolation="no", target_colorspace_hint="yes", cache="yes", + # Resume only with 3s of buffer in hand: after a cache starvation + # (network reset/stall) mpv otherwise resumes the instant one frame is + # available and immediately starves again — a freeze-flicker loop. One + # slightly longer pause beats three visible stutters (probed: option + # accepted + read back). + cache_pause="yes", + cache_pause_wait=3, cache_secs=60, demuxer_max_bytes="1024MiB", demuxer_readahead_secs=60, diff --git a/hyperwall/wall.py b/hyperwall/wall.py index 7df984f..27c9d9a 100644 --- a/hyperwall/wall.py +++ b/hyperwall/wall.py @@ -593,6 +593,8 @@ def _dump_stats_json(self) -> None: "cell": i, "totals": dict(c._stats_total), "info": {k: v for k, v in c._stats_info.items()}, + "freezes": c._freeze_count, + "freeze_seconds": round(c._freeze_total_s, 1), "last_item": (c.current_item or {}).get("Name"), }) payload = { @@ -625,12 +627,13 @@ def _dump_stats_json(self) -> None: i = s["info"] logger.info( "STATS cell %d drop=%g mistimed=%g vo-delayed=%g " - "dec-drop=%g hwdec=%s fps=%s bitrate=%s", + "dec-drop=%g freezes=%d(%ss) hwdec=%s fps=%s bitrate=%s", s["cell"], t.get("frame-drop-count", 0), t.get("mistimed-frame-count", 0), t.get("vo-delayed-frame-count", 0), t.get("decoder-frame-drop-count", 0), + s["freezes"], s["freeze_seconds"], i.get("hwdec-current"), i.get("estimated-vf-fps") or i.get("container-fps"), i.get("video-bitrate"), diff --git a/tests/run_all.py b/tests/run_all.py index 1055596..7425e1d 100644 --- a/tests/run_all.py +++ b/tests/run_all.py @@ -30,6 +30,7 @@ "test_instrumentation", "test_mute_volume", "test_audit_regressions", + "test_freeze_visibility", ] diff --git a/tests/run_repo_guards.py b/tests/run_repo_guards.py index 47ec3f4..7c076e2 100644 --- a/tests/run_repo_guards.py +++ b/tests/run_repo_guards.py @@ -46,10 +46,10 @@ def test_01_entry_point_imports(): def test_02_package_identity(): """Package has version and banner.""" from hyperwall import __version__, runtime_banner - assert __version__ == "10.10.0" + assert __version__ == "10.11.0" banner = runtime_banner() assert "Hyperwall" in banner - assert "10.10.0" in banner + assert "10.11.0" in banner def test_03_config_loads(): diff --git a/tests/test_freeze_visibility.py b/tests/test_freeze_visibility.py new file mode 100644 index 0000000..e3227db --- /dev/null +++ b/tests/test_freeze_visibility.py @@ -0,0 +1,134 @@ +"""Freeze-visibility regression tests (v10.11.0). + +paused-for-cache episodes (network starvation) are the freeze class the +frame-drop counters can't see and the 20s stall watchdog is too slow for — +the gap behind every 'it still freezes sometimes' report. These pin the +detection layer: counters, WARNING logs, BUFFERING card, stats surfacing. +""" +import os +import sys + +sys.path.insert(0, os.path.dirname(os.path.dirname(os.path.abspath(__file__)))) +os.environ.setdefault("QT_QPA_PLATFORM", "offscreen") + +try: + from PyQt6.QtWidgets import QApplication + _app = QApplication.instance() or QApplication([]) + _PYQT = os.name == "nt" +except ImportError: + _PYQT = False + + +class _FakeMpv: + def __init__(self): + self.props = {"mute": True, "volume": 100.0, "aid": "no", + "pause": False, "time-pos": 12.0, "eof-reached": False, + "cache-buffering-state": 42} + self.seek_calls = [] + + def __setitem__(self, k, v): + self.props[k] = v + + def __getitem__(self, k): + return self.props[k] + + def __getattr__(self, name): + key = name.replace("_", "-") + if key in self.props: + return self.props[key] + raise AttributeError(name) + + def seek(self, target, mode="absolute"): + self.seek_calls.append((target, mode)) + + def command(self, *a): + pass + + +class _Ctl: + controls_visible = True + + +def _make_cell(): + from hyperwall.cell import VideoCell + cell = VideoCell(_Ctl()) + cell.resize(1280, 720) + cell.show() + _app.processEvents() + cell._mpv = _FakeMpv() + cell._duration_s = 100.0 + cell._played_anything = True + return cell + + +def test_buffering_episode_counts_and_shows_card(): + cell = _make_cell() + gen = cell._mpv_gen + cell._handle_buffering(gen, True) + assert cell._freeze_count == 1 + assert cell._buffering_card is True + assert cell._title_overlay.isVisible() + assert "BUFFERING" in cell._title_overlay.text() + cell._handle_buffering(gen, False) + assert cell._freeze_total_s >= 0.0 + assert cell._freeze_t0 == 0.0 + assert cell._buffering_card is False + assert not cell._title_overlay.isVisible() + + +def test_startup_fill_is_not_a_freeze(): + cell = _make_cell() + cell._played_anything = False + cell._handle_buffering(cell._mpv_gen, True) + assert cell._freeze_count == 0 + assert cell._buffering_card is False + + +def test_stale_generation_buffering_ignored(): + cell = _make_cell() + cell._handle_buffering(cell._mpv_gen - 1, True) + assert cell._freeze_count == 0 + + +def test_track_change_closes_open_freeze(): + cell = _make_cell() + gen = cell._mpv_gen + cell._handle_buffering(gen, True) + assert cell._freeze_t0 > 0 + cell._begin_track({"Id": "x", "Name": "n"}) + assert cell._freeze_t0 == 0.0 + assert cell._freeze_total_s >= 0.0 + assert cell._buffering_card is False + + +def test_seek_cap_is_98_percent(): + cell = _make_cell() + cell.seek_slider.setSliderDown(True) + cell.seek_slider.setValue(1000) # drag to the very end + cell.seek_slider.setSliderDown(False) + assert cell._mpv.seek_calls, "seek must fire" + target, _mode = cell._mpv.seek_calls[-1] + assert abs(target - 98.0) < 0.01, f"expected 98.0 (0.98 cap), got {target}" + + +def run_all() -> int: + if not _PYQT: + print(" SKIP PyQt6/Windows unavailable — freeze tests run on the " + "windows-build job.") + return 0 + tests = [v for k, v in sorted(globals().items()) if k.startswith("test_")] + passed = failed = 0 + for t in tests: + try: + t() + passed += 1 + print(f" PASS {t.__name__}") + except Exception as e: # noqa: BLE001 + failed += 1 + print(f" FAIL {t.__name__}: {e}") + print(f"\n{passed} passed, {failed} failed out of {len(tests)} tests.") + return failed + + +if __name__ == "__main__": + raise SystemExit(1 if run_all() else 0)