From b67818d5c5d2a63e32d84b488c3fdceb58386f27 Mon Sep 17 00:00:00 2001 From: Chuck <33324927+ChuckBuilds@users.noreply.github.com> Date: Thu, 24 Sep 2026 14:26:04 -0400 Subject: [PATCH] feat(perf): LEDMATRIX_STALL_WATCHDOG_MS lowers the stall watchdog's threshold 250ms catches freezes; the hitches left on hdpi are frames 2-5 refreshes late, which look like the render thread waiting for the GIL. At 30ms the watchdog dumps those too, naming what the other threads were running when the frame missed. It polls at a third of the threshold so a stall one poll long is still seen, which costs some GIL time of its own: a diagnostic setting, not one to soak with. Co-Authored-By: Claude Opus 5.5 --- docs/SCROLL_PERFORMANCE.md | 9 +++++++++ src/common/frame_timing.py | 24 ++++++++++++++++++++++-- test/test_frame_timing.py | 20 ++++++++++++++++++++ 3 files changed, 51 insertions(+), 2 deletions(-) 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.