feat(scroll): report a panel that cannot reach its refresh cap, and suggest one it can hold

CHANGELOG.md

@@ -19,6 +19,25 @@ accepts both, but the store flags the old spelling as deprecated
 
 ## Unreleased
 
+### Scroll speed: a panel slower than its refresh cap is reported
+
+- Scroll speeds are solved against `limit_refresh_rate_hz`, so a panel that
+  cannot reach its cap ran every scroll slow by the shortfall, with no sign
+  why (one Pi 4 on a 120 Hz cap refreshed at ~110 Hz: 60 px/s ran at 55).
+  Once the display has measured the real rate over three windows of
+  scrolling, a panel more than 3% short of the cap is logged once, as a
+  warning from `src.common.frame_timing` that names a cap it can hold (a
+  multiple of 10, 5% under the measurement). The Display tab shows the same
+  under Limit Refresh Rate, with a button that fills it in, from the new
+  `GET /api/v3/config/refresh-rate`. Not checked in the emulator or on the
+  fallback canvas.
+- The frame-stats file records `planned_refresh_hz` (additive), and the
+  scroll-speed advice behind the Vegas slider ignores a measurement written
+  under a different cap. Until now, after the cap changed, the slider kept
+  advising from the old rate until the display restarted.
+- New in `src.common.scroll_config`: `refresh_shortfall()`, `holdable_cap()`
+  and `describe_refresh_shortfall()`.
+
 ### Fixed
 
 - The web preview and `/api/v3/display/current` no longer stay black for a

docs/SCROLL_PERFORMANCE.md

@@ -77,6 +77,31 @@ The Vegas **Scroll Speed** slider in the web UI shows the same thing live: a
 line under it says what your speed will run as on this panel, and links to the
 nearest smooth speeds.
 
+### A panel that cannot reach its cap
+
+Speeds are solved against `limit_refresh_rate_hz`, the configured cap, but a
+cap is only a ceiling: a long chain, a high `pwm_bits` or a big
+`gpio_slowdown` can leave the panel below it. One Pi 4 driving 2×128×64 on
+`adafruit-hat-pwm` with `pwm_bits 9` and `gpio_slowdown 5` measured
+107.6–113.1 Hz under a 120 Hz cap. Frames still move whole pixels, but
+every scroll runs that much slower than configured (60 px/s ran at 55 px/s),
+and the smooth speeds are the cap's rather than the panel's.
+
+The display measures the real rate from its own frames. About a minute
+into scrolling, a panel more than 3% short of its cap is logged once:
+
+```
+WARNING - src.common.frame_timing - The panel refreshes at about 113 Hz, below
+the 120 Hz that scroll speeds are planned for ... Set Limit Refresh Rate to
+100 Hz (web UI, Display tab), which this panel can hold, and restart.
+```
+
+The Display tab says the same under **Limit Refresh Rate**, with a button
+that fills in the suggested cap (`GET /api/v3/config/refresh-rate`). The
+suggestion is a multiple of 10 at least 5% under the measurement, because
+an uncapped panel drifts and the measurement is the fast end of it. A cap the
+panel holds also stops the drift.
+
 ### How a slow speed stays crisp
 
 `SwapOnVSync(canvas, framerate_fraction)` holds each frame for N panel

src/common/frame_timing.py

@@ -135,6 +135,8 @@
 import traceback
 from typing import Any, Callable, Dict, List, Optional, Tuple, TypedDict
 
+from src.common import scroll_config
+
 logger = logging.getLogger(__name__)
 
 #: Bumped when a field changes meaning, so a reader can refuse stale files.
@@ -179,6 +181,12 @@
 #: trusted -- about a second of scrolling.
 MIN_FRAMES_FOR_REFRESH = 90
 
+#: Trusted windows, counting the one that adopted the period, before a panel
+#: slower than its cap is reported. The estimate can still fall (the refresh
+#: rate rise) by up to MAX_REFRESH_DROP per window early on; the warning
+#: should not name a rate one more window would have corrected.
+REFRESH_CHECK_WINDOWS = 3
+
 FLUSH_INTERVAL = 10.0
 
 #: A scroll's last frame older than this is a stall worth a stack dump.
@@ -441,6 +449,12 @@ def __init__(
             1.0 / refresh_hz if refresh_hz and refresh_hz > 0 else None)
         # The first estimate, until a second window agrees with it.
         self._refresh_candidate: Optional[float] = None
+        # The rate scroll speeds are solved against; see plan_refresh().
+        self.planned_refresh_hz: Optional[float] = None
+        # Trusted windows seen since the period was adopted, until the
+        # shortfall check has run.
+        self._refresh_windows = 0
+        self._shortfall_checked = True
         self.totals: Dict[str, Any] = {
             "static_frames": 0,
             "scroll_frames": 0,
@@ -639,7 +653,12 @@ def aggregate(self, batch: List[_Frame], static: int) -> None:
                     self._refresh_candidate = estimate
             elif current * (1.0 - MAX_REFRESH_DROP) <= estimate < current:
                 self.refresh_period = estimate
+            if self.refresh_period is not None:
+                self._refresh_windows += 1
         period = self.refresh_period
+        if (period and not self._shortfall_checked
+                and self._refresh_windows >= REFRESH_CHECK_WINDOWS):
+            self._check_refresh_shortfall(1.0 / period)
 
         histograms = self.histograms
         for frame in batch:
@@ -688,6 +707,25 @@ def aggregate(self, batch: List[_Frame], static: int) -> None:
                 elif missed <= -1:
                     totals["early_frames"] += 1
 
+    def plan_refresh(self, hz: Optional[float]) -> None:
+        """Say what rate scroll speeds are solved against, before frames arrive.
+
+        ``DisplayManager.refresh_hz``: the configured cap. Once the measured
+        rate has held for :data:`REFRESH_CHECK_WINDOWS` windows, a panel that
+        falls short of it is logged once, with a cap it can hold (see
+        :func:`src.common.scroll_config.refresh_shortfall`). The display
+        manager calls this only for a real panel.
+        """
+        self.planned_refresh_hz = hz
+        self._shortfall_checked = not hz
+
+    def _check_refresh_shortfall(self, measured_hz: float) -> None:
+        """Log, once, a panel that cannot reach the rate speeds assume."""
+        self._shortfall_checked = True
+        shortfall = scroll_config.refresh_shortfall(measured_hz, self.planned_refresh_hz)
+        if shortfall:
+            logger.warning(scroll_config.describe_refresh_shortfall(shortfall))
+
     def snapshot(self) -> Dict[str, Any]:
         """The JSON document: cumulative since this process started."""
         if not self._binding_checked:
@@ -704,6 +742,9 @@ def snapshot(self) -> Dict[str, Any]:
             "bucket_ms": BUCKET_MS,
             "freeze_seconds": FREEZE_SECONDS,
             "measured_refresh_hz": round(1.0 / period, 2) if period else None,
+            # Additive: what scroll speeds were solved against, so a reader can
+            # tell a stale file (written under another cap) from this one.
+            "planned_refresh_hz": self.planned_refresh_hz,
             "binding_releases_gil": self._binding_gil,
             "info": info,
             "totals": copy.deepcopy(self.totals),

src/common/scroll_config.py

@@ -538,3 +538,66 @@ def as_dict(c: CrispSpeed) -> Dict[str, Any]:
         "smooth": smooth,
         "alternatives": [as_dict(c) for c in alternatives],
     }
+
+
+#: A measured refresh this far below the rate speeds are planned for means
+#: the panel cannot reach its cap. Smaller gaps are the cap's own slack and
+#: the estimate's: one rig measured 99.95 Hz under a 100 Hz cap.
+REFRESH_SHORTFALL = 0.03
+
+#: How far under the measured rate a suggested cap sits. The measurement is
+#: the fast end of the panel's refreshes (frame_timing takes the 10th
+#: percentile of intervals), and an uncapped panel drifts: one read
+#: 107.6-113.1 Hz over 15 seconds. A cap inside that band would not hold.
+CAP_HEADROOM = 0.05
+
+
+def holdable_cap(measured_hz: Any) -> Optional[int]:
+    """A refresh cap the panel can hold: a multiple of 10, 5% under what it measured.
+
+    A multiple of 10 because its whole-pixel speeds are round numbers (a
+    100 Hz cap gives 50 and 100 px/s). None without a usable measurement, or
+    when the panel is too slow for any cap of 10 Hz or more.
+    """
+    hz = _coerce(measured_hz)
+    if hz is None:
+        return None
+    cap = int(hz * (1.0 - CAP_HEADROOM) // 10) * 10
+    return cap if cap >= 10 else None
+
+
+def refresh_shortfall(measured_hz: Any, planned_hz: Any) -> Optional[Dict[str, Any]]:
+    """When the panel refreshes measurably slower than speeds are planned for.
+
+    ``planned_hz`` is what :func:`configure` solves against -- the
+    ``limit_refresh_rate_hz`` cap, or :data:`DEFAULT_REFRESH_HZ` when it is 0.
+    A panel that cannot reach it still moves whole pixels per frame, but every
+    speed runs slow by the shortfall and the ladder of smooth speeds is the
+    cap's, not the panel's. None when there is no measurement, or the panel
+    reaches the cap (or beats it, as some do by a few Hz).
+    """
+    measured, planned = _coerce(measured_hz), _coerce(planned_hz)
+    if measured is None or planned is None:
+        return None
+    if measured >= planned * (1.0 - REFRESH_SHORTFALL):
+        return None
+    return {
+        "measured_hz": round(measured, 1),
+        "planned_hz": round(planned, 1),
+        "suggested_cap_hz": holdable_cap(measured),
+        "slow_percent": round((1.0 - measured / planned) * 100),
+    }
+
+
+def describe_refresh_shortfall(shortfall: Dict[str, Any]) -> str:
+    """One log line for :func:`refresh_shortfall`'s answer."""
+    text = (
+        f"The panel refreshes at about {shortfall['measured_hz']:.0f} Hz, below "
+        f"the {shortfall['planned_hz']:.0f} Hz that scroll speeds are planned "
+        f"for (display.hardware.limit_refresh_rate_hz), so every scroll runs "
+        f"about {shortfall['slow_percent']}% slower than configured and the "
+        f"smooth speeds are worked out for a rate this panel never reaches.")
+    if shortfall.get("suggested_cap_hz"):
+        text += (f" Set Limit Refresh Rate to {shortfall['suggested_cap_hz']} Hz "
+                 f"(web UI, Display tab), which this panel can hold, and restart.")
+    return text

src/display_manager.py

@@ -393,6 +393,11 @@ def __init__(self, config: Dict[str, Any] = None, force_fallback: bool = False,
 
         self._setup_matrix()
         logger.info("Matrix setup completed in %.3f seconds", time.time() - start_time)
+        # Only a real panel's swaps wait on its refresh: the emulator and the
+        # fallback canvas pace themselves, so "slower than the cap" would be
+        # noise there.
+        if self.matrix is not None and os.environ.get('EMULATOR', 'false') != 'true':
+            self.frame_timing.plan_refresh(self.refresh_hz)
         self._setup_scan_order_compensation()
 
         font_time = time.time()
@@ -1501,7 +1506,9 @@ def refresh_hz(self) -> float:
         fractional-pixel motion. See src/common/scroll_config.py.
 
         Note this is the configured *cap*, not necessarily what the panel
-        achieves -- scripts/scroll_speeds.py --measure reports the real rate.
+        achieves -- scripts/scroll_speeds.py --measure reports the real rate,
+        and the frame-timing recorder logs a warning, with a cap the panel can
+        hold, once it has measured a panel that falls short of this.
         """
         hardware = (self.config.get('display') or {}).get('hardware') or {}
         try:

test/fixtures/api_v3_url_map.json

@@ -175,6 +175,15 @@
       "POST"
     ]
   ],
+  [
+    "/api/v3/config/refresh-rate",
+    "api_v3.get_refresh_rate",
+    [
+      "GET",
+      "HEAD",
+      "OPTIONS"
+    ]
+  ],
   [
     "/api/v3/config/schedule",
     "api_v3.get_schedule_config",

test/test_frame_timing.py

@@ -807,3 +807,54 @@ def test_a_process_with_the_gc_monitor_exits_cleanly():
     assert proc.returncode == 0, proc.stderr
     assert "Exception ignored" not in proc.stderr
     assert "installed at exit: False" in proc.stdout
+
+
+SLOW = 1 / 110.0  # a panel that cannot reach a 120 Hz cap
+
+
+def _windows(recorder, n, interval, start=0.0):
+    for i in range(n):
+        _feed(recorder, [interval] * 200, start=start + 50.0 * i)
+        _aggregate(recorder)
+
+
+def _shortfall_warnings(caplog):
+    return [r for r in caplog.records
+            if r.name == "src.common.frame_timing" and "Limit Refresh Rate" in r.getMessage()]
+
+
+def test_a_panel_slower_than_its_cap_is_reported_once(tmp_path, caplog):
+    r = _recorder(tmp_path)
+    r.plan_refresh(120.0)
+    caplog.set_level("WARNING")
+    _windows(r, 3, SLOW)          # adopted on the 2nd window, checked on the 4th
+    assert _shortfall_warnings(caplog) == []
+    _windows(r, 3, SLOW, start=1000.0)
+    warnings = _shortfall_warnings(caplog)
+    assert len(warnings) == 1
+    assert "about 110 Hz" in warnings[0].getMessage()
+    assert "to 100 Hz" in warnings[0].getMessage()
+
+
+def test_a_panel_that_reaches_its_cap_is_not_reported(tmp_path, caplog):
+    r = _recorder(tmp_path)
+    r.plan_refresh(100.0)
+    caplog.set_level("WARNING")
+    _windows(r, 6, PERIOD)
+    assert _shortfall_warnings(caplog) == []
+
+
+def test_without_a_planned_rate_nothing_is_checked(tmp_path, caplog):
+    # The emulator and the fallback canvas: DisplayManager never calls
+    # plan_refresh(), since their frames are not paced by a panel.
+    r = _recorder(tmp_path)
+    caplog.set_level("WARNING")
+    _windows(r, 6, SLOW)
+    assert _shortfall_warnings(caplog) == []
+
+
+def test_the_snapshot_records_the_planned_rate(tmp_path):
+    r = _recorder(tmp_path)
+    assert r.snapshot()["planned_refresh_hz"] is None
+    r.plan_refresh(120.0)
+    assert r.snapshot()["planned_refresh_hz"] == 120.0

test/test_scroll_config.py

@@ -21,6 +21,7 @@
     refresh_hz_from_config,
     resolve,
 )
+from src.common import scroll_config  # noqa: E402
 
 
 class FakeHelper:
@@ -504,3 +505,46 @@ def test_a_measured_rate_does_not_let_a_stepped_speed_through(self):
         got = solve_crisp(50, 125.74)
         assert got.steppiness == "smooth"
         assert got.pixels_per_frame == 1
+
+
+class TestRefreshShortfall:
+    """A panel that cannot reach its cap runs every scroll slow."""
+
+    def test_the_ledmatrix_rig_is_told_to_cap_at_100(self):
+        # Pi 4, 2x128x64 on adafruit-hat-pwm under a 120 Hz cap: measured
+        # 107.6-113.1 Hz, and frame_timing reports the fast end.
+        s = scroll_config.refresh_shortfall(113.1, 120)
+        assert s == {"measured_hz": 113.1, "planned_hz": 120.0,
+                     "suggested_cap_hz": 100, "slow_percent": 6}
+
+    def test_a_panel_that_holds_its_cap_is_fine(self):
+        assert scroll_config.refresh_shortfall(99.95, 100) is None
+        assert scroll_config.refresh_shortfall(97.5, 100) is None
+
+    def test_a_panel_that_beats_its_cap_is_fine(self):
+        assert scroll_config.refresh_shortfall(125.7, 120) is None
+
+    def test_nothing_measured_says_nothing(self):
+        assert scroll_config.refresh_shortfall(None, 120) is None
+        assert scroll_config.refresh_shortfall(0, 120) is None
+        assert scroll_config.refresh_shortfall("fast", 120) is None
+
+    def test_the_suggestion_leaves_headroom_under_the_measurement(self):
+        assert scroll_config.holdable_cap(113.1) == 100
+        assert scroll_config.holdable_cap(95.0) == 90
+        # 5% under 105 is 99.75: 100 would sit inside the panel's drift.
+        assert scroll_config.holdable_cap(105.0) == 90
+        assert scroll_config.holdable_cap(9.0) is None
+        assert scroll_config.holdable_cap(None) is None
+
+    def test_the_log_line_names_the_cap_to_use(self):
+        text = scroll_config.describe_refresh_shortfall(
+            scroll_config.refresh_shortfall(113.1, 120))
+        assert "about 113 Hz" in text and "120 Hz" in text
+        assert "6% slower" in text
+        assert "Set Limit Refresh Rate to 100 Hz" in text
+
+    def test_no_suggestion_for_a_panel_too_slow_for_any_cap(self):
+        text = scroll_config.describe_refresh_shortfall(
+            scroll_config.refresh_shortfall(9.0, 100))
+        assert "Set Limit Refresh Rate" not in text