WIP: profiling
This commit is contained in:
@@ -2,7 +2,8 @@ from __future__ import annotations
|
||||
import time
|
||||
import psutil
|
||||
import threading
|
||||
from typing import Any, Optional, Callable
|
||||
from typing import Any, Optional, Callable, Dict, List
|
||||
from collections import deque
|
||||
|
||||
_instance: Optional[PerformanceMonitor] = None
|
||||
|
||||
@@ -15,24 +16,36 @@ def get_monitor() -> PerformanceMonitor:
|
||||
class PerformanceMonitor:
|
||||
"""
|
||||
Tracks application performance metrics like FPS, frame time, and CPU usage.
|
||||
Also supports tracking timing for individual components.
|
||||
Supports thread-safe tracking for individual components with efficient moving averages.
|
||||
"""
|
||||
def __init__(self) -> None:
|
||||
def __init__(self, history_size: int = 300) -> None:
|
||||
self.enabled: bool = False
|
||||
self.history_size = history_size
|
||||
self._lock = threading.Lock()
|
||||
|
||||
self._start_time: Optional[float] = None
|
||||
self._last_frame_start_time: float = 0.0
|
||||
self._last_frame_time: float = 0.0
|
||||
self._fps: float = 0.0
|
||||
self._last_calculated_fps: float = 0.0
|
||||
self._frame_count: int = 0
|
||||
self._fps_timer: float = 0.0
|
||||
self._cpu_percent: float = 0.0
|
||||
self._last_cpu_time: float = 0.0
|
||||
self._input_lag_ms: float = 0.0
|
||||
|
||||
self._component_starts: dict[str, float] = {}
|
||||
self._component_timings: dict[str, float] = {}
|
||||
|
||||
# Thread for CPU monitoring to avoid blocking the main thread
|
||||
# Rolling history and running sums for O(1) average calculation
|
||||
# deques are thread-safe for appends and pops.
|
||||
self._history: Dict[str, deque[float]] = {}
|
||||
self._history_sums: Dict[str, float] = {}
|
||||
|
||||
# For slowing down graph updates
|
||||
self._last_sample_time = 0.0
|
||||
self._sample_interval = 0.1 # 100ms
|
||||
|
||||
# Thread for CPU monitoring
|
||||
self._stop_event = threading.Event()
|
||||
self._cpu_thread = threading.Thread(target=self._monitor_cpu, daemon=True)
|
||||
self._cpu_thread.start()
|
||||
@@ -40,48 +53,126 @@ class PerformanceMonitor:
|
||||
def _monitor_cpu(self) -> None:
|
||||
while not self._stop_event.is_set():
|
||||
try:
|
||||
self._cpu_percent = psutil.cpu_percent(interval=None)
|
||||
val = psutil.cpu_percent(interval=None)
|
||||
with self._lock:
|
||||
self._cpu_percent = val
|
||||
except Exception:
|
||||
pass
|
||||
time.sleep(1.0)
|
||||
|
||||
def _add_to_history(self, key: str, value: float) -> None:
|
||||
"""Thread-safe O(1) history update."""
|
||||
with self._lock:
|
||||
if key not in self._history:
|
||||
self._history[key] = deque(maxlen=self.history_size)
|
||||
self._history_sums[key] = 0.0
|
||||
|
||||
h = self._history[key]
|
||||
if len(h) == self.history_size:
|
||||
removed = h[0] # peek left
|
||||
self._history_sums[key] -= removed
|
||||
|
||||
self._history_sums[key] += value
|
||||
h.append(value)
|
||||
|
||||
def _get_avg(self, key: str) -> float:
|
||||
"""Thread-safe O(1) average retrieval."""
|
||||
with self._lock:
|
||||
h = self._history.get(key)
|
||||
if not h or len(h) == 0:
|
||||
return 0.0
|
||||
return self._history_sums[key] / len(h)
|
||||
|
||||
def start_frame(self) -> None:
|
||||
self._start_time = time.time()
|
||||
self._frame_count += 1
|
||||
now = time.time()
|
||||
with self._lock:
|
||||
if self._last_frame_start_time > 0:
|
||||
dt = now - self._last_frame_start_time
|
||||
if dt > 0:
|
||||
self._fps = 1.0 / dt
|
||||
self._last_frame_start_time = now
|
||||
self._start_time = now
|
||||
self._frame_count += 1
|
||||
|
||||
def end_frame(self) -> None:
|
||||
if self._start_time is None:
|
||||
return
|
||||
now = time.time()
|
||||
elapsed = now - self._start_time
|
||||
self._last_frame_time = elapsed * 1000 # convert to ms
|
||||
frame_time_ms = elapsed * 1000
|
||||
|
||||
with self._lock:
|
||||
self._last_frame_time = frame_time_ms
|
||||
cpu = self._cpu_percent
|
||||
ilag = self._input_lag_ms
|
||||
fps = self._fps
|
||||
|
||||
# Slow down history sampling for core metrics
|
||||
if now - self._last_sample_time >= self._sample_interval:
|
||||
self._last_sample_time = now
|
||||
self._add_to_history('frame_time_ms', frame_time_ms)
|
||||
self._add_to_history('cpu_percent', cpu)
|
||||
self._add_to_history('input_lag_ms', ilag)
|
||||
self._add_to_history('fps', fps)
|
||||
|
||||
self._fps_timer += elapsed
|
||||
if self._fps_timer >= 1.0:
|
||||
self._last_calculated_fps = self._frame_count / self._fps_timer
|
||||
self._frame_count = 0
|
||||
self._fps_timer = 0.0
|
||||
with self._lock:
|
||||
self._last_calculated_fps = self._frame_count / self._fps_timer
|
||||
self._frame_count = 0
|
||||
self._fps_timer = 0.0
|
||||
|
||||
def start_component(self, name: str) -> None:
|
||||
self._component_starts[name] = time.time()
|
||||
if not self.enabled: return
|
||||
now = time.time()
|
||||
with self._lock:
|
||||
self._component_starts[name] = now
|
||||
|
||||
def end_component(self, name: str) -> None:
|
||||
if name in self._component_starts:
|
||||
elapsed = (time.time() - self._component_starts.pop(name)) * 1000
|
||||
self._component_timings[name] = elapsed
|
||||
if not self.enabled: return
|
||||
now = time.time()
|
||||
with self._lock:
|
||||
start = self._component_starts.pop(name, None)
|
||||
if start is not None:
|
||||
elapsed = (now - start) * 1000
|
||||
with self._lock:
|
||||
self._component_timings[name] = elapsed
|
||||
self._add_to_history(f'comp_{name}', elapsed)
|
||||
|
||||
def get_metrics(self) -> dict[str, float]:
|
||||
"""Returns current metrics and their moving averages. Thread-safe."""
|
||||
with self._lock:
|
||||
fps = self._fps
|
||||
last_ft = self._last_frame_time
|
||||
cpu = self._cpu_percent
|
||||
ilag = self._input_lag_ms
|
||||
last_calc_fps = self._last_calculated_fps
|
||||
timings_snapshot = dict(self._component_timings)
|
||||
|
||||
metrics = {
|
||||
'fps': self._last_calculated_fps,
|
||||
'last_frame_time_ms': self._last_frame_time,
|
||||
'cpu_percent': self._cpu_percent,
|
||||
'input_lag_ms': self._input_lag_ms
|
||||
'fps': fps,
|
||||
'fps_avg': self._get_avg('fps'),
|
||||
'last_frame_time_ms': last_ft,
|
||||
'frame_time_ms_avg': self._get_avg('frame_time_ms'),
|
||||
'cpu_percent': cpu,
|
||||
'cpu_percent_avg': self._get_avg('cpu_percent'),
|
||||
'input_lag_ms': ilag,
|
||||
'input_lag_ms_avg': self._get_avg('input_lag_ms')
|
||||
}
|
||||
# Add detailed timings
|
||||
for name, elapsed in list(self._component_timings.items()):
|
||||
for name, elapsed in timings_snapshot.items():
|
||||
metrics[f'time_{name}_ms'] = elapsed
|
||||
metrics[f'time_{name}_ms_avg'] = self._get_avg(f'comp_{name}')
|
||||
return metrics
|
||||
|
||||
def get_history(self, key: str) -> List[float]:
|
||||
"""Returns a snapshot of the full history buffer for a specific metric key."""
|
||||
with self._lock:
|
||||
if key in self._history:
|
||||
return list(self._history[key])
|
||||
if f'comp_{key}' in self._history:
|
||||
return list(self._history[f'comp_{key}'])
|
||||
return []
|
||||
|
||||
def stop(self) -> None:
|
||||
self._stop_event.set()
|
||||
if self._cpu_thread.is_alive():
|
||||
|
||||
Reference in New Issue
Block a user