From 1c787f436fca20cbec4541f978ed2a634b880c97 Mon Sep 17 00:00:00 2001 From: Keith Zantow Date: Thu, 16 Nov 2023 17:45:25 -0500 Subject: [PATCH] fix: prevent writing non-report output to stdout (#2324) Signed-off-by: Keith Zantow --- cmd/syft/cli/cli.go | 13 +-- .../ui/__snapshots__/event_writer_test.snap | 41 +++++++++ .../post_ui_event_writer_test.snap | 41 --------- cmd/syft/internal/ui/capture.go | 61 +++++++++++++ cmd/syft/internal/ui/capture_test.go | 85 +++++++++++++++++++ ...ost_ui_event_writer.go => event_writer.go} | 62 ++++++-------- ...nt_writer_test.go => event_writer_test.go} | 7 +- cmd/syft/internal/ui/log_writer.go | 37 ++++++++ cmd/syft/internal/ui/log_writer_test.go | 69 +++++++++++++++ cmd/syft/internal/ui/no_ui.go | 9 +- .../internal/ui/stdout_logging_application.go | 63 ++++++++++++++ cmd/syft/internal/ui/ui.go | 10 ++- go.mod | 3 +- 13 files changed, 407 insertions(+), 94 deletions(-) create mode 100755 cmd/syft/internal/ui/__snapshots__/event_writer_test.snap delete mode 100755 cmd/syft/internal/ui/__snapshots__/post_ui_event_writer_test.snap create mode 100644 cmd/syft/internal/ui/capture.go create mode 100644 cmd/syft/internal/ui/capture_test.go rename cmd/syft/internal/ui/{post_ui_event_writer.go => event_writer.go} (74%) rename cmd/syft/internal/ui/{post_ui_event_writer_test.go => event_writer_test.go} (92%) create mode 100644 cmd/syft/internal/ui/log_writer.go create mode 100644 cmd/syft/internal/ui/log_writer_test.go create mode 100644 cmd/syft/internal/ui/stdout_logging_application.go diff --git a/cmd/syft/cli/cli.go b/cmd/syft/cli/cli.go index 4f4608a66..23984adc3 100644 --- a/cmd/syft/cli/cli.go +++ b/cmd/syft/cli/cli.go @@ -1,6 +1,7 @@ package cli import ( + "io" "os" cranecmd "github.com/google/go-containerregistry/cmd/crane/cmd" @@ -22,18 +23,18 @@ import ( // It also constructs the syft attest command and the syft version command. // `RunE` is the earliest that the complete application configuration can be loaded. func Application(id clio.Identification) clio.Application { - app, _ := create(id) - return app + app, rootCmd := create(id, os.Stdout) + return ui.StdoutLoggingApplication(app, rootCmd) } // Command returns the root command for the syft CLI application. This is useful for embedding the entire syft CLI // into an existing application. func Command(id clio.Identification) *cobra.Command { - _, cmd := create(id) + _, cmd := create(id, os.Stdout) return cmd } -func create(id clio.Identification) (clio.Application, *cobra.Command) { +func create(id clio.Identification, out io.Writer) (clio.Application, *cobra.Command) { clioCfg := clio.NewSetupConfig(id). WithGlobalConfigFlag(). // add persistent -c for reading an application config from WithGlobalLoggingFlags(). // add persistent -v and -q flags tied to the logging config @@ -41,13 +42,13 @@ func create(id clio.Identification) (clio.Application, *cobra.Command) { WithUIConstructor( // select a UI based on the logging configuration and state of stdin (if stdin is a tty) func(cfg clio.Config) ([]clio.UI, error) { - noUI := ui.None(cfg.Log.Quiet) + noUI := ui.None(out, cfg.Log.Quiet) if !cfg.Log.AllowUI(os.Stdin) || cfg.Log.Quiet { return []clio.UI{noUI}, nil } return []clio.UI{ - ui.New(cfg.Log.Quiet, + ui.New(out, cfg.Log.Quiet, handler.New(handler.DefaultHandlerConfig()), ), noUI, diff --git a/cmd/syft/internal/ui/__snapshots__/event_writer_test.snap b/cmd/syft/internal/ui/__snapshots__/event_writer_test.snap new file mode 100755 index 000000000..cac01904c --- /dev/null +++ b/cmd/syft/internal/ui/__snapshots__/event_writer_test.snap @@ -0,0 +1,41 @@ + +[Test_writeEvents/no_events/stdout - 1] + +--- + +[Test_writeEvents/no_events/stderr - 1] + +--- + +[Test_writeEvents/all_events/stdout - 1] + + + + + +--- + +[Test_writeEvents/all_events/stderr - 1] + + + + + + + +A newer version of syft is available for download: v0.33.0 (installed version is [not provided]) + +--- + +[Test_writeEvents/quiet_only_shows_report/stdout - 1] + + +--- + +[Test_writeEvents/quiet_only_shows_report/stderr - 1] + +--- diff --git a/cmd/syft/internal/ui/__snapshots__/post_ui_event_writer_test.snap b/cmd/syft/internal/ui/__snapshots__/post_ui_event_writer_test.snap deleted file mode 100755 index 64cafcab3..000000000 --- a/cmd/syft/internal/ui/__snapshots__/post_ui_event_writer_test.snap +++ /dev/null @@ -1,41 +0,0 @@ - -[Test_postUIEventWriter_write/no_events/stdout - 1] - ---- - -[Test_postUIEventWriter_write/no_events/stderr - 1] - ---- - -[Test_postUIEventWriter_write/all_events/stdout - 1] - - - - - ---- - -[Test_postUIEventWriter_write/all_events/stderr - 1] - - - - - - - -A newer version of syft is available for download: v0.33.0 (installed version is [not provided]) - ---- - -[Test_postUIEventWriter_write/quiet_only_shows_report/stdout - 1] - - ---- - -[Test_postUIEventWriter_write/quiet_only_shows_report/stderr - 1] - ---- diff --git a/cmd/syft/internal/ui/capture.go b/cmd/syft/internal/ui/capture.go new file mode 100644 index 000000000..8148fddfd --- /dev/null +++ b/cmd/syft/internal/ui/capture.go @@ -0,0 +1,61 @@ +package ui + +import ( + "io" + "os" + "time" + + "github.com/anchore/syft/internal/log" +) + +// capture replaces the provided *os.File and redirects output to the provided writer. The return value is a function, +// which is used to stop the current capturing of output and restore the original file. +// Example: +// +// restore := capture(&os.Stderr, writer) +// // here, stderr will be captured and redirected to the provided writer +// restore() // block until the output has all been sent to the writer and restore the original stderr +func capture(target **os.File, writer io.Writer, bufSize int) (close func()) { + original := *target + + r, w, _ := os.Pipe() + + *target = w + + done := make(chan struct{}, 1) + + go func() { + defer func() { + done <- struct{}{} + }() + + buf := make([]byte, bufSize) + for { + if original == nil { + break + } + + n, err := r.Read(buf) + if n > 0 { + _, _ = writer.Write(buf[0:n]) + } + + if err != nil { + break + } + } + }() + + return func() { + if original != nil { + _ = w.Close() + select { + case <-done: + case <-time.After(1 * time.Second): + log.Debugf("stdout buffer timed out after 1 second") + } + *target = original + original = nil + } + } +} diff --git a/cmd/syft/internal/ui/capture_test.go b/cmd/syft/internal/ui/capture_test.go new file mode 100644 index 000000000..da3175549 --- /dev/null +++ b/cmd/syft/internal/ui/capture_test.go @@ -0,0 +1,85 @@ +package ui + +import ( + "bytes" + "io" + "os" + "testing" + + "github.com/stretchr/testify/require" +) + +func Test_capture(t *testing.T) { + r, w, _ := os.Pipe() + t.Logf("pipe1: %+v", w) + + buf := &bytes.Buffer{} + buf2 := &bytes.Buffer{} + + go func() { + // write to the main file (e.g. os.Stdout) + _, _ = w.WriteString("write1") + + // capture the output to the provided buffer + restoreInitial := capture(&w, buf, 1024) + t.Logf("pipe2: %+v", w) + _, _ = w.WriteString("write2") + + // capture output nested + restoreFirstCapture := capture(&w, buf2, 1024) + t.Logf("pipe3: %+v", w) + _, _ = w.WriteString("write3") + + // discard file used to write the "write3" + restoreFirstCapture() + + // restore should block until all output has been captured, so it's safe to read buf2 here + require.Equal(t, "write3", buf2.String()) + + // restore should be safe to call multiple times + restoreFirstCapture() + require.Equal(t, "write3", buf2.String()) + + // write again to the initial buffer + t.Logf("pipe2+: %+v", w) + _, _ = w.WriteString("write2+") + + // restore the initial file (e.g. os.Stdout) and write more to it + restoreInitial() + t.Logf("pipe1+: %+v", w) + _, _ = w.WriteString("write1+") + + // close the pipe to continue with the io.ReadAll, below + _ = w.Close() + }() + + got, err := io.ReadAll(r) + require.NoError(t, err) + require.Equal(t, "write1write1+", string(got)) + + require.Equal(t, "write2write2+", buf.String()) +} + +func Test_captureBufSizes(t *testing.T) { + _, w, _ := os.Pipe() + + buf := &bytes.Buffer{} + restore := capture(&w, buf, 200) + + line := "line1\nline2\nline3" + + _, err := w.WriteString(line) + require.NoError(t, err) + + restore() + require.Equal(t, line, buf.String()) + + buf.Reset() + restore = capture(&w, buf, 2) + + _, err = w.WriteString(line) + require.NoError(t, err) + + restore() + require.Equal(t, line, buf.String()) +} diff --git a/cmd/syft/internal/ui/post_ui_event_writer.go b/cmd/syft/internal/ui/event_writer.go similarity index 74% rename from cmd/syft/internal/ui/post_ui_event_writer.go rename to cmd/syft/internal/ui/event_writer.go index dcef5cb6c..cf6f2b274 100644 --- a/cmd/syft/internal/ui/post_ui_event_writer.go +++ b/cmd/syft/internal/ui/event_writer.go @@ -14,47 +14,35 @@ import ( "github.com/anchore/syft/syft/event/parsers" ) -type postUIEventWriter struct { - handles []postUIHandle -} - -type postUIHandle struct { - respectQuiet bool - event partybus.EventType - writer io.Writer - dispatch eventWriter -} - -type eventWriter func(io.Writer, ...partybus.Event) error - -func newPostUIEventWriter(stdout, stderr io.Writer) *postUIEventWriter { - return &postUIEventWriter{ - handles: []postUIHandle{ - { - event: event.CLIReport, - respectQuiet: false, - writer: stdout, - dispatch: writeReports, - }, - { - event: event.CLINotification, - respectQuiet: true, - writer: stderr, - dispatch: writeNotifications, - }, - { - event: event.CLIAppUpdateAvailable, - respectQuiet: true, - writer: stderr, - dispatch: writeAppUpdate, - }, +func writeEvents(out, err io.Writer, quiet bool, events ...partybus.Event) error { + handles := []struct { + event partybus.EventType + respectQuiet bool + writer io.Writer + dispatch func(writer io.Writer, events ...partybus.Event) error + }{ + { + event: event.CLIReport, + respectQuiet: false, + writer: out, + dispatch: writeReports, + }, + { + event: event.CLINotification, + respectQuiet: true, + writer: err, + dispatch: writeNotifications, + }, + { + event: event.CLIAppUpdateAvailable, + respectQuiet: true, + writer: err, + dispatch: writeAppUpdate, }, } -} -func (w postUIEventWriter) write(quiet bool, events ...partybus.Event) error { var errs error - for _, h := range w.handles { + for _, h := range handles { if quiet && h.respectQuiet { continue } diff --git a/cmd/syft/internal/ui/post_ui_event_writer_test.go b/cmd/syft/internal/ui/event_writer_test.go similarity index 92% rename from cmd/syft/internal/ui/post_ui_event_writer_test.go rename to cmd/syft/internal/ui/event_writer_test.go index 45372e570..159b35029 100644 --- a/cmd/syft/internal/ui/post_ui_event_writer_test.go +++ b/cmd/syft/internal/ui/event_writer_test.go @@ -12,8 +12,7 @@ import ( "github.com/anchore/syft/syft/event/parsers" ) -func Test_postUIEventWriter_write(t *testing.T) { - +func Test_writeEvents(t *testing.T) { tests := []struct { name string quiet bool @@ -86,9 +85,9 @@ func Test_postUIEventWriter_write(t *testing.T) { stdout := &bytes.Buffer{} stderr := &bytes.Buffer{} - w := newPostUIEventWriter(stdout, stderr) - tt.wantErr(t, w.write(tt.quiet, tt.events...)) + err := writeEvents(stdout, stderr, tt.quiet, tt.events...) + tt.wantErr(t, err) t.Run("stdout", func(t *testing.T) { snaps.MatchSnapshot(t, stdout.String()) diff --git a/cmd/syft/internal/ui/log_writer.go b/cmd/syft/internal/ui/log_writer.go new file mode 100644 index 000000000..ebe8381d3 --- /dev/null +++ b/cmd/syft/internal/ui/log_writer.go @@ -0,0 +1,37 @@ +package ui + +import ( + "bufio" + "bytes" + "io" + "strings" + + "github.com/anchore/syft/internal/log" +) + +func newLogWriter() io.Writer { + l := logWriter{} + l.r = bufio.NewReader(&l.buf) + return &l +} + +type logWriter struct { + buf bytes.Buffer + r *bufio.Reader +} + +func (l *logWriter) Write(data []byte) (n int, err error) { + l.buf.Write(data) + s, err := l.r.ReadString('\n') + s = strings.TrimRight(s, "\n") + for s != "" { + log.Trace(s) + n += len(s) + if err != nil { + break + } + s, err = l.r.ReadString('\n') + s = strings.TrimRight(s, "\n") + } + return n, err +} diff --git a/cmd/syft/internal/ui/log_writer_test.go b/cmd/syft/internal/ui/log_writer_test.go new file mode 100644 index 000000000..ad8a0d230 --- /dev/null +++ b/cmd/syft/internal/ui/log_writer_test.go @@ -0,0 +1,69 @@ +package ui + +import ( + "io" + "testing" + + "github.com/stretchr/testify/require" + + "github.com/anchore/go-logger" + "github.com/anchore/syft/internal/log" +) + +func Test_logWriter(t *testing.T) { + w := newLogWriter() + + orig := log.Get() + t.Cleanup(func() { + log.Set(orig) + }) + + bl := &bufferLogger{} + log.Set(bl) + + _, _ = w.Write([]byte("a\nvalue")) + + expected := []any{"a", "value"} + require.Equal(t, expected, bl.values) + + bl.values = nil + _, _ = w.Write([]byte("some")) + _, _ = w.Write([]byte("thing")) + + expected = []any{"some", "thing"} + require.Equal(t, expected, bl.values) +} + +type bufferLogger struct{ values []any } + +func (l *bufferLogger) Tracef(_ string, _ ...interface{}) {} + +func (l *bufferLogger) Debugf(_ string, _ ...interface{}) {} + +func (l *bufferLogger) Infof(_ string, _ ...interface{}) {} + +func (l *bufferLogger) Warnf(_ string, _ ...interface{}) {} + +func (l *bufferLogger) Errorf(_ string, _ ...interface{}) {} + +func (l *bufferLogger) Trace(vals ...interface{}) { + l.values = append(l.values, vals...) +} + +func (l *bufferLogger) Debug(_ ...interface{}) {} + +func (l *bufferLogger) Info(_ ...interface{}) {} + +func (l *bufferLogger) Warn(vals ...interface{}) { + l.values = append(l.values, vals...) +} + +func (l *bufferLogger) Error(_ ...interface{}) {} + +func (l *bufferLogger) WithFields(_ ...interface{}) logger.MessageLogger { return l } + +func (l *bufferLogger) Nested(_ ...interface{}) logger.Logger { return l } + +func (l *bufferLogger) SetOutput(_ io.Writer) {} + +func (l *bufferLogger) GetOutput() io.Writer { return nil } diff --git a/cmd/syft/internal/ui/no_ui.go b/cmd/syft/internal/ui/no_ui.go index e8ad13245..a7a35a8cf 100644 --- a/cmd/syft/internal/ui/no_ui.go +++ b/cmd/syft/internal/ui/no_ui.go @@ -1,6 +1,7 @@ package ui import ( + "io" "os" "github.com/wagoodman/go-partybus" @@ -12,13 +13,17 @@ import ( var _ clio.UI = (*NoUI)(nil) type NoUI struct { + out io.Writer + err io.Writer finalizeEvents []partybus.Event subscription partybus.Unsubscribable quiet bool } -func None(quiet bool) *NoUI { +func None(out io.Writer, quiet bool) *NoUI { return &NoUI{ + out: out, + err: os.Stderr, quiet: quiet, } } @@ -38,5 +43,5 @@ func (n *NoUI) Handle(e partybus.Event) error { } func (n NoUI) Teardown(_ bool) error { - return newPostUIEventWriter(os.Stdout, os.Stderr).write(n.quiet, n.finalizeEvents...) + return writeEvents(n.out, n.err, n.quiet, n.finalizeEvents...) } diff --git a/cmd/syft/internal/ui/stdout_logging_application.go b/cmd/syft/internal/ui/stdout_logging_application.go new file mode 100644 index 000000000..b807a4d4c --- /dev/null +++ b/cmd/syft/internal/ui/stdout_logging_application.go @@ -0,0 +1,63 @@ +package ui + +import ( + "os" + + "github.com/spf13/cobra" + "github.com/spf13/pflag" + + "github.com/anchore/clio" +) + +const defaultStdoutLogBufferSize = 1024 + +// StdoutLoggingApplication wraps the provided app in a clio.Application, which captures non-report data +// written to os.Stdout and instead logs it to the internal logger. It also modifies the rootCmd help function +// to restore os.Stdout in order for Cobra to properly print help to stdout +func StdoutLoggingApplication(app clio.Application, rootCmd *cobra.Command) clio.Application { + return &stdoutLoggingApplication{ + delegate: app, + rootCmd: rootCmd, + } +} + +// stdoutLoggingApplication is a clio.Application, which captures data written to os.Stdout prior to the report +// being output and instead sends non-report output to the internal logger +type stdoutLoggingApplication struct { + delegate clio.Application + rootCmd *cobra.Command +} + +func (s *stdoutLoggingApplication) ID() clio.Identification { + return s.delegate.ID() +} + +func (s *stdoutLoggingApplication) AddFlags(flags *pflag.FlagSet, cfgs ...any) { + s.delegate.AddFlags(flags, cfgs...) +} + +func (s *stdoutLoggingApplication) SetupCommand(cmd *cobra.Command, cfgs ...any) *cobra.Command { + return s.delegate.SetupCommand(cmd, cfgs...) +} + +func (s *stdoutLoggingApplication) SetupRootCommand(cmd *cobra.Command, cfgs ...any) *cobra.Command { + return s.delegate.SetupRootCommand(cmd, cfgs...) +} + +func (s *stdoutLoggingApplication) Run() { + // capture everything written to stdout that is not report output + restoreStdout := capture(&os.Stdout, newLogWriter(), defaultStdoutLogBufferSize) + defer restoreStdout() + + // need to restore stdout for cobra to properly output help text to the user on stdout + baseHelpFunc := s.rootCmd.HelpFunc() + defer s.rootCmd.SetHelpFunc(baseHelpFunc) + s.rootCmd.SetHelpFunc(func(command *cobra.Command, strings []string) { + restoreStdout() + baseHelpFunc(command, strings) + }) + + s.delegate.Run() +} + +var _ clio.Application = (*stdoutLoggingApplication)(nil) diff --git a/cmd/syft/internal/ui/ui.go b/cmd/syft/internal/ui/ui.go index cd31cc4e1..6161294a5 100644 --- a/cmd/syft/internal/ui/ui.go +++ b/cmd/syft/internal/ui/ui.go @@ -2,6 +2,7 @@ package ui import ( "fmt" + "io" "os" "sync" "time" @@ -25,6 +26,8 @@ var _ interface { } = (*UI)(nil) type UI struct { + out io.Writer + err io.Writer program *tea.Program running *sync.WaitGroup quiet bool @@ -35,8 +38,10 @@ type UI struct { frame tea.Model } -func New(quiet bool, handlers ...bubbly.EventHandler) *UI { +func New(out io.Writer, quiet bool, handlers ...bubbly.EventHandler) *UI { return &UI{ + out: out, + err: os.Stderr, handler: bubbly.NewHandlerCollection(handlers...), frame: frame.New(), running: &sync.WaitGroup{}, @@ -99,8 +104,7 @@ func (m *UI) Teardown(force bool) error { // TODO: allow for writing out the full log output to the screen (only a partial log is shown currently) // this needs coordination to know what the last frame event is to change the state accordingly (which isn't possible now) - - return newPostUIEventWriter(os.Stdout, os.Stderr).write(m.quiet, m.finalizeEvents...) + return writeEvents(m.out, m.err, m.quiet, m.finalizeEvents...) } // bubbletea.Model functions diff --git a/go.mod b/go.mod index 57b8deeb6..92cc3f91d 100644 --- a/go.mod +++ b/go.mod @@ -76,6 +76,8 @@ require ( modernc.org/sqlite v1.27.0 ) +require github.com/spf13/pflag v1.0.5 + require ( dario.cat/mergo v1.0.0 // indirect github.com/AdaLogics/go-fuzz-headers v0.0.0-20230811130428-ced1acdcaa24 // indirect @@ -183,7 +185,6 @@ require ( github.com/skeema/knownhosts v1.2.0 // indirect github.com/spf13/cast v1.5.1 // indirect github.com/spf13/jwalterweatherman v1.1.0 // indirect - github.com/spf13/pflag v1.0.5 // indirect github.com/spf13/viper v1.16.0 // indirect github.com/subosito/gotenv v1.4.2 // indirect github.com/sylabs/sif/v2 v2.11.5 // indirect