a lease may not wait in a thread (v0.4.19)

Third run, third failure, and this one was mine. A 5,000-document run
dispatched ZERO pages to 50 healthy pods in 41 minutes: not one
`POST /v1/ocr` in any pod's log, every GPU at `KV 0.0%`, 811 pages waiting,
and the scaler reading that unservable queue as demand and renting to 73
pods at $43/hr. `/healthz` answered in 1.6 ms the whole time, so the loop
fixes from 0.4.16/0.4.17 were holding and nothing looked wrong from outside.

0.4.18 bounded a lease attempt at 20 s and ran it on a 256-thread pool. That
made the LEASE STAGE the ceiling on everything: 256 threads at one attempt
per 20 s passes ~13 pages a second however many pods are up, and a thread
that drew the growth branch sat through an entire ~9-minute boot. Against
811 pages each retrying every couple of seconds, nothing got through.

So `acquire(grow_inline=False)`: answer now, or start growth in the
background and raise `NoPodRightNow`. The caller waits on its event loop,
where waiting is free, and `POD_LEASE_ATTEMPT_S` drops 20 s -> 2 s for the
pools whose acquire predates the flag. Threaded through
`placement.choose(grow_inline=)` by signature inspection, so a candidate
that cannot take it keeps working.

Demand had to survive that. `_waiting` only ever counted THREADS parked in
acquire, and the non-blocking path has none, so the pool would have stopped
growing. It now counts DENIALS over a window equal to the caller's retry
interval, which makes the count distinct waiting PAGES rather than the
attempts they have made between them -- a page retrying every 2 s appears
once in any 2-second window. A longer window multiplies demand by the retry
rate, which is how the same run read its own retries as new work.

Two more things found on the way:

  * `pod_weight`/`pod_capacity`/`pod_threshold` depend only on a card's NAME,
    but were recomputed per POD per acquire -- `_pick` once per free pod,
    `_pods_for_demand` once per serving pod, `_preferred_vram_gb` walking
    every pod inside each -- all under the pool lock. Memoised per card:
    measured 286us -> 69us per acquire at 70 pods, 528us -> 102us at 128. The
    memo self-initialises via getattr, because a pool built without __init__
    must not have an optimisation turn into an AttributeError.

  * `_pick` returned a bare None for four different causes -- no pods,
    none healthy, all draining, all at their in-flight cap -- which need
    opposite responses, and the caller could only report the queue it could
    not drain. It now says which, once per 15 s, with every count in the line.

I also mis-read `futex_do_wait` on 324 of 352 threads as lock contention. A
condition-variable wait IS a futex wait, so that is what pages legitimately
waiting for a pod look like. The pod logs settled it instead: zero POSTs
means the dispatch never happened, not that it was slow.
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01KnfkxBpcZ1v6ypRFFyhrVM

codai/__init__.py

@@ -16,7 +16,7 @@
 
 # Canonical product version for CoderAI — single source of truth. Both the API
 # metadata and the admin web UI read from here.
-__version__ = "0.4.18"
+__version__ = "0.4.19"
 __tagline__ = "Complete orchestration, distribution and escalation of remotizable advanced inference."
 
 # Configure the CUDA caching allocator BEFORE torch is imported anywhere.

codai/models/placement.py

@@ -399,9 +399,15 @@ def _spill_pod_candidate(model_id: str) -> Optional[Candidate]:
     if pool is None:
         return None
 
-    def _acquire(timeout: float = 0.0):
-        # The pool's own default (1200 s) unless the caller bounds the attempt.
-        pod, url = pool.acquire(timeout=timeout) if timeout > 0 else pool.acquire()
+    def _acquire(timeout: float = 0.0, grow_inline: bool = True):
+        # `grow_inline=False` is "answer now": no renting in this thread, no
+        # waiting on the pool's condvar. See PodPool.acquire.
+        if not grow_inline:
+            pod, url = pool.acquire(timeout=0.0, grow_inline=False)
+        elif timeout > 0:
+            pod, url = pool.acquire(timeout=timeout)
+        else:
+            pod, url = pool.acquire()
         key = getattr(pool, "api_key", "") or ""
         return (url.rstrip("/") + "/v1", key, lambda: pool.release(pod),
                 lambda: pool.discard(pod, "connection refused"))
@@ -475,7 +481,7 @@ def _load_of(cand: Candidate) -> int:
 
 
 def choose(model_id: str, spill_after: int = 0,
-           acquire_timeout: float = 0.0) -> Lease:
+           acquire_timeout: float = 0.0, grow_inline: bool = True) -> Lease:
     """A lease on the least-loaded server for the model.
 
     ``spill_after`` is the in-flight count at which a fixed server (the local one,
@@ -511,7 +517,7 @@ def choose(model_id: str, spill_after: int = 0,
     #    pages over the pods it has and grows when they are all at their
     #    threshold. This is "on runpod only", scaling.
     for cand in [c for c in cands if c.primary and c.acquire is not None]:
-        lease = _take(cand, acquire_timeout)
+        lease = _take(cand, acquire_timeout, grow_inline)
         if lease is not None:
             return lease
         last_exc = "pool unavailable"
@@ -533,7 +539,7 @@ def choose(model_id: str, spill_after: int = 0,
     # 3. Everything we own is busy: rent. This is "local + spillover" — the
     #    overflow goes to a pool instead of queueing behind a saturated GPU.
     for cand in pools:
-        lease = _take(cand, acquire_timeout)
+        lease = _take(cand, acquire_timeout, grow_inline)
         if lease is not None:
             return lease
         last_exc = "pool unavailable"
@@ -578,7 +584,16 @@ def _say_once(key: str, message: str, every: float = 30.0) -> None:
     print(message, flush=True)
 
 
-def _take(cand: Candidate, acquire_timeout: float = 0.0) -> Optional[Lease]:
+def _accepts_grow_inline(fn) -> bool:
+    try:
+        import inspect
+        return "grow_inline" in inspect.signature(fn).parameters
+    except Exception:
+        return False
+
+
+def _take(cand: Candidate, acquire_timeout: float = 0.0,
+          grow_inline: bool = True) -> Optional[Lease]:
     """Acquire a pool candidate, or None when it cannot provide a server.
 
     ``acquire_timeout`` bounds ONE attempt. A pool's acquire waits for a pod and
@@ -588,9 +603,12 @@ def _take(cand: Candidate, acquire_timeout: float = 0.0) -> Optional[Lease]:
     thread per page for the length of a boot. 0 keeps the pool's own default.
     """
     try:
-        got = (cand.acquire(timeout=acquire_timeout)
-               if acquire_timeout > 0 and _accepts_timeout(cand.acquire)
-               else cand.acquire())
+        if not grow_inline and _accepts_grow_inline(cand.acquire):
+            got = cand.acquire(grow_inline=False)
+        elif acquire_timeout > 0 and _accepts_timeout(cand.acquire):
+            got = cand.acquire(timeout=acquire_timeout)
+        else:
+            got = cand.acquire()
     except Exception as exc:
         _say_once(f"take:{cand.key}",
                   f"[ocr] {cand.key} cannot serve this page: {exc}")

codai/ocr/manager.py

@@ -744,13 +744,21 @@ def _pod_pipeline_policy(cfg) -> tuple:
 #: budget, or at its ceiling, stays that way for minutes: without this every
 #: page of every document would pay the full wait before going local, turning a
 #: 60s ceiling into a 60s tax per page.
-#: How long ONE lease attempt may hold a pod-pool thread. A pool's acquire
-#: waits for a free pod and may rent one inline, so an unbounded attempt parks a
-#: thread for a whole boot -- several minutes on a cold start, times every page
-#: of every document in flight. Bounded, the attempt comes back and the waiting
-#: happens in `_lease_a_pod`'s own loop, on the event loop, where it is free and
-#: where the policy's ceiling is what decides how long to keep trying.
-POD_LEASE_ATTEMPT_S = 20.0
+#: How long ONE lease attempt may hold a lease-pool thread.
+#:
+#: Near zero, and it has to be: the attempt is made with `grow_inline=False`,
+#: so the pool either has a pod this instant or says so and starts growing in
+#: the background. Nothing in that path blocks, and `_lease_a_pod` does the
+#: waiting on the event loop where it is free.
+#:
+#: This was 20 s in 0.4.18, which made the lease STAGE the ceiling on
+#: everything: 256 threads x one attempt per 20 s is ~13 pages a second however
+#: many pods are up, and a thread that drew the growth branch sat through a
+#: ~9-minute boot. Measured consequence -- zero pages dispatched to 50 healthy
+#: pods in 41 minutes, not one `POST /v1/ocr` in any pod's log, while the
+#: unservable queue made the scaler rent 73 pods at $43/hr. The value is kept
+#: only as the ceiling for a pool whose acquire predates `grow_inline`.
+POD_LEASE_ATTEMPT_S = 2.0
 
 
 def _is_local_exhaustion(exc: BaseException) -> bool:
@@ -831,7 +839,8 @@ async def _lease_a_pod(model_id: str, policy: str, wait_s: float):
             lease = await run_on_lease_pool(
                 placement.choose, model_id,
                 spill_after=placement.spill_threshold(model_id),
-                acquire_timeout=POD_LEASE_ATTEMPT_S)
+                acquire_timeout=POD_LEASE_ATTEMPT_S,
+                grow_inline=False)
         except OcrError:
             raise
         except Exception as exc:

tests/test_runpod_nonblocking_lease.py

+"""A lease must not wait in a thread.
+
+0.4.18 bounded a lease attempt at 20 s and ran it on a 256-thread pool, which
+made the LEASE STAGE the ceiling on everything downstream: 256 threads at one
+attempt per 20 s passes ~13 pages a second however many pods are up, and a
+thread that drew the growth branch sat through an entire ~9-minute boot.
+
+Measured consequence, on a live 5,000-document run: **zero** pages dispatched
+to 50 healthy pods in 41 minutes. Not one `POST /v1/ocr` in any pod's log, GPUs
+at `KV 0.0%`, 811 pages waiting, and the scaler reading that unservable queue
+as demand and renting to 73 pods at $43/hr. `/healthz` answered in 1.6 ms
+throughout, so nothing looked broken from outside.
+
+So `acquire(grow_inline=False)` answers now or raises `NoPodRightNow`, and the
+caller waits on its event loop, where waiting is free. The pool keeps a demand
+signal by counting DENIALS over a window equal to the caller's retry interval,
+so the count is distinct waiting pages rather than the attempts they have made.
+"""
+
+import threading
+import time
+import types
+
+import pytest
+
+from codai.api import runpod_worker as rw
+
+
+def _mcfg(**kw):
+    base = dict(max_pods=128, min_pods=0, max_inflight_per_pod=0,
+                scale_up_inflight_per_pod=32, scale_up_max_parallel_boots=32,
+                gpu_types=["NVIDIA A40"], gpu_weights={"NVIDIA A40": 1.0},
+                gpu_limits=None, sticky_sessions=True, health_path="/v1/models",
+                env={})
+    base.update(kw)
+    return types.SimpleNamespace(**base)
+
+
+def _pool(mcfg=None, pods=()):
+    p = rw.RunpodPodPool.__new__(rw.RunpodPodPool)
+    p.mcfg = mcfg or _mcfg()
+    p._cv = threading.Condition(threading.RLock())
+    p._card_cache, p._card_gen, p._denied = {}, 0, []
+    p._booting = p._waiting = 0
+    p._affinity = {}
+    p.model_key = "m"
+    p.pods = list(pods)
+    p.grew = 0
+
+    def _grow():
+        p.grew += 1
+    p._grow_in_background = _grow
+    return p
+
+
+def _pod(inflight=0, healthy=True, draining=False):
+    return types.SimpleNamespace(gpu="NVIDIA A40", vram_gb=48.0,
+                                 inflight=inflight, healthy=healthy,
+                                 draining=draining, pod_id="p",
+                                 url="https://10.0.0.1:1", last_used=0.0)
+
+
+# ------------------------------------------------------------ answers now #
+
+def test_an_empty_pool_raises_at_once_instead_of_renting_here():
+    p = _pool()
+    t0 = time.monotonic()
+    with pytest.raises(rw.NoPodRightNow):
+        p.acquire(timeout=600.0, grow_inline=False)
+    assert time.monotonic() - t0 < 0.5, "it waited"
+    assert p.grew == 1, "growth must still be triggered, in the background"
+
+
+def test_it_does_not_hold_the_thread_for_the_timeout():
+    """THE REGRESSION: 20 s per attempt x 256 threads = ~13 pages/s."""
+    p = _pool()
+    t0 = time.monotonic()
+    for _ in range(50):
+        with pytest.raises(rw.NoPodRightNow):
+            p.acquire(timeout=1200.0, grow_inline=False)
+    took = time.monotonic() - t0
+    assert took < 1.0, f"50 denials took {took:.1f}s — still waiting somewhere"
+
+
+def test_a_free_pod_is_still_handed_out():
+    p = _pool(pods=[_pod()])
+    pod, url = p.acquire(timeout=600.0, grow_inline=False)
+    assert pod is not None and url
+    assert pod.inflight == 1
+
+
+def test_the_booting_count_is_not_leaked_when_it_raises():
+    """A leaked count stops `_grow_reason` firing for everyone."""
+    p = _pool()
+    for _ in range(5):
+        with pytest.raises(rw.NoPodRightNow):
+            p.acquire(timeout=600.0, grow_inline=False)
+    assert p._booting == 0
+
+
+def test_blocking_mode_is_untouched_for_callers_that_want_it():
+    """A caller with a thread to spare and no retry loop still waits."""
+    p = _pool(_mcfg(max_pods=0), pods=[_pod()])
+    pod, _url = p.acquire(timeout=5.0)
+    assert pod is not None
+
+
+# ------------------------------------------------- demand without threads #
+
+def test_a_denial_is_counted_as_demand():
+    p = _pool()
+    with pytest.raises(rw.NoPodRightNow):
+        p.acquire(grow_inline=False)
+    assert p._queued() >= 1
+
+
+def test_retries_of_one_page_are_not_counted_as_many_pages():
+    """The runaway: reading its own retries as new work rented 73 pods."""
+    p = _pool()
+    p.DENY_WINDOW_S = 0.2
+    for _ in range(20):                 # one page, retrying fast
+        with pytest.raises(rw.NoPodRightNow):
+            p.acquire(grow_inline=False)
+        time.sleep(0.03)
+    # Within one window only the attempts made in that window count.
+    assert p._queued() <= 10, p._queued()
+
+
+def test_the_demand_decays_when_the_pages_stop_asking():
+    p = _pool()
+    p.DENY_WINDOW_S = 0.1
+    with pytest.raises(rw.NoPodRightNow):
+        p.acquire(grow_inline=False)
+    assert p._queued() >= 1
+    time.sleep(0.25)
+    assert p._queued() == 0
+
+
+def test_threads_and_denials_are_not_added_together():
+    """The same page counted two ways would double the fleet."""
+    p = _pool()
+    p._waiting = 7
+    for _ in range(3):
+        with pytest.raises(rw.NoPodRightNow):
+            p.acquire(grow_inline=False)
+    assert p._queued() == max(7, p._denied_recent())
+
+
+def test_the_record_does_not_grow_without_bound():
+    p = _pool()
+    for _ in range(5000):
+        p._note_denied()
+    assert len(p._denied) <= 4096
+
+
+def test_demand_still_drives_the_fleet_size():
+    """With no threads parked, denials must still rent pods."""
+    p = _pool(pods=[_pod(inflight=1)])
+    for _ in range(40):
+        p._note_denied()
+    assert p._pods_for_demand([p.pods[0]]) > 1