From 7f9c73e9aaecf10d14f265a7038d148bbfbcd33a Mon Sep 17 00:00:00 2001 From: Chuck <33324927+ChuckBuilds@users.noreply.github.com> Date: Thu, 24 Sep 2026 19:38:22 -0400 Subject: [PATCH] fix(vegas): smooth Vegas scroll pacing -- whole pixels per refresh, measured refresh, off-thread preview writes (#628) Vegas scrolls a whole number of pixels per panel refresh, locked to SwapOnVSync, against the refresh the panel really holds (measured from swap gaps), instead of blending sub-pixel positions against the refresh cap. The web preview PNG is encoded off the render thread while scrolling, with writes ordered and retried. On hdpi, late frames fell from 6.3% to 0.7%. See docs/SCROLL_PERFORMANCE.md. Co-Authored-By: Claude Opus 5.5 --- docs/CONFIG_REFERENCE.md | 3 +- docs/SCROLL_PERFORMANCE.md | 5 +- src/display_manager.py | 204 +++++++++++++----- src/vegas_mode/config.py | 21 +- src/vegas_mode/coordinator.py | 12 +- src/vegas_mode/render_pipeline.py | 140 +++++++++++- test/test_display_dirty_tracking.py | 148 +++++++++++++ test/test_display_pending_changes.py | 3 + test/test_vegas_coordinator_iteration.py | 3 + test/test_vegas_crisp_pacing.py | 156 ++++++++++++++ test/test_vegas_density.py | 4 + .../templates/v3/partials/display.html | 4 +- 12 files changed, 632 insertions(+), 71 deletions(-) create mode 100644 test/test_vegas_crisp_pacing.py diff --git a/docs/CONFIG_REFERENCE.md b/docs/CONFIG_REFERENCE.md index ac6b1486..6e2bf936 100644 --- a/docs/CONFIG_REFERENCE.md +++ b/docs/CONFIG_REFERENCE.md @@ -127,7 +127,8 @@ Read by `src/vegas_mode/config.py` (`VegasScrollConfig.from_config`). See | `min_content_separation` | int, `24` | | `min_cut_gap` | int, `6` | | `continuous_scroll` | bool, `true` | -| `smooth_scroll` | bool, `true` | +| `smooth_scroll` | bool, `true` — move a whole number of pixels per panel refresh, locked to vsync. `scroll_speed` is snapped to the nearest speed the panel can show that way (at 95Hz: 95, 47.5, 31.7 px/s…), measured against the panel's real refresh rate once scrolling starts | +| `sub_pixel_blend` | bool, `false` — the older smoothing: advance by elapsed time and blend neighbouring pixel columns. Looks anti-aliased in the web preview but shimmers on the panel and is not locked to the refresh. Overrides `smooth_scroll` when on | | `extend_threshold_screens` | float, `2.0` | | `auto_trim` | bool, `true` | | `trim_threshold` | int, `10` | diff --git a/docs/SCROLL_PERFORMANCE.md b/docs/SCROLL_PERFORMANCE.md index b588adfc..5f40b408 100644 --- a/docs/SCROLL_PERFORMANCE.md +++ b/docs/SCROLL_PERFORMANCE.md @@ -207,7 +207,10 @@ Fixed by rebuilding the binding: `scripts/build_rgbmatrix_nogil.sh`. ### 3. Sub-pixel blending was wrong for this display Enabling it made things worse, not better — see the rule at the top. It is off -by default and only Vegas mode opts in via `set_sub_pixel_scrolling(True)`. +by default everywhere. Vegas mode used to opt in; it now scrolls in whole +pixels locked to the refresh like the plugin tickers, and keeps the blend only +behind `display.vegas_scroll.sub_pixel_blend` (default `false`). The blend is +also why text looked anti-aliased in the web preview while the panel shimmered. ### 4. Frame-based stepping raced the vsync clock diff --git a/src/display_manager.py b/src/display_manager.py index 0123e40e..de9708a0 100644 --- a/src/display_manager.py +++ b/src/display_manager.py @@ -194,7 +194,19 @@ class DisplayManager: self._last_snapshot_ts = 0.0 self._last_snapshot_touch_ts = 0.0 self._last_snapshot_digest: Optional[int] = None + # The frame actually on disk. _last_snapshot_digest moves when a frame + # is handed to the writer; this only once it has been saved, so an + # mtime touch never vouches for a frame still waiting to be written. + self._saved_snapshot_digest: Optional[int] = None self._snapshot_dir_prepared = False + # Background writer used mid-scroll; see _write_snapshot_if_due. + self._snapshot_cond = threading.Condition() + self._snapshot_pending: Optional[Tuple[Image.Image, Optional[int]]] = None + self._snapshot_thread: Optional[threading.Thread] = None + self._snapshot_stop = False + # Held for the whole of each PNG write, by the writer thread and by + # the inline static path, so the two land on disk in order. + self._snapshot_write_lock = threading.Lock() self._viewer_check_ts = 0.0 self._viewer_fresh = False self._viewer_was_fresh = False @@ -1270,6 +1282,8 @@ class DisplayManager: def cleanup(self): """Clean up resources.""" + if hasattr(self, '_snapshot_cond'): + self._stop_snapshot_writer() if hasattr(self, 'matrix') and self.matrix is not None: try: self.matrix.Clear() @@ -1590,67 +1604,149 @@ class DisplayManager: viewer_fresh, digest != self._last_snapshot_digest) if action is snapshot_policy.SnapshotAction.SKIP: return - if action is snapshot_policy.SnapshotAction.TOUCH: + if (action is snapshot_policy.SnapshotAction.TOUCH + and self._saved_snapshot_digest == digest): # mtime bump only: keeps the health check (snapshot age) # green without paying for a PNG encode of an unchanged frame os.utime(self._snapshot_path, None) self._last_snapshot_touch_ts = now return + # (A TOUCH for a frame that isn't on disk yet -- still queued, or + # its write failed -- is written instead: touching would make the + # older file on disk look current.) - # WRITE: ensure directory permissions once, not per frame - snapshot_path_obj = Path(self._snapshot_path) - if not self._snapshot_dir_prepared: - # Never modify /tmp permissions - it has special system - # permissions (1777) that must not be changed or it breaks - # apt and other system tools - parent_dir = snapshot_path_obj.parent - if parent_dir and str(parent_dir) != '/tmp': # nosec B108 - guard to skip /tmp for permission ops - ensure_directory_permissions(parent_dir, get_assets_dir_mode()) - self._snapshot_dir_prepared = True - # Write atomically: temp then replace. The temp name must be - # unique, not ".tmp": /tmp is world-writable and sticky, - # and this file is written by whichever user the display service - # runs as while tests and tooling run as someone else. A leftover - # fixed-name temp owned by another user is then unopenable even by - # root (fs.protected_regular refuses O_CREAT on a foreign file in a - # sticky dir), which froze the preview and the health check's - # liveness proxy until somebody deleted it by hand. Same pattern as - # the hardware-status write above. - _fd, tmp_path = tempfile.mkstemp( - dir=str(snapshot_path_obj.parent), - prefix=f".{snapshot_path_obj.name}.", suffix=".tmp") - try: - with os.fdopen(_fd, "wb") as _f: - self.image.save(_f, format='PNG') - os.chmod(tmp_path, 0o644) - os.replace(tmp_path, self._snapshot_path) - except Exception: - # Never leave the temp behind -- that is what made the failure - # permanent rather than transient. - try: - os.unlink(tmp_path) - except OSError: - pass - # Fallback to direct save if replace not supported - self.image.save(self._snapshot_path, format='PNG') - # Set proper file permissions after saving - try: - ensure_file_permissions(snapshot_path_obj, get_assets_file_mode()) - except Exception: - pass + # WRITE. Mid-scroll the PNG encode goes to a background thread: at + # 512x64 it takes 12-14ms on a Pi 4, longer than a 95Hz refresh, + # so on the render thread every preview write made the next swap + # miss its vsync -- five visible hitches a second, but only while + # someone had the web preview open. Pillow releases the GIL while + # it compresses, so the encode no longer holds the loop up. Static + # frames still write inline: nothing is moving to disturb. + if self.is_currently_scrolling(): + self._queue_snapshot(self.image.copy(), digest) + else: + # A scroll that just ended can leave its last frame queued or + # mid-write; it must not land on top of this newer one. + with self._snapshot_write_lock: + with self._snapshot_cond: + self._snapshot_pending = None + self._save_snapshot(self.image) + self._saved_snapshot_digest = digest self._last_snapshot_ts = now self._last_snapshot_touch_ts = now self._last_snapshot_digest = digest except Exception as e: - # Snapshot failures must never break display — but they must not - # be silent either: the snapshot's mtime is the web UI's display - # mirror AND its hardware-liveness proxy, so a quietly failing - # write freezes the mirror and makes health checks lie (seen in - # the field: a stale root-owned /tmp file froze it for a day). - # Warn at most once per 5 minutes to avoid log spam. - if (now - self._snapshot_fail_log_ts) > 300: - self._snapshot_fail_log_ts = now - logger.warning("Snapshot write failing (web preview/health " - "mirror is stale): %s", e) - else: - logger.debug(f"Snapshot write skipped: {e}") \ No newline at end of file + self._log_snapshot_failure(e) + + def _log_snapshot_failure(self, error: Exception) -> None: + # Snapshot failures must never break display — but they must not + # be silent either: the snapshot's mtime is the web UI's display + # mirror AND its hardware-liveness proxy, so a quietly failing + # write freezes the mirror and makes health checks lie (seen in + # the field: a stale root-owned /tmp file froze it for a day). + # Warn at most once per 5 minutes to avoid log spam. + now = time.time() + if (now - self._snapshot_fail_log_ts) > 300: + self._snapshot_fail_log_ts = now + logger.warning("Snapshot write failing (web preview/health " + "mirror is stale): %s", error) + else: + logger.debug(f"Snapshot write skipped: {error}") + + def _save_snapshot(self, image: Image.Image) -> None: + """Encode ``image`` to the snapshot path atomically. Raises on failure.""" + # Ensure directory permissions once, not per frame + snapshot_path_obj = Path(self._snapshot_path) + if not self._snapshot_dir_prepared: + # Never modify /tmp permissions - it has special system + # permissions (1777) that must not be changed or it breaks + # apt and other system tools + parent_dir = snapshot_path_obj.parent + if parent_dir and str(parent_dir) != '/tmp': # nosec B108 - guard to skip /tmp for permission ops + ensure_directory_permissions(parent_dir, get_assets_dir_mode()) + self._snapshot_dir_prepared = True + # Write atomically: temp then replace. The temp name must be + # unique, not ".tmp": /tmp is world-writable and sticky, + # and this file is written by whichever user the display service + # runs as while tests and tooling run as someone else. A leftover + # fixed-name temp owned by another user is then unopenable even by + # root (fs.protected_regular refuses O_CREAT on a foreign file in a + # sticky dir), which froze the preview and the health check's + # liveness proxy until somebody deleted it by hand. Same pattern as + # the hardware-status write above. + _fd, tmp_path = tempfile.mkstemp( + dir=str(snapshot_path_obj.parent), + prefix=f".{snapshot_path_obj.name}.", suffix=".tmp") + try: + with os.fdopen(_fd, "wb") as _f: + image.save(_f, format='PNG') + os.chmod(tmp_path, 0o644) + os.replace(tmp_path, self._snapshot_path) + except Exception: + # Never leave the temp behind -- that is what made the failure + # permanent rather than transient. + try: + os.unlink(tmp_path) + except OSError: + pass + # Fallback to direct save if replace not supported + image.save(self._snapshot_path, format='PNG') + # Set proper file permissions after saving + try: + ensure_file_permissions(snapshot_path_obj, get_assets_file_mode()) + except Exception: + pass + + def _queue_snapshot(self, image: Image.Image, digest: Optional[int] = None) -> None: + """Hand a frame to the snapshot writer thread; the newest frame wins. + + One slot, not a queue: if the writer is still encoding when the next + frame is due, the waiting frame is simply replaced. The preview wants + the latest frame, and a backlog would only cost memory and CPU. + """ + with self._snapshot_cond: + self._snapshot_pending = (image, digest) + if self._snapshot_thread is None or not self._snapshot_thread.is_alive(): + self._snapshot_thread = threading.Thread( + target=self._snapshot_writer, daemon=True, + name="snapshot-writer") + self._snapshot_thread.start() + self._snapshot_cond.notify() + + def _snapshot_writer(self) -> None: + while True: + with self._snapshot_cond: + while self._snapshot_pending is None and not self._snapshot_stop: + self._snapshot_cond.wait() + if self._snapshot_stop: + return # shutting down: a pending frame is dropped + # The write lock before the frame: whichever of this and an inline + # static save gets it first also writes first, and a static save + # clears the slot, so an older frame never lands on a newer one. + with self._snapshot_write_lock: + with self._snapshot_cond: + pending, self._snapshot_pending = self._snapshot_pending, None + if pending is None: + continue + image, digest = pending + try: + self._save_snapshot(image) + self._saved_snapshot_digest = digest + except Exception as e: + # The frame was recorded as written when it was queued. + # Forget that, so an unchanged frame is written again + # rather than only mtime-touching a stale file into + # looking healthy. + self._last_snapshot_digest = None + self._log_snapshot_failure(e) + + def _stop_snapshot_writer(self, timeout: float = 1.0) -> None: + """Stop the writer thread, dropping any frame it has not started.""" + with self._snapshot_cond: + self._snapshot_stop = True + self._snapshot_pending = None + self._snapshot_cond.notify_all() + thread = self._snapshot_thread + if thread is not None and thread is not threading.current_thread(): + thread.join(timeout) + self._snapshot_thread = None \ No newline at end of file diff --git a/src/vegas_mode/config.py b/src/vegas_mode/config.py index 8f33aab6..06e09400 100644 --- a/src/vegas_mode/config.py +++ b/src/vegas_mode/config.py @@ -58,13 +58,22 @@ class VegasModeConfig: # switched off at the start of every cycle. lead_in_width: int = 0 - # Blend between neighbouring pixel positions so motion happens at the frame - # rate rather than the scroll speed. With integer positioning the number of - # distinct frames per second equals scroll_speed, so at 50px/s the motion is - # 50 discrete 1px steps however fast the loop runs. The trade is a slight - # horizontal softening of text, since each frame is a blend of two positions. + # Lock motion to the panel: a whole number of pixels per presented frame, + # each frame held for a whole number of refreshes, with SwapOnVSync as the + # clock (see src/common/scroll_config.py). scroll_speed is snapped to the + # nearest speed the panel can show that way. Off falls back to advancing by + # elapsed time, which drifts against the refresh and judders. smooth_scroll: bool = True + # The older way of smoothing: advance by elapsed time and blend the two + # neighbouring pixel positions each frame. It looks anti-aliased in the web + # preview, but on the panel the blended columns shimmer (the library's + # brightness curve makes a 50% blend far dimmer than half), text softens, + # and the loop is not tied to the refresh, so it still misses frames. + # Measured on a 512x64 chain at 95Hz: 73-89fps, p99 20-28ms. Takes + # precedence over smooth_scroll's whole-pixel pacing when on. + sub_pixel_blend: bool = False + # Keep one continuous strip, extending it with the next group of plugins as # the scroll approaches the end, instead of composing a fresh strip and # swapping it in. A swap stops the motion, substitutes every pixel at once @@ -196,6 +205,7 @@ class VegasModeConfig: get('min_content_separation', d.min_content_separation)), min_cut_gap=int(get('min_cut_gap', d.min_cut_gap)), smooth_scroll=get('smooth_scroll', d.smooth_scroll), + sub_pixel_blend=bool(get('sub_pixel_blend', d.sub_pixel_blend)), continuous_scroll=get('continuous_scroll', d.continuous_scroll), extend_threshold_screens=float( get('extend_threshold_screens', d.extend_threshold_screens)), @@ -238,6 +248,7 @@ class VegasModeConfig: 'min_content_separation': self.min_content_separation, 'min_cut_gap': self.min_cut_gap, 'smooth_scroll': self.smooth_scroll, + 'sub_pixel_blend': self.sub_pixel_blend, 'continuous_scroll': self.continuous_scroll, 'extend_threshold_screens': self.extend_threshold_screens, 'auto_trim': self.auto_trim, diff --git a/src/vegas_mode/coordinator.py b/src/vegas_mode/coordinator.py index c053c06b..1a0f1876 100644 --- a/src/vegas_mode/coordinator.py +++ b/src/vegas_mode/coordinator.py @@ -414,7 +414,6 @@ class VegasModeCoordinator: if not self.start(): return False - frame_interval = self.vegas_config.get_frame_interval() if self.vegas_config.continuous_scroll: # The strip is continuously extended and trimmed, so its width says # nothing about how long to run. This is only how often control @@ -482,7 +481,10 @@ class VegasModeCoordinator: # quarter of the budget spent not rendering. Subtracting the work # already done keeps the pacing target while reclaiming that time, # and yields the GIL either way so other threads still run. + # Read every frame: a config change applied mid-iteration can + # switch between crisp and blended pacing. frame_elapsed = time.monotonic() - frame_started + frame_interval = self.render_pipeline.frame_interval time.sleep(max(0.0, frame_interval - frame_elapsed)) # Measured before the sleep: time spent working, not pacing. @@ -512,20 +514,20 @@ class VegasModeCoordinator: if current_time - last_fps_log_time >= fps_log_interval: fps = fps_frame_count / (current_time - last_fps_log_time) p99 = _percentile(sorted(frame_times), 0.99) - target = self.vegas_config.target_fps + target = self.render_pipeline.target_fps degraded = target > 0 and fps < target * _FPS_HEALTHY_FRACTION due = (current_time - self._fps_last_health_log >= _FPS_HEARTBEAT_INTERVAL) if degraded or self._fps_was_degraded or due: logger.info( - "Vegas FPS: %.1f (target: %d, frames: %d) p99 %.1fms worst %.1fms", + "Vegas FPS: %.1f (target: %.0f, frames: %d) p99 %.1fms worst %.1fms", fps, target, fps_frame_count, p99 * 1000.0, frame_worst * 1000.0 ) self._fps_last_health_log = current_time else: logger.debug( - "Vegas FPS: %.1f (target: %d, frames: %d) p99 %.1fms worst %.1fms", + "Vegas FPS: %.1f (target: %.0f, frames: %d) p99 %.1fms worst %.1fms", fps, target, fps_frame_count, p99 * 1000.0, frame_worst * 1000.0 ) @@ -553,7 +555,7 @@ class VegasModeCoordinator: # main loop's _tick_plugin_updates() finds all intervals already # satisfied on return, so the inter-iteration gap is <1 ms and the # display never shows a frozen frame between iterations. - _UPDATE_TICK_FRAMES = max(1, int(self.vegas_config.target_fps * 4)) # every 4 s regardless of FPS + _UPDATE_TICK_FRAMES = max(1, int(self.render_pipeline.target_fps * 4)) # every 4 s regardless of FPS if (self._update_callback and frame_count % _UPDATE_TICK_FRAMES == 0 and not self._update_tick_running): diff --git a/src/vegas_mode/render_pipeline.py b/src/vegas_mode/render_pipeline.py index b9e5914b..7bb0ca12 100644 --- a/src/vegas_mode/render_pipeline.py +++ b/src/vegas_mode/render_pipeline.py @@ -13,6 +13,7 @@ from collections import deque from typing import Optional, List, Any, Dict, Deque from PIL import Image +from src.common.scroll_config import solve_crisp from src.common.scroll_helper import ScrollHelper from src.vegas_mode.config import VegasModeConfig from src.vegas_mode.geometry import separation_gap @@ -43,6 +44,13 @@ class RenderPipeline: # stalls land in separate moments rather than one run of hitches. DEFERRED_DRAIN_INTERVAL = 2.0 + # Swaps timed before trusting a refresh measurement: about a second. + REFRESH_SAMPLES = 96 + # Frames skipped first, while the hold from whatever ran before settles. + REFRESH_WARMUP_FRAMES = 8 + # A panel measured within this fraction of its cap is keeping up with it. + REFRESH_TOLERANCE = 0.03 + def __init__( self, config: VegasModeConfig, @@ -74,6 +82,11 @@ class RenderPipeline: logger ) + # The panel's real refresh rate, measured from our own vsync-blocked + # swaps once scrolling starts. None until then; see _measure_refresh. + self._measured_hz: Optional[float] = None + self._swap_times: Deque[float] = deque(maxlen=self.REFRESH_SAMPLES + 1) + # Configure scroll helper self._configure_scroll_helper() @@ -89,6 +102,8 @@ class RenderPipeline: self._cycle_complete = False self._segments_in_scroll: List[str] = [] # Plugin IDs in current scroll + # The sub-pixel path's pacing; the crisp path solves its own (frame_interval). + self._frame_interval = config.get_frame_interval() self._cycle_start_time = 0.0 # Statistics @@ -108,9 +123,37 @@ class RenderPipeline: def _configure_scroll_helper(self) -> None: """Configure ScrollHelper with current settings.""" - self.scroll_helper.set_frame_based_scrolling(self.config.frame_based_scrolling) self.scroll_helper.set_scroll_delay(self.config.scroll_delay) - self.scroll_helper.set_sub_pixel_scrolling(self.config.smooth_scroll) + self.scroll_helper.set_sub_pixel_scrolling(self.config.sub_pixel_blend) + + # With smooth_scroll the strip moves a whole number of pixels per + # presented frame, each frame held for frame_hold panel refreshes, and + # SwapOnVSync is the clock -- the same crisp pacing the plugin tickers + # use (src/common/scroll_config.py). The time-based path below has no + # fixed relation to the refresh: at 90px/s on a panel refreshing at + # 95Hz every frame lands 0.95px on, so text is re-blended at a + # different phase each refresh, and any frame that misses a vsync is + # followed by a double step. Measured on a 512x64 chain: 73fps against + # a 95Hz panel, p99 21-28ms -- a visible hitch every few frames. + self._crisp = None + self._frame_hold = 1 + # Gaps timed under the old hold would be divided by the new one. + self._swap_times.clear() + if self.config.smooth_scroll and not self.config.sub_pixel_blend: + self._crisp = solve_crisp(self.config.scroll_speed, self._refresh_hz()) + self._frame_hold = self._crisp.frame_hold + self.scroll_helper.set_frame_based_scrolling(False) + self.scroll_helper.set_scroll_speed(self._crisp.pixels_per_second) + self.scroll_helper.set_pixels_per_frame(self._crisp.pixels_per_frame) + logger.info( + "Vegas scroll: %s (asked for %d px/s on a %.0fHz panel)", + self._crisp.describe(), self.config.scroll_speed, self._refresh_hz() + ) + self._apply_dynamic_duration_settings() + return + + self.scroll_helper.set_pixels_per_frame(None) + self.scroll_helper.set_frame_based_scrolling(self.config.frame_based_scrolling) # Config scroll_speed is always pixels per second, but ScrollHelper # takes it in different units depending on frame_based_scrolling: @@ -125,6 +168,9 @@ class RenderPipeline: self.scroll_helper.set_scroll_speed(pixels_per_frame) else: self.scroll_helper.set_scroll_speed(self.config.scroll_speed) + self._apply_dynamic_duration_settings() + + def _apply_dynamic_duration_settings(self) -> None: self.scroll_helper.set_dynamic_duration_settings( enabled=self.config.dynamic_duration_enabled, min_duration=self.config.min_cycle_duration, @@ -132,6 +178,92 @@ class RenderPipeline: buffer=0.1 # 10% buffer ) + def _cap_hz(self) -> float: + """The panel's refresh cap, as the display manager reports it.""" + try: + hz = float(getattr(self.display_manager, 'refresh_hz', 0) or 0) + except (TypeError, ValueError): + hz = 0.0 + return hz if hz > 0 else 100.0 + + def _refresh_hz(self) -> float: + """The refresh to solve the crisp speed against: measured, else the cap.""" + return self._measured_hz or self._cap_hz() + + def _measure_refresh(self) -> None: + """Time our swaps to learn the rate the panel really refreshes at. + + limit_refresh_rate_hz is a cap, not a rate. A long single chain cannot + reach a high one: 4x128x64 at pwm_bits 8 refreshes at ~95Hz under a + 120Hz cap. Solving against the cap then picks a speed built for a + refresh the panel never delivers -- 90px/s at "120Hz" is 3px every 4 + refreshes, visibly jumpy, where the real 95Hz allows 1px every refresh. + + SwapOnVSync blocks for frame_hold refreshes, and a swap can only come + back late -- a missed vsync lengthens its gap by whole refreshes, never + shortens one -- so the low end of the gaps is frame_hold refresh + periods: the 10th percentile, as src/common/frame_timing.py uses. The + median would track the render loop instead once most frames in the + window were late (startup, a prefetch, a recompose), lock in a rate + too low, and scroll faster than configured until restart. Measured + once: the refresh only changes with the hardware config, which + restarts us. + """ + if self._crisp is None or self._measured_hz is not None: + return + if getattr(self.display_manager, 'matrix', None) is None: + return # No hardware: nothing blocks, so there is nothing to time. + if self.stats['frames_rendered'] < self.REFRESH_WARMUP_FRAMES: + return + self._swap_times.append(time.monotonic()) + if len(self._swap_times) <= self.REFRESH_SAMPLES: + return + + times = list(self._swap_times) + gaps = sorted(b - a for a, b in zip(times, times[1:])) + period = gaps[len(gaps) // 10] + self._swap_times.clear() + if period <= 0: + return + measured = self._frame_hold / period + cap = self._cap_hz() + if measured >= cap * (1.0 - self.REFRESH_TOLERANCE): + self._measured_hz = cap + return + self._measured_hz = round(measured, 1) + logger.info( + "Vegas: panel refreshes at %.1fHz, below its %.0fHz cap; " + "re-solving the scroll speed for the real rate", + self._measured_hz, cap + ) + self._configure_scroll_helper() + + @property + def target_fps(self) -> float: + """Frames per second this scroll presents when it keeps up.""" + if self._crisp is not None: + return self._crisp.frames_per_second + return float(self.config.target_fps) + + @property + def frame_interval(self) -> float: + """Shortest time the render loop should spend on one frame. + + With crisp pacing SwapOnVSync already blocks for frame_hold refreshes, + so this is only a floor for when the swap does not block (no hardware, + or the emulator). It must not exceed the real refresh period: a loop + that sleeps even slightly longer than the panel drifts against it and + misses a refresh every few frames -- which is what target_fps 90 on a + 95Hz panel did. The configured cap is at least the real refresh, so + hold / cap never exceeds hold real periods -- the measured rate is + deliberately not used here. + """ + if self._crisp is not None: + # 0.9: the floor must sit strictly below the real period, or the + # surplus accumulates frame over frame until one misses. + return 0.9 * self._frame_hold / self._cap_hz() + return self._frame_interval + def compose_scroll_content(self) -> bool: """ Compose content from stream manager into scrollable image. @@ -547,10 +679,11 @@ class RenderPipeline: self.sync_manager.send_scroll_x(self.scroll_helper.scroll_position) # Update scrolling state - self.display_manager.set_scrolling_state(True) + self.display_manager.set_scrolling_state(True, self._frame_hold) # Track statistics self.stats['frames_rendered'] += 1 + self._measure_refresh() frame_time = time.time() - frame_start self._track_frame_time(frame_time) @@ -759,6 +892,7 @@ class RenderPipeline: """ old_fps = self.config.target_fps self.config = new_config + self._frame_interval = new_config.get_frame_interval() # Reconfigure scroll helper self._configure_scroll_helper() diff --git a/test/test_display_dirty_tracking.py b/test/test_display_dirty_tracking.py index 01af2884..e91bc93b 100644 --- a/test/test_display_dirty_tracking.py +++ b/test/test_display_dirty_tracking.py @@ -353,3 +353,151 @@ class TestFrameHoldLifetime: assert dm._frame_hold == 1 finally: dm.set_scrolling_state(False) + + +class TestSnapshotOffRenderThread: + """Mid-scroll, the preview PNG is encoded off the render thread. + + At 512x64 the encode takes 12-14ms on a Pi 4 -- longer than a refresh -- + so doing it inline made the next swap miss its vsync five times a second + whenever the web preview was open. + """ + + def _record_saves(self, dm, monkeypatch): + import threading + threads = [] + done = threading.Event() + real = dm._save_snapshot + + def recording(image): + threads.append(threading.current_thread().name) + real(image) + done.set() + + monkeypatch.setattr(dm, "_save_snapshot", recording) + return threads, done + + def _due(self, dm, tmp_path, colour): + dm._snapshot_path = str(tmp_path / "snap.png") + dm._last_snapshot_ts = 0.0 + dm._last_snapshot_touch_ts = 0.0 + dm._last_snapshot_digest = None + dm.draw.rectangle([0, 0, 10, 4], fill=colour) + + def test_scrolling_frames_are_encoded_on_the_writer_thread( + self, dm, tmp_path, monkeypatch): + import threading + threads, done = self._record_saves(dm, monkeypatch) + self._due(dm, tmp_path, (0, 255, 255)) + dm.set_scrolling_state(True) + try: + dm.update_display() + assert done.wait(5), "the snapshot writer never wrote the frame" + finally: + dm.set_scrolling_state(False) + assert threads == ["snapshot-writer"] + assert threads[0] != threading.current_thread().name + assert os.path.exists(dm._snapshot_path) + + def test_a_failed_background_write_is_retried_not_touched( + self, dm, tmp_path, monkeypatch): + # Queuing records the frame as written. If the writer then fails, an + # unchanged frame must be written again, not mtime-touched: touching + # would make a stale preview look healthy. + import threading + import time + failed = threading.Event() + + def failing(image): + failed.set() + raise OSError("disk full") + + monkeypatch.setattr(dm, "_save_snapshot", failing) + self._due(dm, tmp_path, (0, 255, 0)) + dm.set_scrolling_state(True) + try: + dm.update_display() + assert failed.wait(5) + deadline = time.time() + 5 + while dm._last_snapshot_digest is not None and time.time() < deadline: + time.sleep(0.01) + finally: + dm.set_scrolling_state(False) + assert dm._last_snapshot_digest is None + + def test_a_frame_not_yet_on_disk_is_written_not_touched( + self, dm, tmp_path, monkeypatch): + # The digest is recorded when a frame is queued. Until the writer has + # saved it, an unchanged frame must not mtime-touch the older file on + # disk into looking current. + import zlib + from src.common import snapshot_policy + touched, saved = [], [] + self._due(dm, tmp_path, (9, 9, 9)) + digest = zlib.adler32(dm.image.tobytes()) + dm._last_snapshot_digest = digest # queued earlier... + dm._saved_snapshot_digest = 12345 # ...but an older frame is on disk + monkeypatch.setattr(snapshot_policy, "decide", + lambda *a, **k: snapshot_policy.SnapshotAction.TOUCH) + monkeypatch.setattr(os, "utime", lambda *a, **k: touched.append(a)) + monkeypatch.setattr(dm, "_save_snapshot", lambda image: saved.append(image)) + dm.set_scrolling_state(False) + dm._write_snapshot_if_due(digest) + assert touched == [] + assert len(saved) == 1 + assert dm._saved_snapshot_digest == digest + + # Once it is on disk, the same frame is only touched. + dm._write_snapshot_if_due(digest) + assert len(touched) == 1 and len(saved) == 1 + + def test_a_static_frame_lands_after_a_queued_one_still_being_written( + self, dm, tmp_path, monkeypatch): + # The last frame of a scroll can still be encoding when the first + # static frame is due; the older one must not land on top. + import threading + written, started, release = [], threading.Event(), threading.Event() + real = dm._save_snapshot + + def slow_then_record(image): + if threading.current_thread().name == "snapshot-writer": + started.set() + release.wait(5) + written.append((threading.current_thread().name, image.getpixel((0, 0)))) + real(image) + + monkeypatch.setattr(dm, "_save_snapshot", slow_then_record) + self._due(dm, tmp_path, (0, 0, 255)) + dm.set_scrolling_state(True) + dm.update_display() # queued: the writer blocks mid-write + assert started.wait(5) + dm.set_scrolling_state(False) + self._due(dm, tmp_path, (255, 0, 0)) + static = threading.Thread(target=dm.update_display) + static.start() + static.join(0.2) + assert static.is_alive(), "the static save must wait for the write in flight" + release.set() + static.join(5) + assert [colour for _, colour in written] == [(0, 0, 255), (255, 0, 0)] + + def test_cleanup_stops_the_writer(self, dm, tmp_path, monkeypatch): + threads, done = self._record_saves(dm, monkeypatch) + self._due(dm, tmp_path, (0, 255, 255)) + dm.set_scrolling_state(True) + dm.update_display() + assert done.wait(5) + writer = dm._snapshot_thread + dm.set_scrolling_state(False) + dm._stop_snapshot_writer() + writer.join(2) + assert not writer.is_alive() + + def test_static_frames_are_still_written_inline( + self, dm, tmp_path, monkeypatch): + import threading + threads, _ = self._record_saves(dm, monkeypatch) + self._due(dm, tmp_path, (255, 0, 255)) + dm.set_scrolling_state(False) + dm.update_display() + assert threads == [threading.current_thread().name] diff --git a/test/test_display_pending_changes.py b/test/test_display_pending_changes.py index 50aa4574..f30f29bd 100644 --- a/test/test_display_pending_changes.py +++ b/test/test_display_pending_changes.py @@ -140,6 +140,9 @@ def vegas_coordinator(controller): 'enabled': True, 'max_cycle_duration': VEGAS_ITERATION_SECONDS}}}) assert coord.vegas_config.continuous_scroll coord.render_pipeline = MagicMock() + # Real numbers: the loop sleeps and reports against these. + coord.render_pipeline.frame_interval = coord.vegas_config.get_frame_interval() + coord.render_pipeline.target_fps = float(coord.vegas_config.target_fps) coord.stream_manager = MagicMock() coord.display_manager = controller.display_manager coord.stats = {'cycles_completed': 0, 'interruptions': 0} diff --git a/test/test_vegas_coordinator_iteration.py b/test/test_vegas_coordinator_iteration.py index 329b36fa..954c33b7 100644 --- a/test/test_vegas_coordinator_iteration.py +++ b/test/test_vegas_coordinator_iteration.py @@ -21,6 +21,9 @@ def _coordinator(plugins): coord.vegas_config = VegasModeConfig.from_config({'display': {'vegas_scroll': { 'enabled': True, 'max_cycle_duration': 0}}}) coord.render_pipeline = MagicMock() + # The loop paces itself from these (#628); a MagicMock can't be compared. + coord.render_pipeline.frame_interval = 0.0 + coord.render_pipeline.target_fps = 90 coord.stream_manager = MagicMock() coord.display_manager = MagicMock() coord.plugin_manager = SimpleNamespace(plugins=plugins, get_plugin=plugins.get) diff --git a/test/test_vegas_crisp_pacing.py b/test/test_vegas_crisp_pacing.py new file mode 100644 index 00000000..c5b87005 --- /dev/null +++ b/test/test_vegas_crisp_pacing.py @@ -0,0 +1,156 @@ +"""Vegas scrolls in whole pixels locked to the panel refresh. + +It used to advance by elapsed time, blend neighbouring columns, and pace itself +with a sleep to target_fps. On a 512x64 chain refreshing at 95Hz that ran at +73-89fps with p99 frames of 20-28ms: the sleep drifted against the refresh and +missed a vsync every few frames, and the blend shimmered on the panel. +""" +import sys +from pathlib import Path +from unittest.mock import patch + +import pytest +from PIL import Image + +sys.path.insert(0, str(Path(__file__).resolve().parent.parent)) + +from src.common.scroll_config import solve_crisp # noqa: E402 +from src.vegas_mode import render_pipeline as rp_module # noqa: E402 +from src.vegas_mode.config import VegasModeConfig # noqa: E402 +from src.vegas_mode.render_pipeline import RenderPipeline # noqa: E402 + +W, H = 128, 32 + + +class FakeStream: + def get_grouped_content_for_composition(self): + return [('a', [Image.new('RGB', (4000, H), (255, 255, 255))])] + + def get_active_plugin_ids(self): + return ['a'] + + +class FakeDM: + width = W + height = H + + def __init__(self, refresh_hz=100.0, hardware=True): + self.refresh_hz = refresh_hz + self.matrix = object() if hardware else None + self.image = Image.new('RGB', (W, H)) + self.holds = [] + + def set_scrolling_state(self, is_scrolling, frame_hold=1): + self.holds.append(frame_hold) + + def update_display(self): + pass + + +def _pipeline(dm=None, **cfg): + p = RenderPipeline(VegasModeConfig(lead_in_width=0, **cfg), dm or FakeDM(), + FakeStream()) + assert p.compose_scroll_content() + return p + + +def test_default_steps_whole_pixels_and_holds_frames(): + dm = FakeDM(refresh_hz=100.0) + p = _pipeline(dm, scroll_speed=50) + want = solve_crisp(50, 100.0) + assert p.scroll_helper.fixed_pixels_per_frame == want.pixels_per_frame + assert not p.scroll_helper.sub_pixel_scrolling + + before = p.scroll_helper.scroll_position + p.render_frame() + assert p.scroll_helper.scroll_position - before == want.pixels_per_frame + # The hold is what makes 1px every 2 refreshes 50px/s rather than 100. + assert dm.holds[-1] == want.frame_hold == 2 + assert p.target_fps == want.frames_per_second + + +def test_sleep_floor_stays_below_the_refresh_period(): + # A floor at or above the real period accumulates until a frame misses. + p = _pipeline(FakeDM(refresh_hz=100.0), scroll_speed=50) + assert p.frame_interval < p._frame_hold / 100.0 + + +def test_sub_pixel_blend_keeps_the_old_time_based_blend(): + dm = FakeDM() + p = _pipeline(dm, sub_pixel_blend=True, target_fps=90) + assert p.scroll_helper.fixed_pixels_per_frame is None + assert p.scroll_helper.sub_pixel_scrolling + p.render_frame() + assert dm.holds[-1] == 1 + assert p.frame_interval == 1.0 / 90 + assert p.target_fps == 90 + + +def _run_swaps(p, period, frames): + """Render `frames` frames whose swaps are `period` seconds apart.""" + clock = [1000.0] + + def monotonic(): + return clock[0] + + with patch.object(rp_module.time, 'monotonic', monotonic): + for _ in range(frames): + p.render_frame() + clock[0] += period + + +def test_a_panel_below_its_cap_is_measured_and_the_speed_re_solved(): + # 4x128x64 on one chain: capped at 120Hz, really 95Hz. Against the cap + # 90px/s solves to 3px every 4 refreshes; against 95Hz, 1px every one. + p = _pipeline(FakeDM(refresh_hz=120.0), scroll_speed=90) + assert p._crisp.pixels_per_frame == 3 + + frames = RenderPipeline.REFRESH_WARMUP_FRAMES + RenderPipeline.REFRESH_SAMPLES + 2 + _run_swaps(p, p._frame_hold / 95.0, frames) + + assert p._measured_hz == 95.0 + assert (p._crisp.pixels_per_frame, p._crisp.frame_hold) == (1, 1) + # The floor still comes from the cap, not the measurement. + assert p.frame_interval < 1 / 95.0 + + +def test_a_panel_that_keeps_up_with_its_cap_is_left_alone(): + p = _pipeline(FakeDM(refresh_hz=100.0), scroll_speed=50) + crisp = p._crisp + frames = RenderPipeline.REFRESH_WARMUP_FRAMES + RenderPipeline.REFRESH_SAMPLES + 2 + _run_swaps(p, p._frame_hold / 99.5, frames) + assert p._measured_hz == 100.0 + assert p._crisp == crisp + + +def test_a_window_of_mostly_late_frames_still_measures_the_panel(): + # A late swap only lengthens its gap, by whole refreshes. A window where + # most frames missed a vsync (startup, a prefetch) must not read as a + # slower panel: with 7 frames in 10 a refresh late, the median would say + # 76Hz here and the speed would be solved for a panel that isn't there. + p = _pipeline(FakeDM(refresh_hz=120.0), scroll_speed=90) + period, hold = 1 / 95.0, p._frame_hold + gaps = [(hold + 1) * period if i % 10 < 7 else hold * period for i in range(400)] + clock = [1000.0] + with patch.object(rp_module.time, 'monotonic', lambda: clock[0]): + for gap in gaps: + p.render_frame() + clock[0] += gap + if p._measured_hz is not None: + break + assert p._measured_hz == pytest.approx(95.0) + + +def test_re_solving_the_pacing_drops_samples_timed_under_the_old_hold(): + p = _pipeline(FakeDM(refresh_hz=120.0), scroll_speed=90) + p._swap_times.extend([1.0, 1.01, 1.02]) + p._configure_scroll_helper() + assert len(p._swap_times) == 0 + + +def test_no_measurement_without_hardware(): + # Nothing blocks in the emulator, so swap gaps say nothing about a panel. + p = _pipeline(FakeDM(refresh_hz=120.0, hardware=False), scroll_speed=90) + frames = RenderPipeline.REFRESH_WARMUP_FRAMES + RenderPipeline.REFRESH_SAMPLES + 2 + _run_swaps(p, 1 / 50.0, frames) + assert p._measured_hz is None diff --git a/test/test_vegas_density.py b/test/test_vegas_density.py index 28e80a9c..34efcfb9 100644 --- a/test/test_vegas_density.py +++ b/test/test_vegas_density.py @@ -837,6 +837,10 @@ class TestCycleEndsBeforeWrap: return p def _advance_to(self, pipeline, distance): + # render_frame() steps before it checks, and a whole-pixel pace steps + # a fixed amount; start one step short so the checked frame is at + # `distance`. + distance -= pipeline.scroll_helper.fixed_pixels_per_frame or 0 pipeline.scroll_helper.total_distance_scrolled = distance pipeline.scroll_helper.scroll_position = float(distance) diff --git a/web_interface/templates/v3/partials/display.html b/web_interface/templates/v3/partials/display.html index 3859eda6..174411b5 100644 --- a/web_interface/templates/v3/partials/display.html +++ b/web_interface/templates/v3/partials/display.html @@ -523,7 +523,7 @@
- +