From eac7ee49759ca87a2668528651af84f6478953e5 Mon Sep 17 00:00:00 2001 From: Ehab Younes Date: Fri, 5 Jun 2026 14:33:15 +0300 Subject: [PATCH] fix(cli): discard log writes to closed pipes during shutdown (#26082) Add clilog.DiscardOnPipeError, an io.Writer wrapper that drops writes failing with io.ErrClosedPipe or syscall.EPIPE, and apply it to the clilog stdout/stderr sinks and the port-forward verbose sink. Background goroutines (e.g. port-forward -v tailnet goroutines) keep logging after the reader on the log destination is gone. slog reports those failed writes to stderr, which is noise and can interleave with and corrupt go test/test2json output, misreporting passing tests as failed. os.ErrClosed and all other errors are still returned, so writes to a writer we closed ourselves are not hidden, and normal CLI pipe semantics are unchanged. --- cli/clilog/clilog.go | 29 +++++++++++++++-- cli/clilog/clilog_test.go | 67 +++++++++++++++++++++++++++++++++++++++ cli/portforward.go | 3 +- 3 files changed, 96 insertions(+), 3 deletions(-) diff --git a/cli/clilog/clilog.go b/cli/clilog/clilog.go index 81c87bb033..1dfe25da5b 100644 --- a/cli/clilog/clilog.go +++ b/cli/clilog/clilog.go @@ -2,11 +2,14 @@ package clilog import ( "context" + "errors" "fmt" "io" + "os" "regexp" "strings" "sync" + "syscall" "golang.org/x/xerrors" "gopkg.in/natefinch/lumberjack.v2" @@ -106,10 +109,10 @@ func (b *Builder) Build(inv *serpent.Invocation) (log slog.Logger, closeLog func switch loc { case "", "/dev/null": case "/dev/stdout": - sinks = append(sinks, sinkFn(inv.Stdout)) + sinks = append(sinks, sinkFn(MaybeDiscardOnPipeError(inv.Stdout))) case "/dev/stderr": - sinks = append(sinks, sinkFn(inv.Stderr)) + sinks = append(sinks, sinkFn(MaybeDiscardOnPipeError(inv.Stderr))) default: logWriter := &LumberjackWriteCloseFixer{Writer: &lumberjack.Logger{ @@ -238,3 +241,25 @@ func (c *LumberjackWriteCloseFixer) Write(p []byte) (int, error) { } return c.Writer.Write(p) } + +// MaybeDiscardOnPipeError wraps w so writes to alternate CLI sinks that fail +// because the reader is gone are dropped. It leaves os.Stdout and os.Stderr +// unchanged so production pipe errors keep their existing behavior. +func MaybeDiscardOnPipeError(w io.Writer) io.Writer { + if w == os.Stdout || w == os.Stderr { + return w + } + return &discardOnPipeError{w: w} +} + +type discardOnPipeError struct { + w io.Writer +} + +func (d *discardOnPipeError) Write(p []byte) (int, error) { + n, err := d.w.Write(p) + if err != nil && (errors.Is(err, io.ErrClosedPipe) || errors.Is(err, syscall.EPIPE)) { + return len(p), nil + } + return n, err +} diff --git a/cli/clilog/clilog_test.go b/cli/clilog/clilog_test.go index 18a3c8a10e..d2485a3169 100644 --- a/cli/clilog/clilog_test.go +++ b/cli/clilog/clilog_test.go @@ -1,14 +1,18 @@ package clilog_test import ( + "bytes" "encoding/json" + "io" "os" "path/filepath" "strings" + "syscall" "testing" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" + "golang.org/x/xerrors" "github.com/coder/coder/v2/cli/clilog" "github.com/coder/coder/v2/coderd/coderdtest" @@ -146,6 +150,57 @@ func TestBuilder(t *testing.T) { }) } +func TestMaybeDiscardOnPipeError(t *testing.T) { + t.Parallel() + + const payload = "log entry" + + t.Run("LeavesStdoutStderrUnchanged", func(t *testing.T) { + t.Parallel() + + require.Same(t, os.Stdout, clilog.MaybeDiscardOnPipeError(os.Stdout)) + require.Same(t, os.Stderr, clilog.MaybeDiscardOnPipeError(os.Stderr)) + }) + + t.Run("DiscardsClosedPipe", func(t *testing.T) { + t.Parallel() + + for _, target := range []error{ + io.ErrClosedPipe, + syscall.EPIPE, + xerrors.Errorf("wrapped: %w", io.ErrClosedPipe), + xerrors.Errorf("wrapped: %w", syscall.EPIPE), + } { + fw := &fakeWriter{err: target} + n, err := clilog.MaybeDiscardOnPipeError(fw).Write([]byte(payload)) + require.NoError(t, err, "%v should be discarded", target) + assert.Equal(t, len(payload), n) + } + }) + + t.Run("ReportsOtherErrors", func(t *testing.T) { + t.Parallel() + + // os.ErrClosed stays reported: a write to a writer we closed ourselves + // is worth surfacing. + for _, target := range []error{os.ErrClosed, io.ErrShortWrite, xerrors.New("boom")} { + fw := &fakeWriter{err: target} + _, err := clilog.MaybeDiscardOnPipeError(fw).Write([]byte(payload)) + require.ErrorIs(t, err, target) + } + }) + + t.Run("PassesThroughSuccess", func(t *testing.T) { + t.Parallel() + + fw := &fakeWriter{} + n, err := clilog.MaybeDiscardOnPipeError(fw).Write([]byte(payload)) + require.NoError(t, err) + assert.Equal(t, len(payload), n) + assert.Equal(t, payload, fw.buf.String()) + }) +} + var ( debug = "DEBUG" info = "INFO" @@ -216,3 +271,15 @@ func assertLogsJSON(t testing.TB, path string, levelExpected ...string) { require.Equal(t, levelExpected[2*i+1], entry.Message) } } + +type fakeWriter struct { + buf bytes.Buffer + err error +} + +func (f *fakeWriter) Write(p []byte) (int, error) { + if f.err != nil { + return 0, f.err + } + return f.buf.Write(p) +} diff --git a/cli/portforward.go b/cli/portforward.go index 741279c54f..cd7160e31f 100644 --- a/cli/portforward.go +++ b/cli/portforward.go @@ -18,6 +18,7 @@ import ( "cdr.dev/slog/v3" "cdr.dev/slog/v3/sloggers/sloghuman" "github.com/coder/coder/v2/agent/agentssh" + "github.com/coder/coder/v2/cli/clilog" "github.com/coder/coder/v2/cli/cliui" "github.com/coder/coder/v2/codersdk" "github.com/coder/coder/v2/codersdk/workspacesdk" @@ -111,7 +112,7 @@ func (r *RootCmd) portForward() *serpent.Command { logger := inv.Logger if r.verbose { - opts.Logger = logger.AppendSinks(sloghuman.Sink(inv.Stdout)).Leveled(slog.LevelDebug) + opts.Logger = logger.AppendSinks(sloghuman.Sink(clilog.MaybeDiscardOnPipeError(inv.Stdout))).Leveled(slog.LevelDebug) } if r.disableDirect {