diff --git a/assets/sports/soccer_logos/MAN.png b/assets/sports/soccer_logos/MAN.png new file mode 100644 index 00000000..b957f61d Binary files /dev/null and b/assets/sports/soccer_logos/MAN.png differ diff --git a/assets/sports/soccer_logos/MNC.png b/assets/sports/soccer_logos/MNC.png new file mode 100644 index 00000000..3e0a8cdc Binary files /dev/null and b/assets/sports/soccer_logos/MNC.png differ diff --git a/src/common/scroll_helper.py b/src/common/scroll_helper.py index 4f2e215e..6e2f4218 100644 --- a/src/common/scroll_helper.py +++ b/src/common/scroll_helper.py @@ -328,7 +328,11 @@ class ScrollHelper: elapsed_time = current_time - (self.scroll_start_time or current_time) # The image already includes display_width padding, so we only need total_scroll_width required_total_distance = self.total_scroll_width - self.logger.info( + # Progress telemetry, emitted every few seconds for the whole of + # every scroll. It says how far along a marquee is, which is what + # you turn debug on to watch and not something an operator needs + # in the journal on a device that scrolls all day. + self.logger.debug( "Scroll progress: elapsed=%.2fs, target=%.2fs, total_scrolled=%.0f/%d px (%.1f%%)", elapsed_time, self.calculated_duration, diff --git a/src/vegas_mode/coordinator.py b/src/vegas_mode/coordinator.py index 430cbef6..92980ef3 100644 --- a/src/vegas_mode/coordinator.py +++ b/src/vegas_mode/coordinator.py @@ -31,6 +31,14 @@ if TYPE_CHECKING: logger = logging.getLogger(__name__) +#: A frame rate this close to target is not news; below it is. +_FPS_HEALTHY_FRACTION = 0.9 + +#: A healthy marquee still reports this often, so silence means stopped +#: rather than fine. +_FPS_HEARTBEAT_INTERVAL = 300.0 + + def _percentile(ordered: List[float], fraction: float) -> float: """Nearest-rank percentile of an already-sorted list. @@ -395,7 +403,9 @@ class VegasModeCoordinator: duration = self.render_pipeline.get_dynamic_duration() start_time = time.time() frame_count = 0 - fps_log_interval = 5.0 # Log FPS every 5 seconds + fps_log_interval = 5.0 # Sample FPS every 5 seconds + last_fps_health_log = 0.0 # last INFO-level report + was_degraded = False # so the recovery is reported too last_fps_log_time = start_time fps_frame_count = 0 # A mean hides stutter completely. At 120fps a five-second window is @@ -448,16 +458,36 @@ class VegasModeCoordinator: frame_count += 1 fps_frame_count += 1 - # Periodic FPS logging + # Periodic FPS logging. Reported at INFO only when the frame rate + # is actually worth an operator's attention -- a shortfall against + # target, or the recovery from one -- with a slow heartbeat so a + # healthy marquee still shows a pulse. + # + # Measured over two hours on a running rig: 1410 samples, 98.5% + # of them within 10% of target. The 1.5% that were not included a + # reading of 8.6fps against a target of 60 -- a real stall, and + # completely invisible inside 1389 lines reading "59.6". current_time = time.time() 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) - logger.info( - "Vegas FPS: %.1f (target: %d, frames: %d) p99 %.1fms worst %.1fms", - fps, self.vegas_config.target_fps, fps_frame_count, - p99 * 1000.0, frame_worst * 1000.0 - ) + target = self.vegas_config.target_fps + degraded = target > 0 and fps < target * _FPS_HEALTHY_FRACTION + due = current_time - last_fps_health_log >= _FPS_HEARTBEAT_INTERVAL + if degraded or was_degraded or due: + logger.info( + "Vegas FPS: %.1f (target: %d, frames: %d) p99 %.1fms worst %.1fms", + fps, target, fps_frame_count, + p99 * 1000.0, frame_worst * 1000.0 + ) + last_fps_health_log = current_time + else: + logger.debug( + "Vegas FPS: %.1f (target: %d, frames: %d) p99 %.1fms worst %.1fms", + fps, target, fps_frame_count, + p99 * 1000.0, frame_worst * 1000.0 + ) + was_degraded = degraded last_fps_log_time = current_time fps_frame_count = 0 frame_worst = 0.0