fix(bench): kill a TTY exchange on inactivity instead of total time

bench/journeys_issue3766.go

@@ -4,10 +4,24 @@ import (
 	"bufio"
 	"fmt"
 	"io"
+	"path/filepath"
 	"strings"
 	"time"
 )
 
+// issue3766UpdateCooldownFixture seeds the sandbox HOME's state.json with a
+// current last_update_check, mirroring issue3561DanglingAncestorFixture: a
+// fresh sandbox HOME has no update cooldown, so when upstream is newer the
+// launch update check pops an "Update Available" modal that covers the menu
+// the TTY exchange waits for (#3971's second manifestation). No state.json
+// exists at this point, so only the cooldown is seeded and the journey keeps
+// running against a not-installed state.
+func issue3766UpdateCooldownFixture(sandbox *Sandbox) error {
+	statePath := filepath.Join(sandbox.Home, ".gentle-ai", "state.json")
+	state := fmt.Sprintf(`{"last_update_check":%q}`, time.Now().UTC().Format(time.RFC3339Nano))
+	return sandbox.write(statePath, state)
+}
+
 // issue3766Journeys drives #3766's switch under a real PTY. The sandbox supplies
 // an isolated HOME, so this proof cannot read or change a user's global config.
 func issue3766Journeys() []Journey {
@@ -18,6 +32,7 @@ func issue3766Journeys() []Journey {
 		Source: "#3766: the switch screen must expose resolved state and never touch a real user config",
 		Steps: []Step{
 			{Name: "fixture: repository", Fixture: baseRepo},
+			{Name: "fixture: update-check cooldown in the sandbox HOME", Fixture: issue3766UpdateCooldownFixture},
 			{Name: "Receipt-Driven Development toggles globally in the TUI", Composite: func(run *journeyRun) error {
 				observation, err := run.runTTY(nil, false, reviewModeTTYExchange)
 				if err != nil {

bench/runner.go

@@ -13,6 +13,7 @@ import (
 	"path/filepath"
 	"strings"
 	"sync"
+	"sync/atomic"
 	"time"
 
 	"github.com/charmbracelet/x/xpty"
@@ -238,7 +239,21 @@ func (s *Sandbox) invokeAt(dir string, args []string) Observation {
 	}
 }
 
+// ttyTimeout is the inactivity budget for one TTY exchange: how long the
+// exchange may go without receiving a single PTY byte before the child is
+// killed. It is deliberately NOT a whole-exchange deadline. In the CI
+// transition-axis run (#3971) the TUI keeps painting under CPU contention but
+// the whole multi-screen exchange outlives a fixed total budget, so the same
+// journey that passed the core run minutes earlier dies mid-read. Progress
+// resets this timer; a hung TUI that emits nothing still dies after exactly
+// this long.
 const ttyTimeout = 10 * time.Second
+
+// ttyOverallTimeout caps one whole TTY exchange however chatty the child is,
+// so a TUI that paints forever without ever reaching the expected screen
+// still terminates deterministically.
+const ttyOverallTimeout = 2 * time.Minute
+
 const ttyCleanupGrace = 250 * time.Millisecond
 
 var errTTYWaitCleanupTimeout = errors.New("TTY wait cleanup timed out")
@@ -270,17 +285,81 @@ func awaitTTYResult(result <-chan error) (error, bool) {
 	}
 }
 
-// runTTYWithTimeout owns every reader worker it starts. Exchange callbacks are
-// package-local and must return when terminal.Close unblocks their pending I/O.
+// runTTYWithTimeout runs one exchange with the given inactivity budget and
+// the default overall cap.
 func runTTYWithTimeout(cmd *exec.Cmd, terminal io.ReadWriteCloser, args []string, exchange func(*bufio.Reader, io.WriteCloser) error, timeout time.Duration, wait func(context.Context, *exec.Cmd) error) (Observation, error) {
+	return runTTYWithDeadlines(cmd, terminal, args, exchange, timeout, ttyOverallTimeout, wait)
+}
+
+// ttyWatchdog expires an exchange on either of two budgets: inactivity —
+// this long without receiving a PTY byte, refreshed by every byte the
+// terminal yields — or overall, a cap on the whole exchange. Both causes
+// unwrap to context.DeadlineExceeded so callers classify them exactly as the
+// old fixed deadline.
+type ttyWatchdog struct {
+	ctx    context.Context
+	cancel context.CancelCauseFunc
+	epoch  time.Time
+	last   atomic.Int64 // nanoseconds since epoch of the last PTY byte
+	done   chan struct{}
+	once   sync.Once
+}
+
+func newTTYWatchdog(inactivity, overall time.Duration) *ttyWatchdog {
+	ctx, cancel := context.WithCancelCause(context.Background())
+	watchdog := &ttyWatchdog{ctx: ctx, cancel: cancel, epoch: time.Now(), done: make(chan struct{})}
+	go watchdog.run(inactivity, overall)
+	return watchdog
+}
+
+func (w *ttyWatchdog) run(inactivity, overall time.Duration) {
+	for {
+		elapsed := time.Since(w.epoch)
+		idle := elapsed - time.Duration(w.last.Load())
+		if idle >= inactivity {
+			w.cancel(fmt.Errorf("no PTY output for %s: %w", inactivity, context.DeadlineExceeded))
+			return
+		}
+		if elapsed >= overall {
+			w.cancel(fmt.Errorf("TTY exchange exceeded its overall %s budget: %w", overall, context.DeadlineExceeded))
+			return
+		}
+		select {
+		case <-time.After(min(inactivity-idle, overall-elapsed)):
+		case <-w.done:
+			return
+		}
+	}
+}
+
+func (w *ttyWatchdog) stop() { w.once.Do(func() { close(w.done); w.cancel(nil) }) }
+
+// ttyProgressReader marks every received byte as watchdog progress.
+type ttyProgressReader struct {
+	watchdog *ttyWatchdog
+	reader   io.Reader
+}
+
+func (r *ttyProgressReader) Read(p []byte) (int, error) {
+	read, err := r.reader.Read(p)
+	if read > 0 {
+		r.watchdog.last.Store(int64(time.Since(r.watchdog.epoch)))
+	}
+	return read, err
+}
+
+// runTTYWithDeadlines owns every reader worker it starts. Exchange callbacks are
+// package-local and must return when terminal.Close unblocks their pending I/O.
+func runTTYWithDeadlines(cmd *exec.Cmd, terminal io.ReadWriteCloser, args []string, exchange func(*bufio.Reader, io.WriteCloser) error, inactivity, overall time.Duration, wait func(context.Context, *exec.Cmd) error) (Observation, error) {
 	var closed sync.Once
 	var closeErr error
 	closePTY := func() { closed.Do(func() { closeErr = terminal.Close() }) }
 	defer closePTY()
 	var output bytes.Buffer
-	reader := bufio.NewReader(io.TeeReader(terminal, &output))
-	ctx, cancel := context.WithTimeout(context.Background(), timeout)
-	defer cancel()
+	watchdog := newTTYWatchdog(inactivity, overall)
+	defer watchdog.stop()
+	reader := bufio.NewReader(io.TeeReader(&ttyProgressReader{watchdog: watchdog, reader: terminal}, &output))
+	ctx := watchdog.ctx
 	waitResult := make(chan error, 1)
 	go func() { waitResult <- wait(context.Background(), cmd) }()
 	exchangeResult := make(chan error, 1)
@@ -298,7 +377,7 @@ func runTTYWithTimeout(cmd *exec.Cmd, terminal io.ReadWriteCloser, args []string
 			terminate()
 		}
 	case <-ctx.Done():
-		timeoutErr = ctx.Err()
+		timeoutErr = context.Cause(ctx)
 		terminate()
 	}
 	if !exchangeDone {
@@ -323,7 +402,7 @@ func runTTYWithTimeout(cmd *exec.Cmd, terminal io.ReadWriteCloser, args []string
 			waitDone = true
 		case <-ctx.Done():
 			if timeoutErr == nil {
-				timeoutErr = ctx.Err()
+				timeoutErr = context.Cause(ctx)
 				terminate()
 			}
 			waitErr, waitDone = awaitTTYResult(waitResult)

bench/runner_test.go

@@ -10,6 +10,7 @@ import (
 	"os/exec"
 	"path/filepath"
 	"strings"
+	"sync"
 	"testing"
 	"time"
 
@@ -230,6 +231,148 @@ func TestRunTTYCleansUpAfterARealExchangeFailure(t *testing.T) {
 	}
 }
 
+// ttyFrame is one scripted burst of terminal output preceded by silence.
+type ttyFrame struct {
+	silence time.Duration
+	text    string
+}
+
+// slowFrameTTY replays scripted frames the way a loaded runner's TUI paints
+// them: silence, then a partial screen, then more silence. It stands in for
+// the real PTY so the #3971 timing can be reproduced deterministically and
+// fast, without a real child or a real 10s budget. Writing anything
+// containing "q" — the j121 quit key — makes the fake child exit, and Close
+// unblocks any pending read exactly as runTTY requires of a terminal.
+type slowFrameTTY struct {
+	mu        sync.Mutex
+	frames    []ttyFrame
+	loop      bool
+	closed    chan struct{}
+	quit      chan struct{}
+	closeOnce sync.Once
+	quitOnce  sync.Once
+}
+
+func newSlowFrameTTY(frames []ttyFrame, loop bool) *slowFrameTTY {
+	return &slowFrameTTY{frames: frames, loop: loop, closed: make(chan struct{}), quit: make(chan struct{})}
+}
+
+func (terminal *slowFrameTTY) Read(p []byte) (int, error) {
+	terminal.mu.Lock()
+	if len(terminal.frames) == 0 {
+		terminal.mu.Unlock()
+		return 0, io.EOF
+	}
+	frame := terminal.frames[0]
+	if !terminal.loop || len(terminal.frames) > 1 {
+		terminal.frames = terminal.frames[1:]
+	}
+	terminal.mu.Unlock()
+	select {
+	case <-time.After(frame.silence):
+	case <-terminal.closed:
+		return 0, os.ErrClosed
+	}
+	return copy(p, frame.text), nil
+}
+
+func (terminal *slowFrameTTY) Write(p []byte) (int, error) {
+	if strings.Contains(string(p), "q") {
+		terminal.quitOnce.Do(func() { close(terminal.quit) })
+	}
+	return len(p), nil
+}
+
+func (terminal *slowFrameTTY) Close() error {
+	terminal.closeOnce.Do(func() { close(terminal.closed) })
+	return nil
+}
+
+// wait exits the fake child when the exchange quits it or the PTY is closed,
+// exactly as the real TUI child behaves.
+func (terminal *slowFrameTTY) wait(context.Context, *exec.Cmd) error {
+	select {
+	case <-terminal.quit:
+	case <-terminal.closed:
+	}
+	return nil
+}
+
+// TestRunTTYToleratesASlowFirstFrameUnderLoad is #3971 with every duration
+// scaled down: in the CI transition-axis run, j121's TUI keeps painting under
+// CPU contention but the whole exchange outlives the fixed 10s budget, so the
+// step deadline kills the child mid-read ("read TUI before ... input/output
+// error; context deadline exceeded"). Here the budget passed to
+// runTTYWithTimeout stands in for the old fixed 10s total: the terminal keeps
+// making progress — every silence is shorter than the budget — but the
+// expected banner only completes after more than the budget in total. A
+// fixed whole-exchange deadline kills this exchange; a deadline that treats
+// PTY bytes as progress lets it finish.
+func TestRunTTYToleratesASlowFirstFrameUnderLoad(t *testing.T) {
+	terminal := newSlowFrameTTY([]ttyFrame{
+		{silence: 400 * time.Millisecond, text: "\x1b[2J\x1b[HReceipt-Driven Development\r\n"},
+		{silence: 400 * time.Millisecond, text: "RDD is currently "},
+		{silence: 700 * time.Millisecond, text: "ENABLED globally.\r\n"},
+	}, false)
+	observation, err := runTTYWithTimeout(&exec.Cmd{}, terminal, []string{"review-mode"}, func(reader *bufio.Reader, writer io.WriteCloser) error {
+		return waitForReviewModeTTY(reader, "RDD is currently ENABLED globally.", "", "", func() error {
+			_, err := io.WriteString(writer, "q")
+			return err
+		})
+	}, time.Second, terminal.wait)
+	if err != nil {
+		t.Fatalf("runTTY killed an exchange that never stopped making progress: %v", err)
+	}
+	if !strings.Contains(observation.Stdout, "RDD is currently ENABLED globally.") {
+		t.Fatalf("transcript = %q, want the banner the exchange waited for", observation.Stdout)
+	}
+	if observation.ExitCode != 0 {
+		t.Fatalf("exit code = %d, want 0", observation.ExitCode)
+	}
+}
+
+// A TUI that paints forever without ever reaching the expected screen must
+// not outlive the overall cap just because every byte resets the inactivity
+// timer.
+func TestRunTTYOverallCapKillsAForeverChatteringExchange(t *testing.T) {
+	terminal := newSlowFrameTTY([]ttyFrame{{silence: 25 * time.Millisecond, text: "tick "}}, true)
+	started := time.Now()
+	_, err := runTTYWithDeadlines(&exec.Cmd{}, terminal, []string{"review-mode"}, func(reader *bufio.Reader, _ io.WriteCloser) error {
+		_, err := reader.ReadString('\n')
+		return err
+	}, 5*time.Second, 300*time.Millisecond, terminal.wait)
+	if !errors.Is(err, context.DeadlineExceeded) {
+		t.Fatalf("runTTY error = %v, want the overall cap's deadline", err)
+	}
+	if !strings.Contains(err.Error(), "overall") {
+		t.Fatalf("runTTY error = %v, want it to name the overall budget", err)
+	}
+	if elapsed := time.Since(started); elapsed > 3*time.Second {
+		t.Fatalf("runTTY took %v, want bounded termination", elapsed)
+	}
+}
+
+// A hung TUI still dies after exactly the inactivity budget — long before an
+// eventual frame that would only arrive after the exchange stopped receiving
+// bytes for that long — and the failure names the inactivity, not a total.
+func TestRunTTYInactivityBudgetStillKillsASilentExchange(t *testing.T) {
+	terminal := newSlowFrameTTY([]ttyFrame{{silence: 5 * time.Second, text: "too late\r\n"}}, false)
+	started := time.Now()
+	_, err := runTTYWithDeadlines(&exec.Cmd{}, terminal, []string{"review-mode"}, func(reader *bufio.Reader, _ io.WriteCloser) error {
+		_, err := reader.ReadString('\n')
+		return err
+	}, 200*time.Millisecond, 10*time.Second, terminal.wait)
+	if !errors.Is(err, context.DeadlineExceeded) {
+		t.Fatalf("runTTY error = %v, want the inactivity deadline", err)
+	}
+	if !strings.Contains(err.Error(), "no PTY output") {
+		t.Fatalf("runTTY error = %v, want it to name the inactivity budget", err)
+	}
+	if elapsed := time.Since(started); elapsed > 2*time.Second {
+		t.Fatalf("runTTY took %v, want the inactivity budget to fire well before the frame", elapsed)
+	}
+}
+
 func TestInvokeTTYReportsPromptStartFailure(t *testing.T) {
 	sandbox := fakeBinary(t, "")
 	sandbox.Binary = filepath.Join(t.TempDir(), "missing-gentle-ai")