mirror of
https://github.com/k3s-io/kubernetes.git
synced 2025-07-22 19:31:44 +00:00
Merge pull request #53903 from vmware/e2e-vsphere-volume-stress-merge
Automatic merge from submit-queue. If you want to cherry-pick this change to another branch, please follow the instructions <a href="https://github.com/kubernetes/community/blob/master/contributors/devel/cherry-picks.md">here</a>. E2E stress test for vSphere Cloud Provider Volume lifecycle operations **What this PR does / why we need it**: This PR adds an E2E test for vSphere Cloud Provider which can induce the stress to attach/detach/delete the volumes in parallel with multiple threads based on user configurable values for number of threads and iterations per thread. Test performs following tasks. - Create Storage Classes of 4 Categories (Default, SC with Non Default Datastore, SC with SPBM Policy, SC with VSAN Storage Capalibilies.) - Read VCP_STRESS_INSTANCES and VCP_STRESS_ITERATIONS from System Environment. - Launch goroutine for volume lifecycle operations. - Each instance of routine iterates for n times, where n is read from system env - VCP_STRESS_ITERATIONS - Each iteration creates 1 PVC, 1 POD using the provisioned PV, Verify disk is attached to the node, Verify pod can access the volume, delete the pod and finally delete the PVC. **Which issue this PR fixes** fixes # https://github.com/vmware/kubernetes/issues/297 **Special notes for your reviewer**: Test Logs ``` # export VSPHERE_SPBM_POLICY_NAME=gold # export VSPHERE_DATASTORE=vsanDatastore # export VCP_STRESS_INSTANCES=5 # export VCP_STRESS_ITERATIONS=2 # go run hack/e2e.go --check-version-skew=false -v -test '--test_args=--ginkgo.focus=vsphere\sstress\stests' flag provided but not defined: -check-version-skew Usage of /tmp/go-build278564968/command-line-arguments/_obj/exe/e2e: -get go get -u kubetest if old or not installed (default true) -old duration Consider kubetest old if it exceeds this (default 24h0m0s) 2017/10/09 17:50:58 e2e.go:55: NOTICE: go run hack/e2e.go is now a shim for test-infra/kubetest 2017/10/09 17:50:58 e2e.go:56: Usage: go run hack/e2e.go [--get=true] [--old=24h0m0s] -- [KUBETEST_ARGS] 2017/10/09 17:50:58 e2e.go:57: The separator is required to use --get or --old flags 2017/10/09 17:50:58 e2e.go:58: The -- flag separator also suppresses this message 2017/10/09 17:50:58 e2e.go:77: Calling kubetest --check-version-skew=false -v -test --test_args=--ginkgo.focus=vsphere\sstress\stests... 2017/10/09 17:50:58 util.go:154: Running: ./cluster/kubectl.sh --match-server-version=false version 2017/10/09 17:50:59 util.go:156: Step './cluster/kubectl.sh --match-server-version=false version' finished in 368.788119ms 2017/10/09 17:50:59 util.go:154: Running: ./hack/e2e-internal/e2e-status.sh Skeleton Provider: prepare-e2e not implemented Client Version: version.Info{Major:"1", Minor:"6+", GitVersion:"v1.6.0-alpha.0.16775+93408b3d08957e", GitCommit:"93408b3d08957ea52f587dadbe06850af860ab71", GitTreeState:"clean", BuildDate:"2017-10-10T00:41:24Z", GoVersion:"go1.8.3", Compiler:"gc", Platform:"linux/amd64"} Server Version: version.Info{Major:"1", Minor:"9+", GitVersion:"v1.9.0-alpha.1.838+9782a5a0a9c351", GitCommit:"9782a5a0a9c3517c5dc35e7826dfcab963cf3d9c", GitTreeState:"clean", BuildDate:"2017-10-09T07:15:02Z", GoVersion:"go1.8.3", Compiler:"gc", Platform:"linux/amd64"} 2017/10/09 17:50:59 util.go:156: Step './hack/e2e-internal/e2e-status.sh' finished in 304.191318ms 2017/10/09 17:50:59 util.go:154: Running: ./hack/ginkgo-e2e.sh --ginkgo.focus=vsphere\sstress\stests Conformance test: not doing test setup. Oct 9 17:51:01.086: INFO: Overriding default scale value of zero to 1 Oct 9 17:51:01.086: INFO: Overriding default milliseconds value of zero to 5000 I1009 17:51:01.327180 15282 e2e.go:369] Starting e2e run "15d29041-ad55-11e7-9400-0050569c26b8" on Ginkgo node 1 Running Suite: Kubernetes e2e suite =================================== Random Seed: 1507596660 - Will randomize all specs Will run 1 of 701 specs Oct 9 17:51:01.370: INFO: >>> kubeConfig: /root/.kube/config Oct 9 17:51:01.377: INFO: Waiting up to 4h0m0s for all (but 0) nodes to be schedulable Oct 9 17:51:01.413: INFO: Waiting up to 10m0s for all pods (need at least 0) in namespace 'kube-system' to be running and ready Oct 9 17:51:01.543: INFO: 13 / 13 pods in namespace 'kube-system' are running and ready (0 seconds elapsed) Oct 9 17:51:01.543: INFO: expected 4 pod replicas in namespace 'kube-system', 4 are Running and Ready. Oct 9 17:51:01.547: INFO: Waiting for pods to enter Success, but no pods in "kube-system" match label map[name:e2e-image-puller] Oct 9 17:51:01.548: INFO: Dumping network health container logs from all nodes... SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS ------------------------------ [sig-storage] vsphere cloud provider stress [Feature:vsphere] vsphere stress tests /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/vsphere_stress.go:125 [BeforeEach] [sig-storage] vsphere cloud provider stress [Feature:vsphere] /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:133 STEP: Creating a kubernetes client Oct 9 17:51:01.557: INFO: >>> kubeConfig: /root/.kube/config STEP: Building a namespace api object STEP: Waiting for a default service account to be provisioned in namespace [BeforeEach] [sig-storage] vsphere cloud provider stress [Feature:vsphere] /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/vsphere_stress.go:72 [It] vsphere stress tests /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/vsphere_stress.go:125 STEP: Creating Storage Class : sc-default STEP: Creating Storage Class : sc-vsan STEP: Creating Storage Class : sc-spbm STEP: Creating Storage Class : sc-user-specified-ds STEP: Instance: [Thread:1], Iteration: [1] : Creating PVC using the Storage Class: sc-default STEP: Instance: [Thread:1], Iteration: [1] : Waiting for claim: pvc-rhvzf to be in bound phase Oct 9 17:51:01.895: INFO: Waiting up to 5m0s for PersistentVolumeClaim pvc-rhvzf to have phase Bound STEP: Instance: [Thread:2], Iteration: [1] : Creating PVC using the Storage Class: sc-vsan Oct 9 17:51:01.899: INFO: PersistentVolumeClaim pvc-rhvzf found but phase is Pending instead of Bound. STEP: Instance: [Thread:3], Iteration: [1] : Creating PVC using the Storage Class: sc-spbm STEP: Instance: [Thread:2], Iteration: [1] : Waiting for claim: pvc-zvs8j to be in bound phase Oct 9 17:51:01.915: INFO: Waiting up to 5m0s for PersistentVolumeClaim pvc-zvs8j to have phase Bound STEP: Instance: [Thread:3], Iteration: [1] : Waiting for claim: pvc-2xqld to be in bound phase Oct 9 17:51:01.916: INFO: Waiting up to 5m0s for PersistentVolumeClaim pvc-2xqld to have phase Bound Oct 9 17:51:01.921: INFO: PersistentVolumeClaim pvc-2xqld found but phase is Pending instead of Bound. Oct 9 17:51:01.921: INFO: PersistentVolumeClaim pvc-zvs8j found but phase is Pending instead of Bound. STEP: Instance: [Thread:5], Iteration: [1] : Creating PVC using the Storage Class: sc-default STEP: Instance: [Thread:4], Iteration: [1] : Creating PVC using the Storage Class: sc-user-specified-ds STEP: Instance: [Thread:5], Iteration: [1] : Waiting for claim: pvc-5m5qz to be in bound phase Oct 9 17:51:01.940: INFO: Waiting up to 5m0s for PersistentVolumeClaim pvc-5m5qz to have phase Bound STEP: Instance: [Thread:4], Iteration: [1] : Waiting for claim: pvc-jwhb7 to be in bound phase Oct 9 17:51:01.949: INFO: Waiting up to 5m0s for PersistentVolumeClaim pvc-jwhb7 to have phase Bound Oct 9 17:51:01.949: INFO: PersistentVolumeClaim pvc-5m5qz found but phase is Pending instead of Bound. Oct 9 17:51:01.958: INFO: PersistentVolumeClaim pvc-jwhb7 found but phase is Pending instead of Bound. Oct 9 17:51:03.905: INFO: PersistentVolumeClaim pvc-rhvzf found but phase is Pending instead of Bound. Oct 9 17:51:03.925: INFO: PersistentVolumeClaim pvc-2xqld found but phase is Pending instead of Bound. Oct 9 17:51:03.926: INFO: PersistentVolumeClaim pvc-zvs8j found but phase is Pending instead of Bound. Oct 9 17:51:03.955: INFO: PersistentVolumeClaim pvc-5m5qz found but phase is Pending instead of Bound. Oct 9 17:51:03.964: INFO: PersistentVolumeClaim pvc-jwhb7 found and phase=Bound (2.014321484s) STEP: Instance: [Thread:4], Iteration: [1] : Creating Pod using the claim: pvc-jwhb7 Oct 9 17:51:05.910: INFO: PersistentVolumeClaim pvc-rhvzf found but phase is Pending instead of Bound. Oct 9 17:51:05.930: INFO: PersistentVolumeClaim pvc-2xqld found but phase is Pending instead of Bound. Oct 9 17:51:05.930: INFO: PersistentVolumeClaim pvc-zvs8j found but phase is Pending instead of Bound. Oct 9 17:51:05.960: INFO: PersistentVolumeClaim pvc-5m5qz found but phase is Pending instead of Bound. Oct 9 17:51:07.915: INFO: PersistentVolumeClaim pvc-rhvzf found and phase=Bound (6.020575276s) STEP: Instance: [Thread:1], Iteration: [1] : Creating Pod using the claim: pvc-rhvzf Oct 9 17:51:07.934: INFO: PersistentVolumeClaim pvc-2xqld found but phase is Pending instead of Bound. Oct 9 17:51:07.936: INFO: PersistentVolumeClaim pvc-zvs8j found but phase is Pending instead of Bound. Oct 9 17:51:07.968: INFO: PersistentVolumeClaim pvc-5m5qz found and phase=Bound (6.027676262s) STEP: Instance: [Thread:5], Iteration: [1] : Creating Pod using the claim: pvc-5m5qz Oct 9 17:51:09.940: INFO: PersistentVolumeClaim pvc-zvs8j found but phase is Pending instead of Bound. Oct 9 17:51:09.940: INFO: PersistentVolumeClaim pvc-2xqld found but phase is Pending instead of Bound. Oct 9 17:51:11.945: INFO: PersistentVolumeClaim pvc-2xqld found but phase is Pending instead of Bound. Oct 9 17:51:11.946: INFO: PersistentVolumeClaim pvc-zvs8j found but phase is Pending instead of Bound. Oct 9 17:51:13.950: INFO: PersistentVolumeClaim pvc-2xqld found but phase is Pending instead of Bound. Oct 9 17:51:13.951: INFO: PersistentVolumeClaim pvc-zvs8j found but phase is Pending instead of Bound. Oct 9 17:51:15.954: INFO: PersistentVolumeClaim pvc-zvs8j found but phase is Pending instead of Bound. Oct 9 17:51:15.954: INFO: PersistentVolumeClaim pvc-2xqld found but phase is Pending instead of Bound. STEP: Instance: [Thread:4], Iteration: [1] : Waiting for the Pod: pvc-tester-rptwh to be in the running state STEP: Instance: [Thread:4], Iteration: [1] : Verifing the volume: [vsanDatastore] 1874c359-f300-a0cc-fd7e-02002a623c85/kubernetes-dynamic-pvc-16804ea2-ad55-11e7-a775-0050569cce2c.vmdk is attached to the node VM: kubernetes-node1 STEP: Instance: [Thread:4], Iteration: [1] : Verifing the volume: [vsanDatastore] 1874c359-f300-a0cc-fd7e-02002a623c85/kubernetes-dynamic-pvc-16804ea2-ad55-11e7-a775-0050569cce2c.vmdk is accessible in the pod: pvc-tester-rptwh STEP: Verify the volume is accessible and available in the pod Oct 9 17:51:16.262: INFO: Running '/root/divyenp/kubernetes/_output/dockerized/bin/linux/amd64/kubectl --server=https://10.192.57.171 --kubeconfig=/root/.kube/config exec pvc-tester-rptwh --namespace=e2e-tests-vcp-stress-dxrkx -- /bin/touch /mnt/volume1/emptyFile.txt' Oct 9 17:51:16.752: INFO: stderr: "" Oct 9 17:51:16.752: INFO: stdout: "" STEP: Instance: [Thread:4], Iteration: [1] : Deleting pod: pvc-tester-rptwh Oct 9 17:51:16.752: INFO: Deleting pod pvc-tester-rptwh Oct 9 17:51:16.761: INFO: Waiting up to 5m0s for pod "pvc-tester-rptwh" in namespace "e2e-tests-vcp-stress-dxrkx" to be "terminated due to deadline exceeded" Oct 9 17:51:16.768: INFO: Pod "pvc-tester-rptwh": Phase="Running", Reason="", readiness=true. Elapsed: 6.93674ms STEP: Instance: [Thread:1], Iteration: [1] : Waiting for the Pod: pvc-tester-4mj7m to be in the running state STEP: Instance: [Thread:1], Iteration: [1] : Verifing the volume: [vsanDatastore] 1874c359-f300-a0cc-fd7e-02002a623c85/kubernetes-dynamic-pvc-1678c1b4-ad55-11e7-a775-0050569cce2c.vmdk is attached to the node VM: kubernetes-node3 Oct 9 17:51:17.961: INFO: PersistentVolumeClaim pvc-2xqld found but phase is Pending instead of Bound. Oct 9 17:51:17.961: INFO: PersistentVolumeClaim pvc-zvs8j found and phase=Bound (16.046192588s) STEP: Instance: [Thread:2], Iteration: [1] : Creating Pod using the claim: pvc-zvs8j STEP: Instance: [Thread:1], Iteration: [1] : Verifing the volume: [vsanDatastore] 1874c359-f300-a0cc-fd7e-02002a623c85/kubernetes-dynamic-pvc-1678c1b4-ad55-11e7-a775-0050569cce2c.vmdk is accessible in the pod: pvc-tester-4mj7m STEP: Verify the volume is accessible and available in the pod Oct 9 17:51:18.208: INFO: Running '/root/divyenp/kubernetes/_output/dockerized/bin/linux/amd64/kubectl --server=https://10.192.57.171 --kubeconfig=/root/.kube/config exec pvc-tester-4mj7m --namespace=e2e-tests-vcp-stress-dxrkx -- /bin/touch /mnt/volume1/emptyFile.txt' Oct 9 17:51:18.794: INFO: Pod "pvc-tester-rptwh": Phase="Running", Reason="", readiness=true. Elapsed: 2.033071649s Oct 9 17:51:18.999: INFO: stderr: "" Oct 9 17:51:18.999: INFO: stdout: "" STEP: Instance: [Thread:1], Iteration: [1] : Deleting pod: pvc-tester-4mj7m Oct 9 17:51:18.999: INFO: Deleting pod pvc-tester-4mj7m Oct 9 17:51:19.047: INFO: Waiting up to 5m0s for pod "pvc-tester-4mj7m" in namespace "e2e-tests-vcp-stress-dxrkx" to be "terminated due to deadline exceeded" Oct 9 17:51:19.060: INFO: Pod "pvc-tester-4mj7m": Phase="Running", Reason="", readiness=true. Elapsed: 13.3838ms Oct 9 17:51:19.968: INFO: PersistentVolumeClaim pvc-2xqld found and phase=Bound (18.051615752s) STEP: Instance: [Thread:3], Iteration: [1] : Creating Pod using the claim: pvc-2xqld Oct 9 17:51:20.801: INFO: Pod "pvc-tester-rptwh": Phase="Running", Reason="", readiness=true. Elapsed: 4.03982234s Oct 9 17:51:21.065: INFO: Pod "pvc-tester-4mj7m": Phase="Running", Reason="", readiness=true. Elapsed: 2.018156624s Oct 9 17:51:22.807: INFO: Pod "pvc-tester-rptwh": Phase="Running", Reason="", readiness=true. Elapsed: 6.045445351s Oct 9 17:51:23.069: INFO: Pod "pvc-tester-4mj7m": Phase="Running", Reason="", readiness=true. Elapsed: 4.022426785s Oct 9 17:51:24.812: INFO: Pod "pvc-tester-rptwh": Phase="Running", Reason="", readiness=true. Elapsed: 8.051188597s Oct 9 17:51:25.073: INFO: Pod "pvc-tester-4mj7m": Phase="Running", Reason="", readiness=true. Elapsed: 6.026287211s STEP: Instance: [Thread:5], Iteration: [1] : Waiting for the Pod: pvc-tester-chzs7 to be in the running state STEP: Instance: [Thread:5], Iteration: [1] : Verifing the volume: [vsanDatastore] 1874c359-f300-a0cc-fd7e-02002a623c85/kubernetes-dynamic-pvc-168008a1-ad55-11e7-a775-0050569cce2c.vmdk is attached to the node VM: kubernetes-node2 STEP: Instance: [Thread:5], Iteration: [1] : Verifing the volume: [vsanDatastore] 1874c359-f300-a0cc-fd7e-02002a623c85/kubernetes-dynamic-pvc-168008a1-ad55-11e7-a775-0050569cce2c.vmdk is accessible in the pod: pvc-tester-chzs7 STEP: Verify the volume is accessible and available in the pod Oct 9 17:51:26.238: INFO: Running '/root/divyenp/kubernetes/_output/dockerized/bin/linux/amd64/kubectl --server=https://10.192.57.171 --kubeconfig=/root/.kube/config exec pvc-tester-chzs7 --namespace=e2e-tests-vcp-stress-dxrkx -- /bin/touch /mnt/volume1/emptyFile.txt' Oct 9 17:51:26.734: INFO: stderr: "" Oct 9 17:51:26.734: INFO: stdout: "" STEP: Instance: [Thread:5], Iteration: [1] : Deleting pod: pvc-tester-chzs7 Oct 9 17:51:26.734: INFO: Deleting pod pvc-tester-chzs7 Oct 9 17:51:26.746: INFO: Waiting up to 5m0s for pod "pvc-tester-chzs7" in namespace "e2e-tests-vcp-stress-dxrkx" to be "terminated due to deadline exceeded" Oct 9 17:51:26.756: INFO: Pod "pvc-tester-chzs7": Phase="Running", Reason="", readiness=true. Elapsed: 9.035165ms Oct 9 17:51:26.819: INFO: Pod "pvc-tester-rptwh": Phase="Running", Reason="", readiness=true. Elapsed: 10.058217873s Oct 9 17:51:27.080: INFO: Pod "pvc-tester-4mj7m": Phase="Running", Reason="", readiness=true. Elapsed: 8.033449133s Oct 9 17:51:28.761: INFO: Pod "pvc-tester-chzs7": Phase="Running", Reason="", readiness=true. Elapsed: 2.014968719s Oct 9 17:51:28.825: INFO: Pod "pvc-tester-rptwh": Phase="Running", Reason="", readiness=true. Elapsed: 12.063793421s Oct 9 17:51:29.088: INFO: Pod "pvc-tester-4mj7m": Phase="Running", Reason="", readiness=true. Elapsed: 10.041667217s Oct 9 17:51:30.767: INFO: Pod "pvc-tester-chzs7": Phase="Running", Reason="", readiness=true. Elapsed: 4.020329766s Oct 9 17:51:30.832: INFO: Pod "pvc-tester-rptwh": Phase="Running", Reason="", readiness=true. Elapsed: 14.070674886s Oct 9 17:51:31.096: INFO: Pod "pvc-tester-4mj7m": Phase="Running", Reason="", readiness=true. Elapsed: 12.049489254s Oct 9 17:51:32.772: INFO: Pod "pvc-tester-chzs7": Phase="Running", Reason="", readiness=true. Elapsed: 6.025647318s Oct 9 17:51:32.838: INFO: Pod "pvc-tester-rptwh": Phase="Running", Reason="", readiness=true. Elapsed: 16.076326935s Oct 9 17:51:33.103: INFO: Pod "pvc-tester-4mj7m": Phase="Running", Reason="", readiness=true. Elapsed: 14.056365138s Oct 9 17:51:34.779: INFO: Pod "pvc-tester-chzs7": Phase="Running", Reason="", readiness=true. Elapsed: 8.032771596s Oct 9 17:51:34.844: INFO: Pod "pvc-tester-rptwh": Phase="Running", Reason="", readiness=true. Elapsed: 18.08248384s Oct 9 17:51:35.113: INFO: Pod "pvc-tester-4mj7m": Phase="Running", Reason="", readiness=true. Elapsed: 16.066547959s STEP: Instance: [Thread:2], Iteration: [1] : Waiting for the Pod: pvc-tester-dc5wn to be in the running state STEP: Instance: [Thread:2], Iteration: [1] : Verifing the volume: [vsanDatastore] 1874c359-f300-a0cc-fd7e-02002a623c85/kubernetes-dynamic-pvc-167a93ac-ad55-11e7-a775-0050569cce2c.vmdk is attached to the node VM: kubernetes-node4 STEP: Instance: [Thread:2], Iteration: [1] : Verifing the volume: [vsanDatastore] 1874c359-f300-a0cc-fd7e-02002a623c85/kubernetes-dynamic-pvc-167a93ac-ad55-11e7-a775-0050569cce2c.vmdk is accessible in the pod: pvc-tester-dc5wn STEP: Verify the volume is accessible and available in the pod Oct 9 17:51:36.251: INFO: Running '/root/divyenp/kubernetes/_output/dockerized/bin/linux/amd64/kubectl --server=https://10.192.57.171 --kubeconfig=/root/.kube/config exec pvc-tester-dc5wn --namespace=e2e-tests-vcp-stress-dxrkx -- /bin/touch /mnt/volume1/emptyFile.txt' Oct 9 17:51:36.748: INFO: stderr: "" Oct 9 17:51:36.748: INFO: stdout: "" STEP: Instance: [Thread:2], Iteration: [1] : Deleting pod: pvc-tester-dc5wn Oct 9 17:51:36.748: INFO: Deleting pod pvc-tester-dc5wn Oct 9 17:51:36.763: INFO: Waiting up to 5m0s for pod "pvc-tester-dc5wn" in namespace "e2e-tests-vcp-stress-dxrkx" to be "terminated due to deadline exceeded" Oct 9 17:51:36.768: INFO: Pod "pvc-tester-dc5wn": Phase="Running", Reason="", readiness=true. Elapsed: 5.263893ms Oct 9 17:51:36.784: INFO: Pod "pvc-tester-chzs7": Phase="Running", Reason="", readiness=true. Elapsed: 10.03756344s Oct 9 17:51:36.850: INFO: Pod "pvc-tester-rptwh": Phase="Running", Reason="", readiness=true. Elapsed: 20.088344736s Oct 9 17:51:37.124: INFO: Pod "pvc-tester-4mj7m": Phase="Running", Reason="", readiness=true. Elapsed: 18.077434044s Oct 9 17:51:38.782: INFO: Pod "pvc-tester-dc5wn": Phase="Running", Reason="", readiness=true. Elapsed: 2.019746606s Oct 9 17:51:38.801: INFO: Pod "pvc-tester-chzs7": Phase="Running", Reason="", readiness=true. Elapsed: 12.054521268s Oct 9 17:51:38.865: INFO: Pod "pvc-tester-rptwh": Phase="Running", Reason="", readiness=true. Elapsed: 22.103792805s Oct 9 17:51:39.140: INFO: Pod "pvc-tester-4mj7m": Phase="Running", Reason="", readiness=true. Elapsed: 20.093429568s Oct 9 17:51:40.790: INFO: Pod "pvc-tester-dc5wn": Phase="Running", Reason="", readiness=true. Elapsed: 4.027097108s Oct 9 17:51:40.806: INFO: Pod "pvc-tester-chzs7": Phase="Running", Reason="", readiness=true. Elapsed: 14.059417058s Oct 9 17:51:40.872: INFO: Pod "pvc-tester-rptwh": Phase="Running", Reason="", readiness=true. Elapsed: 24.110446949s Oct 9 17:51:41.146: INFO: Pod "pvc-tester-4mj7m": Phase="Running", Reason="", readiness=true. Elapsed: 22.099044249s Oct 9 17:51:42.795: INFO: Pod "pvc-tester-dc5wn": Phase="Running", Reason="", readiness=true. Elapsed: 6.03264245s Oct 9 17:51:42.811: INFO: Pod "pvc-tester-chzs7": Phase="Running", Reason="", readiness=true. Elapsed: 16.064140339s Oct 9 17:51:42.877: INFO: Pod "pvc-tester-rptwh": Phase="Running", Reason="", readiness=true. Elapsed: 26.116020085s Oct 9 17:51:43.150: INFO: Pod "pvc-tester-4mj7m": Phase="Running", Reason="", readiness=true. Elapsed: 24.103779148s Oct 9 17:51:44.801: INFO: Pod "pvc-tester-dc5wn": Phase="Running", Reason="", readiness=true. Elapsed: 8.03865792s Oct 9 17:51:44.819: INFO: Pod "pvc-tester-chzs7": Phase="Running", Reason="", readiness=true. Elapsed: 18.072869647s Oct 9 17:51:44.886: INFO: Pod "pvc-tester-rptwh": Phase="Running", Reason="", readiness=true. Elapsed: 28.124741033s Oct 9 17:51:45.158: INFO: Pod "pvc-tester-4mj7m": Phase="Running", Reason="", readiness=true. Elapsed: 26.111815212s STEP: Instance: [Thread:3], Iteration: [1] : Waiting for the Pod: pvc-tester-jxm6s to be in the running state STEP: Instance: [Thread:3], Iteration: [1] : Verifing the volume: [vsanDatastore] 1874c359-f300-a0cc-fd7e-02002a623c85/kubernetes-dynamic-pvc-167ab992-ad55-11e7-a775-0050569cce2c.vmdk is attached to the node VM: kubernetes-node3 STEP: Instance: [Thread:3], Iteration: [1] : Verifing the volume: [vsanDatastore] 1874c359-f300-a0cc-fd7e-02002a623c85/kubernetes-dynamic-pvc-167ab992-ad55-11e7-a775-0050569cce2c.vmdk is accessible in the pod: pvc-tester-jxm6s STEP: Verify the volume is accessible and available in the pod Oct 9 17:51:46.256: INFO: Running '/root/divyenp/kubernetes/_output/dockerized/bin/linux/amd64/kubectl --server=https://10.192.57.171 --kubeconfig=/root/.kube/config exec pvc-tester-jxm6s --namespace=e2e-tests-vcp-stress-dxrkx -- /bin/touch /mnt/volume1/emptyFile.txt' Oct 9 17:51:46.731: INFO: stderr: "" Oct 9 17:51:46.731: INFO: stdout: "" STEP: Instance: [Thread:3], Iteration: [1] : Deleting pod: pvc-tester-jxm6s Oct 9 17:51:46.731: INFO: Deleting pod pvc-tester-jxm6s Oct 9 17:51:46.740: INFO: Waiting up to 5m0s for pod "pvc-tester-jxm6s" in namespace "e2e-tests-vcp-stress-dxrkx" to be "terminated due to deadline exceeded" Oct 9 17:51:46.746: INFO: Pod "pvc-tester-jxm6s": Phase="Running", Reason="", readiness=true. Elapsed: 5.407006ms Oct 9 17:51:46.807: INFO: Pod "pvc-tester-dc5wn": Phase="Running", Reason="", readiness=true. Elapsed: 10.044451733s Oct 9 17:51:46.825: INFO: Pod "pvc-tester-chzs7": Phase="Running", Reason="", readiness=true. Elapsed: 20.078324904s Oct 9 17:51:46.893: INFO: Pod "pvc-tester-rptwh": Phase="Running", Reason="", readiness=true. Elapsed: 30.131884236s Oct 9 17:51:47.164: INFO: Pod "pvc-tester-4mj7m": Phase="Running", Reason="", readiness=true. Elapsed: 28.117674803s Oct 9 17:51:48.750: INFO: Pod "pvc-tester-jxm6s": Phase="Running", Reason="", readiness=true. Elapsed: 2.009882128s Oct 9 17:51:48.814: INFO: Pod "pvc-tester-dc5wn": Phase="Running", Reason="", readiness=true. Elapsed: 12.051617489s Oct 9 17:51:48.830: INFO: Pod "pvc-tester-chzs7": Phase="Running", Reason="", readiness=true. Elapsed: 22.083337193s Oct 9 17:51:48.898: INFO: Pod "pvc-tester-rptwh": Phase="Pending", Reason="", readiness=false. Elapsed: 32.136342568s Oct 9 17:51:49.169: INFO: Pod "pvc-tester-4mj7m": Phase="Running", Reason="", readiness=true. Elapsed: 30.122615329s Oct 9 17:51:50.755: INFO: Pod "pvc-tester-jxm6s": Phase="Running", Reason="", readiness=true. Elapsed: 4.014480477s Oct 9 17:51:50.820: INFO: Pod "pvc-tester-dc5wn": Phase="Running", Reason="", readiness=true. Elapsed: 14.057147982s Oct 9 17:51:50.834: INFO: Pod "pvc-tester-chzs7": Phase="Running", Reason="", readiness=true. Elapsed: 24.087982363s Oct 9 17:51:50.904: INFO: Pod "pvc-tester-rptwh": Phase="Pending", Reason="", readiness=false. Elapsed: 34.14249379s Oct 9 17:51:51.174: INFO: Pod "pvc-tester-4mj7m": Phase="Running", Reason="", readiness=false. Elapsed: 32.127626877s Oct 9 17:51:52.761: INFO: Pod "pvc-tester-jxm6s": Phase="Running", Reason="", readiness=true. Elapsed: 6.020322527s Oct 9 17:51:52.824: INFO: Pod "pvc-tester-dc5wn": Phase="Running", Reason="", readiness=true. Elapsed: 16.061607637s Oct 9 17:51:52.838: INFO: Pod "pvc-tester-chzs7": Phase="Running", Reason="", readiness=true. Elapsed: 26.091831456s Oct 9 17:51:52.909: INFO: Pod "pvc-tester-rptwh": Phase="Pending", Reason="", readiness=false. Elapsed: 36.147366617s Oct 9 17:51:53.180: INFO: Pod "pvc-tester-4mj7m": Phase="Running", Reason="", readiness=false. Elapsed: 34.133796454s Oct 9 17:51:54.767: INFO: Pod "pvc-tester-jxm6s": Phase="Running", Reason="", readiness=true. Elapsed: 8.027058818s Oct 9 17:51:54.829: INFO: Pod "pvc-tester-dc5wn": Phase="Running", Reason="", readiness=true. Elapsed: 18.066035535s Oct 9 17:51:54.843: INFO: Pod "pvc-tester-chzs7": Phase="Running", Reason="", readiness=true. Elapsed: 28.096173077s Oct 9 17:51:54.914: INFO: Pod "pvc-tester-rptwh": Phase="Pending", Reason="", readiness=false. Elapsed: 38.152737429s Oct 9 17:51:55.185: INFO: Pod "pvc-tester-4mj7m" in namespace "e2e-tests-vcp-stress-dxrkx" not found. Error: pods "pvc-tester-4mj7m" not found Oct 9 17:51:55.185: INFO: Ignore "not found" error above. Pod "pvc-tester-4mj7m" successfully deleted STEP: Instance: [Thread:1], Iteration: [1] : Waiting for volume: [vsanDatastore] 1874c359-f300-a0cc-fd7e-02002a623c85/kubernetes-dynamic-pvc-1678c1b4-ad55-11e7-a775-0050569cce2c.vmdk to be detached from the node: kubernetes-node3 Oct 9 17:51:56.773: INFO: Pod "pvc-tester-jxm6s": Phase="Running", Reason="", readiness=true. Elapsed: 10.033072025s Oct 9 17:51:56.833: INFO: Pod "pvc-tester-dc5wn": Phase="Running", Reason="", readiness=true. Elapsed: 20.070428813s Oct 9 17:51:56.848: INFO: Pod "pvc-tester-chzs7": Phase="Running", Reason="", readiness=true. Elapsed: 30.101189782s Oct 9 17:51:56.918: INFO: Pod "pvc-tester-rptwh" in namespace "e2e-tests-vcp-stress-dxrkx" not found. Error: pods "pvc-tester-rptwh" not found Oct 9 17:51:56.918: INFO: Ignore "not found" error above. Pod "pvc-tester-rptwh" successfully deleted STEP: Instance: [Thread:4], Iteration: [1] : Waiting for volume: [vsanDatastore] 1874c359-f300-a0cc-fd7e-02002a623c85/kubernetes-dynamic-pvc-16804ea2-ad55-11e7-a775-0050569cce2c.vmdk to be detached from the node: kubernetes-node1 Oct 9 17:51:58.779: INFO: Pod "pvc-tester-jxm6s": Phase="Running", Reason="", readiness=true. Elapsed: 12.038949555s Oct 9 17:51:58.837: INFO: Pod "pvc-tester-dc5wn": Phase="Running", Reason="", readiness=true. Elapsed: 22.074708478s Oct 9 17:51:58.851: INFO: Pod "pvc-tester-chzs7": Phase="Pending", Reason="", readiness=false. Elapsed: 32.105057156s Oct 9 17:52:00.784: INFO: Pod "pvc-tester-jxm6s": Phase="Running", Reason="", readiness=true. Elapsed: 14.04412356s Oct 9 17:52:00.843: INFO: Pod "pvc-tester-dc5wn": Phase="Running", Reason="", readiness=true. Elapsed: 24.080562885s Oct 9 17:52:00.856: INFO: Pod "pvc-tester-chzs7": Phase="Pending", Reason="", readiness=false. Elapsed: 34.109805682s Oct 9 17:52:02.789: INFO: Pod "pvc-tester-jxm6s": Phase="Running", Reason="", readiness=true. Elapsed: 16.049148061s Oct 9 17:52:02.849: INFO: Pod "pvc-tester-dc5wn": Phase="Running", Reason="", readiness=true. Elapsed: 26.086231649s Oct 9 17:52:02.861: INFO: Pod "pvc-tester-chzs7" in namespace "e2e-tests-vcp-stress-dxrkx" not found. Error: pods "pvc-tester-chzs7" not found Oct 9 17:52:02.861: INFO: Ignore "not found" error above. Pod "pvc-tester-chzs7" successfully deleted STEP: Instance: [Thread:5], Iteration: [1] : Waiting for volume: [vsanDatastore] 1874c359-f300-a0cc-fd7e-02002a623c85/kubernetes-dynamic-pvc-168008a1-ad55-11e7-a775-0050569cce2c.vmdk to be detached from the node: kubernetes-node2 Oct 9 17:52:04.796: INFO: Pod "pvc-tester-jxm6s": Phase="Running", Reason="", readiness=true. Elapsed: 18.055356249s Oct 9 17:52:04.855: INFO: Pod "pvc-tester-dc5wn": Phase="Running", Reason="", readiness=true. Elapsed: 28.09190524s Oct 9 17:52:05.311: INFO: Volume "[vsanDatastore] 1874c359-f300-a0cc-fd7e-02002a623c85/kubernetes-dynamic-pvc-1678c1b4-ad55-11e7-a775-0050569cce2c.vmdk" appears to have successfully detached from "kubernetes-node3". STEP: Instance: [Thread:1], Iteration: [1] : Deleting the Claim: pvc-rhvzf Oct 9 17:52:05.311: INFO: Deleting PersistentVolumeClaim "pvc-rhvzf" STEP: Instance: [Thread:1], Iteration: [2] : Creating PVC using the Storage Class: sc-default STEP: Instance: [Thread:1], Iteration: [2] : Waiting for claim: pvc-62bqt to be in bound phase Oct 9 17:52:05.349: INFO: Waiting up to 5m0s for PersistentVolumeClaim pvc-62bqt to have phase Bound Oct 9 17:52:05.354: INFO: PersistentVolumeClaim pvc-62bqt found but phase is Pending instead of Bound. Oct 9 17:52:06.801: INFO: Pod "pvc-tester-jxm6s": Phase="Running", Reason="", readiness=true. Elapsed: 20.06083511s Oct 9 17:52:06.861: INFO: Pod "pvc-tester-dc5wn": Phase="Running", Reason="", readiness=true. Elapsed: 30.098390861s Oct 9 17:52:07.034: INFO: Volume "[vsanDatastore] 1874c359-f300-a0cc-fd7e-02002a623c85/kubernetes-dynamic-pvc-16804ea2-ad55-11e7-a775-0050569cce2c.vmdk" appears to have successfully detached from "kubernetes-node1". STEP: Instance: [Thread:4], Iteration: [1] : Deleting the Claim: pvc-jwhb7 Oct 9 17:52:07.034: INFO: Deleting PersistentVolumeClaim "pvc-jwhb7" STEP: Instance: [Thread:4], Iteration: [2] : Creating PVC using the Storage Class: sc-user-specified-ds STEP: Instance: [Thread:4], Iteration: [2] : Waiting for claim: pvc-dq5fv to be in bound phase Oct 9 17:52:07.062: INFO: Waiting up to 5m0s for PersistentVolumeClaim pvc-dq5fv to have phase Bound Oct 9 17:52:07.072: INFO: PersistentVolumeClaim pvc-dq5fv found but phase is Pending instead of Bound. Oct 9 17:52:07.358: INFO: PersistentVolumeClaim pvc-62bqt found and phase=Bound (2.008995823s) STEP: Instance: [Thread:1], Iteration: [2] : Creating Pod using the claim: pvc-62bqt Oct 9 17:52:08.807: INFO: Pod "pvc-tester-jxm6s": Phase="Running", Reason="", readiness=true. Elapsed: 22.066668316s Oct 9 17:52:08.866: INFO: Pod "pvc-tester-dc5wn" in namespace "e2e-tests-vcp-stress-dxrkx" not found. Error: pods "pvc-tester-dc5wn" not found Oct 9 17:52:08.866: INFO: Ignore "not found" error above. Pod "pvc-tester-dc5wn" successfully deleted STEP: Instance: [Thread:2], Iteration: [1] : Waiting for volume: [vsanDatastore] 1874c359-f300-a0cc-fd7e-02002a623c85/kubernetes-dynamic-pvc-167a93ac-ad55-11e7-a775-0050569cce2c.vmdk to be detached from the node: kubernetes-node4 Oct 9 17:52:09.078: INFO: PersistentVolumeClaim pvc-dq5fv found and phase=Bound (2.015958443s) STEP: Instance: [Thread:4], Iteration: [2] : Creating Pod using the claim: pvc-dq5fv Oct 9 17:52:10.813: INFO: Pod "pvc-tester-jxm6s": Phase="Running", Reason="", readiness=true. Elapsed: 24.073206532s Oct 9 17:52:12.819: INFO: Pod "pvc-tester-jxm6s": Phase="Running", Reason="", readiness=true. Elapsed: 26.078696186s Oct 9 17:52:12.988: INFO: Volume "[vsanDatastore] 1874c359-f300-a0cc-fd7e-02002a623c85/kubernetes-dynamic-pvc-168008a1-ad55-11e7-a775-0050569cce2c.vmdk" appears to have successfully detached from "kubernetes-node2". STEP: Instance: [Thread:5], Iteration: [1] : Deleting the Claim: pvc-5m5qz Oct 9 17:52:12.988: INFO: Deleting PersistentVolumeClaim "pvc-5m5qz" STEP: Instance: [Thread:5], Iteration: [2] : Creating PVC using the Storage Class: sc-default STEP: Instance: [Thread:5], Iteration: [2] : Waiting for claim: pvc-xt9wf to be in bound phase Oct 9 17:52:13.005: INFO: Waiting up to 5m0s for PersistentVolumeClaim pvc-xt9wf to have phase Bound Oct 9 17:52:13.017: INFO: PersistentVolumeClaim pvc-xt9wf found but phase is Pending instead of Bound. Oct 9 17:52:14.824: INFO: Pod "pvc-tester-jxm6s": Phase="Running", Reason="", readiness=true. Elapsed: 28.084246449s Oct 9 17:52:15.022: INFO: PersistentVolumeClaim pvc-xt9wf found and phase=Bound (2.01689098s) STEP: Instance: [Thread:5], Iteration: [2] : Creating Pod using the claim: pvc-xt9wf STEP: Instance: [Thread:1], Iteration: [2] : Waiting for the Pod: pvc-tester-sp495 to be in the running state STEP: Instance: [Thread:1], Iteration: [2] : Verifing the volume: [vsanDatastore] 1874c359-f300-a0cc-fd7e-02002a623c85/kubernetes-dynamic-pvc-3c4b0b87-ad55-11e7-a775-0050569cce2c.vmdk is attached to the node VM: kubernetes-node1 STEP: Instance: [Thread:1], Iteration: [2] : Verifing the volume: [vsanDatastore] 1874c359-f300-a0cc-fd7e-02002a623c85/kubernetes-dynamic-pvc-3c4b0b87-ad55-11e7-a775-0050569cce2c.vmdk is accessible in the pod: pvc-tester-sp495 STEP: Verify the volume is accessible and available in the pod Oct 9 17:52:15.624: INFO: Running '/root/divyenp/kubernetes/_output/dockerized/bin/linux/amd64/kubectl --server=https://10.192.57.171 --kubeconfig=/root/.kube/config exec pvc-tester-sp495 --namespace=e2e-tests-vcp-stress-dxrkx -- /bin/touch /mnt/volume1/emptyFile.txt' Oct 9 17:52:16.836: INFO: Pod "pvc-tester-jxm6s": Phase="Running", Reason="", readiness=true. Elapsed: 30.096124474s Oct 9 17:52:17.005: INFO: stderr: "" Oct 9 17:52:17.005: INFO: stdout: "" STEP: Instance: [Thread:1], Iteration: [2] : Deleting pod: pvc-tester-sp495 Oct 9 17:52:17.006: INFO: Deleting pod pvc-tester-sp495 Oct 9 17:52:17.014: INFO: Waiting up to 5m0s for pod "pvc-tester-sp495" in namespace "e2e-tests-vcp-stress-dxrkx" to be "terminated due to deadline exceeded" Oct 9 17:52:17.019: INFO: Pod "pvc-tester-sp495": Phase="Running", Reason="", readiness=true. Elapsed: 4.899879ms Oct 9 17:52:18.843: INFO: Pod "pvc-tester-jxm6s": Phase="Pending", Reason="", readiness=false. Elapsed: 32.102881535s Oct 9 17:52:18.987: INFO: Volume "[vsanDatastore] 1874c359-f300-a0cc-fd7e-02002a623c85/kubernetes-dynamic-pvc-167a93ac-ad55-11e7-a775-0050569cce2c.vmdk" appears to have successfully detached from "kubernetes-node4". STEP: Instance: [Thread:2], Iteration: [1] : Deleting the Claim: pvc-zvs8j Oct 9 17:52:18.988: INFO: Deleting PersistentVolumeClaim "pvc-zvs8j" STEP: Instance: [Thread:2], Iteration: [2] : Creating PVC using the Storage Class: sc-vsan STEP: Instance: [Thread:2], Iteration: [2] : Waiting for claim: pvc-k7g5b to be in bound phase Oct 9 17:52:19.013: INFO: Waiting up to 5m0s for PersistentVolumeClaim pvc-k7g5b to have phase Bound Oct 9 17:52:19.020: INFO: PersistentVolumeClaim pvc-k7g5b found but phase is Pending instead of Bound. Oct 9 17:52:19.024: INFO: Pod "pvc-tester-sp495": Phase="Running", Reason="", readiness=true. Elapsed: 2.009607414s Oct 9 17:52:20.850: INFO: Pod "pvc-tester-jxm6s": Phase="Pending", Reason="", readiness=false. Elapsed: 34.109500453s Oct 9 17:52:21.026: INFO: PersistentVolumeClaim pvc-k7g5b found but phase is Pending instead of Bound. Oct 9 17:52:21.028: INFO: Pod "pvc-tester-sp495": Phase="Running", Reason="", readiness=true. Elapsed: 4.014247594s Oct 9 17:52:22.857: INFO: Pod "pvc-tester-jxm6s": Phase="Pending", Reason="", readiness=false. Elapsed: 36.116908532s Oct 9 17:52:23.035: INFO: Pod "pvc-tester-sp495": Phase="Running", Reason="", readiness=true. Elapsed: 6.020815878s Oct 9 17:52:23.035: INFO: PersistentVolumeClaim pvc-k7g5b found but phase is Pending instead of Bound. STEP: Instance: [Thread:4], Iteration: [2] : Waiting for the Pod: pvc-tester-ln72g to be in the running state STEP: Instance: [Thread:4], Iteration: [2] : Verifing the volume: [vsanDatastore] 1874c359-f300-a0cc-fd7e-02002a623c85/kubernetes-dynamic-pvc-3d4f03c3-ad55-11e7-a775-0050569cce2c.vmdk is attached to the node VM: kubernetes-node2 STEP: Instance: [Thread:4], Iteration: [2] : Verifing the volume: [vsanDatastore] 1874c359-f300-a0cc-fd7e-02002a623c85/kubernetes-dynamic-pvc-3d4f03c3-ad55-11e7-a775-0050569cce2c.vmdk is accessible in the pod: pvc-tester-ln72g STEP: Verify the volume is accessible and available in the pod Oct 9 17:52:23.366: INFO: Running '/root/divyenp/kubernetes/_output/dockerized/bin/linux/amd64/kubectl --server=https://10.192.57.171 --kubeconfig=/root/.kube/config exec pvc-tester-ln72g --namespace=e2e-tests-vcp-stress-dxrkx -- /bin/touch /mnt/volume1/emptyFile.txt' Oct 9 17:52:23.841: INFO: stderr: "" Oct 9 17:52:23.841: INFO: stdout: "" STEP: Instance: [Thread:4], Iteration: [2] : Deleting pod: pvc-tester-ln72g Oct 9 17:52:23.841: INFO: Deleting pod pvc-tester-ln72g Oct 9 17:52:23.854: INFO: Waiting up to 5m0s for pod "pvc-tester-ln72g" in namespace "e2e-tests-vcp-stress-dxrkx" to be "terminated due to deadline exceeded" Oct 9 17:52:23.859: INFO: Pod "pvc-tester-ln72g": Phase="Running", Reason="", readiness=true. Elapsed: 4.950418ms Oct 9 17:52:24.862: INFO: Pod "pvc-tester-jxm6s" in namespace "e2e-tests-vcp-stress-dxrkx" not found. Error: pods "pvc-tester-jxm6s" not found Oct 9 17:52:24.862: INFO: Ignore "not found" error above. Pod "pvc-tester-jxm6s" successfully deleted STEP: Instance: [Thread:3], Iteration: [1] : Waiting for volume: [vsanDatastore] 1874c359-f300-a0cc-fd7e-02002a623c85/kubernetes-dynamic-pvc-167ab992-ad55-11e7-a775-0050569cce2c.vmdk to be detached from the node: kubernetes-node3 Oct 9 17:52:25.040: INFO: PersistentVolumeClaim pvc-k7g5b found but phase is Pending instead of Bound. Oct 9 17:52:25.041: INFO: Pod "pvc-tester-sp495": Phase="Running", Reason="", readiness=true. Elapsed: 8.026880939s STEP: Instance: [Thread:5], Iteration: [2] : Waiting for the Pod: pvc-tester-9ccbr to be in the running state STEP: Instance: [Thread:5], Iteration: [2] : Verifing the volume: [vsanDatastore] 1874c359-f300-a0cc-fd7e-02002a623c85/kubernetes-dynamic-pvc-40dac6d6-ad55-11e7-a775-0050569cce2c.vmdk is attached to the node VM: kubernetes-node4 STEP: Instance: [Thread:5], Iteration: [2] : Verifing the volume: [vsanDatastore] 1874c359-f300-a0cc-fd7e-02002a623c85/kubernetes-dynamic-pvc-40dac6d6-ad55-11e7-a775-0050569cce2c.vmdk is accessible in the pod: pvc-tester-9ccbr STEP: Verify the volume is accessible and available in the pod Oct 9 17:52:25.289: INFO: Running '/root/divyenp/kubernetes/_output/dockerized/bin/linux/amd64/kubectl --server=https://10.192.57.171 --kubeconfig=/root/.kube/config exec pvc-tester-9ccbr --namespace=e2e-tests-vcp-stress-dxrkx -- /bin/touch /mnt/volume1/emptyFile.txt' Oct 9 17:52:25.776: INFO: stderr: "" Oct 9 17:52:25.776: INFO: stdout: "" STEP: Instance: [Thread:5], Iteration: [2] : Deleting pod: pvc-tester-9ccbr Oct 9 17:52:25.776: INFO: Deleting pod pvc-tester-9ccbr Oct 9 17:52:25.784: INFO: Waiting up to 5m0s for pod "pvc-tester-9ccbr" in namespace "e2e-tests-vcp-stress-dxrkx" to be "terminated due to deadline exceeded" Oct 9 17:52:25.789: INFO: Pod "pvc-tester-9ccbr": Phase="Running", Reason="", readiness=true. Elapsed: 5.077074ms Oct 9 17:52:25.865: INFO: Pod "pvc-tester-ln72g": Phase="Running", Reason="", readiness=true. Elapsed: 2.010455778s Oct 9 17:52:27.049: INFO: PersistentVolumeClaim pvc-k7g5b found but phase is Pending instead of Bound. Oct 9 17:52:27.050: INFO: Pod "pvc-tester-sp495": Phase="Running", Reason="", readiness=true. Elapsed: 10.036188038s Oct 9 17:52:27.795: INFO: Pod "pvc-tester-9ccbr": Phase="Running", Reason="", readiness=true. Elapsed: 2.010755611s Oct 9 17:52:27.870: INFO: Pod "pvc-tester-ln72g": Phase="Running", Reason="", readiness=true. Elapsed: 4.015435683s Oct 9 17:52:29.057: INFO: PersistentVolumeClaim pvc-k7g5b found but phase is Pending instead of Bound. Oct 9 17:52:29.057: INFO: Pod "pvc-tester-sp495": Phase="Running", Reason="", readiness=true. Elapsed: 12.042647665s Oct 9 17:52:29.799: INFO: Pod "pvc-tester-9ccbr": Phase="Running", Reason="", readiness=true. Elapsed: 4.015473785s Oct 9 17:52:29.874: INFO: Pod "pvc-tester-ln72g": Phase="Running", Reason="", readiness=true. Elapsed: 6.019526541s Oct 9 17:52:31.063: INFO: PersistentVolumeClaim pvc-k7g5b found and phase=Bound (12.050203168s) Oct 9 17:52:31.070: INFO: Pod "pvc-tester-sp495": Phase="Running", Reason="", readiness=true. Elapsed: 14.055968911s STEP: Instance: [Thread:2], Iteration: [2] : Creating Pod using the claim: pvc-k7g5b Oct 9 17:52:31.804: INFO: Pod "pvc-tester-9ccbr": Phase="Running", Reason="", readiness=true. Elapsed: 6.020069131s Oct 9 17:52:31.878: INFO: Pod "pvc-tester-ln72g": Phase="Running", Reason="", readiness=true. Elapsed: 8.023939374s Oct 9 17:52:33.076: INFO: Pod "pvc-tester-sp495": Phase="Running", Reason="", readiness=true. Elapsed: 16.062024505s Oct 9 17:52:33.809: INFO: Pod "pvc-tester-9ccbr": Phase="Running", Reason="", readiness=true. Elapsed: 8.024668351s Oct 9 17:52:33.883: INFO: Pod "pvc-tester-ln72g": Phase="Running", Reason="", readiness=true. Elapsed: 10.028299403s Oct 9 17:52:34.981: INFO: Volume "[vsanDatastore] 1874c359-f300-a0cc-fd7e-02002a623c85/kubernetes-dynamic-pvc-167ab992-ad55-11e7-a775-0050569cce2c.vmdk" appears to have successfully detached from "kubernetes-node3". STEP: Instance: [Thread:3], Iteration: [1] : Deleting the Claim: pvc-2xqld Oct 9 17:52:34.981: INFO: Deleting PersistentVolumeClaim "pvc-2xqld" STEP: Instance: [Thread:3], Iteration: [2] : Creating PVC using the Storage Class: sc-spbm STEP: Instance: [Thread:3], Iteration: [2] : Waiting for claim: pvc-6fzlg to be in bound phase Oct 9 17:52:35.003: INFO: Waiting up to 5m0s for PersistentVolumeClaim pvc-6fzlg to have phase Bound Oct 9 17:52:35.007: INFO: PersistentVolumeClaim pvc-6fzlg found but phase is Pending instead of Bound. Oct 9 17:52:35.081: INFO: Pod "pvc-tester-sp495": Phase="Running", Reason="", readiness=true. Elapsed: 18.066651271s Oct 9 17:52:35.813: INFO: Pod "pvc-tester-9ccbr": Phase="Running", Reason="", readiness=true. Elapsed: 10.029090054s Oct 9 17:52:35.888: INFO: Pod "pvc-tester-ln72g": Phase="Running", Reason="", readiness=true. Elapsed: 12.033339409s Oct 9 17:52:37.012: INFO: PersistentVolumeClaim pvc-6fzlg found but phase is Pending instead of Bound. Oct 9 17:52:37.086: INFO: Pod "pvc-tester-sp495": Phase="Running", Reason="", readiness=true. Elapsed: 20.071714001s Oct 9 17:52:37.818: INFO: Pod "pvc-tester-9ccbr": Phase="Running", Reason="", readiness=true. Elapsed: 12.03425865s Oct 9 17:52:37.892: INFO: Pod "pvc-tester-ln72g": Phase="Running", Reason="", readiness=true. Elapsed: 14.038121797s Oct 9 17:52:39.017: INFO: PersistentVolumeClaim pvc-6fzlg found but phase is Pending instead of Bound. Oct 9 17:52:39.090: INFO: Pod "pvc-tester-sp495": Phase="Running", Reason="", readiness=true. Elapsed: 22.076384364s Oct 9 17:52:39.823: INFO: Pod "pvc-tester-9ccbr": Phase="Running", Reason="", readiness=true. Elapsed: 14.03919873s Oct 9 17:52:39.898: INFO: Pod "pvc-tester-ln72g": Phase="Running", Reason="", readiness=true. Elapsed: 16.043326459s Oct 9 17:52:41.023: INFO: PersistentVolumeClaim pvc-6fzlg found but phase is Pending instead of Bound. Oct 9 17:52:41.096: INFO: Pod "pvc-tester-sp495": Phase="Running", Reason="", readiness=true. Elapsed: 24.08157391s Oct 9 17:52:41.828: INFO: Pod "pvc-tester-9ccbr": Phase="Running", Reason="", readiness=true. Elapsed: 16.043772601s Oct 9 17:52:41.902: INFO: Pod "pvc-tester-ln72g": Phase="Running", Reason="", readiness=true. Elapsed: 18.047447776s Oct 9 17:52:43.027: INFO: PersistentVolumeClaim pvc-6fzlg found but phase is Pending instead of Bound. Oct 9 17:52:43.100: INFO: Pod "pvc-tester-sp495": Phase="Running", Reason="", readiness=true. Elapsed: 26.085733296s Oct 9 17:52:43.834: INFO: Pod "pvc-tester-9ccbr": Phase="Running", Reason="", readiness=true. Elapsed: 18.049781572s Oct 9 17:52:43.908: INFO: Pod "pvc-tester-ln72g": Phase="Running", Reason="", readiness=true. Elapsed: 20.053282297s Oct 9 17:52:45.032: INFO: PersistentVolumeClaim pvc-6fzlg found but phase is Pending instead of Bound. Oct 9 17:52:45.103: INFO: Pod "pvc-tester-sp495": Phase="Running", Reason="", readiness=true. Elapsed: 28.089513313s Oct 9 17:52:45.839: INFO: Pod "pvc-tester-9ccbr": Phase="Running", Reason="", readiness=true. Elapsed: 20.054711207s Oct 9 17:52:45.913: INFO: Pod "pvc-tester-ln72g": Phase="Running", Reason="", readiness=true. Elapsed: 22.058430309s Oct 9 17:52:47.046: INFO: PersistentVolumeClaim pvc-6fzlg found and phase=Bound (12.043259324s) STEP: Instance: [Thread:3], Iteration: [2] : Creating Pod using the claim: pvc-6fzlg Oct 9 17:52:47.108: INFO: Pod "pvc-tester-sp495": Phase="Running", Reason="", readiness=true. Elapsed: 30.093660084s Oct 9 17:52:47.845: INFO: Pod "pvc-tester-9ccbr": Phase="Running", Reason="", readiness=true. Elapsed: 22.060724894s Oct 9 17:52:47.918: INFO: Pod "pvc-tester-ln72g": Phase="Running", Reason="", readiness=true. Elapsed: 24.063376246s Oct 9 17:52:49.112: INFO: Pod "pvc-tester-sp495" in namespace "e2e-tests-vcp-stress-dxrkx" not found. Error: pods "pvc-tester-sp495" not found Oct 9 17:52:49.112: INFO: Ignore "not found" error above. Pod "pvc-tester-sp495" successfully deleted STEP: Instance: [Thread:1], Iteration: [2] : Waiting for volume: [vsanDatastore] 1874c359-f300-a0cc-fd7e-02002a623c85/kubernetes-dynamic-pvc-3c4b0b87-ad55-11e7-a775-0050569cce2c.vmdk to be detached from the node: kubernetes-node1 Oct 9 17:52:49.852: INFO: Pod "pvc-tester-9ccbr": Phase="Running", Reason="", readiness=true. Elapsed: 24.067751559s Oct 9 17:52:49.923: INFO: Pod "pvc-tester-ln72g": Phase="Running", Reason="", readiness=true. Elapsed: 26.069102215s Oct 9 17:52:51.866: INFO: Pod "pvc-tester-9ccbr": Phase="Running", Reason="", readiness=true. Elapsed: 26.081690003s Oct 9 17:52:51.931: INFO: Pod "pvc-tester-ln72g": Phase="Running", Reason="", readiness=true. Elapsed: 28.07627797s Oct 9 17:52:53.870: INFO: Pod "pvc-tester-9ccbr": Phase="Running", Reason="", readiness=true. Elapsed: 28.086324102s Oct 9 17:52:53.936: INFO: Pod "pvc-tester-ln72g": Phase="Running", Reason="", readiness=true. Elapsed: 30.081664905s STEP: Instance: [Thread:2], Iteration: [2] : Waiting for the Pod: pvc-tester-s78sw to be in the running state STEP: Instance: [Thread:2], Iteration: [2] : Verifing the volume: [vsanDatastore] 1874c359-f300-a0cc-fd7e-02002a623c85/kubernetes-dynamic-pvc-446eb6d3-ad55-11e7-a775-0050569cce2c.vmdk is attached to the node VM: kubernetes-node3 STEP: Instance: [Thread:2], Iteration: [2] : Verifing the volume: [vsanDatastore] 1874c359-f300-a0cc-fd7e-02002a623c85/kubernetes-dynamic-pvc-446eb6d3-ad55-11e7-a775-0050569cce2c.vmdk is accessible in the pod: pvc-tester-s78sw STEP: Verify the volume is accessible and available in the pod Oct 9 17:52:55.331: INFO: Running '/root/divyenp/kubernetes/_output/dockerized/bin/linux/amd64/kubectl --server=https://10.192.57.171 --kubeconfig=/root/.kube/config exec pvc-tester-s78sw --namespace=e2e-tests-vcp-stress-dxrkx -- /bin/touch /mnt/volume1/emptyFile.txt' Oct 9 17:52:55.889: INFO: Pod "pvc-tester-9ccbr": Phase="Running", Reason="", readiness=true. Elapsed: 30.105318047s Oct 9 17:52:55.892: INFO: stderr: "" Oct 9 17:52:55.892: INFO: stdout: "" STEP: Instance: [Thread:2], Iteration: [2] : Deleting pod: pvc-tester-s78sw Oct 9 17:52:55.892: INFO: Deleting pod pvc-tester-s78sw Oct 9 17:52:55.899: INFO: Waiting up to 5m0s for pod "pvc-tester-s78sw" in namespace "e2e-tests-vcp-stress-dxrkx" to be "terminated due to deadline exceeded" Oct 9 17:52:55.905: INFO: Pod "pvc-tester-s78sw": Phase="Running", Reason="", readiness=true. Elapsed: 6.090844ms Oct 9 17:52:55.942: INFO: Pod "pvc-tester-ln72g": Phase="Running", Reason="", readiness=false. Elapsed: 32.087404597s Oct 9 17:52:57.896: INFO: Pod "pvc-tester-9ccbr" in namespace "e2e-tests-vcp-stress-dxrkx" not found. Error: pods "pvc-tester-9ccbr" not found Oct 9 17:52:57.896: INFO: Ignore "not found" error above. Pod "pvc-tester-9ccbr" successfully deleted STEP: Instance: [Thread:5], Iteration: [2] : Waiting for volume: [vsanDatastore] 1874c359-f300-a0cc-fd7e-02002a623c85/kubernetes-dynamic-pvc-40dac6d6-ad55-11e7-a775-0050569cce2c.vmdk to be detached from the node: kubernetes-node4 Oct 9 17:52:57.910: INFO: Pod "pvc-tester-s78sw": Phase="Running", Reason="", readiness=true. Elapsed: 2.011411806s Oct 9 17:52:57.948: INFO: Pod "pvc-tester-ln72g": Phase="Running", Reason="", readiness=false. Elapsed: 34.094015959s Oct 9 17:52:59.230: INFO: Volume "[vsanDatastore] 1874c359-f300-a0cc-fd7e-02002a623c85/kubernetes-dynamic-pvc-3c4b0b87-ad55-11e7-a775-0050569cce2c.vmdk" appears to have successfully detached from "kubernetes-node1". STEP: Instance: [Thread:1], Iteration: [2] : Deleting the Claim: pvc-62bqt Oct 9 17:52:59.230: INFO: Deleting PersistentVolumeClaim "pvc-62bqt" Oct 9 17:52:59.239: INFO: Deleting PersistentVolumeClaim "pvc-62bqt" Oct 9 17:52:59.243: INFO: Deleting PersistentVolumeClaim "pvc-rhvzf" Oct 9 17:52:59.915: INFO: Pod "pvc-tester-s78sw": Phase="Running", Reason="", readiness=true. Elapsed: 4.015945507s Oct 9 17:52:59.953: INFO: Pod "pvc-tester-ln72g": Phase="Running", Reason="", readiness=false. Elapsed: 36.09898893s Oct 9 17:53:01.920: INFO: Pod "pvc-tester-s78sw": Phase="Running", Reason="", readiness=true. Elapsed: 6.021629725s Oct 9 17:53:01.958: INFO: Pod "pvc-tester-ln72g": Phase="Running", Reason="", readiness=false. Elapsed: 38.103461259s STEP: Instance: [Thread:3], Iteration: [2] : Waiting for the Pod: pvc-tester-qb2tk to be in the running state STEP: Instance: [Thread:3], Iteration: [2] : Verifing the volume: [vsanDatastore] 1874c359-f300-a0cc-fd7e-02002a623c85/kubernetes-dynamic-pvc-4df73922-ad55-11e7-a775-0050569cce2c.vmdk is attached to the node VM: kubernetes-node2 STEP: Instance: [Thread:3], Iteration: [2] : Verifing the volume: [vsanDatastore] 1874c359-f300-a0cc-fd7e-02002a623c85/kubernetes-dynamic-pvc-4df73922-ad55-11e7-a775-0050569cce2c.vmdk is accessible in the pod: pvc-tester-qb2tk STEP: Verify the volume is accessible and available in the pod Oct 9 17:53:03.337: INFO: Running '/root/divyenp/kubernetes/_output/dockerized/bin/linux/amd64/kubectl --server=https://10.192.57.171 --kubeconfig=/root/.kube/config exec pvc-tester-qb2tk --namespace=e2e-tests-vcp-stress-dxrkx -- /bin/touch /mnt/volume1/emptyFile.txt' Oct 9 17:53:03.810: INFO: stderr: "" Oct 9 17:53:03.811: INFO: stdout: "" STEP: Instance: [Thread:3], Iteration: [2] : Deleting pod: pvc-tester-qb2tk Oct 9 17:53:03.811: INFO: Deleting pod pvc-tester-qb2tk Oct 9 17:53:03.825: INFO: Waiting up to 5m0s for pod "pvc-tester-qb2tk" in namespace "e2e-tests-vcp-stress-dxrkx" to be "terminated due to deadline exceeded" Oct 9 17:53:03.832: INFO: Pod "pvc-tester-qb2tk": Phase="Running", Reason="", readiness=true. Elapsed: 6.26982ms Oct 9 17:53:03.926: INFO: Pod "pvc-tester-s78sw": Phase="Running", Reason="", readiness=true. Elapsed: 8.027348625s Oct 9 17:53:03.962: INFO: Pod "pvc-tester-ln72g" in namespace "e2e-tests-vcp-stress-dxrkx" not found. Error: pods "pvc-tester-ln72g" not found Oct 9 17:53:03.963: INFO: Ignore "not found" error above. Pod "pvc-tester-ln72g" successfully deleted STEP: Instance: [Thread:4], Iteration: [2] : Waiting for volume: [vsanDatastore] 1874c359-f300-a0cc-fd7e-02002a623c85/kubernetes-dynamic-pvc-3d4f03c3-ad55-11e7-a775-0050569cce2c.vmdk to be detached from the node: kubernetes-node2 Oct 9 17:53:05.839: INFO: Pod "pvc-tester-qb2tk": Phase="Running", Reason="", readiness=true. Elapsed: 2.01364314s Oct 9 17:53:05.934: INFO: Pod "pvc-tester-s78sw": Phase="Running", Reason="", readiness=true. Elapsed: 10.03492506s Oct 9 17:53:07.845: INFO: Pod "pvc-tester-qb2tk": Phase="Running", Reason="", readiness=true. Elapsed: 4.019234355s Oct 9 17:53:07.940: INFO: Pod "pvc-tester-s78sw": Phase="Running", Reason="", readiness=true. Elapsed: 12.041369494s Oct 9 17:53:08.011: INFO: Volume "[vsanDatastore] 1874c359-f300-a0cc-fd7e-02002a623c85/kubernetes-dynamic-pvc-40dac6d6-ad55-11e7-a775-0050569cce2c.vmdk" appears to have successfully detached from "kubernetes-node4". STEP: Instance: [Thread:5], Iteration: [2] : Deleting the Claim: pvc-xt9wf Oct 9 17:53:08.011: INFO: Deleting PersistentVolumeClaim "pvc-xt9wf" Oct 9 17:53:08.020: INFO: Deleting PersistentVolumeClaim "pvc-xt9wf" Oct 9 17:53:08.024: INFO: Deleting PersistentVolumeClaim "pvc-5m5qz" Oct 9 17:53:09.850: INFO: Pod "pvc-tester-qb2tk": Phase="Running", Reason="", readiness=true. Elapsed: 6.024746047s Oct 9 17:53:09.946: INFO: Pod "pvc-tester-s78sw": Phase="Running", Reason="", readiness=true. Elapsed: 14.047387123s Oct 9 17:53:11.855: INFO: Pod "pvc-tester-qb2tk": Phase="Running", Reason="", readiness=true. Elapsed: 8.030120224s Oct 9 17:53:11.951: INFO: Pod "pvc-tester-s78sw": Phase="Running", Reason="", readiness=true. Elapsed: 16.052132244s Oct 9 17:53:13.861: INFO: Pod "pvc-tester-qb2tk": Phase="Running", Reason="", readiness=true. Elapsed: 10.035671133s Oct 9 17:53:13.955: INFO: Pod "pvc-tester-s78sw": Phase="Running", Reason="", readiness=true. Elapsed: 18.056536216s Oct 9 17:53:14.092: INFO: Volume "[vsanDatastore] 1874c359-f300-a0cc-fd7e-02002a623c85/kubernetes-dynamic-pvc-3d4f03c3-ad55-11e7-a775-0050569cce2c.vmdk" appears to have successfully detached from "kubernetes-node2". STEP: Instance: [Thread:4], Iteration: [2] : Deleting the Claim: pvc-dq5fv Oct 9 17:53:14.092: INFO: Deleting PersistentVolumeClaim "pvc-dq5fv" Oct 9 17:53:14.099: INFO: Deleting PersistentVolumeClaim "pvc-dq5fv" Oct 9 17:53:14.104: INFO: Deleting PersistentVolumeClaim "pvc-jwhb7" Oct 9 17:53:15.867: INFO: Pod "pvc-tester-qb2tk": Phase="Running", Reason="", readiness=true. Elapsed: 12.042114923s Oct 9 17:53:15.960: INFO: Pod "pvc-tester-s78sw": Phase="Running", Reason="", readiness=true. Elapsed: 20.061433791s Oct 9 17:53:17.872: INFO: Pod "pvc-tester-qb2tk": Phase="Running", Reason="", readiness=true. Elapsed: 14.046870231s Oct 9 17:53:17.965: INFO: Pod "pvc-tester-s78sw": Phase="Running", Reason="", readiness=true. Elapsed: 22.065753282s Oct 9 17:53:19.879: INFO: Pod "pvc-tester-qb2tk": Phase="Running", Reason="", readiness=true. Elapsed: 16.053246581s Oct 9 17:53:19.970: INFO: Pod "pvc-tester-s78sw": Phase="Running", Reason="", readiness=true. Elapsed: 24.070874243s Oct 9 17:53:21.885: INFO: Pod "pvc-tester-qb2tk": Phase="Running", Reason="", readiness=true. Elapsed: 18.059560605s Oct 9 17:53:21.975: INFO: Pod "pvc-tester-s78sw": Phase="Running", Reason="", readiness=true. Elapsed: 26.075734362s Oct 9 17:53:23.890: INFO: Pod "pvc-tester-qb2tk": Phase="Running", Reason="", readiness=true. Elapsed: 20.064951947s Oct 9 17:53:23.980: INFO: Pod "pvc-tester-s78sw": Phase="Running", Reason="", readiness=true. Elapsed: 28.080766952s Oct 9 17:53:25.897: INFO: Pod "pvc-tester-qb2tk": Phase="Running", Reason="", readiness=true. Elapsed: 22.071477008s Oct 9 17:53:25.985: INFO: Pod "pvc-tester-s78sw": Phase="Running", Reason="", readiness=true. Elapsed: 30.085685437s Oct 9 17:53:27.902: INFO: Pod "pvc-tester-qb2tk": Phase="Running", Reason="", readiness=true. Elapsed: 24.077026267s Oct 9 17:53:27.989: INFO: Pod "pvc-tester-s78sw": Phase="Running", Reason="", readiness=false. Elapsed: 32.089820823s Oct 9 17:53:29.909: INFO: Pod "pvc-tester-qb2tk": Phase="Running", Reason="", readiness=true. Elapsed: 26.083376709s Oct 9 17:53:30.001: INFO: Pod "pvc-tester-s78sw": Phase="Pending", Reason="", readiness=false. Elapsed: 34.101689567s Oct 9 17:53:31.916: INFO: Pod "pvc-tester-qb2tk": Phase="Running", Reason="", readiness=true. Elapsed: 28.090324224s Oct 9 17:53:32.005: INFO: Pod "pvc-tester-s78sw": Phase="Pending", Reason="", readiness=false. Elapsed: 36.105854171s Oct 9 17:53:33.921: INFO: Pod "pvc-tester-qb2tk": Phase="Running", Reason="", readiness=true. Elapsed: 30.095752079s Oct 9 17:53:34.009: INFO: Pod "pvc-tester-s78sw" in namespace "e2e-tests-vcp-stress-dxrkx" not found. Error: pods "pvc-tester-s78sw" not found Oct 9 17:53:34.009: INFO: Ignore "not found" error above. Pod "pvc-tester-s78sw" successfully deleted STEP: Instance: [Thread:2], Iteration: [2] : Waiting for volume: [vsanDatastore] 1874c359-f300-a0cc-fd7e-02002a623c85/kubernetes-dynamic-pvc-446eb6d3-ad55-11e7-a775-0050569cce2c.vmdk to be detached from the node: kubernetes-node3 Oct 9 17:53:35.926: INFO: Pod "pvc-tester-qb2tk" in namespace "e2e-tests-vcp-stress-dxrkx" not found. Error: pods "pvc-tester-qb2tk" not found Oct 9 17:53:35.926: INFO: Ignore "not found" error above. Pod "pvc-tester-qb2tk" successfully deleted STEP: Instance: [Thread:3], Iteration: [2] : Waiting for volume: [vsanDatastore] 1874c359-f300-a0cc-fd7e-02002a623c85/kubernetes-dynamic-pvc-4df73922-ad55-11e7-a775-0050569cce2c.vmdk to be detached from the node: kubernetes-node2 Oct 9 17:53:44.119: INFO: Volume "[vsanDatastore] 1874c359-f300-a0cc-fd7e-02002a623c85/kubernetes-dynamic-pvc-446eb6d3-ad55-11e7-a775-0050569cce2c.vmdk" appears to have successfully detached from "kubernetes-node3". STEP: Instance: [Thread:2], Iteration: [2] : Deleting the Claim: pvc-k7g5b Oct 9 17:53:44.119: INFO: Deleting PersistentVolumeClaim "pvc-k7g5b" Oct 9 17:53:44.126: INFO: Deleting PersistentVolumeClaim "pvc-k7g5b" Oct 9 17:53:44.131: INFO: Deleting PersistentVolumeClaim "pvc-zvs8j" Oct 9 17:53:46.043: INFO: Volume "[vsanDatastore] 1874c359-f300-a0cc-fd7e-02002a623c85/kubernetes-dynamic-pvc-4df73922-ad55-11e7-a775-0050569cce2c.vmdk" appears to have successfully detached from "kubernetes-node2". STEP: Instance: [Thread:3], Iteration: [2] : Deleting the Claim: pvc-6fzlg Oct 9 17:53:46.043: INFO: Deleting PersistentVolumeClaim "pvc-6fzlg" Oct 9 17:53:46.051: INFO: Deleting PersistentVolumeClaim "pvc-6fzlg" Oct 9 17:53:46.055: INFO: Deleting PersistentVolumeClaim "pvc-2xqld" [AfterEach] [sig-storage] vsphere cloud provider stress [Feature:vsphere] /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/framework/framework.go:134 Oct 9 17:53:46.104: INFO: Waiting up to 3m0s for all (but 0) nodes to be ready STEP: Destroying namespace "e2e-tests-vcp-stress-dxrkx" for this suite. Oct 9 17:53:54.214: INFO: namespace: e2e-tests-vcp-stress-dxrkx, resource: bindings, ignored listing per whitelist Oct 9 17:53:54.286: INFO: namespace e2e-tests-vcp-stress-dxrkx deletion completed in 8.175682274s • [SLOW TEST:172.729 seconds] [sig-storage] vsphere cloud provider stress [Feature:vsphere] /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/framework.go:22 vsphere stress tests /go/src/k8s.io/kubernetes/_output/dockerized/go/src/k8s.io/kubernetes/test/e2e/storage/vsphere_stress.go:125 ------------------------------ SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSOct 9 17:53:54.292: INFO: Running AfterSuite actions on all node Oct 9 17:53:54.292: INFO: Running AfterSuite actions on node 1 Ran 1 of 701 Specs in 172.923 seconds SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 700 Skipped PASS Ginkgo ran 1 suite in 2m53.787863724s Test Suite Passed 2017/10/09 17:53:54 util.go:156: Step './hack/ginkgo-e2e.sh --ginkgo.focus=vsphere\sstress\stests' finished in 2m54.698907311s 2017/10/09 17:53:54 e2e.go:81: Done ``` VMware Reviewers: @rohitjogvmw @BaluDontu @tusharnt **Release note**: ```release-note NONE ```
This commit is contained in:
Kubernetes Submit Queue
GitHub
commit
51244eb0fd
@ -24,6 +24,7 @@ go_library(
|
||||
"volume_provisioning.go",
|
||||
"volumes.go",
|
||||
"vsphere_statefulsets.go",
|
||||
"vsphere_stress.go",
|
||||
"vsphere_utils.go",
|
||||
"vsphere_volume_cluster_ds.go",
|
||||
"vsphere_volume_datastore.go",
|
||||
|
||||
191
test/e2e/storage/vsphere_stress.go
Normal file
191
test/e2e/storage/vsphere_stress.go
Normal file
@ -0,0 +1,191 @@
|
||||
/*
|
||||
Copyright 2017 The Kubernetes Authors.
|
||||
|
||||
Licensed under the Apache License, Version 2.0 (the "License");
|
||||
you may not use this file except in compliance with the License.
|
||||
You may obtain a copy of the License at
|
||||
|
||||
http://www.apache.org/licenses/LICENSE-2.0
|
||||
|
||||
Unless required by applicable law or agreed to in writing, software
|
||||
distributed under the License is distributed on an "AS IS" BASIS,
|
||||
WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
|
||||
See the License for the specific language governing permissions and
|
||||
limitations under the License.
|
||||
*/
|
||||
|
||||
package storage
|
||||
|
||||
import (
|
||||
"fmt"
|
||||
. "github.com/onsi/ginkgo"
|
||||
. "github.com/onsi/gomega"
|
||||
"k8s.io/api/core/v1"
|
||||
storageV1 "k8s.io/api/storage/v1"
|
||||
metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
|
||||
"k8s.io/apimachinery/pkg/types"
|
||||
k8stype "k8s.io/apimachinery/pkg/types"
|
||||
clientset "k8s.io/client-go/kubernetes"
|
||||
"k8s.io/kubernetes/pkg/cloudprovider/providers/vsphere"
|
||||
"k8s.io/kubernetes/test/e2e/framework"
|
||||
"os"
|
||||
"strconv"
|
||||
"sync"
|
||||
)
|
||||
|
||||
/*
|
||||
Induce stress to create volumes in parallel with multiple threads based on user configurable values for number of threads and iterations per thread.
|
||||
The following actions will be performed as part of this test.
|
||||
|
||||
1. Create Storage Classes of 4 Categories (Default, SC with Non Default Datastore, SC with SPBM Policy, SC with VSAN Storage Capalibilies.)
|
||||
2. READ VCP_STRESS_INSTANCES, VCP_STRESS_ITERATIONS, VSPHERE_SPBM_POLICY_NAME and VSPHERE_DATASTORE from System Environment.
|
||||
3. Launch goroutine for volume lifecycle operations.
|
||||
4. Each instance of routine iterates for n times, where n is read from system env - VCP_STRESS_ITERATIONS
|
||||
5. Each iteration creates 1 PVC, 1 POD using the provisioned PV, Verify disk is attached to the node, Verify pod can access the volume, delete the pod and finally delete the PVC.
|
||||
*/
|
||||
var _ = SIGDescribe("vsphere cloud provider stress [Feature:vsphere]", func() {
|
||||
f := framework.NewDefaultFramework("vcp-stress")
|
||||
const (
|
||||
volumesPerNode = 55
|
||||
storageclass1 = "sc-default"
|
||||
storageclass2 = "sc-vsan"
|
||||
storageclass3 = "sc-spbm"
|
||||
storageclass4 = "sc-user-specified-ds"
|
||||
)
|
||||
var (
|
||||
client clientset.Interface
|
||||
namespace string
|
||||
instances int
|
||||
iterations int
|
||||
err error
|
||||
scNames = []string{storageclass1, storageclass2, storageclass3, storageclass4}
|
||||
policyName string
|
||||
datastoreName string
|
||||
)
|
||||
|
||||
BeforeEach(func() {
|
||||
framework.SkipUnlessProviderIs("vsphere")
|
||||
client = f.ClientSet
|
||||
namespace = f.Namespace.Name
|
||||
|
||||
nodeList := framework.GetReadySchedulableNodesOrDie(f.ClientSet)
|
||||
Expect(nodeList.Items).NotTo(BeEmpty(), "Unable to find ready and schedulable Node")
|
||||
|
||||
// if VCP_STRESS_INSTANCES = 12 and VCP_STRESS_ITERATIONS is 10. 12 threads will run in parallel for 10 times.
|
||||
// Resulting 120 Volumes and POD Creation. Volumes will be provisioned with each different types of Storage Class,
|
||||
// Each iteration creates PVC, verify PV is provisioned, then creates a pod, verify volume is attached to the node, and then delete the pod and delete pvc.
|
||||
instancesStr := os.Getenv("VCP_STRESS_INSTANCES")
|
||||
Expect(instancesStr).NotTo(BeEmpty(), "ENV VCP_STRESS_INSTANCES is not set")
|
||||
instances, err = strconv.Atoi(instancesStr)
|
||||
Expect(err).NotTo(HaveOccurred(), "Error Parsing VCP-STRESS-INSTANCES")
|
||||
Expect(instances <= volumesPerNode*len(nodeList.Items)).To(BeTrue(), fmt.Sprintf("Number of Instances should be less or equal: %v", volumesPerNode*len(nodeList.Items)))
|
||||
Expect(instances > len(scNames)).To(BeTrue(), "VCP_STRESS_INSTANCES should be greater than 3 to utilize all 4 types of storage classes")
|
||||
|
||||
iterationStr := os.Getenv("VCP_STRESS_ITERATIONS")
|
||||
Expect(instancesStr).NotTo(BeEmpty(), "ENV VCP_STRESS_ITERATIONS is not set")
|
||||
iterations, err = strconv.Atoi(iterationStr)
|
||||
Expect(err).NotTo(HaveOccurred(), "Error Parsing VCP_STRESS_ITERATIONS")
|
||||
Expect(iterations > 0).To(BeTrue(), "VCP_STRESS_ITERATIONS should be greater than 0")
|
||||
|
||||
policyName = os.Getenv("VSPHERE_SPBM_POLICY_NAME")
|
||||
datastoreName = os.Getenv("VSPHERE_DATASTORE")
|
||||
Expect(policyName).NotTo(BeEmpty(), "ENV VSPHERE_SPBM_POLICY_NAME is not set")
|
||||
Expect(datastoreName).NotTo(BeEmpty(), "ENV VSPHERE_DATASTORE is not set")
|
||||
})
|
||||
|
||||
It("vsphere stress tests", func() {
|
||||
scArrays := make([]*storageV1.StorageClass, len(scNames))
|
||||
for index, scname := range scNames {
|
||||
// Create vSphere Storage Class
|
||||
By(fmt.Sprintf("Creating Storage Class : %v", scname))
|
||||
var sc *storageV1.StorageClass
|
||||
var err error
|
||||
switch scname {
|
||||
case storageclass1:
|
||||
sc, err = client.StorageV1().StorageClasses().Create(getVSphereStorageClassSpec(storageclass1, nil))
|
||||
case storageclass2:
|
||||
var scVSanParameters map[string]string
|
||||
scVSanParameters = make(map[string]string)
|
||||
scVSanParameters[Policy_HostFailuresToTolerate] = "1"
|
||||
sc, err = client.StorageV1().StorageClasses().Create(getVSphereStorageClassSpec(storageclass2, scVSanParameters))
|
||||
case storageclass3:
|
||||
var scSPBMPolicyParameters map[string]string
|
||||
scSPBMPolicyParameters = make(map[string]string)
|
||||
scSPBMPolicyParameters[SpbmStoragePolicy] = policyName
|
||||
sc, err = client.StorageV1().StorageClasses().Create(getVSphereStorageClassSpec(storageclass3, scSPBMPolicyParameters))
|
||||
case storageclass4:
|
||||
var scWithDSParameters map[string]string
|
||||
scWithDSParameters = make(map[string]string)
|
||||
scWithDSParameters[Datastore] = datastoreName
|
||||
scWithDatastoreSpec := getVSphereStorageClassSpec(storageclass4, scWithDSParameters)
|
||||
sc, err = client.StorageV1().StorageClasses().Create(scWithDatastoreSpec)
|
||||
}
|
||||
Expect(sc).NotTo(BeNil())
|
||||
Expect(err).NotTo(HaveOccurred())
|
||||
defer client.StorageV1().StorageClasses().Delete(scname, nil)
|
||||
scArrays[index] = sc
|
||||
}
|
||||
|
||||
var wg sync.WaitGroup
|
||||
wg.Add(instances)
|
||||
for instanceCount := 0; instanceCount < instances; instanceCount++ {
|
||||
instanceId := fmt.Sprintf("Thread:%v", instanceCount+1)
|
||||
go PerformVolumeLifeCycleInParallel(f, client, namespace, instanceId, scArrays[instanceCount%len(scArrays)], iterations, &wg)
|
||||
}
|
||||
wg.Wait()
|
||||
})
|
||||
|
||||
})
|
||||
|
||||
// goroutine to perform volume lifecycle operations in parallel
|
||||
func PerformVolumeLifeCycleInParallel(f *framework.Framework, client clientset.Interface, namespace string, instanceId string, sc *storageV1.StorageClass, iterations int, wg *sync.WaitGroup) {
|
||||
defer wg.Done()
|
||||
defer GinkgoRecover()
|
||||
vsp, err := vsphere.GetVSphere()
|
||||
Expect(err).NotTo(HaveOccurred())
|
||||
|
||||
for iterationCount := 0; iterationCount < iterations; iterationCount++ {
|
||||
logPrefix := fmt.Sprintf("Instance: [%v], Iteration: [%v] :", instanceId, iterationCount+1)
|
||||
By(fmt.Sprintf("%v Creating PVC using the Storage Class: %v", logPrefix, sc.Name))
|
||||
pvclaim, err := framework.CreatePVC(client, namespace, getVSphereClaimSpecWithStorageClassAnnotation(namespace, "1Gi", sc))
|
||||
Expect(err).NotTo(HaveOccurred())
|
||||
defer framework.DeletePersistentVolumeClaim(client, pvclaim.Name, namespace)
|
||||
|
||||
var pvclaims []*v1.PersistentVolumeClaim
|
||||
pvclaims = append(pvclaims, pvclaim)
|
||||
By(fmt.Sprintf("%v Waiting for claim: %v to be in bound phase", logPrefix, pvclaim.Name))
|
||||
persistentvolumes, err := framework.WaitForPVClaimBoundPhase(client, pvclaims, framework.ClaimProvisionTimeout)
|
||||
Expect(err).NotTo(HaveOccurred())
|
||||
|
||||
By(fmt.Sprintf("%v Creating Pod using the claim: %v", logPrefix, pvclaim.Name))
|
||||
// Create pod to attach Volume to Node
|
||||
pod, err := framework.CreatePod(client, namespace, pvclaims, false, "")
|
||||
Expect(err).NotTo(HaveOccurred())
|
||||
|
||||
By(fmt.Sprintf("%v Waiting for the Pod: %v to be in the running state", logPrefix, pod.Name))
|
||||
Expect(f.WaitForPodRunningSlow(pod.Name)).NotTo(HaveOccurred())
|
||||
|
||||
// Get the copy of the Pod to know the assigned node name.
|
||||
pod, err = client.CoreV1().Pods(namespace).Get(pod.Name, metav1.GetOptions{})
|
||||
Expect(err).NotTo(HaveOccurred())
|
||||
|
||||
By(fmt.Sprintf("%v Verifing the volume: %v is attached to the node VM: %v", logPrefix, persistentvolumes[0].Spec.VsphereVolume.VolumePath, pod.Spec.NodeName))
|
||||
isVolumeAttached, verifyDiskAttachedError := verifyVSphereDiskAttached(vsp, persistentvolumes[0].Spec.VsphereVolume.VolumePath, types.NodeName(pod.Spec.NodeName))
|
||||
Expect(isVolumeAttached).To(BeTrue())
|
||||
Expect(verifyDiskAttachedError).NotTo(HaveOccurred())
|
||||
|
||||
By(fmt.Sprintf("%v Verifing the volume: %v is accessible in the pod: %v", logPrefix, persistentvolumes[0].Spec.VsphereVolume.VolumePath, pod.Name))
|
||||
verifyVSphereVolumesAccessible(pod, persistentvolumes, vsp)
|
||||
|
||||
By(fmt.Sprintf("%v Deleting pod: %v", logPrefix, pod.Name))
|
||||
err = framework.DeletePodWithWait(f, client, pod)
|
||||
Expect(err).NotTo(HaveOccurred())
|
||||
|
||||
By(fmt.Sprintf("%v Waiting for volume: %v to be detached from the node: %v", logPrefix, persistentvolumes[0].Spec.VsphereVolume.VolumePath, pod.Spec.NodeName))
|
||||
err = waitForVSphereDiskToDetach(vsp, persistentvolumes[0].Spec.VsphereVolume.VolumePath, k8stype.NodeName(pod.Spec.NodeName))
|
||||
Expect(err).NotTo(HaveOccurred())
|
||||
|
||||
By(fmt.Sprintf("%v Deleting the Claim: %v", logPrefix, pvclaim.Name))
|
||||
Expect(framework.DeletePersistentVolumeClaim(client, pvclaim.Name, namespace)).NotTo(HaveOccurred())
|
||||
}
|
||||
}
|
||||
Loading…
Reference in New Issue
Block a user