Hotfix no logs in stdout/stderr if uses stdoutConfig [source fix pr](#…

…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 <zchengjoey@gmail.com>

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
 }

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,15 +111,15 @@ 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)
 	}
 }
 
 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)