fix: add raced handling for mire record to handle delays for breaking stdin

2026-03-24 23:05:40 +00:00
parent 2171e2d907
commit be4c143b9d
10 changed files with 419 additions and 18 deletions
@@ -24,8 +24,8 @@ func newRecordCommand() *cobra.Command {
 				if errors.Is(err, mire.ErrRecordingDiscarded) {
 					return nil
 				}
-				cmd.PrintErrln(err)
-				return nil
+				cmd.SilenceUsage = true
+				return err
 			}

 			output.Println(createdPath)
@@ -172,6 +172,40 @@ func TestRunRecordSaveFlagSkipsPrompt(t *testing.T) {
 	})
 }

+func TestRunRecordReturnsNonZeroWhenVerificationFails(t *testing.T) {
+	testutil.AddFakeRecordDependencies(t, "bwrap", "bash")
+
+	root := t.TempDir()
+	testDir := filepath.Join(root, "e2e")
+	testutil.WriteValidConfig(t, filepath.Join(root, "mire.toml"), "e2e")
+	testutil.WriteFile(t, filepath.Join(testDir, "shell.sh"), "#!/bin/sh\nexit 0\n")
+	if err := os.Chmod(filepath.Join(testDir, "shell.sh"), 0o755); err != nil {
+		t.Fatalf("Chmod(shell.sh) error = %v", err)
+	}
+
+	testutil.WithWorkingDir(t, root, func() struct{} {
+		testutil.WithStdin(t, "", func() {
+			stdout, stderr := testutil.CaptureOutput(t, func() {
+				if got := Run([]string{"record", "--save", "suite/spec"}); got != 1 {
+					t.Fatalf("Run() code = %d, want %d", got, 1)
+				}
+			})
+
+			if stdout != "" {
+				t.Fatalf("stdout = %q, want empty", stdout)
+			}
+			if !strings.Contains(stderr, "internal mire failure - failed to replicate within time") {
+				t.Fatalf("stderr = %q, want propagated record failure", stderr)
+			}
+			if strings.Contains(stderr, "Usage:") {
+				t.Fatalf("stderr = %q, want usage suppressed", stderr)
+			}
+		})
+
+		return struct{}{}
+	})
+}
+
 func TestRunRewrite(t *testing.T) {
 	testutil.AddFakeRecordDependencies(t, "bwrap", "bash")

@@ -21,20 +21,70 @@ const (

 var interruptSuffix = []byte("^C\x1b[?2004l\r\x1b[?2004h\x1b[?2004l\r\r\n")

+const runWithBreaksMarker = "__MIRE_RUN_WITH_BREAKS___"
+
+type recordedInputFile struct {
+	data          []byte
+	runWithBreaks bool
+}
+
 func loadRecordedInput(path string) ([]byte, error) {
-	data, err := os.ReadFile(path)
+	recorded, err := loadRecordedInputFile(path)
 	if err != nil {
 		return nil, err
 	}

+	return recorded.data, nil
+}
+
+func loadRecordedInputFile(path string) (recordedInputFile, error) {
+	data, err := os.ReadFile(path)
+	if err != nil {
+		return recordedInputFile{}, err
+	}
+
 	if hasScriptWrapper(data) {
 		data, err = stripScriptWrapper(data)
 		if err != nil {
-			return nil, err
+			return recordedInputFile{}, err
 		}
 	}

-	return trimTrailingReplayNewline(data), nil
+	data = trimTrailingReplayNewline(data)
+
+	return parseRecordedInputFile(data), nil
+}
+
+func parseRecordedInputFile(data []byte) recordedInputFile {
+	recorded := recordedInputFile{data: data}
+
+	switch {
+	case bytes.Equal(data, []byte(runWithBreaksMarker)):
+		recorded.runWithBreaks = true
+		recorded.data = nil
+	case bytes.HasPrefix(data, []byte(runWithBreaksMarker+"\n")):
+		recorded.runWithBreaks = true
+		recorded.data = data[len(runWithBreaksMarker)+1:]
+	case bytes.HasPrefix(data, []byte(runWithBreaksMarker+"\r\n")):
+		recorded.runWithBreaks = true
+		recorded.data = data[len(runWithBreaksMarker)+2:]
+	}
+
+	return recorded
+}
+
+func prependRunWithBreaksMarker(data []byte) []byte {
+	recorded := parseRecordedInputFile(data)
+	if recorded.runWithBreaks {
+		return append([]byte(nil), data...)
+	}
+
+	prefixed := make([]byte, 0, len(runWithBreaksMarker)+1+len(data))
+	prefixed = append(prefixed, runWithBreaksMarker...)
+	prefixed = append(prefixed, '\n')
+	prefixed = append(prefixed, data...)
+
+	return prefixed
 }

 func loadRecordedOutput(path string) ([]byte, error) {
@@ -2,11 +2,13 @@ package mire

 import (
 	"bufio"
+	"errors"
 	"io"
 	"os"
 	"os/exec"
 	"path/filepath"
 	"strings"
+	"time"

 	"mire/internal/output"
 	"mire/internal/script"
@@ -18,6 +20,20 @@ type recordIO struct {
 	err io.Writer
 }

+var errInternalMireFailure = errors.New("internal mire failure - failed to replicate within time")
+
+type recordVerificationMode int
+
+const (
+	recordVerificationFast recordVerificationMode = iota
+	recordVerificationBreaks
+)
+
+type recordVerificationResult struct {
+	mode recordVerificationMode
+	err  error
+}
+
 func recordScenario(target, shellPath string, rio recordIO, sandboxConfig map[string]string, mounts, paths, setupScripts []string, save bool) error {
 	rawIn, rawOut, cleanup, err := newRecordFiles()
 	if err != nil {
@@ -41,9 +57,11 @@ func recordScenario(target, shellPath string, rio recordIO, sandboxConfig map[st

 	output.Fprintln(rio.err, "Run commands in the recorder shell, then type exit to finish.")

+	recordingStart := time.Now()
 	// this error is intentionally discarded to avoid non zero exit status inside record
 	// as an error
 	runRecordSession(target, rawIn, rawOut, shellPath, sandbox, rio, sandboxConfig, mounts, paths, setupScripts)
+	recordingElapsed := time.Since(recordingStart)

 	if !save {
 		save, err = confirmRecordSave(rio)
@@ -68,7 +86,74 @@ func recordScenario(target, shellPath string, rio recordIO, sandboxConfig map[st
 		return err
 	}

+	output.Fprintln(rio.err, "Verifying recording...")
+
+	scenario := testScenario{
+		dir:          target,
+		relPath:      target,
+		inPath:       filepath.Join(target, "in"),
+		outPath:      filepath.Join(target, "out"),
+		setupScripts: setupScripts,
+	}
+
+	return verifyRecordedScenario(target, recordedIn, recordingElapsed, func(opts replayOptions) error {
+		_, err := replayScenarioOutputWithOptions(scenario, shellPath, sandboxConfig, mounts, paths, opts)
+		return err
+	})
+}
+
+func countReplayBreaks(data []byte) int {
+	count := 0
+	for _, b := range data {
+		if b == '\n' || b == interruptByte || b == eofByte {
+			count++
+		}
+	}
+
+	return count
+}
+
+func verifyRecordedScenario(target string, recordedIn []byte, recordingElapsed time.Duration, verify func(replayOptions) error) error {
+	results := make(chan recordVerificationResult, 2)
+
+	go func() {
+		results <- recordVerificationResult{
+			mode: recordVerificationFast,
+			err: verify(replayOptions{
+				timeout: recordingElapsed + replayVerificationBuffer,
+			}),
+		}
+	}()
+
+	breakCount := countReplayBreaks(recordedIn)
+	go func() {
+		results <- recordVerificationResult{
+			mode: recordVerificationBreaks,
+			err: verify(replayOptions{
+				runWithBreaks: true,
+				timeout:       recordingElapsed + replayVerificationBuffer + (time.Duration(breakCount) * replayBreakDelay),
+			}),
+		}
+	}()
+
+	failures := 0
+	for failures < 2 {
+		result := <-results
+		if result.err == nil {
+			if result.mode != recordVerificationBreaks {
 				return nil
+			}
+
+			if err := os.WriteFile(filepath.Join(target, "in"), prependRunWithBreaksMarker(recordedIn), 0o644); err != nil {
+				return err
+			}
+			return nil
+		}
+
+		failures++
+	}
+
+	return errInternalMireFailure
 }

 func newRecordFiles() (string, string, func(), error) {
@@ -33,6 +33,7 @@ if [ "${MIRE_COMPARE_MARKER:-0}" = "1" ]; then
  }
  PROMPT_COMMAND=__mire_prompt_ready
 fi
+unset MIRE_COMPARE_MARKER
 EOF

 # the first ro-bind allows for /usr/bin etc to be mounted and accessible
@@ -42,8 +42,12 @@ func TestRecordCreatesRelativePath(t *testing.T) {
 		}
 	}

-	if got := testutil.ReadFile(t, filepath.Join(want, "in")); got != "exit\n" {
-		t.Fatalf("saved in = %q, want %q", got, "exit\n")
+	gotIn, err := loadRecordedInput(filepath.Join(want, "in"))
+	if err != nil {
+		t.Fatalf("loadRecordedInput(saved in) error = %v", err)
+	}
+	if string(gotIn) != "exit\n" {
+		t.Fatalf("saved in = %q, want replay input %q", string(gotIn), "exit\n")
 	}
 	if got := testutil.ReadFile(t, filepath.Join(want, "out")); got != "exit\r\nexit\r\n" {
 		t.Fatalf("saved out = %q, want %q", got, "exit\\r\\nexit\\r\\n")
@@ -146,6 +150,7 @@ func TestBuildRecordShellScriptUsesExpectedCommands(t *testing.T) {
 		`if [ "${MIRE_COMPARE_MARKER:-0}" = "1" ]; then`,
 		"printf '__MIRE_PROMPT_READY__\\n'",
 		"PROMPT_COMMAND=__mire_prompt_ready",
+		"unset MIRE_COMPARE_MARKER",
 		"--bind \"$host_home\" \"$visible_home\"",
 		"--bind \"$host_tmp\" '/tmp'",
 		"--setenv HOME \"$visible_home\"",
@@ -226,6 +231,102 @@ func TestRecordSessionEnvWithExtraIncludesAdditionalEntries(t *testing.T) {
 	}
 }

+func TestVerifyRecordedScenarioLeavesInputUnchangedWhenFastWins(t *testing.T) {
+	target := t.TempDir()
+	inPath := filepath.Join(target, "in")
+	recordedIn := []byte("echo hi\n")
+	testutil.WriteFile(t, inPath, string(recordedIn))
+
+	err := verifyRecordedScenario(target, recordedIn, 100*time.Millisecond, func(opts replayOptions) error {
+		if opts.runWithBreaks {
+			time.Sleep(20 * time.Millisecond)
+			return nil
+		}
+
+		time.Sleep(5 * time.Millisecond)
+		return nil
+	})
+	if err != nil {
+		t.Fatalf("verifyRecordedScenario() error = %v", err)
+	}
+
+	if got := testutil.ReadFile(t, inPath); got != string(recordedIn) {
+		t.Fatalf("saved in = %q, want %q", got, string(recordedIn))
+	}
+}
+
+func TestVerifyRecordedScenarioWritesMarkerWhenBreakModeWinsAfterFastFailure(t *testing.T) {
+	target := t.TempDir()
+	inPath := filepath.Join(target, "in")
+	recordedIn := []byte("echo hi\n")
+	testutil.WriteFile(t, inPath, string(recordedIn))
+
+	err := verifyRecordedScenario(target, recordedIn, 100*time.Millisecond, func(opts replayOptions) error {
+		if opts.runWithBreaks {
+			time.Sleep(20 * time.Millisecond)
+			return nil
+		}
+
+		time.Sleep(5 * time.Millisecond)
+		return errors.New("fast failed")
+	})
+	if err != nil {
+		t.Fatalf("verifyRecordedScenario() error = %v", err)
+	}
+
+	if got := testutil.ReadFile(t, inPath); got != runWithBreaksMarker+"\n"+string(recordedIn) {
+		t.Fatalf("saved in = %q, want slow marker prefix", got)
+	}
+}
+
+func TestVerifyRecordedScenarioWritesMarkerWhenBreakModeSucceedsFirst(t *testing.T) {
+	target := t.TempDir()
+	inPath := filepath.Join(target, "in")
+	recordedIn := []byte("echo hi\n")
+	testutil.WriteFile(t, inPath, string(recordedIn))
+
+	err := verifyRecordedScenario(target, recordedIn, 100*time.Millisecond, func(opts replayOptions) error {
+		if opts.runWithBreaks {
+			time.Sleep(5 * time.Millisecond)
+			return nil
+		}
+
+		time.Sleep(40 * time.Millisecond)
+		return nil
+	})
+	if err != nil {
+		t.Fatalf("verifyRecordedScenario() error = %v", err)
+	}
+
+	if got := testutil.ReadFile(t, inPath); got != runWithBreaksMarker+"\n"+string(recordedIn) {
+		t.Fatalf("saved in = %q, want slow marker prefix", got)
+	}
+}
+
+func TestVerifyRecordedScenarioFailsWhenBothModesFail(t *testing.T) {
+	target := t.TempDir()
+	inPath := filepath.Join(target, "in")
+	recordedIn := []byte("echo hi\n")
+	testutil.WriteFile(t, inPath, string(recordedIn))
+
+	err := verifyRecordedScenario(target, recordedIn, 100*time.Millisecond, func(opts replayOptions) error {
+		if opts.runWithBreaks {
+			time.Sleep(10 * time.Millisecond)
+			return errors.New("slow failed")
+		}
+
+		time.Sleep(5 * time.Millisecond)
+		return errors.New("fast failed")
+	})
+	if !errors.Is(err, errInternalMireFailure) {
+		t.Fatalf("verifyRecordedScenario() error = %v, want errInternalMireFailure", err)
+	}
+
+	if got := testutil.ReadFile(t, inPath); got != string(recordedIn) {
+		t.Fatalf("saved in = %q, want unchanged input", got)
+	}
+}
+
 func TestRunRecordSessionCapturesInputAndOutput(t *testing.T) {
 	shellPath := filepath.Join(t.TempDir(), "shell.sh")
 	testutil.WriteFile(t, shellPath, "#!/bin/sh\nprintf 'ready\\n'\nread line\nprintf 'seen:%s\\n' \"$line\"\n")
@@ -21,6 +21,16 @@ type replaySuite struct {
 	paths         []string
 }

+const (
+	replayBreakDelay         = 100 * time.Millisecond
+	replayVerificationBuffer = 2 * time.Second
+)
+
+type replayOptions struct {
+	runWithBreaks bool
+	timeout       time.Duration
+}
+
 func loadReplaySuite(path string) (replaySuite, error) {
 	root, err := currentProjectRoot()
 	if err != nil {
@@ -66,11 +76,26 @@ func loadReplaySuite(path string) (replaySuite, error) {
 }

 func replayScenarioOutput(scenario testScenario, shellPath string, sandboxConfig map[string]string, mounts, paths []string) ([]byte, error) {
-	input, err := loadRecordedInput(scenario.inPath)
+	recordedInput, err := loadRecordedInputFile(scenario.inPath)
 	if err != nil {
 		return nil, fmt.Errorf("failed to read recorded input: %v", err)
 	}

+	return replayScenarioOutputFromInput(scenario, shellPath, sandboxConfig, mounts, paths, recordedInput.data, replayOptions{
+		runWithBreaks: recordedInput.runWithBreaks,
+	})
+}
+
+func replayScenarioOutputWithOptions(scenario testScenario, shellPath string, sandboxConfig map[string]string, mounts, paths []string, opts replayOptions) ([]byte, error) {
+	recordedInput, err := loadRecordedInputFile(scenario.inPath)
+	if err != nil {
+		return nil, fmt.Errorf("failed to read recorded input: %v", err)
+	}
+
+	return replayScenarioOutputFromInput(scenario, shellPath, sandboxConfig, mounts, paths, recordedInput.data, opts)
+}
+
+func replayScenarioOutputFromInput(scenario testScenario, shellPath string, sandboxConfig map[string]string, mounts, paths []string, input []byte, opts replayOptions) ([]byte, error) {
 	_, rawOut, cleanupFiles, err := newRecordFiles()
 	if err != nil {
 		return nil, fmt.Errorf("failed to prepare replay files: %v", err)
@@ -104,6 +129,9 @@ func replayScenarioOutput(scenario testScenario, shellPath string, sandboxConfig
 		Input:      input,
 		InputReady: ready,
 		OutputLog:  promptWriter,
+		DelayInput: opts.runWithBreaks,
+		InputDelay: replayBreakDelay,
+		Timeout:    opts.timeout,
 	})
 	if err := rawOutFile.Close(); err != nil {
 		return nil, fmt.Errorf("failed to close replay output: %v", err)
@@ -114,6 +142,9 @@ func replayScenarioOutput(scenario testScenario, shellPath string, sandboxConfig
 		}
 		return nil, fmt.Errorf("replay shell never emitted %q; rerun `mire init` or refresh %q", compareOutputMarker, shellPath)
 	}
+	if replayResult.ProcessErr != nil {
+		return nil, fmt.Errorf("replay failed: %v", replayResult.ProcessErr)
+	}
 	if replayResult.OutputErr != nil {
 		return nil, fmt.Errorf("replay failed: %v", replayResult.OutputErr)
 	}
@@ -130,7 +161,6 @@ func replayScenarioOutput(scenario testScenario, shellPath string, sandboxConfig
 	if err != nil {
 		return nil, err
 	}
-
 	return got, nil
 }

@@ -214,6 +214,10 @@ func replayScenario(scenario testScenario, shellPath string, ignoreDiffs []strin
 		return err
 	}

+	return compareReplayedScenarioOutput(scenario, ignoreDiffs, got)
+}
+
+func compareReplayedScenarioOutput(scenario testScenario, ignoreDiffs []string, got []byte) error {
 	want, err := os.ReadFile(scenario.outPath)
 	if err != nil {
 		return fmt.Errorf("failed to read expected output: %v", err)
@@ -183,6 +183,33 @@ func TestReplayScenarioFailsWhenCompareMarkerMissing(t *testing.T) {
 	}
 }

+func TestReplayScenarioFailsWhenReplayTimesOutAfterPromptReady(t *testing.T) {
+	testDir := filepath.Join(t.TempDir(), "e2e")
+	shellPath := filepath.Join(testDir, "shell.sh")
+	testutil.WriteFile(t, shellPath, "#!/bin/sh\nprintf '__MIRE_PROMPT_READY__\\n'\nsleep 1\n")
+	if err := os.Chmod(shellPath, 0o755); err != nil {
+		t.Fatalf("Chmod(%q) error = %v", shellPath, err)
+	}
+	scenarioDir := filepath.Join(testDir, "suite", "spec")
+	testutil.WriteScenarioFixtures(t, scenarioDir, "exit\n", "exit\n")
+
+	_, err := replayScenarioOutputWithOptions(testScenario{
+		dir:          scenarioDir,
+		relPath:      filepath.Join("suite", "spec"),
+		inPath:       filepath.Join(scenarioDir, "in"),
+		outPath:      filepath.Join(scenarioDir, "out"),
+		setupScripts: nil,
+	}, shellPath, defaultSandboxConfig(), nil, nil, replayOptions{
+		timeout: 10 * time.Millisecond,
+	})
+	if err == nil {
+		t.Fatal("replayScenarioOutputWithOptions() error = nil, want timeout error")
+	}
+	if !strings.Contains(err.Error(), "context deadline exceeded") {
+		t.Fatalf("replayScenarioOutputWithOptions() error = %q, want context deadline exceeded", err.Error())
+	}
+}
+
 func TestDiscoverTestScenariosUsesDisplayRootForRelativePaths(t *testing.T) {
 	testDir := filepath.Join(t.TempDir(), "e2e")
 	scopedDir := filepath.Join(testDir, "nested")
@@ -13,6 +13,7 @@ package script

 import (
 	"bytes"
+	"context"
 	"errors"
 	"io"
 	"os"
@@ -47,6 +48,9 @@ type ReplayRequest struct {
 	Input      []byte
 	InputReady <-chan struct{}
 	OutputLog  io.Writer
+	DelayInput bool
+	InputDelay time.Duration
+	Timeout    time.Duration
 }

 type ReplayResult struct {
@@ -121,9 +125,31 @@ func Replay(req ReplayRequest) ReplayResult {

 	outputDone := copyAsync(combineWriters(req.OutputLog), ptmx)
 	processDone := make(chan struct{})
-	inputDone := copyAsyncWhenReady(ptmx, bytes.NewReader(replayInput(req.Input)), req.InputReady, processDone)
+	inputDone := copyReplayInputWhenReady(ptmx, req.Input, req.InputReady, processDone, req.DelayInput, req.InputDelay)
+
+	timedOut := make(chan struct{}, 1)
+	var timeout *time.Timer
+	if req.Timeout > 0 {
+		timeout = time.AfterFunc(req.Timeout, func() {
+			select {
+			case timedOut <- struct{}{}:
+			default:
+			}
+			if req.Cmd.Process != nil {
+				_ = req.Cmd.Process.Kill()
+			}
+		})
+	}

 	waitErr := req.Cmd.Wait()
+	if timeout != nil {
+		timeout.Stop()
+	}
+	select {
+	case <-timedOut:
+		waitErr = context.DeadlineExceeded
+	default:
+	}
 	close(processDone)
 	ptmx.Close()

@@ -166,8 +192,8 @@ func copyAsync(dst io.Writer, src io.Reader) <-chan error {
 	return done
 }

-// copyAsyncWhenReady delays replay input until the child shell is ready enough to receive it reliably.
-func copyAsyncWhenReady(dst io.Writer, src io.Reader, ready <-chan struct{}, stop <-chan struct{}) <-chan error {
+// copyReplayInputWhenReady delays replay input until the child shell is ready enough to receive it reliably.
+func copyReplayInputWhenReady(dst io.Writer, input []byte, ready <-chan struct{}, stop <-chan struct{}, delayInput bool, inputDelay time.Duration) <-chan error {
 	done := make(chan error, 1)
 	go func() {
 		if ready != nil {
@@ -181,22 +207,65 @@ func copyAsyncWhenReady(dst io.Writer, src io.Reader, ready <-chan struct{}, sto
 				return
 			}
 		}
-		_, err := io.Copy(dst, src)
+
+		data, appendedEOF := replayInput(input)
+		if !delayInput || inputDelay <= 0 {
+			_, err := io.Copy(dst, bytes.NewReader(data))
 			done <- normalizeCopyError(err)
+			return
+		}
+
+		for i, b := range data {
+			select {
+			case <-stop:
+				done <- nil
+				return
+			default:
+			}
+
+			if _, err := dst.Write([]byte{b}); err != nil {
+				done <- normalizeCopyError(err)
+				return
+			}
+
+			if appendedEOF && i == len(data)-1 {
+				continue
+			}
+			if !shouldDelayReplayByte(b) {
+				continue
+			}
+
+			timer := time.NewTimer(inputDelay)
+			select {
+			case <-timer.C:
+			case <-stop:
+				if !timer.Stop() {
+					<-timer.C
+				}
+				done <- nil
+				return
+			}
+		}
+
+		done <- nil
 	}()
 	return done
 }

 // replayInput appends terminal EOF so non-interactive replays still tell the shell when scripted input is finished.
-func replayInput(input []byte) []byte {
+func replayInput(input []byte) ([]byte, bool) {
 	if len(input) > 0 && input[len(input)-1] == terminalEOF {
-		return input
+		return input, false
 	}

 	data := make([]byte, 0, len(input)+1)
 	data = append(data, input...)
 	data = append(data, terminalEOF)
-	return data
+	return data, true
+}
+
+func shouldDelayReplayByte(b byte) bool {
+	return b == '\n' || b == 0x03 || b == terminalEOF
 }

 // copyInputAsync gives file-backed input an interruptible read loop so shutdown does not hang on blocked stdin reads.