"""Rolling pipeline timing metrics emitted to the runtime log. Three independent samples are accumulated: * acquisition — `capture_end_ns - capture_start_ns` from each raw sweep * processing — `processing_duration_ns` from each result collection * rendering — wall time of the Python render call Each metric flushes an averaged report to a caller-supplied logger as soon as its rolling buffer reaches `report_every` samples (default 50). Metrics are strictly read-only: malformed or missing input is silently ignored so a busy pipeline never blocks on a stray sample. """ from __future__ import annotations from collections import deque from dataclasses import dataclass import logging from typing import Callable, Iterable logger = logging.getLogger(__name__) @dataclass(frozen=True, slots=True) class MetricReport: """Summary of one rolling-window flush. All durations are in nanoseconds. `n` is the number of samples that fed the summary — never less than 1. `min_ns` / `max_ns` mark the extremes of the window so spikes are visible even when the average stays calm. """ name: str n: int avg_ns: int min_ns: int max_ns: int def format_ms(self) -> str: """Format the summary as a one-line `ms`-scaled log message.""" return ( f"metrics: {self.name} n={self.n} " f"avg={self.avg_ns / 1_000_000:.2f}ms " f"min={self.min_ns / 1_000_000:.2f}ms " f"max={self.max_ns / 1_000_000:.2f}ms" ) class PipelineMetrics: """Accumulate per-stage durations and flush averaged reports. The caller supplies a `log_sink` (a function taking a single string) that receives one report line per flushed metric. Wiring `log_sink` to the GUI log writer keeps metric output co-located with the rest of the runtime log; routing it to `print` keeps the class trivially unit-testable. """ def __init__( self, *, report_every: int = 50, log_sink: Callable[[str], None] | None = None, ) -> None: """Create a collector with a flush threshold and optional log sink.""" if report_every < 1: raise ValueError("report_every must be >= 1") self._report_every = int(report_every) self._log_sink = log_sink self._buffers: dict[str, deque[int]] = {} logger.debug("PipelineMetrics init: report_every=%d", self._report_every) def set_log_sink(self, log_sink: Callable[[str], None] | None) -> None: """Reassign the log sink (used when the GUI log appears after init).""" self._log_sink = log_sink def record(self, name: str, duration_ns: int) -> MetricReport | None: """Append one sample. Return a flushed report if the buffer is full.""" if duration_ns <= 0: return None buffer = self._buffers.setdefault(name, deque()) buffer.append(int(duration_ns)) if len(buffer) < self._report_every: return None samples = list(buffer) buffer.clear() report = self._summarize(name, samples) if self._log_sink is not None: self._log_sink(report.format_ms()) return report def reset(self) -> None: """Discard all buffered samples without emitting a report.""" self._buffers.clear() @staticmethod def _summarize(name: str, samples: Iterable[int]) -> MetricReport: """Reduce a sample sequence to one report.""" sample_list = list(samples) total = sum(sample_list) count = len(sample_list) return MetricReport( name=name, n=count, avg_ns=total // count, min_ns=min(sample_list), max_ns=max(sample_list), )