diff --git a/docs/SCROLL_PERFORMANCE.md b/docs/SCROLL_PERFORMANCE.md index 904191df..67788396 100644 --- a/docs/SCROLL_PERFORMANCE.md +++ b/docs/SCROLL_PERFORMANCE.md @@ -349,6 +349,15 @@ A soak is only meaningful against a fixed workload. Compare runs with the same content and `--preview` setting, and alternate which build goes first when you A/B two of them. A live-API workload drifts over time. +The soak says how often; the service's log says why. A scroll that presents no +frame for 250 ms logs `Render stall:` with the stack of the render thread and +the top of every other thread's, and whether the whole interpreter was blocked +(C code holding the GIL) rather than one thread. To see what is behind the +shorter hitches, run the service with `LEDMATRIX_STALL_WATCHDOG_MS=30`, which +dumps at three refreshes late instead: its extra polling costs a little GIL +time of its own, so do that on a diagnostic run, not a soak you are grading. +`LEDMATRIX_STALL_WATCHDOG=0` turns it off. + ### Results: hdpi, 2026-09-24 Pi 4, 4×128×64 on one chain (512×64), `gpio_slowdown` 3, cap 120 Hz, the diff --git a/src/common/frame_timing.py b/src/common/frame_timing.py index 3e94b6fe..2c151f3a 100644 --- a/src/common/frame_timing.py +++ b/src/common/frame_timing.py @@ -62,7 +62,10 @@ top of every other thread's, so the log names what the render thread was waiting on. It also measures how late its own wake-up was: if the watchdog was held up as long as the render thread, the whole interpreter was blocked (C code holding the GIL, or the process not scheduled), not one thread on a lock. -Set ``LEDMATRIX_STALL_WATCHDOG=0`` to turn it off. +Set ``LEDMATRIX_STALL_WATCHDOG=0`` to turn it off, or +``LEDMATRIX_STALL_WATCHDOG_MS`` to dump at a lower threshold -- 30 catches +frames three refreshes late, which is where GIL contention shows. It polls +three times per threshold, so keep it to diagnostic runs, not soaks. """ from __future__ import annotations @@ -283,7 +286,7 @@ class FrameTimingRecorder: self._static_frames += 1 elif self.watchdog is None and self.scrolling_now is not None \ and os.environ.get("LEDMATRIX_STALL_WATCHDOG", "1") != "0": - self.watchdog = StallWatchdog(self) + self.watchdog = StallWatchdog(self, **watchdog_settings()) self.watchdog.start() elif previous is not None and previous[1]: interval = presented_at - previous[0] @@ -417,6 +420,23 @@ class FrameTimingRecorder: raise +def watchdog_settings() -> Dict[str, float]: + """StallWatchdog arguments from ``LEDMATRIX_STALL_WATCHDOG_MS``, if set. + + The poll comes down with the threshold, or a stall shorter than one poll + would go unseen. + """ + try: + ms = float(os.environ.get("LEDMATRIX_STALL_WATCHDOG_MS") or 0) + except ValueError: + ms = 0.0 + if ms <= 0: + return {} + threshold = ms / 1000.0 + return {"threshold": threshold, + "poll": min(WATCHDOG_POLL_SECONDS, threshold / 3)} + + class StallWatchdog: """Log what the render thread is doing when a scroll stops presenting. diff --git a/test/test_frame_timing.py b/test/test_frame_timing.py index 274bf029..c2f27b62 100644 --- a/test/test_frame_timing.py +++ b/test/test_frame_timing.py @@ -9,6 +9,8 @@ import sys import time from pathlib import Path +import pytest + sys.path.insert(0, str(Path(__file__).resolve().parent.parent)) from src.common import frame_timing # noqa: E402 @@ -303,6 +305,24 @@ def test_watchdog_rate_limits_its_dumps(caplog): assert dog.stalls == 2 +def test_watchdog_threshold_can_be_lowered_for_a_diagnostic_run(monkeypatch): + monkeypatch.delenv("LEDMATRIX_STALL_WATCHDOG_MS", raising=False) + assert frame_timing.watchdog_settings() == {} + monkeypatch.setenv("LEDMATRIX_STALL_WATCHDOG_MS", "nonsense") + assert frame_timing.watchdog_settings() == {} + monkeypatch.setenv("LEDMATRIX_STALL_WATCHDOG_MS", "30") + settings = frame_timing.watchdog_settings() + assert settings["threshold"] == pytest.approx(0.030) + assert settings["poll"] == pytest.approx(0.010) # sees a stall one poll long + + # ...and the recorder starts its watchdog with them. + rec = frame_timing.FrameTimingRecorder(path=None) + rec.scrolling_now = lambda: True + monkeypatch.setattr(frame_timing.StallWatchdog, "start", lambda self: None) + rec.record(0.001, 0.009, 1, True, 1.0) + assert rec.watchdog.threshold == pytest.approx(0.030) + + # --- measuring the panel, and runs that never locked ------------------------- # The refresh measurement and the "not locked" cases came from the first # version of scripts/render_bench.py, which graded runs with its own module.