fix(worker): stop wedged retains from holding worker slots forever - #3020
Merged
Conversation
…3002) A retain task that blocks indefinitely held its worker slot until the process restarted. The operation stayed 'processing' — which the API refuses to either retry or cancel — so once every slot was held the worker stopped claiming retains and the backlog grew without bound. Five changes, outermost first: * HINDSIGHT_API_RETAIN_WALL_TIMEOUT (default 1h, 0 disables) bounds one retain task in the poller, mirroring REFLECT_WALL_TIMEOUT. The existing timeouts each bound one LLM call, query or acquire; none bounded the task. On expiry the executor is cancelled and the operation is marked 'failed', so it is retryable. asyncio.timeout() (not wait_for) so an inner TimeoutError isn't misreported as a wedge. * The streaming retain pipeline now cancels both halves explicitly. Plain gather() propagated the consumer's exception but left the producer and every extraction task under it running; they parked forever on chunk_queue.put() into a queue nobody drained, pinning chunk payloads and still spending LLM permits on a failed operation. * The LLM stage breadcrumb says '.queued' until the concurrency permits are held. It was stamped before the acquire, so a call waiting on a saturated semaphore was indistinguishable from one the provider was running — the label sent the reporting operator after Bedrock for tasks that had never reached Bedrock. Providers now stamp attempt 1 too, so a retry ladder is visible from the first attempt. * bulk_insert_entities orders by LOWER(name), making the database's collation the single arbiter of insert order for all writers. The caller already sorted by Python's str.lower(), which agrees with the conflict target for ASCII but not every locale. * HINDSIGHT_API_DB_ACQUIRE_TIMEOUT now bounds the wait it names. It was only passed to create_pool(timeout=...), a connect kwarg; Pool.acquire() kept asyncpg's default of waiting forever, so pool exhaustion never surfaced as an error.
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Fixes #3002.
What the investigation found
The chain in the issue doesn't hold up, and the correction changes the fix set.
A deadlock in
_db_consumercannot park the gather.asyncio.gather(_llm_producer(), _db_consumer())runs withreturn_exceptions=False, so the consumer'sDeadlockDetectedErrorpropagates immediately, and nothing in the retain path retries deadlocks (retry_with_backoffis never wrapped around phase 1/2). The task would fail and free its slot. Verified with a probe reproducing the exact shape.But that probe exposed a real defect: when the consumer raises, the producer and every extraction task under it are never cancelled. Nine tasks stayed pending forever, blocked on
chunk_queue.put()into a queue nobody drains — still holding their chunk payloads, still entitled to spend LLM permits and provider tokens on an operation that already failed.The stage label was telling the truth.
set_stage(f"llm.{provider}.{scope}{structured}")fires before the LLM semaphore acquire, and the provider only re-stamped.attempt=N/Mwhenattempt > 0, with each attempt hard-capped byasyncio.wait_for(timeout=self.timeout). AtLLM_TIMEOUT=500, a coroutine actually inside a Bedrock call cannot sit at the bare label for more than 500s — it flips to.attempt=2/N.stage_age=2405sat the bare label means opce12eba3never reached the provider: it was queued on an LLM concurrency semaphore. Not Bedrock, not the DB. That also explains why consolidation kept running — it isn't behind retain's per-op semaphore.What holds permits that long: retain's retry budget multiplies.
extract_factsruns an outer loop ofllm_max_retries + 1, and each iteration callsllm_config.call(max_retries=llm_max_retries), which runs its ownN+1transport attempts with the permit held across the whole inner ladder — 4 × 4 × 500s ≈ 2.2 hours per chunk at the reporter's settings.Changes
1.
HINDSIGHT_API_RETAIN_WALL_TIMEOUT(default 3600s,0disables) — the issue's requested fix. Applied in the poller at_execute_task_inner, resolved per operation type, rather than around the gather: the poller is where the slot is held, so it bounds anything that wedges a retain, not just the one site we identified. On expiry the executor is cancelled and the operation is markedfailed— which the API will retry, unlikeprocessing, which it refuses to retry or cancel.Uses
asyncio.timeout()rather thanwait_for()socm.expired()distinguishes our ceiling firing from an innerTimeoutErrorbubbling out (an asyncpg command timeout).wait_forsurfaces both as the same exception, and reporting a task's own timeout as a wedge sends operators after the wrong thing. The failure message carries the stage current when the ceiling hit.Only retain is bounded: reflect self-bounds in the engine (
reflect_wall_timeout), and nothing else has a reported wedge.2. Explicit cancellation of both pipeline halves in
_streaming_retain_batch, plus afinallyin the producer covering tasks created before it reaches its own gather. Fixes the leak above, and the mirror case (producer fails, consumer parked onget()).3. Stage breadcrumbs distinguish waiting from calling.
.queueduntil the permits are held, then the in-flight label. Providers now stamp attempt 1 too, so a retry ladder is visible from the first attempt instead of only from the second.4.
bulk_insert_entitiesorders byLOWER(name). The issue's fix #1, downgraded to hardening: the caller already sorts (sorted_groups = sorted(groups.items())on lowercased keys), so this isn't the headline fix. The residual hole is Pythonstr.lower()vs PGLOWER()divergence (documented inentity_resolverfor Turkish İ) — ordering in SQL makes the database's collation the single arbiter for all writers.5.
HINDSIGHT_API_DB_ACQUIRE_TIMEOUTnow bounds the wait it names. It was only passed toasyncpg.create_pool(timeout=...), a connect kwarg;Pool.acquire()was called with no timeout and asyncpg's_acquireskipswait_forentirely when timeout is None. Pool exhaustion never surfaced as an error — it just hung. Included because the issue tabulates this knob as one that should have bounded the incident. Behaviour change: an exhausted pool now raises after the configured wait (retried up to 3× byacquire_with_retry) instead of blocking indefinitely;0restores the old behaviour.Deliberately not fixed
The retry-ladder multiplication. It's real and it's my best candidate for what saturated the permits, but capping it would turn currently-succeeding slow retains into failures, and the wall timeout already defuses the systemic damage — cancelling the task releases the permits, so a ladder can no longer hold them past the ceiling. Worth a separate issue.
Tests
4 new files, 15 tests:
test_worker_wall_timeout.py— the ceiling cancels the executor and marksfailed; the message carries the stage; fast tasks untouched; an innerTimeoutErroris not reported as a wedge; non-retain types stay unbounded;0disables.test_retain_pipeline_cancellation.py— drives the real pipeline with a DB error injected into the consumer while extractions are in flight. Confirmed it fails without the fix, reproducing the actual leak (producer + 3 _extract_onetasks surviving a failed operation).test_llm_stage_breadcrumbs.py— stage says.queuedwhile blocked on a saturated semaphore, and names the in-flight call once the permit is granted.test_pool_acquire_timeout.py—acquire()andtransaction()pass the configured timeout;0maps to asyncpg's unboundedNone.Full sweep of the worker, retain, entity-resolver, provider and pool suites green;
lint.shandty checkclean.Open questions for the reporter
Neither blocks this PR, but both would confirm the incident is closed:
HINDSIGHT_API_RETAIN_LLM_MAX_CONCURRENTset, and to what? That's the choke point in this reading, and its value predicts how fast a worker re-wedges./llm-requests, are there retain rows in that 50-minute window with errors/timeouts (not just successes)? That distinguishes "permits held by the retry ladder" from "permits leaked".