From d754847d8bae27fea6e740e1b08ea99cb0f1ea6a Mon Sep 17 00:00:00 2001 From: ChuckBuilds Date: Wed, 12 Aug 2026 08:45:06 -0400 Subject: [PATCH] fix(vegas): let the watchdog see stalls that hold the GIL The watchdog only noticed a late heartbeat, which a whole class of freeze can never produce: if the loop is inside one long C call that holds the GIL, this thread cannot run during the stall, and by the time it does the loop has already checked in. On the dev rig that hid a recurring 3.2s freeze completely -- twenty minutes of watching produced one dump, for an unrelated 0.4s stall. What it can still observe is that its own sleep ran long. A badly overshot wait is now reported as a stall in its own right. The stacks are stale by then and the message says so, but knowing the freeze is GIL-holding is most of the diagnosis: it rules out lock contention and scheduling, and points at a single long C call. This also explains why lowering sys.setswitchinterval changed nothing -- the switch interval cannot preempt a C call that never releases the GIL. Co-Authored-By: Claude Opus 5 (1M context) Claude-Session: https://claude.ai/code/session_01Udr6MfaFLUPhX5Fgo67Jf5 --- src/vegas_mode/coordinator.py | 25 ++++++++++++++++++++++--- 1 file changed, 22 insertions(+), 3 deletions(-) diff --git a/src/vegas_mode/coordinator.py b/src/vegas_mode/coordinator.py index 59f57743..196f7f7d 100644 --- a/src/vegas_mode/coordinator.py +++ b/src/vegas_mode/coordinator.py @@ -71,11 +71,30 @@ class _StallWatchdog: self._stop.set() def _watch(self) -> None: - while not self._stop.wait(self.threshold / 4.0): + poll = self.threshold / 4.0 + while True: + woke_at = time.time() + if self._stop.wait(poll): + break with self._lock: last = self._beat - stalled = time.time() - last - if stalled < self.threshold or last == self._dumped_for: + now = time.time() + stalled = now - last + # A stall inside a C call that holds the GIL never shows up as a + # late beat: this thread cannot run during it, and by the time it + # does the loop has already checked in. What it can see is that + # its own sleep ran long. Treat a badly overshot wait as a stall + # in its own right -- the stacks are stale by then, but knowing + # the freeze is GIL-holding is itself the diagnosis. + overshoot = (now - woke_at) - poll + if overshoot > self.threshold: + logger.warning( + "render loop stalled %.2fs holding the GIL -- no Python " + "frames ran, so the stacks below are from after it ended; " + "look for one long C call (a large PIL operation, a " + "compress, a big allocation)", overshoot) + stalled = overshoot + elif stalled < self.threshold or last == self._dumped_for: continue self._dumped_for = last # one dump per stall, not per poll frames = sys._current_frames()