diff --git a/.gitignore b/.gitignore index 8ad215f6..4cf82df2 100644 --- a/.gitignore +++ b/.gitignore @@ -70,3 +70,4 @@ CLAUDE.md # Added by ggshield .cache_ggshield specs/*/review-transcript.jsonl +specs/*/review-transcript.jsonl.stderr diff --git a/cli/internal/cmd/spec.go b/cli/internal/cmd/spec.go index fd790309..3327bdad 100644 --- a/cli/internal/cmd/spec.go +++ b/cli/internal/cmd/spec.go @@ -6,6 +6,7 @@ import ( "os" "os/exec" "path/filepath" + "strings" "time" "github.com/spf13/cobra" @@ -38,6 +39,15 @@ var lookPath = exec.LookPath // runCommand is a seam for the launch itself, so the command's wiring is // testable without spawning a reviewer that would take half an hour. +// sessionAlive reports whether a detached tmux session still exists, and +// sleepFor paces the probe. Both are seams so tests can simulate a launch that +// died without needing tmux or real time. +var sessionAlive = func(session string) bool { + return exec.Command("tmux", "has-session", "-t", session).Run() == nil +} + +var sleepFor = time.Sleep + var runCommand = func(dir string, argv []string) error { c := exec.Command(argv[0], argv[1:]...) c.Dir = dir @@ -192,6 +202,9 @@ is the only record of how.`, if err := runCommand(repoRoot, launch); err != nil { return fmt.Errorf("starting the tmux session: %w", err) } + if err := confirmLaunched(session, transcript); err != nil { + return err + } cmd.Printf("[OK] Review running detached. Watch it with:\n\n tmux attach -t %s\n\n", session) cmd.Printf("When it finishes, %s carries the verdict and archive reads it.\n", spec.ReviewFile) return nil @@ -210,6 +223,63 @@ is the only record of how.`, return cmd } +// confirmLaunched turns "the session was created" into "the reviewer survived +// startup" — two claims the launcher used to conflate (#989). +// +// `tmux new-session -d` exits 0 the moment the session exists; the process +// inside it can be dead a fraction of a second later. Measured on the failure +// that prompted this: the session lasted 0.54s and the launcher reported a +// running review over a 0-byte transcript, so the archive gate's much later +// "no review.md" read as "you forgot to run it" rather than "it died". +// +// The window is deliberately modest. It proves the reviewer got past startup, +// which is where a bad credential, a missing binary or an unreachable model all +// fail; it does NOT promise the run will finish. A death at minute three is +// inherently unwatched in detached mode, and `spec archive` refusing without a +// review.md stays the backstop for that. +func confirmLaunched(session, transcript string) error { + const ( + window = 3 * time.Second // ~6x the slowest observed startup failure + step = 250 * time.Millisecond // cheap enough to poll, coarse enough not to spin + ) + for waited := time.Duration(0); waited < window; waited += step { + sleepFor(step) + if sessionAlive(session) { + continue + } + return fmt.Errorf("the review died on startup — tmux session %q is already gone.\n%s\n"+ + "Nothing was reviewed and %s was not written; re-run with --foreground to watch it fail live", + session, reviewerLastWords(transcript), spec.ReviewFile) + } + return nil +} + +// reviewerLastWords quotes what the dead reviewer actually said. An error that +// reproduces the output it received beats one that only reports that parsing or +// launching failed — the original defect discarded the reason entirely, which is +// why nobody could tell a broken credential from a missing binary. +func reviewerLastWords(transcript string) string { + for _, src := range []struct{ label, path string }{ + {"stderr", spec.StderrPath(transcript)}, + {"transcript", transcript}, + } { + b, err := os.ReadFile(src.path) + if err != nil { + continue + } + out := strings.TrimSpace(string(b)) + if out == "" { + continue + } + const max = 800 + if len(out) > max { + out = out[:max] + fmt.Sprintf("\n… (truncated; full %s at %s)", src.label, src.path) + } + return "It wrote, on " + src.label + ":\n" + out + } + return "It wrote nothing to either the transcript or its stderr, so the failure happened before the reviewer produced output at all." +} + func newSpecInitCmd() *cobra.Command { var ( issueNum int diff --git a/cli/internal/cmd/spec_review_test.go b/cli/internal/cmd/spec_review_test.go index 10a78cf9..24b4142c 100644 --- a/cli/internal/cmd/spec_review_test.go +++ b/cli/internal/cmd/spec_review_test.go @@ -4,6 +4,7 @@ import ( "os" "path/filepath" "strings" + "time" "testing" ) @@ -100,3 +101,104 @@ func TestSpecReviewRefusesAnUnpooledReviewer(t *testing.T) { t.Errorf("the refusal must list the available reviewers, got: %v", err) } } + +// --- BUG-081: the launcher must not announce a review it never started ------- +// +// `tmux new-session -d` returns 0 once the SESSION exists, which says nothing +// about the process inside it. Observed on HARNESS-072: the reviewer died on a +// broken credential, the session was gone within half a second, and the +// launcher printed "[OK] Review running detached" over a 0-byte transcript. + +// stubLaunch makes the detached path runnable in a test: tmux "exists", the +// new-session call "succeeds", and the sleep between liveness probes is free. +// alive decides whether the session outlives the probe window. +func stubLaunch(t *testing.T, alive bool) { + t.Helper() + prevLook, prevRun, prevAlive, prevSleep := lookPath, runCommand, sessionAlive, sleepFor + lookPath = func(string) (string, error) { return "/usr/bin/tmux", nil } + runCommand = func(string, []string) error { return nil } + sessionAlive = func(string) bool { return alive } + sleepFor = func(time.Duration) {} + t.Cleanup(func() { + lookPath, runCommand, sessionAlive, sleepFor = prevLook, prevRun, prevAlive, prevSleep + }) +} + +func TestSpecReviewFailsWhenTheLaunchDiedImmediately(t *testing.T) { + root := makeRepo(t) + seedPool(t, root) + seedSpec(t, root, "AI-001-x", "---\nstatus: implementing\n---\n# AI-001-x\n") + stubLaunch(t, false) + + stdout, stderr, err := execute(t, "spec", "review", "AI-001-x") + out := stdout + stderr + if err == nil { + t.Fatalf("a launch whose session is already gone must fail:\n%s", out) + } + if strings.Contains(out, "Review running detached") { + t.Errorf("announced a running review over a dead one:\n%s", out) + } +} + +// The error has to carry what the reviewer said, not just that it died. The +// death reason arrives on stderr, which the `| tee` pipeline never captured — +// that is why the original failure left no clue anywhere. +func TestSpecReviewQuotesTheReviewerStderrWhenItDies(t *testing.T) { + root := makeRepo(t) + seedPool(t, root) + seedSpec(t, root, "AI-001-x", "---\nstatus: implementing\n---\n# AI-001-x\n") + stubLaunch(t, false) + + stderrFile := filepath.Join(root, "specs", "AI-001-x", "review-transcript.jsonl.stderr") + if err := os.WriteFile(stderrFile, []byte("Error: bw resolve dockerhub/password: not found\n"), 0o644); err != nil { + t.Fatal(err) + } + + _, _, err := execute(t, "spec", "review", "AI-001-x") + if err == nil { + t.Fatal("expected the dead launch to fail") + } + if !strings.Contains(err.Error(), "bw resolve dockerhub/password") { + t.Errorf("the error must quote what the reviewer wrote, got: %v", err) + } +} + +func TestSpecReviewAnnouncesALaunchThatSurvived(t *testing.T) { + root := makeRepo(t) + seedPool(t, root) + seedSpec(t, root, "AI-001-x", "---\nstatus: implementing\n---\n# AI-001-x\n") + stubLaunch(t, true) + + stdout, stderr, err := execute(t, "spec", "review", "AI-001-x") + out := stdout + stderr + if err != nil { + t.Fatalf("a surviving launch must succeed: %v\n%s", err, out) + } + if !strings.Contains(out, "tmux attach -t review-AI-001-x") { + t.Errorf("a surviving launch must still tell the caller how to watch it:\n%s", out) + } +} + +// The stderr file is a sibling of the transcript, never merged into it: the +// transcript is jsonl an auditor parses, and interleaved diagnostics break that. +func TestSpecReviewRedirectsStderrBesideTheTranscript(t *testing.T) { + root := makeRepo(t) + seedPool(t, root) + seedSpec(t, root, "AI-001-x", "---\nstatus: implementing\n---\n# AI-001-x\n") + + prev := lookPath + lookPath = func(string) (string, error) { return "/usr/bin/tmux", nil } + t.Cleanup(func() { lookPath = prev }) + + stdout, stderr, err := execute(t, "spec", "review", "AI-001-x", "--dry-run") + if err != nil { + t.Fatalf("spec review --dry-run: %v", err) + } + out := stdout + stderr + if !strings.Contains(out, "review-transcript.jsonl.stderr") { + t.Errorf("stderr must be captured to its own file:\n%s", out) + } + if strings.Contains(out, "2>&1") { + t.Errorf("stderr must not be folded into the transcript pipe:\n%s", out) + } +} diff --git a/cli/internal/spec/review_launch.go b/cli/internal/spec/review_launch.go index 95aad00d..805b4de5 100644 --- a/cli/internal/spec/review_launch.go +++ b/cli/internal/spec/review_launch.go @@ -156,6 +156,16 @@ func TranscriptPath(repoRoot, specID string) string { return filepath.Join(repoRoot, "specs", specID, TranscriptFile) } +// StderrPath is where the launched reviewer's stderr lands, beside the +// transcript rather than inside it: the transcript is machine-readable jsonl an +// auditor parses, and interleaving diagnostics into it would corrupt that. +// +// It exists because the death reason used to have nowhere to go. TmuxWrap pipes +// the reviewer through `tee`, which carries stdout only, so a reviewer that died +// on startup wrote its error to a pane that vanished with the session — leaving +// a 0-byte transcript and no clue (#989). +func StderrPath(transcript string) string { return transcript + ".stderr" } + // ResolveReviewer picks which pool member runs. // // Default is the pool's FIRST entry — the launcher's primary. An explicit want @@ -279,6 +289,8 @@ func TmuxWrap(session, dir string, argv []string, transcript string) []string { "tmux", "new-session", "-d", "-s", session, "-c", dir, - ShellJoin(argv) + " | tee " + shellQuote(transcript), + ShellJoin(argv) + + " 2> " + shellQuote(StderrPath(transcript)) + + " | tee " + shellQuote(transcript), } }