a73x

604f4e07

fix(ci): a test must fail, not hang; a failing gate must print its evidence

a73x   2026-08-09 15:08

Commit message
fix(ci): a test must fail, not hang; a failing gate must print its evidence

The serial pump records its console stream only after ConsoleSource.Open
returns, and input written while there is no stream is dropped — typing into an
unplugged terminal. The listener accepting a dial is therefore not the moment
the pump can forward keystrokes, so a test that synchronises on the accept and
then writes input is racing: when the pump goroutine is descheduled in that
window the keystroke goes nowhere and the test waits for a byte that will never
come. It now waits for the pump to hold the stream.

Every wait in the pump's tests is bounded: reads and writes carry a deadline or
a watchdog, and channel receives go through one helper that names what never
arrived. A broken claim about the pump reports as a failed assertion in seconds
instead of a ten-minute suite-wide panic that names no claim at all.

The coverage gate streams the test run and reads the per-package percentages
from a tee'd copy. Captured into a variable, a failing `go test` took its whole
output down with it under `set -e` — the gate reported a real test failure as
silence — and the run's exit status is now surfaced with the output that
explains it.

internal/agent/serialpump/serialpump_test.go
Old New
@@ -2,6 +2,7 @@ package serialpump
2 2
3 import ( 3 import (
4 "context" 4 "context"
5 "fmt"
5 "io" 6 "io"
6 "net" 7 "net"
7 "os" 8 "os"
@@ -14,6 +15,26 @@ import (
14 "github.com/stretchr/testify/require" 15 "github.com/stretchr/testify/require"
15 ) 16 )
16 17
18 // Every wait in this file is bounded. A pump that stops forwarding bytes must
19 // report as a failed assertion in seconds; an unbounded read or write turns one
20 // broken claim into a ten-minute suite-wide panic that names no claim at all.
21 const ioTimeout = 5 * time.Second
22
23 // recvWithin receives one value from ch, failing with what if none arrives.
24 //
25 //nolint:ireturn // the type parameter IS the channel's element type (conn, error, signal)
26 func recvWithin[T any](t *testing.T, ch <-chan T, what string) T {
27 t.Helper()
28 select {
29 case v := <-ch:
30 return v
31 case <-time.After(ioTimeout):
32 t.Fatal(what)
33 var zero T
34 return zero
35 }
36 }
37
17 // fakeCH is a unix-socket listener standing in for cloud-hypervisor's 38 // fakeCH is a unix-socket listener standing in for cloud-hypervisor's
18 // --serial socket=. It records input written by the pump and lets tests 39 // --serial socket=. It records input written by the pump and lets tests
19 // emit guest output. 40 // emit guest output.
@@ -42,13 +63,7 @@ func newFakeCH(t *testing.T, sock string) *fakeCH {
42 63
43 func (f *fakeCH) conn(t *testing.T) net.Conn { 64 func (f *fakeCH) conn(t *testing.T) net.Conn {
44 t.Helper() 65 t.Helper()
45 select { 66 return recvWithin(t, f.conns, "pump never dialed the serial socket")
46 case c := <-f.conns:
47 return c
48 case <-time.After(5 * time.Second):
49 t.Fatal("pump never dialed the serial socket")
50 return nil
51 }
52 } 67 }
53 68
54 // testSource dials the unix socket path returned by socketPath, standing in 69 // testSource dials the unix socket path returned by socketPath, standing in
@@ -59,6 +74,26 @@ func (s testSource) Open(vmID string) (io.ReadWriteCloser, error) {
59 return net.Dial("unix", s(vmID)) 74 return net.Dial("unix", s(vmID))
60 } 75 }
61 76
77 // waitConnected blocks until the pump has recorded its console stream. A
78 // listener accepting is NOT that moment: the pump stores p.conn only after
79 // Open returns, and viewer input arriving before then is dropped by design
80 // (typing into an unplugged terminal). Any test that forwards keystrokes must
81 // synchronise on the pump, not on the socket.
82 func waitConnected(t *testing.T, m *Manager, vmID string) {
83 t.Helper()
84 require.Eventually(t, func() bool {
85 m.mu.Lock()
86 p := m.pumps[vmID]
87 m.mu.Unlock()
88 if p == nil {
89 return false
90 }
91 p.mu.Lock()
92 defer p.mu.Unlock()
93 return p.conn != nil
94 }, ioTimeout, time.Millisecond, "pump never recorded a console stream")
95 }
96
62 func newTestManager(t *testing.T, dir string) *Manager { 97 func newTestManager(t *testing.T, dir string) *Manager {
63 t.Helper() 98 t.Helper()
64 m := NewManager( 99 m := NewManager(
@@ -81,14 +116,36 @@ func pipeViewer() (viewer io.ReadWriter, out io.Reader, in io.Writer) {
81 return rw{ir, ow}, or, iw 116 return rw{ir, ow}, or, iw
82 } 117 }
83 118
119 // readN reads exactly n bytes, failing the test if they never come. The read
120 // runs in its own goroutine because the viewer end is an io.Pipe, which has no
121 // deadline to set.
84 func readN(t *testing.T, r io.Reader, n int) []byte { 122 func readN(t *testing.T, r io.Reader, n int) []byte {
85 t.Helper() 123 t.Helper()
86 buf := make([]byte, n) 124 buf := make([]byte, n)
87 _, err := io.ReadFull(r, buf) 125 done := make(chan error, 1)
88 require.NoError(t, err) 126 go func() { _, err := io.ReadFull(r, buf); done <- err }()
127 require.NoError(t, recvWithin(t, done, fmt.Sprintf("timed out reading %d bytes", n)))
89 return buf 128 return buf
90 } 129 }
91 130
131 // writeAll writes b, failing rather than parking forever when nothing drains
132 // the far end — a stalled pump must not stall the test (the 1 MiB flood in
133 // TestSlowViewerIsDroppedNotBlocking would otherwise fill the socket buffer
134 // and block for good).
135 func writeAll(t *testing.T, w io.Writer, b []byte) {
136 t.Helper()
137 if c, ok := w.(net.Conn); ok {
138 require.NoError(t, c.SetWriteDeadline(time.Now().Add(ioTimeout)))
139 defer func() { _ = c.SetWriteDeadline(time.Time{}) }()
140 _, err := c.Write(b)
141 require.NoError(t, err)
142 return
143 }
144 done := make(chan error, 1)
145 go func() { _, err := w.Write(b); done <- err }()
146 require.NoError(t, recvWithin(t, done, fmt.Sprintf("timed out writing %d bytes", len(b))))
147 }
148
92 func TestBacklogReplayThenLive(t *testing.T) { 149 func TestBacklogReplayThenLive(t *testing.T) {
93 dir := t.TempDir() 150 dir := t.TempDir()
94 m := newTestManager(t, dir) 151 m := newTestManager(t, dir)
@@ -96,8 +153,7 @@ func TestBacklogReplayThenLive(t *testing.T) {
96 m.Ensure("vm1") 153 m.Ensure("vm1")
97 guest := ch.conn(t) 154 guest := ch.conn(t)
98 155
99 _, err := guest.Write([]byte("BOOT-LOG\n")) 156 writeAll(t, guest, []byte("BOOT-LOG\n"))
100 require.NoError(t, err)
101 157
102 viewer, out, _ := pipeViewer() 158 viewer, out, _ := pipeViewer()
103 errc := make(chan error, 1) 159 errc := make(chan error, 1)
@@ -108,11 +164,10 @@ func TestBacklogReplayThenLive(t *testing.T) {
108 // Backlog written before attach is replayed first... 164 // Backlog written before attach is replayed first...
109 assert.Equal(t, "BOOT-LOG\n", string(readN(t, out, 9))) 165 assert.Equal(t, "BOOT-LOG\n", string(readN(t, out, 9)))
110 // ...then live bytes flow. 166 // ...then live bytes flow.
111 _, err = guest.Write([]byte("LIVE\n")) 167 writeAll(t, guest, []byte("LIVE\n"))
112 require.NoError(t, err)
113 assert.Equal(t, "LIVE\n", string(readN(t, out, 5))) 168 assert.Equal(t, "LIVE\n", string(readN(t, out, 5)))
114 cancel() 169 cancel()
115 assert.ErrorIs(t, <-errc, context.Canceled) 170 assert.ErrorIs(t, recvWithin(t, errc, "Attach never returned after cancel"), context.Canceled)
116 } 171 }
117 172
118 func TestInputForwardedToSocket(t *testing.T) { 173 func TestInputForwardedToSocket(t *testing.T) {
@@ -121,13 +176,13 @@ func TestInputForwardedToSocket(t *testing.T) {
121 ch := newFakeCH(t, filepath.Join(dir, "vm1.serial.sock")) 176 ch := newFakeCH(t, filepath.Join(dir, "vm1.serial.sock"))
122 m.Ensure("vm1") 177 m.Ensure("vm1")
123 guest := ch.conn(t) 178 guest := ch.conn(t)
179 waitConnected(t, m, "vm1") // keystrokes sent before this are dropped, not queued
124 180
125 viewer, _, in := pipeViewer() 181 viewer, _, in := pipeViewer()
126 ctx := t.Context() 182 ctx := t.Context()
127 go m.Attach(ctx, "vm1", viewer, nil) //nolint:errcheck 183 go m.Attach(ctx, "vm1", viewer, nil) //nolint:errcheck
128 184
129 _, err := in.Write([]byte("ls\r")) 185 writeAll(t, in, []byte("ls\r"))
130 require.NoError(t, err)
131 assert.Equal(t, "ls\r", string(readN(t, guest, 3))) 186 assert.Equal(t, "ls\r", string(readN(t, guest, 3)))
132 } 187 }
133 188
@@ -145,13 +200,14 @@ func TestOnReadyFiresBeforeBacklog(t *testing.T) {
145 ch := newFakeCH(t, filepath.Join(dir, "vm1.serial.sock")) 200 ch := newFakeCH(t, filepath.Join(dir, "vm1.serial.sock"))
146 m.Ensure("vm1") 201 m.Ensure("vm1")
147 guest := ch.conn(t) 202 guest := ch.conn(t)
148 _, _ = guest.Write([]byte("X")) 203 writeAll(t, guest, []byte("X"))
149 204
150 viewer, out, _ := pipeViewer() 205 viewer, out, _ := pipeViewer()
151 ready := make(chan struct{}) 206 ready := make(chan struct{})
152 ctx := t.Context() 207 ctx := t.Context()
153 go m.Attach(ctx, "vm1", viewer, func() error { close(ready); return nil }) //nolint:errcheck 208 go m.Attach(ctx, "vm1", viewer, func() error { close(ready); return nil }) //nolint:errcheck
154 <-ready // onReady before any viewer write (protocol: reply frame precedes raw bytes) 209 // onReady before any viewer write (protocol: reply frame precedes raw bytes).
210 recvWithin(t, ready, "onReady never fired")
155 assert.Equal(t, "X", string(readN(t, out, 1))) 211 assert.Equal(t, "X", string(readN(t, out, 1)))
156 } 212 }
157 213
@@ -163,8 +219,7 @@ func TestRingIsBounded(t *testing.T) {
163 m.Ensure("vm1") 219 m.Ensure("vm1")
164 guest := ch.conn(t) 220 guest := ch.conn(t)
165 221
166 _, err := guest.Write([]byte("0123456789ABCDEFGHIJ")) // 20 bytes > 16 222 writeAll(t, guest, []byte("0123456789ABCDEFGHIJ")) // 20 bytes > 16
167 require.NoError(t, err)
168 // Wait until the pump has drained all 20 bytes into the log. 223 // Wait until the pump has drained all 20 bytes into the log.
169 log := filepath.Join(dir, "vm1.serial.log") 224 log := filepath.Join(dir, "vm1.serial.log")
170 require.Eventually(t, func() bool { 225 require.Eventually(t, func() bool {
@@ -191,8 +246,7 @@ func TestOnDiskLogRotatesAtCap(t *testing.T) {
191 for i := range big { 246 for i := range big {
192 big[i] = 'a' 247 big[i] = 'a'
193 } 248 }
194 _, err := guest.Write(big) 249 writeAll(t, guest, big)
195 require.NoError(t, err)
196 require.Eventually(t, func() bool { 250 require.Eventually(t, func() bool {
197 _, err := os.Stat(filepath.Join(dir, "vm1.serial.log.old")) 251 _, err := os.Stat(filepath.Join(dir, "vm1.serial.log.old"))
198 return err == nil 252 return err == nil
@@ -230,8 +284,7 @@ func TestSlowViewerIsDroppedNotBlocking(t *testing.T) {
230 // receive observes the close and errors out. 284 // receive observes the close and errors out.
231 junk := make([]byte, 4096) 285 junk := make([]byte, 4096)
232 for range 256 { 286 for range 256 {
233 _, err := guest.Write(junk) 287 writeAll(t, guest, junk)
234 require.NoError(t, err)
235 } 288 }
236 select { 289 select {
237 case err := <-errc: 290 case err := <-errc:
@@ -242,8 +295,7 @@ func TestSlowViewerIsDroppedNotBlocking(t *testing.T) {
242 // Pump still healthy after the drop: fresh output still lands in the log. 295 // Pump still healthy after the drop: fresh output still lands in the log.
243 log := filepath.Join(dir, "vm1.serial.log") 296 log := filepath.Join(dir, "vm1.serial.log")
244 prev, _ := os.Stat(log) 297 prev, _ := os.Stat(log)
245 _, err := guest.Write([]byte("still-draining")) 298 writeAll(t, guest, []byte("still-draining"))
246 require.NoError(t, err)
247 require.Eventually(t, func() bool { 299 require.Eventually(t, func() bool {
248 st, err := os.Stat(log) 300 st, err := os.Stat(log)
249 return err == nil && (prev == nil || st.Size() > prev.Size()) 301 return err == nil && (prev == nil || st.Size() > prev.Size())
@@ -267,15 +319,13 @@ func TestFanOutToTwoViewers(t *testing.T) {
267 319
268 // Both viewers see the same bytes (whichever attached later gets them via 320 // Both viewers see the same bytes (whichever attached later gets them via
269 // the ring replay — same contract either way). 321 // the ring replay — same contract either way).
270 _, err := guest.Write([]byte("BOTH")) 322 writeAll(t, guest, []byte("BOTH"))
271 require.NoError(t, err)
272 assert.Equal(t, "BOTH", string(readN(t, out1, 4))) 323 assert.Equal(t, "BOTH", string(readN(t, out1, 4)))
273 assert.Equal(t, "BOTH", string(readN(t, out2, 4))) 324 assert.Equal(t, "BOTH", string(readN(t, out2, 4)))
274 325
275 // One viewer detaching must not disturb the other. 326 // One viewer detaching must not disturb the other.
276 cancel1() 327 cancel1()
277 _, err = guest.Write([]byte("SOLO")) 328 writeAll(t, guest, []byte("SOLO"))
278 require.NoError(t, err)
279 assert.Equal(t, "SOLO", string(readN(t, out2, 4))) 329 assert.Equal(t, "SOLO", string(readN(t, out2, 4)))
280 } 330 }
281 331
@@ -296,7 +346,7 @@ func TestPumpReconnectsAfterSocketRestart(t *testing.T) {
296 ch := newFakeCH(t, sock) 346 ch := newFakeCH(t, sock)
297 m.Ensure("vm1") 347 m.Ensure("vm1")
298 guest := ch.conn(t) 348 guest := ch.conn(t)
299 _, _ = guest.Write([]byte("A")) 349 writeAll(t, guest, []byte("A"))
300 // Listener FIRST, then conn: closing the conn first lets the pump re-dial 350 // Listener FIRST, then conn: closing the conn first lets the pump re-dial
301 // into the still-live old listener, parking it on a conn ch2 never sees. 351 // into the still-live old listener, parking it on a conn ch2 never sees.
302 ch.ln.Close() 352 ch.ln.Close()
@@ -310,8 +360,7 @@ func TestPumpReconnectsAfterSocketRestart(t *testing.T) {
310 // CH restarts (VM stop/start): a new listener appears; pump must re-dial. 360 // CH restarts (VM stop/start): a new listener appears; pump must re-dial.
311 ch2 := newFakeCH(t, sock) 361 ch2 := newFakeCH(t, sock)
312 guest2 := ch2.conn(t) // blocks until the pump reconnects 362 guest2 := ch2.conn(t) // blocks until the pump reconnects
313 _, err := guest2.Write([]byte("B")) 363 writeAll(t, guest2, []byte("B"))
314 require.NoError(t, err)
315 } 364 }
316 365
317 // TestEnsurePokesBackedOffPump pins the re-Ensure nudge: Shutdown deliberately 366 // TestEnsurePokesBackedOffPump pins the re-Ensure nudge: Shutdown deliberately
scripts/coverage.sh
Old New
@@ -59,11 +59,21 @@ declare -A FLOOR=(
59 ) 59 )
60 60
61 profile="$(mktemp)" 61 profile="$(mktemp)"
62 trap 'rm -f "$profile"' EXIT 62 report="$(mktemp)"
63 trap 'rm -f "$profile" "$report"' EXIT
63 64
64 # Capture the per-package "coverage: NN.N% of statements" lines. 65 # The run streams to the terminal and is teed to $report, from which the
65 report="$(go test -count=1 -covermode=atomic -coverprofile="$profile" \ 66 # per-package "coverage: NN.N% of statements" lines are read below. A failing
66 ./internal/... ./cmd/... 2>&1)" 67 # check must print its evidence: captured into a variable instead, a failing
68 # `go test` took its whole output down with it under `set -e`, and the gate
69 # reported a real test failure as silence.
70 status=0
71 go test -count=1 -covermode=atomic -coverprofile="$profile" \
72 ./internal/... ./cmd/... 2>&1 | tee "$report" || status=$?
73 if [ "$status" -ne 0 ]; then
74 echo "coverage gate: go test failed (exit $status) — see the output above" >&2
75 exit "$status"
76 fi
67 77
68 fail=0 78 fail=0
69 checked=0 79 checked=0
@@ -86,12 +96,12 @@ while IFS= read -r line; do
86 else 96 else
87 printf ' ok %-34s %5s%% (floor %s%%)\n' "$pkg" "$pct" "$floor" 97 printf ' ok %-34s %5s%% (floor %s%%)\n' "$pkg" "$pct" "$floor"
88 fi 98 fi
89 done <<<"$report" 99 done <"$report"
90 100
91 # Guard against a renamed/removed package silently dropping out of the gate. 101 # Guard against a renamed/removed package silently dropping out of the gate.
92 if [ "$checked" -ne "${#FLOOR[@]}" ]; then 102 if [ "$checked" -ne "${#FLOOR[@]}" ]; then
93 echo "coverage gate: expected ${#FLOOR[@]} gated packages, saw $checked — a gated package was renamed or removed" >&2 103 echo "coverage gate: expected ${#FLOOR[@]} gated packages, saw $checked — a gated package was renamed or removed" >&2
94 echo "$report" | grep -E 'FAIL|cannot|error' >&2 || true 104 grep -E 'FAIL|cannot|error' "$report" >&2 || true
95 exit 1 105 exit 1
96 fi 106 fi
97 107