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

Build Still Running!


Show 27 Passed Tests

Show 6 Skipped Tests

Error lines from build-log.txt

... skipping 183 lines ...
|   o.+./S=   .   |
|  . *.B.* o   .  |
| . + B = o . .   |
|  o * * +   .    |
|   ooO+o         |
+----[SHA256]-----+
Error: cluster not found "test-cluster-9837.k8s.local"
###
## Creating cluster test-cluster-9837.k8s.local with /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/hack/e2e/csi-test-artifacts/test-cluster-9837.k8s.local.kops.yaml (dry run)
#
I0816 10:21:57.558328    5643 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
I0816 10:21:58.259937    5643 new_cluster.go:248] Inferred "aws" cloud provider from zone "us-west-2a"
I0816 10:21:58.260037    5643 new_cluster.go:1102]  Cloud Provider ID = aws
... skipping 72 lines ...
## Validating cluster test-cluster-9837.k8s.local
#
Using cluster from kubectl context: test-cluster-9837.k8s.local

Validating cluster test-cluster-9837.k8s.local

W0816 10:22:52.226690    5759 validate_cluster.go:184] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-9837-k8s-cg810k-1825688641.us-west-2.elb.amazonaws.com/api/v1/nodes": dial tcp: lookup api-test-cluster-9837-k8s-cg810k-1825688641.us-west-2.elb.amazonaws.com on 10.63.240.10:53: no such host
W0816 10:23:02.263161    5759 validate_cluster.go:184] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-9837-k8s-cg810k-1825688641.us-west-2.elb.amazonaws.com/api/v1/nodes": dial tcp: lookup api-test-cluster-9837-k8s-cg810k-1825688641.us-west-2.elb.amazonaws.com on 10.63.240.10:53: no such host
W0816 10:23:12.294176    5759 validate_cluster.go:184] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-9837-k8s-cg810k-1825688641.us-west-2.elb.amazonaws.com/api/v1/nodes": dial tcp: lookup api-test-cluster-9837-k8s-cg810k-1825688641.us-west-2.elb.amazonaws.com on 10.63.240.10:53: no such host
W0816 10:23:22.325966    5759 validate_cluster.go:184] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-9837-k8s-cg810k-1825688641.us-west-2.elb.amazonaws.com/api/v1/nodes": dial tcp: lookup api-test-cluster-9837-k8s-cg810k-1825688641.us-west-2.elb.amazonaws.com on 10.63.240.10:53: no such host
W0816 10:23:32.377801    5759 validate_cluster.go:184] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-9837-k8s-cg810k-1825688641.us-west-2.elb.amazonaws.com/api/v1/nodes": dial tcp: lookup api-test-cluster-9837-k8s-cg810k-1825688641.us-west-2.elb.amazonaws.com on 10.63.240.10:53: no such host
W0816 10:23:42.399311    5759 validate_cluster.go:184] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-9837-k8s-cg810k-1825688641.us-west-2.elb.amazonaws.com/api/v1/nodes": dial tcp: lookup api-test-cluster-9837-k8s-cg810k-1825688641.us-west-2.elb.amazonaws.com on 10.63.240.10:53: no such host
W0816 10:23:52.434122    5759 validate_cluster.go:184] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-9837-k8s-cg810k-1825688641.us-west-2.elb.amazonaws.com/api/v1/nodes": dial tcp: lookup api-test-cluster-9837-k8s-cg810k-1825688641.us-west-2.elb.amazonaws.com on 10.63.240.10:53: no such host
W0816 10:24:02.481214    5759 validate_cluster.go:184] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-9837-k8s-cg810k-1825688641.us-west-2.elb.amazonaws.com/api/v1/nodes": dial tcp: lookup api-test-cluster-9837-k8s-cg810k-1825688641.us-west-2.elb.amazonaws.com on 10.63.240.10:53: no such host
W0816 10:24:12.520259    5759 validate_cluster.go:184] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-9837-k8s-cg810k-1825688641.us-west-2.elb.amazonaws.com/api/v1/nodes": dial tcp: lookup api-test-cluster-9837-k8s-cg810k-1825688641.us-west-2.elb.amazonaws.com on 10.63.240.10:53: no such host
W0816 10:24:31.766006    5759 validate_cluster.go:184] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-9837-k8s-cg810k-1825688641.us-west-2.elb.amazonaws.com/api/v1/nodes": dial tcp: lookup api-test-cluster-9837-k8s-cg810k-1825688641.us-west-2.elb.amazonaws.com on 10.63.240.10:53: no such host
W0816 10:24:49.841921    5759 validate_cluster.go:184] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-9837-k8s-cg810k-1825688641.us-west-2.elb.amazonaws.com/api/v1/nodes": dial tcp: lookup api-test-cluster-9837-k8s-cg810k-1825688641.us-west-2.elb.amazonaws.com on 10.63.240.10:53: no such host
W0816 10:25:11.476364    5759 validate_cluster.go:184] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-9837-k8s-cg810k-1825688641.us-west-2.elb.amazonaws.com/api/v1/nodes": EOF
W0816 10:25:33.138346    5759 validate_cluster.go:184] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-9837-k8s-cg810k-1825688641.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-0023d3e2d00d393fc				machine "i-0023d3e2d00d393fc" has not yet joined cluster
Machine	i-04f916f6db8f5df08				machine "i-04f916f6db8f5df08" has not yet joined cluster
Machine	i-0bea5c43fb8b9a9bf				machine "i-0bea5c43fb8b9a9bf" has not yet joined cluster
Node	ip-172-20-36-229.us-west-2.compute.internal	node "ip-172-20-36-229.us-west-2.compute.internal" of role "master" is not ready

Validation Failed
W0816 10:25:45.102413    5759 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 ...
KIND	NAME						MESSAGE
Machine	i-0023d3e2d00d393fc				machine "i-0023d3e2d00d393fc" has not yet joined cluster
Machine	i-04f916f6db8f5df08				machine "i-04f916f6db8f5df08" has not yet joined cluster
Machine	i-0bea5c43fb8b9a9bf				machine "i-0bea5c43fb8b9a9bf" has not yet joined cluster
Node	ip-172-20-36-229.us-west-2.compute.internal	node "ip-172-20-36-229.us-west-2.compute.internal" of role "master" is not ready

Validation Failed
W0816 10:25:56.615013    5759 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 10 lines ...
Pod	kube-system/coredns-6d467c5d59-wphtl					system-cluster-critical pod "coredns-6d467c5d59-wphtl" is pending
Pod	kube-system/coredns-autoscaler-5c7694cfcc-54tlw				system-cluster-critical pod "coredns-autoscaler-5c7694cfcc-54tlw" is pending
Pod	kube-system/dns-controller-7c956b559c-cv5js				system-cluster-critical pod "dns-controller-7c956b559c-cv5js" is pending
Pod	kube-system/kops-controller-24c5k					system-cluster-critical pod "kops-controller-24c5k" is pending
Pod	kube-system/kube-proxy-ip-172-20-36-229.us-west-2.compute.internal	system-node-critical pod "kube-proxy-ip-172-20-36-229.us-west-2.compute.internal" is pending

Validation Failed
W0816 10:26:08.217849    5759 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-36-229.us-west-2.compute.internal	master "ip-172-20-36-229.us-west-2.compute.internal" is missing kube-apiserver pod
Node	ip-172-20-36-229.us-west-2.compute.internal	master "ip-172-20-36-229.us-west-2.compute.internal" is missing kube-controller-manager pod
Pod	kube-system/coredns-6d467c5d59-wphtl		system-cluster-critical pod "coredns-6d467c5d59-wphtl" is pending
Pod	kube-system/coredns-autoscaler-5c7694cfcc-54tlw	system-cluster-critical pod "coredns-autoscaler-5c7694cfcc-54tlw" is pending
Pod	kube-system/kops-controller-24c5k		system-cluster-critical pod "kops-controller-24c5k" is pending

Validation Failed
W0816 10:26:19.924683    5759 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 8 lines ...
Machine	i-0bea5c43fb8b9a9bf				machine "i-0bea5c43fb8b9a9bf" has not yet joined cluster
Node	ip-172-20-36-229.us-west-2.compute.internal	master "ip-172-20-36-229.us-west-2.compute.internal" is missing kube-apiserver pod
Node	ip-172-20-36-229.us-west-2.compute.internal	master "ip-172-20-36-229.us-west-2.compute.internal" is missing kube-controller-manager pod
Pod	kube-system/coredns-6d467c5d59-wphtl		system-cluster-critical pod "coredns-6d467c5d59-wphtl" is pending
Pod	kube-system/coredns-autoscaler-5c7694cfcc-54tlw	system-cluster-critical pod "coredns-autoscaler-5c7694cfcc-54tlw" is pending

Validation Failed
W0816 10:26:31.326083    5759 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 8 lines ...
Machine	i-0bea5c43fb8b9a9bf							machine "i-0bea5c43fb8b9a9bf" has not yet joined cluster
Node	ip-172-20-36-229.us-west-2.compute.internal				master "ip-172-20-36-229.us-west-2.compute.internal" is missing kube-controller-manager pod
Pod	kube-system/coredns-6d467c5d59-wphtl					system-cluster-critical pod "coredns-6d467c5d59-wphtl" is pending
Pod	kube-system/coredns-autoscaler-5c7694cfcc-54tlw				system-cluster-critical pod "coredns-autoscaler-5c7694cfcc-54tlw" is pending
Pod	kube-system/kube-proxy-ip-172-20-54-71.us-west-2.compute.internal	system-node-critical pod "kube-proxy-ip-172-20-54-71.us-west-2.compute.internal" is pending

Validation Failed
W0816 10:26:42.828942    5759 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-36-229.us-west-2.compute.internal	master "ip-172-20-36-229.us-west-2.compute.internal" is missing kube-controller-manager pod
Node	ip-172-20-40-117.us-west-2.compute.internal	node "ip-172-20-40-117.us-west-2.compute.internal" of role "node" is not ready
Node	ip-172-20-43-31.us-west-2.compute.internal	node "ip-172-20-43-31.us-west-2.compute.internal" of role "node" is not ready
Pod	kube-system/coredns-6d467c5d59-wphtl		system-cluster-critical pod "coredns-6d467c5d59-wphtl" is not ready (coredns)
Pod	kube-system/coredns-autoscaler-5c7694cfcc-54tlw	system-cluster-critical pod "coredns-autoscaler-5c7694cfcc-54tlw" is pending

Validation Failed
W0816 10:26:54.307407    5759 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-36-229.us-west-2.compute.internal					master "ip-172-20-36-229.us-west-2.compute.internal" is missing kube-controller-manager pod
Pod	kube-system/coredns-6d467c5d59-n2q6d						system-cluster-critical pod "coredns-6d467c5d59-n2q6d" is not ready (coredns)
Pod	kube-system/kube-controller-manager-ip-172-20-36-229.us-west-2.compute.internal	system-cluster-critical pod "kube-controller-manager-ip-172-20-36-229.us-west-2.compute.internal" is pending

Validation Failed
W0816 10:27:05.823757    5759 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 164 lines ...
Aug 16 10:29:26.226: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-n56sh] to have phase Bound
Aug 16 10:29:26.292: INFO: PersistentVolumeClaim pvc-n56sh found and phase=Bound (65.483765ms)
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 16 10:29:26.495: INFO: Waiting up to 15m0s for pod "ebs-volume-tester-dnwhd" in namespace "ebs-1218" to be "Succeeded or Failed"
Aug 16 10:29:26.564: INFO: Pod "ebs-volume-tester-dnwhd": Phase="Pending", Reason="", readiness=false. Elapsed: 69.193858ms
Aug 16 10:29:28.630: INFO: Pod "ebs-volume-tester-dnwhd": Phase="Pending", Reason="", readiness=false. Elapsed: 2.135343498s
Aug 16 10:29:30.698: INFO: Pod "ebs-volume-tester-dnwhd": Phase="Pending", Reason="", readiness=false. Elapsed: 4.203201484s
Aug 16 10:29:32.766: INFO: Pod "ebs-volume-tester-dnwhd": Phase="Pending", Reason="", readiness=false. Elapsed: 6.270607535s
Aug 16 10:29:34.833: INFO: Pod "ebs-volume-tester-dnwhd": Phase="Pending", Reason="", readiness=false. Elapsed: 8.337879337s
Aug 16 10:29:36.903: INFO: Pod "ebs-volume-tester-dnwhd": Phase="Succeeded", Reason="", readiness=false. Elapsed: 10.408501641s
STEP: Saw pod success
Aug 16 10:29:36.904: INFO: Pod "ebs-volume-tester-dnwhd" satisfied condition "Succeeded or Failed"
Aug 16 10:29:36.904: INFO: deleting Pod "ebs-1218"/"ebs-volume-tester-dnwhd"
Aug 16 10:29:36.998: INFO: Pod ebs-volume-tester-dnwhd has the following logs: hello world

STEP: Deleting pod ebs-volume-tester-dnwhd in namespace ebs-1218
Aug 16 10:29:37.079: INFO: deleting PVC "ebs-1218"/"pvc-n56sh"
Aug 16 10:29:37.079: INFO: Deleting PersistentVolumeClaim "pvc-n56sh"
... skipping 61 lines ...
Aug 16 10:29:33.017: INFO: PersistentVolumeClaim pvc-9hk8z found but phase is Pending instead of Bound.
Aug 16 10:29:35.085: INFO: PersistentVolumeClaim pvc-9hk8z found and phase=Bound (4.205501988s)
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 16 10:29:35.290: INFO: Waiting up to 15m0s for pod "ebs-volume-tester-7lcc9" in namespace "ebs-8738" to be "Succeeded or Failed"
Aug 16 10:29:35.358: INFO: Pod "ebs-volume-tester-7lcc9": Phase="Pending", Reason="", readiness=false. Elapsed: 68.265533ms
Aug 16 10:29:37.426: INFO: Pod "ebs-volume-tester-7lcc9": Phase="Pending", Reason="", readiness=false. Elapsed: 2.135856614s
Aug 16 10:29:39.494: INFO: Pod "ebs-volume-tester-7lcc9": Phase="Pending", Reason="", readiness=false. Elapsed: 4.204036968s
Aug 16 10:29:41.562: INFO: Pod "ebs-volume-tester-7lcc9": Phase="Pending", Reason="", readiness=false. Elapsed: 6.271786334s
Aug 16 10:29:43.630: INFO: Pod "ebs-volume-tester-7lcc9": Phase="Pending", Reason="", readiness=false. Elapsed: 8.34007807s
Aug 16 10:29:45.698: INFO: Pod "ebs-volume-tester-7lcc9": Phase="Pending", Reason="", readiness=false. Elapsed: 10.408421326s
Aug 16 10:29:47.766: INFO: Pod "ebs-volume-tester-7lcc9": Phase="Succeeded", Reason="", readiness=false. Elapsed: 12.476234391s
STEP: Saw pod success
Aug 16 10:29:47.766: INFO: Pod "ebs-volume-tester-7lcc9" satisfied condition "Succeeded or Failed"
Aug 16 10:29:47.766: INFO: deleting Pod "ebs-8738"/"ebs-volume-tester-7lcc9"
Aug 16 10:29:47.835: INFO: Pod ebs-volume-tester-7lcc9 has the following logs: 100+0 records in
100+0 records out
104857600 bytes (100.0MB) copied, 0.054454 seconds, 1.8GB/s
hello world

... skipping 56 lines ...
Aug 16 10:29:50.585: INFO: PersistentVolumeClaim pvc-lfzzm found but phase is Pending instead of Bound.
Aug 16 10:29:52.652: INFO: PersistentVolumeClaim pvc-lfzzm found and phase=Bound (4.199278799s)
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 16 10:29:52.859: INFO: Waiting up to 15m0s for pod "ebs-volume-tester-2k687" in namespace "ebs-8891" to be "Succeeded or Failed"
Aug 16 10:29:52.928: INFO: Pod "ebs-volume-tester-2k687": Phase="Pending", Reason="", readiness=false. Elapsed: 69.224047ms
Aug 16 10:29:54.996: INFO: Pod "ebs-volume-tester-2k687": Phase="Pending", Reason="", readiness=false. Elapsed: 2.13662737s
Aug 16 10:29:57.062: INFO: Pod "ebs-volume-tester-2k687": Phase="Pending", Reason="", readiness=false. Elapsed: 4.202748935s
Aug 16 10:29:59.128: INFO: Pod "ebs-volume-tester-2k687": Phase="Pending", Reason="", readiness=false. Elapsed: 6.268849992s
Aug 16 10:30:01.195: INFO: Pod "ebs-volume-tester-2k687": Phase="Pending", Reason="", readiness=false. Elapsed: 8.335941575s
Aug 16 10:30:03.262: INFO: Pod "ebs-volume-tester-2k687": Phase="Succeeded", Reason="", readiness=false. Elapsed: 10.403419747s
STEP: Saw pod success
Aug 16 10:30:03.263: INFO: Pod "ebs-volume-tester-2k687" satisfied condition "Succeeded or Failed"
Aug 16 10:30:03.263: INFO: deleting Pod "ebs-8891"/"ebs-volume-tester-2k687"
Aug 16 10:30:03.333: INFO: Pod ebs-volume-tester-2k687 has the following logs: hello world

STEP: Deleting pod ebs-volume-tester-2k687 in namespace ebs-8891
Aug 16 10:30:03.418: INFO: deleting PVC "ebs-8891"/"pvc-lfzzm"
Aug 16 10:30:03.418: INFO: Deleting PersistentVolumeClaim "pvc-lfzzm"
... skipping 45 lines ...
Aug 16 10:29:28.532: INFO: PersistentVolumeClaim pvc-6l7n5 found but phase is Pending instead of Bound.
Aug 16 10:29:30.601: INFO: PersistentVolumeClaim pvc-6l7n5 found and phase=Bound (8.34109235s)
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 16 10:29:30.810: INFO: Waiting up to 15m0s for pod "ebs-volume-tester-6xtrd" in namespace "ebs-5032" to be "Succeeded or Failed"
Aug 16 10:29:30.878: INFO: Pod "ebs-volume-tester-6xtrd": Phase="Pending", Reason="", readiness=false. Elapsed: 67.688326ms
Aug 16 10:29:32.949: INFO: Pod "ebs-volume-tester-6xtrd": Phase="Pending", Reason="", readiness=false. Elapsed: 2.139321493s
Aug 16 10:29:35.018: INFO: Pod "ebs-volume-tester-6xtrd": Phase="Pending", Reason="", readiness=false. Elapsed: 4.207918961s
Aug 16 10:29:37.087: INFO: Pod "ebs-volume-tester-6xtrd": Phase="Pending", Reason="", readiness=false. Elapsed: 6.276950602s
Aug 16 10:29:39.154: INFO: Pod "ebs-volume-tester-6xtrd": Phase="Pending", Reason="", readiness=false. Elapsed: 8.344264363s
Aug 16 10:29:41.221: INFO: Pod "ebs-volume-tester-6xtrd": Phase="Pending", Reason="", readiness=false. Elapsed: 10.41126702s
Aug 16 10:29:43.289: INFO: Pod "ebs-volume-tester-6xtrd": Phase="Pending", Reason="", readiness=false. Elapsed: 12.479458917s
Aug 16 10:29:45.358: INFO: Pod "ebs-volume-tester-6xtrd": Phase="Pending", Reason="", readiness=false. Elapsed: 14.54789463s
Aug 16 10:29:47.425: INFO: Pod "ebs-volume-tester-6xtrd": Phase="Pending", Reason="", readiness=false. Elapsed: 16.614920902s
Aug 16 10:29:49.493: INFO: Pod "ebs-volume-tester-6xtrd": Phase="Succeeded", Reason="", readiness=false. Elapsed: 18.68299584s
STEP: Saw pod success
Aug 16 10:29:49.493: INFO: Pod "ebs-volume-tester-6xtrd" satisfied condition "Succeeded or Failed"
Aug 16 10:29:49.493: INFO: deleting Pod "ebs-5032"/"ebs-volume-tester-6xtrd"
Aug 16 10:29:49.564: INFO: Pod ebs-volume-tester-6xtrd has the following logs: hello world

STEP: Deleting pod ebs-volume-tester-6xtrd in namespace ebs-5032
Aug 16 10:29:49.643: INFO: deleting PVC "ebs-5032"/"pvc-6l7n5"
Aug 16 10:29:49.644: INFO: Deleting PersistentVolumeClaim "pvc-6l7n5"
... skipping 148 lines ...
Aug 16 10:29:28.513: INFO: PersistentVolumeClaim pvc-rqj8q found but phase is Pending instead of Bound.
Aug 16 10:29:30.583: INFO: PersistentVolumeClaim pvc-rqj8q found and phase=Bound (8.34409139s)
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 16 10:29:30.794: INFO: Waiting up to 15m0s for pod "ebs-volume-tester-dxmn6" in namespace "ebs-9347" to be "Succeeded or Failed"
Aug 16 10:29:30.867: INFO: Pod "ebs-volume-tester-dxmn6": Phase="Pending", Reason="", readiness=false. Elapsed: 73.45062ms
Aug 16 10:29:32.938: INFO: Pod "ebs-volume-tester-dxmn6": Phase="Pending", Reason="", readiness=false. Elapsed: 2.144262829s
Aug 16 10:29:35.007: INFO: Pod "ebs-volume-tester-dxmn6": Phase="Pending", Reason="", readiness=false. Elapsed: 4.212960054s
Aug 16 10:29:37.081: INFO: Pod "ebs-volume-tester-dxmn6": Phase="Pending", Reason="", readiness=false. Elapsed: 6.287409028s
Aug 16 10:29:39.149: INFO: Pod "ebs-volume-tester-dxmn6": Phase="Pending", Reason="", readiness=false. Elapsed: 8.35531525s
Aug 16 10:29:41.218: INFO: Pod "ebs-volume-tester-dxmn6": Phase="Pending", Reason="", readiness=false. Elapsed: 10.424342045s
Aug 16 10:29:43.288: INFO: Pod "ebs-volume-tester-dxmn6": Phase="Pending", Reason="", readiness=false. Elapsed: 12.494147339s
Aug 16 10:29:45.356: INFO: Pod "ebs-volume-tester-dxmn6": Phase="Pending", Reason="", readiness=false. Elapsed: 14.562179568s
Aug 16 10:29:47.425: INFO: Pod "ebs-volume-tester-dxmn6": Phase="Pending", Reason="", readiness=false. Elapsed: 16.631000502s
Aug 16 10:29:49.493: INFO: Pod "ebs-volume-tester-dxmn6": Phase="Succeeded", Reason="", readiness=false. Elapsed: 18.699483639s
STEP: Saw pod success
Aug 16 10:29:49.493: INFO: Pod "ebs-volume-tester-dxmn6" 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 16 10:29:49.631: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-hjhl6] to have phase Bound
Aug 16 10:29:49.698: INFO: PersistentVolumeClaim pvc-hjhl6 found but phase is Pending instead of Bound.
Aug 16 10:29:51.766: INFO: PersistentVolumeClaim pvc-hjhl6 found but phase is Pending instead of Bound.
Aug 16 10:29:53.834: INFO: PersistentVolumeClaim pvc-hjhl6 found and phase=Bound (4.202855451s)
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 16 10:29:54.038: INFO: Waiting up to 15m0s for pod "ebs-volume-tester-nqs6v" in namespace "ebs-9347" to be "Succeeded or Failed"
Aug 16 10:29:54.108: INFO: Pod "ebs-volume-tester-nqs6v": Phase="Pending", Reason="", readiness=false. Elapsed: 69.188582ms
Aug 16 10:29:56.176: INFO: Pod "ebs-volume-tester-nqs6v": Phase="Pending", Reason="", readiness=false. Elapsed: 2.137355216s
Aug 16 10:29:58.245: INFO: Pod "ebs-volume-tester-nqs6v": Phase="Pending", Reason="", readiness=false. Elapsed: 4.206375464s
Aug 16 10:30:00.314: INFO: Pod "ebs-volume-tester-nqs6v": Phase="Pending", Reason="", readiness=false. Elapsed: 6.275571527s
Aug 16 10:30:02.400: INFO: Pod "ebs-volume-tester-nqs6v": Phase="Pending", Reason="", readiness=false. Elapsed: 8.361946997s
Aug 16 10:30:04.470: INFO: Pod "ebs-volume-tester-nqs6v": Phase="Pending", Reason="", readiness=false. Elapsed: 10.431531229s
Aug 16 10:30:06.540: INFO: Pod "ebs-volume-tester-nqs6v": Phase="Succeeded", Reason="", readiness=false. Elapsed: 12.501703323s
STEP: Saw pod success
Aug 16 10:30:06.540: INFO: Pod "ebs-volume-tester-nqs6v" satisfied condition "Succeeded or Failed"
Aug 16 10:30:06.540: INFO: deleting Pod "ebs-9347"/"ebs-volume-tester-nqs6v"
Aug 16 10:30:06.612: INFO: Pod ebs-volume-tester-nqs6v has the following logs: hello world

STEP: Deleting pod ebs-volume-tester-nqs6v in namespace ebs-9347
Aug 16 10:30:06.695: INFO: deleting PVC "ebs-9347"/"pvc-hjhl6"
Aug 16 10:30:06.695: INFO: Deleting PersistentVolumeClaim "pvc-hjhl6"
... skipping 71 lines ...
Aug 16 10:30:32.717: INFO: PersistentVolumeClaim pvc-l6tns found but phase is Pending instead of Bound.
Aug 16 10:30:34.785: INFO: PersistentVolumeClaim pvc-l6tns found and phase=Bound (4.206496333s)
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 16 10:30:35.010: INFO: Waiting up to 15m0s for pod "ebs-volume-tester-bqdn2" in namespace "ebs-8240" to be "Succeeded or Failed"
Aug 16 10:30:35.077: INFO: Pod "ebs-volume-tester-bqdn2": Phase="Pending", Reason="", readiness=false. Elapsed: 67.045026ms
Aug 16 10:30:37.145: INFO: Pod "ebs-volume-tester-bqdn2": Phase="Pending", Reason="", readiness=false. Elapsed: 2.135136156s
Aug 16 10:30:39.212: INFO: Pod "ebs-volume-tester-bqdn2": Phase="Pending", Reason="", readiness=false. Elapsed: 4.202478692s
Aug 16 10:30:41.280: INFO: Pod "ebs-volume-tester-bqdn2": Phase="Pending", Reason="", readiness=false. Elapsed: 6.270599851s
Aug 16 10:30:43.348: INFO: Pod "ebs-volume-tester-bqdn2": Phase="Pending", Reason="", readiness=false. Elapsed: 8.338753631s
Aug 16 10:30:45.418: INFO: Pod "ebs-volume-tester-bqdn2": Phase="Pending", Reason="", readiness=false. Elapsed: 10.408207872s
Aug 16 10:30:47.486: INFO: Pod "ebs-volume-tester-bqdn2": Phase="Succeeded", Reason="", readiness=false. Elapsed: 12.476385945s
STEP: Saw pod success
Aug 16 10:30:47.486: INFO: Pod "ebs-volume-tester-bqdn2" satisfied condition "Succeeded or Failed"
Aug 16 10:30:47.486: INFO: deleting Pod "ebs-8240"/"ebs-volume-tester-bqdn2"
Aug 16 10:30:47.555: INFO: Pod ebs-volume-tester-bqdn2 has the following logs: hello world
hello world

STEP: Deleting pod ebs-volume-tester-bqdn2 in namespace ebs-8240
Aug 16 10:30:47.628: INFO: deleting PVC "ebs-8240"/"pvc-l6tns"
... skipping 56 lines ...
Aug 16 10:30:50.761: INFO: PersistentVolumeClaim pvc-qbfl4 found but phase is Pending instead of Bound.
Aug 16 10:30:52.829: INFO: PersistentVolumeClaim pvc-qbfl4 found and phase=Bound (4.204264507s)
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 16 10:30:53.034: INFO: Waiting up to 15m0s for pod "ebs-volume-tester-hqtgc" in namespace "ebs-5688" to be "Succeeded or Failed"
Aug 16 10:30:53.101: INFO: Pod "ebs-volume-tester-hqtgc": Phase="Pending", Reason="", readiness=false. Elapsed: 67.407955ms
Aug 16 10:30:55.170: INFO: Pod "ebs-volume-tester-hqtgc": Phase="Pending", Reason="", readiness=false. Elapsed: 2.136615934s
Aug 16 10:30:57.239: INFO: Pod "ebs-volume-tester-hqtgc": Phase="Pending", Reason="", readiness=false. Elapsed: 4.204802911s
Aug 16 10:30:59.308: INFO: Pod "ebs-volume-tester-hqtgc": Phase="Pending", Reason="", readiness=false. Elapsed: 6.273816734s
Aug 16 10:31:01.377: INFO: Pod "ebs-volume-tester-hqtgc": Phase="Succeeded", Reason="", readiness=false. Elapsed: 8.343360183s
STEP: Saw pod success
Aug 16 10:31:01.377: INFO: Pod "ebs-volume-tester-hqtgc" satisfied condition "Succeeded or Failed"
Aug 16 10:31:01.377: INFO: deleting Pod "ebs-5688"/"ebs-volume-tester-hqtgc"
Aug 16 10:31:01.451: INFO: Pod ebs-volume-tester-hqtgc has the following logs: 100+0 records in
100+0 records out
104857600 bytes (100.0MB) copied, 0.052325 seconds, 1.9GB/s

STEP: Deleting pod ebs-volume-tester-hqtgc in namespace ebs-5688
... skipping 99 lines ...
Aug 16 10:30:11.563: INFO: PersistentVolumeClaim pvc-7q92m found but phase is Pending instead of Bound.
Aug 16 10:30:13.631: INFO: PersistentVolumeClaim pvc-7q92m found and phase=Bound (4.201935586s)
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 16 10:30:13.834: INFO: Waiting up to 15m0s for pod "ebs-volume-tester-zhn4m" in namespace "ebs-5200" to be "Succeeded or Failed"
Aug 16 10:30:13.901: INFO: Pod "ebs-volume-tester-zhn4m": Phase="Pending", Reason="", readiness=false. Elapsed: 66.755954ms
Aug 16 10:30:15.968: INFO: Pod "ebs-volume-tester-zhn4m": Phase="Pending", Reason="", readiness=false. Elapsed: 2.13415855s
Aug 16 10:30:18.036: INFO: Pod "ebs-volume-tester-zhn4m": Phase="Pending", Reason="", readiness=false. Elapsed: 4.201894276s
Aug 16 10:30:20.105: INFO: Pod "ebs-volume-tester-zhn4m": Phase="Pending", Reason="", readiness=false. Elapsed: 6.270495314s
Aug 16 10:30:22.174: INFO: Pod "ebs-volume-tester-zhn4m": Phase="Pending", Reason="", readiness=false. Elapsed: 8.339943812s
Aug 16 10:30:24.245: INFO: Pod "ebs-volume-tester-zhn4m": Phase="Succeeded", Reason="", readiness=false. Elapsed: 10.41088276s
STEP: Saw pod success
Aug 16 10:30:24.245: INFO: Pod "ebs-volume-tester-zhn4m" satisfied condition "Succeeded or Failed"
STEP: taking snapshots
STEP: setting up the VolumeSnapshotClass
STEP: creating a VolumeSnapshotClass
STEP: creating a VolumeSnapshot for pvc-7q92m
STEP: waiting for VolumeSnapshot to be ready to use - volume-snapshot-862p8
STEP: setting up the StorageClass
... skipping 7 lines ...
Aug 16 10:31:26.747: INFO: PersistentVolumeClaim pvc-nm8d6 found but phase is Pending instead of Bound.
Aug 16 10:31:28.817: INFO: PersistentVolumeClaim pvc-nm8d6 found and phase=Bound (4.20226748s)
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 16 10:31:29.025: INFO: Waiting up to 15m0s for pod "ebs-volume-tester-lzkfl" in namespace "ebs-5200" to be "Succeeded or Failed"
Aug 16 10:31:29.091: INFO: Pod "ebs-volume-tester-lzkfl": Phase="Pending", Reason="", readiness=false. Elapsed: 66.163714ms
Aug 16 10:31:31.158: INFO: Pod "ebs-volume-tester-lzkfl": Phase="Pending", Reason="", readiness=false. Elapsed: 2.132936016s
Aug 16 10:31:33.225: INFO: Pod "ebs-volume-tester-lzkfl": Phase="Pending", Reason="", readiness=false. Elapsed: 4.20057459s
Aug 16 10:31:35.292: INFO: Pod "ebs-volume-tester-lzkfl": Phase="Succeeded", Reason="", readiness=false. Elapsed: 6.267067681s
STEP: Saw pod success
Aug 16 10:31:35.292: INFO: Pod "ebs-volume-tester-lzkfl" satisfied condition "Succeeded or Failed"
Aug 16 10:31:35.292: INFO: deleting Pod "ebs-5200"/"ebs-volume-tester-lzkfl"
Aug 16 10:31:35.359: INFO: Pod ebs-volume-tester-lzkfl has the following logs: hello world

STEP: Deleting pod ebs-volume-tester-lzkfl in namespace ebs-5200
Aug 16 10:31:35.432: INFO: deleting PVC "ebs-5200"/"pvc-nm8d6"
Aug 16 10:31:35.433: INFO: Deleting PersistentVolumeClaim "pvc-nm8d6"
... skipping 61 lines ...
Aug 16 10:31:45.847: INFO: PersistentVolumeClaim pvc-l6mwl found but phase is Pending instead of Bound.
Aug 16 10:31:47.916: INFO: PersistentVolumeClaim pvc-l6mwl found and phase=Bound (4.204546831s)
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 16 10:31:48.121: INFO: Waiting up to 15m0s for pod "ebs-volume-tester-rn98d" in namespace "ebs-6989" to be "Succeeded or Failed"
Aug 16 10:31:48.193: INFO: Pod "ebs-volume-tester-rn98d": Phase="Pending", Reason="", readiness=false. Elapsed: 71.442745ms
Aug 16 10:31:50.261: INFO: Pod "ebs-volume-tester-rn98d": Phase="Pending", Reason="", readiness=false. Elapsed: 2.1399022s
Aug 16 10:31:52.329: INFO: Pod "ebs-volume-tester-rn98d": Phase="Pending", Reason="", readiness=false. Elapsed: 4.208141224s
Aug 16 10:31:54.397: INFO: Pod "ebs-volume-tester-rn98d": Phase="Succeeded", Reason="", readiness=false. Elapsed: 6.275869289s
STEP: Saw pod success
Aug 16 10:31:54.397: INFO: Pod "ebs-volume-tester-rn98d" satisfied condition "Succeeded or Failed"
Aug 16 10:31:54.397: INFO: deleting Pod "ebs-6989"/"ebs-volume-tester-rn98d"
Aug 16 10:31:54.469: INFO: Pod ebs-volume-tester-rn98d has the following logs: hello world

STEP: Deleting pod ebs-volume-tester-rn98d in namespace ebs-6989
Aug 16 10:31:54.544: INFO: deleting PVC "ebs-6989"/"pvc-l6mwl"
Aug 16 10:31:54.544: INFO: Deleting PersistentVolumeClaim "pvc-l6mwl"
... skipping 42 lines ...
Aug 16 10:32:04.505: INFO: PersistentVolumeClaim pvc-phrhr found but phase is Pending instead of Bound.
Aug 16 10:32:06.575: INFO: PersistentVolumeClaim pvc-phrhr found and phase=Bound (4.205086251s)
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 16 10:32:06.777: INFO: Waiting up to 15m0s for pod "ebs-volume-tester-phvzw" in namespace "ebs-6537" to be "Succeeded or Failed"
Aug 16 10:32:06.843: INFO: Pod "ebs-volume-tester-phvzw": Phase="Pending", Reason="", readiness=false. Elapsed: 66.034954ms
Aug 16 10:32:08.909: INFO: Pod "ebs-volume-tester-phvzw": Phase="Pending", Reason="", readiness=false. Elapsed: 2.132425247s
Aug 16 10:32:10.976: INFO: Pod "ebs-volume-tester-phvzw": Phase="Pending", Reason="", readiness=false. Elapsed: 4.199141771s
Aug 16 10:32:13.043: INFO: Pod "ebs-volume-tester-phvzw": Phase="Succeeded", Reason="", readiness=false. Elapsed: 6.266159528s
STEP: Saw pod success
Aug 16 10:32:13.043: INFO: Pod "ebs-volume-tester-phvzw" satisfied condition "Succeeded or Failed"
Aug 16 10:32:13.043: INFO: deleting Pod "ebs-6537"/"ebs-volume-tester-phvzw"
Aug 16 10:32:13.112: INFO: Pod ebs-volume-tester-phvzw has the following logs: hello world

STEP: Deleting pod ebs-volume-tester-phvzw in namespace ebs-6537
Aug 16 10:32:13.188: INFO: deleting PVC "ebs-6537"/"pvc-phrhr"
Aug 16 10:32:13.188: INFO: Deleting PersistentVolumeClaim "pvc-phrhr"
... skipping 145 lines ...
STEP: checking the resizing PV result
STEP: Waiting up to 1m0s for pv in namespace "ebs-9929" 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 16 10:32:38.935: INFO: Waiting up to 15m0s for pod "ebs-volume-tester-tvtz8" in namespace "ebs-9929" to be "Succeeded or Failed"
Aug 16 10:32:39.001: INFO: Pod "ebs-volume-tester-tvtz8": Phase="Pending", Reason="", readiness=false. Elapsed: 65.51301ms
Aug 16 10:32:41.068: INFO: Pod "ebs-volume-tester-tvtz8": Phase="Pending", Reason="", readiness=false. Elapsed: 2.132846214s
Aug 16 10:32:43.135: INFO: Pod "ebs-volume-tester-tvtz8": Phase="Pending", Reason="", readiness=false. Elapsed: 4.199764151s
Aug 16 10:32:45.202: INFO: Pod "ebs-volume-tester-tvtz8": Phase="Succeeded", Reason="", readiness=false. Elapsed: 6.266964328s
STEP: Saw pod success
Aug 16 10:32:45.202: INFO: Pod "ebs-volume-tester-tvtz8" satisfied condition "Succeeded or Failed"
Aug 16 10:32:45.202: INFO: deleting Pod "ebs-9929"/"ebs-volume-tester-tvtz8"
Aug 16 10:32:45.270: INFO: Pod ebs-volume-tester-tvtz8 has the following logs: hello world

STEP: Deleting pod ebs-volume-tester-tvtz8 in namespace ebs-9929
Aug 16 10:32:45.349: INFO: deleting PVC "ebs-9929"/"pvc-w6z85"
Aug 16 10:32:45.349: INFO: Deleting PersistentVolumeClaim "pvc-w6z85"
... skipping 41 lines ...
Aug 16 10:32:12.784: INFO: PersistentVolumeClaim pvc-vhlvk found but phase is Pending instead of Bound.
Aug 16 10:32:14.852: INFO: PersistentVolumeClaim pvc-vhlvk found and phase=Bound (4.20397831s)
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 16 10:32:15.059: INFO: Waiting up to 15m0s for pod "ebs-volume-tester-wnsd5" in namespace "ebs-5875" to be "Succeeded or Failed"
Aug 16 10:32:15.127: INFO: Pod "ebs-volume-tester-wnsd5": Phase="Pending", Reason="", readiness=false. Elapsed: 67.621867ms
Aug 16 10:32:17.195: INFO: Pod "ebs-volume-tester-wnsd5": Phase="Pending", Reason="", readiness=false. Elapsed: 2.135768884s
Aug 16 10:32:19.265: INFO: Pod "ebs-volume-tester-wnsd5": Phase="Pending", Reason="", readiness=false. Elapsed: 4.20553868s
Aug 16 10:32:21.333: INFO: Pod "ebs-volume-tester-wnsd5": Phase="Pending", Reason="", readiness=false. Elapsed: 6.274218361s
Aug 16 10:32:23.401: INFO: Pod "ebs-volume-tester-wnsd5": Phase="Pending", Reason="", readiness=false. Elapsed: 8.34154595s
Aug 16 10:32:25.471: INFO: Pod "ebs-volume-tester-wnsd5": Phase="Succeeded", Reason="", readiness=false. Elapsed: 10.411362235s
STEP: Saw pod success
Aug 16 10:32:25.471: INFO: Pod "ebs-volume-tester-wnsd5" satisfied condition "Succeeded or Failed"
Aug 16 10:32:25.471: INFO: deleting Pod "ebs-5875"/"ebs-volume-tester-wnsd5"
Aug 16 10:32:25.540: INFO: Pod ebs-volume-tester-wnsd5 has the following logs: hello world

STEP: Deleting pod ebs-volume-tester-wnsd5 in namespace ebs-5875
Aug 16 10:32:25.612: INFO: deleting PVC "ebs-5875"/"pvc-vhlvk"
Aug 16 10:32:25.612: INFO: Deleting PersistentVolumeClaim "pvc-vhlvk"
... skipping 102 lines ...
Aug 16 10:32:51.605: INFO: PersistentVolumeClaim pvc-5v8jc found but phase is Pending instead of Bound.
Aug 16 10:32:53.677: INFO: PersistentVolumeClaim pvc-5v8jc found and phase=Bound (4.204513109s)
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 16 10:32:53.877: INFO: Waiting up to 15m0s for pod "ebs-volume-tester-9vxw4" in namespace "ebs-4368" to be "Succeeded or Failed"
Aug 16 10:32:53.944: INFO: Pod "ebs-volume-tester-9vxw4": Phase="Pending", Reason="", readiness=false. Elapsed: 66.847687ms
Aug 16 10:32:56.012: INFO: Pod "ebs-volume-tester-9vxw4": Phase="Pending", Reason="", readiness=false. Elapsed: 2.134964648s
Aug 16 10:32:58.079: INFO: Pod "ebs-volume-tester-9vxw4": Phase="Pending", Reason="", readiness=false. Elapsed: 4.201873391s
Aug 16 10:33:00.146: INFO: Pod "ebs-volume-tester-9vxw4": Phase="Pending", Reason="", readiness=false. Elapsed: 6.269168179s
Aug 16 10:33:02.217: INFO: Pod "ebs-volume-tester-9vxw4": Phase="Pending", Reason="", readiness=false. Elapsed: 8.340246452s
Aug 16 10:33:04.284: INFO: Pod "ebs-volume-tester-9vxw4": Phase="Succeeded", Reason="", readiness=false. Elapsed: 10.407766272s
STEP: Saw pod success
Aug 16 10:33:04.285: INFO: Pod "ebs-volume-tester-9vxw4" satisfied condition "Succeeded or Failed"
Aug 16 10:33:04.285: INFO: deleting Pod "ebs-4368"/"ebs-volume-tester-9vxw4"
Aug 16 10:33:04.352: INFO: Pod ebs-volume-tester-9vxw4 has the following logs: hello world

STEP: Deleting pod ebs-volume-tester-9vxw4 in namespace ebs-4368
Aug 16 10:33:04.425: INFO: deleting PVC "ebs-4368"/"pvc-5v8jc"
Aug 16 10:33:04.425: INFO: Deleting PersistentVolumeClaim "pvc-5v8jc"
... skipping 121 lines ...
Aug 16 10:33:09.706: INFO: PersistentVolumeClaim pvc-vkbsw found but phase is Pending instead of Bound.
Aug 16 10:33:11.775: INFO: PersistentVolumeClaim pvc-vkbsw found and phase=Bound (4.205841664s)
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 16 10:33:11.981: INFO: Waiting up to 15m0s for pod "ebs-volume-tester-sc5lw" in namespace "ebs-5581" to be "Succeeded or Failed"
Aug 16 10:33:12.050: INFO: Pod "ebs-volume-tester-sc5lw": Phase="Pending", Reason="", readiness=false. Elapsed: 69.407824ms
Aug 16 10:33:14.118: INFO: Pod "ebs-volume-tester-sc5lw": Phase="Pending", Reason="", readiness=false. Elapsed: 2.137548715s
Aug 16 10:33:16.190: INFO: Pod "ebs-volume-tester-sc5lw": Phase="Pending", Reason="", readiness=false. Elapsed: 4.208877429s
Aug 16 10:33:18.258: INFO: Pod "ebs-volume-tester-sc5lw": Phase="Pending", Reason="", readiness=false. Elapsed: 6.277431301s
Aug 16 10:33:20.327: INFO: Pod "ebs-volume-tester-sc5lw": Phase="Pending", Reason="", readiness=false. Elapsed: 8.346066684s
Aug 16 10:33:22.395: INFO: Pod "ebs-volume-tester-sc5lw": Phase="Pending", Reason="", readiness=false. Elapsed: 10.41454555s
Aug 16 10:33:24.465: INFO: Pod "ebs-volume-tester-sc5lw": Phase="Pending", Reason="", readiness=false. Elapsed: 12.483896836s
Aug 16 10:33:26.533: INFO: Pod "ebs-volume-tester-sc5lw": Phase="Pending", Reason="", readiness=false. Elapsed: 14.551840292s
Aug 16 10:33:28.610: INFO: Pod "ebs-volume-tester-sc5lw": Phase="Pending", Reason="", readiness=false. Elapsed: 16.628827273s
Aug 16 10:33:30.678: INFO: Pod "ebs-volume-tester-sc5lw": Phase="Succeeded", Reason="", readiness=false. Elapsed: 18.697491706s
STEP: Saw pod success
Aug 16 10:33:30.678: INFO: Pod "ebs-volume-tester-sc5lw" satisfied condition "Succeeded or Failed"
Aug 16 10:33:30.678: INFO: deleting Pod "ebs-5581"/"ebs-volume-tester-sc5lw"
Aug 16 10:33:30.748: INFO: Pod ebs-volume-tester-sc5lw has the following logs: hello world

STEP: Deleting pod ebs-volume-tester-sc5lw in namespace ebs-5581
Aug 16 10:33:30.822: INFO: deleting PVC "ebs-5581"/"pvc-vkbsw"
Aug 16 10:33:30.822: INFO: Deleting PersistentVolumeClaim "pvc-vkbsw"
... skipping 41 lines ...
Aug 16 10:33:22.635: INFO: PersistentVolumeClaim pvc-pxstm found but phase is Pending instead of Bound.
Aug 16 10:33:24.701: INFO: PersistentVolumeClaim pvc-pxstm found and phase=Bound (4.199100795s)
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 16 10:33:24.900: INFO: Waiting up to 15m0s for pod "ebs-volume-tester-rr4vr" in namespace "ebs-3108" to be "Succeeded or Failed"
Aug 16 10:33:24.966: INFO: Pod "ebs-volume-tester-rr4vr": Phase="Pending", Reason="", readiness=false. Elapsed: 65.475148ms
Aug 16 10:33:27.032: INFO: Pod "ebs-volume-tester-rr4vr": Phase="Pending", Reason="", readiness=false. Elapsed: 2.132076167s
Aug 16 10:33:29.098: INFO: Pod "ebs-volume-tester-rr4vr": Phase="Pending", Reason="", readiness=false. Elapsed: 4.197769032s
Aug 16 10:33:31.165: INFO: Pod "ebs-volume-tester-rr4vr": Phase="Pending", Reason="", readiness=false. Elapsed: 6.264929143s
Aug 16 10:33:33.233: INFO: Pod "ebs-volume-tester-rr4vr": Phase="Pending", Reason="", readiness=false. Elapsed: 8.332574668s
Aug 16 10:33:35.300: INFO: Pod "ebs-volume-tester-rr4vr": Phase="Succeeded", Reason="", readiness=false. Elapsed: 10.399516529s
STEP: Saw pod success
Aug 16 10:33:35.300: INFO: Pod "ebs-volume-tester-rr4vr" satisfied condition "Succeeded or Failed"
Aug 16 10:33:35.300: INFO: deleting Pod "ebs-3108"/"ebs-volume-tester-rr4vr"
Aug 16 10:33:35.367: INFO: Pod ebs-volume-tester-rr4vr has the following logs: hello world

STEP: Deleting pod ebs-volume-tester-rr4vr in namespace ebs-3108
Aug 16 10:33:35.440: INFO: deleting PVC "ebs-3108"/"pvc-pxstm"
Aug 16 10:33:35.440: INFO: Deleting PersistentVolumeClaim "pvc-pxstm"
... skipping 45 lines ...
Aug 16 10:33:40.285: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [pvc-dp8fz] to have phase Bound
Aug 16 10:33:40.351: INFO: PersistentVolumeClaim pvc-dp8fz found and phase=Bound (66.400371ms)
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 16 10:33:40.554: INFO: Waiting up to 15m0s for pod "ebs-volume-tester-zkd5t" in namespace "ebs-5234" to be "Error status code"
Aug 16 10:33:40.624: INFO: Pod "ebs-volume-tester-zkd5t": Phase="Pending", Reason="", readiness=false. Elapsed: 70.18453ms
Aug 16 10:33:42.692: INFO: Pod "ebs-volume-tester-zkd5t": Phase="Pending", Reason="", readiness=false. Elapsed: 2.137336739s
Aug 16 10:33:44.758: INFO: Pod "ebs-volume-tester-zkd5t": Phase="Pending", Reason="", readiness=false. Elapsed: 4.204231052s
Aug 16 10:33:46.826: INFO: Pod "ebs-volume-tester-zkd5t": Phase="Pending", Reason="", readiness=false. Elapsed: 6.271740283s
Aug 16 10:33:48.893: INFO: Pod "ebs-volume-tester-zkd5t": Phase="Pending", Reason="", readiness=false. Elapsed: 8.338552132s
Aug 16 10:33:50.960: INFO: Pod "ebs-volume-tester-zkd5t": Phase="Pending", Reason="", readiness=false. Elapsed: 10.405544307s
Aug 16 10:33:53.029: INFO: Pod "ebs-volume-tester-zkd5t": Phase="Pending", Reason="", readiness=false. Elapsed: 12.474834914s
Aug 16 10:33:55.103: INFO: Pod "ebs-volume-tester-zkd5t": Phase="Pending", Reason="", readiness=false. Elapsed: 14.54865991s
Aug 16 10:33:57.170: INFO: Pod "ebs-volume-tester-zkd5t": Phase="Pending", Reason="", readiness=false. Elapsed: 16.615645423s
Aug 16 10:33:59.238: INFO: Pod "ebs-volume-tester-zkd5t": Phase="Failed", Reason="", readiness=false. Elapsed: 18.683642128s
STEP: Saw pod failure
Aug 16 10:33:59.238: INFO: Pod "ebs-volume-tester-zkd5t" satisfied condition "Error status code"
STEP: checking that pod logs contain expected message
Aug 16 10:33:59.307: INFO: deleting Pod "ebs-5234"/"ebs-volume-tester-zkd5t"
Aug 16 10:33:59.375: INFO: Pod ebs-volume-tester-zkd5t has the following logs: /bin/sh: can't create /mnt/test-1/data: Read-only file system

STEP: Deleting pod ebs-volume-tester-zkd5t in namespace ebs-5234
Aug 16 10:33:59.450: INFO: deleting PVC "ebs-5234"/"pvc-dp8fz"
... skipping 45 lines ...
Aug 16 10:33:53.651: INFO: PersistentVolumeClaim pvc-zdqmb found but phase is Pending instead of Bound.
Aug 16 10:33:55.717: INFO: PersistentVolumeClaim pvc-zdqmb found and phase=Bound (4.199599232s)
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 16 10:33:55.916: INFO: Waiting up to 15m0s for pod "ebs-volume-tester-zbsbx" in namespace "ebs-6090" to be "Error status code"
Aug 16 10:33:55.981: INFO: Pod "ebs-volume-tester-zbsbx": Phase="Pending", Reason="", readiness=false. Elapsed: 65.547878ms
Aug 16 10:33:58.051: INFO: Pod "ebs-volume-tester-zbsbx": Phase="Pending", Reason="", readiness=false. Elapsed: 2.135248434s
Aug 16 10:34:00.118: INFO: Pod "ebs-volume-tester-zbsbx": Phase="Pending", Reason="", readiness=false. Elapsed: 4.202270662s
Aug 16 10:34:02.185: INFO: Pod "ebs-volume-tester-zbsbx": Phase="Pending", Reason="", readiness=false. Elapsed: 6.269472437s
Aug 16 10:34:04.251: INFO: Pod "ebs-volume-tester-zbsbx": Phase="Pending", Reason="", readiness=false. Elapsed: 8.335326978s
Aug 16 10:34:06.319: INFO: Pod "ebs-volume-tester-zbsbx": Phase="Failed", Reason="", readiness=false. Elapsed: 10.403034803s
STEP: Saw pod failure
Aug 16 10:34:06.319: INFO: Pod "ebs-volume-tester-zbsbx" satisfied condition "Error status code"
STEP: checking that pod logs contain expected message
Aug 16 10:34:06.386: INFO: deleting Pod "ebs-6090"/"ebs-volume-tester-zbsbx"
Aug 16 10:34:06.453: INFO: Pod ebs-volume-tester-zbsbx has the following logs: touch: /mnt/test-1/data: Read-only file system

STEP: Deleting pod ebs-volume-tester-zbsbx in namespace ebs-6090
Aug 16 10:34:06.528: INFO: deleting PVC "ebs-6090"/"pvc-zdqmb"
... skipping 43 lines ...
Aug 16 10:33:43.990: INFO: PersistentVolumeClaim pvc-lvpjf found but phase is Pending instead of Bound.
Aug 16 10:33:46.058: INFO: PersistentVolumeClaim pvc-lvpjf found and phase=Bound (4.20340776s)
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 16 10:33:46.262: INFO: Waiting up to 15m0s for pod "ebs-volume-tester-nwdcx" in namespace "ebs-6323" to be "Succeeded or Failed"
Aug 16 10:33:46.330: INFO: Pod "ebs-volume-tester-nwdcx": Phase="Pending", Reason="", readiness=false. Elapsed: 67.667507ms
Aug 16 10:33:48.398: INFO: Pod "ebs-volume-tester-nwdcx": Phase="Pending", Reason="", readiness=false. Elapsed: 2.135804036s
Aug 16 10:33:50.465: INFO: Pod "ebs-volume-tester-nwdcx": Phase="Pending", Reason="", readiness=false. Elapsed: 4.2031822s
Aug 16 10:33:52.533: INFO: Pod "ebs-volume-tester-nwdcx": Phase="Pending", Reason="", readiness=false. Elapsed: 6.271316218s
Aug 16 10:33:54.602: INFO: Pod "ebs-volume-tester-nwdcx": Phase="Pending", Reason="", readiness=false. Elapsed: 8.339950856s
Aug 16 10:33:56.670: INFO: Pod "ebs-volume-tester-nwdcx": Phase="Succeeded", Reason="", readiness=false. Elapsed: 10.407688674s
STEP: Saw pod success
Aug 16 10:33:56.670: INFO: Pod "ebs-volume-tester-nwdcx" satisfied condition "Succeeded or Failed"
Aug 16 10:33:56.670: INFO: deleting Pod "ebs-6323"/"ebs-volume-tester-nwdcx"
Aug 16 10:33:56.741: INFO: Pod ebs-volume-tester-nwdcx has the following logs: hello world

STEP: Deleting pod ebs-volume-tester-nwdcx in namespace ebs-6323
Aug 16 10:33:56.815: INFO: deleting PVC "ebs-6323"/"pvc-lvpjf"
Aug 16 10:33:56.815: INFO: Deleting PersistentVolumeClaim "pvc-lvpjf"
... skipping 46 lines ...
Aug 16 10:34:12.913: INFO: PersistentVolumeClaim pvc-wvn8m found but phase is Pending instead of Bound.
Aug 16 10:34:14.980: INFO: PersistentVolumeClaim pvc-wvn8m found and phase=Bound (4.200450462s)
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 16 10:34:15.186: INFO: Waiting up to 15m0s for pod "ebs-volume-tester-vcm9k" in namespace "ebs-377" to be "Succeeded or Failed"
Aug 16 10:34:15.261: INFO: Pod "ebs-volume-tester-vcm9k": Phase="Pending", Reason="", readiness=false. Elapsed: 74.732813ms
Aug 16 10:34:17.328: INFO: Pod "ebs-volume-tester-vcm9k": Phase="Pending", Reason="", readiness=false. Elapsed: 2.142143962s
Aug 16 10:34:19.397: INFO: Pod "ebs-volume-tester-vcm9k": Phase="Pending", Reason="", readiness=false. Elapsed: 4.210771453s
Aug 16 10:34:21.467: INFO: Pod "ebs-volume-tester-vcm9k": Phase="Pending", Reason="", readiness=false. Elapsed: 6.281280813s
Aug 16 10:34:23.536: INFO: Pod "ebs-volume-tester-vcm9k": Phase="Pending", Reason="", readiness=false. Elapsed: 8.349771291s
Aug 16 10:34:25.603: INFO: Pod "ebs-volume-tester-vcm9k": Phase="Succeeded", Reason="", readiness=false. Elapsed: 10.417142881s
STEP: Saw pod success
Aug 16 10:34:25.603: INFO: Pod "ebs-volume-tester-vcm9k" satisfied condition "Succeeded or Failed"
Aug 16 10:34:25.603: INFO: deleting Pod "ebs-377"/"ebs-volume-tester-vcm9k"
Aug 16 10:34:25.671: INFO: Pod ebs-volume-tester-vcm9k has the following logs: hello world

STEP: Deleting pod ebs-volume-tester-vcm9k in namespace ebs-377
Aug 16 10:34:25.757: INFO: deleting PVC "ebs-377"/"pvc-wvn8m"
Aug 16 10:34:25.757: INFO: Deleting PersistentVolumeClaim "pvc-wvn8m"
... skipping 42 lines ...
Aug 16 10:34:24.745: INFO: PersistentVolumeClaim pvc-bs7gw found but phase is Pending instead of Bound.
Aug 16 10:34:26.811: INFO: PersistentVolumeClaim pvc-bs7gw found and phase=Bound (4.201601102s)
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 16 10:34:27.010: INFO: Waiting up to 15m0s for pod "ebs-volume-tester-2bvs9" in namespace "ebs-9816" to be "Succeeded or Failed"
Aug 16 10:34:27.076: INFO: Pod "ebs-volume-tester-2bvs9": Phase="Pending", Reason="", readiness=false. Elapsed: 66.100416ms
Aug 16 10:34:29.142: INFO: Pod "ebs-volume-tester-2bvs9": Phase="Pending", Reason="", readiness=false. Elapsed: 2.13208334s
Aug 16 10:34:31.209: INFO: Pod "ebs-volume-tester-2bvs9": Phase="Pending", Reason="", readiness=false. Elapsed: 4.199382509s
Aug 16 10:34:33.278: INFO: Pod "ebs-volume-tester-2bvs9": Phase="Pending", Reason="", readiness=false. Elapsed: 6.268286648s
Aug 16 10:34:35.345: INFO: Pod "ebs-volume-tester-2bvs9": Phase="Succeeded", Reason="", readiness=false. Elapsed: 8.335254702s
STEP: Saw pod success
Aug 16 10:34:35.345: INFO: Pod "ebs-volume-tester-2bvs9" satisfied condition "Succeeded or Failed"
Aug 16 10:34:35.345: INFO: deleting Pod "ebs-9816"/"ebs-volume-tester-2bvs9"
Aug 16 10:34:35.414: INFO: Pod ebs-volume-tester-2bvs9 has the following logs: hello world

STEP: Deleting pod ebs-volume-tester-2bvs9 in namespace ebs-9816
Aug 16 10:34:35.489: INFO: deleting PVC "ebs-9816"/"pvc-bs7gw"
Aug 16 10:34:35.489: INFO: Deleting PersistentVolumeClaim "pvc-bs7gw"
... skipping 45 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 16 10:33:05.835: INFO: Waiting up to 15m0s for pod "ebs-volume-tester-rbnml" in namespace "ebs-1298" to be "Succeeded or Failed"
Aug 16 10:33:05.901: INFO: Pod "ebs-volume-tester-rbnml": Phase="Pending", Reason="", readiness=false. Elapsed: 65.966825ms
Aug 16 10:33:07.969: INFO: Pod "ebs-volume-tester-rbnml": Phase="Pending", Reason="", readiness=false. Elapsed: 2.133384235s
Aug 16 10:33:10.037: INFO: Pod "ebs-volume-tester-rbnml": Phase="Pending", Reason="", readiness=false. Elapsed: 4.201334235s
Aug 16 10:33:12.105: INFO: Pod "ebs-volume-tester-rbnml": Phase="Pending", Reason="", readiness=false. Elapsed: 6.269913544s
Aug 16 10:33:14.172: INFO: Pod "ebs-volume-tester-rbnml": Phase="Pending", Reason="", readiness=false. Elapsed: 8.336436591s
Aug 16 10:33:16.239: INFO: Pod "ebs-volume-tester-rbnml": Phase="Pending", Reason="", readiness=false. Elapsed: 10.403172864s
... skipping 387 lines ...
Aug 16 10:46:38.884: INFO: Pod "ebs-volume-tester-rbnml": Phase="Pending", Reason="", readiness=false. Elapsed: 13m33.048590853s
Aug 16 10:46:40.951: INFO: Pod "ebs-volume-tester-rbnml": Phase="Pending", Reason="", readiness=false. Elapsed: 13m35.115437953s
Aug 16 10:46:43.019: INFO: Pod "ebs-volume-tester-rbnml": Phase="Pending", Reason="", readiness=false. Elapsed: 13m37.183349106s
Aug 16 10:46:45.086: INFO: Pod "ebs-volume-tester-rbnml": Phase="Pending", Reason="", readiness=false. Elapsed: 13m39.250356846s
Aug 16 10:46:47.154: INFO: Pod "ebs-volume-tester-rbnml": Phase="Succeeded", Reason="", readiness=false. Elapsed: 13m41.318464392s
STEP: Saw pod success
Aug 16 10:46:47.154: INFO: Pod "ebs-volume-tester-rbnml" satisfied condition "Succeeded or Failed"
Aug 16 10:46:47.154: INFO: deleting Pod "ebs-1298"/"ebs-volume-tester-rbnml"
Aug 16 10:46:47.249: INFO: Pod ebs-volume-tester-rbnml has the following logs: hello world

STEP: Deleting pod ebs-volume-tester-rbnml in namespace ebs-1298
Aug 16 10:46:47.323: INFO: deleting PVC "ebs-1298"/"pvc-8gxhq"
Aug 16 10:46:47.323: INFO: Deleting PersistentVolumeClaim "pvc-8gxhq"
... 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 1052.095 seconds
SUCCESS! -- 27 Passed | 0 Failed | 0 Pending | 6 Skipped


Ginkgo ran 1 suite in 19m12.878089961s
Test Suite Passed
+ TEST_PASSED=0
+ set -e
... skipping 681 lines ...
  Device: "/dev/xvdbb",
  InstanceId: "i-0023d3e2d00d393fc",
  State: "attaching",
  VolumeId: "vol-0d0d0eaa399166a7a"
}
I0816 10:33:46.979111       1 cloud.go:635] Waiting for volume "vol-0d0d0eaa399166a7a" state: actual=attaching, desired=attached
E0816 10:33:47.099749       1 manager.go:44] Error releasing device: release on device "/dev/xvdbb" assigned to different volume: "vol-0ef148dfa0447bebf" vs "vol-0d0d0eaa399166a7a"
I0816 10:33:47.099769       1 controller.go:388] [Debug] ControllerUnpublishVolume: volume vol-0ef148dfa0447bebf detached from node i-0023d3e2d00d393fc
I0816 10:33:47.112656       1 controller.go:374] ControllerUnpublishVolume: called with args {VolumeId:vol-0ef148dfa0447bebf NodeId:i-0023d3e2d00d393fc Secrets:map[] XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
W0816 10:33:47.154918       1 cloud.go:509] DetachDisk called on non-attached volume: vol-0ef148dfa0447bebf
I0816 10:33:48.043403       1 manager.go:197] [Debug] Releasing in-process attachment entry: /dev/xvdbb -> volume vol-0d0d0eaa399166a7a
I0816 10:33:48.043421       1 controller.go:343] [Debug] ControllerPublishVolume: volume vol-0d0d0eaa399166a7a attached to node i-0023d3e2d00d393fc through device /dev/xvdbb
I0816 10:33:55.953495       1 controller.go:315] ControllerPublishVolume: called with args {VolumeId:vol-0a8dc5d5ab693e5d0 NodeId:i-0023d3e2d00d393fc VolumeCapability:mount:<fs_type:"ext4" > access_mode:<mode:SINGLE_NODE_WRITER >  Readonly:false Secrets:map[] VolumeContext:map[storage.kubernetes.io/csiProvisionerIdentity:1660645652435-8081-ebs.csi.aws.com] XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
... skipping 1357 lines ...