From 83200da19e8489e2b5bbb78bed37ab6a61876d6a Mon Sep 17 00:00:00 2001 From: joey Date: Tue, 14 Feb 2023 23:10:55 +0800 Subject: [PATCH] Hotfix no logs in stdout/stderr if uses stdoutConfig [source fix pr](https://github.com/tektoncd/pipeline/pull/6162) used to only collect stdout and err to a file if the std{out/err}Path is specified, now add both os.std{out/err} and the std{out/err}Path to multiwriter to collect logs io/ioutil has been deprecaed in Go 1.16 Signed-off-by: chengjoey --- cmd/entrypoint/runner.go | 64 ++++++++--------------------------- cmd/entrypoint/runner_test.go | 53 +++++++++++++++++++++++++---- 2 files changed, 60 insertions(+), 57 deletions(-) diff --git a/cmd/entrypoint/runner.go b/cmd/entrypoint/runner.go index 836c8450e1e..d4deee1d11f 100644 --- a/cmd/entrypoint/runner.go +++ b/cmd/entrypoint/runner.go @@ -22,7 +22,6 @@ import ( "context" "fmt" "io" - "log" "os" "os/exec" "os/signal" @@ -84,26 +83,25 @@ func (rr *realRunner) Run(ctx context.Context, args ...string) error { cmd := exec.CommandContext(ctx, name, args...) - // Build a list of tee readers that we'll read from after the command is - // is started. If we are not configured to tee stdout/stderr this will be - // empty and contents will not be copied. - var readers []*namedReader + // if a standard output file is specified + // create the log file and add to the std multi writer if rr.stdoutPath != "" { - stdout, err := newTeeReader(cmd.StdoutPipe, rr.stdoutPath) + stdout, err := newStdLogWriter(rr.stdoutPath) if err != nil { return err } - readers = append(readers, stdout) + defer stdout.Close() + cmd.Stdout = io.MultiWriter(os.Stdout, stdout) } else { - // This needs to be set in an else since StdoutPipe will fail if cmd.Stdout is already set. cmd.Stdout = os.Stdout } if rr.stderrPath != "" { - stderr, err := newTeeReader(cmd.StderrPipe, rr.stderrPath) + stderr, err := newStdLogWriter(rr.stderrPath) if err != nil { return err } - readers = append(readers, stderr) + defer stderr.Close() + cmd.Stderr = io.MultiWriter(os.Stderr, stderr) } else { cmd.Stderr = os.Stderr } @@ -134,22 +132,6 @@ func (rr *realRunner) Run(ctx context.Context, args ...string) error { } }() - wg := new(sync.WaitGroup) - for _, r := range readers { - wg.Add(1) - // Read concurrently so that we can pipe stdout and stderr at the same - // time. - go func(r *namedReader) { - defer wg.Done() - if _, err := io.ReadAll(r); err != nil { - log.Printf("error reading to %s: %v", r.name, err) - } - }(r) - } - - // Wait for stdout/err buffers to finish reading before returning. - wg.Wait() - // Wait for command to exit if err := cmd.Wait(); err != nil { if ctx.Err() == context.DeadlineExceeded { @@ -161,36 +143,18 @@ func (rr *realRunner) Run(ctx context.Context, args ...string) error { return nil } -// newTeeReader creates a new Reader that copies data from the given pipe function -// (i.e. cmd.StdoutPipe, cmd.StderrPipe) into a file specified by path. -// The file is opened with os.O_WRONLY|os.O_CREATE|os.O_APPEND, and will not +// newStdLogWriter create a new file writer that used for collecting std log +// the file is opened with os.O_WRONLY|os.O_CREATE|os.O_APPEND, and will not // override any existing content in the path. This means that the same file can -// be used for multiple streams if desired. -// The behavior of the Reader is the same as io.TeeReader - reads from the pipe -// will be written to the file. -func newTeeReader(pipe func() (io.ReadCloser, error), path string) (*namedReader, error) { - in, err := pipe() - if err != nil { - return nil, fmt.Errorf("error creating pipe: %w", err) - } - +// be used for multiple streams if desired. note that close after use +func newStdLogWriter(path string) (*os.File, error) { if err := os.MkdirAll(filepath.Dir(path), os.ModePerm); err != nil { return nil, fmt.Errorf("error creating parent directory: %w", err) } - f, err := os.OpenFile(path, os.O_WRONLY|os.O_CREATE|os.O_APPEND, 0600) + f, err := os.OpenFile(path, os.O_WRONLY|os.O_CREATE|os.O_APPEND, 0644) if err != nil { return nil, fmt.Errorf("error opening %s: %w", path, err) } - return &namedReader{ - name: path, - Reader: io.TeeReader(in, f), - }, nil -} - -// namedReader is just a helper struct that lets us give a reader a name for -// logging purposes. -type namedReader struct { - io.Reader - name string + return f, nil } diff --git a/cmd/entrypoint/runner_test.go b/cmd/entrypoint/runner_test.go index 646eae72e39..c1e1dc3f9d0 100644 --- a/cmd/entrypoint/runner_test.go +++ b/cmd/entrypoint/runner_test.go @@ -1,10 +1,11 @@ package main import ( + "bytes" "context" "errors" "fmt" - "io/ioutil" + "io" "os" "path/filepath" "strings" @@ -29,7 +30,7 @@ func TestRealRunnerSignalForwarding(t *testing.T) { } func TestRealRunnerStdoutAndStderrPaths(t *testing.T) { - tmp, err := ioutil.TempDir("", "") + tmp, err := os.MkdirTemp("", "") if err != nil { t.Fatalf("Unexpected error: %v", err) } @@ -40,12 +41,50 @@ func TestRealRunnerStdoutAndStderrPaths(t *testing.T) { stdoutPath: filepath.Join(tmp, "stdout"), stderrPath: filepath.Join(tmp, "subpath/stderr"), } + + // capture the std{out/err} output to verify whether we print log in the std + oldStdout := os.Stdout // keep backup of the real stdout + outReader, outWriter, _ := os.Pipe() + os.Stdout = outWriter + + oldStderr := os.Stderr + errReader, errWriter, _ := os.Pipe() + os.Stderr = errWriter + if err := rr.Run(context.Background(), "sh", "-c", fmt.Sprintf("echo %s && echo %s >&2", expectedString, expectedString)); err != nil { t.Fatalf("Unexpected error: %v", err) } + outC := make(chan string) + errC := make(chan string) + // copy the output in a separate goroutine so realRunner command can't block indefinitely + go func() { + var stdOutBuf bytes.Buffer + io.Copy(&stdOutBuf, outReader) + outC <- stdOutBuf.String() + + var stdErrBuf bytes.Buffer + io.Copy(&stdErrBuf, errReader) + errC <- stdErrBuf.String() + }() + // back to normal state + outWriter.Close() + errWriter.Close() + os.Stdout = oldStdout // restoring the real stdout + os.Stderr = oldStderr // restoring the real stderr + stdOut := <-outC + stdErr := <-errC + + // echo command will auto add \n in end, so we should remove trailing newline + if strings.TrimSuffix(stdOut, "\n") != expectedString { + t.Fatalf("Unexpected stdout output: %s, wanted stdout output: %s", stdOut, expectedString) + } + if strings.TrimSuffix(stdErr, "\n") != expectedString { + t.Fatalf("Unexpected stderr output: %s, wanted stderr output: %s", stdErr, expectedString) + } + for _, path := range []string{"stdout", "subpath/stderr"} { - if got, err := ioutil.ReadFile(filepath.Join(tmp, path)); err != nil { + if got, err := os.ReadFile(filepath.Join(tmp, path)); err != nil { t.Fatalf("Unexpected error: %v", err) } else if gotString := strings.TrimSpace(string(got)); gotString != expectedString { t.Errorf("%v: got: %v, wanted: %v", path, gotString, expectedString) @@ -54,7 +93,7 @@ func TestRealRunnerStdoutAndStderrPaths(t *testing.T) { } func TestRealRunnerStdoutAndStderrSamePath(t *testing.T) { - tmp, err := ioutil.TempDir("", "") + tmp, err := os.MkdirTemp("", "") if err != nil { t.Fatalf("Unexpected error: %v", err) } @@ -72,7 +111,7 @@ func TestRealRunnerStdoutAndStderrSamePath(t *testing.T) { // Since writes to stdout and stderr might be racy, we only check for lengths here. expectedSize := (len(expectedString) + 1) * 2 - if got, err := ioutil.ReadFile(path); err != nil { + if got, err := os.ReadFile(path); err != nil { t.Fatalf("Unexpected error: %v", err) } else if gotSize := len(got); gotSize != expectedSize { t.Errorf("got: %v, wanted: %v", gotSize, expectedSize) @@ -80,7 +119,7 @@ func TestRealRunnerStdoutAndStderrSamePath(t *testing.T) { } func TestRealRunnerStdoutPathWithSignal(t *testing.T) { - tmp, err := ioutil.TempDir("", "") + tmp, err := os.MkdirTemp("", "") if err != nil { t.Fatalf("Unexpected error: %v", err) } @@ -113,7 +152,7 @@ func TestRealRunnerStdoutPathWithSignal(t *testing.T) { if err := rr.Run(context.Background(), "sh", "-c", fmt.Sprintf("echo %s && sleep 20", expectedString)); err == nil || err.Error() != expectedError { t.Fatalf("Expected error %v but got %v", expectedError, err) } - if got, err := ioutil.ReadFile(path); err != nil { + if got, err := os.ReadFile(path); err != nil { t.Fatalf("Unexpected error: %v", err) } else if gotString := strings.TrimSpace(string(got)); gotString != expectedString { t.Errorf("got: %v, wanted: %v", gotString, expectedString)