carlos / platform Public

merge fix 7 and 8: a run ended before launch reads as cancelled or timed out

Re-review findings 7 and 8.

7. A cancel, or the run's deadline, that cut short the record read in
the post-switch Recheck set prepared=true. That disabled the launch
context's mapping, so the run ended as start failed (exit 125) instead
of cancelled (130) or timed out (124). The worker now keeps Prepare's
refusal and the Recheck's answer apart. A Recheck error is a refusal
unless it is context.Canceled or context.DeadlineExceeded and the run's
own launch context has ended. Only then do the run's cancel and
deadline decide the result. notOurs, the cancelled-before-launch,
import and incarnation refusals, and a Prepare that failed (staging that
meets the deadline included) keep their results.

8. A run whose deadline passed before any box launched it has a zero
Started time, so the CLI printed "timed out after" about 292 years.
followRun now tells it as "<host>: run <id> timed out before it
started", the before-launch pattern of RUN-C66 (cancelled before it
started), with no duration. That sentence is not in the copy deck and
needs copy review. Exit 124 is unchanged.

Tests: a post-switch record read blocked and then cancelled ends
cancelled, and blocked until the deadline ends timed out, neither with a
start time. With the old classification, both end as start failed. The
CLI tells a timeout before launch without a duration, and a timeout
after launch with its duration.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>

claude 2 weeks ago 4a05a71fd46d4f03047f869755f8d2200483b550 parent 1c23afa

4 files changed, +110 −7

internal/host/runexec.go +18 −6
internal/host/runexec_linux_test.go +63 −0
run.go +6 −1
run_test.go +23 −0

CI passed — run details

diff --git a/internal/host/runexec.go b/internal/host/runexec.go

index 9df72ec5a..4b8aacf1f 100644

--- a/internal/host/runexec.go

+++ b/internal/host/runexec.go

@@ -148,9 +148,14 @@ func (w *runsWorker) execute(ctx context.Context, rec provision.Record, req runs

// overlapped Prepare in place of Prepare's error, and a run the record

// no longer gives this box must get no result whatever RunCmd says.

notOurs := false

- // prepared: Prepare (or the Recheck after a switch wait) answered, so

- // its own error, not the launch context's end, is the run's story.

- prepared := false

+ // prepRefused: Prepare answered an error, so its own result, not the

+ // launch context's end, is the run's story (a staging that meets the

+ // deadline stays start failed). recheckErr is the post-switch

+ // Recheck's answer: a refusal keeps its own result too, but a record

+ // read the run's own cancel or deadline cut short is not a refusal

+ // (re-review 7).

+ prepRefused := false

+ var recheckErr error

spec := activator.CmdSpec{

RunID: req.ID,

Args: req.Argv,

@@ -159,12 +164,12 @@ func (w *runsWorker) execute(ctx context.Context, rec provision.Record, req runs

Stderr: chunks.Stream(runs.StreamErr),

Prepare: func(ctx context.Context) error {

err := w.prepare(ctx, instDir, req, h, launchDeadline(rec, req, w.now()))

- notOurs, prepared = errors.Is(err, errRunNotOurs), err != nil

+ notOurs, prepRefused = errors.Is(err, errRunNotOurs), err != nil

return err

Recheck: func(ctx context.Context) error {

err := w.launchable(ctx, req, h)

- notOurs, prepared = errors.Is(err, errRunNotOurs), err != nil

+ notOurs, recheckErr = errors.Is(err, errRunNotOurs), err

return err

}

@@ -188,7 +193,8 @@ func (w *runsWorker) execute(ctx context.Context, rec provision.Record, req runs

return

}

res := runResultForLaunch(err)

- if launchEnded != nil && !prepared {

+ recheckRefused := recheckErr != nil && !(launchEnded != nil && endedByContext(recheckErr))

+ if launchEnded != nil && !prepRefused && !recheckRefused {

// The admission ended with the run's own cancel or deadline:

// the run's own result, as after launch (re-review 5).

cancelled := cancelRequested(h)

@@ -239,6 +245,12 @@ func (w *runsWorker) execute(ctx context.Context, rec provision.Record, req runs

w.finish(ctx, rec, req, res, handle)

}

+// endedByContext reports whether err is a context's end: a read cut short

+// by a cancel or a deadline, never a refusal on the record's say.

+func endedByContext(err error) bool {

+ return errors.Is(err, context.Canceled) || errors.Is(err, context.DeadlineExceeded)

// launchContext is ctx bounded by the run's deadline and ended by its

// cancel: what RunCmd runs under (re-review 5). The cancel func must be

// called once RunCmd has returned.

diff --git a/internal/host/runexec_linux_test.go b/internal/host/runexec_linux_test.go

index e1e21bb91..192c06120 100644

--- a/internal/host/runexec_linux_test.go

+++ b/internal/host/runexec_linux_test.go

@@ -9,6 +9,7 @@ import (

"os"

"strings"

"sync"

+ "sync/atomic"

"testing"

"time"

@@ -717,6 +718,68 @@ func TestRunEndedDuringASwitchWaitGetsItsOwnResult(t *testing.T) {

})

}

+// blockOneRead holds the first store read after it is armed until the

+// read's context ends: the post-switch record read, cut short.

+type blockOneRead struct {

+ release.Store

+ armed atomic.Bool

+ reading chan struct{}

+func (b *blockOneRead) Get(ctx context.Context, key string) ([]byte, string, error) {

+ if b.armed.CompareAndSwap(true, false) {

+ close(b.reading)

+ <-ctx.Done()

+ return nil, "", ctx.Err()

+ }

+ return b.Store.Get(ctx, key)

+// rechecksAfterSwitch is RunCmd past a switch wait: Prepare, then the

+// post-switch Recheck, whose record read the store holds. It starts

+// nothing, and returns the Recheck's answer as RunCmd does.

+type rechecksAfterSwitch struct{ store *blockOneRead }

+func (l *rechecksAfterSwitch) RunCmd(ctx context.Context, rt registry.Route, spec activator.CmdSpec) (activator.CmdHandle, error) {

+ if err := spec.Prepare(ctx); err != nil {

+ return nil, err

+ }

+ l.store.armed.Store(true)

+ return nil, spec.Recheck(ctx)

+// A cancel or the deadline that cuts short the post-switch record read is

+// the run's own end, cancelled (130) or timed out (124), never "start

+// failed" (re-review 7).

+func TestRunEndedDuringThePostSwitchRecheckGetsItsOwnResult(t *testing.T) {

+ t.Run("cancelled", func(t *testing.T) {

+ s := &blockOneRead{Store: release.NewDirStore(t.TempDir()), reading: make(chan struct{})}

+ rec, req := pickedRun(t, s, 60)

+ h := newRunHandle()

+ go func() { <-s.reading; h.requestCancel() }()

+ res := runOn(t, execWorker(t, s, &rechecksAfterSwitch{store: s}, "boot-1"), s, rec, req, h)

+ if !res.Cancelled || res.TimedOut || res.Interrupted != "" || !res.Started.IsZero() {

+ t.Fatalf("result %+v, want cancelled", res)

+ }

+ })

+ t.Run("expired", func(t *testing.T) {

+ s := &blockOneRead{Store: release.NewDirStore(t.TempDir()), reading: make(chan struct{})}

+ rec, id := queueRun(t, s, time.Now().Add(time.Minute))

+ req, err := runs.ReadRequest(context.Background(), s, rec.Account, rec.App, id)

+ if err != nil {

+ t.Fatal(err)

+ }

+ got, err := provision.SetRecordRun(context.Background(), s, rec.Account, rec.App, rec.Host, provision.RunPick(id, "box-1", "boot-1", time.Now().Add(300*time.Millisecond)))

+ if err != nil {

+ t.Fatal(err)

+ }

+ res := runOn(t, execWorker(t, s, &rechecksAfterSwitch{store: s}, "boot-1"), s, *got, *req, newRunHandle())

+ if !res.TimedOut || res.Cancelled || res.Interrupted != "" || !res.Started.IsZero() {

+ t.Fatalf("result %+v, want timed out", res)

+ }

+ })

func TestExitOfReadsNumbersAndWords(t *testing.T) {

for _, c := range []struct {

code, status string

diff --git a/run.go b/run.go

index f8140c777..645035006 100644

--- a/run.go

+++ b/run.go

@@ -457,9 +457,14 @@ func followRun(ctx context.Context, c runClient, t runTerm, host, id string, exp

// it ends the ack, not the exit code, and cancels nothing.

watch.run(ctx, func(ctx context.Context) { ackRun(ctx, c, t, id, p.Result.LastSeq) })

code, lines := runExit(host, *p.Result)

- if p.Result.Cancelled && p.Result.Started.IsZero() {

+ switch {

+ case p.Result.Cancelled && p.Result.Started.IsZero():

// Cancelled before any box launched it: there was no command.

lines = []string{fmt.Sprintf("%s: run %s was cancelled before it started", host, id)}

+ case p.Result.TimedOut && p.Result.Started.IsZero():

+ // Its deadline passed before any box launched it: there was

+ // no command, and so no duration to report (re-review 8).

+ lines = []string{fmt.Sprintf("%s: run %s timed out before it started", host, id)}

}

for _, l := range lines {

t.say(l)

diff --git a/run_test.go b/run_test.go

index be5532f5c..a1d797383 100644

--- a/run_test.go

+++ b/run_test.go

@@ -517,6 +517,29 @@ func TestFollowRunTellsCancelledBeforeStartFromCancelledAfter(t *testing.T) {

}

+// A run whose deadline passed before any box launched it has no start

+// time: it is told as timed out before it started, never with a duration

+// measured from the zero time (re-review 8). Exit 124 either way.

+func TestFollowRunTellsTimedOutBeforeStartFromTimedOutAfter(t *testing.T) {

+ started := time.Unix(1_700_000_000, 0)

+ for _, c := range []struct {

+ res runs.Result

+ says string

+ }{

+ {runs.Result{TimedOut: true, Ended: started}, "shop.example.com: run run_a timed out before it started\n"},

+ {runs.Result{TimedOut: true, Started: started, Ended: started.Add(30 * time.Minute)}, "shop.example.com: the command timed out after 30m0s\n"},

+ } {

+ f := newTermFx()

+ s := &scriptedRun{pages: []runs.Page{{State: "done", Result: &c.res}}}

+ if code := followRun(context.Background(), s, f.term(), "shop.example.com", "run_a", time.Time{}); code != 124 {

+ t.Fatalf("%+v: exit %d", c.res, code)

+ }

+ if got := f.err.String(); got != c.says {

+ t.Fatalf("%+v: stderr %q, want %q", c.res, got, c.says)

+ }

func TestFollowRunExpiresAQueuedRunAfterSixtySeconds(t *testing.T) {

f := newTermFx()

s := &scriptedRun{pages: []runs.Page{{State: "queued"}}, expireTo: "expired"}