Report work that ends after the skill timeout as llm.ErrTimeout
runOnce only mapped an expired context to llm.ErrTimeout when execute returned an error, so a PostProcess that succeeded after the deadline was reported as a success. Check the deadline after execution (context cause or the clock, since the timer may not have fired yet) and fail such a run with llm.ErrTimeout and a provider_error ai_runs row. Adds a TestRunTimeout case with a skill whose PostProcess succeeds only after its timeout. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
This commit is contained in:
@@ -18,6 +18,17 @@ type timeoutSkill struct {
|
||||
|
||||
func (s timeoutSkill) Timeout() time.Duration { return s.timeout }
|
||||
|
||||
// slowSkill is timeoutSkill whose PostProcess succeeds only after its
|
||||
// timeout has passed.
|
||||
type slowSkill struct {
|
||||
timeoutSkill
|
||||
}
|
||||
|
||||
func (s slowSkill) PostProcess(out echoOutput) (echoOutput, error) {
|
||||
time.Sleep(3 * s.timeout)
|
||||
return s.timeoutSkill.PostProcess(out)
|
||||
}
|
||||
|
||||
// blocked is one scripted Generate call that blocks until released.
|
||||
type blocked struct {
|
||||
started chan struct{}
|
||||
@@ -266,6 +277,24 @@ func TestRunTimeout(t *testing.T) {
|
||||
t.Fatalf("rows = %+v, want one provider_error row naming the timeout", rows)
|
||||
}
|
||||
})
|
||||
t.Run("work that succeeds late", func(t *testing.T) {
|
||||
var f llm.Fake
|
||||
cfg := testConfig(t, &f)
|
||||
f.QueueGenerate(reply(`{"echo":"taco"}`))
|
||||
s := slowSkill{timeoutSkill{timeout: 20 * time.Millisecond}}
|
||||
out, err := Run(context.Background(), cfg, s, "week-1", echoInput{Word: "taco"})
|
||||
if !errors.Is(err, llm.ErrTimeout) {
|
||||
t.Fatalf("err = %v, want ErrTimeout", err)
|
||||
}
|
||||
if out != (echoOutput{}) {
|
||||
t.Fatalf("out = %+v, want no output", out)
|
||||
}
|
||||
assertCalls(t, &f, 1)
|
||||
rows := runRows(t, cfg.Store)
|
||||
if len(rows) != 1 || rows[0].Status != string(StatusProviderError) || !strings.Contains(rows[0].Error.String, llm.ErrTimeout.Error()) {
|
||||
t.Fatalf("rows = %+v, want one provider_error row naming the timeout", rows)
|
||||
}
|
||||
})
|
||||
t.Run("waiting for a slot", func(t *testing.T) {
|
||||
var f llm.Fake
|
||||
cfg := testConfig(t, &f)
|
||||
|
||||
@@ -165,12 +165,20 @@ func Run[In, Out any](ctx context.Context, cfg Config, s Skill[In, Out], scope s
|
||||
func runOnce[In, Out any](ctx context.Context, cfg Config, s Skill[In, Out], timeout time.Duration, in In) (Out, error) {
|
||||
var zero Out
|
||||
expired := fmt.Errorf("harness: skill %s v%d: %w: no result within %v", s.Name(), s.Version(), llm.ErrTimeout, timeout)
|
||||
ctx, cancel := context.WithTimeoutCause(ctx, timeout, expired)
|
||||
deadline := time.Now().Add(timeout)
|
||||
ctx, cancel := context.WithDeadlineCause(ctx, deadline, expired)
|
||||
defer cancel()
|
||||
log := &runLog{start: store.Now()}
|
||||
out, status, err := execute(ctx, cfg, s, in, log)
|
||||
if err != nil && context.Cause(ctx) == expired {
|
||||
err = fmt.Errorf("%w: %w", expired, err)
|
||||
// Work that only ends after the deadline, such as a slow PostProcess,
|
||||
// may return no error; it is still a timeout, not a success. The clock
|
||||
// is checked as well as ctx because ctx's timer may not have fired yet.
|
||||
if context.Cause(ctx) == expired || !time.Now().Before(deadline) {
|
||||
if err == nil {
|
||||
err, status = expired, StatusProviderError
|
||||
} else {
|
||||
err = fmt.Errorf("%w: %w", expired, err)
|
||||
}
|
||||
}
|
||||
if saveErr := log.save(ctx, cfg, s.Name(), s.Version(), status, err); saveErr != nil {
|
||||
return zero, errors.Join(err, fmt.Errorf("harness: skill %s v%d: record ai_runs row: %w", s.Name(), s.Version(), saveErr))
|
||||
|
||||
Reference in New Issue
Block a user