fix(perf): count a stall even when the scroll state went missing across it

On hdpi the stall watchdog logged a 1.9s stall during the hourly sports
refresh that the soak report never had: its worst gap was 655ms. The frame
that ended the stall was recorded as static, so its interval was dropped.

"Scrolling" is DisplayManager's scroll state at the moment a frame is
presented, and it goes missing mid-scroll: it expires after 2s without
activity, and any thread can clear it. Plugins call
set_scrolling_state(False) from their own display() (news, stocks, the odds
ticker's fallback), and Vegas captures some of those on the render thread
between two of its own frames. Vegas sets the state again only after its
next frame, so that frame is recorded as static -- along with the capture
or stall it followed.

One static frame between two scrolling frames, with the scroll resuming
within RESUME_SECONDS (1s), is now a frame of the scroll and both of its
intervals count, the first at the scroll's own hold (clearing the state
drops the hold to 1 too). Two static frames in a row still end the scroll.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>

docs/SCROLL_PERFORMANCE.md

@@ -334,7 +334,7 @@ service's user.
 | line | what it tells you |
 |---|---|
 | **Late frames** | Frames presented one or more refreshes after they were due: the panel showed the previous frame again, a visible hitch. **The pass/fail number**, 0.1% by default (`--max-late-pct`). Only intervals between two scrolling frames count, and a frame held for `frame_hold` refreshes is due `frame_hold` refreshes after the last. |
-| **Freezes** | Gaps of 250 ms or more inside a scroll: recomposes, plugin handovers, blocking calls on the render thread. Reported but not failed on, because some are handovers between plugins rather than faults. |
+| **Freezes** | Gaps of 250 ms or more inside a scroll: recomposes, plugin handovers, blocking calls on the render thread. Reported but not failed on, because some are handovers between plugins rather than faults. A gap still counts when the display's scroll state went missing across it (it expires after 2 s, and plugins clear it from their own `display()`), as long as the scroll carries on straight after. |
 | **blit** | Copying the frame into the matrix canvas (`SetImage`). It grows with width × height × `pwm_bits`: ~5.5 ms at 512×64 with 8 bits on a Pi 4. It is the biggest fixed cost, and it sets the refresh rates a rig can hold one pixel per refresh at. |
 | **wait** | Time blocked in `SwapOnVSync`, i.e. the slack left in each refresh. A p50 near zero means the rig has no headroom and anything extra lands a frame late. |
 | **work** | Everything else between two frames: drawing, scrolling, and waiting for the GIL. A wide gap between its p50 and p99 is another thread getting in the way. |

src/common/frame_timing.py

@@ -19,6 +19,19 @@ Only intervals between two consecutive *scrolling* frames count: a static
 screen that changes once a second has no timing to get wrong, and the first
 frame of a scroll has no predecessor worth measuring against.
 
+"Scrolling" is DisplayManager's scroll state when the frame is presented, and
+that state can go missing in the middle of a scroll. It expires after 2s
+without scroll activity, which a long enough stall outlasts, and any thread can
+clear it: plugins call ``set_scrolling_state(False)`` from their own
+``display()``, and Vegas captures some of those on the render thread between
+two of its frames. The frame after that is recorded as static, and the interval
+it ends -- the stall, or the capture -- would vanish from the report. So a
+single static frame between two scrolling ones, with the scroll picking up
+again within ``RESUME_SECONDS``, is treated as a frame of the scroll: both of
+its intervals count. A second static frame in a row means the scroll really
+ended. (On hdpi on 2026-09-24 the watchdog logged a 1.9s stall that the soak
+report did not have; this is how.)
+
 A frame held for ``hold`` refreshes should arrive ``hold`` refresh periods
 after the one before it. One that arrives a whole refresh or more after that is
 **late**: the panel showed the previous frame again, which on a moving strip is
@@ -94,12 +107,16 @@ BUCKET_COUNT = 256
 #: See the module docstring.
 FREEZE_SECONDS = 0.25
 
-#: Two frames that are both "scrolling" can be at most DisplayManager's
+#: Intervals this long are not frames of one scroll. This used to be 1s,
-#: scroll_inactivity_threshold (2s) apart: after that the second is recorded
+#: which silently dropped every 1-2s stall inside a scroll. It is now only a
-#: as static. This used to be 1s, which silently dropped every 1-2s stall
+#: sanity bound.
-#: inside a scroll. It is now only a sanity bound.
 GAP_SECONDS = 5.0
 
+#: A frame recorded as static between two scrolling frames is a frame of the
+#: scroll whose state went missing, if the scroll resumes within this long.
+#: See "What is counted".
+RESUME_SECONDS = 1.0
+
 #: Buckets for freeze length, as cumulative counters a soak can difference.
 FREEZE_BUCKETS = ((0.5, "<0.5s"), (1.0, "0.5-1s"), (2.0, "1-2s"),
                   (float("inf"), "2s+"))
@@ -232,6 +249,9 @@ class FrameTimingRecorder:
         self._pending: List[Tuple[float, float, float, int]] = []
         self._static_frames = 0
         self._previous: Optional[Tuple[float, bool, int]] = None
+        # The interval ended by a static frame that followed a scrolling one,
+        # until the next frame shows whether the scroll went on.
+        self._unsure: Optional[Tuple[float, float, float, int]] = None
         self._last_flush: Optional[float] = None
         self._queue: "queue.SimpleQueue" = queue.SimpleQueue()
         self._worker: Optional[threading.Thread] = None
@@ -284,14 +304,29 @@ class FrameTimingRecorder:
         self.last_frame = (presented_at, scrolling, threading.get_ident())
         if not scrolling:
             self._static_frames += 1
+            # The scroll ended, or its state went missing for this frame: the
+            # next frame says which. Its hold may have been dropped with the
+            # state, so the interval is due at the scroll's own.
+            self._unsure = None
+            if previous is not None and previous[1]:
+                self._unsure = (presented_at - previous[0], blit, wait, previous[2])
         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, **watchdog_settings())
             self.watchdog.start()
-        elif previous is not None and previous[1]:
+        elif previous is not None:
             interval = presented_at - previous[0]
+            unsure, self._unsure = self._unsure, None
+            if previous[1]:
                 if interval < GAP_SECONDS:
                     self._pending.append((interval, blit, wait, hold))
+            elif unsure is not None and interval < RESUME_SECONDS:
+                # One static frame between two scrolling ones: the scroll never
+                # stopped, only its state did. Both intervals were motion.
+                self._static_frames -= 1
+                if unsure[0] < GAP_SECONDS:
+                    self._pending.append(unsure)
+                self._pending.append((interval, blit, wait, hold))
 
         if self._last_flush is None:
             self._last_flush = presented_at

test/test_frame_timing.py

@@ -121,6 +121,72 @@ def test_a_stall_between_one_and_two_seconds_is_not_lost(tmp_path):
     assert _aggregate(r)["freezes"] == 1
 
 
+def test_a_stall_whose_scroll_state_went_missing_still_counts(tmp_path):
+    # hdpi, 14:48: the watchdog logged a 1.9s stall the soak never reported.
+    # A plugin captured between two Vegas frames cleared the scroll state, so
+    # the frame that ended the stall was recorded as static and its interval
+    # dropped. Vegas set the state again right after, as it does every frame.
+    r = _recorder(tmp_path)
+    t = _feed(r, [PERIOD] * 100)
+    t += 1.911
+    r.record(0.002, 0.004, 1, False, t)          # state missing: "static"
+    _feed(r, [PERIOD] * 100, start=t + PERIOD)   # the scroll carries on
+    totals = _aggregate(r)
+    assert totals["freezes"] == 1
+    assert totals["freeze_by"]["1-2s"] == 1
+    assert totals["static_frames"] == 0
+    # 100 before, the step back into the scroll, 100 after: all but the freeze.
+    assert totals["scroll_frames"] == 100 + 1 + 100
+
+
+def test_a_frame_with_its_scroll_state_missing_is_still_timed(tmp_path):
+    # No stall at all -- the state was cleared and the frame went out on
+    # time. Nothing is late and no interval is lost.
+    r = _recorder(tmp_path)
+    t = _feed(r, [PERIOD] * 100)
+    r.record(0.002, 0.004, 1, False, t + PERIOD)
+    _feed(r, [PERIOD] * 100, start=t + 2 * PERIOD)
+    totals = _aggregate(r)
+    assert totals["scroll_frames"] == 202
+    assert totals["late_frames"] == totals["freezes"] == totals["static_frames"] == 0
+
+
+def test_a_scroll_that_really_ended_is_not_a_freeze(tmp_path):
+    # Two static frames in a row, then a new scroll: the gaps between them
+    # were a static screen, not a stall.
+    r = _recorder(tmp_path)
+    t = _feed(r, [PERIOD] * 100)
+    t = _feed(r, [0.5], scrolling=False, start=t + 0.3)
+    _feed(r, [PERIOD] * 100, start=t + 0.4)
+    totals = _aggregate(r)
+    assert totals["freezes"] == 0
+    assert totals["static_frames"] == 2
+    assert totals["scroll_frames"] == 200
+
+
+def test_one_static_frame_then_a_scroll_much_later_is_a_new_scroll(tmp_path):
+    r = _recorder(tmp_path)
+    t = _feed(r, [PERIOD] * 100)
+    r.record(0.002, 0.004, 1, False, t + 0.3)
+    _feed(r, [PERIOD] * 100, start=t + 0.3 + frame_timing.RESUME_SECONDS + 0.1)
+    totals = _aggregate(r)
+    assert totals["freezes"] == 0
+    assert totals["static_frames"] == 1
+    assert totals["scroll_frames"] == 200
+
+
+def test_a_missing_state_interval_is_due_at_the_scrolls_own_hold(tmp_path):
+    # Clearing the state drops the hold to 1 as well, so the "static" frame
+    # reports hold 1. Its interval is still due two refreshes after the last.
+    r = _recorder(tmp_path)
+    t = _feed(r, [2 * PERIOD] * 100, hold=2)
+    r.record(0.002, 0.004, 1, False, t + 2 * PERIOD)
+    _feed(r, [2 * PERIOD] * 100, hold=2, start=t + 4 * PERIOD)
+    totals = _aggregate(r)
+    assert totals["late_frames"] == totals["early_frames"] == 0
+    assert totals["scroll_frames"] == 202
+
+
 def test_early_frames_are_counted(tmp_path):
     # Hold 2 on a 100Hz panel: frames are due every 20ms. A swap that returns
     # after 10ms did not wait out the hold.