Include kubelet logs in output when running node e2e tests

test/e2e_node/gcloud/gcloud.go

@@ -17,13 +17,13 @@ limitations under the License.
 package gcloud
 
 import (
+	"bytes"
 	"errors"
 	"fmt"
 	"math/rand"
-	"os/exec"
-
 	"net"
 	"net/http"
+	"os/exec"
 	"path/filepath"
 	"regexp"
 	"strings"
@@ -54,9 +54,10 @@ type RunResult struct {
 }
 
 type CmdHandle struct {
-	TearDown TearDown
-	Output   chan RunResult
-	LPort    string
+	TearDown       TearDown
+	CombinedOutput bytes.Buffer
+	Output         chan RunResult
+	LPort          string
 }
 
 func NewGCloudClient(host string, zone string) GCloudClient {
@@ -74,7 +75,7 @@ func (gc *gCloudClientImpl) Command(cmd string, moreargs ...string) ([]byte, err
 	return exec.Command("gcloud", args...).CombinedOutput()
 }
 
-func (gc *gCloudClientImpl) TunnelCommand(sudo bool, lPort string, rPort string, dir string, cmd string, moreargs ...string) ([]byte, error) {
+func (gc *gCloudClientImpl) TunnelCommand(sudo bool, lPort string, rPort string, dir string, cmd string, moreargs ...string) *exec.Cmd {
 	tunnelStr := fmt.Sprintf("-L %s:localhost:%s", lPort, rPort)
 	args := []string{"compute", "ssh"}
 	if gc.zone != "" {
@@ -88,7 +89,7 @@ func (gc *gCloudClientImpl) TunnelCommand(sudo bool, lPort string, rPort string,
 	args = append(args, cmd)
 	args = append(args, moreargs...)
 	glog.V(2).Infof("Command gcloud %s", strings.Join(args, " "))
-	return exec.Command("gcloud", args...).CombinedOutput()
+	return exec.Command("gcloud", args...)
 }
 
 func (gc *gCloudClientImpl) CopyToHost(from string, to string) ([]byte, error) {
@@ -162,13 +163,15 @@ func (gc *gCloudClientImpl) Run(
 			}
 		}
 
-		// Do the setup
+		c := gc.TunnelCommand(sudo, h.LPort, remotePort, tDir, cmd, args...)
+		c.Stdout = &h.CombinedOutput
+		c.Stderr = &h.CombinedOutput
 		go func() {
 			// Start the process
-			out, err = gc.TunnelCommand(sudo, h.LPort, remotePort, tDir, cmd, args...)
+			err = c.Run()
 			if err != nil {
-				glog.Errorf("command failed %v %s", err, out)
-				h.Output <- RunResult{out, err, fmt.Sprintf("%s %s", cmd, strings.Join(args, " "))}
+				glog.Errorf("command failed %v %s", err, h.CombinedOutput.Bytes())
+				h.Output <- RunResult{h.CombinedOutput.Bytes(), err, fmt.Sprintf("%s %s", cmd, strings.Join(args, " "))}
 				return
 			}
 		}()

test/e2e_node/runner/run_e2e.go

@@ -43,6 +43,10 @@ type Result struct {
 	err    error
 }
 
+const gray = "\033[1;30m"
+const blue = "\033[0;34m"
+const noColour = "\033[0m"
+
 var u = sync.WaitGroup{}
 var zone = flag.String("zone", "", "gce zone the hosts live in")
 var hosts = flag.String("hosts", "", "hosts to test")
@@ -77,18 +81,10 @@ func main() {
 		u.Add(1)
 	}
 
-	results := make(chan error)
+	results := make(chan *TestResult)
 	hs := strings.Split(*hosts, ",")
 	for _, h := range hs {
-		go func(host string) {
-			out, err := runTests(host)
-			if err != nil {
-				glog.Infof("Failure Finished Host %s Test Suite %s %v", host, out, err)
-			} else {
-				glog.Infof("Success Finished Host %s Test Suite %s", host, out)
-			}
-			results <- err
-		}(h)
+		go func(host string) { results <- runTests(host) }(h)
 	}
 
 	// Maybe wait for user input before running tests
@@ -96,11 +92,26 @@ func main() {
 		WaitForUser()
 	}
 
-	// Wait for all tests to complete and check for failures
+	// Wait for all tests to complete and emit the results
 	errCount := 0
 	for i := 0; i < len(hs); i++ {
-		if <-results != nil {
+		tr := <-results
+		host := tr.fullhost
+		if tr.err != nil {
 			errCount++
+			glog.Infof("%s================================================================%s", blue, noColour)
+			glog.Infof("Failure Finished Host %s Test Suite %s %v", host, tr.testCombinedOutput, tr.err)
+			glog.V(2).Infof("----------------------------------------------------------------")
+			glog.V(5).Infof("Host %s Etcd Logs\n%s%s%s", host, gray, tr.etcdCombinedOutput, noColour)
+			glog.V(5).Infof("----------------------------------------------------------------")
+			glog.V(5).Infof("Host %s Apiserver Logs\n%s%s%s", host, gray, tr.apiServerCombinedOutput, noColour)
+			glog.V(5).Infof("----------------------------------------------------------------")
+			glog.V(2).Infof("Host %s Kubelet Logs\n%s%s%s", host, gray, tr.kubeletCombinedOutput, noColour)
+			glog.Infof("%s================================================================%s", blue, noColour)
+		} else {
+			glog.Infof("================================================================")
+			glog.Infof("Success Finished Host %s Test Suite %s", host, tr.testCombinedOutput)
+			glog.Infof("================================================================")
 		}
 	}
 
@@ -123,34 +134,58 @@ func WaitForUser() {
 	u.Done()
 }
 
-func runTests(fullhost string) ([]byte, error) {
+type TestResult struct {
+	fullhost                string
+	err                     error
+	testCombinedOutput      string
+	etcdCombinedOutput      string
+	apiServerCombinedOutput string
+	kubeletCombinedOutput   string
+}
+
+func runTests(fullhost string) *TestResult {
+	result := &TestResult{fullhost: fullhost}
+
 	host := strings.Split(fullhost, ".")[0]
 	c := gcloud.NewGCloudClient(host, *zone)
 	// TODO(pwittrock): Come up with something better for bootstrapping the environment.
 	eh, err := c.RunAndWaitTillHealthy(
 		false, false, "4001", healthyTimeoutDuration, "v2/keys/", "etcd", "--data-dir", "./", "--name", "e2e-node")
-	defer func() { eh.TearDown() }()
+	defer func() {
+		eh.TearDown()
+		result.etcdCombinedOutput = fmt.Sprintf("%s", eh.CombinedOutput.Bytes())
+	}()
 	if err != nil {
-		return nil, fmt.Errorf("Host %s failed to run command %v", host, err)
+		result.err = fmt.Errorf("Host %s failed to run command %v", host, err)
+		return result
 	}
 
 	apiBin := filepath.Join(kubeRoot, *kubeOutputRelPath, "kube-apiserver")
 	ah, err := c.RunAndWaitTillHealthy(
 		true, true, "8080", healthyTimeoutDuration, "healthz", apiBin, "--service-cluster-ip-range",
 		"10.0.0.1/24", "--insecure-bind-address", "0.0.0.0", "--etcd-servers", "http://127.0.0.1:4001",
-		"--v", "2", "--kubelet-port", "10250")
-	defer func() { ah.TearDown() }()
+		"--v", "2", "--alsologtostderr", "--kubelet-port", "10250")
+	defer func() {
+		ah.TearDown()
+		result.apiServerCombinedOutput = fmt.Sprintf("%s", ah.CombinedOutput.Bytes())
+	}()
 	if err != nil {
-		return nil, fmt.Errorf("Host %s failed to run command %v", host, err)
+		result.err = fmt.Errorf("Host %s failed to run command %v", host, err)
+		return result
 	}
 
 	kubeletBin := filepath.Join(kubeRoot, *kubeOutputRelPath, "kubelet")
+	// TODO: Used --v 4 or higher and upload to gcs instead of printing to the console
+	// TODO: Copy /var/log/messages and upload to GCS for failed tests
 	kh, err := c.RunAndWaitTillHealthy(
 		true, true, "10255", healthyTimeoutDuration, "healthz", kubeletBin, "--api-servers", "http://127.0.0.1:8080",
-		"--logtostderr", "--address", "0.0.0.0", "--port", "10250")
-	defer func() { kh.TearDown() }()
+		"--v", "2", "--alsologtostderr", "--address", "0.0.0.0", "--port", "10250")
+	defer func() {
+		kh.TearDown()
+		result.kubeletCombinedOutput = fmt.Sprintf("%s", kh.CombinedOutput.Bytes())
+	}()
 	if err != nil {
-		return nil, fmt.Errorf("Host %s failed to run command %v", host, err)
+		result.err = fmt.Errorf("Host %s failed to run command %v", host, err)
 	}
 
 	// Run the tests
@@ -159,10 +194,14 @@ func runTests(fullhost string) ([]byte, error) {
 	u.Wait()
 	glog.Infof("Running ginkgo tests against host %s", host)
 	ginkgoTests := filepath.Join(kubeRoot, ginkgoTestRelPath)
-	return exec.Command(
+	out, err := exec.Command(
 		"ginkgo", ginkgoTests, "--",
 		"--kubelet-address", fmt.Sprintf("http://127.0.0.1:%s", kh.LPort),
 		"--api-server-address", fmt.Sprintf("http://127.0.0.1:%s", ah.LPort),
 		"--node-name", fullhost,
-		"-logtostderr").CombinedOutput()
+		"--v", "2", "--alsologtostderr").CombinedOutput()
+
+	result.err = err
+	result.testCombinedOutput = fmt.Sprintf("%s", out)
+	return result
 }