Capture log to error when executing command (#1947)

* Capture log to error when executing command

* Address review note

* Make logTailDefaultLength as unexported.

* Simplify ExecError

* Add unwrap method

pkg/kube/log_tail.go

@@ -20,6 +20,8 @@ import (
 	"strings"
 )
 
+const logTailDefaultLength = 10
+
 // LogTail interface allows to store last N lines of log written to it
 type LogTail interface {
 	Write(p []byte) (int, error)

pkg/kube/pod.go

@@ -252,7 +252,7 @@ func getErrorFromLogs(ctx context.Context, cli kubernetes.Interface, namespace,
 	defer r.Close()
 
 	// Grab last log lines and put them to an error
-	lt := NewLogTail(10)
+	lt := NewLogTail(logTailDefaultLength)
 	// We are not interested in log extraction error
 	io.Copy(lt, r) // nolint: errcheck
 

pkg/kube/pod_command_executor.go

@@ -21,6 +21,24 @@ import (
 	"k8s.io/client-go/kubernetes"
 )
 
+type ExecError struct {
+	error
+	stdout LogTail
+	stderr LogTail
+}
+
+func (e *ExecError) Unwrap() error {
+	return e.error
+}
+
+func (e *ExecError) Stdout() string {
+	return e.stdout.ToString()
+}
+
+func (e *ExecError) Stderr() string {
+	return e.stderr.ToString()
+}
+
 // PodCommandExecutor allows us to execute command within the pod
 type PodCommandExecutor interface {
 	Exec(ctx context.Context, command []string, stdin io.Reader, stdout, stderr io.Writer) error
@@ -44,19 +62,29 @@ type podCommandExecutor struct {
 // Exec runs the command and logs stdout and stderr.
 func (p *podCommandExecutor) Exec(ctx context.Context, command []string, stdin io.Reader, stdout, stderr io.Writer) error {
 	var (
-		opts = ExecOptions{
+		stderrTail = NewLogTail(logTailDefaultLength)
+		stdoutTail = NewLogTail(logTailDefaultLength)
+		opts       = ExecOptions{
 			Command:       command,
 			Namespace:     p.namespace,
 			PodName:       p.podName,
 			ContainerName: p.containerName,
 			Stdin:         stdin,
-			Stdout:        stdout,
-			Stderr:        stderr,
+			Stdout:        stdoutTail,
+			Stderr:        stderrTail,
 		}
+
 		cmdDone = make(chan struct{})
 		err     error
 	)
 
+	if stdout != nil {
+		opts.Stdout = io.MultiWriter(stdout, stdoutTail)
+	}
+	if stderr != nil {
+		opts.Stderr = io.MultiWriter(stderr, stderrTail)
+	}
+
 	go func() {
 		_, _, err = p.pcep.execWithOptions(p.cli, opts)
 		close(cmdDone)
@@ -66,6 +94,13 @@ func (p *podCommandExecutor) Exec(ctx context.Context, command []string, stdin i
 	case <-ctx.Done():
 		err = ctx.Err()
 	case <-cmdDone:
+		if err != nil {
+			err = &ExecError{
+				error:  err,
+				stdout: stdoutTail,
+				stderr: stderrTail,
+			}
+		}
 	}
 
 	return err

pkg/kube/pod_command_executor_test.go

@@ -17,7 +17,9 @@ package kube
 import (
 	"bytes"
 	"context"
+	"fmt"
 	"os"
+	"strings"
 	"sync"
 	"time"
 
@@ -100,7 +102,6 @@ func (s *PodCommandExecutorTestSuite) TestPodRunnerExec(c *C) {
 	ctx := context.Background()
 	cli := fake.NewSimpleClientset()
 
-	//simulatedError := errors.New("SimulatedError")
 	command := []string{"command", "arg1"}
 
 	cases := map[string]func(ctx context.Context, pr PodCommandExecutor, prp *fakePodCommandExecutorProcessor){
@@ -174,20 +175,61 @@ func (s *PodCommandExecutorTestSuite) TestPodRunnerExec(c *C) {
 
 			c.Assert(err, IsNil)
 			c.Assert(prp.inExecWithOptionsCli, Equals, cli)
-			c.Assert(prp.inExecWithOptionsOpts, DeepEquals, &ExecOptions{
-				Command:       command,
-				Namespace:     podCommandExecutorNS,
-				PodName:       podCommandExecutorPodName,
-				ContainerName: podCommandExecutorContainerName,
-				Stdin:         &bStdin,
-				Stdout:        &bStdout,
-				Stderr:        &bStderr,
-			})
+			c.Assert(prp.inExecWithOptionsOpts.Command, DeepEquals, command)
+			c.Assert(prp.inExecWithOptionsOpts.Namespace, Equals, podCommandExecutorNS)
+			c.Assert(prp.inExecWithOptionsOpts.PodName, Equals, podCommandExecutorPodName)
+			c.Assert(prp.inExecWithOptionsOpts.ContainerName, Equals, podCommandExecutorContainerName)
+			c.Assert(prp.inExecWithOptionsOpts.Stdin, Equals, &bStdin)
+			c.Assert(prp.inExecWithOptionsOpts.Stdout, Not(IsNil))
+			c.Assert(prp.inExecWithOptionsOpts.Stderr, Not(IsNil))
 			c.Assert(bStdout.Len() > 0, Equals, true)
 			c.Assert(bStderr.Len() > 0, Equals, true)
 			c.Assert(bStdout.String(), Equals, expStdout)
 			c.Assert(bStderr.String(), Equals, expStderr)
 		},
+		"In case of failure, we have tail of logs": func(ctx context.Context, pr PodCommandExecutor, prp *fakePodCommandExecutorProcessor) {
+			var errorLines []string
+			var outputLines []string
+			for i := 1; i <= 12; i++ {
+				errorLines = append(errorLines, fmt.Sprintf("error line %d", i))
+				outputLines = append(outputLines, fmt.Sprintf("output line %d", i))
+			}
+
+			var err error
+			prp.execWithOptionsStdout = strings.Join(outputLines, "\n")
+			prp.execWithOptionsStderr = strings.Join(errorLines, "\n")
+			prp.execWithOptionsErr = errors.New("SimulatedError")
+
+			expStdout := prp.execWithOptionsStdout
+			expStderr := prp.execWithOptionsStderr
+			expErrorStderr := strings.Join(errorLines[2:], "\r\n")
+			expErrorStdout := strings.Join(outputLines[2:], "\r\n")
+
+			var bStdin, bStdout, bStderr bytes.Buffer
+			var wg sync.WaitGroup
+			wg.Add(1)
+			go func() {
+				err = pr.Exec(ctx, command, &bStdin, &bStdout, &bStderr)
+				wg.Done()
+			}()
+			prp.execWithOptionsSyncStart.Sync() // Ensure ExecWithOptions is called
+			wg.Wait()
+			prp.execWithOptionsSyncEnd.Sync() // Release execWithOptions
+
+			c.Assert(err, Not(IsNil))
+			c.Assert(prp.inExecWithOptionsOpts.Stdout, Not(IsNil))
+			c.Assert(prp.inExecWithOptionsOpts.Stderr, Not(IsNil))
+			c.Assert(bStdout.Len() > 0, Equals, true)
+			c.Assert(bStderr.Len() > 0, Equals, true)
+			c.Assert(bStdout.String(), Equals, expStdout)
+			c.Assert(bStderr.String(), Equals, expStderr)
+
+			var ee *ExecError
+			c.Assert(errors.As(err, &ee), Equals, true)
+			c.Assert(ee.Error(), Equals, "SimulatedError")
+			c.Assert(ee.Stderr(), Equals, expErrorStderr)
+			c.Assert(ee.Stdout(), Equals, expErrorStdout)
+		},
 	}
 
 	for l, tc := range cases {