test: enable timeouts for running E2E commands

test/e2e/kubernetes/deployment/deployment.go

@@ -17,6 +17,8 @@ import (
 	"github.com/pkg/errors"
 )
 
+const commandTimeout = 1 * time.Minute
+
 // List holds a list of deployments returned from kubectl get deploy
 type List struct {
 	Deployments []Deployment `json:"items"`
@@ -71,7 +73,7 @@ func CreateLinuxDeploy(image, name, namespace, miscOpts string) (*Deployment, er
 	} else {
 		cmd = exec.Command("k", "run", name, "-n", namespace, "--image", image, "--image-pull-policy=IfNotPresent", "--overrides", overrides)
 	}
-	out, err := util.RunAndLogCommand(cmd)
+	out, err := util.RunAndLogCommand(cmd, commandTimeout)
 	if err != nil {
 		log.Printf("Error trying to deploy %s [%s] in namespace %s:%s\n", name, image, namespace, string(out))
 		return nil, err
@@ -99,7 +101,7 @@ func CreateLinuxDeployIfNotExist(image, name, namespace, miscOpts string) (*Depl
 func RunLinuxDeploy(image, name, namespace, command string, replicas int) (*Deployment, error) {
 	overrides := `{ "spec":{"template":{"spec": {"nodeSelector":{"beta.kubernetes.io/os":"linux"}}}}}`
 	cmd := exec.Command("k", "run", name, "-n", namespace, "--image", image, "--image-pull-policy=IfNotPresent", "--replicas", strconv.Itoa(replicas), "--overrides", overrides, "--command", "--", "/bin/sh", "-c", command)
-	out, err := util.RunAndLogCommand(cmd)
+	out, err := util.RunAndLogCommand(cmd, commandTimeout)
 	if err != nil {
 		log.Printf("Error trying to deploy %s [%s] in namespace %s:%s\n", name, image, namespace, string(out))
 		return nil, err
@@ -116,7 +118,7 @@ func RunLinuxDeploy(image, name, namespace, command string, replicas int) (*Depl
 func CreateWindowsDeploy(image, name, namespace string, port int, hostport int) (*Deployment, error) {
 	overrides := `{ "spec":{"template":{"spec": {"nodeSelector":{"beta.kubernetes.io/os":"windows"}}}}}`
 	cmd := exec.Command("k", "run", name, "-n", namespace, "--image", image, "--port", strconv.Itoa(port), "--hostport", strconv.Itoa(hostport), "--overrides", overrides)
-	out, err := util.RunAndLogCommand(cmd)
+	out, err := util.RunAndLogCommand(cmd, commandTimeout)
 	if err != nil {
 		log.Printf("Error trying to deploy %s [%s] in namespace %s:%s\n", name, image, namespace, string(out))
 		return nil, err
@@ -132,7 +134,7 @@ func CreateWindowsDeploy(image, name, namespace string, port int, hostport int)
 // Get returns a deployment from a name and namespace
 func Get(name, namespace string) (*Deployment, error) {
 	cmd := exec.Command("k", "get", "deploy", "-o", "json", "-n", namespace, name)
-	out, err := util.RunAndLogCommand(cmd)
+	out, err := util.RunAndLogCommand(cmd, commandTimeout)
 	if err != nil {
 		log.Printf("Error while trying to fetch deployment %s in namespace %s:%s\n", name, namespace, string(out))
 		return nil, err
@@ -152,7 +154,7 @@ func (d *Deployment) Delete(retries int) error {
 	var kubectlError error
 	for i := 0; i < retries; i++ {
 		cmd := exec.Command("k", "delete", "deploy", "-n", d.Metadata.Namespace, d.Metadata.Name)
-		kubectlOutput, kubectlError = util.RunAndLogCommand(cmd)
+		kubectlOutput, kubectlError = util.RunAndLogCommand(cmd, commandTimeout)
 		if kubectlError != nil {
 			log.Printf("Error while trying to delete deployment %s in namespace %s:%s\n", d.Metadata.Namespace, d.Metadata.Name, string(kubectlOutput))
 			continue
@@ -167,7 +169,7 @@ func (d *Deployment) Delete(retries int) error {
 	if d.Metadata.HasHPA {
 		for i := 0; i < retries; i++ {
 			cmd := exec.Command("k", "delete", "hpa", "-n", d.Metadata.Namespace, d.Metadata.Name)
-			kubectlOutput, kubectlError = util.RunAndLogCommand(cmd)
+			kubectlOutput, kubectlError = util.RunAndLogCommand(cmd, commandTimeout)
 			if kubectlError != nil {
 				log.Printf("Deployment %s has associated HPA but unable to delete in namespace %s:%s\n", d.Metadata.Namespace, d.Metadata.Name, string(kubectlOutput))
 				continue
@@ -182,7 +184,7 @@ func (d *Deployment) Delete(retries int) error {
 // Expose will create a load balancer and expose the deployment on a given port
 func (d *Deployment) Expose(svcType string, targetPort, exposedPort int) error {
 	cmd := exec.Command("k", "expose", "deployment", d.Metadata.Name, "--type", svcType, "-n", d.Metadata.Namespace, "--target-port", strconv.Itoa(targetPort), "--port", strconv.Itoa(exposedPort))
-	out, err := util.RunAndLogCommand(cmd)
+	out, err := util.RunAndLogCommand(cmd, commandTimeout)
 	if err != nil {
 		log.Printf("Error while trying to expose (%s) target port (%v) for deployment %s in namespace %s on port %v:%s\n", svcType, targetPort, d.Metadata.Name, d.Metadata.Namespace, exposedPort, string(out))
 		return err
@@ -193,7 +195,7 @@ func (d *Deployment) Expose(svcType string, targetPort, exposedPort int) error {
 // ScaleDeployment scales a deployment to n instancees
 func (d *Deployment) ScaleDeployment(n int) error {
 	cmd := exec.Command("k", "scale", fmt.Sprintf("--replicas=%d", n), "deployment", d.Metadata.Name)
-	out, err := util.RunAndLogCommand(cmd)
+	out, err := util.RunAndLogCommand(cmd, commandTimeout)
 	if err != nil {
 		log.Printf("Error while scaling deployment %s to %d pods:%s\n", d.Metadata.Name, n, string(out))
 		return err
@@ -205,7 +207,7 @@ func (d *Deployment) ScaleDeployment(n int) error {
 func (d *Deployment) CreateDeploymentHPA(cpuPercent, min, max int) error {
 	cmd := exec.Command("k", "autoscale", "deployment", d.Metadata.Name, fmt.Sprintf("--cpu-percent=%d", cpuPercent),
 		fmt.Sprintf("--min=%d", min), fmt.Sprintf("--max=%d", max))
-	out, err := util.RunAndLogCommand(cmd)
+	out, err := util.RunAndLogCommand(cmd, commandTimeout)
 	if err != nil {
 		log.Printf("Error while configuring autoscale against deployment %s:%s\n", d.Metadata.Name, string(out))
 		return err

test/e2e/kubernetes/hpa/hpa.go

@@ -12,6 +12,8 @@ import (
 	"github.com/Azure/aks-engine/test/e2e/kubernetes/util"
 )
 
+const commandTimeout = 1 * time.Minute
+
 // HPA represents a kubernetes HPA
 type HPA struct {
 	Metadata Metadata `json:"metadata"`
@@ -69,7 +71,7 @@ func (h *HPA) Delete(retries int) error {
 	var kubectlError error
 	for i := 0; i < retries; i++ {
 		cmd := exec.Command("k", "delete", "hpa", "-n", h.Metadata.Namespace, h.Metadata.Name)
-		kubectlOutput, kubectlError = util.RunAndLogCommand(cmd)
+		kubectlOutput, kubectlError = util.RunAndLogCommand(cmd, commandTimeout)
 		if kubectlError != nil {
 			log.Printf("Error while trying to delete service %s in namespace %s:%s\n", h.Metadata.Namespace, h.Metadata.Name, string(kubectlOutput))
 			continue

test/e2e/kubernetes/kubernetes_test.go

@@ -41,6 +41,8 @@ const (
 	retryCommandsTimeout            = 5 * time.Minute
 	kubeSystemPodsReadinessChecks   = 6
 	retryTimeWhenWaitingForPodReady = 1 * time.Minute
+	stabilityCommandTimeout         = 5 * time.Second
+	windowsCommandTimeout           = 1 * time.Minute
 )
 
 var (
@@ -362,7 +364,7 @@ var _ = Describe("Azure Container Cluster using the Kubernetes Orchestrator", fu
 		It("should have stable external container networking as we recycle a bunch of pods", func() {
 			name := fmt.Sprintf("alpine-%s", cfg.Name)
 			command := fmt.Sprintf("nc -vz 8.8.8.8 53 || nc -vz 8.8.4.4 53")
-			successes, err := pod.RunCommandMultipleTimes(pod.RunLinuxPod, "alpine", name, command, cfg.StabilityIterations, 1*time.Second, retryCommandsTimeout)
+			successes, err := pod.RunCommandMultipleTimes(pod.RunLinuxPod, "alpine", name, command, cfg.StabilityIterations, 1*time.Second, retryCommandsTimeout, stabilityCommandTimeout)
 			Expect(err).NotTo(HaveOccurred())
 			Expect(successes).To(Equal(cfg.StabilityIterations))
 		})
@@ -375,7 +377,7 @@ var _ = Describe("Azure Container Cluster using the Kubernetes Orchestrator", fu
 			} else {
 				command = fmt.Sprintf("nc -vz kubernetes 443")
 			}
-			successes, err := pod.RunCommandMultipleTimes(pod.RunLinuxPod, "alpine", name, command, cfg.StabilityIterations, 1*time.Second, retryCommandsTimeout)
+			successes, err := pod.RunCommandMultipleTimes(pod.RunLinuxPod, "alpine", name, command, cfg.StabilityIterations, 1*time.Second, retryCommandsTimeout, stabilityCommandTimeout)
 			Expect(err).NotTo(HaveOccurred())
 			Expect(successes).To(Equal(cfg.StabilityIterations))
 		})
@@ -387,7 +389,7 @@ var _ = Describe("Azure Container Cluster using the Kubernetes Orchestrator", fu
 				By("Creating another pod that will connect to the php-apache pod")
 				commandString := fmt.Sprintf("nc -vz %s.default.svc.cluster.local 80", longRunningApacheDeploymentName)
 				consumerPodName := fmt.Sprintf("consumer-pod-%s-%v", cfg.Name, r.Intn(99999))
-				successes, err := pod.RunCommandMultipleTimes(pod.RunLinuxPod, "busybox", consumerPodName, commandString, cfg.StabilityIterations, 1*time.Second, retryCommandsTimeout)
+				successes, err := pod.RunCommandMultipleTimes(pod.RunLinuxPod, "busybox", consumerPodName, commandString, cfg.StabilityIterations, 1*time.Second, retryCommandsTimeout, stabilityCommandTimeout)
 				Expect(err).NotTo(HaveOccurred())
 				Expect(successes).To(Equal(cfg.StabilityIterations))
 			} else {
@@ -503,7 +505,7 @@ var _ = Describe("Azure Container Cluster using the Kubernetes Orchestrator", fu
 			By("Ensuring that we have stable external DNS resolution as we recycle a bunch of pods")
 			name := fmt.Sprintf("alpine-%s", cfg.Name)
 			command := fmt.Sprintf("nc -vz bbc.co.uk 80 || nc -vz google.com 443 || nc -vz microsoft.com 80")
-			successes, err := pod.RunCommandMultipleTimes(pod.RunLinuxPod, "alpine", name, command, cfg.StabilityIterations, 1*time.Second, retryCommandsTimeout)
+			successes, err := pod.RunCommandMultipleTimes(pod.RunLinuxPod, "alpine", name, command, cfg.StabilityIterations, 1*time.Second, retryCommandsTimeout, stabilityCommandTimeout)
 			Expect(err).NotTo(HaveOccurred())
 			Expect(successes).To(Equal(cfg.StabilityIterations))
 		})
@@ -1243,21 +1245,21 @@ var _ = Describe("Azure Container Cluster using the Kubernetes Orchestrator", fu
 				By("Connecting to Windows from another Windows deployment")
 				name := fmt.Sprintf("windows-2-windows-%s", cfg.Name)
 				command := fmt.Sprintf("iwr -UseBasicParsing -TimeoutSec 60 %s", windowsService.Metadata.Name)
-				successes, err := pod.RunCommandMultipleTimes(pod.RunWindowsPod, windowsImages.ServerCore, name, command, cfg.StabilityIterations, 1*time.Second, retryCommandsTimeout)
+				successes, err := pod.RunCommandMultipleTimes(pod.RunWindowsPod, windowsImages.ServerCore, name, command, cfg.StabilityIterations, 1*time.Second, retryCommandsTimeout, windowsCommandTimeout)
 				Expect(err).NotTo(HaveOccurred())
 				Expect(successes).To(Equal(cfg.StabilityIterations))
 
 				By("Connecting to Linux from Windows deployment")
 				name = fmt.Sprintf("windows-2-linux-%s", cfg.Name)
 				command = fmt.Sprintf("iwr -UseBasicParsing -TimeoutSec 60 %s", linuxService.Metadata.Name)
-				successes, err = pod.RunCommandMultipleTimes(pod.RunWindowsPod, windowsImages.ServerCore, name, command, cfg.StabilityIterations, 1*time.Second, retryCommandsTimeout)
+				successes, err = pod.RunCommandMultipleTimes(pod.RunWindowsPod, windowsImages.ServerCore, name, command, cfg.StabilityIterations, 1*time.Second, retryCommandsTimeout, windowsCommandTimeout)
 				Expect(err).NotTo(HaveOccurred())
 				Expect(successes).To(Equal(cfg.StabilityIterations))
 
 				By("Connecting to Windows from Linux deployment")
 				name = fmt.Sprintf("linux-2-windows-%s", cfg.Name)
 				command = fmt.Sprintf("wget %s", windowsService.Metadata.Name)
-				successes, err = pod.RunCommandMultipleTimes(pod.RunLinuxPod, "alpine", name, command, cfg.StabilityIterations, 1*time.Second, retryCommandsTimeout)
+				successes, err = pod.RunCommandMultipleTimes(pod.RunLinuxPod, "alpine", name, command, cfg.StabilityIterations, 1*time.Second, retryCommandsTimeout, windowsCommandTimeout)
 				Expect(err).NotTo(HaveOccurred())
 				Expect(successes).To(Equal(cfg.StabilityIterations))
 

test/e2e/kubernetes/persistentvolumeclaims/persistentvolumeclaims.go

@@ -15,6 +15,8 @@ import (
 	"github.com/pkg/errors"
 )
 
+const commandTimeout = 1 * time.Minute
+
 // PersistentVolumeClaims is used to parse data from kubectl get pvc
 type PersistentVolumeClaims struct {
 	Metadata Metadata `json:"metadata"`
@@ -93,7 +95,7 @@ func (pvc *PersistentVolumeClaims) Delete(retries int) error {
 	var kubectlError error
 	for i := 0; i < retries; i++ {
 		cmd := exec.Command("k", "delete", "pvc", "-n", pvc.Metadata.NameSpace, pvc.Metadata.Name)
-		kubectlOutput, kubectlError = util.RunAndLogCommand(cmd)
+		kubectlOutput, kubectlError = util.RunAndLogCommand(cmd, commandTimeout)
 		if kubectlError != nil {
 			log.Printf("Error while trying to delete PVC %s in namespace %s:%s\n", pvc.Metadata.Name, pvc.Metadata.NameSpace, string(kubectlOutput))
 			continue

test/e2e/kubernetes/pod/pod.go

@@ -24,7 +24,8 @@ import (
 )
 
 const (
-	testDir string = "testdirectory"
+	testDir        string = "testdirectory"
+	commandTimeout        = 1 * time.Minute
 )
 
 // List is a container that holds all pods returned from doing a kubectl get pods
@@ -176,13 +177,13 @@ func CreatePodFromFile(filename, name, namespace string, sleep, duration time.Du
 
 // RunLinuxPod will create a pod that runs a bash command
 // --overrides := `"spec": {"nodeSelector":{"beta.kubernetes.io/os":"windows"}}}`
-func RunLinuxPod(image, name, namespace, command string, printOutput bool, sleep, duration time.Duration) (*Pod, error) {
+func RunLinuxPod(image, name, namespace, command string, printOutput bool, sleep, duration, timeout time.Duration) (*Pod, error) {
 	overrides := `{ "spec": {"nodeSelector":{"beta.kubernetes.io/os":"linux"}}}`
 	cmd := exec.Command("k", "run", name, "-n", namespace, "--image", image, "--image-pull-policy=IfNotPresent", "--restart=Never", "--overrides", overrides, "--command", "--", "/bin/sh", "-c", command)
 	var out []byte
 	var err error
 	if printOutput {
-		out, err = util.RunAndLogCommand(cmd)
+		out, err = util.RunAndLogCommand(cmd, timeout)
 	} else {
 		out, err = cmd.CombinedOutput()
 	}
@@ -200,13 +201,13 @@ func RunLinuxPod(image, name, namespace, command string, printOutput bool, sleep
 
 // RunWindowsPod will create a pod that runs a powershell command
 // --overrides := `"spec": {"nodeSelector":{"beta.kubernetes.io/os":"windows"}}}`
-func RunWindowsPod(image, name, namespace, command string, printOutput bool, sleep, duration time.Duration) (*Pod, error) {
+func RunWindowsPod(image, name, namespace, command string, printOutput bool, sleep, duration time.Duration, timeout time.Duration) (*Pod, error) {
 	overrides := `{ "spec": {"nodeSelector":{"beta.kubernetes.io/os":"windows"}}}`
 	cmd := exec.Command("k", "run", name, "-n", namespace, "--image", image, "--image-pull-policy=IfNotPresent", "--restart=Never", "--overrides", overrides, "--command", "--", "powershell", command)
 	var out []byte
 	var err error
 	if printOutput {
-		out, err = util.RunAndLogCommand(cmd)
+		out, err = util.RunAndLogCommand(cmd, timeout)
 	} else {
 		out, err = cmd.CombinedOutput()
 	}
@@ -222,10 +223,10 @@ func RunWindowsPod(image, name, namespace, command string, printOutput bool, sle
 	return p, nil
 }
 
-type podRunnerCmd func(string, string, string, string, bool, time.Duration, time.Duration) (*Pod, error)
+type podRunnerCmd func(string, string, string, string, bool, time.Duration, time.Duration, time.Duration) (*Pod, error)
 
 // RunCommandMultipleTimes runs the same command 'desiredAttempts' times
-func RunCommandMultipleTimes(podRunnerCmd podRunnerCmd, image, name, command string, desiredAttempts int, sleep, duration time.Duration) (int, error) {
+func RunCommandMultipleTimes(podRunnerCmd podRunnerCmd, image, name, command string, desiredAttempts int, sleep, duration, timeout time.Duration) (int, error) {
 	var successfulAttempts int
 	var actualAttempts int
 	logResults := func() {
@@ -238,12 +239,7 @@ func RunCommandMultipleTimes(podRunnerCmd podRunnerCmd, image, name, command str
 		podName := fmt.Sprintf("%s-%d", name, r.Intn(99999))
 		var p *Pod
 		var err error
-		if i < 1 {
-			// Print the first attempt
-			p, err = podRunnerCmd(image, podName, "default", command, true, sleep, duration)
-		} else {
-			p, err = podRunnerCmd(image, podName, "default", command, false, sleep, duration)
-		}
+		p, err = podRunnerCmd(image, podName, "default", command, true, sleep, duration, timeout)
 
 		if err != nil {
 			return successfulAttempts, err
@@ -578,7 +574,7 @@ func (p *Pod) Delete(retries int) error {
 	var kubectlError error
 	for i := 0; i < retries; i++ {
 		cmd := exec.Command("k", "delete", "po", "-n", p.Metadata.Namespace, p.Metadata.Name)
-		kubectlOutput, kubectlError = util.RunAndLogCommand(cmd)
+		kubectlOutput, kubectlError = util.RunAndLogCommand(cmd, commandTimeout)
 		if kubectlError != nil {
 			log.Printf("Error while trying to delete Pod %s in namespace %s:%s\n", p.Metadata.Namespace, p.Metadata.Name, string(kubectlOutput))
 			continue
@@ -771,7 +767,7 @@ func (p *Pod) ValidateHostPort(check string, attempts int, sleep time.Duration,
 
 	for i := 0; i < attempts; i++ {
 		cmd := exec.Command("ssh", "-i", sshKeyPath, "-o", "ConnectTimeout=10", "-o", "StrictHostKeyChecking=no", "-o", "UserKnownHostsFile=/dev/null", master, curlCMD)
-		out, err := util.RunAndLogCommand(cmd)
+		out, err := util.RunAndLogCommand(cmd, commandTimeout)
 		if err == nil {
 			matched, _ := regexp.MatchString(check, string(out))
 			if matched {
@@ -787,7 +783,7 @@ func (p *Pod) ValidateHostPort(check string, attempts int, sleep time.Duration,
 func (p *Pod) Logs() error {
 	for _, container := range p.Spec.Containers {
 		cmd := exec.Command("k", "logs", p.Metadata.Name, "-c", container.Name, "-n", p.Metadata.Namespace)
-		out, err := util.RunAndLogCommand(cmd)
+		out, err := util.RunAndLogCommand(cmd, commandTimeout)
 		log.Printf("\n%s\n", string(out))
 		if err != nil {
 			return err

test/e2e/kubernetes/service/service.go

@@ -18,6 +18,8 @@ import (
 	"github.com/pkg/errors"
 )
 
+const commandTimeout = 1 * time.Minute
+
 // Service represents a kubernetes service
 type Service struct {
 	Metadata Metadata `json:"metadata"`
@@ -82,7 +84,7 @@ func (s *Service) Delete(retries int) error {
 	var kubectlError error
 	for i := 0; i < retries; i++ {
 		cmd := exec.Command("k", "delete", "svc", "-n", s.Metadata.Namespace, s.Metadata.Name)
-		kubectlOutput, kubectlError = util.RunAndLogCommand(cmd)
+		kubectlOutput, kubectlError = util.RunAndLogCommand(cmd, commandTimeout)
 		if kubectlError != nil {
 			log.Printf("Error while trying to delete service %s in namespace %s:%s\n", s.Metadata.Namespace, s.Metadata.Name, string(kubectlOutput))
 			continue

test/e2e/kubernetes/util/util.go

@@ -17,12 +17,18 @@ func PrintCommand(cmd *exec.Cmd) {
 }
 
 // RunAndLogCommand logs the command with a timestamp when it's run, and the duration at end
-func RunAndLogCommand(cmd *exec.Cmd) ([]byte, error) {
+func RunAndLogCommand(cmd *exec.Cmd, timeout time.Duration) ([]byte, error) {
+	var err error
+	var out []byte
 	cmdLine := fmt.Sprintf("$ %s", strings.Join(cmd.Args, " "))
 	start := time.Now()
 	log.Printf("%s", cmdLine)
-	out, err := cmd.CombinedOutput()
+	out, err = cmd.CombinedOutput()
 	end := time.Now()
+	total := time.Since(start)
 	log.Printf("#### %s completed in %s", cmdLine, end.Sub(start).String())
+	if total.Seconds() > timeout.Seconds() {
+		err = fmt.Errorf(fmt.Sprintf("%s took too long!", cmdLine))
+	}
 	return out, err
 }