Skip to content

Commit a1ea97e

Browse files
cristimclaude
andauthored
test(cli): harden output capture and signal failure diagnostics (#2216)
* test(cli): drain captureAppOutput while the callback runs The helper read the pipe only after fn returned, so output above the pipe buffer deadlocked the writer. Drain concurrently, close both ends on every path including panics, and add a 1 MiB regression test with a 10s guard. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> * test(cli): report child state when GCP signal markers time out Marker waits now fail with the child exit status (or still running) and its captured stderr. Child stdout is not read, preserving the blocked-stdout scenario. Timeouts are unchanged. Closes #2150 Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> --------- Co-authored-by: Claude Opus 5.5 <noreply@anthropic.com>
1 parent a2c4c7e commit a1ea97e

2 files changed

Lines changed: 96 additions & 11 deletions

File tree

‎cmd/configure_gcp_signal_test.go‎

Lines changed: 56 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -16,6 +16,7 @@ import (
1616
"os/exec"
1717
"path/filepath"
1818
"strings"
19+
"sync"
1920
"syscall"
2021
"testing"
2122
"time"
@@ -36,7 +37,7 @@ func TestRunConfigureGCP_InterruptCleansMintedKey(t *testing.T) {
3637
child, dir, stdout, stderr := startGCPInterruptChild(t, "upload")
3738
defer stdout.Close()
3839
var keyFile string
39-
require.Eventually(t, func() bool {
40+
requireMarker(t, child, stderr, "minted key.json with fixture secret", func() bool {
4041
matches, err := filepath.Glob(filepath.Join(dir, "cudly-gcp-key-*", "key.json"))
4142
if err != nil || len(matches) != 1 {
4243
return false
@@ -47,7 +48,7 @@ func TestRunConfigureGCP_InterruptCleansMintedKey(t *testing.T) {
4748
}
4849
keyFile = matches[0]
4950
return true
50-
}, 10*time.Second, 10*time.Millisecond)
51+
})
5152
require.NoError(t, child.Process.Signal(sig))
5253
err := child.Wait()
5354
require.NoFileExists(t, keyFile)
@@ -63,10 +64,10 @@ func TestRunConfigureGCP_InterruptCleansMintedKey(t *testing.T) {
6364
func TestRunConfigureGCP_InterruptDuringMint(t *testing.T) {
6465
child, dir, stdout, stderr := startGCPInterruptChild(t, "mint")
6566
defer stdout.Close()
66-
require.Eventually(t, func() bool {
67+
requireMarker(t, child, stderr, "creating marker", func() bool {
6768
_, err := os.Stat(filepath.Join(dir, "creating"))
6869
return err == nil
69-
}, 10*time.Second, 10*time.Millisecond)
70+
})
7071
require.NoError(t, child.Process.Signal(os.Interrupt))
7172
require.NoError(t, child.Wait(), "child stderr: %s", stderr.String())
7273
matches, err := filepath.Glob(filepath.Join(dir, "cudly-gcp-key-*"))
@@ -94,7 +95,56 @@ func TestRunConfigureGCP_InterruptAtPromptExits(t *testing.T) {
9495
require.NoFileExists(t, filepath.Join(dir, "minted"))
9596
}
9697

97-
func startGCPInterruptChild(t *testing.T, phase string) (*exec.Cmd, string, io.ReadCloser, *bytes.Buffer) {
98+
// syncBuffer lets the test read child stderr while exec is still copying it.
99+
type syncBuffer struct {
100+
mu sync.Mutex
101+
buf bytes.Buffer
102+
}
103+
104+
func (b *syncBuffer) Write(p []byte) (int, error) {
105+
b.mu.Lock()
106+
defer b.mu.Unlock()
107+
return b.buf.Write(p)
108+
}
109+
110+
func (b *syncBuffer) String() string {
111+
b.mu.Lock()
112+
defer b.mu.Unlock()
113+
return b.buf.String()
114+
}
115+
116+
// requireMarker polls cond for 10s. On timeout it fails with the child's
117+
// stderr and process state; child stdout is left untouched because one
118+
// scenario keeps it deliberately full.
119+
func requireMarker(t *testing.T, child *exec.Cmd, stderr *syncBuffer, what string, cond func() bool) {
120+
t.Helper()
121+
deadline := time.Now().Add(10 * time.Second)
122+
for !cond() {
123+
if time.Now().After(deadline) {
124+
t.Fatalf("timed out after 10s waiting for %s\nchild state: %s\nchild stderr: %q", what, childState(child), stderr.String())
125+
}
126+
time.Sleep(10 * time.Millisecond)
127+
}
128+
}
129+
130+
// childState reaps the child if it already exited, so a later Wait would
131+
// fail; it is only called on the failing path.
132+
func childState(child *exec.Cmd) string {
133+
var ws syscall.WaitStatus
134+
pid, err := syscall.Wait4(child.Process.Pid, &ws, syscall.WNOHANG, nil)
135+
switch {
136+
case err != nil:
137+
return fmt.Sprintf("wait4 failed: %v", err)
138+
case pid == 0:
139+
return fmt.Sprintf("still running (pid %d)", child.Process.Pid)
140+
case ws.Signaled():
141+
return fmt.Sprintf("exited, killed by signal %v", ws.Signal())
142+
default:
143+
return fmt.Sprintf("exited with code %d", ws.ExitStatus())
144+
}
145+
}
146+
147+
func startGCPInterruptChild(t *testing.T, phase string) (*exec.Cmd, string, io.ReadCloser, *syncBuffer) {
98148
t.Helper()
99149
dir := t.TempDir()
100150
adc := filepath.Join(dir, "adc.json")
@@ -111,7 +161,7 @@ func startGCPInterruptChild(t *testing.T, phase string) (*exec.Cmd, string, io.R
111161
t.Cleanup(func() { _ = stdin.Close() })
112162
stdout, err := child.StdoutPipe()
113163
require.NoError(t, err)
114-
stderr := new(bytes.Buffer)
164+
stderr := new(syncBuffer)
115165
child.Stderr = stderr
116166
require.NoError(t, child.Start())
117167
t.Cleanup(func() { _ = child.Process.Kill() })

‎cmd/multi_service_stats_test.go‎

Lines changed: 40 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -6,14 +6,17 @@ import (
66
"io"
77
"log"
88
"os"
9+
"strings"
910
"testing"
11+
"time"
1012

1113
"github.com/LeanerCloud/cloud-commitments-go/pkg/common"
1214
"github.com/stretchr/testify/assert"
1315
)
1416

1517
// captureAppOutput captures output from AppLogger and returns the captured string.
16-
// Usage: output := captureAppOutput(t, func() { printSomething() }).
18+
// The pipe is drained while fn runs so output beyond the pipe buffer cannot
19+
// block the writer. Usage: output := captureAppOutput(t, func() { printSomething() }).
1720
func captureAppOutput(t *testing.T, fn func()) string {
1821
t.Helper()
1922
old := os.Stdout
@@ -22,19 +25,29 @@ func captureAppOutput(t *testing.T, fn func()) string {
2225
if err != nil {
2326
t.Fatalf("os.Pipe failed: %v", err)
2427
}
28+
var buf bytes.Buffer
29+
drained := make(chan struct{})
30+
go func() {
31+
defer close(drained)
32+
_, _ = io.Copy(&buf, r)
33+
}()
2534
os.Stdout = w
2635
AppLogger = log.New(w, "", 0)
2736

37+
// Runs on panic too: restore, close the writer to end the drain, then
38+
// close the reader.
2839
defer func() {
2940
os.Stdout = old
3041
AppLogger = oldLogger
42+
_ = w.Close()
43+
<-drained
44+
_ = r.Close()
3145
}()
3246

3347
fn()
34-
35-
w.Close() // Must close writer before reading to unblock io.Copy
36-
var buf bytes.Buffer
37-
_, _ = io.Copy(&buf, r)
48+
// Close the writer before reading the buffer so the drain sees EOF.
49+
_ = w.Close()
50+
<-drained
3851
return buf.String()
3952
}
4053

@@ -558,3 +571,25 @@ func TestPrintFinalMessage(t *testing.T) {
558571
})
559572
}
560573
}
574+
575+
func TestCaptureAppOutputDrainsLargeOutput(t *testing.T) {
576+
const lines, width = 1024, 1024 // 1 MiB, far above the pipe buffer
577+
line := strings.Repeat("x", width-1)
578+
// A deadlocked helper never restores these; do it so later tests run.
579+
savedStdout, savedLogger := os.Stdout, AppLogger
580+
t.Cleanup(func() { os.Stdout, AppLogger = savedStdout, savedLogger })
581+
done := make(chan string, 1)
582+
go func() {
583+
done <- captureAppOutput(t, func() {
584+
for i := 0; i < lines; i++ {
585+
AppLogger.Println(line)
586+
}
587+
})
588+
}()
589+
select {
590+
case out := <-done:
591+
assert.Equal(t, lines*width, len(out))
592+
case <-time.After(10 * time.Second):
593+
t.Fatal("captureAppOutput deadlocked on output larger than the pipe buffer")
594+
}
595+
}

0 commit comments

Comments
 (0)