This job view page is being replaced by Spyglass soon. Check out the new job view.
ResultNot Finished
Started2022-08-17 16:21
Revision

Build Still Running!


Show 27 Passed Tests

Show 6 Skipped Tests

Error lines from build-log.txt

... skipping 212 lines ...
|..o...o.S . =    |
| . *..o... . .   |
|  = *o =  o      |
| o o.++ .  .     |
|    +o           |
+----[SHA256]-----+
Error: cluster not found "test-cluster-27535.k8s.local"
###
## Creating cluster test-cluster-27535.k8s.local with /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/hack/e2e/csi-test-artifacts/test-cluster-27535.k8s.local.kops.yaml (dry run)
#
I0817 16:23:40.029275    5766 create_cluster.go:843] Using SSH public key: /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/hack/e2e/csi-test-artifacts/id_rsa.pub
I0817 16:23:40.782855    5766 new_cluster.go:248] Inferred "aws" cloud provider from zone "us-west-2a"
I0817 16:23:40.782949    5766 new_cluster.go:1102]  Cloud Provider ID = aws
... skipping 72 lines ...
## Validating cluster test-cluster-27535.k8s.local
#
Using cluster from kubectl context: test-cluster-27535.k8s.local

Validating cluster test-cluster-27535.k8s.local

W0817 16:24:34.720350    5886 validate_cluster.go:184] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-27535-k8-3eqn40-1127628485.us-west-2.elb.amazonaws.com/api/v1/nodes": dial tcp: lookup api-test-cluster-27535-k8-3eqn40-1127628485.us-west-2.elb.amazonaws.com on 10.63.240.10:53: no such host
W0817 16:24:44.754765    5886 validate_cluster.go:184] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-27535-k8-3eqn40-1127628485.us-west-2.elb.amazonaws.com/api/v1/nodes": dial tcp: lookup api-test-cluster-27535-k8-3eqn40-1127628485.us-west-2.elb.amazonaws.com on 10.63.240.10:53: no such host
W0817 16:24:54.788978    5886 validate_cluster.go:184] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-27535-k8-3eqn40-1127628485.us-west-2.elb.amazonaws.com/api/v1/nodes": dial tcp: lookup api-test-cluster-27535-k8-3eqn40-1127628485.us-west-2.elb.amazonaws.com on 10.63.240.10:53: no such host
W0817 16:25:04.823209    5886 validate_cluster.go:184] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-27535-k8-3eqn40-1127628485.us-west-2.elb.amazonaws.com/api/v1/nodes": dial tcp: lookup api-test-cluster-27535-k8-3eqn40-1127628485.us-west-2.elb.amazonaws.com on 10.63.240.10:53: no such host
W0817 16:25:16.012226    5886 validate_cluster.go:184] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-27535-k8-3eqn40-1127628485.us-west-2.elb.amazonaws.com/api/v1/nodes": dial tcp: lookup api-test-cluster-27535-k8-3eqn40-1127628485.us-west-2.elb.amazonaws.com on 10.63.240.10:53: no such host
W0817 16:25:40.762191    5886 validate_cluster.go:184] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-27535-k8-3eqn40-1127628485.us-west-2.elb.amazonaws.com/api/v1/nodes": EOF
W0817 16:26:02.390538    5886 validate_cluster.go:184] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-27535-k8-3eqn40-1127628485.us-west-2.elb.amazonaws.com/api/v1/nodes": EOF
W0817 16:26:24.038167    5886 validate_cluster.go:184] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-27535-k8-3eqn40-1127628485.us-west-2.elb.amazonaws.com/api/v1/nodes": EOF
W0817 16:26:48.718245    5886 validate_cluster.go:184] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-27535-k8-3eqn40-1127628485.us-west-2.elb.amazonaws.com/api/v1/nodes": EOF
W0817 16:27:10.381180    5886 validate_cluster.go:184] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-27535-k8-3eqn40-1127628485.us-west-2.elb.amazonaws.com/api/v1/nodes": EOF
INSTANCE GROUPS
NAME			ROLE	MACHINETYPE	MIN	MAX	SUBNETS
master-us-west-2a	Master	t3.medium	1	1	us-west-2a
nodes-us-west-2a	Node	c5.large	3	3	us-west-2a

NODE STATUS
... skipping 4 lines ...
KIND	NAME						MESSAGE
Machine	i-0106749c1a71ca7f7				machine "i-0106749c1a71ca7f7" has not yet joined cluster
Machine	i-0402981cb43e7c889				machine "i-0402981cb43e7c889" has not yet joined cluster
Machine	i-0dd27f48a534dc5dd				machine "i-0dd27f48a534dc5dd" has not yet joined cluster
Node	ip-172-20-39-70.us-west-2.compute.internal	node "ip-172-20-39-70.us-west-2.compute.internal" of role "master" is not ready

Validation Failed
W0817 16:27:22.305569    5886 validate_cluster.go:232] (will retry): cluster not yet healthy
INSTANCE GROUPS
NAME			ROLE	MACHINETYPE	MIN	MAX	SUBNETS
master-us-west-2a	Master	t3.medium	1	1	us-west-2a
nodes-us-west-2a	Node	c5.large	3	3	us-west-2a

... skipping 9 lines ...
Node	ip-172-20-39-70.us-west-2.compute.internal	node "ip-172-20-39-70.us-west-2.compute.internal" of role "master" is not ready
Pod	kube-system/coredns-6d467c5d59-kzb89		system-cluster-critical pod "coredns-6d467c5d59-kzb89" is pending
Pod	kube-system/coredns-autoscaler-5c7694cfcc-9mzm2	system-cluster-critical pod "coredns-autoscaler-5c7694cfcc-9mzm2" is pending
Pod	kube-system/dns-controller-7c956b559c-6kqbm	system-cluster-critical pod "dns-controller-7c956b559c-6kqbm" is pending
Pod	kube-system/kops-controller-x9khw		system-cluster-critical pod "kops-controller-x9khw" is pending

Validation Failed
W0817 16:27:33.715586    5886 validate_cluster.go:232] (will retry): cluster not yet healthy
INSTANCE GROUPS
NAME			ROLE	MACHINETYPE	MIN	MAX	SUBNETS
master-us-west-2a	Master	t3.medium	1	1	us-west-2a
nodes-us-west-2a	Node	c5.large	3	3	us-west-2a

... skipping 11 lines ...
Node	ip-172-20-39-70.us-west-2.compute.internal	master "ip-172-20-39-70.us-west-2.compute.internal" is missing kube-scheduler pod
Pod	kube-system/coredns-6d467c5d59-kzb89		system-cluster-critical pod "coredns-6d467c5d59-kzb89" is pending
Pod	kube-system/coredns-autoscaler-5c7694cfcc-9mzm2	system-cluster-critical pod "coredns-autoscaler-5c7694cfcc-9mzm2" is pending
Pod	kube-system/dns-controller-7c956b559c-6kqbm	system-cluster-critical pod "dns-controller-7c956b559c-6kqbm" is pending
Pod	kube-system/kops-controller-x9khw		system-cluster-critical pod "kops-controller-x9khw" is pending

Validation Failed
W0817 16:27:45.204592    5886 validate_cluster.go:232] (will retry): cluster not yet healthy
INSTANCE GROUPS
NAME			ROLE	MACHINETYPE	MIN	MAX	SUBNETS
master-us-west-2a	Master	t3.medium	1	1	us-west-2a
nodes-us-west-2a	Node	c5.large	3	3	us-west-2a

... skipping 12 lines ...
Pod	kube-system/coredns-6d467c5d59-kzb89					system-cluster-critical pod "coredns-6d467c5d59-kzb89" is pending
Pod	kube-system/coredns-autoscaler-5c7694cfcc-9mzm2				system-cluster-critical pod "coredns-autoscaler-5c7694cfcc-9mzm2" is pending
Pod	kube-system/dns-controller-7c956b559c-6kqbm				system-cluster-critical pod "dns-controller-7c956b559c-6kqbm" is pending
Pod	kube-system/kops-controller-x9khw					system-cluster-critical pod "kops-controller-x9khw" is pending
Pod	kube-system/kube-scheduler-ip-172-20-39-70.us-west-2.compute.internal	system-cluster-critical pod "kube-scheduler-ip-172-20-39-70.us-west-2.compute.internal" is pending

Validation Failed
W0817 16:27:57.010808    5886 validate_cluster.go:232] (will retry): cluster not yet healthy
INSTANCE GROUPS
NAME			ROLE	MACHINETYPE	MIN	MAX	SUBNETS
master-us-west-2a	Master	t3.medium	1	1	us-west-2a
nodes-us-west-2a	Node	c5.large	3	3	us-west-2a

... skipping 11 lines ...
Pod	kube-system/coredns-6d467c5d59-kzb89						system-cluster-critical pod "coredns-6d467c5d59-kzb89" is pending
Pod	kube-system/coredns-autoscaler-5c7694cfcc-9mzm2					system-cluster-critical pod "coredns-autoscaler-5c7694cfcc-9mzm2" is pending
Pod	kube-system/etcd-manager-events-ip-172-20-39-70.us-west-2.compute.internal	system-cluster-critical pod "etcd-manager-events-ip-172-20-39-70.us-west-2.compute.internal" is pending
Pod	kube-system/etcd-manager-main-ip-172-20-39-70.us-west-2.compute.internal	system-cluster-critical pod "etcd-manager-main-ip-172-20-39-70.us-west-2.compute.internal" is pending
Pod	kube-system/kube-proxy-ip-172-20-39-70.us-west-2.compute.internal		system-node-critical pod "kube-proxy-ip-172-20-39-70.us-west-2.compute.internal" is pending

Validation Failed
W0817 16:28:08.403266    5886 validate_cluster.go:232] (will retry): cluster not yet healthy
INSTANCE GROUPS
NAME			ROLE	MACHINETYPE	MIN	MAX	SUBNETS
master-us-west-2a	Master	t3.medium	1	1	us-west-2a
nodes-us-west-2a	Node	c5.large	3	3	us-west-2a

... skipping 11 lines ...
Node	ip-172-20-57-218.us-west-2.compute.internal				node "ip-172-20-57-218.us-west-2.compute.internal" of role "node" is not ready
Pod	kube-system/coredns-6d467c5d59-kzb89					system-cluster-critical pod "coredns-6d467c5d59-kzb89" is pending
Pod	kube-system/coredns-autoscaler-5c7694cfcc-9mzm2				system-cluster-critical pod "coredns-autoscaler-5c7694cfcc-9mzm2" is pending
Pod	kube-system/kube-proxy-ip-172-20-52-10.us-west-2.compute.internal	system-node-critical pod "kube-proxy-ip-172-20-52-10.us-west-2.compute.internal" is pending
Pod	kube-system/kube-proxy-ip-172-20-57-218.us-west-2.compute.internal	system-node-critical pod "kube-proxy-ip-172-20-57-218.us-west-2.compute.internal" is pending

Validation Failed
W0817 16:28:19.923625    5886 validate_cluster.go:232] (will retry): cluster not yet healthy
INSTANCE GROUPS
NAME			ROLE	MACHINETYPE	MIN	MAX	SUBNETS
master-us-west-2a	Master	t3.medium	1	1	us-west-2a
nodes-us-west-2a	Node	c5.large	3	3	us-west-2a

... skipping 7 lines ...
VALIDATION ERRORS
KIND	NAME						MESSAGE
Node	ip-172-20-39-70.us-west-2.compute.internal	master "ip-172-20-39-70.us-west-2.compute.internal" is missing kube-controller-manager pod
Pod	kube-system/coredns-6d467c5d59-kzb89		system-cluster-critical pod "coredns-6d467c5d59-kzb89" is not ready (coredns)
Pod	kube-system/coredns-6d467c5d59-rzrqs		system-cluster-critical pod "coredns-6d467c5d59-rzrqs" is pending

Validation Failed
W0817 16:28:31.508020    5886 validate_cluster.go:232] (will retry): cluster not yet healthy
INSTANCE GROUPS
NAME			ROLE	MACHINETYPE	MIN	MAX	SUBNETS
master-us-west-2a	Master	t3.medium	1	1	us-west-2a
nodes-us-west-2a	Node	c5.large	3	3	us-west-2a

... skipping 5 lines ...
ip-172-20-57-218.us-west-2.compute.internal	node	True

VALIDATION ERRORS
KIND	NAME						MESSAGE
Node	ip-172-20-39-70.us-west-2.compute.internal	master "ip-172-20-39-70.us-west-2.compute.internal" is missing kube-controller-manager pod

Validation Failed
W0817 16:28:42.944552    5886 validate_cluster.go:232] (will retry): cluster not yet healthy
INSTANCE GROUPS
NAME			ROLE	MACHINETYPE	MIN	MAX	SUBNETS
master-us-west-2a	Master	t3.medium	1	1	us-west-2a
nodes-us-west-2a	Node	c5.large	3	3	us-west-2a

... skipping 166 lines ...
Aug 17 16:31:00.446: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-cfbfg] to have phase Bound
Aug 17 16:31:00.509: INFO: PersistentVolumeClaim pvc-cfbfg found and phase=Bound (63.463641ms)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pods command exits with an error
Aug 17 16:31:00.833: INFO: Waiting up to 15m0s for pod "ebs-volume-tester-97pdv" in namespace "ebs-3426" to be "Error status code"
Aug 17 16:31:00.897: INFO: Pod "ebs-volume-tester-97pdv": Phase="Pending", Reason="", readiness=false. Elapsed: 63.905363ms
Aug 17 16:31:02.962: INFO: Pod "ebs-volume-tester-97pdv": Phase="Pending", Reason="", readiness=false. Elapsed: 2.129449273s
Aug 17 16:31:05.026: INFO: Pod "ebs-volume-tester-97pdv": Phase="Pending", Reason="", readiness=false. Elapsed: 4.192945114s
Aug 17 16:31:07.090: INFO: Pod "ebs-volume-tester-97pdv": Phase="Pending", Reason="", readiness=false. Elapsed: 6.257457978s
Aug 17 16:31:09.156: INFO: Pod "ebs-volume-tester-97pdv": Phase="Pending", Reason="", readiness=false. Elapsed: 8.323057129s
Aug 17 16:31:11.220: INFO: Pod "ebs-volume-tester-97pdv": Phase="Pending", Reason="", readiness=false. Elapsed: 10.387395503s
Aug 17 16:31:13.285: INFO: Pod "ebs-volume-tester-97pdv": Phase="Failed", Reason="", readiness=false. Elapsed: 12.451849886s
STEP: Saw pod failure
Aug 17 16:31:13.285: INFO: Pod "ebs-volume-tester-97pdv" satisfied condition "Error status code"
STEP: checking that pod logs contain expected message
Aug 17 16:31:13.367: INFO: deleting Pod "ebs-3426"/"ebs-volume-tester-97pdv"
Aug 17 16:31:13.443: INFO: Pod ebs-volume-tester-97pdv has the following logs: /bin/sh: can't create /mnt/test-1/data: Read-only file system

STEP: Deleting pod ebs-volume-tester-97pdv in namespace ebs-3426
Aug 17 16:31:13.515: INFO: deleting PVC "ebs-3426"/"pvc-cfbfg"
... skipping 57 lines ...
STEP: checking the resizing PV result
STEP: Waiting up to 1m0s for pv in namespace "ebs-3553" to be complete
STEP: Pv size is updated to 2Gi
STEP: Validate volume can be attached
STEP: deploying the pod
STEP: checking that the pods is running
Aug 17 16:31:10.321: INFO: Waiting up to 15m0s for pod "ebs-volume-tester-75ht7" in namespace "ebs-3553" to be "Succeeded or Failed"
Aug 17 16:31:10.391: INFO: Pod "ebs-volume-tester-75ht7": Phase="Pending", Reason="", readiness=false. Elapsed: 69.329241ms
Aug 17 16:31:12.457: INFO: Pod "ebs-volume-tester-75ht7": Phase="Pending", Reason="", readiness=false. Elapsed: 2.135481183s
Aug 17 16:31:14.523: INFO: Pod "ebs-volume-tester-75ht7": Phase="Pending", Reason="", readiness=false. Elapsed: 4.201104868s
Aug 17 16:31:16.589: INFO: Pod "ebs-volume-tester-75ht7": Phase="Pending", Reason="", readiness=false. Elapsed: 6.267075345s
Aug 17 16:31:18.656: INFO: Pod "ebs-volume-tester-75ht7": Phase="Pending", Reason="", readiness=false. Elapsed: 8.334157355s
Aug 17 16:31:20.722: INFO: Pod "ebs-volume-tester-75ht7": Phase="Succeeded", Reason="", readiness=false. Elapsed: 10.400116036s
STEP: Saw pod success
Aug 17 16:31:20.722: INFO: Pod "ebs-volume-tester-75ht7" satisfied condition "Succeeded or Failed"
Aug 17 16:31:20.722: INFO: deleting Pod "ebs-3553"/"ebs-volume-tester-75ht7"
Aug 17 16:31:20.789: INFO: Pod ebs-volume-tester-75ht7 has the following logs: hello world

STEP: Deleting pod ebs-volume-tester-75ht7 in namespace ebs-3553
Aug 17 16:31:20.864: INFO: deleting PVC "ebs-3553"/"pvc-knzht"
Aug 17 16:31:20.864: INFO: Deleting PersistentVolumeClaim "pvc-knzht"
... skipping 44 lines ...
Aug 17 16:31:02.772: INFO: PersistentVolumeClaim pvc-j8l2v found but phase is Pending instead of Bound.
Aug 17 16:31:04.838: INFO: PersistentVolumeClaim pvc-j8l2v found and phase=Bound (8.36036077s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pods command exits with no error
Aug 17 16:31:05.044: INFO: Waiting up to 15m0s for pod "ebs-volume-tester-nrw9j" in namespace "ebs-2308" to be "Succeeded or Failed"
Aug 17 16:31:05.118: INFO: Pod "ebs-volume-tester-nrw9j": Phase="Pending", Reason="", readiness=false. Elapsed: 73.138937ms
Aug 17 16:31:07.185: INFO: Pod "ebs-volume-tester-nrw9j": Phase="Pending", Reason="", readiness=false. Elapsed: 2.140199921s
Aug 17 16:31:09.252: INFO: Pod "ebs-volume-tester-nrw9j": Phase="Pending", Reason="", readiness=false. Elapsed: 4.207005976s
Aug 17 16:31:11.318: INFO: Pod "ebs-volume-tester-nrw9j": Phase="Pending", Reason="", readiness=false. Elapsed: 6.273313382s
Aug 17 16:31:13.384: INFO: Pod "ebs-volume-tester-nrw9j": Phase="Succeeded", Reason="", readiness=false. Elapsed: 8.339887468s
STEP: Saw pod success
Aug 17 16:31:13.384: INFO: Pod "ebs-volume-tester-nrw9j" satisfied condition "Succeeded or Failed"
Aug 17 16:31:13.385: INFO: deleting Pod "ebs-2308"/"ebs-volume-tester-nrw9j"
Aug 17 16:31:13.456: INFO: Pod ebs-volume-tester-nrw9j has the following logs: hello world

STEP: Deleting pod ebs-volume-tester-nrw9j in namespace ebs-2308
Aug 17 16:31:13.539: INFO: deleting PVC "ebs-2308"/"pvc-j8l2v"
Aug 17 16:31:13.539: INFO: Deleting PersistentVolumeClaim "pvc-j8l2v"
... skipping 49 lines ...
Aug 17 16:31:02.773: INFO: PersistentVolumeClaim pvc-z6rmq found but phase is Pending instead of Bound.
Aug 17 16:31:04.840: INFO: PersistentVolumeClaim pvc-z6rmq found and phase=Bound (8.402553132s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pods command exits with no error
Aug 17 16:31:05.060: INFO: Waiting up to 15m0s for pod "ebs-volume-tester-qfz85" in namespace "ebs-5195" to be "Succeeded or Failed"
Aug 17 16:31:05.144: INFO: Pod "ebs-volume-tester-qfz85": Phase="Pending", Reason="", readiness=false. Elapsed: 84.455031ms
Aug 17 16:31:07.212: INFO: Pod "ebs-volume-tester-qfz85": Phase="Pending", Reason="", readiness=false. Elapsed: 2.151863353s
Aug 17 16:31:09.279: INFO: Pod "ebs-volume-tester-qfz85": Phase="Pending", Reason="", readiness=false. Elapsed: 4.218732659s
Aug 17 16:31:11.345: INFO: Pod "ebs-volume-tester-qfz85": Phase="Succeeded", Reason="", readiness=false. Elapsed: 6.285157755s
STEP: Saw pod success
Aug 17 16:31:11.345: INFO: Pod "ebs-volume-tester-qfz85" satisfied condition "Succeeded or Failed"
STEP: setting up the StorageClass
STEP: creating a StorageClass 
STEP: setting up the PVC and PV
STEP: creating a PVC
STEP: waiting for PVC to be in phase "Bound"
Aug 17 16:31:11.481: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-kzhfc] to have phase Bound
Aug 17 16:31:11.547: INFO: PersistentVolumeClaim pvc-kzhfc found but phase is Pending instead of Bound.
Aug 17 16:31:13.625: INFO: PersistentVolumeClaim pvc-kzhfc found but phase is Pending instead of Bound.
Aug 17 16:31:15.691: INFO: PersistentVolumeClaim pvc-kzhfc found and phase=Bound (4.210033198s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pods command exits with no error
Aug 17 16:31:15.891: INFO: Waiting up to 15m0s for pod "ebs-volume-tester-bb6zm" in namespace "ebs-5195" to be "Succeeded or Failed"
Aug 17 16:31:15.957: INFO: Pod "ebs-volume-tester-bb6zm": Phase="Pending", Reason="", readiness=false. Elapsed: 66.240387ms
Aug 17 16:31:18.023: INFO: Pod "ebs-volume-tester-bb6zm": Phase="Pending", Reason="", readiness=false. Elapsed: 2.132438539s
Aug 17 16:31:20.090: INFO: Pod "ebs-volume-tester-bb6zm": Phase="Pending", Reason="", readiness=false. Elapsed: 4.199374854s
Aug 17 16:31:22.162: INFO: Pod "ebs-volume-tester-bb6zm": Phase="Pending", Reason="", readiness=false. Elapsed: 6.27079795s
Aug 17 16:31:24.228: INFO: Pod "ebs-volume-tester-bb6zm": Phase="Succeeded", Reason="", readiness=false. Elapsed: 8.337428309s
STEP: Saw pod success
Aug 17 16:31:24.228: INFO: Pod "ebs-volume-tester-bb6zm" satisfied condition "Succeeded or Failed"
Aug 17 16:31:24.228: INFO: deleting Pod "ebs-5195"/"ebs-volume-tester-bb6zm"
Aug 17 16:31:24.297: INFO: Pod ebs-volume-tester-bb6zm has the following logs: hello world

STEP: Deleting pod ebs-volume-tester-bb6zm in namespace ebs-5195
Aug 17 16:31:24.373: INFO: deleting PVC "ebs-5195"/"pvc-kzhfc"
Aug 17 16:31:24.373: INFO: Deleting PersistentVolumeClaim "pvc-kzhfc"
... skipping 61 lines ...
Aug 17 16:31:37.141: INFO: PersistentVolumeClaim pvc-8g5xh found but phase is Pending instead of Bound.
Aug 17 16:31:39.209: INFO: PersistentVolumeClaim pvc-8g5xh found and phase=Bound (4.195843443s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pods command exits with no error
Aug 17 16:31:39.404: INFO: Waiting up to 15m0s for pod "ebs-volume-tester-8pqpm" in namespace "ebs-8111" to be "Succeeded or Failed"
Aug 17 16:31:39.468: INFO: Pod "ebs-volume-tester-8pqpm": Phase="Pending", Reason="", readiness=false. Elapsed: 64.150739ms
Aug 17 16:31:41.532: INFO: Pod "ebs-volume-tester-8pqpm": Phase="Pending", Reason="", readiness=false. Elapsed: 2.128041536s
Aug 17 16:31:43.597: INFO: Pod "ebs-volume-tester-8pqpm": Phase="Pending", Reason="", readiness=false. Elapsed: 4.19298891s
Aug 17 16:31:45.661: INFO: Pod "ebs-volume-tester-8pqpm": Phase="Pending", Reason="", readiness=false. Elapsed: 6.257025992s
Aug 17 16:31:47.726: INFO: Pod "ebs-volume-tester-8pqpm": Phase="Pending", Reason="", readiness=false. Elapsed: 8.32181833s
Aug 17 16:31:49.792: INFO: Pod "ebs-volume-tester-8pqpm": Phase="Pending", Reason="", readiness=false. Elapsed: 10.387719656s
Aug 17 16:31:51.856: INFO: Pod "ebs-volume-tester-8pqpm": Phase="Succeeded", Reason="", readiness=false. Elapsed: 12.452022232s
STEP: Saw pod success
Aug 17 16:31:51.856: INFO: Pod "ebs-volume-tester-8pqpm" satisfied condition "Succeeded or Failed"
Aug 17 16:31:51.856: INFO: deleting Pod "ebs-8111"/"ebs-volume-tester-8pqpm"
Aug 17 16:31:51.920: INFO: Pod ebs-volume-tester-8pqpm has the following logs: hello world

STEP: Deleting pod ebs-volume-tester-8pqpm in namespace ebs-8111
Aug 17 16:31:51.989: INFO: deleting PVC "ebs-8111"/"pvc-8g5xh"
Aug 17 16:31:51.989: INFO: Deleting PersistentVolumeClaim "pvc-8g5xh"
... skipping 44 lines ...
Aug 17 16:31:52.130: INFO: PersistentVolumeClaim pvc-pgnqs found but phase is Pending instead of Bound.
Aug 17 16:31:54.198: INFO: PersistentVolumeClaim pvc-pgnqs found and phase=Bound (4.197723363s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pods command exits with no error
Aug 17 16:31:54.399: INFO: Waiting up to 15m0s for pod "ebs-volume-tester-768fj" in namespace "ebs-5188" to be "Succeeded or Failed"
Aug 17 16:31:54.465: INFO: Pod "ebs-volume-tester-768fj": Phase="Pending", Reason="", readiness=false. Elapsed: 65.640659ms
Aug 17 16:31:56.533: INFO: Pod "ebs-volume-tester-768fj": Phase="Pending", Reason="", readiness=false. Elapsed: 2.133463091s
Aug 17 16:31:58.599: INFO: Pod "ebs-volume-tester-768fj": Phase="Pending", Reason="", readiness=false. Elapsed: 4.199542757s
Aug 17 16:32:00.665: INFO: Pod "ebs-volume-tester-768fj": Phase="Succeeded", Reason="", readiness=false. Elapsed: 6.265959231s
STEP: Saw pod success
Aug 17 16:32:00.666: INFO: Pod "ebs-volume-tester-768fj" satisfied condition "Succeeded or Failed"
Aug 17 16:32:00.666: INFO: deleting Pod "ebs-5188"/"ebs-volume-tester-768fj"
Aug 17 16:32:00.732: INFO: Pod ebs-volume-tester-768fj has the following logs: hello world

STEP: Deleting pod ebs-volume-tester-768fj in namespace ebs-5188
Aug 17 16:32:00.805: INFO: deleting PVC "ebs-5188"/"pvc-pgnqs"
Aug 17 16:32:00.805: INFO: Deleting PersistentVolumeClaim "pvc-pgnqs"
... skipping 95 lines ...
Aug 17 16:32:10.230: INFO: PersistentVolumeClaim pvc-tldk7 found but phase is Pending instead of Bound.
Aug 17 16:32:12.294: INFO: PersistentVolumeClaim pvc-tldk7 found and phase=Bound (4.191470153s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pods command exits with an error
Aug 17 16:32:12.489: INFO: Waiting up to 15m0s for pod "ebs-volume-tester-q89kh" in namespace "ebs-9063" to be "Error status code"
Aug 17 16:32:12.552: INFO: Pod "ebs-volume-tester-q89kh": Phase="Pending", Reason="", readiness=false. Elapsed: 63.107469ms
Aug 17 16:32:14.616: INFO: Pod "ebs-volume-tester-q89kh": Phase="Pending", Reason="", readiness=false. Elapsed: 2.127073647s
Aug 17 16:32:16.686: INFO: Pod "ebs-volume-tester-q89kh": Phase="Pending", Reason="", readiness=false. Elapsed: 4.197535949s
Aug 17 16:32:18.751: INFO: Pod "ebs-volume-tester-q89kh": Phase="Pending", Reason="", readiness=false. Elapsed: 6.262514886s
Aug 17 16:32:20.816: INFO: Pod "ebs-volume-tester-q89kh": Phase="Pending", Reason="", readiness=false. Elapsed: 8.327273392s
Aug 17 16:32:22.880: INFO: Pod "ebs-volume-tester-q89kh": Phase="Failed", Reason="", readiness=false. Elapsed: 10.39179019s
STEP: Saw pod failure
Aug 17 16:32:22.881: INFO: Pod "ebs-volume-tester-q89kh" satisfied condition "Error status code"
STEP: checking that pod logs contain expected message
Aug 17 16:32:22.945: INFO: deleting Pod "ebs-9063"/"ebs-volume-tester-q89kh"
Aug 17 16:32:23.010: INFO: Pod ebs-volume-tester-q89kh has the following logs: touch: /mnt/test-1/data: Read-only file system

STEP: Deleting pod ebs-volume-tester-q89kh in namespace ebs-9063
Aug 17 16:32:23.078: INFO: deleting PVC "ebs-9063"/"pvc-tldk7"
... skipping 45 lines ...
Aug 17 16:32:32.116: INFO: PersistentVolumeClaim pvc-r7kzj found but phase is Pending instead of Bound.
Aug 17 16:32:34.182: INFO: PersistentVolumeClaim pvc-r7kzj found and phase=Bound (4.200719142s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pods command exits with no error
Aug 17 16:32:34.384: INFO: Waiting up to 15m0s for pod "ebs-volume-tester-t54ct" in namespace "ebs-6367" to be "Succeeded or Failed"
Aug 17 16:32:34.474: INFO: Pod "ebs-volume-tester-t54ct": Phase="Pending", Reason="", readiness=false. Elapsed: 90.134253ms
Aug 17 16:32:36.540: INFO: Pod "ebs-volume-tester-t54ct": Phase="Pending", Reason="", readiness=false. Elapsed: 2.156665892s
Aug 17 16:32:38.606: INFO: Pod "ebs-volume-tester-t54ct": Phase="Pending", Reason="", readiness=false. Elapsed: 4.222890617s
Aug 17 16:32:40.672: INFO: Pod "ebs-volume-tester-t54ct": Phase="Succeeded", Reason="", readiness=false. Elapsed: 6.288705286s
STEP: Saw pod success
Aug 17 16:32:40.672: INFO: Pod "ebs-volume-tester-t54ct" satisfied condition "Succeeded or Failed"
Aug 17 16:32:40.672: INFO: deleting Pod "ebs-6367"/"ebs-volume-tester-t54ct"
Aug 17 16:32:40.742: INFO: Pod ebs-volume-tester-t54ct has the following logs: hello world

STEP: Deleting pod ebs-volume-tester-t54ct in namespace ebs-6367
Aug 17 16:32:40.814: INFO: deleting PVC "ebs-6367"/"pvc-r7kzj"
Aug 17 16:32:40.814: INFO: Deleting PersistentVolumeClaim "pvc-r7kzj"
... skipping 42 lines ...
Aug 17 16:32:08.464: INFO: PersistentVolumeClaim pvc-swpmm found but phase is Pending instead of Bound.
Aug 17 16:32:10.532: INFO: PersistentVolumeClaim pvc-swpmm found and phase=Bound (4.200660142s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pods command exits with no error
Aug 17 16:32:10.731: INFO: Waiting up to 15m0s for pod "ebs-volume-tester-f9zjq" in namespace "ebs-8351" to be "Succeeded or Failed"
Aug 17 16:32:10.799: INFO: Pod "ebs-volume-tester-f9zjq": Phase="Pending", Reason="", readiness=false. Elapsed: 67.939998ms
Aug 17 16:32:12.866: INFO: Pod "ebs-volume-tester-f9zjq": Phase="Pending", Reason="", readiness=false. Elapsed: 2.134170924s
Aug 17 16:32:14.935: INFO: Pod "ebs-volume-tester-f9zjq": Phase="Pending", Reason="", readiness=false. Elapsed: 4.203585793s
Aug 17 16:32:17.001: INFO: Pod "ebs-volume-tester-f9zjq": Phase="Pending", Reason="", readiness=false. Elapsed: 6.26962398s
Aug 17 16:32:19.069: INFO: Pod "ebs-volume-tester-f9zjq": Phase="Pending", Reason="", readiness=false. Elapsed: 8.337139211s
Aug 17 16:32:21.135: INFO: Pod "ebs-volume-tester-f9zjq": Phase="Succeeded", Reason="", readiness=false. Elapsed: 10.403659264s
STEP: Saw pod success
Aug 17 16:32:21.135: INFO: Pod "ebs-volume-tester-f9zjq" satisfied condition "Succeeded or Failed"
Aug 17 16:32:21.135: INFO: deleting Pod "ebs-8351"/"ebs-volume-tester-f9zjq"
Aug 17 16:32:21.202: INFO: Pod ebs-volume-tester-f9zjq has the following logs: hello world

STEP: Deleting pod ebs-volume-tester-f9zjq in namespace ebs-8351
Aug 17 16:32:21.279: INFO: deleting PVC "ebs-8351"/"pvc-swpmm"
Aug 17 16:32:21.279: INFO: Deleting PersistentVolumeClaim "pvc-swpmm"
... skipping 46 lines ...
Aug 17 16:32:41.253: INFO: PersistentVolumeClaim pvc-t9jhd found but phase is Pending instead of Bound.
Aug 17 16:32:43.318: INFO: PersistentVolumeClaim pvc-t9jhd found and phase=Bound (4.19516246s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pods command exits with no error
Aug 17 16:32:43.514: INFO: Waiting up to 15m0s for pod "ebs-volume-tester-lqh5z" in namespace "ebs-3575" to be "Succeeded or Failed"
Aug 17 16:32:43.577: INFO: Pod "ebs-volume-tester-lqh5z": Phase="Pending", Reason="", readiness=false. Elapsed: 63.562704ms
Aug 17 16:32:45.642: INFO: Pod "ebs-volume-tester-lqh5z": Phase="Pending", Reason="", readiness=false. Elapsed: 2.12807377s
Aug 17 16:32:47.706: INFO: Pod "ebs-volume-tester-lqh5z": Phase="Pending", Reason="", readiness=false. Elapsed: 4.192186993s
Aug 17 16:32:49.775: INFO: Pod "ebs-volume-tester-lqh5z": Phase="Succeeded", Reason="", readiness=false. Elapsed: 6.261361209s
STEP: Saw pod success
Aug 17 16:32:49.775: INFO: Pod "ebs-volume-tester-lqh5z" satisfied condition "Succeeded or Failed"
Aug 17 16:32:49.775: INFO: deleting Pod "ebs-3575"/"ebs-volume-tester-lqh5z"
Aug 17 16:32:49.840: INFO: Pod ebs-volume-tester-lqh5z has the following logs: hello world

STEP: Deleting pod ebs-volume-tester-lqh5z in namespace ebs-3575
Aug 17 16:32:49.918: INFO: deleting PVC "ebs-3575"/"pvc-t9jhd"
Aug 17 16:32:49.918: INFO: Deleting PersistentVolumeClaim "pvc-t9jhd"
... skipping 95 lines ...
Aug 17 16:33:02.084: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-jhktt] to have phase Bound
Aug 17 16:33:02.149: INFO: PersistentVolumeClaim pvc-jhktt found and phase=Bound (65.70775ms)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pods command exits with no error
Aug 17 16:33:02.349: INFO: Waiting up to 15m0s for pod "ebs-volume-tester-hnqjg" in namespace "ebs-6182" to be "Succeeded or Failed"
Aug 17 16:33:02.416: INFO: Pod "ebs-volume-tester-hnqjg": Phase="Pending", Reason="", readiness=false. Elapsed: 66.221403ms
Aug 17 16:33:04.484: INFO: Pod "ebs-volume-tester-hnqjg": Phase="Pending", Reason="", readiness=false. Elapsed: 2.134233275s
Aug 17 16:33:06.550: INFO: Pod "ebs-volume-tester-hnqjg": Phase="Pending", Reason="", readiness=false. Elapsed: 4.200772969s
Aug 17 16:33:08.618: INFO: Pod "ebs-volume-tester-hnqjg": Phase="Pending", Reason="", readiness=false. Elapsed: 6.268397491s
Aug 17 16:33:10.684: INFO: Pod "ebs-volume-tester-hnqjg": Phase="Pending", Reason="", readiness=false. Elapsed: 8.334450879s
Aug 17 16:33:12.751: INFO: Pod "ebs-volume-tester-hnqjg": Phase="Succeeded", Reason="", readiness=false. Elapsed: 10.401347929s
STEP: Saw pod success
Aug 17 16:33:12.751: INFO: Pod "ebs-volume-tester-hnqjg" satisfied condition "Succeeded or Failed"
Aug 17 16:33:12.751: INFO: deleting Pod "ebs-6182"/"ebs-volume-tester-hnqjg"
Aug 17 16:33:12.818: INFO: Pod ebs-volume-tester-hnqjg has the following logs: hello world

STEP: Deleting pod ebs-volume-tester-hnqjg in namespace ebs-6182
Aug 17 16:33:12.895: INFO: deleting PVC "ebs-6182"/"pvc-jhktt"
Aug 17 16:33:12.895: INFO: Deleting PersistentVolumeClaim "pvc-jhktt"
... skipping 47 lines ...
Aug 17 16:33:03.140: INFO: PersistentVolumeClaim pvc-nxdld found but phase is Pending instead of Bound.
Aug 17 16:33:05.205: INFO: PersistentVolumeClaim pvc-nxdld found and phase=Bound (8.329521582s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pods command exits with no error
Aug 17 16:33:05.405: INFO: Waiting up to 15m0s for pod "ebs-volume-tester-gnb9l" in namespace "ebs-3401" to be "Succeeded or Failed"
Aug 17 16:33:05.471: INFO: Pod "ebs-volume-tester-gnb9l": Phase="Pending", Reason="", readiness=false. Elapsed: 66.249213ms
Aug 17 16:33:07.537: INFO: Pod "ebs-volume-tester-gnb9l": Phase="Pending", Reason="", readiness=false. Elapsed: 2.13203022s
Aug 17 16:33:09.603: INFO: Pod "ebs-volume-tester-gnb9l": Phase="Pending", Reason="", readiness=false. Elapsed: 4.197558085s
Aug 17 16:33:11.670: INFO: Pod "ebs-volume-tester-gnb9l": Phase="Succeeded", Reason="", readiness=false. Elapsed: 6.265404475s
STEP: Saw pod success
Aug 17 16:33:11.670: INFO: Pod "ebs-volume-tester-gnb9l" satisfied condition "Succeeded or Failed"
Aug 17 16:33:11.670: INFO: deleting Pod "ebs-3401"/"ebs-volume-tester-gnb9l"
Aug 17 16:33:11.737: INFO: Pod ebs-volume-tester-gnb9l has the following logs: hello world

STEP: Deleting pod ebs-volume-tester-gnb9l in namespace ebs-3401
Aug 17 16:33:11.814: INFO: deleting PVC "ebs-3401"/"pvc-nxdld"
Aug 17 16:33:11.814: INFO: Deleting PersistentVolumeClaim "pvc-nxdld"
... skipping 58 lines ...
Aug 17 16:33:18.237: INFO: PersistentVolumeClaim pvc-s5lch found but phase is Pending instead of Bound.
Aug 17 16:33:20.302: INFO: PersistentVolumeClaim pvc-s5lch found and phase=Bound (4.193662761s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pods command exits with no error
Aug 17 16:33:20.494: INFO: Waiting up to 15m0s for pod "ebs-volume-tester-b88tb" in namespace "ebs-1831" to be "Succeeded or Failed"
Aug 17 16:33:20.557: INFO: Pod "ebs-volume-tester-b88tb": Phase="Pending", Reason="", readiness=false. Elapsed: 63.311161ms
Aug 17 16:33:22.621: INFO: Pod "ebs-volume-tester-b88tb": Phase="Pending", Reason="", readiness=false. Elapsed: 2.126570141s
Aug 17 16:33:24.684: INFO: Pod "ebs-volume-tester-b88tb": Phase="Pending", Reason="", readiness=false. Elapsed: 4.190081291s
Aug 17 16:33:26.748: INFO: Pod "ebs-volume-tester-b88tb": Phase="Pending", Reason="", readiness=false. Elapsed: 6.253898023s
Aug 17 16:33:28.813: INFO: Pod "ebs-volume-tester-b88tb": Phase="Pending", Reason="", readiness=false. Elapsed: 8.318953623s
Aug 17 16:33:30.877: INFO: Pod "ebs-volume-tester-b88tb": Phase="Pending", Reason="", readiness=false. Elapsed: 10.383146293s
Aug 17 16:33:32.943: INFO: Pod "ebs-volume-tester-b88tb": Phase="Succeeded", Reason="", readiness=false. Elapsed: 12.448698003s
STEP: Saw pod success
Aug 17 16:33:32.943: INFO: Pod "ebs-volume-tester-b88tb" satisfied condition "Succeeded or Failed"
Aug 17 16:33:32.943: INFO: deleting Pod "ebs-1831"/"ebs-volume-tester-b88tb"
Aug 17 16:33:33.009: INFO: Pod ebs-volume-tester-b88tb has the following logs: hello world
hello world

STEP: Deleting pod ebs-volume-tester-b88tb in namespace ebs-1831
Aug 17 16:33:33.085: INFO: deleting PVC "ebs-1831"/"pvc-s5lch"
... skipping 52 lines ...
Aug 17 16:33:50.270: INFO: PersistentVolumeClaim pvc-x8gc4 found but phase is Pending instead of Bound.
Aug 17 16:33:52.342: INFO: PersistentVolumeClaim pvc-x8gc4 found and phase=Bound (4.20232243s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pods command exits with no error
Aug 17 16:33:52.542: INFO: Waiting up to 15m0s for pod "ebs-volume-tester-pvt7d" in namespace "ebs-1468" to be "Succeeded or Failed"
Aug 17 16:33:52.607: INFO: Pod "ebs-volume-tester-pvt7d": Phase="Pending", Reason="", readiness=false. Elapsed: 64.666266ms
Aug 17 16:33:54.677: INFO: Pod "ebs-volume-tester-pvt7d": Phase="Pending", Reason="", readiness=false. Elapsed: 2.134762068s
Aug 17 16:33:56.744: INFO: Pod "ebs-volume-tester-pvt7d": Phase="Pending", Reason="", readiness=false. Elapsed: 4.201648951s
Aug 17 16:33:58.810: INFO: Pod "ebs-volume-tester-pvt7d": Phase="Pending", Reason="", readiness=false. Elapsed: 6.267894234s
Aug 17 16:34:00.877: INFO: Pod "ebs-volume-tester-pvt7d": Phase="Pending", Reason="", readiness=false. Elapsed: 8.334502648s
Aug 17 16:34:02.943: INFO: Pod "ebs-volume-tester-pvt7d": Phase="Succeeded", Reason="", readiness=false. Elapsed: 10.400917671s
STEP: Saw pod success
Aug 17 16:34:02.943: INFO: Pod "ebs-volume-tester-pvt7d" satisfied condition "Succeeded or Failed"
Aug 17 16:34:02.943: INFO: deleting Pod "ebs-1468"/"ebs-volume-tester-pvt7d"
Aug 17 16:34:03.010: INFO: Pod ebs-volume-tester-pvt7d has the following logs: hello world

STEP: Deleting pod ebs-volume-tester-pvt7d in namespace ebs-1468
Aug 17 16:34:03.086: INFO: deleting PVC "ebs-1468"/"pvc-x8gc4"
Aug 17 16:34:03.087: INFO: Deleting PersistentVolumeClaim "pvc-x8gc4"
... skipping 98 lines ...
Aug 17 16:33:56.577: INFO: PersistentVolumeClaim pvc-mh275 found but phase is Pending instead of Bound.
Aug 17 16:33:58.641: INFO: PersistentVolumeClaim pvc-mh275 found and phase=Bound (4.191327051s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pods command exits with no error
Aug 17 16:33:58.833: INFO: Waiting up to 15m0s for pod "ebs-volume-tester-nqvf6" in namespace "ebs-1937" to be "Succeeded or Failed"
Aug 17 16:33:58.897: INFO: Pod "ebs-volume-tester-nqvf6": Phase="Pending", Reason="", readiness=false. Elapsed: 63.860446ms
Aug 17 16:34:00.961: INFO: Pod "ebs-volume-tester-nqvf6": Phase="Pending", Reason="", readiness=false. Elapsed: 2.127646933s
Aug 17 16:34:03.027: INFO: Pod "ebs-volume-tester-nqvf6": Phase="Pending", Reason="", readiness=false. Elapsed: 4.194206233s
Aug 17 16:34:05.091: INFO: Pod "ebs-volume-tester-nqvf6": Phase="Pending", Reason="", readiness=false. Elapsed: 6.258142822s
Aug 17 16:34:07.156: INFO: Pod "ebs-volume-tester-nqvf6": Phase="Pending", Reason="", readiness=false. Elapsed: 8.322719471s
Aug 17 16:34:09.221: INFO: Pod "ebs-volume-tester-nqvf6": Phase="Pending", Reason="", readiness=false. Elapsed: 10.387568815s
Aug 17 16:34:11.287: INFO: Pod "ebs-volume-tester-nqvf6": Phase="Pending", Reason="", readiness=false. Elapsed: 12.453293458s
Aug 17 16:34:13.351: INFO: Pod "ebs-volume-tester-nqvf6": Phase="Pending", Reason="", readiness=false. Elapsed: 14.517324646s
Aug 17 16:34:15.415: INFO: Pod "ebs-volume-tester-nqvf6": Phase="Pending", Reason="", readiness=false. Elapsed: 16.581477436s
Aug 17 16:34:17.479: INFO: Pod "ebs-volume-tester-nqvf6": Phase="Succeeded", Reason="", readiness=false. Elapsed: 18.645434348s
STEP: Saw pod success
Aug 17 16:34:17.479: INFO: Pod "ebs-volume-tester-nqvf6" satisfied condition "Succeeded or Failed"
Aug 17 16:34:17.479: INFO: deleting Pod "ebs-1937"/"ebs-volume-tester-nqvf6"
Aug 17 16:34:17.544: INFO: Pod ebs-volume-tester-nqvf6 has the following logs: hello world

STEP: Deleting pod ebs-volume-tester-nqvf6 in namespace ebs-1937
Aug 17 16:34:17.612: INFO: deleting PVC "ebs-1937"/"pvc-mh275"
Aug 17 16:34:17.612: INFO: Deleting PersistentVolumeClaim "pvc-mh275"
... skipping 53 lines ...
Aug 17 16:34:31.077: INFO: PersistentVolumeClaim pvc-dmqws found but phase is Pending instead of Bound.
Aug 17 16:34:33.147: INFO: PersistentVolumeClaim pvc-dmqws found and phase=Bound (4.205135335s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pods command exits with no error
Aug 17 16:34:33.362: INFO: Waiting up to 15m0s for pod "ebs-volume-tester-bmvxl" in namespace "ebs-5652" to be "Succeeded or Failed"
Aug 17 16:34:33.430: INFO: Pod "ebs-volume-tester-bmvxl": Phase="Pending", Reason="", readiness=false. Elapsed: 68.575029ms
Aug 17 16:34:35.497: INFO: Pod "ebs-volume-tester-bmvxl": Phase="Pending", Reason="", readiness=false. Elapsed: 2.134867811s
Aug 17 16:34:37.563: INFO: Pod "ebs-volume-tester-bmvxl": Phase="Pending", Reason="", readiness=false. Elapsed: 4.201626313s
Aug 17 16:34:39.629: INFO: Pod "ebs-volume-tester-bmvxl": Phase="Pending", Reason="", readiness=false. Elapsed: 6.267565032s
Aug 17 16:34:41.695: INFO: Pod "ebs-volume-tester-bmvxl": Phase="Pending", Reason="", readiness=false. Elapsed: 8.333635441s
Aug 17 16:34:43.765: INFO: Pod "ebs-volume-tester-bmvxl": Phase="Pending", Reason="", readiness=false. Elapsed: 10.40373562s
Aug 17 16:34:45.832: INFO: Pod "ebs-volume-tester-bmvxl": Phase="Succeeded", Reason="", readiness=false. Elapsed: 12.469868581s
STEP: Saw pod success
Aug 17 16:34:45.832: INFO: Pod "ebs-volume-tester-bmvxl" satisfied condition "Succeeded or Failed"
Aug 17 16:34:45.832: INFO: deleting Pod "ebs-5652"/"ebs-volume-tester-bmvxl"
Aug 17 16:34:45.899: INFO: Pod ebs-volume-tester-bmvxl has the following logs: 100+0 records in
100+0 records out
104857600 bytes (100.0MB) copied, 0.048589 seconds, 2.0GB/s
hello world

... skipping 196 lines ...
Aug 17 16:35:19.729: INFO: PersistentVolumeClaim pvc-p7ch9 found but phase is Pending instead of Bound.
Aug 17 16:35:21.795: INFO: PersistentVolumeClaim pvc-p7ch9 found and phase=Bound (4.196460055s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pods command exits with no error
Aug 17 16:35:21.993: INFO: Waiting up to 15m0s for pod "ebs-volume-tester-54n7t" in namespace "ebs-804" to be "Succeeded or Failed"
Aug 17 16:35:22.059: INFO: Pod "ebs-volume-tester-54n7t": Phase="Pending", Reason="", readiness=false. Elapsed: 65.439511ms
Aug 17 16:35:24.130: INFO: Pod "ebs-volume-tester-54n7t": Phase="Pending", Reason="", readiness=false. Elapsed: 2.136505753s
Aug 17 16:35:26.196: INFO: Pod "ebs-volume-tester-54n7t": Phase="Pending", Reason="", readiness=false. Elapsed: 4.202537612s
Aug 17 16:35:28.262: INFO: Pod "ebs-volume-tester-54n7t": Phase="Pending", Reason="", readiness=false. Elapsed: 6.26907705s
Aug 17 16:35:30.328: INFO: Pod "ebs-volume-tester-54n7t": Phase="Pending", Reason="", readiness=false. Elapsed: 8.334474867s
Aug 17 16:35:32.396: INFO: Pod "ebs-volume-tester-54n7t": Phase="Succeeded", Reason="", readiness=false. Elapsed: 10.402594652s
STEP: Saw pod success
Aug 17 16:35:32.396: INFO: Pod "ebs-volume-tester-54n7t" satisfied condition "Succeeded or Failed"
Aug 17 16:35:32.396: INFO: deleting Pod "ebs-804"/"ebs-volume-tester-54n7t"
Aug 17 16:35:32.464: INFO: Pod ebs-volume-tester-54n7t has the following logs: hello world

STEP: Deleting pod ebs-volume-tester-54n7t in namespace ebs-804
Aug 17 16:35:32.542: INFO: deleting PVC "ebs-804"/"pvc-p7ch9"
Aug 17 16:35:32.543: INFO: Deleting PersistentVolumeClaim "pvc-p7ch9"
... skipping 43 lines ...
Aug 17 16:35:37.476: INFO: PersistentVolumeClaim pvc-shb4x found but phase is Pending instead of Bound.
Aug 17 16:35:39.542: INFO: PersistentVolumeClaim pvc-shb4x found and phase=Bound (4.198002316s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pods command exits with no error
Aug 17 16:35:39.747: INFO: Waiting up to 15m0s for pod "ebs-volume-tester-6zr6x" in namespace "ebs-7102" to be "Succeeded or Failed"
Aug 17 16:35:39.814: INFO: Pod "ebs-volume-tester-6zr6x": Phase="Pending", Reason="", readiness=false. Elapsed: 67.221892ms
Aug 17 16:35:41.881: INFO: Pod "ebs-volume-tester-6zr6x": Phase="Pending", Reason="", readiness=false. Elapsed: 2.134318298s
Aug 17 16:35:43.949: INFO: Pod "ebs-volume-tester-6zr6x": Phase="Pending", Reason="", readiness=false. Elapsed: 4.202658729s
Aug 17 16:35:46.017: INFO: Pod "ebs-volume-tester-6zr6x": Phase="Pending", Reason="", readiness=false. Elapsed: 6.270180377s
Aug 17 16:35:48.084: INFO: Pod "ebs-volume-tester-6zr6x": Phase="Pending", Reason="", readiness=false. Elapsed: 8.337769701s
Aug 17 16:35:50.163: INFO: Pod "ebs-volume-tester-6zr6x": Phase="Succeeded", Reason="", readiness=false. Elapsed: 10.415965879s
STEP: Saw pod success
Aug 17 16:35:50.163: INFO: Pod "ebs-volume-tester-6zr6x" satisfied condition "Succeeded or Failed"
Aug 17 16:35:50.163: INFO: deleting Pod "ebs-7102"/"ebs-volume-tester-6zr6x"
Aug 17 16:35:50.234: INFO: Pod ebs-volume-tester-6zr6x has the following logs: 100+0 records in
100+0 records out
104857600 bytes (100.0MB) copied, 0.048133 seconds, 2.0GB/s

STEP: Deleting pod ebs-volume-tester-6zr6x in namespace ebs-7102
... skipping 44 lines ...
Aug 17 16:36:08.533: INFO: PersistentVolumeClaim pvc-2mxls found but phase is Pending instead of Bound.
Aug 17 16:36:10.600: INFO: PersistentVolumeClaim pvc-2mxls found and phase=Bound (4.205189145s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pods command exits with no error
Aug 17 16:36:10.805: INFO: Waiting up to 15m0s for pod "ebs-volume-tester-zv9sk" in namespace "ebs-5163" to be "Succeeded or Failed"
Aug 17 16:36:10.896: INFO: Pod "ebs-volume-tester-zv9sk": Phase="Pending", Reason="", readiness=false. Elapsed: 90.078655ms
Aug 17 16:36:12.963: INFO: Pod "ebs-volume-tester-zv9sk": Phase="Pending", Reason="", readiness=false. Elapsed: 2.15754148s
Aug 17 16:36:15.045: INFO: Pod "ebs-volume-tester-zv9sk": Phase="Pending", Reason="", readiness=false. Elapsed: 4.239544608s
Aug 17 16:36:17.112: INFO: Pod "ebs-volume-tester-zv9sk": Phase="Pending", Reason="", readiness=false. Elapsed: 6.306492937s
Aug 17 16:36:19.180: INFO: Pod "ebs-volume-tester-zv9sk": Phase="Pending", Reason="", readiness=false. Elapsed: 8.37403273s
Aug 17 16:36:21.247: INFO: Pod "ebs-volume-tester-zv9sk": Phase="Succeeded", Reason="", readiness=false. Elapsed: 10.441626989s
STEP: Saw pod success
Aug 17 16:36:21.247: INFO: Pod "ebs-volume-tester-zv9sk" satisfied condition "Succeeded or Failed"
Aug 17 16:36:21.247: INFO: deleting Pod "ebs-5163"/"ebs-volume-tester-zv9sk"
Aug 17 16:36:21.323: INFO: Pod ebs-volume-tester-zv9sk has the following logs: hello world

STEP: Deleting pod ebs-volume-tester-zv9sk in namespace ebs-5163
Aug 17 16:36:21.399: INFO: deleting PVC "ebs-5163"/"pvc-2mxls"
Aug 17 16:36:21.399: INFO: Deleting PersistentVolumeClaim "pvc-2mxls"
... skipping 43 lines ...
Aug 17 16:34:30.706: INFO: PersistentVolumeClaim pvc-p8x9s found but phase is Pending instead of Bound.
Aug 17 16:34:32.770: INFO: PersistentVolumeClaim pvc-p8x9s found and phase=Bound (4.190622662s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying the pod
STEP: checking that the pods command exits with no error
Aug 17 16:34:32.963: INFO: Waiting up to 15m0s for pod "ebs-volume-tester-sd8vr" in namespace "ebs-2534" to be "Succeeded or Failed"
Aug 17 16:34:33.026: INFO: Pod "ebs-volume-tester-sd8vr": Phase="Pending", Reason="", readiness=false. Elapsed: 63.888554ms
Aug 17 16:34:35.091: INFO: Pod "ebs-volume-tester-sd8vr": Phase="Pending", Reason="", readiness=false. Elapsed: 2.128181453s
Aug 17 16:34:37.155: INFO: Pod "ebs-volume-tester-sd8vr": Phase="Pending", Reason="", readiness=false. Elapsed: 4.192029055s
Aug 17 16:34:39.220: INFO: Pod "ebs-volume-tester-sd8vr": Phase="Pending", Reason="", readiness=false. Elapsed: 6.257181444s
Aug 17 16:34:41.285: INFO: Pod "ebs-volume-tester-sd8vr": Phase="Pending", Reason="", readiness=false. Elapsed: 8.32222782s
Aug 17 16:34:43.348: INFO: Pod "ebs-volume-tester-sd8vr": Phase="Running", Reason="", readiness=true. Elapsed: 10.385848691s
Aug 17 16:34:45.421: INFO: Pod "ebs-volume-tester-sd8vr": Phase="Succeeded", Reason="", readiness=false. Elapsed: 12.458545313s
STEP: Saw pod success
Aug 17 16:34:45.421: INFO: Pod "ebs-volume-tester-sd8vr" satisfied condition "Succeeded or Failed"
STEP: taking snapshots
STEP: setting up the VolumeSnapshotClass
STEP: creating a VolumeSnapshotClass
STEP: creating a VolumeSnapshot for pvc-p8x9s
STEP: waiting for VolumeSnapshot to be ready to use - volume-snapshot-kf5nd
STEP: setting up the StorageClass
... skipping 7 lines ...
Aug 17 16:35:47.884: INFO: PersistentVolumeClaim pvc-s28mn found but phase is Pending instead of Bound.
Aug 17 16:35:49.947: INFO: PersistentVolumeClaim pvc-s28mn found and phase=Bound (4.192960495s)
STEP: checking the PVC
STEP: validating provisioned PV
STEP: checking the PV
STEP: deploying a second pod with a volume restored from the snapshot
STEP: checking that the pods command exits with no error
Aug 17 16:35:50.141: INFO: Waiting up to 15m0s for pod "ebs-volume-tester-bscq4" in namespace "ebs-2534" to be "Succeeded or Failed"
Aug 17 16:35:50.205: INFO: Pod "ebs-volume-tester-bscq4": Phase="Pending", Reason="", readiness=false. Elapsed: 63.618967ms
Aug 17 16:35:52.269: INFO: Pod "ebs-volume-tester-bscq4": Phase="Pending", Reason="", readiness=false. Elapsed: 2.127747809s
Aug 17 16:35:54.333: INFO: Pod "ebs-volume-tester-bscq4": Phase="Pending", Reason="", readiness=false. Elapsed: 4.191981811s
Aug 17 16:35:56.397: INFO: Pod "ebs-volume-tester-bscq4": Phase="Pending", Reason="", readiness=false. Elapsed: 6.255865716s
Aug 17 16:35:58.464: INFO: Pod "ebs-volume-tester-bscq4": Phase="Pending", Reason="", readiness=false. Elapsed: 8.323271225s
Aug 17 16:36:00.528: INFO: Pod "ebs-volume-tester-bscq4": Phase="Succeeded", Reason="", readiness=false. Elapsed: 10.387214522s
STEP: Saw pod success
Aug 17 16:36:00.528: INFO: Pod "ebs-volume-tester-bscq4" satisfied condition "Succeeded or Failed"
Aug 17 16:36:00.528: INFO: deleting Pod "ebs-2534"/"ebs-volume-tester-bscq4"
Aug 17 16:36:00.595: INFO: Pod ebs-volume-tester-bscq4 has the following logs: hello world

STEP: Deleting pod ebs-volume-tester-bscq4 in namespace ebs-2534
Aug 17 16:36:00.676: INFO: deleting PVC "ebs-2534"/"pvc-s28mn"
Aug 17 16:36:00.676: INFO: Deleting PersistentVolumeClaim "pvc-s28mn"
... skipping 144 lines ...
STEP: setting up the StorageClass
STEP: creating a StorageClass 
STEP: setting up the PVC and PV
STEP: Create tpvc with data source
STEP: creating a PVC
STEP: deploying a second pod with a volume restored from the snapshot
STEP: checking that the pods command exits with no error
Aug 17 16:31:41.262: INFO: Waiting up to 15m0s for pod "ebs-volume-tester-2ns74" in namespace "ebs-4081" to be "Succeeded or Failed"
Aug 17 16:31:41.327: INFO: Pod "ebs-volume-tester-2ns74": Phase="Pending", Reason="", readiness=false. Elapsed: 64.624958ms
Aug 17 16:31:43.393: INFO: Pod "ebs-volume-tester-2ns74": Phase="Pending", Reason="", readiness=false. Elapsed: 2.131069072s
Aug 17 16:31:45.459: INFO: Pod "ebs-volume-tester-2ns74": Phase="Pending", Reason="", readiness=false. Elapsed: 4.197304952s
Aug 17 16:31:47.525: INFO: Pod "ebs-volume-tester-2ns74": Phase="Pending", Reason="", readiness=false. Elapsed: 6.263377517s
Aug 17 16:31:49.592: INFO: Pod "ebs-volume-tester-2ns74": Phase="Pending", Reason="", readiness=false. Elapsed: 8.330557659s
Aug 17 16:31:51.663: INFO: Pod "ebs-volume-tester-2ns74": Phase="Pending", Reason="", readiness=false. Elapsed: 10.400877498s
... skipping 395 lines ...
Aug 17 16:45:30.349: INFO: Pod "ebs-volume-tester-2ns74": Phase="Pending", Reason="", readiness=false. Elapsed: 13m49.08669664s
Aug 17 16:45:32.417: INFO: Pod "ebs-volume-tester-2ns74": Phase="Pending", Reason="", readiness=false. Elapsed: 13m51.15473623s
Aug 17 16:45:34.484: INFO: Pod "ebs-volume-tester-2ns74": Phase="Pending", Reason="", readiness=false. Elapsed: 13m53.222294799s
Aug 17 16:45:36.551: INFO: Pod "ebs-volume-tester-2ns74": Phase="Pending", Reason="", readiness=false. Elapsed: 13m55.288969252s
Aug 17 16:45:38.618: INFO: Pod "ebs-volume-tester-2ns74": Phase="Succeeded", Reason="", readiness=false. Elapsed: 13m57.355627038s
STEP: Saw pod success
Aug 17 16:45:38.618: INFO: Pod "ebs-volume-tester-2ns74" satisfied condition "Succeeded or Failed"
Aug 17 16:45:38.618: INFO: deleting Pod "ebs-4081"/"ebs-volume-tester-2ns74"
Aug 17 16:45:38.718: INFO: Pod ebs-volume-tester-2ns74 has the following logs: hello world

STEP: Deleting pod ebs-volume-tester-2ns74 in namespace ebs-4081
Aug 17 16:45:38.796: INFO: deleting PVC "ebs-4081"/"pvc-vsndf"
Aug 17 16:45:38.796: INFO: Deleting PersistentVolumeClaim "pvc-vsndf"
... skipping 20 lines ...
/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/tests/e2e/pre_provsioning.go:52
  [env] should use a pre-defined snapshot and create pv from that
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/tests/e2e/pre_provsioning.go:154
------------------------------

Ran 27 of 33 Specs in 889.422 seconds
SUCCESS! -- 27 Passed | 0 Failed | 0 Pending | 6 Skipped


Ginkgo ran 1 suite in 16m23.446072831s
Test Suite Passed
+ TEST_PASSED=0
+ set -e
... skipping 295 lines ...
  Device: "/dev/xvdbb",
  InstanceId: "i-0106749c1a71ca7f7",
  State: "attaching",
  VolumeId: "vol-05b279258877cdb9c"
}
I0817 16:32:13.318634       1 cloud.go:635] Waiting for volume "vol-05b279258877cdb9c" state: actual=attaching, desired=attached
E0817 16:32:13.561584       1 manager.go:44] Error releasing device: release on device "/dev/xvdbb" assigned to different volume: "vol-0451e0b948b00b59e" vs "vol-05b279258877cdb9c"
I0817 16:32:13.561603       1 controller.go:388] [Debug] ControllerUnpublishVolume: volume vol-0451e0b948b00b59e detached from node i-0106749c1a71ca7f7
I0817 16:32:14.396368       1 manager.go:197] [Debug] Releasing in-process attachment entry: /dev/xvdbb -> volume vol-05b279258877cdb9c
I0817 16:32:14.396385       1 controller.go:343] [Debug] ControllerPublishVolume: volume vol-05b279258877cdb9c attached to node i-0106749c1a71ca7f7 through device /dev/xvdbb
I0817 16:32:27.098667       1 controller.go:374] ControllerUnpublishVolume: called with args {VolumeId:vol-0e17a1aa3ad654c6b NodeId:i-0106749c1a71ca7f7 Secrets:map[] XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
I0817 16:32:27.109185       1 controller.go:374] ControllerUnpublishVolume: called with args {VolumeId:vol-05b279258877cdb9c NodeId:i-0106749c1a71ca7f7 Secrets:map[] XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
I0817 16:32:27.447420       1 cloud.go:635] Waiting for volume "vol-05b279258877cdb9c" state: actual=detaching, desired=detached
... skipping 46 lines ...
  Device: "/dev/xvdba",
  InstanceId: "i-0106749c1a71ca7f7",
  State: "attaching",
  VolumeId: "vol-0d5f4f3b210bdeb75"
}
I0817 16:33:03.029035       1 cloud.go:635] Waiting for volume "vol-0d5f4f3b210bdeb75" state: actual=attaching, desired=attached
E0817 16:33:03.651194       1 manager.go:44] Error releasing device: release on device "/dev/xvdba" assigned to different volume: "vol-0a3bed2094dc005ad" vs "vol-0d5f4f3b210bdeb75"
I0817 16:33:03.651211       1 controller.go:388] [Debug] ControllerUnpublishVolume: volume vol-0a3bed2094dc005ad detached from node i-0106749c1a71ca7f7
I0817 16:33:04.088977       1 manager.go:197] [Debug] Releasing in-process attachment entry: /dev/xvdba -> volume vol-0d5f4f3b210bdeb75
I0817 16:33:04.088994       1 controller.go:343] [Debug] ControllerPublishVolume: volume vol-0d5f4f3b210bdeb75 attached to node i-0106749c1a71ca7f7 through device /dev/xvdba
I0817 16:33:05.504181       1 controller.go:315] ControllerPublishVolume: called with args {VolumeId:vol-084fd80ded2452dc9 NodeId:i-0106749c1a71ca7f7 VolumeCapability:mount:<fs_type:"ext4" > access_mode:<mode:SINGLE_NODE_WRITER >  Readonly:false Secrets:map[] VolumeContext:map[storage.kubernetes.io/csiProvisionerIdentity:1660753748946-8081-ebs.csi.aws.com] XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
I0817 16:33:06.163677       1 cloud.go:462] [Debug] AttachVolume volume="vol-084fd80ded2452dc9" instance="i-0106749c1a71ca7f7" request returned {
  AttachTime: 2022-08-17 16:33:06.138 +0000 UTC,
... skipping 125 lines ...
  Device: "/dev/xvdbb",
  InstanceId: "i-0106749c1a71ca7f7",
  State: "attaching",
  VolumeId: "vol-0cfe5649f9ae71d3e"
}
I0817 16:34:33.670560       1 cloud.go:635] Waiting for volume "vol-0cfe5649f9ae71d3e" state: actual=attaching, desired=attached
E0817 16:34:33.857426       1 manager.go:44] Error releasing device: release on device "/dev/xvdbb" assigned to different volume: "vol-0b03a965c61e62cee" vs "vol-0cfe5649f9ae71d3e"
I0817 16:34:33.857448       1 controller.go:388] [Debug] ControllerUnpublishVolume: volume vol-0b03a965c61e62cee detached from node i-0106749c1a71ca7f7
I0817 16:34:34.123467       1 cloud.go:462] [Debug] AttachVolume volume="vol-01a95dbaf76580c04" instance="i-0106749c1a71ca7f7" request returned {
  AttachTime: 2022-08-17 16:34:34.098 +0000 UTC,
  Device: "/dev/xvdbc",
  InstanceId: "i-0106749c1a71ca7f7",
  State: "attaching",
... skipping 1652 lines ...