-
Stefy Lanza (nextime / spora ) authored
0.4.16 fixed one blocking call on the loop by finding it the hard way: a 5,000-document run rented 127 pods and completed nothing for ten minutes, and the only honest signal in the system was that /v1/runpod/status had stopped answering. Nothing in the process said "the loop was blocked", though it had been, for minutes at a time. Both halves of that are addressed here. MEASURED: codai/api/loop_watch.py samples the loop's own behaviour -- a sleep that asks for 0.5 s and returns at 4 s says the loop was busy elsewhere for 3.5 s and served NOTHING in that window. Installed in both the engine and the front (the front is the process the client talks to, so a stall there is the one it experiences), logged per stall with its duration, and exported on /metrics as coderai_loop_lag_seconds, _lag_worst_seconds, _stalls_total and _blocked_seconds_total. It cannot name the culprit, but it turns "the server is slow" into "the server was not running", which is a different investigation. CHECKED: tests/test_no_blocking_calls_on_the_loop.py walks every coroutine in codai/ for calls that block the calling thread. What makes it precise is that it does not look inside a nested def or lambda -- `to_thread(lambda: f())` and `run_on_pod_pool(f, x)` are both correct, so only a call reached without crossing a function boundary is on the loop. Its own ten tests prove it catches what it claims and ignores os.path.join, asyncio primitives and coroutines handed to ensure_future. It found 20 more, all fixed: * ocr/gateway.py: `placement.choose()` in async chat_completions -- the SAME 1200 s pool acquire as 0.4.16, on the chat path instead of the page path, and with no retry loop above it to make the wait visible. * api/ocr.py: a sync urlopen of a caller-supplied URL, so an OCR step was as slow as whoever served that URL, for every request in the process. * eleven `subprocess.run()` ffmpeg/ffprobe calls across faceswap, video, pipelines, voice_clone, custom_pipelines and the outfit video path. A media encode is seconds to minutes, and all of it was everyone's wait. * two HuggingFace API fetches in the admin routes. * two `thread.join()`s on the CUDA streaming path, and a `time.sleep(0.1)` per generated image. The allowlist in that test is empty and should stay empty: an entry in it is a request that cannot be served while the named call runs. Also tools/loadprobe.py, for the outside view: /healthz does no work and returns the instant the loop is free, so its latency IS loop lag as a client sees it. p99 healthz flat while documents crawl is a capacity problem; p99 healthz in seconds is not, and no extra capacity would have helped. Co-Authored-By:Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01KnfkxBpcZ1v6ypRFFyhrVM
174a3753