Skip to content

Commit 2ce359a

Browse files
authored
fix(tcp): stop a cancelled context from being swallowed by the deadline re-arm (#366)
* fix(tcp): stop the read-deadline re-arm from swallowing a cancelled ctx the cancel watchdog trips conn.SetDeadline(now) once. if that trip lands while the probe write is still in flight, readTCP's later SetReadDeadline(now+timeout) call silently overwrote it, so the read blocked for the full timeout instead of returning promptly. thread ctx into readTCP and check it before arming the deadline and on every read iteration so a cancellation already in flight aborts immediately. * test(tcp): make the cancel-during-write test exercise the actual race the old test cancelled ctx before calling ExecuteTCPModule, so the pre-write ctx.Err() guard returned immediately and the test never reached readTCP at all; reverting the fix and rerunning it still passed in ~0ms. cancel from a goroutine mid-write instead, so the watchdog trips the deadline while readTCP is the next call on the path, and assert the call returns promptly rather than blocking for the full timeout. also add a case proving a legitimately slow but uncancelled connection still completes and matches normally.
1 parent f6db61b commit 2ce359a

2 files changed

Lines changed: 207 additions & 3 deletions

File tree

internal/modules/tcp.go

Lines changed: 28 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -101,14 +101,27 @@ func ExecuteTCPModule(ctx context.Context, target string, def *YAMLModule, opts
101101
}()
102102

103103
if cfg.Data != "" {
104+
// same re-arm hazard readTCP guards against: if the cancel watchdog's
105+
// SetDeadline(now) trip lands before this SetWriteDeadline call, the
106+
// call below would silently push the deadline back out to the full
107+
// timeout. Check ctx first so an already-cancelled run never arms it,
108+
// and prefer ctx.Err() over the raw write error so a write the
109+
// watchdog does trip is reported as a cancellation, not an i/o
110+
// timeout.
111+
if err := ctx.Err(); err != nil {
112+
return result, err
113+
}
104114
payload := decodeTCPData(cfg.Data)
105115
_ = conn.SetWriteDeadline(time.Now().Add(timeout))
106116
if _, err := conn.Write([]byte(payload)); err != nil {
117+
if ctxErr := ctx.Err(); ctxErr != nil {
118+
return result, ctxErr
119+
}
107120
return nil, fmt.Errorf("tcp write %q: %w", addr, err)
108121
}
109122
}
110123

111-
data := readTCP(conn, timeout)
124+
data := readTCP(ctx, conn, timeout)
112125
if err := ctx.Err(); err != nil {
113126
return result, err
114127
}
@@ -130,11 +143,24 @@ func ExecuteTCPModule(ctx context.Context, target string, def *YAMLModule, opts
130143
// cap bounds memory to roughly the limit plus one buffer. A timeout or EOF ends
131144
// the read normally: a silent or half-open service yields the bytes seen so far
132145
// rather than an error, leaving the verdict to the matchers.
133-
func readTCP(conn net.Conn, timeout time.Duration) string {
146+
//
147+
// ctx is checked before arming the read deadline and again on every loop
148+
// iteration. The cancel watchdog in ExecuteTCPModule trips the deadline with a
149+
// single SetDeadline(now) call, which arming a later deadline here would
150+
// otherwise silently overwrite (e.g. if the cancel lands while the probe
151+
// Write is still in flight): a cancelled ctx must abort the read immediately
152+
// rather than re-arm and block for the full timeout.
153+
func readTCP(ctx context.Context, conn net.Conn, timeout time.Duration) string {
154+
if ctx.Err() != nil {
155+
return ""
156+
}
134157
_ = conn.SetReadDeadline(time.Now().Add(timeout))
135158
var out []byte
136159
buf := make([]byte, 4096)
137160
for len(out) < tcpReadLimit {
161+
if ctx.Err() != nil {
162+
break
163+
}
138164
n, err := conn.Read(buf)
139165
if n > 0 {
140166
out = append(out, buf[:n]...)

internal/modules/tcp_test.go

Lines changed: 179 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -19,6 +19,7 @@ import (
1919
"net"
2020
"os"
2121
"path/filepath"
22+
"sync"
2223
"testing"
2324
"time"
2425
)
@@ -303,6 +304,183 @@ func TestExecuteTCPModuleContextCancel(t *testing.T) {
303304
}
304305
}
305306

307+
// fakeSlowConn is a net.Conn stand-in whose Write yields for a fixed duration
308+
// before returning success regardless of any deadline, and whose Read blocks
309+
// until whatever deadline was last armed via SetReadDeadline/SetDeadline, then
310+
// returns a timeout error. It reproduces a real socket closely enough to prove
311+
// the cancellation race: a cancel landing while the slow Write is in flight
312+
// trips the watchdog's SetDeadline(now) before readTCP arms its own (later)
313+
// read deadline.
314+
type fakeSlowConn struct {
315+
net.Conn
316+
mu sync.Mutex
317+
readDeadline time.Time
318+
writeYield time.Duration
319+
}
320+
321+
func (c *fakeSlowConn) Write(b []byte) (int, error) {
322+
time.Sleep(c.writeYield)
323+
return len(b), nil
324+
}
325+
326+
func (c *fakeSlowConn) Read([]byte) (int, error) {
327+
c.mu.Lock()
328+
dl := c.readDeadline
329+
c.mu.Unlock()
330+
if dl.IsZero() {
331+
dl = time.Now().Add(time.Hour)
332+
}
333+
if wait := time.Until(dl); wait > 0 {
334+
time.Sleep(wait)
335+
}
336+
return 0, os.ErrDeadlineExceeded
337+
}
338+
339+
func (c *fakeSlowConn) SetDeadline(t time.Time) error {
340+
c.mu.Lock()
341+
c.readDeadline = t
342+
c.mu.Unlock()
343+
return nil
344+
}
345+
346+
func (c *fakeSlowConn) SetReadDeadline(t time.Time) error { return c.SetDeadline(t) }
347+
func (c *fakeSlowConn) SetWriteDeadline(time.Time) error { return nil }
348+
func (c *fakeSlowConn) Close() error { return nil }
349+
350+
// TestExecuteTCPModuleContextCancelDuringWrite reproduces the deadline re-arm
351+
// race: the ctx is cancelled from another goroutine while the probe Write is
352+
// still yielding, so the watchdog's conn.SetDeadline(now) trip lands mid-write
353+
// rather than before ExecuteTCPModule is even entered. The Write then returns
354+
// its normal success (a fake real socket does not itself enforce the deadline
355+
// on a write already in flight), so execution reaches readTCP with the ctx
356+
// already done but no error yet surfaced. Before the fix, readTCP's own
357+
// SetReadDeadline(now+timeout) call overwrote the watchdog's trip and the read
358+
// blocked for the full timeout instead of returning promptly.
359+
func TestExecuteTCPModuleContextCancelDuringWrite(t *testing.T) {
360+
conn := &fakeSlowConn{writeYield: 200 * time.Millisecond}
361+
orig := newTCPConn
362+
newTCPConn = func(context.Context, string, time.Duration) (net.Conn, error) { return conn, nil }
363+
t.Cleanup(func() { newTCPConn = orig })
364+
365+
ctx, cancel := context.WithCancel(context.Background())
366+
go func() {
367+
time.Sleep(50 * time.Millisecond)
368+
cancel()
369+
}()
370+
371+
def := tcpDef(&TCPConfig{Port: 22, Data: "PING\r\n", Matchers: []Matcher{tcpWord("x")}})
372+
start := time.Now()
373+
res, err := ExecuteTCPModule(ctx, "example.com", def, Options{Timeout: 2 * time.Second})
374+
elapsed := time.Since(start)
375+
376+
if elapsed > time.Second {
377+
t.Errorf("returned after %v, want prompt (a cancel landing mid-write must not be swallowed by the read-deadline re-arm)", elapsed)
378+
}
379+
if !errors.Is(err, context.Canceled) {
380+
t.Fatalf("err = %v, want context.Canceled", err)
381+
}
382+
if len(res.Findings) != 0 {
383+
t.Errorf("got %d findings on cancel, want 0", len(res.Findings))
384+
}
385+
}
386+
387+
// TestExecuteTCPModuleContextCancelBeforeWrite proves an already-cancelled ctx
388+
// is caught before the probe write arms its deadline, rather than falling
389+
// through to SetWriteDeadline and Write regardless. Without the guard this
390+
// would only fail if the write itself then blocked past the deadline; here it
391+
// is asserted directly so the guard cannot regress silently.
392+
func TestExecuteTCPModuleContextCancelBeforeWrite(t *testing.T) {
393+
client, server := net.Pipe()
394+
t.Cleanup(func() { server.Close() })
395+
orig := newTCPConn
396+
newTCPConn = func(context.Context, string, time.Duration) (net.Conn, error) { return client, nil }
397+
t.Cleanup(func() { newTCPConn = orig })
398+
399+
ctx, cancel := context.WithCancel(context.Background())
400+
cancel()
401+
402+
def := tcpDef(&TCPConfig{Port: 22, Data: "PING\r\n", Matchers: []Matcher{tcpWord("x")}})
403+
res, err := ExecuteTCPModule(ctx, "example.com", def, Options{Timeout: 2 * time.Second})
404+
if !errors.Is(err, context.Canceled) {
405+
t.Fatalf("err = %v, want context.Canceled", err)
406+
}
407+
if len(res.Findings) != 0 {
408+
t.Errorf("got %d findings on cancel, want 0", len(res.Findings))
409+
}
410+
}
411+
412+
// TestExecuteTCPModuleContextCancelBlocksInWrite reproduces the write-side
413+
// twin of the read-deadline re-arm race: the probe write blocks on a real
414+
// synchronous conn (net.Pipe with no reader), and the cancel watchdog's
415+
// SetDeadline(now) is what has to unblock it. Before the ctx.Err() guard, the
416+
// watchdog trip could land between goroutine start and the SetWriteDeadline
417+
// call and be silently overwritten by it, since the watchdog only fires once
418+
// and never gets a second chance to re-trip; the write would then block for
419+
// the full timeout instead of returning promptly, and a write that the
420+
// watchdog did manage to trip surfaced as a raw i/o timeout rather than the
421+
// cancellation it actually was.
422+
func TestExecuteTCPModuleContextCancelBlocksInWrite(t *testing.T) {
423+
client, server := net.Pipe()
424+
t.Cleanup(func() { server.Close() }) // no reader: the probe write blocks until the deadline trips
425+
426+
orig := newTCPConn
427+
newTCPConn = func(context.Context, string, time.Duration) (net.Conn, error) { return client, nil }
428+
t.Cleanup(func() { newTCPConn = orig })
429+
430+
ctx, cancel := context.WithCancel(context.Background())
431+
go func() {
432+
time.Sleep(20 * time.Millisecond)
433+
cancel()
434+
}()
435+
436+
def := tcpDef(&TCPConfig{Port: 22, Data: "PING\r\n", Matchers: []Matcher{tcpWord("x")}})
437+
start := time.Now()
438+
res, err := ExecuteTCPModule(ctx, "example.com", def, Options{Timeout: 5 * time.Second})
439+
if elapsed := time.Since(start); elapsed > 2*time.Second {
440+
t.Errorf("returned after %v, want the watchdog to trip the blocked write promptly", elapsed)
441+
}
442+
if !errors.Is(err, context.Canceled) {
443+
t.Fatalf("err = %v, want context.Canceled", err)
444+
}
445+
if len(res.Findings) != 0 {
446+
t.Errorf("got %d findings on cancel, want 0", len(res.Findings))
447+
}
448+
}
449+
450+
// TestExecuteTCPModuleSlowConnCompletesWithoutCancel proves the ctx.Err()
451+
// guards added for the read-deadline re-arm fix do not clip a legitimately
452+
// slow but healthy connection: with no cancellation, a banner that trickles
453+
// in well under the timeout still completes and matches normally.
454+
func TestExecuteTCPModuleSlowConnCompletesWithoutCancel(t *testing.T) {
455+
client, server := net.Pipe()
456+
orig := newTCPConn
457+
newTCPConn = func(context.Context, string, time.Duration) (net.Conn, error) { return client, nil }
458+
t.Cleanup(func() { newTCPConn = orig })
459+
460+
go func() {
461+
buf := make([]byte, 4096)
462+
_, _ = server.Read(buf)
463+
time.Sleep(200 * time.Millisecond)
464+
_, _ = server.Write([]byte("+OK ready\r\n"))
465+
server.Close()
466+
}()
467+
468+
def := tcpDef(&TCPConfig{Port: 22, Data: "PING\r\n", Matchers: []Matcher{tcpWord("+OK")}})
469+
start := time.Now()
470+
res, err := ExecuteTCPModule(context.Background(), "example.com", def, Options{Timeout: 2 * time.Second})
471+
elapsed := time.Since(start)
472+
473+
if err != nil {
474+
t.Fatalf("ExecuteTCPModule: %v", err)
475+
}
476+
if elapsed < 200*time.Millisecond {
477+
t.Errorf("returned after %v, want it to wait out the slow banner (~200ms)", elapsed)
478+
}
479+
if len(res.Findings) != 1 {
480+
t.Fatalf("got %d findings, want 1 (a healthy slow connection must not be treated as cancelled)", len(res.Findings))
481+
}
482+
}
483+
306484
func TestExecuteTCPModuleDialError(t *testing.T) {
307485
orig := newTCPConn
308486
newTCPConn = func(context.Context, string, time.Duration) (net.Conn, error) {
@@ -430,7 +608,7 @@ func TestReadTCPCapsAtLimit(t *testing.T) {
430608
}()
431609
defer client.Close()
432610

433-
got := readTCP(client, time.Second)
611+
got := readTCP(context.Background(), client, time.Second)
434612
if len(got) < tcpReadLimit {
435613
t.Fatalf("read %d bytes, want at least the %d cap", len(got), tcpReadLimit)
436614
}

0 commit comments

Comments
 (0)