Merge pull request #20957 from openshift-cherrypick-robot/cherry-pick-20944-to-release-3.11

[release-3.11] Add more logging to deployment tests and waiting for tests to set up

Author: openshift-merge-robot

test/extended/deployments/deployments.go

@@ -318,28 +318,36 @@ var _ = g.Describe("[Feature:DeploymentConfig] deploymentconfigs", func() {
 		})
 
 		g.It("should run a deployment to completion and then scale to zero", func() {
-			dc, err := createDeploymentConfig(oc, deploymentFixture)
+			namespace := oc.Namespace()
+
+			dc, err := readDCFixture(deploymentFixture)
+			o.Expect(err).NotTo(o.HaveOccurred())
+			o.Expect(dc.Name).To(o.Equal(dcName))
+
+			dc, err = oc.AppsClient().AppsV1().DeploymentConfigs(namespace).Create(dc)
 			o.Expect(err).NotTo(o.HaveOccurred())
 			o.Expect(dc.Name).To(o.Equal(dcName))
+			e2e.Logf("created DC, creationTimestamp: %v", dc.CreationTimestamp)
 
 			o.Expect(waitForLatestCondition(oc, "deployment-test", deploymentRunTimeout, deploymentRunning)).NotTo(o.HaveOccurred())
 
 			out, err := oc.Run("logs").Args("-f", "dc/deployment-test").Output()
 			o.Expect(err).NotTo(o.HaveOccurred())
+			e2e.Logf("oc logs finished")
 
-			g.By("verifying the deployment is marked complete and scaled to zero")
+			e2e.Logf("verifying the deployment is marked complete and scaled to zero")
 			o.Expect(waitForLatestCondition(oc, "deployment-test", deploymentRunTimeout, deploymentReachedCompletion)).NotTo(o.HaveOccurred())
 
-			g.By(fmt.Sprintf("checking the logs for substrings\n%s", out))
+			e2e.Logf("checking the logs for substrings\n%s", out)
 			o.Expect(out).To(o.ContainSubstring("deployment-test-1 to 2"))
 			o.Expect(out).To(o.ContainSubstring("--> pre: Success"))
 			o.Expect(out).To(o.ContainSubstring("--> Success"))
 
-			g.By("verifying that scaling does not result in new pods")
+			e2e.Logf("verifying that scaling does not result in new pods")
 			out, err = oc.Run("scale").Args("dc/deployment-test", "--replicas=1").Output()
 			o.Expect(err).NotTo(o.HaveOccurred())
 
-			g.By("ensuring no scale up of the deployment happens")
+			e2e.Logf("ensuring no scale up of the deployment happens")
 			wait.PollImmediate(100*time.Millisecond, 10*time.Second, func() (bool, error) {
 				rc, err := oc.KubeClient().CoreV1().ReplicationControllers(oc.Namespace()).Get("deployment-test-1", metav1.GetOptions{})
 				o.Expect(err).NotTo(o.HaveOccurred())
@@ -348,13 +356,13 @@ var _ = g.Describe("[Feature:DeploymentConfig] deploymentconfigs", func() {
 				return false, nil
 			})
 
-			g.By("verifying the scale is updated on the deployment config")
+			e2e.Logf("verifying the scale is updated on the deployment config")
 			config, err := oc.AppsClient().AppsV1().DeploymentConfigs(oc.Namespace()).Get("deployment-test", metav1.GetOptions{})
 			o.Expect(err).NotTo(o.HaveOccurred())
 			o.Expect(config.Spec.Replicas).Should(o.BeEquivalentTo(1))
 			o.Expect(config.Spec.Test).Should(o.BeTrue())
 
-			g.By("deploying a few more times")
+			e2e.Logf("deploying a few more times")
 			for i := 0; i < 3; i++ {
 				rolloutCompleteWithLogs := make(chan struct{})
 				out := ""
@@ -371,12 +379,12 @@ var _ = g.Describe("[Feature:DeploymentConfig] deploymentconfigs", func() {
 				// deployer container runs.
 				_, err := oc.Run("rollout").Args("latest", "deployment-test").Output()
 				o.Expect(err).NotTo(o.HaveOccurred())
-				g.By(fmt.Sprintf("waiting for the rollout #%d to finish", i+2))
+				e2e.Logf("waiting for the rollout #%d to finish", i+2)
 				<-rolloutCompleteWithLogs
 				o.Expect(out).NotTo(o.BeEmpty())
 				o.Expect(waitForLatestCondition(oc, "deployment-test", deploymentRunTimeout, deploymentReachedCompletion)).NotTo(o.HaveOccurred())
 
-				g.By(fmt.Sprintf("checking the logs for substrings\n%s", out))
+				e2e.Logf("checking the logs for substrings\n%s", out)
 				o.Expect(out).To(o.ContainSubstring(fmt.Sprintf("deployment-test-%d up to 1", i+2)))
 				o.Expect(out).To(o.ContainSubstring("--> pre: Success"))
 				o.Expect(out).To(o.ContainSubstring("test pre hook executed"))
@@ -575,19 +583,27 @@ var _ = g.Describe("[Feature:DeploymentConfig] deploymentconfigs", func() {
 		})
 
 		g.It("should run the custom deployment steps", func() {
-			dc, err := createDeploymentConfig(oc, customDeploymentFixture)
+			namespace := oc.Namespace()
+
+			dc, err := readDCFixture(customDeploymentFixture)
 			o.Expect(err).NotTo(o.HaveOccurred())
 			o.Expect(dc.Name).To(o.Equal(dcName))
 
+			dc, err = oc.AppsClient().AppsV1().DeploymentConfigs(namespace).Create(dc)
+			o.Expect(err).NotTo(o.HaveOccurred())
+			o.Expect(dc.Name).To(o.Equal(dcName))
+			e2e.Logf("created DC, creationTimestamp: %v", dc.CreationTimestamp)
+
 			o.Expect(waitForLatestCondition(oc, dcName, deploymentRunTimeout, deploymentRunning)).NotTo(o.HaveOccurred())
 
 			out, err := oc.Run("logs").Args("--follow", "dc/custom-deployment").Output()
 			o.Expect(err).NotTo(o.HaveOccurred())
+			e2e.Logf("oc logs finished")
 
-			g.By("verifying the deployment is marked complete")
+			e2e.Logf("verifying the deployment is marked complete")
 			o.Expect(waitForLatestCondition(oc, "custom-deployment", deploymentRunTimeout, deploymentReachedCompletion)).NotTo(o.HaveOccurred())
 
-			g.By(fmt.Sprintf("checking the logs for substrings\n%s", out))
+			e2e.Logf("checking the logs for substrings\n%s", out)
 			o.Expect(out).To(o.ContainSubstring("--> pre: Running hook pod ..."))
 			o.Expect(out).To(o.ContainSubstring("test pre hook executed"))
 			o.Expect(out).To(o.ContainSubstring("--> Scaling custom-deployment-1 to 2"))

test/extended/deployments/util.go

@@ -214,6 +214,10 @@ func deploymentReachedCompletion(dc *appsv1.DeploymentConfig, rcs []*corev1.Repl
 		return false, nil
 	}
 
+	if appsutil.IsFailedDeployment(rc) {
+		return true, fmt.Errorf("deployment %s/%s failed", rc.Namespace, rc.Name)
+	}
+
 	if !appsutil.IsCompleteDeployment(rc) {
 		return false, nil
 	}
@@ -278,8 +282,11 @@ func deploymentRunning(dc *appsv1.DeploymentConfig, rcs []*corev1.ReplicationCon
 			return true, nil
 		}
 		return false, fmt.Errorf("deployment failed: %v", appsutil.DeploymentStatusReasonFor(rc))
+
 	case appsv1.DeploymentStatusRunning, appsv1.DeploymentStatusComplete:
+		e2e.Logf("deployment %s/%s reached state %q", rc.Namespace, rc.Name, status)
 		return true, nil
+
 	default:
 		return false, nil
 	}

test/extended/testdata/bindata.go

@@ -22,11 +22,11 @@ spec:
       - -c
       - |
         set -e
+        sleep 15  # give tests time to set up
         openshift-deploy --until=50%
         echo Halfway
         openshift-deploy
         echo Finished
-        sleep 1
   template:
     metadata:
       labels:

test/extended/testdata/deployments/custom-deployment.yaml

@@ -16,7 +16,9 @@ spec:
           command:
           - /bin/bash
           - -c
-          - "echo 'test pre hook executed' && sleep 15"
+          - |
+            sleep 15  # give tests time to setup
+            echo 'test pre hook executed'
   template:
     metadata:
       labels: