From 76ad71d1c56370b53302b72554e7f3edf0d28e03 Mon Sep 17 00:00:00 2001 From: Chuck <33324927+ChuckBuilds@users.noreply.github.com> Date: Sat, 3 Oct 2026 11:51:06 -0400 Subject: [PATCH] fix(frame-timing): keep the GC monitor quiet at interpreter shutdown (#734) A collection during interpreter shutdown called GcMonitor after the module's `time` global was torn down, printing "Exception ignored while calling GC callback ... 'NoneType' object has no attribute 'perf_counter'" at the end of service and test runs. - GcMonitor binds its clock and sys.is_finalizing at construction and does nothing once the interpreter is finalizing. - install_gc_monitor() unregisters it with atexit; new uninstall_gc_monitor(). - DisplayManager.cleanup() (reached from SIGTERM via run()'s finally) unregisters it alongside the frame recorder. Co-authored-by: Claude Opus 5.5 --- CHANGELOG.md | 10 ++++++ src/common/frame_timing.py | 41 +++++++++++++++++++-- src/display_manager.py | 5 ++- test/test_display_manager.py | 12 +++++++ test/test_frame_timing.py | 70 +++++++++++++++++++++++++++++++++++- 5 files changed, 133 insertions(+), 5 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 7bb6ea06..7b00a972 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -242,6 +242,16 @@ policies are unchanged. ### Fixes +- The garbage-collection timer (`GcMonitor`, above) no longer prints + `Exception ignored while calling GC callback ... 'NoneType' object has no + attribute 'perf_counter'` when the display service or a test run exits. + A collection during interpreter shutdown called it after the module's + `time` global was torn down. The monitor now binds its clock at + construction and does nothing once `sys.is_finalizing()`; + `install_gc_monitor()` unregisters it with `atexit`, and + `DisplayManager.cleanup()` (reached from SIGTERM through `run()`'s + `finally`) unregisters it with the frame recorder. New + `frame_timing.uninstall_gc_monitor()`. - A plugin reload after a store update (`plugin.reload`, #720) no longer freezes the panel during Vegas. On ledpi a football reload froze it for 3.0 s (`Render stall over: no frame for 3043ms`). The reload ran on the diff --git a/src/common/frame_timing.py b/src/common/frame_timing.py index a97d3a1c..4c0edbdc 100644 --- a/src/common/frame_timing.py +++ b/src/common/frame_timing.py @@ -121,6 +121,7 @@ three times per threshold, so keep it to diagnostic runs, not soaks. from __future__ import annotations +import atexit import copy import gc import json @@ -213,10 +214,19 @@ class GcMonitor: lock: the render thread and the stats writer only read them. Install it once per process with :func:`install_gc_monitor`. + + Collections still run while the interpreter shuts down, after module + globals such as ``time`` may already be torn down to ``None``. The clock + and ``sys.is_finalizing`` are bound here so the callback never looks a + global up, it does nothing once finalization has begun, and + :func:`install_gc_monitor` unregisters it at exit anyway. """ - def __init__(self, threshold: float = GC_PAUSE_SECONDS): + def __init__(self, threshold: float = GC_PAUSE_SECONDS, + clock: Callable[[], float] = time.perf_counter): self.threshold = threshold + self._clock = clock + self._is_finalizing = sys.is_finalizing self._started: Optional[float] = None #: Per generation (0, 1, 2), since the monitor was installed. self.collections = [0, 0, 0] @@ -232,7 +242,9 @@ class GcMonitor: self.last_long: Optional[Tuple[float, float]] = None def __call__(self, phase: str, info: Dict[str, Any]) -> None: - now = time.perf_counter() + if self._is_finalizing(): + return + now = self._clock() if phase == "start": self._started = now return @@ -267,15 +279,38 @@ _gc_monitor_lock = threading.Lock() def install_gc_monitor() -> GcMonitor: - """The process's GcMonitor, installed in ``gc.callbacks`` on first call.""" + """The process's GcMonitor, installed in ``gc.callbacks`` on first call. + + It is unregistered at exit (:func:`uninstall_gc_monitor`), before the + interpreter tears module globals down. + """ global _gc_monitor with _gc_monitor_lock: if _gc_monitor is None: _gc_monitor = GcMonitor() gc.callbacks.append(_gc_monitor) + atexit.register(uninstall_gc_monitor) return _gc_monitor +def uninstall_gc_monitor() -> None: + """Take the process's GcMonitor out of ``gc.callbacks``; safe to repeat. + + A recorder that still holds the monitor keeps its counters; they just + stop moving. The next :func:`install_gc_monitor` installs a fresh one. + """ + global _gc_monitor + with _gc_monitor_lock: + monitor, _gc_monitor = _gc_monitor, None + if monitor is None: + return + atexit.unregister(uninstall_gc_monitor) + try: + gc.callbacks.remove(monitor) + except ValueError: + pass + + #: One presented frame's interval: (interval, blit, wait, hold, ops), where #: ops is the work noted before it (kind -> bytes) or None. _Frame = Tuple[float, float, float, int, Optional[Dict[str, int]]] diff --git a/src/display_manager.py b/src/display_manager.py index dcae7d96..3e211e9f 100644 --- a/src/display_manager.py +++ b/src/display_manager.py @@ -57,7 +57,8 @@ import freetype from src.common import snapshot_policy from src import display_watchdog -from src.common.frame_timing import FrameTimingRecorder, install_gc_monitor +from src.common.frame_timing import ( + FrameTimingRecorder, install_gc_monitor, uninstall_gc_monitor) if TYPE_CHECKING: from src.common.render_gate import RenderGate @@ -1407,6 +1408,8 @@ class DisplayManager: # The stall watchdog would otherwise outlive this manager. if getattr(self, 'frame_timing', None) is not None: self.frame_timing.close() + # Installed with the recorder; stop timing collections with it. + uninstall_gc_monitor() # Reset the singleton state when cleaning up DisplayManager._instance = None diff --git a/test/test_display_manager.py b/test/test_display_manager.py index 747bdfd8..3bb774c2 100644 --- a/test/test_display_manager.py +++ b/test/test_display_manager.py @@ -118,6 +118,18 @@ class TestDisplayManagerResourceManagement: dm.matrix.Clear.assert_called() + def test_cleanup_takes_the_gc_monitor_out_of_gc_callbacks( + self, test_config, mock_rgb_matrix): + """The service stops (SIGTERM -> run()'s finally -> cleanup()) with + its collection timer unregistered, not left for interpreter teardown.""" + import gc + with patch.dict('os.environ', {'EMULATOR': 'false'}): + dm = DisplayManager(test_config) + monitor = dm.frame_timing.gc_monitor + assert monitor in gc.callbacks + dm.cleanup() + assert monitor not in gc.callbacks + class TestDisplayManagerDoubleSided: """Double-sided mode: render once at logical size, tile across the chain.""" diff --git a/test/test_frame_timing.py b/test/test_frame_timing.py index f9df04c4..e6610ddf 100644 --- a/test/test_frame_timing.py +++ b/test/test_frame_timing.py @@ -626,7 +626,7 @@ def test_render_bench_strip_lights_a_real_share_of_pixels(): def _collection(monitor, monkeypatch, start, took, generation=2): """One collection of ``took`` seconds, as gc.callbacks would report it.""" clock = iter([start, start + took]) - monkeypatch.setattr(frame_timing.time, "perf_counter", lambda: next(clock)) + monkeypatch.setattr(monitor, "_clock", lambda: next(clock)) monitor("start", {"generation": generation}) monitor("stop", {"generation": generation, "collected": 0, "uncollectable": 0}) monkeypatch.undo() @@ -739,3 +739,71 @@ def test_installing_the_gc_monitor_twice_installs_it_once(): first = frame_timing.install_gc_monitor() assert frame_timing.install_gc_monitor() is first assert sum(1 for cb in gc.callbacks if cb is first) == 1 + + +def test_uninstalling_the_gc_monitor_removes_it_and_can_repeat(): + import gc + first = frame_timing.install_gc_monitor() + frame_timing.uninstall_gc_monitor() + frame_timing.uninstall_gc_monitor() + assert first not in gc.callbacks + second = frame_timing.install_gc_monitor() + assert second is not first + assert sum(1 for cb in gc.callbacks if cb is second) == 1 + + +def test_the_gc_monitor_needs_no_module_globals(monkeypatch): + # At shutdown, module globals can be torn down to None while a collection + # still calls the monitor ("'NoneType' object has no attribute + # 'perf_counter'"). Its clock is bound at construction. + monitor = frame_timing.GcMonitor(threshold=0.0) + monkeypatch.setattr(frame_timing, "time", None) + monkeypatch.setattr(frame_timing, "sys", None) + monitor("start", {"generation": 2}) + monitor("stop", {"generation": 2}) + assert monitor.collections == [0, 0, 1] + + +def test_the_gc_monitor_does_nothing_once_the_interpreter_is_finalizing(monkeypatch): + monitor = frame_timing.GcMonitor(threshold=0.0) + monkeypatch.setattr(monitor, "_is_finalizing", lambda: True) + monkeypatch.setattr(monitor, "_clock", lambda: pytest.fail("clock read")) + monitor("start", {"generation": 2}) + monitor("stop", {"generation": 2}) + assert monitor.collections == [0, 0, 0] + + +_EXIT_SCRIPT = """ +import atexit, gc, sys +sys.path.insert(0, {root!r}) +from src.common import frame_timing + +# Registered before the monitor, so it runs after the monitor's own exit hook. +atexit.register(lambda: print("installed at exit:", any( + isinstance(cb, frame_timing.GcMonitor) for cb in gc.callbacks))) +monitor = frame_timing.install_gc_monitor() +gc.collect() +assert monitor.collections[2] >= 1 + +class Garbage: + # Makes cyclic garbage while modules are being torn down, so collections + # run during finalization. + def __del__(self): + for _ in range(5000): + cycle = [] + cycle.append(cycle) + +keep = Garbage() +keep.self = keep +""" + + +def test_a_process_with_the_gc_monitor_exits_cleanly(): + import subprocess + root = str(Path(__file__).resolve().parent.parent) + proc = subprocess.run( + [sys.executable, "-c", _EXIT_SCRIPT.format(root=root)], + capture_output=True, text=True, timeout=60) + assert proc.returncode == 0, proc.stderr + assert "Exception ignored" not in proc.stderr + assert "installed at exit: False" in proc.stdout