Merge pull request #30731 from ncdc/exec-probe-message

Automatic merge from submit-queue

Always return command output for exec probes and kubelet RunInContainer

Always return command output for exec probes and kubelet RunInContainer, even if the command invocation returns nonzero.

When #24921 replaced RunInContainer with ExecInContainer, it introduced a change where an exec probe that failed no longer included the stdout/stderr from the probe in the event. For example, when running at log level 4, you see:

```
I0816 15:01:36.259826 29713 exec.go:38] Exec probe response: "Failed to access the status endpoint : HTTP Error 404: Not Found.\nHawkular metrics has only been running for 7\n seconds not aborting yet.\n"
```

But the event looks like this:

```
54s 22s 5 hawkular-metrics-hjme4 Pod spec.containers{hawkular-metrics} Warning Unhealthy {kubelet corbeau} Readiness probe failed:
```

Note the absence of the exec probe response after "Readiness probe failed". This PR restores the previous behavior.

cc @kubernetes/rh-cluster-infra @mwringe 

xref https://github.com/openshift/origin/issues/10424

pkg/kubelet/kubelet.go

@@ -2914,11 +2914,10 @@ func (kl *Kubelet) RunInContainer(podFullName string, podUID types.UID, containe
 	var buffer bytes.Buffer
 	output := ioutils.WriteCloserWrapper(&buffer)
 	err = kl.runner.ExecInContainer(container.ID, cmd, nil, output, output, false, nil)
-	if err != nil {
-		return nil, err
-	}
-
-	return buffer.Bytes(), nil
+	// Even if err is non-nil, there still may be output (e.g. the exec wrote to stdout or stderr but
+	// the command returned a nonzero exit code). Therefore, always return the output along with the
+	// error.
+	return buffer.Bytes(), err
 }
 
 // ExecInContainer executes a command in a container, connecting the supplied

pkg/kubelet/kubelet_test.go

@@ -18,6 +18,7 @@ package kubelet
 
 import (
 	"bytes"
+	"errors"
 	"fmt"
 	"io"
 	"io/ioutil"
@@ -976,6 +977,7 @@ func TestMakeVolumeMounts(t *testing.T) {
 }
 
 type fakeContainerCommandRunner struct {
+	// what was passed in
 	Cmd    []string
 	ID     kubecontainer.ContainerID
 	PodID  types.UID
@@ -986,15 +988,25 @@ type fakeContainerCommandRunner struct {
 	TTY    bool
 	Port   uint16
 	Stream io.ReadWriteCloser
+
+	// what to return
+	StdoutData string
+	StderrData string
 }
 
 func (f *fakeContainerCommandRunner) ExecInContainer(id kubecontainer.ContainerID, cmd []string, in io.Reader, out, err io.WriteCloser, tty bool, resize <-chan term.Size) error {
+	// record params
 	f.Cmd = cmd
 	f.ID = id
 	f.Stdin = in
 	f.Stdout = out
 	f.Stderr = err
 	f.TTY = tty
+
+	// Copy stdout/stderr data
+	fmt.Fprint(out, f.StdoutData)
+	fmt.Fprint(out, f.StderrData)
+
 	return f.E
 }
 
@@ -1028,35 +1040,45 @@ func TestRunInContainerNoSuchPod(t *testing.T) {
 }
 
 func TestRunInContainer(t *testing.T) {
-	testKubelet := newTestKubelet(t, false /* controllerAttachDetachEnabled */)
-	kubelet := testKubelet.kubelet
-	fakeRuntime := testKubelet.fakeRuntime
-	fakeCommandRunner := fakeContainerCommandRunner{}
-	kubelet.runner = &fakeCommandRunner
+	for _, testError := range []error{nil, errors.New("foo")} {
+		testKubelet := newTestKubelet(t, false /* controllerAttachDetachEnabled */)
+		kubelet := testKubelet.kubelet
+		fakeRuntime := testKubelet.fakeRuntime
+		fakeCommandRunner := fakeContainerCommandRunner{
+			E:          testError,
+			StdoutData: "foo",
+			StderrData: "bar",
+		}
+		kubelet.runner = &fakeCommandRunner
 
-	containerID := kubecontainer.ContainerID{Type: "test", ID: "abc1234"}
-	fakeRuntime.PodList = []*containertest.FakePod{
-		{Pod: &kubecontainer.Pod{
-			ID:        "12345678",
-			Name:      "podFoo",
-			Namespace: "nsFoo",
-			Containers: []*kubecontainer.Container{
-				{Name: "containerFoo",
-					ID: containerID,
+		containerID := kubecontainer.ContainerID{Type: "test", ID: "abc1234"}
+		fakeRuntime.PodList = []*containertest.FakePod{
+			{Pod: &kubecontainer.Pod{
+				ID:        "12345678",
+				Name:      "podFoo",
+				Namespace: "nsFoo",
+				Containers: []*kubecontainer.Container{
+					{Name: "containerFoo",
+						ID: containerID,
+					},
 				},
-			},
-		}},
-	}
-	cmd := []string{"ls"}
-	_, err := kubelet.RunInContainer("podFoo_nsFoo", "", "containerFoo", cmd)
-	if fakeCommandRunner.ID != containerID {
-		t.Errorf("unexpected Name: %s", fakeCommandRunner.ID)
-	}
-	if !reflect.DeepEqual(fakeCommandRunner.Cmd, cmd) {
-		t.Errorf("unexpected command: %s", fakeCommandRunner.Cmd)
-	}
-	if err != nil {
-		t.Errorf("unexpected error: %v", err)
+			}},
+		}
+		cmd := []string{"ls"}
+		actualOutput, err := kubelet.RunInContainer("podFoo_nsFoo", "", "containerFoo", cmd)
+		if fakeCommandRunner.ID != containerID {
+			t.Errorf("(testError=%v) unexpected Name: %s", testError, fakeCommandRunner.ID)
+		}
+		if !reflect.DeepEqual(fakeCommandRunner.Cmd, cmd) {
+			t.Errorf("(testError=%v) unexpected command: %s", testError, fakeCommandRunner.Cmd)
+		}
+		// this isn't 100% foolproof as a bug in a real ContainerCommandRunner where it fails to copy to stdout/stderr wouldn't be caught by this test
+		if "foobar" != string(actualOutput) {
+			t.Errorf("(testError=%v) unexpected output %q", testError, actualOutput)
+		}
+		if e, a := fmt.Sprintf("%v", testError), fmt.Sprintf("%v", err); e != a {
+			t.Errorf("(testError=%v) error: expected %s, got %s", testError, e, a)
+		}
 	}
 }
 

pkg/kubelet/prober/prober.go

@@ -223,6 +223,8 @@ func formatURL(scheme string, host string, port int, path string) *url.URL {
 }
 
 type execInContainer struct {
+	// run executes a command in a container. Combined stdout and stderr output is always returned. An
+	// error is returned if one occurred.
 	run func() ([]byte, error)
 }
 
@@ -231,11 +233,10 @@ func (p *prober) newExecInContainer(container api.Container, containerID kubecon
 		var buffer bytes.Buffer
 		output := ioutils.WriteCloserWrapper(&buffer)
 		err := p.runner.ExecInContainer(containerID, cmd, nil, output, output, false, nil)
-		if err != nil {
-			return nil, err
-		}
-
-		return buffer.Bytes(), nil
+		// Even if err is non-nil, there still may be output (e.g. the exec wrote to stdout or stderr but
+		// the command returned a nonzero exit code). Therefore, always return the output along with the
+		// error.
+		return buffer.Bytes(), err
 	}}
 }
 

pkg/kubelet/prober/prober_test.go

@@ -19,6 +19,7 @@ package prober
 import (
 	"errors"
 	"fmt"
+	"io"
 	"net/http"
 	"reflect"
 	"testing"
@@ -29,6 +30,7 @@ import (
 	"k8s.io/kubernetes/pkg/kubelet/prober/results"
 	"k8s.io/kubernetes/pkg/probe"
 	"k8s.io/kubernetes/pkg/util/intstr"
+	"k8s.io/kubernetes/pkg/util/term"
 )
 
 func TestFormatURL(t *testing.T) {
@@ -276,3 +278,93 @@ func TestProbe(t *testing.T) {
 		}
 	}
 }
+
+type fakeContainerCommandRunner struct {
+	// what to return
+	stdoutData string
+	stderrData string
+	err        error
+
+	// actual values when invoked
+	containerID kubecontainer.ContainerID
+	cmd         []string
+	stdin       io.Reader
+	tty         bool
+	resize      <-chan term.Size
+}
+
+var _ kubecontainer.ContainerCommandRunner = &fakeContainerCommandRunner{}
+
+func (f *fakeContainerCommandRunner) ExecInContainer(containerID kubecontainer.ContainerID, cmd []string, stdin io.Reader, stdout, stderr io.WriteCloser, tty bool, resize <-chan term.Size) error {
+	// record invoked values
+	f.containerID = containerID
+	f.cmd = cmd
+	f.stdin = stdin
+	f.tty = tty
+	f.resize = resize
+
+	fmt.Fprint(stdout, f.stdoutData)
+	fmt.Fprint(stdout, f.stderrData)
+
+	return f.err
+}
+
+func (f *fakeContainerCommandRunner) PortForward(pod *kubecontainer.Pod, port uint16, stream io.ReadWriteCloser) error {
+	panic("not implemented")
+}
+
+func TestNewExecInContainer(t *testing.T) {
+	tests := []struct {
+		name string
+		err  error
+	}{
+		{
+			name: "no error",
+			err:  nil,
+		},
+		{
+			name: "error - make sure we get output",
+			err:  errors.New("bad"),
+		},
+	}
+
+	for _, test := range tests {
+		runner := &fakeContainerCommandRunner{
+			stdoutData: "foo",
+			stderrData: "bar",
+			err:        test.err,
+		}
+		prober := &prober{
+			runner: runner,
+		}
+
+		container := api.Container{}
+		containerID := kubecontainer.ContainerID{Type: "docker", ID: "containerID"}
+		cmd := []string{"/foo", "bar"}
+		exec := prober.newExecInContainer(container, containerID, cmd)
+
+		actualOutput, err := exec.CombinedOutput()
+		if e, a := containerID, runner.containerID; e != a {
+			t.Errorf("%s: container id: expected %v, got %v", test.name, e, a)
+		}
+		if e, a := cmd, runner.cmd; !reflect.DeepEqual(e, a) {
+			t.Errorf("%s: cmd: expected %v, got %v", test.name, e, a)
+		}
+		if runner.stdin != nil {
+			t.Errorf("%s: stdin: expected nil, got %v", test.name, runner.stdin)
+		}
+		if runner.tty {
+			t.Errorf("%s: tty: expected false", test.name)
+		}
+		if runner.resize != nil {
+			t.Errorf("%s: resize chan: expected nil, got %v", test.name, runner.resize)
+		}
+		// this isn't 100% foolproof as a bug in a real ContainerCommandRunner where it fails to copy to stdout/stderr wouldn't be caught by this test
+		if e, a := "foobar", string(actualOutput); e != a {
+			t.Errorf("%s: output: expected %q, got %q", test.name, e, a)
+		}
+		if e, a := fmt.Sprintf("%v", test.err), fmt.Sprintf("%v", err); e != a {
+			t.Errorf("%s: error: expected %s, got %s", test.name, e, a)
+		}
+	}
+}