_shared: phase-outcome-post.sh routinely exceeds the 120s tool timeout; backgrounding is a normalized workaround

jbr870 commented

2026-08-13 11:18:35 +00:00

Owner

Observation

phase-outcome-post.sh routinely exceeds the harness's 120s Bash tool timeout while still succeeding, so orchestrators background it and poll — a workaround now normalized across runs:

verity-main-4c283a2c: "exceeds the 120s Bash timeout on every invocation; all 5 posts hand-backgrounded with nohup+polling"
verity-slot1-112: "exceeds the Bash tool timeout while still succeeding — every caller must know not to retry, or it double-posts"
verity-slot2-167: "slow enough that the lead backgrounded it and slept 100s"
verity-slot5-164: "backgrounding it is a normalised workaround (4 of 6 posts backgrounded)" — with the model narrating it as "the known workaround"

A required helper on the critical path of every phase has an accepted workaround baked into model behavior. The slot1-112 phrasing names the sharp edge: timeout-then-retry double-posts, timeout-then-background loses the receipt (wait-discipline.md now governs the waiting side, but the helper is still slow).

Recurrence

4 independent runs (2 projects' forges: glab-cli on verity, all under load). Behavioral/perf — not desk-verifiable here; recurrence is the evidence.

Hypothesis

Profile one slow invocation first (adapter round-trips? label reconciliation? ordinal scan over all comments?). Likely candidates: the read-all-comments ordinal/collision scan and the set_status label reconciliation each costing several forge API round-trips. A --timings trace flag would make the next dogfood run the profiler.

Suggested lane

Full pipeline (helper behavior change) — but the profiling spike can happen ad hoc first.

Filed by /meta-retrospective 2026-08-13.

## Observation `phase-outcome-post.sh` routinely exceeds the harness's 120s Bash tool timeout while still succeeding, so orchestrators background it and poll — a workaround now normalized across runs: - verity-main-4c283a2c: "exceeds the 120s Bash timeout on every invocation; all 5 posts hand-backgrounded with nohup+polling" - verity-slot1-112: "exceeds the Bash tool timeout while still succeeding — every caller must know not to retry, or it double-posts" - verity-slot2-167: "slow enough that the lead backgrounded it and slept 100s" - verity-slot5-164: "backgrounding it is a normalised workaround (4 of 6 posts backgrounded)" — with the model narrating it as "the known workaround" A required helper on the critical path of every phase has an accepted workaround baked into model behavior. The slot1-112 phrasing names the sharp edge: timeout-then-retry double-posts, timeout-then-background loses the receipt (`wait-discipline.md` now governs the waiting side, but the helper is still slow). ## Recurrence 4 independent runs (2 projects' forges: glab-cli on verity, all under load). Behavioral/perf — not desk-verifiable here; recurrence is the evidence. ## Hypothesis Profile one slow invocation first (adapter round-trips? label reconciliation? ordinal scan over all comments?). Likely candidates: the read-all-comments ordinal/collision scan and the `set_status` label reconciliation each costing several forge API round-trips. A `--timings` trace flag would make the next dogfood run the profiler. ## Suggested lane Full pipeline (helper behavior change) — but the profiling spike can happen ad hoc first. *Filed by /meta-retrospective 2026-08-13.*

jbr870 added the

type:tech-debt

component:shared

labels

2026-08-13 11:18:35 +00:00

jbr870 referenced this issue

2026-08-13 11:20:03 +00:00

Slow loop: periodic process review (drains devwork learnings, defer-rot, process-quality trend, conformance census) #10

jbr870 commented

2026-08-13 11:46:38 +00:00

Author

Owner

Fifth source, and the first from the current skill text: verity-release session, 2026-08-13, first-hand — "the glab helpers here are slow enough that one of them routinely exceeds a 120s tool timeout while still succeeding." Also relevant scale datapoint from the same report: per-issue comments-scan round-trips over verity's 230+ issues make a full-forge scan an hour-class operation, which is why the retrospective's learning drain had to be scoped to a hand-picked issue list. Both point at the same fix: fewer round-trips per helper invocation.

Evidence added by /meta-retrospective 2026-08-13 (second pass — verity drain).

Fifth source, and the first from the current skill text: verity-release session, 2026-08-13, first-hand — "the glab helpers here are slow enough that one of them routinely exceeds a 120s tool timeout while still succeeding." Also relevant scale datapoint from the same report: per-issue comments-scan round-trips over verity's 230+ issues make a full-forge scan an hour-class operation, which is why the retrospective's learning drain had to be scoped to a hand-picked issue list. Both point at the same fix: fewer round-trips per helper invocation. *Evidence added by /meta-retrospective 2026-08-13 (second pass — verity drain).*

jbr870 referenced this issue from a commit

2026-08-13 12:06:38 +00:00

meta-retrospective: second pass 2026-08-13 — verity drain (8 learnings watchlisted, gate validated live)

jbr870 added the

priority:high

labels

2026-08-13 12:49:28 +00:00

jbr870 commented

2026-08-13 13:05:57 +00:00

Author

Owner

Two additions from the slot3/#191 deep-dive:

Count: 8 more backgrounded posts in one run (all 6 POs + 2 comment posts, plus 2 dedicated sleep-and-cat waiter processes).
The workaround is hardening into false model beliefs. The run stated "retrying phase-outcome-post.sh mints a duplicate PO" (08-12 11:42), later read the helper source containing the 3b idempotent retry-absorption guard (17:15) — and still restated the false belief at 18:32. Verified at HEAD: the guard exists (same-skill/same-state retry returns the landed post's receipt). So the latency isn't just costing backgrounding ceremony; it's training orchestrators into contract-false workarounds that will outlive the fix. Raises the value of fixing the latency itself rather than documenting around it.

Evidence added by /meta-retrospective 2026-08-13 (slot3 deep-dive).

Two additions from the slot3/#191 deep-dive: 1. **Count:** 8 more backgrounded posts in one run (all 6 POs + 2 comment posts, plus 2 dedicated sleep-and-cat waiter processes). 2. **The workaround is hardening into false model beliefs.** The run stated "retrying phase-outcome-post.sh mints a duplicate PO" (08-12 11:42), later *read the helper source containing the 3b idempotent retry-absorption guard* (17:15) — and still restated the false belief at 18:32. Verified at HEAD: the guard exists (same-skill/same-state retry returns the landed post's receipt). So the latency isn't just costing backgrounding ceremony; it's training orchestrators into contract-false workarounds that will outlive the fix. Raises the value of fixing the latency itself rather than documenting around it. *Evidence added by /meta-retrospective 2026-08-13 (slot3 deep-dive).*

Rows
Columns

_shared: phase-outcome-post.sh routinely exceeds the 120s tool timeout; backgrounding is a normalized workaround #28

Observation

Recurrence

Hypothesis

Suggested lane