Skip to content

Commit e244dd9

Browse files
author
Alex
committed
fix(orchestrator): handle push events directly and break probe deadlock
- Handle WebhookDispatch::Push by calling handle_push() directly instead of enqueuing to dispatcher. Push events now bypass the reconcile_tick timeout, so build-runner spawns immediately. - Set probed_at at START of probe_all() so is_stale() returns false even if tick is cancelled. Breaks the deadlock where probes never complete, circuit breakers never open, probes re-run every tick. - Update circuit breakers inline as each probe result arrives. - Process group kill via kill -9 -<pgid> kills opencode children. - Runtime orphan reaping: pkill .opencode run every 12 ticks. Refs #1721
2 parents 9a4a83a + 64136b2 commit e244dd9

4 files changed

Lines changed: 386 additions & 47 deletions

File tree

Lines changed: 156 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,156 @@
1+
# Design & Implementation Plan: ADF Reconciler Timeout and Process Leak Fix
2+
3+
**Date:** 2026-05-19
4+
**Status:** Phase 2 design
5+
**Research:** `.docs/research-adf-reconciler-timeout.md`
6+
7+
## 1. Summary of Target Behaviour
8+
9+
After implementation:
10+
11+
| Outcome | Before | After |
12+
|---------|--------|-------|
13+
| Build-runner spawns on push | Never (queue stuck behind probes) | Within 1-2 s of webhook receipt |
14+
| reconcile_tick timeout | Every tick | Only when TTL expires and probes re-run |
15+
| Orphaned opencode processes | 60+ accumulated over 50 min | Zero orphans — killed on timeout or periodic cleanup |
16+
| Circuit breaker for timeout providers | Never opens (deadlock) | Opens after 5 consecutive failures within cooldown window |
17+
18+
## 2. Key Invariants and Acceptance Criteria
19+
20+
| # | Criterion | Verification |
21+
|---|-----------|-------------|
22+
| AC1 | `handle_push()` called directly from `handle_webhook_dispatch()` for Push events, NOT via dispatcher queue | Code review: match arm in `handle_webhook_dispatch` calls `self.handle_push(task)` |
23+
| AC2 | `provider_health.probed_at` updated at START of `probe_all()`, not end | Code review; `is_stale()` returns false after first probe attempt |
24+
| AC3 | Probe process group (not just bash) killed on timeout | Manual: insert `sleep 300 &` into probe action, verify grandchild also killed |
25+
| AC4 | Orphaned opencode processes reaped in `adf-cleanup.sh` at startup AND periodically during runtime | Manual: verify `pkill` matches running opencode processes |
26+
| AC5 | Circuit breaker opens for providers that time out 5 times consecutively | Log output shows "probe skipped: circuit breaker open" after 5th timeout |
27+
| AC6 | `reconcile_tick` completes within timeout when probes are skipped (circuit breaker open) | No "reconcile_tick exceeded timeout" in logs after fix |
28+
| AC7 | Dispatch queue still drained for non-Push tasks (ReviewPr, AutoMerge, etc.) | Other task types still processed in Step 17 |
29+
30+
## 3. High-Level Design
31+
32+
### 3.1 Change 1: Direct push handling (bypass dispatcher)
33+
34+
**Current:** `handle_webhook_dispatch()` at `lib.rs:3714` → enqueues `DispatchTask::Push` → reconciled later in Step 17
35+
36+
**New:** Match arm for `WebhookDispatch::Push` calls `self.handle_push(task).await` directly instead of enqueuing.
37+
38+
**Why this is safe:**
39+
- `handle_push()` already takes `&mut self` (same as `handle_webhook_dispatch`)
40+
- `handle_push()` already checks if build-runner is active (line 2985) — prevents double-spawn
41+
- Other task types (ReviewPr, AutoMerge, PostMergeTestGate) still use dispatcher — no change to PR workflow
42+
43+
### 3.2 Change 2: Set probed_at at start (break circuit breaker deadlock)
44+
45+
**Current:** `probe_all()` at `provider_probe.rs:200` sets `self.probed_at = Some(Instant::now())` ONLY after ALL probes complete
46+
47+
**New:** Move `self.probed_at = Some(Instant::now())` to line 98 (start of `probe_all()`)
48+
49+
**Effect:** After a single probe attempt (even if cancelled), `is_stale()` returns false for TTL duration. Probes only re-run every TTL seconds, not every tick. The reconciler gets TTL seconds of clean ticks to drain dispatcher.
50+
51+
**Additional:** Also update circuit breaker state for each probe result AS THEY ARRIVE, not only after all complete. This means even if `probe_all()` is cancelled partway through, the breakers for completed probes are already updated.
52+
53+
### 3.3 Change 3: Process group kill
54+
55+
**Current:** `probe_single()` at `provider_probe.rs:638`: `kill -9 <pid>` — kills bash, orphans opencode
56+
57+
**New:** `kill -9 -<pgid>` — kills entire process group including opencode and its children
58+
59+
**Mechanism:** After spawning the child, call `nix::unistd::getpgid(pid)` to get the process group ID. On timeout, use negative PID to signal the entire group. The `nix` crate is already in the dependency tree.
60+
61+
### 3.4 Change 4: Runtime orphan reaping
62+
63+
**Current:** `adf-cleanup.sh` runs at startup only
64+
65+
**New:** Add a step 0.5 to `reconcile_tick()` that runs `pkill -9 -f '\.opencode run'` every N ticks (e.g., every 12 ticks = ~1 minute at 5 s interval)
66+
67+
**Alternative:** Use `tokio::process::Command::new("pkill")` to run the cleanup from Rust.
68+
69+
## 4. File/Module Change Plan
70+
71+
| File | Action | What Changes | Risk |
72+
|------|--------|-------------|------|
73+
| `lib.rs:3714-3738` | Modify | `WebhookDispatch::Push` arm: call `handle_push(task)` instead of `dispatcher.enqueue()` | Low — push events no longer go through dispatcher |
74+
| `provider_probe.rs:98` | Modify | Add `self.probed_at = Some(Instant::now())` at start of `probe_all()` | Low — single line |
75+
| `provider_probe.rs:156-188` | Modify | Update circuit breakers inside the `for task in tasks` loop as results arrive, not after | Medium — changes control flow |
76+
| `provider_probe.rs:637-641` | Modify | Replace `kill -9 <pid>` with `kill -9 -<pgid>` | Low — requires `nix` crate |
77+
| `lib.rs:5621` | Add | New step 0.5: `pkill -9 -f '\.opencode run'` every 12 ticks | Low — new step in reconcile_tick |
78+
79+
## 5. Step-by-Step Implementation Sequence
80+
81+
### Step 1: Direct push handling (highest value, lowest risk)
82+
**File:** `lib.rs` lines 3714-3738
83+
84+
Change the `WebhookDispatch::Push` match arm from:
85+
```rust
86+
self.dispatcher.enqueue(dispatcher::DispatchTask::Push { ... });
87+
```
88+
to:
89+
```rust
90+
let task = dispatcher::DispatchTask::Push { ... };
91+
if let Err(e) = self.handle_push(task).await {
92+
warn!(error = %e, "handle_push failed in webhook handler");
93+
}
94+
```
95+
96+
**Verification:** Push to Gitea, check if build-runner spawns within seconds.
97+
98+
### Step 2: Set probed_at at start
99+
**File:** `provider_probe.rs` line 98
100+
101+
Add after the function signature: `self.probed_at = Some(Instant::now());`
102+
103+
Also move the circuit breaker update loop (`for result in &results`) to inside the `for task in tasks` loop, updating each breaker as results arrive.
104+
105+
### Step 3: Process group kill
106+
**File:** `provider_probe.rs` lines 634-642
107+
108+
1. After `let child = match tokio::process::Command::new("bash")...`, capture pgid:
109+
```rust
110+
let pgid = child.id().and_then(|pid| {
111+
nix::unistd::getpgid(Some(nix::unistd::Pid::from_raw(pid as i32))).ok()
112+
});
113+
```
114+
2. On timeout, use: `kill -9 -<pgid>`
115+
116+
### Step 4: Runtime orphan reaping
117+
**File:** `lib.rs` around line 5621
118+
119+
Add as Step 0.5 (before rate limit cleaning):
120+
```rust
121+
if self.tick_count % 12 == 0 {
122+
let _ = std::process::Command::new("pkill")
123+
.arg("-9")
124+
.arg("-f")
125+
.arg(".opencode run")
126+
.spawn();
127+
}
128+
```
129+
130+
## 6. Testing Strategy
131+
132+
| Criterion | Test Method | Location |
133+
|-----------|------------|----------|
134+
| AC1: Direct push handling | Manual: push to Gitea, check build-runner log | Bigbox |
135+
| AC2: probed_at at start | Unit: call probe_all(), cancel, check is_stale() | New test in provider_probe.rs |
136+
| AC3: Process group kill | Unit: spawn shell that spawns grandchild, kill pgid, verify grandchild dead | New test in provider_probe.rs |
137+
| AC5: Circuit breaker opens | Integration: let ADF run 5+ ticks with timeout providers, verify breaker state | Bigbox |
138+
| AC6: reconciler completes | System: monitor logs for absence of "exceeded timeout" | Bigbox |
139+
| AC7: Other tasks still dispatched | Existing: PR review and auto-merge tests still pass | Existing test suite |
140+
141+
## 7. Risk Review
142+
143+
| Risk | Mitigation | Residual |
144+
|------|------------|----------|
145+
| Push events double-dispatched (webhook + dispatcher) | Change 1 removes `dispatcher.enqueue()` for Push — no double-enqueue | Low |
146+
| probe_all() with probed_at at start prevents re-probing when provider recovers | TTL ensures re-probing after TTL expires — normal behaviour | None |
147+
| kill -9 -<pgid> may not work on all systems | `nix::unistd::getpgid` returns EPERM on some kernels — fall back to kill -9 <pid> if pgid unavailable | Low |
148+
| Runtime pkill may match legitimate opencode processes | `-f '\.opencode run'` pattern is specific to probe commands | Low |
149+
150+
## 8. Questions for Reviewer
151+
152+
1. **Should `handle_push()` call from webhook handler be conditional on `reconcile_tick` completion?** Currently proposed: always call directly. Alternative: only call directly if `provider_health.is_stale()` is true (indicating probes are blocking ticks).
153+
154+
2. **Should the TTL for provider probes be increased from current value to reduce probe frequency?** Currently probes run every `self.ttl` (configurable in config). A longer TTL means less frequent probe re-attempts.
155+
156+
3. **Should the `DispatchTask::Push` variant remain in the enum, or be removed?** Since push events are now handled directly, the variant is dead code. Should we clean it up?
Lines changed: 141 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,141 @@
1+
# Research Document: ADF Reconciler Tick Timeout and Process Leak
2+
3+
**Date:** 2026-05-19
4+
**Status:** Phase 1 research (thorough code review)
5+
6+
## 1. Problem Restatement and Scope
7+
8+
### Problem
9+
10+
The ADF orchestrator logs `reconcile_tick exceeded timeout, forcing continuation` every 90 s. Build-runner never spawns automatically on push events. Sixty-plus orphaned `opencode` processes accumulate during runtime.
11+
12+
### IN scope
13+
14+
- Why reconcile_tick always times out
15+
- Why build-runner never dispatches
16+
- Why opencode processes leak
17+
- The circuit breaker deadlock
18+
19+
### OUT of scope
20+
21+
- Changing tick interval configuration
22+
- Removing providers from KG routing rules
23+
- General memory optimisation
24+
25+
## 2. System Elements — Trace of a Push Event
26+
27+
Read from source at `crates/terraphim_orchestrator/src/`:
28+
29+
### 2.1 Push webhook arrival
30+
31+
1. **Gitea push** → webhook handler at `webhook.rs:498` (`handle_push_event`)
32+
2. Parses payload, creates `WebhookDispatch::Push`, sends via `dispatch_tx` (mpsc channel)
33+
3. Arrives in event loop at `lib.rs:1280` — tokio task forwards to main mpsc `loop_tx`
34+
4. Main loop `lib.rs:1301` receives `LoopEvent::Webhook(dispatch)`
35+
5. Calls `handle_webhook_dispatch()` at `lib.rs:3432`
36+
6. Match arm at `lib.rs:3714`**enqueues `DispatchTask::Push` into `self.dispatcher`** — does NOT spawn build-runner here
37+
7. Sends `LoopEvent::Tick` to trigger reconciliation
38+
39+
### 2.2 Tick event — where dispatch SHOULD happen
40+
41+
8. Main loop receives `LoopEvent::Tick` at `lib.rs:1314`
42+
9. Drains queued events (webhooks, schedules, alerts), coalescing stale ticks
43+
10. Calls `reconcile_tick()` wrapped in `tokio::time::timeout(90s)` at `lib.rs:1336`
44+
11. `reconcile_tick()` has 18 numbered steps at `lib.rs:5618`
45+
46+
### 2.3 reconcile_tick step ordering is the problem
47+
48+
| Step | Line | What | Duration |
49+
|------|------|------|----------|
50+
| 0 | 5621 | Clean rate limits, poll timeouts | Fast |
51+
| 1 | 5629 | Poll agent exits | Fast |
52+
| 2 | 5632 | Restart safety agents | Fast |
53+
| 3 | 5635 | Check cron schedules | Fast |
54+
| 4 | 5638 | Drain output events | Fast |
55+
| 5-12 | 5644-5717 | Nightwatch, handoff, budget, flows, mentions, KG reload | Fast |
56+
| **13** | **5719** | **Provider probes**`probe_all(kg_router).await` | **Blocks > 90 s** |
57+
| 14 | 5748 | Update `last_tick_time` | Fast |
58+
| 15-16 | 5752-5764 | Telemetry, budget persist | Fast |
59+
| **17** | **5795** | **Dispatch queue drain**`handle_push()` for each Push task | **Never reached** |
60+
| 18 | 5859 | Poll pending reviews | Never reached |
61+
62+
The tick is always cancelled at Step 13, so Steps 14-18 never execute.
63+
64+
### 2.4 Why probes take > 90 s
65+
66+
`probe_all()` at `provider_probe.rs:98`:
67+
68+
1. Iterates KG routing rules, collects unique `(provider, model, action)` triples
69+
2. For each, spawns `tokio::spawn(async { probe_single(...) })`
70+
3. Awaits all results sequentially
71+
72+
`probe_single()` at `provider_probe.rs:465`:
73+
74+
1. Spawns `bash -c "opencode run -m <model> --format json echo hello"`
75+
2. Waits up to 120 s for completion (`Duration::from_secs(120)` at line 542)
76+
3. On timeout: `kill -9 <pid>` (line 638)
77+
4. Returns `ProbeResult { status: Timeout }`
78+
79+
**Two connected problems:**
80+
81+
**Problem A — Timing mismatch:** The probe's internal 120 s timeout exceeds reconcile_tick's 90 s timeout. Even a single slow probe causes the entire tick to timeout.
82+
83+
**Problem B — Circuit breaker deadlock:** `probed_at` and circuit breaker state are only updated at lines 199-200 of `probe_all()`, AFTER all probes complete. When `probe_all()` is cancelled by the reconcile_tick timeout:
84+
85+
- `probed_at` is never set → `is_stale()` always returns `true` → probes re-run on every tick
86+
- Circuit breakers are never updated → providers never transition to `Open` state → probes always include timeout providers
87+
- Each tick spawns a new set of probe tasks → tasks accumulate
88+
89+
### 2.5 Process leak mechanism
90+
91+
When `reconcile_tick()` is cancelled at 90 s, the `probe_all().await` is dropped. But `tokio::spawn` tasks are NOT cancelled — they continue running independently.
92+
93+
Each probe task:
94+
1. `bash -c "opencode run ..."` is spawned
95+
2. The 120 s internal timeout fires
96+
3. `kill -9 <pid>` kills bash
97+
4. opencode (child of bash) becomes orphaned (PPID=1)
98+
5. orphan spawns child processes (`gtr`, `cached-context`, `sentrux`)
99+
6. All continue running indefinitely
100+
101+
Over 50 minutes (~33 tick cycles × 3 timeout providers ≈ 99 leaked opencode instances), 60+ orphans observed.
102+
103+
### 2.6 Why cleanup is insufficient
104+
105+
`adf-cleanup.sh` already has `pkill -9 -f '\.opencode run'` — but it only runs at startup. Orphans that accumulate during runtime are never cleaned up.
106+
107+
## 3. Constraints and Their Implications
108+
109+
### C1: Probe timeout (120 s) exceeds reconcile timeout (90 s)
110+
- **Effect:** Multiple probes running in `tokio::spawn` will always exceed 90 s if any provider is slow/unavailable
111+
- **Implication:** reconcile_tick is ALWAYS cancelled; dispatch never happens
112+
113+
### C2: Circuit breaker never opens for timeout providers
114+
- **Effect:** `probed_at` and breaker state only updated after `probe_all()` completes — which never happens
115+
- **Implication:** `is_stale()` always true → probes always run with full set of providers → self-perpetuating
116+
117+
### C3: tokio::spawn handles not cancelled on parent drop
118+
- **Effect:** Probe tasks continue running after reconcile_tick is cancelled
119+
- **Implication:** Accumulating orphans drive memory/swapping, further slowing the reconciler (death spiral)
120+
121+
### C4: Dispatch drain positioned after probes
122+
- **Effect:** Push events are enqueued but never dequeued because Step 17 is never reached
123+
- **Implication:** Build-runner never spawns automatically
124+
125+
## 4. Risks
126+
127+
| Risk | Severity | Cause |
128+
|------|----------|-------|
129+
| OOM killer terminates critical processes | Critical | 60+ orphaned opencode consuming 20+ GB |
130+
| Push events silently dropped | High | Dispatcher queue never drained |
131+
| System becomes unresponsive | Medium | Load 23+, swap 3.9/4 GB exhausted |
132+
133+
## 5. Simplification Opportunities
134+
135+
1. **Handle push events directly** — Don't use the dispatch queue for push events. Call `handle_push()` directly from `handle_webhook_dispatch()`. This completely decouples build-runner dispatch from probe health.
136+
137+
2. **Set probed_at immediately** — Move `self.probed_at = Some(Instant::now())` to the START of `probe_all()`. This prevents `is_stale()` from returning true for the TTL duration, giving the reconciler breathing room.
138+
139+
3. **Kill process groups** — Use `kill -9 -<pgid>` to kill opencode children, not just bash parent.
140+
141+
4. **Add periodic orphan reaping** — Add a cleanup step to reconcile_tick that kills opencode processes older than 2 minutes.

crates/terraphim_orchestrator/src/lib.rs

Lines changed: 21 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -1704,7 +1704,9 @@ impl AgentOrchestrator {
17041704
let truncated: Vec<_> = learnings.into_iter().take(max_entries).collect();
17051705
let ids: Vec<String> = truncated.iter().map(|l| l.id.clone()).collect();
17061706

1707-
let mut section = String::from("## Prior Lessons\n\nLessons learned from previous agent runs. Apply relevant insights:\n\n");
1707+
let mut section = String::from(
1708+
"## Prior Lessons\n\nLessons learned from previous agent runs. Apply relevant insights:\n\n",
1709+
);
17081710
for l in &truncated {
17091711
section.push_str(&format!(
17101712
"- [{}] {} (trust: {}, verified {}x)\n",
@@ -3725,16 +3727,19 @@ impl AgentOrchestrator {
37253727
after_sha = %after_sha,
37263728
pusher = %pusher_login,
37273729
files = files_changed.len(),
3728-
"webhook: enqueuing Push dispatch task"
3730+
"webhook: dispatching Push directly"
37293731
);
3730-
self.dispatcher.enqueue(dispatcher::DispatchTask::Push {
3732+
let task = dispatcher::DispatchTask::Push {
37313733
project,
37323734
ref_name,
37333735
before_sha,
37343736
after_sha,
37353737
pusher_login,
37363738
files_changed,
3737-
});
3739+
};
3740+
if let Err(e) = self.handle_push(task).await {
3741+
warn!(error = %e, "handle_push failed in webhook handler");
3742+
}
37383743
}
37393744
}
37403745
}
@@ -5618,6 +5623,18 @@ impl AgentOrchestrator {
56185623
async fn reconcile_tick(&mut self) {
56195624
let tick_start = Instant::now();
56205625

5626+
// 0. Reap orphaned opencode probe processes every 12 ticks (~1 min
5627+
// at 5 s interval). Processes that survive kill -9 -<pgid> in
5628+
// probe_single may become PPID=1 orphans; periodic cleanup
5629+
// prevents accumulation.
5630+
if self.tick_count % 12 == 0 {
5631+
let _ = std::process::Command::new("pkill")
5632+
.arg("-9")
5633+
.arg("-f")
5634+
.arg(".opencode run")
5635+
.spawn();
5636+
}
5637+
56215638
self.provider_rate_limits.clean_expired();
56225639
self.retry_counts
56235640
.retain(|_, (_, ts)| ts.elapsed() < Duration::from_secs(3600));

0 commit comments

Comments
 (0)