Skip to content

Commit 268ea10

Browse files
authored
fix(agent): tick waiting progress during long provider calls (#256)
On a 90-file PR (+5848/-842) a single provider call legitimately runs for many minutes (observed 4m18s for turn 1; turn 3 exceeded 8m). Progress was only reported at turn boundaries, tool calls, and between retries — never while a call was in flight — so the stalled-review watchdog (which cancels after N minutes of progress silence) killed the review mid-call, discarding 12+ minutes of work to a full retry ("review stalled: no progress for 8m0s"). Add callWithWaitProgress: while a provider call is in flight, tick progress with "waiting on <label> (elapsed)" every minute, resetting the watchdog. Wired into retryProviderCall (anthropic/openai) and the codex post loop. A genuinely dead call is still bounded by the overall review timeout, as any sub-stall-timeout call already was. Tests run under -race (the ticker calls progress from a goroutine; the watchdog reset channel is concurrency-safe).
1 parent cc1d380 commit 268ea10

3 files changed

Lines changed: 138 additions & 2 deletions

File tree

internal/engine/agent/codex.go

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -331,7 +331,9 @@ func (a *codexAgent) post(ctx stdctx.Context, retry config.ProviderRetry, progre
331331
if err := ctx.Err(); err != nil {
332332
return nil, err
333333
}
334-
resp, err := a.postOnce(ctx, body)
334+
resp, err := callWithWaitProgress(ctx, progress, "codex.responses", func() (*codexResp, error) {
335+
return a.postOnce(ctx, body)
336+
})
335337
if err == nil {
336338
return resp, nil
337339
}

internal/engine/agent/provider_retry.go

Lines changed: 36 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -34,6 +34,41 @@ func (r providerRetryReason) String() string {
3434
return r.code
3535
}
3636

37+
// providerWaitProgressInterval is how often an in-flight provider call reports
38+
// waiting progress. A single call on a huge diff can legitimately run for many
39+
// minutes (observed: 4-8+ min per turn on a 90-file PR); without these ticks the
40+
// stalled-review watchdog (which cancels after N minutes of progress silence)
41+
// kills a review the provider is still working on. Var so tests can shorten it.
42+
var providerWaitProgressInterval = time.Minute
43+
44+
// callWithWaitProgress runs call, ticking progress with "waiting on <label>
45+
// (elapsed)" every providerWaitProgressInterval until it returns, so a long
46+
// provider call keeps resetting the stalled-review watchdog. A genuinely dead
47+
// call is still bounded by the overall review timeout.
48+
func callWithWaitProgress[T any](ctx stdctx.Context, progress func(string), label string, call func() (T, error)) (T, error) {
49+
if progress == nil {
50+
return call()
51+
}
52+
done := make(chan struct{})
53+
defer close(done)
54+
start := time.Now()
55+
go func() {
56+
ticker := time.NewTicker(providerWaitProgressInterval)
57+
defer ticker.Stop()
58+
for {
59+
select {
60+
case <-done:
61+
return
62+
case <-ctx.Done():
63+
return
64+
case <-ticker.C:
65+
progress(fmt.Sprintf("waiting on %s (%s)", label, time.Since(start).Round(time.Second)))
66+
}
67+
}
68+
}()
69+
return call()
70+
}
71+
3772
func retryProviderCall[T any](ctx stdctx.Context, retry config.ProviderRetry, progress func(string), label string, call func() (T, error), classify func(error) error, retryable func(error) (providerRetryReason, bool)) (T, error) {
3873
policy := resolveProviderRetryPolicy(retry, config.DefaultProviderRetryMaxRetries)
3974
var zero T
@@ -42,7 +77,7 @@ func retryProviderCall[T any](ctx stdctx.Context, retry config.ProviderRetry, pr
4277
if err := ctx.Err(); err != nil {
4378
return zero, err
4479
}
45-
out, err := call()
80+
out, err := callWithWaitProgress(ctx, progress, label, call)
4681
if err == nil {
4782
return out, nil
4883
}
Lines changed: 99 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,99 @@
1+
package agent
2+
3+
import (
4+
stdctx "context"
5+
"strings"
6+
"sync"
7+
"testing"
8+
"time"
9+
10+
"github.com/vanducng/miu-cr/internal/config"
11+
)
12+
13+
// progressRecorder collects progress messages; safe for the ticker goroutine.
14+
type progressRecorder struct {
15+
mu sync.Mutex
16+
msgs []string
17+
}
18+
19+
func (r *progressRecorder) record(s string) {
20+
r.mu.Lock()
21+
defer r.mu.Unlock()
22+
r.msgs = append(r.msgs, s)
23+
}
24+
25+
func (r *progressRecorder) waiting() []string {
26+
r.mu.Lock()
27+
defer r.mu.Unlock()
28+
var out []string
29+
for _, m := range r.msgs {
30+
if strings.Contains(m, "waiting on") {
31+
out = append(out, m)
32+
}
33+
}
34+
return out
35+
}
36+
37+
func shortWaitInterval(t *testing.T, d time.Duration) {
38+
t.Helper()
39+
old := providerWaitProgressInterval
40+
providerWaitProgressInterval = d
41+
t.Cleanup(func() { providerWaitProgressInterval = old })
42+
}
43+
44+
// A provider call that outlives the tick interval must emit waiting progress —
45+
// without it, the stalled-review watchdog (progress-silence based) cancels a
46+
// review the provider is still working on (observed on a 90-file PR whose
47+
// single turn ran past the 8m stall timeout).
48+
func TestCallWithWaitProgressTicksDuringLongCall(t *testing.T) {
49+
shortWaitInterval(t, 10*time.Millisecond)
50+
rec := &progressRecorder{}
51+
52+
out, err := callWithWaitProgress(stdctx.Background(), rec.record, "anthropic.messages", func() (string, error) {
53+
time.Sleep(80 * time.Millisecond)
54+
return "ok", nil
55+
})
56+
if err != nil || out != "ok" {
57+
t.Fatalf("call result = %q, %v", out, err)
58+
}
59+
ticks := rec.waiting()
60+
if len(ticks) == 0 {
61+
t.Fatal("expected waiting-progress ticks during a long provider call (stall watchdog would fire without them)")
62+
}
63+
if !strings.Contains(ticks[0], "waiting on anthropic.messages") {
64+
t.Fatalf("tick must name the call: %q", ticks[0])
65+
}
66+
}
67+
68+
func TestCallWithWaitProgressNilProgress(t *testing.T) {
69+
shortWaitInterval(t, time.Millisecond)
70+
out, err := callWithWaitProgress(stdctx.Background(), nil, "x", func() (int, error) {
71+
time.Sleep(10 * time.Millisecond)
72+
return 7, nil
73+
})
74+
if err != nil || out != 7 {
75+
t.Fatalf("call result = %d, %v", out, err)
76+
}
77+
}
78+
79+
// The wiring: retryProviderCall must tick waiting progress while its call is in
80+
// flight (this is the path the anthropic/openai review loops use).
81+
func TestRetryProviderCallTicksWaitingProgress(t *testing.T) {
82+
shortWaitInterval(t, 10*time.Millisecond)
83+
rec := &progressRecorder{}
84+
85+
out, err := retryProviderCall(stdctx.Background(), config.ProviderRetry{}, rec.record, "openai.chat",
86+
func() (string, error) {
87+
time.Sleep(60 * time.Millisecond)
88+
return "done", nil
89+
},
90+
func(err error) error { return err },
91+
func(err error) (providerRetryReason, bool) { return providerRetryReason{}, false },
92+
)
93+
if err != nil || out != "done" {
94+
t.Fatalf("call result = %q, %v", out, err)
95+
}
96+
if len(rec.waiting()) == 0 {
97+
t.Fatal("retryProviderCall must emit waiting-progress ticks during a long call")
98+
}
99+
}

0 commit comments

Comments
 (0)