log stderr added retriable command

test/integration/a_download_only_test.go

@@ -75,4 +75,3 @@ func TestDownloadOnly(t *testing.T) {
 // 	}
 // 	return nil
 // }
-

test/integration/fn_addons.go

@@ -178,9 +178,9 @@ func testServicesList(t *testing.T) {
 	mk := NewMinikubeRunner(t, p)
 
 	checkServices := func() error {
-		output := mk.RunCommand("service list", false)
+		output, stderr := mk.RunCommand("service list", false)
 		if !strings.Contains(output, "kubernetes") {
-			return fmt.Errorf("error, kubernetes service missing from output %s", output)
+			return fmt.Errorf("error, kubernetes service missing from output: %s, \n stderr: %s", output, stderr)
 		}
 		return nil
 	}
@@ -211,12 +211,12 @@ func testRegistry(t *testing.T) {
 	if err := pkgutil.WaitForPodsWithLabelRunning(client, "kube-system", ps); err != nil {
 		t.Fatalf("waiting for registry-proxy pods: %v", err)
 	}
-
+	ip, stderr := mk.RunCommand("ip", true)
-	ip := strings.TrimSpace(mk.RunCommand("ip", true))
+	ip = strings.TrimSpace(ip)
 	endpoint := fmt.Sprintf("http://%s:%d", ip, 5000)
 	u, err := url.Parse(endpoint)
 	if err != nil {
-		t.Fatalf("failed to parse %q: %v", endpoint, err)
+		t.Fatalf("failed to parse %q: %v stderr : %s", endpoint, err, stderr)
 	}
 	t.Log("checking registry access from outside cluster")
 

test/integration/fn_cluster_env.go

@@ -34,10 +34,10 @@ func testClusterEnv(t *testing.T) {
 	mk := NewMinikubeRunner(t, p, "--wait=false")
 
 	// Set a specific shell syntax so that we don't have to handle every possible user shell
-	envOut := mk.RunCommand("docker-env --shell=bash", true)
+	envOut, stderr := mk.RunCommand("docker-env --shell=bash", true)
 	vars := mk.ParseEnvCmdOutput(envOut)
 	if len(vars) == 0 {
-		t.Fatalf("Failed to parse env vars:\n%s", envOut)
+		t.Fatalf("Failed to parse env vars:\n%s, \n stderr: %s ", envOut, stderr)
 	}
 	for k, v := range vars {
 		t.Logf("Found: %s=%s", k, v)

test/integration/fn_cluster_ssh.go

@@ -28,8 +28,8 @@ func testClusterSSH(t *testing.T) {
 	p := "minikube"
 	mk := NewMinikubeRunner(t, p, "--wait=false")
 	expectedStr := "hello"
-	sshCmdOutput := mk.RunCommand("ssh echo "+expectedStr, true)
+	sshCmdOutput, stderr := mk.RunCommand("ssh echo "+expectedStr, true)
 	if !strings.Contains(sshCmdOutput, expectedStr) {
-		t.Fatalf("ExpectedStr sshCmdOutput to be: %s. Output was: %s", expectedStr, sshCmdOutput)
+		t.Fatalf("ExpectedStr sshCmdOutput to be: %s. Output was: %s Stderr: %s", expectedStr, sshCmdOutput, stderr)
 	}
 }

test/integration/fn_profile.go

@@ -28,8 +28,8 @@ func testProfileList(t *testing.T) {
 	p := "minikube"
 	t.Parallel()
 	mk := NewMinikubeRunner(t, p, "--wait=false")
-	out := mk.RunCommand("profile list", true)
+	out, stderr := mk.RunCommand("profile list", true)
 	if !strings.Contains(out, p) {
-		t.Errorf("Error , failed to read profile name (%s) in `profile list` command output : \n %q ", p, out)
+		t.Errorf("Error , failed to read profile name (%s) in `profile list` command output : \n %q : \n stderr: %s ", p, out, stderr)
 	}
 }

test/integration/fn_tunnel.go

@@ -48,9 +48,10 @@ func testTunnel(t *testing.T) {
 	p := "minikube"
 	mk := NewMinikubeRunner(t, p, "--wait=false")
 	go func() {
-		output := mk.RunCommand("tunnel --alsologtostderr -v 8 --logtostderr", true)
+		output, stderr := mk.RunCommand("tunnel --alsologtostderr -v 8 --logtostderr", true)
 		if t.Failed() {
-			fmt.Println(output)
+			t.Errorf("tunnel stderr : %s", stderr)
+			t.Errorf("tunnel output : %s", output)
 		}
 	}()
 

test/integration/start_stop_delete_test.go

@@ -95,10 +95,10 @@ func TestStartStop(t *testing.T) {
 
 				mk.CheckStatus(state.Running.String())
 
-				ip := mk.RunCommand("ip", true)
+				ip, stderr := mk.RunCommand("ip", true)
 				ip = strings.TrimRight(ip, "\n")
 				if net.ParseIP(ip) == nil {
-					t.Fatalf("IP command returned an invalid address: %s", ip)
+					t.Fatalf("IP command returned an invalid address: %s \n %s", ip, stderr)
 				}
 
 				// check for the current-context before and after the stop

test/integration/util/common.go

@@ -21,10 +21,10 @@ import (
 	"testing"
 	"time"
 
+	"github.com/cenkalti/backoff"
 	"github.com/pkg/errors"
 	"k8s.io/apimachinery/pkg/labels"
 	commonutil "k8s.io/minikube/pkg/util"
-	"github.com/cenkalti/backoff"
 )
 
 // WaitForBusyboxRunning waits until busybox pod to be running
@@ -175,15 +175,17 @@ func Retry2(callback func() error, d time.Duration, attempts int) (err error) {
 	return err
 }
 
-// RetryX is expontntial back off retrying
+// RetryX is expontential backoff retry
-func RetryX(cb func() error) error {
+func RetryX(callback func() error, maxTime time.Duration) error {
 	b := backoff.NewExponentialBackOff()
-	b.MaxElapsedTime = time.Second * 15
+	b.MaxElapsedTime = maxTime
-
+	b.InitialInterval = 1 * time.Minute
-	return backoff.Retry(cb, b)
+	b.RandomizationFactor = 0.5
+	b.Multiplier = 1.5
+	b.Reset()
+	return backoff.Retry(callback, b)
 }
 
-
 // Logf writes logs to stdout if -v is set.
 func Logf(str string, args ...interface{}) {
 	if !testing.Verbose() {

test/integration/util/minikube_runner.go

@@ -61,10 +61,10 @@ func (m *MinikubeRunner) Remove(f assets.CopyableFile) error {
 }
 
 // teeRun runs a command, streaming stdout, stderr to console
-func (m *MinikubeRunner) teeRun(cmd *exec.Cmd, wait ...bool) (string, string, error) {
+func (m *MinikubeRunner) teeRun(cmd *exec.Cmd, waitForRun ...bool) (string, string, error) {
 	w := true
-	if wait != nil {
+	if waitForRun != nil {
-		w = wait[0]
+		w = waitForRun[0]
 	}
 
 	errPipe, err := cmd.StderrPipe()
@@ -104,8 +104,8 @@ func (m *MinikubeRunner) teeRun(cmd *exec.Cmd, wait ...bool) (string, string, er
 	return "", "", err
 }
 
-// RunCommand executes a command, optionally checking for error
+// RunCommand executes a command, optionally checking for error and by default waits for run to finish
-func (m *MinikubeRunner) RunCommand(cmdStr string, failError bool, wait ...bool) string {
+func (m *MinikubeRunner) RunCommand(cmdStr string, failError bool, waitForRun ...bool) (string, string) {
 	profileArg := fmt.Sprintf("-p=%s ", m.Profile)
 	cmdStr = profileArg + cmdStr
 	cmdArgs := strings.Split(cmdStr, " ")
@@ -113,15 +113,43 @@ func (m *MinikubeRunner) RunCommand(cmdStr string, failError bool, wait ...bool)
 
 	cmd := exec.Command(path, cmdArgs...)
 	Logf("Run: %s", cmd.Args)
-	stdout, stderr, err := m.teeRun(cmd, wait...)
+	stdout, stderr, err := m.teeRun(cmd, waitForRun...)
-	if failError && err != nil {
+	if err != nil {
+		errMsg := ""
 		if exitError, ok := err.(*exec.ExitError); ok {
-			m.T.Fatalf("Error running command: %s %s. Output: %s", cmdStr, exitError.Stderr, stdout)
+			errMsg = fmt.Sprintf("Error running command: %s %s. Output: %s Stderr: %s", cmdStr, exitError.Stderr, stdout, stderr)
 		} else {
-			m.T.Fatalf("Error running command: %s %v. Output: %s", cmdStr, err, stderr)
+			errMsg = fmt.Sprintf("Error running command: %s %s. Output: %s", cmdStr, stderr, stdout)
+		}
+		if failError {
+			m.T.Fatalf(errMsg)
+		} else {
+			m.T.Errorf(errMsg)
 		}
 	}
-	return stdout
+	return stdout, stderr
+}
+
+// RunCommandRetriable Error  executes a command, returns error
+// the purpose of this command is to make it retriable and
+// better logging for retrying
+func (m *MinikubeRunner) RunCommandRetriable(cmdStr string, waitForRun ...bool) (stdout string, stderr string, err error) {
+	profileArg := fmt.Sprintf("-p=%s ", m.Profile)
+	cmdStr = profileArg + cmdStr
+	cmdArgs := strings.Split(cmdStr, " ")
+	path, _ := filepath.Abs(m.BinaryPath)
+
+	cmd := exec.Command(path, cmdArgs...)
+	Logf("Run: %s", cmd.Args)
+	stdout, stderr, err = m.teeRun(cmd, waitForRun...)
+	if err != nil {
+		if exitError, ok := err.(*exec.ExitError); ok {
+			m.T.Logf("temproary error running command: %s %s. Output: \n%s", cmdStr, exitError.Stderr, stdout)
+		} else {
+			m.T.Logf("temproary error: running command: %s %s. Output: \n%s", cmdStr, stderr, stdout)
+		}
+	}
+	return stdout, stderr, err
 }
 
 // RunWithContext calls the minikube command with a context, useful for timeouts.
@@ -206,15 +234,15 @@ func (m *MinikubeRunner) SSH(cmdStr string) (string, error) {
 	return string(stdout), nil
 }
 
-// Start starts the cluster with console output without verbose log
+// Start starts the cluster
 func (m *MinikubeRunner) Start(opts ...string) (stdout string, stderr string, err error) {
-	ctx, cancel := context.WithTimeout(context.Background(), m.TimeOutStart)
-	defer cancel()
 	cmd := fmt.Sprintf("start %s %s %s", m.StartArgs, m.GlobalArgs, strings.Join(opts, " "))
-	
+	s := func() error {
-	m.RunWithContext(ctx, cmd)
+		stdout, stderr, err = m.RunCommandRetriable(cmd)
-	
+		return nil
-	return "", "", nil
+	}
+	err = RetryX(s, m.TimeOutStart)
+	return stdout, stderr, err
 }
 
 // TearDown deletes minikube without waiting for it. used to free up ram/cpu after each test
@@ -251,12 +279,15 @@ func (m *MinikubeRunner) ParseEnvCmdOutput(out string) map[string]string {
 
 // GetStatus returns the status of a service
 func (m *MinikubeRunner) GetStatus() string {
-	return m.RunCommand(fmt.Sprintf("status --format={{.Host}} %s", m.GlobalArgs), false)
+	stdout, _ := m.RunCommand(fmt.Sprintf("status --format={{.Host}} %s", m.GlobalArgs), false)
+	return stdout
 }
 
 // GetLogs returns the logs of a service
 func (m *MinikubeRunner) GetLogs() string {
-	return m.RunCommand(fmt.Sprintf("logs %s", m.GlobalArgs), true)
+	// TODO: this test needs to check sterr too !
+	stdout, _ := m.RunCommand(fmt.Sprintf("logs %s", m.GlobalArgs), true)
+	return stdout
 }
 
 // CheckStatus makes sure the service has the desired status, or cause fatal error