Skip to content

Commit 3476104

Browse files
runtime: the deadline guard's teardown cannot be interrupted into leaking a timer (#121)
The last unverified finding from the 2026-08 sweep, recorded as "traced, never demonstrated". It is real, and it is demonstrated now: without this change the regression test records **six** further interrupts queued after the guard was released. `fire` queues its async exception while holding `lock`, so a guard already blocked on that same lock inside `disarm` is handed the exception the moment it acquires it -- at the next bytecode, which is before `armed` is cleared and before the re-armed timer is cancelled. `disarm` then propagated and the 50ms timer it was meant to cancel stayed alive, still reading `armed` as true, re-raising `NodeDeadlineExceeded` into that thread every 50ms for the life of the thread. On a pooled thread that is an unattributable crash in whatever ran next -- precisely what `test_no_interrupt_survives_the_node_that_earned_it` exists to rule out, reached by a path it did not cover. The lock was not the flaw. Both sides do take it, as the old comment said; what the lock cannot do is stop an asynchronous exception arriving between two bytecodes inside the critical section it protects. So the teardown is retried rather than abandoned, and clears `armed` outside the lock as a last resort -- that single store is what stops `fire` re-arming. Swallowing the interrupt there costs nothing: the guard decides the outcome from `state["fired"]` once `disarm` returns, and still raises on it. Mechanism 1 (SIGALRM) is not affected and is unchanged. CPython runs the Python-level handler at a bytecode boundary, so `setitimer(ITIMER_REAL, 0)` has already completed when the handler raises, and the existing `finally` restores the handler and releases the slot. Two notes on getting the test to say something true, since the first two attempts did not. Raising from `Timer.cancel` proves nothing -- by then `armed` is already false, so `fire` returns early and no timer leaks; that version passed without the fix. And raising from the lock's `__enter__` holds the lock forever, which deadlocks the very timer under test instead of letting it spin, reporting a clean zero for the wrong reason. The interrupt has to be delivered the way CPython delivers it: inside the `with` body, with the block's exit releasing the lock. Verified: 120 tests across the budget, async-kernel and lease files, ruff clean, figure refreshed to 2,190. Red without the fix, green with it. Co-authored-by: Claude Opus 5 (1M context) <noreply@anthropic.com>
1 parent 652d979 commit 3476104

3 files changed

Lines changed: 147 additions & 6 deletions

File tree

‎docs/deep-dive.md‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -254,7 +254,7 @@ A stable system is not one that claims to have no edges — it is one whose edge
254254
- **`.env` and `grapharc.toml` follow the same discovery rule: the working directory, and nowhere else.** Neither searches parent directories — a run must not be governed by a file you did not know about, and must not be *billed* to one either. **This is a behaviour change:** the credential loader used to walk up to `/`, so a `.env` in an ancestor directory (a `$HOME` one on a shared box, a client project one above a demo checkout) was picked up silently. If you relied on that, move the file into the directory you run from, `export` the variable, or pass `env_file=` to name it explicitly. A real environment variable still beats any file.
255255
- **`grapharc run` has no budget unless you give it one.** Set any of `--max-tokens`, `--max-iterations`, `--max-seconds`, or `--max-concurrency`; without them each dimension is unlimited and the gate admits a topology of any worst-case cost.
256256

257-
**Verified this pass:** `pytest` → green, 2,189 selected and 13 deselected (the live ones); `ruff check .` clean; all eight `grapharc demo` stages green, plus the `trace` / `metrics` / `viz` / `replay` tour against a freshly recorded demo trace; the wheel builds and imports all submodules in a clean virtualenv with `[all]`, and `0.1.7` on PyPI is that wheel. The counts are a snapshot, not a property of the project — `pytest` re-derives them in one command, which is the only reason they are quoted, and `tests/test_deep_dive.py` fails this line rather than letting it drift.
257+
**Verified this pass:** `pytest` → green, 2,190 selected and 13 deselected (the live ones); `ruff check .` clean; all eight `grapharc demo` stages green, plus the `trace` / `metrics` / `viz` / `replay` tour against a freshly recorded demo trace; the wheel builds and imports all submodules in a clean virtualenv with `[all]`, and `0.1.7` on PyPI is that wheel. The counts are a snapshot, not a property of the project — `pytest` re-derives them in one command, which is the only reason they are quoted, and `tests/test_deep_dive.py` fails this line rather than letting it drift.
258258

259259
[ROADMAP.md](../ROADMAP.md) tracks what is built and what is not, item by item.
260260

‎grapharc/runtime/budget.py‎

Lines changed: 40 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -333,6 +333,13 @@ def snapshot(self) -> dict[str, float | int]:
333333
# node alive; the cost while a node is being torn down is one timer per 50ms.
334334
_REARM_SECONDS = 0.05
335335

336+
#: How many times a mechanism-2 teardown may be interrupted before it stops
337+
#: retrying and clears the flag outside the lock. Two is already generous --
338+
#: once `armed` is false `fire` returns without re-arming, so no further
339+
#: exception is queued -- and the loop exists for the interrupt that lands
340+
#: *inside* the teardown, not for a steady stream of them.
341+
_DISARM_ATTEMPTS = 8
342+
336343
# The longest delay both mechanisms can actually be armed with. `setitimer`
337344
# raises `OverflowError` past the platform's `time_t` (~2**31 seconds), and
338345
# `threading.Timer` accepts a larger value but crashes its own thread once the
@@ -487,11 +494,39 @@ def rearm(delay: float) -> None:
487494
rearm(armable)
488495

489496
def disarm() -> None:
490-
with lock:
491-
state["armed"] = False
492-
state["timer"].cancel()
493-
if state["fired"]:
494-
_async_raise(thread_id, None)
497+
# An interrupt can land *inside* this teardown, and used to leave a
498+
# timer running for the life of the thread. `fire` queues the async
499+
# exception while holding `lock`, so a guard already blocked on
500+
# `lock` here is handed it the moment it acquires the lock -- at the
501+
# next bytecode, which is before `armed` is cleared and before the
502+
# re-armed timer is cancelled. Letting that propagate left a live
503+
# 50ms timer whose `fire` still read `armed` as true, so it raised
504+
# `NodeDeadlineExceeded` into this thread every 50ms, indefinitely,
505+
# long after the run that armed it had finished. On a pooled thread
506+
# that is an unattributable crash in whatever ran next -- the exact
507+
# failure `test_no_interrupt_survives_the_node_that_earned_it`
508+
# exists to rule out, arriving by a path it did not cover.
509+
#
510+
# So the teardown is retried rather than abandoned. Swallowing the
511+
# interrupt costs nothing: the guard decides the outcome from
512+
# `state["fired"]` once this returns, and raises on it.
513+
for _ in range(_DISARM_ATTEMPTS):
514+
try:
515+
with lock:
516+
state["armed"] = False
517+
state["timer"].cancel()
518+
if state["fired"]:
519+
_async_raise(thread_id, None)
520+
return
521+
except NodeDeadlineExceeded:
522+
# An interrupt landing here *is* the deadline firing.
523+
state["fired"] = True
524+
# Last resort. Clearing `armed` is the single store that stops
525+
# `fire` re-arming, so it is done outside the lock rather than
526+
# risking another interrupt on the way to it.
527+
state["armed"] = False
528+
state["timer"].cancel()
529+
_async_raise(thread_id, None)
495530

496531
try:
497532
try:

‎tests/test_budget_enforcement.py‎

Lines changed: 106 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -35,12 +35,14 @@
3535
import threading
3636
import time
3737
from typing import Annotated
38+
from unittest import mock
3839

3940
import pytest
4041
from langchain_core.messages import AIMessage, HumanMessage
4142
from pydantic import BaseModel
4243

4344
from grapharc.runtime.budget import (
45+
_REARM_SECONDS,
4446
Budget,
4547
BudgetExceeded,
4648
BudgetMeter,
@@ -741,3 +743,107 @@ def spend(state: State) -> dict:
741743
assert metrics.errors == 1
742744
# The cost report and the audit trail must never disagree.
743745
assert replay(trace, run_id).tokens == metrics.tokens
746+
747+
748+
def test_an_interrupt_landing_inside_the_teardown_leaves_no_timer_running():
749+
"""The teardown race, and the leak it left behind.
750+
751+
`fire` queues its async exception *while holding the lock*, so a guard
752+
already blocked on that same lock inside `disarm` is handed the exception
753+
the moment it acquires it — at the next bytecode, which is before `armed`
754+
is cleared and before the re-armed timer is cancelled. `disarm` then
755+
propagated, leaving a live 50 ms timer whose `fire` still read `armed` as
756+
true: it re-raised into this thread every 50 ms for the life of the thread,
757+
long after the run that armed it had finished. On a pooled thread that is
758+
an unattributable crash in whatever ran next.
759+
760+
Forcing the interleaving needs the exception delivered at exactly that
761+
point, so the lock is wrapped and raises on the guard thread's *second*
762+
entry — the first is the initial arm, the second is `disarm`. It releases
763+
before raising, because a real async exception lands inside the `with` body
764+
and that block's exit releases the lock; raising from `__enter__` instead
765+
would hold the lock forever and deadlock the very timer under test rather
766+
than letting it spin.
767+
768+
The harm is then measured the way a caller feels it: whether anything is
769+
still interrupting this thread once the guard has been released. Without the
770+
retry in `disarm` this records six further interrupts; with it, none.
771+
"""
772+
from grapharc.runtime import budget as budget_module
773+
774+
worker = {}
775+
calls: list[object] = []
776+
has_fired = threading.Event()
777+
real_lock = threading.Lock
778+
779+
# Recorded, not delivered: injecting into the test runner's own thread would
780+
# surface as an unrelated crash somewhere later in the session.
781+
monkey = mock.patch.object(
782+
budget_module, "_async_raise", lambda thread_id, exc: calls.append(exc)
783+
)
784+
785+
class InterruptingLock:
786+
"""A lock that delivers the deadline interrupt inside `disarm`."""
787+
788+
def __init__(self) -> None:
789+
self._lock = real_lock()
790+
self._guard_entries = 0
791+
792+
def __getattr__(self, name): # Condition and Event poke at locked() etc.
793+
return getattr(self._lock, name)
794+
795+
def acquire(self, *args, **kwargs):
796+
return self._lock.acquire(*args, **kwargs)
797+
798+
def release(self):
799+
return self._lock.release()
800+
801+
def __enter__(self):
802+
self._lock.acquire()
803+
if threading.get_ident() == worker.get("id"):
804+
self._guard_entries += 1
805+
if self._guard_entries == 2 and has_fired.is_set():
806+
self._lock.release()
807+
raise NodeDeadlineExceeded("delivered inside the teardown")
808+
return self
809+
810+
def __exit__(self, *exc_info):
811+
self._lock.release()
812+
return False
813+
814+
class NotingTimer(threading.Timer):
815+
"""Records that `fire` has run at least once, so the interrupt is
816+
delivered to a teardown that actually has a re-armed timer to lose."""
817+
818+
def run(self):
819+
has_fired.set()
820+
return super().run()
821+
822+
def body():
823+
worker["id"] = threading.get_ident()
824+
meter = BudgetMeter(Budget(max_seconds=0.1))
825+
try:
826+
with deadline_guard(meter, what="worker"):
827+
time.sleep(0.4) # past the deadline, so the timer fires and re-arms
828+
except NodeDeadlineExceeded:
829+
pass
830+
831+
with (
832+
monkey,
833+
mock.patch.object(budget_module.threading, "Lock", InterruptingLock),
834+
mock.patch.object(budget_module.threading, "Timer", NotingTimer),
835+
):
836+
thread = threading.Thread(target=body)
837+
thread.start()
838+
thread.join(timeout=10)
839+
assert not thread.is_alive()
840+
assert has_fired.is_set(), "the timer never fired; the race was not exercised"
841+
842+
settled = len(calls)
843+
time.sleep(6 * _REARM_SECONDS)
844+
845+
assert len(calls) == settled, (
846+
f"{len(calls) - settled} interrupt(s) queued after the guard was "
847+
"released: a re-armed timer outlived its teardown and will keep "
848+
"raising into this thread"
849+
)

0 commit comments

Comments
 (0)