fix: curing collect fan-in hangs forever and leaks state when a leg permanently DLQs by TGPSKI · Pull Request #45 · TGPSKI/leather

TGPSKI · 2026-07-02T23:42:02Z

Summary

Fixes #44. runCollectFromQueue/runCollect (the collect_size fan-in join path in internal/curing) polled len(items) < CollectSize forever with no timeout, TTL, or staleness check. If any one of a fan-in group's expected legs exhausted its own max_attempts and got routed to its own <queue>-dlq, the group could never reach CollectSize again: the downstream agent never fired, and the already-collected items (plus their underlying hides) leaked on disk indefinitely with zero operator-visible signal.

Found while load-testing examples/11-high-volume-ci against a backend serialized to one request at a time (vllm serve --max-num-seqs 1) with tannery.yaml concurrency set higher than the backend could sustain — decision-artifact counts plateaued well below the target webhook count with nothing in the logs explaining why.

Fix

Added CuringDefinition.CollectTimeoutSeconds (collect_timeout_seconds in *.curing.yaml), default 900; an explicit 0 preserves the old wait-forever behavior for anyone who wants it.
A partial collect group whose oldest item exceeds this age is now evicted to <queue>-dlq (same DLQ naming/retention convention as the per-item retry path — hides are retained for manual inspection) and GC'd.
New TanneryEvent{Kind: "stale"}, rendered in leather serve --pretty (✕ stale) and forwarded to the devtools SSE bus as queue.stale.
Fixed both fan-in code paths: runCollectFromQueue (prefix-based single-use queues, e.g. example 11's analysis/<id>) and runCollect (static-queue multi-group collects) — the latter evicts a stale group without blocking other, still-fresh groups sharing the same queue.

Test plan

go build ./...
go test ./...
go test -race ./internal/curing/...
gofmt -l clean
New regression tests: default/explicit/zero collect_timeout_seconds parsing (loader_test.go), stale-group eviction to DLQ + TanneryEvent emission + hide retention (runCollectFromQueue), fresh-group-not-evicted guard, and stale-group eviction not blocking a sibling fresh group in the static-queue runCollect path (worker_test.go)

🤖 Generated with Claude Code

Update: two more fan-in fixes found in the same area

Continued load-testing (examples/11-high-volume-ci, real vLLM backend,
concurrency 8+) surfaced two more bugs in the same fan-in/collect code path
that this PR already touches:

Shared agent config mutation under concurrency: process() and
handleCollected() mutated a shared *model.Agent directly (injecting
hide content into the prompt), garbling prompts under concurrency: 8+.
Fixed by cloning the agent config before any per-run mutation.
Fan-in collect groups silently dropped when the agent call itself
fails: a second, distinct instance of the original bug this PR fixes.
runCollectFromQueue dequeues all collect_size items before invoking
the agent, so unlike the per-item retry path, a failed handleCollected
call (e.g. the decision agent's LLM call timing out under load) had
nowhere to put the items back — no retry, no DLQ, and the source hides
leaked on disk. max_attempts in the curing YAML was silently unenforced
for this path. Added requeueOrDLQGroup, mirroring the per-item
retry/DLQ convention: bump each item's AttemptCount and either
re-enqueue the whole group (retried on the next scan tick) or route it to
<queue>-dlq once attempts are exhausted.

Also fixed hide_kind provenance on fan-in artifacts (cosmetic/provenance
only — a fan-in curing's own artifact recorded hide_kind as whichever
input leg was collected first, never its own name).

New test: TestWorker_RunCollect_AgentFailureRetriesThenDLQs — forces an
LLM failure on a complete fan-in group and verifies attempt 1 requeues,
attempt 2 (MaxAttempts exhausted) routes to DLQ, hides are retained, and
retry/dlq TanneryEvents fire correctly.

A related but separate set of fixes (reasoning-model flakiness in the
tool-call loop, a thinking: frontmatter feature, and example-11 config
tuning) found during the same load-testing session is split out into #46,
based on top of this branch.

…ermanently DLQs (#44)

Four fixes to the curing worker found via load-testing a fan-out/fan-in pipeline under concurrency: - Shared agent config mutation: process() and handleCollected() mutated a shared *model.Agent directly (injecting hide content into the prompt), garbling prompts under concurrency > 1. Both now clone the agent config before mutating. - Queue items deleted regardless of outcome: handleItemFromQueue deleted the queue entry even on failure, permanently losing the item on any transient error. process()/handleCollected() now return error, and the queue is only deleted on success — failures re-enqueue up to max_attempts, then route to <queue>-dlq. - Fan-in collect groups silently dropped on failure: a second, distinct instance of the item above. runCollectFromQueue dequeues all collect_size items before invoking the agent, so a failed handleCollected call (e.g. an LLM timeout) had nowhere to put the items back — no retry, no DLQ, source hides leaked on disk, and the curing's own max_attempts config was silently unenforced for this path. Added requeueOrDLQGroup, mirroring the per-item retry/DLQ convention: bump AttemptCount and either re-enqueue the whole group or route it to <queue>-dlq once attempts are exhausted. - hide_kind provenance on fan-in artifacts: a fan-in curing's own artifact recorded hide_kind as whichever input leg was collected first, never its own name. Cosmetic — the actual dispatch-relevant hide kind was already correct — but fixed so the artifact record doesn't lie to tooling that reads it. Also retains added observability logging (worker start, scan-tick, queues-found, collect-goroutine semaphore acquisition) from the same investigation.

TestWorker_RunCollect_AgentFailureRetriesThenDLQs forces an LLM failure on a complete fan-in group and verifies: attempt 1 requeues the group (not dropped), attempt 2 (MaxAttempts exhausted) routes it to DLQ, source hides are retained, and retry/dlq TanneryEvents fire correctly.

Adds Unreleased entries that were missing for work already on this branch and its base: the four curing-worker concurrency fixes (#45), the HTTP client timeout race, the reasoning-model tool-call-loop flakiness fixes (duplicate-call guard, empty-stop retry), the split-answer head-truncation fix, the thinking: front-matter field, and shell-mcp per-argument pattern validation.

… groups Root cause of a 99/100 completion in a 100-webhook burst of examples/11-high-volume-ci: ids.TimestampHex drew its uniqueness suffix from mathrand.Int31n(0x10000) — 65,536 values per (prefix, minute) bucket, ~1% birthday-collision odds at ~40 IDs/minute. Two concurrent pr-context legs drew the same output hide ID (hide_pr_context_..._c461); hide.Store.Put's os.MkdirAll silently merged them; PR #1019's decision group collected the shared hide, succeeded, and deleted it; PR #1043's group then found its leg's hide missing 6 seconds later and DLQ'd after exhausting retries (the #45 requeueOrDLQGroup machinery surfaced the loss exactly as designed). With the opposite race order the failure would have been worse: a silently wrong decision built from another PR's analysis content. Two layers: - ids.TimestampHex suffix widened to 32 bits (%08x): collision odds at hundreds of IDs per bucket drop to ~1 in a million. - hide.Store.Put now creates the entry directory exclusively (os.Mkdir instead of MkdirAll) and regenerates the ID on collision, bounded at 5 attempts — a drawn collision can no longer overwrite another hide's content out from under its queue references. Note: the NamesContaining reference-check used by the prefix-scan GC path was considered for handleCollected's cleanup as well, but it matches hide IDs embedded in queue *names* (fan-out input hides) and cannot see leg-output hides referenced only by queue item contents — exclusive creation at the write point is the guard that actually closes this class.

…e-ci tuning (#46) * fix: HTTP client timeout races the context deadline http.Client{Timeout: ...} fired independently of the run's context deadline, producing spurious "context deadline exceeded" errors well before the real timeout under load. The context deadline (set once in runner.Run / the curing's timeout_seconds) is now the single source of truth for request timeouts. * feat: add Agent.DisableThinking field New per-agent override that will send chat_template_kwargs.enable_thinking = false to the model. Zero value (false) leaves default model behavior untouched. Wired up to frontmatter parsing and the runner in following commits. * feat: parse thinking: agent frontmatter field Adds "thinking: false" as a recognized *.agent.md frontmatter key, parsed into frontMatter.DisableThinking (inverted so the zero value matches "no override, model default"). * feat: wire DisableThinking from frontmatter into model.Agent LoadFile now copies frontMatter.DisableThinking into the constructed model.Agent, completing the thinking: false frontmatter feature. * test: cover thinking: frontmatter parsing Verifies "thinking: false" sets DisableThinking, and that it defaults to false (model default, no override) when unset. * fix: reasoning-model flakiness in the tool-call loop Three related fixes found while load-testing a fan-out/fan-in pipeline against a real reasoning model (Qwen3 via vLLM, tool-call-parser qwen3_xml). Confirmed via direct replay against the LLM endpoint outside leather that this is model/parser flakiness under load, not a request- construction bug in the runner (~25% of isolated replays reproduced it; an explicit "don't do this" prompt instruction had zero effect). - Duplicate tool-call guard: the model would occasionally re-issue an already-succeeded tool call verbatim instead of progressing, spinning until max tool rounds was hit. A tool call with the same name and arguments that already succeeded this run is no longer re-executed — the model is told it already happened and the run proceeds. Also guards against duplicating a real side effect (e.g. posting a comment twice). Scoped to non-hide tools; hide pagination tools legitimately expect repeated calls. - Self-healing retry on empty final answers: a related manifestation of the same flakiness — the model would sometimes stop naturally (finish_reason "stop", not "length") with zero output tokens instead of the expected answer, propagating downstream as blank/N/A fields. Extended the existing length-truncation retry to also retry once, bare, on this case. - DisableThinking wiring: merges chat_template_kwargs.enable_thinking = false into the request when Agent.DisableThinking is set, alongside the existing parallel_tool_calls override. Also retains the tool-call-argument debug logging added during investigation (agent/tool/args at DEBUG) — the byte-count-only logging that existed before didn't reveal repeated-argument loops. * test: cover duplicate-tool-call guard, empty-stop retry, thinking wiring - TestRunner_DuplicateToolCallSkipsReExecution: a repeated identical tool call hits the real endpoint once, not twice. - TestRun_SelfHealingRetry_OnEmptyStopCompletion / TestRun_EmptyStopRetry_IsSingleShot: empty finish_reason=stop retries exactly once and passes through if the retry is also empty. - TestRun_DisableThinkingMergesChatTemplateKwargs: DisableThinking merges chat_template_kwargs without clobbering parallel_tool_calls. * fix(11-high-volume-ci): fix N/A decisions, disable thinking on all agents - decision.agent.md: the prompt said "copy PR_NUMBER, REPO, SHA verbatim from ANALYSIS 1", assuming the 3 parallel analysis agents always arrive in submission order. Only pr-metadata emits those fields, but pr-context (zero tool calls) often won the race for slot 1, leaving nothing to copy and producing "PR_NUMBER: N/A". Now references the block by its "(from: pr-metadata)" tag instead of position. - All 5 agents: added "thinking: false" and "completion_reserve: 768" (down from the reasoning-model default of 8192). Disabling the hidden reasoning trace was the most effective fix for both the tool-call-loop and empty-final-answer flakiness (see internal/runner fixes), and measured a 5.2x speedup on a 40-webhook burst load test (323s -> 62s) with equal-or-better correctness. See README.md for full numbers. - pr-metadata.agent.md / pr-diff.agent.md: tool_rounds 2 -> 3, giving one extra round of headroom before the max-rounds guard trips. - pr-comments.agent.md: tool_rounds 3 -> 5, and added an explicit "do not call post_pr_comment more than once per PR" instruction (kept as defense in depth alongside the runner-level dedupe guard, even though the instruction alone measurably had no effect on the underlying flakiness). * fix(11-high-volume-ci): remove stale llm_timeout, raise max_concurrent_jobs llm_timeout no longer applies now that the HTTP client timeout race fix (internal/session/http_client.go) makes the context deadline the single timeout source — leaving it here was dead config that could confuse a reader into thinking it still did something. max_concurrent_jobs raised 8 -> 16 to give the higher webhook volumes in this example room to run without saturating the scheduler ahead of the per-queue concurrency limits in tannery.yaml. * fix(11-high-volume-ci): raise shell tool timeouts for burst load get_pr_files/get_pr_diff (20s/30s) and post_pr_comment/add_pr_label (15s) were too tight once the pipeline was actually driving burst concurrency against a real backend — bumped all four to 60s to match the per-agent LLM call timeout, so a slow shell-mcp round trip under load fails via the same timeout budget as everything else instead of tripping first. * fix(11-high-volume-ci): raise comments-in queue concurrency comments-in was pinned to concurrency: 1 (serial, ordered delivery) — under real burst load this made pr-comments the pipeline's bottleneck, queueing up behind every decision even though comment order across different PRs doesn't need to be preserved. Raised to 8 to match the other queues. * fix(11-high-volume-ci): fix completion wait target and shell robustness - Wait/drain reordering: the script waited for `decision` artifact count to reach WEBHOOK_COUNT, but decision isn't the pipeline's last stage — pr-comments is. The results/tally/done summary printed while pr-comments runs (and the server's own --pretty live trace, unredirected and sharing this terminal) were still active, making it look like output kept streaming after the script said it was done. Now waits on pr-comments artifact count (tracking decision count alongside it for visibility), and moved the queue-drain + server-shutdown step to run before the results/tally/done section instead of after. - .env sourcing for LLM endpoint/model overrides without exporting them in the shell first. - Shell robustness: `[ "$WEBHOOK_COUNT" -lt 25 ] && WEBHOOK_COUNT=25` style short-circuit clamping replaced with explicit if/then (the `&&` form exits non-zero under `set -e` when the condition is false, intermittently aborting the script); `read -r f || [ -n "$f" ]` guards against a last line without a trailing newline; `|| true` after find pipelines so a transient empty result doesn't trip `set -e`; capture() regex fixed to standard `(?<name>...)` syntax. * docs(11-high-volume-ci): document reliability & performance fixes Adds a "Reliability & performance fixes" section covering all issues found and fixed while load-testing this pipeline against a real vLLM endpoint: the 8 framework-level and example-level bugs fixed across the preceding commits, and the measured 5.2x speedup (323s -> 62s) from disabling thinking mode and right-sizing completion_reserve. * fix: answer text emitted alongside tool calls was dropped from the final answer Load-testing examples/11-high-volume-ci surfaced another qwen3-under-load flakiness mode: the model sometimes emits the head of its final answer (e.g. the PR_NUMBER/REPO/SHA header) in the same completion as a tool call, then — seeing that text in the session as already said — continues from where it stopped after the tool result. The runner recorded only the last round's content as the answer, silently head-truncating the artifact (6/40 pr-metadata artifacts in a 40-webhook burst lost their identifier header, cascading into blank or literal-placeholder decision reports and garbage post_pr_comment calls downstream). Answer fragments emitted in tool-call rounds are now banked and spliced ahead of the final round's text, so the recorded turn, cache write, and output routing all see the full answer. Scoped to non-hide rounds — text next to hide pagination calls is navigation narration, not answer. The bare empty-stop self-healing retry is skipped when fragments are banked: an empty stop then just means the model had nothing left to add. * test: cover split-answer reassembly across tool-call rounds - TestRun_SplitAnswerAcrossToolRounds_IsReassembled: content emitted alongside a tool call is spliced ahead of the post-tool-result continuation in LastResponse. - TestRun_SplitAnswer_EmptyFinalStopSkipsBareRetry: when the fragments already carry the whole answer and the final completion is an empty stop, the banked fragment is the answer and the empty-stop retry does not burn an extra completion. * feat(shell-mcp): per-argument pattern validation for tool calls New optional per-tool "patterns" map in shell-tools.json: argument key -> RE2 regexp that the substituted value must match before the command runs. A missing argument validates as the empty string, so anchored patterns also reject absent values — catching a flaky model passing blanks or literal prompt-template placeholders like "<number>" instead of real values. Patterns are validated at startup (bad regexps fail fast) and advertised in the tool's inputSchema so schema-aware clients see the constraint too. * fix(11-high-volume-ci): guard PR identifiers end to end A 40-webhook burst produced 6 decision reports with blank or literal placeholder ("<number>") PR identifiers when the pr-metadata artifact lost its header (see the runner split-answer fix). Downstream, five pr-comments runs dutifully posted comments to PR #<number> and one burned its whole completion budget reasoning about the malformed input. Three layers of defense: - shell-tools.json: pattern-constrain pr_number (^[0-9]+$) and repo (owner/name) on all four tools, so garbage identifiers now fail loudly at the shell-mcp boundary instead of executing with placeholder text. - decision.agent.md: on a missing/non-numeric pr-metadata block, emit Decision: ERROR with blank identifier fields rather than guessing or echoing template placeholders. - pr-comments.agent.md: on Decision: ERROR or a blank/placeholder PR_NUMBER, make no tool calls and report the skip — preventing both the garbage posts and the completion-budget reasoning spiral. * docs: backfill changelog for load-test and reasoning-model fixes Adds Unreleased entries that were missing for work already on this branch and its base: the four curing-worker concurrency fixes (#45), the HTTP client timeout race, the reasoning-model tool-call-loop flakiness fixes (duplicate-call guard, empty-stop retry), the split-answer head-truncation fix, the thinking: front-matter field, and shell-mcp per-argument pattern validation. * fix: 16-bit ID suffixes collide under burst load, cross-wiring fan-in groups Root cause of a 99/100 completion in a 100-webhook burst of examples/11-high-volume-ci: ids.TimestampHex drew its uniqueness suffix from mathrand.Int31n(0x10000) — 65,536 values per (prefix, minute) bucket, ~1% birthday-collision odds at ~40 IDs/minute. Two concurrent pr-context legs drew the same output hide ID (hide_pr_context_..._c461); hide.Store.Put's os.MkdirAll silently merged them; PR #1019's decision group collected the shared hide, succeeded, and deleted it; PR #1043's group then found its leg's hide missing 6 seconds later and DLQ'd after exhausting retries (the #45 requeueOrDLQGroup machinery surfaced the loss exactly as designed). With the opposite race order the failure would have been worse: a silently wrong decision built from another PR's analysis content. Two layers: - ids.TimestampHex suffix widened to 32 bits (%08x): collision odds at hundreds of IDs per bucket drop to ~1 in a million. - hide.Store.Put now creates the entry directory exclusively (os.Mkdir instead of MkdirAll) and regenerates the ID on collision, bounded at 5 attempts — a drawn collision can no longer overwrite another hide's content out from under its queue references. Note: the NamesContaining reference-check used by the prefix-scan GC path was considered for handleCollected's cleanup as well, but it matches hide IDs embedded in queue *names* (fan-out input hides) and cannot see leg-output hides referenced only by queue item contents — exclusive creation at the write point is the guard that actually closes this class. * test: cover hide ID collision regeneration and persistent-collision error - TestStore_Put_RegeneratesIDOnCollision: a Put whose generated ID collides with an existing hide regenerates instead of reusing it, and the existing hide's content survives untouched. - TestStore_Put_PersistentCollisionErrors: a permanently colliding ID generator makes Put fail loudly after bounded attempts rather than overwrite or loop forever. Also tightens TestTimestampHexUniqueness: with a 32-bit suffix, any collision in 1000 draws now fails the test instead of tolerating up to 100. * feat: full-system load-test profiler + measured 100-webhook profile scripts/profile-run.sh wraps any command with 1-2 Hz samplers: host CPU/memory/disk (vmstat, plus iostat/mpstat/pidstat when sysstat is installed), kernel pressure-stall information, per-process attribution, GPU telemetry via nvidia-smi, lm-sensors temperatures, and vLLM's /metrics endpoint (running/waiting requests, KV-cache usage, token throughput, prefix-cache hit rate). scripts/profile-summary.py renders an avg/peak summary from any capture directory; sysstat and GPU samplers degrade gracefully when absent. examples/11-high-volume-ci/README.md gains a 'Measured at scale' section with the profiled 100-webhook burst on a single RTX PRO 4500: ~500 LLM jobs, 972k tokens, 3.2k prompt tok/s sustained — orchestrated for ~6% of one host's CPU, zero PSI stalls, and 2% peak disk util. The pipeline is GPU-bound end to end; leather's orchestration overhead is effectively free at this scale. * docs(11-high-volume-ci): update measured profile to the canonical 100/100 run Replaces the interim numbers (from a run on the pre-ID-fix binary that finished 99/100) with the canonical post-fix run: 100/100 through every stage in 190s, 500 jobs / 965k tokens, 4.6k prompt tok/s sustained, host at 6.5% CPU with zero PSI stalls, GPU 79.7% avg.

TGPSKI added bug Something isn't working full-test labels Jul 2, 2026

TGPSKI mentioned this pull request Jul 3, 2026

fix: reasoning-model flakiness, thinking-mode support, and high-volume-ci tuning #46

Merged

5 tasks

TGPSKI force-pushed the fix/curing-collect-fanin-staleness branch from 60600e4 to cbdc1da Compare July 3, 2026 07:28

TGPSKI added 3 commits July 3, 2026 00:35

fix: curing collect fan-in hangs forever and leaks state when a leg p…

09a7f4e

…ermanently DLQs (#44)

TGPSKI force-pushed the fix/curing-collect-fanin-staleness branch from cbdc1da to 8deb88c Compare July 3, 2026 07:36

TGPSKI merged commit 3a36c26 into main Jul 3, 2026
3 checks passed

TGPSKI deleted the fix/curing-collect-fanin-staleness branch July 3, 2026 16:46

TGPSKI mentioned this pull request Jul 5, 2026

Release v0.4.0 "vegan leather" #47

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

fix: curing collect fan-in hangs forever and leaks state when a leg permanently DLQs#45

fix: curing collect fan-in hangs forever and leaks state when a leg permanently DLQs#45
TGPSKI merged 3 commits into
mainfrom
fix/curing-collect-fanin-staleness

TGPSKI commented Jul 2, 2026 •

edited

Loading

Uh oh!

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

1 participant

Conversation

TGPSKI commented Jul 2, 2026 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Summary

Fix

Test plan

Update: two more fan-in fixes found in the same area

Uh oh!

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

1 participant

TGPSKI commented Jul 2, 2026 •

edited

Loading