This job view page is being replaced by Spyglass soon. Check out the new job view.
PRtorredil: Use minimal base image for linux builds
ResultABORTED
Tests 0 failed / 0 succeeded
Started2022-05-11 01:16
Elapsed1h7m
Revision63e9fa57d952f24f42cd7388ca757253d3ab5992
Refs 1233

No Test Failures!


Error lines from build-log.txt

... skipping 575 lines ...
## Validating cluster test-cluster-28361.k8s.local
#
Using cluster from kubectl context: test-cluster-28361.k8s.local

Validating cluster test-cluster-28361.k8s.local

W0511 01:18:29.176295    9357 validate_cluster.go:173] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-28361-k8-vgl76g-1901786756.us-west-2.elb.amazonaws.com/api/v1/nodes": dial tcp: lookup api-test-cluster-28361-k8-vgl76g-1901786756.us-west-2.elb.amazonaws.com on 10.63.240.10:53: no such host
W0511 01:18:39.209710    9357 validate_cluster.go:173] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-28361-k8-vgl76g-1901786756.us-west-2.elb.amazonaws.com/api/v1/nodes": dial tcp: lookup api-test-cluster-28361-k8-vgl76g-1901786756.us-west-2.elb.amazonaws.com on 10.63.240.10:53: no such host
W0511 01:18:49.240627    9357 validate_cluster.go:173] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-28361-k8-vgl76g-1901786756.us-west-2.elb.amazonaws.com/api/v1/nodes": dial tcp: lookup api-test-cluster-28361-k8-vgl76g-1901786756.us-west-2.elb.amazonaws.com on 10.63.240.10:53: no such host
W0511 01:18:59.276747    9357 validate_cluster.go:173] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-28361-k8-vgl76g-1901786756.us-west-2.elb.amazonaws.com/api/v1/nodes": dial tcp: lookup api-test-cluster-28361-k8-vgl76g-1901786756.us-west-2.elb.amazonaws.com on 10.63.240.10:53: no such host
W0511 01:19:09.312386    9357 validate_cluster.go:173] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-28361-k8-vgl76g-1901786756.us-west-2.elb.amazonaws.com/api/v1/nodes": dial tcp: lookup api-test-cluster-28361-k8-vgl76g-1901786756.us-west-2.elb.amazonaws.com on 10.63.240.10:53: no such host
W0511 01:19:19.365225    9357 validate_cluster.go:173] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-28361-k8-vgl76g-1901786756.us-west-2.elb.amazonaws.com/api/v1/nodes": dial tcp: lookup api-test-cluster-28361-k8-vgl76g-1901786756.us-west-2.elb.amazonaws.com on 10.63.240.10:53: no such host
W0511 01:19:32.873796    9357 validate_cluster.go:173] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-28361-k8-vgl76g-1901786756.us-west-2.elb.amazonaws.com/api/v1/nodes": dial tcp: lookup api-test-cluster-28361-k8-vgl76g-1901786756.us-west-2.elb.amazonaws.com on 10.63.240.10:53: no such host
W0511 01:19:47.465160    9357 validate_cluster.go:173] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-28361-k8-vgl76g-1901786756.us-west-2.elb.amazonaws.com/api/v1/nodes": dial tcp: lookup api-test-cluster-28361-k8-vgl76g-1901786756.us-west-2.elb.amazonaws.com on 10.63.240.10:53: no such host
W0511 01:20:09.064772    9357 validate_cluster.go:173] (will retry): unexpected error during validation: error listing nodes: an error on the server ("") has prevented the request from succeeding (get nodes)
W0511 01:20:30.593845    9357 validate_cluster.go:173] (will retry): unexpected error during validation: error listing nodes: an error on the server ("") has prevented the request from succeeding (get nodes)
W0511 01:20:52.176656    9357 validate_cluster.go:173] (will retry): unexpected error during validation: error listing nodes: an error on the server ("") has prevented the request from succeeding (get nodes)
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	1	1	us-west-2a
nodes-us-west-2b	Node	c5.large	1	1	us-west-2b
nodes-us-west-2c	Node	c5.large	1	1	us-west-2c
... skipping 6 lines ...
KIND	NAME						MESSAGE
Machine	i-0586c67e72dd6cbdb				machine "i-0586c67e72dd6cbdb" has not yet joined cluster
Machine	i-0afa6e52b1c8e40f6				machine "i-0afa6e52b1c8e40f6" has not yet joined cluster
Machine	i-0b2dfa841f4666361				machine "i-0b2dfa841f4666361" has not yet joined cluster
Node	ip-172-20-45-119.us-west-2.compute.internal	node "ip-172-20-45-119.us-west-2.compute.internal" of role "master" is not ready

Validation Failed
W0511 01:21:07.128001    9357 validate_cluster.go:221] (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	1	1	us-west-2a
nodes-us-west-2b	Node	c5.large	1	1	us-west-2b
... skipping 10 lines ...
Machine	i-0b2dfa841f4666361				machine "i-0b2dfa841f4666361" has not yet joined cluster
Node	ip-172-20-45-119.us-west-2.compute.internal	node "ip-172-20-45-119.us-west-2.compute.internal" of role "master" is not ready
Pod	kube-system/coredns-8f5559c9b-4brz7		system-cluster-critical pod "coredns-8f5559c9b-4brz7" is pending
Pod	kube-system/coredns-autoscaler-6f594f4c58-zfclb	system-cluster-critical pod "coredns-autoscaler-6f594f4c58-zfclb" is pending
Pod	kube-system/dns-controller-5d59c585d8-4c4dw	system-cluster-critical pod "dns-controller-5d59c585d8-4c4dw" is pending

Validation Failed
W0511 01:21:19.249975    9357 validate_cluster.go:221] (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	1	1	us-west-2a
nodes-us-west-2b	Node	c5.large	1	1	us-west-2b
... skipping 13 lines ...
Node	ip-172-20-45-119.us-west-2.compute.internal	master "ip-172-20-45-119.us-west-2.compute.internal" is missing kube-scheduler pod
Pod	kube-system/coredns-8f5559c9b-4brz7		system-cluster-critical pod "coredns-8f5559c9b-4brz7" is pending
Pod	kube-system/coredns-autoscaler-6f594f4c58-zfclb	system-cluster-critical pod "coredns-autoscaler-6f594f4c58-zfclb" is pending
Pod	kube-system/dns-controller-5d59c585d8-4c4dw	system-cluster-critical pod "dns-controller-5d59c585d8-4c4dw" is pending
Pod	kube-system/kops-controller-89xgn		system-node-critical pod "kops-controller-89xgn" is pending

Validation Failed
W0511 01:21:31.715985    9357 validate_cluster.go:221] (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	1	1	us-west-2a
nodes-us-west-2b	Node	c5.large	1	1	us-west-2b
... skipping 13 lines ...
Node	ip-172-20-45-119.us-west-2.compute.internal					master "ip-172-20-45-119.us-west-2.compute.internal" is missing kube-scheduler pod
Pod	kube-system/coredns-8f5559c9b-4brz7						system-cluster-critical pod "coredns-8f5559c9b-4brz7" is pending
Pod	kube-system/coredns-autoscaler-6f594f4c58-zfclb					system-cluster-critical pod "coredns-autoscaler-6f594f4c58-zfclb" is pending
Pod	kube-system/dns-controller-5d59c585d8-4c4dw					system-cluster-critical pod "dns-controller-5d59c585d8-4c4dw" is pending
Pod	kube-system/etcd-manager-main-ip-172-20-45-119.us-west-2.compute.internal	system-cluster-critical pod "etcd-manager-main-ip-172-20-45-119.us-west-2.compute.internal" is pending

Validation Failed
W0511 01:21:44.091623    9357 validate_cluster.go:221] (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	1	1	us-west-2a
nodes-us-west-2b	Node	c5.large	1	1	us-west-2b
... skipping 10 lines ...
Machine	i-0b2dfa841f4666361				machine "i-0b2dfa841f4666361" has not yet joined cluster
Node	ip-172-20-45-119.us-west-2.compute.internal	master "ip-172-20-45-119.us-west-2.compute.internal" is missing kube-controller-manager pod
Node	ip-172-20-45-119.us-west-2.compute.internal	master "ip-172-20-45-119.us-west-2.compute.internal" is missing kube-scheduler pod
Pod	kube-system/coredns-8f5559c9b-4brz7		system-cluster-critical pod "coredns-8f5559c9b-4brz7" is pending
Pod	kube-system/coredns-autoscaler-6f594f4c58-zfclb	system-cluster-critical pod "coredns-autoscaler-6f594f4c58-zfclb" is pending

Validation Failed
W0511 01:21:56.190544    9357 validate_cluster.go:221] (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	1	1	us-west-2a
nodes-us-west-2b	Node	c5.large	1	1	us-west-2b
... skipping 15 lines ...
Pod	kube-system/coredns-8f5559c9b-4brz7					system-cluster-critical pod "coredns-8f5559c9b-4brz7" is pending
Pod	kube-system/coredns-autoscaler-6f594f4c58-zfclb				system-cluster-critical pod "coredns-autoscaler-6f594f4c58-zfclb" is pending
Pod	kube-system/kube-proxy-ip-172-20-126-84.us-west-2.compute.internal	system-node-critical pod "kube-proxy-ip-172-20-126-84.us-west-2.compute.internal" is pending
Pod	kube-system/kube-proxy-ip-172-20-61-6.us-west-2.compute.internal	system-node-critical pod "kube-proxy-ip-172-20-61-6.us-west-2.compute.internal" is pending
Pod	kube-system/kube-proxy-ip-172-20-84-243.us-west-2.compute.internal	system-node-critical pod "kube-proxy-ip-172-20-84-243.us-west-2.compute.internal" is pending

Validation Failed
W0511 01:22:08.331329    9357 validate_cluster.go:221] (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	1	1	us-west-2a
nodes-us-west-2b	Node	c5.large	1	1	us-west-2b
... skipping 8 lines ...

VALIDATION ERRORS
KIND	NAME						MESSAGE
Node	ip-172-20-45-119.us-west-2.compute.internal	master "ip-172-20-45-119.us-west-2.compute.internal" is missing kube-scheduler pod
Pod	kube-system/coredns-8f5559c9b-l6xw9		system-cluster-critical pod "coredns-8f5559c9b-l6xw9" is pending

Validation Failed
W0511 01:22:20.586483    9357 validate_cluster.go:221] (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	1	1	us-west-2a
nodes-us-west-2b	Node	c5.large	1	1	us-west-2b
... skipping 7 lines ...
ip-172-20-84-243.us-west-2.compute.internal	node	True

VALIDATION ERRORS
KIND	NAME						MESSAGE
Node	ip-172-20-45-119.us-west-2.compute.internal	master "ip-172-20-45-119.us-west-2.compute.internal" is missing kube-scheduler pod

Validation Failed
W0511 01:22:32.589951    9357 validate_cluster.go:221] (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	1	1	us-west-2a
nodes-us-west-2b	Node	c5.large	1	1	us-west-2b
... skipping 7 lines ...
ip-172-20-84-243.us-west-2.compute.internal	node	True

VALIDATION ERRORS
KIND	NAME						MESSAGE
Node	ip-172-20-45-119.us-west-2.compute.internal	master "ip-172-20-45-119.us-west-2.compute.internal" is missing kube-scheduler pod

Validation Failed
W0511 01:22:44.960505    9357 validate_cluster.go:221] (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	1	1	us-west-2a
nodes-us-west-2b	Node	c5.large	1	1	us-west-2b
... skipping 126 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: ebs.csi.aws.com]
/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:175
  [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    should fail if subpath directory is outside the volume [Slow][LinuxOnly] [BeforeEach]
    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:240

    Driver ebs.csi.aws.com doesn't support ntfs -- skipping

    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:121
------------------------------
... skipping 45 lines ...
May 11 01:29:41.690: INFO: Waiting for pod external-injector to disappear
May 11 01:29:41.753: INFO: Pod external-injector still exists
May 11 01:29:43.690: INFO: Waiting for pod external-injector to disappear
May 11 01:29:43.753: INFO: Pod external-injector still exists
May 11 01:29:45.690: INFO: Waiting for pod external-injector to disappear
May 11 01:29:45.754: INFO: Pod external-injector no longer exists
May 11 01:29:45.754: FAIL: Failed to create injector pod: timed out waiting for the condition

Full Stack Trace
k8s.io/kubernetes/test/e2e/storage/testsuites.prepareSnapshotDataSourceForProvisioning(_, {{0xc00005f7e8, 0x11}, {0x281b564, 0x8}, {0x0, 0x0}, {0x0, 0x0, 0x0}, ...}, ...)
	/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/provisioning.go:845 +0x2e5
k8s.io/kubernetes/test/e2e/storage/testsuites.(*provisioningTestSuite).DefineTests.func4()
	/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/provisioning.go:219 +0x565
... skipping 10 lines ...
May 11 01:29:45.819: INFO: At 2022-05-11 01:24:37 +0000 UTC - event for pvc-vs8xz: {persistentvolume-controller } ExternalProvisioning: waiting for a volume to be created, either by external provisioner "ebs.csi.aws.com" or manually created by system administrator
May 11 01:29:45.819: INFO: At 2022-05-11 01:24:37 +0000 UTC - event for pvc-vs8xz: {ebs.csi.aws.com_ebs-csi-controller-65f7fb9696-j8nqp_23e52550-a198-4e6b-86aa-7a440fbfd693 } Provisioning: External provisioner is provisioning volume for claim "provisioning-5260/pvc-vs8xz"
May 11 01:29:45.819: INFO: At 2022-05-11 01:24:37 +0000 UTC - event for pvc-vs8xz: {persistentvolume-controller } WaitForFirstConsumer: waiting for first consumer to be created before binding
May 11 01:29:45.819: INFO: At 2022-05-11 01:24:43 +0000 UTC - event for pvc-vs8xz: {ebs.csi.aws.com_ebs-csi-controller-65f7fb9696-j8nqp_23e52550-a198-4e6b-86aa-7a440fbfd693 } ProvisioningSucceeded: Successfully provisioned volume pvc-11e032d9-f867-4428-8004-5f8e1520d361
May 11 01:29:45.819: INFO: At 2022-05-11 01:24:44 +0000 UTC - event for external-injector: {default-scheduler } Scheduled: Successfully assigned provisioning-5260/external-injector to ip-172-20-61-6.us-west-2.compute.internal
May 11 01:29:45.819: INFO: At 2022-05-11 01:24:48 +0000 UTC - event for external-injector: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-11e032d9-f867-4428-8004-5f8e1520d361" 
May 11 01:29:45.819: INFO: At 2022-05-11 01:25:02 +0000 UTC - event for external-injector: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: MountVolume.MountDevice failed for volume "pvc-11e032d9-f867-4428-8004-5f8e1520d361" : rpc error: code = Internal desc = could not format "/dev/nvme4n1" and mount it at "/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-11e032d9-f867-4428-8004-5f8e1520d361/globalmount": format of disk "/dev/nvme4n1" failed: type:("ext4") target:("/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-11e032d9-f867-4428-8004-5f8e1520d361/globalmount") options:("defaults") errcode:(exit status 127) output:(mkfs.ext4: symbol lookup error: /lib/x86_64-linux-gnu/libpthread.so.0: undefined symbol: __libc_vfork, version GLIBC_PRIVATE
) 
May 11 01:29:45.819: INFO: At 2022-05-11 01:26:47 +0000 UTC - event for external-injector: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[external-volume-0], unattached volumes=[external-volume-0 default-token-zb59k]: timed out waiting for the condition
May 11 01:29:45.819: INFO: At 2022-05-11 01:29:00 +0000 UTC - event for external-injector: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[external-volume-0], unattached volumes=[default-token-zb59k external-volume-0]: timed out waiting for the condition
May 11 01:29:45.881: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
May 11 01:29:45.881: INFO: 
May 11 01:29:46.004: INFO: 
... skipping 102 lines ...
/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:175
  [Testpattern: Dynamic PV (default fs)] provisioning
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    should provision storage with snapshot data source [Feature:VolumeSnapshotDataSource] [It]
    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/provisioning.go:200

    May 11 01:29:45.754: Failed to create injector pod: timed out waiting for the condition

    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/provisioning.go:845
------------------------------
SSS
------------------------------
[BeforeEach] [Testpattern: Inline-volume (default fs)] subPath
... skipping 188 lines ...
May 11 01:24:37.002: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(ebs.csi.aws.com) supported size:{ 1Mi} 
STEP: creating a StorageClass provisioning-4172-e2e-scr5pxd
STEP: creating a claim
May 11 01:24:37.071: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
STEP: Creating pod pod-subpath-test-dynamicpv-jjqm
STEP: Creating a pod to test atomic-volume-subpath
May 11 01:24:37.294: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-jjqm" in namespace "provisioning-4172" to be "Succeeded or Failed"
May 11 01:24:37.361: INFO: Pod "pod-subpath-test-dynamicpv-jjqm": Phase="Pending", Reason="", readiness=false. Elapsed: 66.835079ms
May 11 01:24:39.429: INFO: Pod "pod-subpath-test-dynamicpv-jjqm": Phase="Pending", Reason="", readiness=false. Elapsed: 2.134112199s
May 11 01:24:41.496: INFO: Pod "pod-subpath-test-dynamicpv-jjqm": Phase="Pending", Reason="", readiness=false. Elapsed: 4.201378215s
May 11 01:24:43.563: INFO: Pod "pod-subpath-test-dynamicpv-jjqm": Phase="Pending", Reason="", readiness=false. Elapsed: 6.26890894s
May 11 01:24:45.632: INFO: Pod "pod-subpath-test-dynamicpv-jjqm": Phase="Pending", Reason="", readiness=false. Elapsed: 8.337219156s
May 11 01:24:47.700: INFO: Pod "pod-subpath-test-dynamicpv-jjqm": Phase="Pending", Reason="", readiness=false. Elapsed: 10.405475874s
... skipping 134 lines ...
May 11 01:29:26.946: INFO: Pod "pod-subpath-test-dynamicpv-jjqm": Phase="Pending", Reason="", readiness=false. Elapsed: 4m49.651544765s
May 11 01:29:29.019: INFO: Pod "pod-subpath-test-dynamicpv-jjqm": Phase="Pending", Reason="", readiness=false. Elapsed: 4m51.724758335s
May 11 01:29:31.087: INFO: Pod "pod-subpath-test-dynamicpv-jjqm": Phase="Pending", Reason="", readiness=false. Elapsed: 4m53.792946833s
May 11 01:29:33.154: INFO: Pod "pod-subpath-test-dynamicpv-jjqm": Phase="Pending", Reason="", readiness=false. Elapsed: 4m55.860004569s
May 11 01:29:35.221: INFO: Pod "pod-subpath-test-dynamicpv-jjqm": Phase="Pending", Reason="", readiness=false. Elapsed: 4m57.926936047s
May 11 01:29:37.289: INFO: Pod "pod-subpath-test-dynamicpv-jjqm": Phase="Pending", Reason="", readiness=false. Elapsed: 4m59.994120095s
May 11 01:29:39.432: INFO: Failed to get logs from node "ip-172-20-61-6.us-west-2.compute.internal" pod "pod-subpath-test-dynamicpv-jjqm" container "init-volume-dynamicpv-jjqm": the server rejected our request for an unknown reason (get pods pod-subpath-test-dynamicpv-jjqm)
May 11 01:29:39.502: INFO: Failed to get logs from node "ip-172-20-61-6.us-west-2.compute.internal" pod "pod-subpath-test-dynamicpv-jjqm" container "test-container-subpath-dynamicpv-jjqm": the server rejected our request for an unknown reason (get pods pod-subpath-test-dynamicpv-jjqm)
STEP: delete the pod
May 11 01:29:39.571: INFO: Waiting for pod pod-subpath-test-dynamicpv-jjqm to disappear
May 11 01:29:39.637: INFO: Pod pod-subpath-test-dynamicpv-jjqm still exists
May 11 01:29:41.639: INFO: Waiting for pod pod-subpath-test-dynamicpv-jjqm to disappear
May 11 01:29:41.706: INFO: Pod pod-subpath-test-dynamicpv-jjqm still exists
May 11 01:29:43.638: INFO: Waiting for pod pod-subpath-test-dynamicpv-jjqm to disappear
... skipping 16 lines ...
May 11 01:29:56.329: INFO: At 2022-05-11 01:24:37 +0000 UTC - event for ebs.csi.aws.comfknhc: {persistentvolume-controller } WaitForFirstConsumer: waiting for first consumer to be created before binding
May 11 01:29:56.329: INFO: At 2022-05-11 01:24:37 +0000 UTC - event for ebs.csi.aws.comfknhc: {persistentvolume-controller } ExternalProvisioning: waiting for a volume to be created, either by external provisioner "ebs.csi.aws.com" or manually created by system administrator
May 11 01:29:56.330: INFO: At 2022-05-11 01:24:37 +0000 UTC - event for ebs.csi.aws.comfknhc: {ebs.csi.aws.com_ebs-csi-controller-65f7fb9696-j8nqp_23e52550-a198-4e6b-86aa-7a440fbfd693 } Provisioning: External provisioner is provisioning volume for claim "provisioning-4172/ebs.csi.aws.comfknhc"
May 11 01:29:56.330: INFO: At 2022-05-11 01:24:43 +0000 UTC - event for ebs.csi.aws.comfknhc: {ebs.csi.aws.com_ebs-csi-controller-65f7fb9696-j8nqp_23e52550-a198-4e6b-86aa-7a440fbfd693 } ProvisioningSucceeded: Successfully provisioned volume pvc-6910dfff-40b0-4c07-adbe-a53e563c240f
May 11 01:29:56.330: INFO: At 2022-05-11 01:24:44 +0000 UTC - event for pod-subpath-test-dynamicpv-jjqm: {default-scheduler } Scheduled: Successfully assigned provisioning-4172/pod-subpath-test-dynamicpv-jjqm to ip-172-20-61-6.us-west-2.compute.internal
May 11 01:29:56.330: INFO: At 2022-05-11 01:24:46 +0000 UTC - event for pod-subpath-test-dynamicpv-jjqm: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-6910dfff-40b0-4c07-adbe-a53e563c240f" 
May 11 01:29:56.330: INFO: At 2022-05-11 01:25:01 +0000 UTC - event for pod-subpath-test-dynamicpv-jjqm: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: MountVolume.MountDevice failed for volume "pvc-6910dfff-40b0-4c07-adbe-a53e563c240f" : rpc error: code = Internal desc = could not format "/dev/nvme3n1" and mount it at "/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-6910dfff-40b0-4c07-adbe-a53e563c240f/globalmount": format of disk "/dev/nvme3n1" failed: type:("ext4") target:("/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-6910dfff-40b0-4c07-adbe-a53e563c240f/globalmount") options:("defaults") errcode:(exit status 127) output:(mkfs.ext4: symbol lookup error: /lib/x86_64-linux-gnu/libpthread.so.0: undefined symbol: __libc_vfork, version GLIBC_PRIVATE
) 
May 11 01:29:56.330: INFO: At 2022-05-11 01:26:47 +0000 UTC - event for pod-subpath-test-dynamicpv-jjqm: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[test-volume], unattached volumes=[test-volume liveness-probe-volume default-token-bqv4x]: timed out waiting for the condition
May 11 01:29:56.399: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
May 11 01:29:56.399: INFO: 
May 11 01:29:56.531: INFO: 
Logging node info for node ip-172-20-126-84.us-west-2.compute.internal
... skipping 106 lines ...
/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:175
  [Testpattern: Dynamic PV (default fs)] subPath
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    should support file as subpath [LinuxOnly] [It]
    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:230

    Unexpected error:
        <*errors.errorString | 0xc000e97f80>: {
            s: "expected pod \"pod-subpath-test-dynamicpv-jjqm\" success: Gave up after waiting 5m0s for pod \"pod-subpath-test-dynamicpv-jjqm\" to be \"Succeeded or Failed\"",
        }
        expected pod "pod-subpath-test-dynamicpv-jjqm" success: Gave up after waiting 5m0s for pod "pod-subpath-test-dynamicpv-jjqm" to be "Succeeded or Failed"
    occurred

    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/framework/util.go:742
------------------------------
SSS
------------------------------
... skipping 75 lines ...
May 11 01:24:36.999: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(ebs.csi.aws.com) supported size:{ 1Mi} 
STEP: creating a StorageClass volume-3650-e2e-sc99trh
STEP: creating a claim
May 11 01:24:37.062: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
STEP: Creating pod exec-volume-test-dynamicpv-t424
STEP: Creating a pod to test exec-volume-test
May 11 01:24:37.291: INFO: Waiting up to 5m0s for pod "exec-volume-test-dynamicpv-t424" in namespace "volume-3650" to be "Succeeded or Failed"
May 11 01:24:37.353: INFO: Pod "exec-volume-test-dynamicpv-t424": Phase="Pending", Reason="", readiness=false. Elapsed: 62.542355ms
May 11 01:24:39.417: INFO: Pod "exec-volume-test-dynamicpv-t424": Phase="Pending", Reason="", readiness=false. Elapsed: 2.126740305s
May 11 01:24:41.479: INFO: Pod "exec-volume-test-dynamicpv-t424": Phase="Pending", Reason="", readiness=false. Elapsed: 4.188750843s
May 11 01:24:43.542: INFO: Pod "exec-volume-test-dynamicpv-t424": Phase="Pending", Reason="", readiness=false. Elapsed: 6.251497416s
May 11 01:24:45.605: INFO: Pod "exec-volume-test-dynamicpv-t424": Phase="Pending", Reason="", readiness=false. Elapsed: 8.314597311s
May 11 01:24:47.668: INFO: Pod "exec-volume-test-dynamicpv-t424": Phase="Pending", Reason="", readiness=false. Elapsed: 10.377279354s
... skipping 134 lines ...
May 11 01:29:26.242: INFO: Pod "exec-volume-test-dynamicpv-t424": Phase="Pending", Reason="", readiness=false. Elapsed: 4m48.951530076s
May 11 01:29:28.305: INFO: Pod "exec-volume-test-dynamicpv-t424": Phase="Pending", Reason="", readiness=false. Elapsed: 4m51.014369545s
May 11 01:29:30.367: INFO: Pod "exec-volume-test-dynamicpv-t424": Phase="Pending", Reason="", readiness=false. Elapsed: 4m53.076655674s
May 11 01:29:32.429: INFO: Pod "exec-volume-test-dynamicpv-t424": Phase="Pending", Reason="", readiness=false. Elapsed: 4m55.138514854s
May 11 01:29:34.491: INFO: Pod "exec-volume-test-dynamicpv-t424": Phase="Pending", Reason="", readiness=false. Elapsed: 4m57.200204033s
May 11 01:29:36.554: INFO: Pod "exec-volume-test-dynamicpv-t424": Phase="Pending", Reason="", readiness=false. Elapsed: 4m59.263079081s
May 11 01:29:38.704: INFO: Failed to get logs from node "ip-172-20-61-6.us-west-2.compute.internal" pod "exec-volume-test-dynamicpv-t424" container "exec-container-dynamicpv-t424": the server rejected our request for an unknown reason (get pods exec-volume-test-dynamicpv-t424)
STEP: delete the pod
May 11 01:29:38.767: INFO: Waiting for pod exec-volume-test-dynamicpv-t424 to disappear
May 11 01:29:38.829: INFO: Pod exec-volume-test-dynamicpv-t424 still exists
May 11 01:29:40.830: INFO: Waiting for pod exec-volume-test-dynamicpv-t424 to disappear
May 11 01:29:40.892: INFO: Pod exec-volume-test-dynamicpv-t424 still exists
May 11 01:29:42.830: INFO: Waiting for pod exec-volume-test-dynamicpv-t424 to disappear
... skipping 18 lines ...
May 11 01:30:07.589: INFO: At 2022-05-11 01:24:37 +0000 UTC - event for ebs.csi.aws.com4wqsf: {persistentvolume-controller } WaitForFirstConsumer: waiting for first consumer to be created before binding
May 11 01:30:07.589: INFO: At 2022-05-11 01:24:37 +0000 UTC - event for ebs.csi.aws.com4wqsf: {persistentvolume-controller } ExternalProvisioning: waiting for a volume to be created, either by external provisioner "ebs.csi.aws.com" or manually created by system administrator
May 11 01:30:07.589: INFO: At 2022-05-11 01:24:37 +0000 UTC - event for ebs.csi.aws.com4wqsf: {ebs.csi.aws.com_ebs-csi-controller-65f7fb9696-j8nqp_23e52550-a198-4e6b-86aa-7a440fbfd693 } Provisioning: External provisioner is provisioning volume for claim "volume-3650/ebs.csi.aws.com4wqsf"
May 11 01:30:07.589: INFO: At 2022-05-11 01:24:43 +0000 UTC - event for ebs.csi.aws.com4wqsf: {ebs.csi.aws.com_ebs-csi-controller-65f7fb9696-j8nqp_23e52550-a198-4e6b-86aa-7a440fbfd693 } ProvisioningSucceeded: Successfully provisioned volume pvc-0e101c5f-d6bb-48d3-b41e-207d78035684
May 11 01:30:07.589: INFO: At 2022-05-11 01:24:44 +0000 UTC - event for exec-volume-test-dynamicpv-t424: {default-scheduler } Scheduled: Successfully assigned volume-3650/exec-volume-test-dynamicpv-t424 to ip-172-20-61-6.us-west-2.compute.internal
May 11 01:30:07.589: INFO: At 2022-05-11 01:24:46 +0000 UTC - event for exec-volume-test-dynamicpv-t424: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-0e101c5f-d6bb-48d3-b41e-207d78035684" 
May 11 01:30:07.589: INFO: At 2022-05-11 01:24:47 +0000 UTC - event for exec-volume-test-dynamicpv-t424: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: MountVolume.MountDevice failed for volume "pvc-0e101c5f-d6bb-48d3-b41e-207d78035684" : rpc error: code = Internal desc = could not format "/dev/nvme2n1" and mount it at "/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-0e101c5f-d6bb-48d3-b41e-207d78035684/globalmount": format of disk "/dev/nvme2n1" failed: type:("xfs") target:("/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-0e101c5f-d6bb-48d3-b41e-207d78035684/globalmount") options:("nouuid,defaults") errcode:(exit status 127) output:(mkfs.xfs: symbol lookup error: /lib/x86_64-linux-gnu/libpthread.so.0: undefined symbol: __libc_vfork, version GLIBC_PRIVATE
) 
May 11 01:30:07.589: INFO: At 2022-05-11 01:26:47 +0000 UTC - event for exec-volume-test-dynamicpv-t424: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[vol1], unattached volumes=[vol1 default-token-rkkvm]: timed out waiting for the condition
May 11 01:30:07.650: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
May 11 01:30:07.650: INFO: 
May 11 01:30:07.771: INFO: 
Logging node info for node ip-172-20-126-84.us-west-2.compute.internal
... skipping 108 lines ...
/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:175
  [Testpattern: Dynamic PV (xfs)][Slow] volumes
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    should allow exec of files on the volume [It]
    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/volumes.go:196

    Unexpected error:
        <*errors.errorString | 0xc0003be970>: {
            s: "expected pod \"exec-volume-test-dynamicpv-t424\" success: Gave up after waiting 5m0s for pod \"exec-volume-test-dynamicpv-t424\" to be \"Succeeded or Failed\"",
        }
        expected pod "exec-volume-test-dynamicpv-t424" success: Gave up after waiting 5m0s for pod "exec-volume-test-dynamicpv-t424" to be "Succeeded or Failed"
    occurred

    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/framework/util.go:742
------------------------------
[BeforeEach] [Testpattern: Pre-provisioned PV (block volmode)] multiVolume [Slow]
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:51
... skipping 55 lines ...
May 11 01:29:59.111: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(ebs.csi.aws.com) supported size:{ 1Mi} 
STEP: creating a StorageClass volume-7516-e2e-scw6fkt
STEP: creating a claim
May 11 01:29:59.178: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
STEP: Creating pod exec-volume-test-dynamicpv-h9nt
STEP: Creating a pod to test exec-volume-test
May 11 01:29:59.386: INFO: Waiting up to 5m0s for pod "exec-volume-test-dynamicpv-h9nt" in namespace "volume-7516" to be "Succeeded or Failed"
May 11 01:29:59.452: INFO: Pod "exec-volume-test-dynamicpv-h9nt": Phase="Pending", Reason="", readiness=false. Elapsed: 66.215926ms
May 11 01:30:01.520: INFO: Pod "exec-volume-test-dynamicpv-h9nt": Phase="Pending", Reason="", readiness=false. Elapsed: 2.133748302s
May 11 01:30:03.588: INFO: Pod "exec-volume-test-dynamicpv-h9nt": Phase="Pending", Reason="", readiness=false. Elapsed: 4.201804407s
May 11 01:30:05.656: INFO: Pod "exec-volume-test-dynamicpv-h9nt": Phase="Pending", Reason="", readiness=false. Elapsed: 6.270286183s
May 11 01:30:07.725: INFO: Pod "exec-volume-test-dynamicpv-h9nt": Phase="Pending", Reason="", readiness=false. Elapsed: 8.338838484s
May 11 01:30:09.792: INFO: Pod "exec-volume-test-dynamicpv-h9nt": Phase="Pending", Reason="", readiness=false. Elapsed: 10.406303732s
... skipping 134 lines ...
May 11 01:34:49.006: INFO: Pod "exec-volume-test-dynamicpv-h9nt": Phase="Pending", Reason="", readiness=false. Elapsed: 4m49.619759081s
May 11 01:34:51.074: INFO: Pod "exec-volume-test-dynamicpv-h9nt": Phase="Pending", Reason="", readiness=false. Elapsed: 4m51.688620176s
May 11 01:34:53.142: INFO: Pod "exec-volume-test-dynamicpv-h9nt": Phase="Pending", Reason="", readiness=false. Elapsed: 4m53.755727478s
May 11 01:34:55.208: INFO: Pod "exec-volume-test-dynamicpv-h9nt": Phase="Pending", Reason="", readiness=false. Elapsed: 4m55.822582427s
May 11 01:34:57.276: INFO: Pod "exec-volume-test-dynamicpv-h9nt": Phase="Pending", Reason="", readiness=false. Elapsed: 4m57.889787468s
May 11 01:34:59.343: INFO: Pod "exec-volume-test-dynamicpv-h9nt": Phase="Pending", Reason="", readiness=false. Elapsed: 4m59.957487618s
May 11 01:35:01.485: INFO: Failed to get logs from node "ip-172-20-61-6.us-west-2.compute.internal" pod "exec-volume-test-dynamicpv-h9nt" container "exec-container-dynamicpv-h9nt": the server rejected our request for an unknown reason (get pods exec-volume-test-dynamicpv-h9nt)
STEP: delete the pod
May 11 01:35:01.555: INFO: Waiting for pod exec-volume-test-dynamicpv-h9nt to disappear
May 11 01:35:01.622: INFO: Pod exec-volume-test-dynamicpv-h9nt still exists
May 11 01:35:03.622: INFO: Waiting for pod exec-volume-test-dynamicpv-h9nt to disappear
May 11 01:35:03.690: INFO: Pod exec-volume-test-dynamicpv-h9nt still exists
May 11 01:35:05.622: INFO: Waiting for pod exec-volume-test-dynamicpv-h9nt to disappear
... skipping 13 lines ...
May 11 01:35:21.300: INFO: At 2022-05-11 01:29:59 +0000 UTC - event for ebs.csi.aws.comqmhhw: {persistentvolume-controller } WaitForFirstConsumer: waiting for first consumer to be created before binding
May 11 01:35:21.300: INFO: At 2022-05-11 01:29:59 +0000 UTC - event for ebs.csi.aws.comqmhhw: {persistentvolume-controller } ExternalProvisioning: waiting for a volume to be created, either by external provisioner "ebs.csi.aws.com" or manually created by system administrator
May 11 01:35:21.300: INFO: At 2022-05-11 01:29:59 +0000 UTC - event for ebs.csi.aws.comqmhhw: {ebs.csi.aws.com_ebs-csi-controller-65f7fb9696-j8nqp_23e52550-a198-4e6b-86aa-7a440fbfd693 } Provisioning: External provisioner is provisioning volume for claim "volume-7516/ebs.csi.aws.comqmhhw"
May 11 01:35:21.300: INFO: At 2022-05-11 01:30:02 +0000 UTC - event for ebs.csi.aws.comqmhhw: {ebs.csi.aws.com_ebs-csi-controller-65f7fb9696-j8nqp_23e52550-a198-4e6b-86aa-7a440fbfd693 } ProvisioningSucceeded: Successfully provisioned volume pvc-8e6b9a3e-504c-42d4-ba59-0bf2eba2be2a
May 11 01:35:21.300: INFO: At 2022-05-11 01:30:03 +0000 UTC - event for exec-volume-test-dynamicpv-h9nt: {default-scheduler } Scheduled: Successfully assigned volume-7516/exec-volume-test-dynamicpv-h9nt to ip-172-20-61-6.us-west-2.compute.internal
May 11 01:35:21.300: INFO: At 2022-05-11 01:30:05 +0000 UTC - event for exec-volume-test-dynamicpv-h9nt: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-8e6b9a3e-504c-42d4-ba59-0bf2eba2be2a" 
May 11 01:35:21.300: INFO: At 2022-05-11 01:30:07 +0000 UTC - event for exec-volume-test-dynamicpv-h9nt: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: MountVolume.MountDevice failed for volume "pvc-8e6b9a3e-504c-42d4-ba59-0bf2eba2be2a" : rpc error: code = Internal desc = could not format "/dev/nvme3n1" and mount it at "/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-8e6b9a3e-504c-42d4-ba59-0bf2eba2be2a/globalmount": format of disk "/dev/nvme3n1" failed: type:("ext4") target:("/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-8e6b9a3e-504c-42d4-ba59-0bf2eba2be2a/globalmount") options:("defaults") errcode:(exit status 127) output:(mkfs.ext4: symbol lookup error: /lib/x86_64-linux-gnu/libpthread.so.0: undefined symbol: __libc_vfork, version GLIBC_PRIVATE
) 
May 11 01:35:21.300: INFO: At 2022-05-11 01:32:06 +0000 UTC - event for exec-volume-test-dynamicpv-h9nt: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[vol1], unattached volumes=[vol1 default-token-tfmj6]: timed out waiting for the condition
May 11 01:35:21.366: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
May 11 01:35:21.366: INFO: 
May 11 01:35:21.475: INFO: 
Logging node info for node ip-172-20-126-84.us-west-2.compute.internal
... skipping 101 lines ...
/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:175
  [Testpattern: Dynamic PV (ext4)] volumes
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    should allow exec of files on the volume [It]
    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/volumes.go:196

    Unexpected error:
        <*errors.errorString | 0xc000f94c80>: {
            s: "expected pod \"exec-volume-test-dynamicpv-h9nt\" success: Gave up after waiting 5m0s for pod \"exec-volume-test-dynamicpv-h9nt\" to be \"Succeeded or Failed\"",
        }
        expected pod "exec-volume-test-dynamicpv-h9nt" success: Gave up after waiting 5m0s for pod "exec-volume-test-dynamicpv-h9nt" to be "Succeeded or Failed"
    occurred

    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/framework/util.go:742
------------------------------
S
------------------------------
... skipping 95 lines ...
May 11 01:30:10.191: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(ebs.csi.aws.com) supported size:{ 1Mi} 
STEP: creating a StorageClass provisioning-7927-e2e-scnr5p9
STEP: creating a claim
May 11 01:30:10.253: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
STEP: Creating pod pod-subpath-test-dynamicpv-xx4b
STEP: Creating a pod to test subpath
May 11 01:30:10.442: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-xx4b" in namespace "provisioning-7927" to be "Succeeded or Failed"
May 11 01:30:10.504: INFO: Pod "pod-subpath-test-dynamicpv-xx4b": Phase="Pending", Reason="", readiness=false. Elapsed: 61.642997ms
May 11 01:30:12.566: INFO: Pod "pod-subpath-test-dynamicpv-xx4b": Phase="Pending", Reason="", readiness=false. Elapsed: 2.123683019s
May 11 01:30:14.628: INFO: Pod "pod-subpath-test-dynamicpv-xx4b": Phase="Pending", Reason="", readiness=false. Elapsed: 4.185663754s
May 11 01:30:16.691: INFO: Pod "pod-subpath-test-dynamicpv-xx4b": Phase="Pending", Reason="", readiness=false. Elapsed: 6.249509535s
May 11 01:30:18.754: INFO: Pod "pod-subpath-test-dynamicpv-xx4b": Phase="Pending", Reason="", readiness=false. Elapsed: 8.312024457s
May 11 01:30:20.817: INFO: Pod "pod-subpath-test-dynamicpv-xx4b": Phase="Pending", Reason="", readiness=false. Elapsed: 10.375279296s
... skipping 134 lines ...
May 11 01:34:59.305: INFO: Pod "pod-subpath-test-dynamicpv-xx4b": Phase="Pending", Reason="", readiness=false. Elapsed: 4m48.862663392s
May 11 01:35:01.375: INFO: Pod "pod-subpath-test-dynamicpv-xx4b": Phase="Pending", Reason="", readiness=false. Elapsed: 4m50.933508166s
May 11 01:35:03.437: INFO: Pod "pod-subpath-test-dynamicpv-xx4b": Phase="Pending", Reason="", readiness=false. Elapsed: 4m52.994622525s
May 11 01:35:05.498: INFO: Pod "pod-subpath-test-dynamicpv-xx4b": Phase="Pending", Reason="", readiness=false. Elapsed: 4m55.056091004s
May 11 01:35:07.559: INFO: Pod "pod-subpath-test-dynamicpv-xx4b": Phase="Pending", Reason="", readiness=false. Elapsed: 4m57.116914491s
May 11 01:35:09.620: INFO: Pod "pod-subpath-test-dynamicpv-xx4b": Phase="Pending", Reason="", readiness=false. Elapsed: 4m59.177916095s
May 11 01:35:11.750: INFO: Failed to get logs from node "ip-172-20-61-6.us-west-2.compute.internal" pod "pod-subpath-test-dynamicpv-xx4b" container "init-volume-dynamicpv-xx4b": the server rejected our request for an unknown reason (get pods pod-subpath-test-dynamicpv-xx4b)
May 11 01:35:11.821: INFO: Failed to get logs from node "ip-172-20-61-6.us-west-2.compute.internal" pod "pod-subpath-test-dynamicpv-xx4b" container "test-init-volume-dynamicpv-xx4b": the server rejected our request for an unknown reason (get pods pod-subpath-test-dynamicpv-xx4b)
May 11 01:35:11.883: INFO: Failed to get logs from node "ip-172-20-61-6.us-west-2.compute.internal" pod "pod-subpath-test-dynamicpv-xx4b" container "test-container-subpath-dynamicpv-xx4b": the server rejected our request for an unknown reason (get pods pod-subpath-test-dynamicpv-xx4b)
STEP: delete the pod
May 11 01:35:11.950: INFO: Waiting for pod pod-subpath-test-dynamicpv-xx4b to disappear
May 11 01:35:12.010: INFO: Pod pod-subpath-test-dynamicpv-xx4b still exists
May 11 01:35:14.012: INFO: Waiting for pod pod-subpath-test-dynamicpv-xx4b to disappear
May 11 01:35:14.073: INFO: Pod pod-subpath-test-dynamicpv-xx4b still exists
May 11 01:35:16.012: INFO: Waiting for pod pod-subpath-test-dynamicpv-xx4b to disappear
... skipping 14 lines ...
May 11 01:35:26.659: INFO: At 2022-05-11 01:30:10 +0000 UTC - event for ebs.csi.aws.comdmcfr: {persistentvolume-controller } WaitForFirstConsumer: waiting for first consumer to be created before binding
May 11 01:35:26.659: INFO: At 2022-05-11 01:30:10 +0000 UTC - event for ebs.csi.aws.comdmcfr: {persistentvolume-controller } ExternalProvisioning: waiting for a volume to be created, either by external provisioner "ebs.csi.aws.com" or manually created by system administrator
May 11 01:35:26.659: INFO: At 2022-05-11 01:30:10 +0000 UTC - event for ebs.csi.aws.comdmcfr: {ebs.csi.aws.com_ebs-csi-controller-65f7fb9696-j8nqp_23e52550-a198-4e6b-86aa-7a440fbfd693 } Provisioning: External provisioner is provisioning volume for claim "provisioning-7927/ebs.csi.aws.comdmcfr"
May 11 01:35:26.659: INFO: At 2022-05-11 01:30:13 +0000 UTC - event for ebs.csi.aws.comdmcfr: {ebs.csi.aws.com_ebs-csi-controller-65f7fb9696-j8nqp_23e52550-a198-4e6b-86aa-7a440fbfd693 } ProvisioningSucceeded: Successfully provisioned volume pvc-67447100-db4a-4297-a151-2c8039abba69
May 11 01:35:26.659: INFO: At 2022-05-11 01:30:14 +0000 UTC - event for pod-subpath-test-dynamicpv-xx4b: {default-scheduler } Scheduled: Successfully assigned provisioning-7927/pod-subpath-test-dynamicpv-xx4b to ip-172-20-61-6.us-west-2.compute.internal
May 11 01:35:26.659: INFO: At 2022-05-11 01:30:16 +0000 UTC - event for pod-subpath-test-dynamicpv-xx4b: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-67447100-db4a-4297-a151-2c8039abba69" 
May 11 01:35:26.659: INFO: At 2022-05-11 01:30:18 +0000 UTC - event for pod-subpath-test-dynamicpv-xx4b: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: MountVolume.MountDevice failed for volume "pvc-67447100-db4a-4297-a151-2c8039abba69" : rpc error: code = Internal desc = could not format "/dev/nvme4n1" and mount it at "/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-67447100-db4a-4297-a151-2c8039abba69/globalmount": format of disk "/dev/nvme4n1" failed: type:("ext4") target:("/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-67447100-db4a-4297-a151-2c8039abba69/globalmount") options:("defaults") errcode:(exit status 127) output:(mkfs.ext4: symbol lookup error: /lib/x86_64-linux-gnu/libpthread.so.0: undefined symbol: __libc_vfork, version GLIBC_PRIVATE
) 
May 11 01:35:26.659: INFO: At 2022-05-11 01:32:17 +0000 UTC - event for pod-subpath-test-dynamicpv-xx4b: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[test-volume], unattached volumes=[test-volume liveness-probe-volume default-token-46vpx]: timed out waiting for the condition
May 11 01:35:26.659: INFO: At 2022-05-11 01:34:32 +0000 UTC - event for pod-subpath-test-dynamicpv-xx4b: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[test-volume], unattached volumes=[default-token-46vpx test-volume liveness-probe-volume]: timed out waiting for the condition
May 11 01:35:26.719: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
May 11 01:35:26.719: INFO: 
May 11 01:35:26.839: INFO: 
... skipping 102 lines ...
/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:175
  [Testpattern: Dynamic PV (default fs)] subPath
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    should support readOnly directory specified in the volumeMount [It]
    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:369

    Unexpected error:
        <*errors.errorString | 0xc000a91cc0>: {
            s: "expected pod \"pod-subpath-test-dynamicpv-xx4b\" success: Gave up after waiting 5m0s for pod \"pod-subpath-test-dynamicpv-xx4b\" to be \"Succeeded or Failed\"",
        }
        expected pod "pod-subpath-test-dynamicpv-xx4b" success: Gave up after waiting 5m0s for pod "pod-subpath-test-dynamicpv-xx4b" to be "Succeeded or Failed"
    occurred

    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/framework/util.go:742
------------------------------
External Storage [Driver: ebs.csi.aws.com] [Testpattern: Dynamic PV (default fs)] subPath 
  should support existing directory
... skipping 13 lines ...
May 11 01:29:49.868: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(ebs.csi.aws.com) supported size:{ 1Mi} 
STEP: creating a StorageClass provisioning-2305-e2e-sc26rgr
STEP: creating a claim
May 11 01:29:49.932: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
STEP: Creating pod pod-subpath-test-dynamicpv-msbw
STEP: Creating a pod to test subpath
May 11 01:29:50.125: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-msbw" in namespace "provisioning-2305" to be "Succeeded or Failed"
May 11 01:29:50.188: INFO: Pod "pod-subpath-test-dynamicpv-msbw": Phase="Pending", Reason="", readiness=false. Elapsed: 62.753847ms
May 11 01:29:52.251: INFO: Pod "pod-subpath-test-dynamicpv-msbw": Phase="Pending", Reason="", readiness=false. Elapsed: 2.125897151s
May 11 01:29:54.315: INFO: Pod "pod-subpath-test-dynamicpv-msbw": Phase="Pending", Reason="", readiness=false. Elapsed: 4.189212886s
May 11 01:29:56.378: INFO: Pod "pod-subpath-test-dynamicpv-msbw": Phase="Pending", Reason="", readiness=false. Elapsed: 6.252427954s
May 11 01:29:58.441: INFO: Pod "pod-subpath-test-dynamicpv-msbw": Phase="Pending", Reason="", readiness=false. Elapsed: 8.315421572s
May 11 01:30:00.504: INFO: Pod "pod-subpath-test-dynamicpv-msbw": Phase="Pending", Reason="", readiness=false. Elapsed: 10.378947341s
... skipping 134 lines ...
May 11 01:34:39.458: INFO: Pod "pod-subpath-test-dynamicpv-msbw": Phase="Pending", Reason="", readiness=false. Elapsed: 4m49.332715743s
May 11 01:34:41.522: INFO: Pod "pod-subpath-test-dynamicpv-msbw": Phase="Pending", Reason="", readiness=false. Elapsed: 4m51.396315644s
May 11 01:34:43.586: INFO: Pod "pod-subpath-test-dynamicpv-msbw": Phase="Pending", Reason="", readiness=false. Elapsed: 4m53.460320199s
May 11 01:34:45.649: INFO: Pod "pod-subpath-test-dynamicpv-msbw": Phase="Pending", Reason="", readiness=false. Elapsed: 4m55.523442303s
May 11 01:34:47.713: INFO: Pod "pod-subpath-test-dynamicpv-msbw": Phase="Pending", Reason="", readiness=false. Elapsed: 4m57.587549432s
May 11 01:34:49.777: INFO: Pod "pod-subpath-test-dynamicpv-msbw": Phase="Pending", Reason="", readiness=false. Elapsed: 4m59.651604083s
May 11 01:34:51.920: INFO: Failed to get logs from node "ip-172-20-61-6.us-west-2.compute.internal" pod "pod-subpath-test-dynamicpv-msbw" container "init-volume-dynamicpv-msbw": the server rejected our request for an unknown reason (get pods pod-subpath-test-dynamicpv-msbw)
May 11 01:34:51.984: INFO: Failed to get logs from node "ip-172-20-61-6.us-west-2.compute.internal" pod "pod-subpath-test-dynamicpv-msbw" container "test-init-subpath-dynamicpv-msbw": the server rejected our request for an unknown reason (get pods pod-subpath-test-dynamicpv-msbw)
May 11 01:34:52.050: INFO: Failed to get logs from node "ip-172-20-61-6.us-west-2.compute.internal" pod "pod-subpath-test-dynamicpv-msbw" container "test-container-subpath-dynamicpv-msbw": the server rejected our request for an unknown reason (get pods pod-subpath-test-dynamicpv-msbw)
May 11 01:34:52.113: INFO: Failed to get logs from node "ip-172-20-61-6.us-west-2.compute.internal" pod "pod-subpath-test-dynamicpv-msbw" container "test-container-volume-dynamicpv-msbw": the server rejected our request for an unknown reason (get pods pod-subpath-test-dynamicpv-msbw)
STEP: delete the pod
May 11 01:34:52.178: INFO: Waiting for pod pod-subpath-test-dynamicpv-msbw to disappear
May 11 01:34:52.241: INFO: Pod pod-subpath-test-dynamicpv-msbw still exists
May 11 01:34:54.242: INFO: Waiting for pod pod-subpath-test-dynamicpv-msbw to disappear
May 11 01:34:54.305: INFO: Pod pod-subpath-test-dynamicpv-msbw still exists
May 11 01:34:56.242: INFO: Waiting for pod pod-subpath-test-dynamicpv-msbw to disappear
... skipping 19 lines ...
May 11 01:35:32.202: INFO: At 2022-05-11 01:29:49 +0000 UTC - event for ebs.csi.aws.combfhz6: {persistentvolume-controller } WaitForFirstConsumer: waiting for first consumer to be created before binding
May 11 01:35:32.202: INFO: At 2022-05-11 01:29:50 +0000 UTC - event for ebs.csi.aws.combfhz6: {persistentvolume-controller } ExternalProvisioning: waiting for a volume to be created, either by external provisioner "ebs.csi.aws.com" or manually created by system administrator
May 11 01:35:32.202: INFO: At 2022-05-11 01:29:50 +0000 UTC - event for ebs.csi.aws.combfhz6: {ebs.csi.aws.com_ebs-csi-controller-65f7fb9696-j8nqp_23e52550-a198-4e6b-86aa-7a440fbfd693 } Provisioning: External provisioner is provisioning volume for claim "provisioning-2305/ebs.csi.aws.combfhz6"
May 11 01:35:32.202: INFO: At 2022-05-11 01:29:53 +0000 UTC - event for ebs.csi.aws.combfhz6: {ebs.csi.aws.com_ebs-csi-controller-65f7fb9696-j8nqp_23e52550-a198-4e6b-86aa-7a440fbfd693 } ProvisioningSucceeded: Successfully provisioned volume pvc-69ea62cc-a9a6-489f-9403-964c6b9bb529
May 11 01:35:32.202: INFO: At 2022-05-11 01:29:54 +0000 UTC - event for pod-subpath-test-dynamicpv-msbw: {default-scheduler } Scheduled: Successfully assigned provisioning-2305/pod-subpath-test-dynamicpv-msbw to ip-172-20-61-6.us-west-2.compute.internal
May 11 01:35:32.202: INFO: At 2022-05-11 01:29:56 +0000 UTC - event for pod-subpath-test-dynamicpv-msbw: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-69ea62cc-a9a6-489f-9403-964c6b9bb529" 
May 11 01:35:32.202: INFO: At 2022-05-11 01:29:57 +0000 UTC - event for pod-subpath-test-dynamicpv-msbw: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: MountVolume.MountDevice failed for volume "pvc-69ea62cc-a9a6-489f-9403-964c6b9bb529" : rpc error: code = Internal desc = could not format "/dev/nvme2n1" and mount it at "/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-69ea62cc-a9a6-489f-9403-964c6b9bb529/globalmount": format of disk "/dev/nvme2n1" failed: type:("ext4") target:("/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-69ea62cc-a9a6-489f-9403-964c6b9bb529/globalmount") options:("defaults") errcode:(exit status 127) output:(mkfs.ext4: symbol lookup error: /lib/x86_64-linux-gnu/libpthread.so.0: undefined symbol: __libc_vfork, version GLIBC_PRIVATE
) 
May 11 01:35:32.202: INFO: At 2022-05-11 01:31:57 +0000 UTC - event for pod-subpath-test-dynamicpv-msbw: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[test-volume], unattached volumes=[test-volume liveness-probe-volume default-token-j4v5b]: timed out waiting for the condition
May 11 01:35:32.264: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
May 11 01:35:32.264: INFO: 
May 11 01:35:32.329: INFO: 
Logging node info for node ip-172-20-126-84.us-west-2.compute.internal
... skipping 105 lines ...
/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:175
  [Testpattern: Dynamic PV (default fs)] subPath
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    should support existing directory [It]
    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:205

    Unexpected error:
        <*errors.errorString | 0xc000f34000>: {
            s: "expected pod \"pod-subpath-test-dynamicpv-msbw\" success: Gave up after waiting 5m0s for pod \"pod-subpath-test-dynamicpv-msbw\" to be \"Succeeded or Failed\"",
        }
        expected pod "pod-subpath-test-dynamicpv-msbw" success: Gave up after waiting 5m0s for pod "pod-subpath-test-dynamicpv-msbw" to be "Succeeded or Failed"
    occurred

    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/framework/util.go:742
------------------------------
[BeforeEach] [Testpattern: Pre-provisioned PV (block volmode)] multiVolume [Slow]
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:51
... skipping 34 lines ...
May 11 01:24:37.012: INFO: Creating resource for dynamic PV
May 11 01:24:37.012: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(ebs.csi.aws.com) supported size:{ 1Mi} 
STEP: creating a StorageClass snapshotting-8694-e2e-scn28z6
STEP: creating a claim
May 11 01:24:37.077: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
STEP: [init] starting a pod to use the claim
May 11 01:24:37.293: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-l7s22" in namespace "snapshotting-8694" to be "Succeeded or Failed"
May 11 01:24:37.358: INFO: Pod "pvc-snapshottable-tester-l7s22": Phase="Pending", Reason="", readiness=false. Elapsed: 64.549504ms
May 11 01:24:39.422: INFO: Pod "pvc-snapshottable-tester-l7s22": Phase="Pending", Reason="", readiness=false. Elapsed: 2.128501908s
May 11 01:24:41.486: INFO: Pod "pvc-snapshottable-tester-l7s22": Phase="Pending", Reason="", readiness=false. Elapsed: 4.192572768s
May 11 01:24:43.550: INFO: Pod "pvc-snapshottable-tester-l7s22": Phase="Pending", Reason="", readiness=false. Elapsed: 6.257018617s
May 11 01:24:45.615: INFO: Pod "pvc-snapshottable-tester-l7s22": Phase="Pending", Reason="", readiness=false. Elapsed: 8.321863291s
May 11 01:24:47.681: INFO: Pod "pvc-snapshottable-tester-l7s22": Phase="Pending", Reason="", readiness=false. Elapsed: 10.387570524s
... skipping 424 lines ...
May 11 01:39:25.473: INFO: Pod "pvc-snapshottable-tester-l7s22": Phase="Pending", Reason="", readiness=false. Elapsed: 14m48.180015293s
May 11 01:39:27.537: INFO: Pod "pvc-snapshottable-tester-l7s22": Phase="Pending", Reason="", readiness=false. Elapsed: 14m50.243419892s
May 11 01:39:29.601: INFO: Pod "pvc-snapshottable-tester-l7s22": Phase="Pending", Reason="", readiness=false. Elapsed: 14m52.30789049s
May 11 01:39:31.665: INFO: Pod "pvc-snapshottable-tester-l7s22": Phase="Pending", Reason="", readiness=false. Elapsed: 14m54.371463134s
May 11 01:39:33.728: INFO: Pod "pvc-snapshottable-tester-l7s22": Phase="Pending", Reason="", readiness=false. Elapsed: 14m56.434840861s
May 11 01:39:35.793: INFO: Pod "pvc-snapshottable-tester-l7s22": Phase="Pending", Reason="", readiness=false. Elapsed: 14m58.49985632s
May 11 01:39:37.864: INFO: Error getting logs for pod pvc-snapshottable-tester-l7s22: the server rejected our request for an unknown reason (get pods pvc-snapshottable-tester-l7s22)
May 11 01:39:37.864: INFO: Deleting pod "pvc-snapshottable-tester-l7s22" in namespace "snapshotting-8694"
May 11 01:39:37.929: INFO: Wait up to 5m0s for pod "pvc-snapshottable-tester-l7s22" to be fully deleted
[AfterEach] volume snapshot controller
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/snapshottable.go:223
STEP: Deleting pvc
May 11 01:39:46.183: INFO: Deleting PersistentVolumeClaim "ebs.csi.aws.com9gznc"
... skipping 9 lines ...
May 11 01:39:56.570: INFO: At 2022-05-11 01:24:37 +0000 UTC - event for ebs.csi.aws.com9gznc: {persistentvolume-controller } WaitForFirstConsumer: waiting for first consumer to be created before binding
May 11 01:39:56.570: INFO: At 2022-05-11 01:24:37 +0000 UTC - event for ebs.csi.aws.com9gznc: {persistentvolume-controller } ExternalProvisioning: waiting for a volume to be created, either by external provisioner "ebs.csi.aws.com" or manually created by system administrator
May 11 01:39:56.570: INFO: At 2022-05-11 01:24:37 +0000 UTC - event for ebs.csi.aws.com9gznc: {ebs.csi.aws.com_ebs-csi-controller-65f7fb9696-j8nqp_23e52550-a198-4e6b-86aa-7a440fbfd693 } Provisioning: External provisioner is provisioning volume for claim "snapshotting-8694/ebs.csi.aws.com9gznc"
May 11 01:39:56.570: INFO: At 2022-05-11 01:24:43 +0000 UTC - event for ebs.csi.aws.com9gznc: {ebs.csi.aws.com_ebs-csi-controller-65f7fb9696-j8nqp_23e52550-a198-4e6b-86aa-7a440fbfd693 } ProvisioningSucceeded: Successfully provisioned volume pvc-890df997-d6be-4b66-831f-a2c052e6aca6
May 11 01:39:56.570: INFO: At 2022-05-11 01:24:44 +0000 UTC - event for pvc-snapshottable-tester-l7s22: {default-scheduler } Scheduled: Successfully assigned snapshotting-8694/pvc-snapshottable-tester-l7s22 to ip-172-20-61-6.us-west-2.compute.internal
May 11 01:39:56.570: INFO: At 2022-05-11 01:24:46 +0000 UTC - event for pvc-snapshottable-tester-l7s22: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-890df997-d6be-4b66-831f-a2c052e6aca6" 
May 11 01:39:56.570: INFO: At 2022-05-11 01:24:47 +0000 UTC - event for pvc-snapshottable-tester-l7s22: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: MountVolume.MountDevice failed for volume "pvc-890df997-d6be-4b66-831f-a2c052e6aca6" : rpc error: code = Internal desc = could not format "/dev/nvme1n1" and mount it at "/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-890df997-d6be-4b66-831f-a2c052e6aca6/globalmount": format of disk "/dev/nvme1n1" failed: type:("ext4") target:("/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-890df997-d6be-4b66-831f-a2c052e6aca6/globalmount") options:("defaults") errcode:(exit status 127) output:(mkfs.ext4: symbol lookup error: /lib/x86_64-linux-gnu/libpthread.so.0: undefined symbol: __libc_vfork, version GLIBC_PRIVATE
) 
May 11 01:39:56.570: INFO: At 2022-05-11 01:26:47 +0000 UTC - event for pvc-snapshottable-tester-l7s22: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[my-volume], unattached volumes=[my-volume default-token-cdf9s]: timed out waiting for the condition
May 11 01:39:56.570: INFO: At 2022-05-11 01:33:37 +0000 UTC - event for pvc-snapshottable-tester-l7s22: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[my-volume], unattached volumes=[default-token-cdf9s my-volume]: timed out waiting for the condition
May 11 01:39:56.633: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
May 11 01:39:56.633: INFO: 
May 11 01:39:56.757: INFO: 
... skipping 110 lines ...
    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/snapshottable.go:108
       [BeforeEach]
      /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/snapshottable.go:227
        should check snapshot fields, check restore correctly works after modifying source data, check deletion
        /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/snapshottable.go:245

        Unexpected error:
            <*errors.errorString | 0xc000b42e50>: {
                s: "Gave up after waiting 15m0s for pod \"pvc-snapshottable-tester-l7s22\" to be \"Succeeded or Failed\"",
            }
            Gave up after waiting 15m0s for pod "pvc-snapshottable-tester-l7s22" to be "Succeeded or Failed"
        occurred

        /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/provisioning.go:675
------------------------------
S
------------------------------
... skipping 37 lines ...
May 11 01:41:11.586: INFO: At 2022-05-11 01:35:29 +0000 UTC - event for ebs.csi.aws.comc9jbc: {persistentvolume-controller } WaitForFirstConsumer: waiting for first consumer to be created before binding
May 11 01:41:11.586: INFO: At 2022-05-11 01:35:29 +0000 UTC - event for ebs.csi.aws.comc9jbc: {persistentvolume-controller } ExternalProvisioning: waiting for a volume to be created, either by external provisioner "ebs.csi.aws.com" or manually created by system administrator
May 11 01:41:11.586: INFO: At 2022-05-11 01:35:29 +0000 UTC - event for ebs.csi.aws.comc9jbc: {ebs.csi.aws.com_ebs-csi-controller-65f7fb9696-j8nqp_23e52550-a198-4e6b-86aa-7a440fbfd693 } Provisioning: External provisioner is provisioning volume for claim "multivolume-9749/ebs.csi.aws.comc9jbc"
May 11 01:41:11.586: INFO: At 2022-05-11 01:35:32 +0000 UTC - event for ebs.csi.aws.comc9jbc: {ebs.csi.aws.com_ebs-csi-controller-65f7fb9696-j8nqp_23e52550-a198-4e6b-86aa-7a440fbfd693 } ProvisioningSucceeded: Successfully provisioned volume pvc-f96ca91c-7770-48de-81c1-dca423b4f971
May 11 01:41:11.586: INFO: At 2022-05-11 01:35:33 +0000 UTC - event for pod-d8979626-32d7-4518-ab85-97f6e36b50bb: {default-scheduler } Scheduled: Successfully assigned multivolume-9749/pod-d8979626-32d7-4518-ab85-97f6e36b50bb to ip-172-20-61-6.us-west-2.compute.internal
May 11 01:41:11.586: INFO: At 2022-05-11 01:35:35 +0000 UTC - event for pod-d8979626-32d7-4518-ab85-97f6e36b50bb: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-f96ca91c-7770-48de-81c1-dca423b4f971" 
May 11 01:41:11.586: INFO: At 2022-05-11 01:35:37 +0000 UTC - event for pod-d8979626-32d7-4518-ab85-97f6e36b50bb: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: MountVolume.MountDevice failed for volume "pvc-f96ca91c-7770-48de-81c1-dca423b4f971" : rpc error: code = Internal desc = could not format "/dev/nvme3n1" and mount it at "/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-f96ca91c-7770-48de-81c1-dca423b4f971/globalmount": format of disk "/dev/nvme3n1" failed: type:("ext4") target:("/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-f96ca91c-7770-48de-81c1-dca423b4f971/globalmount") options:("defaults") errcode:(exit status 127) output:(mkfs.ext4: symbol lookup error: /lib/x86_64-linux-gnu/libpthread.so.0: undefined symbol: __libc_vfork, version GLIBC_PRIVATE
) 
May 11 01:41:11.586: INFO: At 2022-05-11 01:37:36 +0000 UTC - event for pod-d8979626-32d7-4518-ab85-97f6e36b50bb: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[volume1], unattached volumes=[volume1 default-token-f2cgv]: timed out waiting for the condition
May 11 01:41:11.586: INFO: At 2022-05-11 01:39:50 +0000 UTC - event for pod-d8979626-32d7-4518-ab85-97f6e36b50bb: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[volume1], unattached volumes=[default-token-f2cgv volume1]: timed out waiting for the condition
May 11 01:41:11.649: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
May 11 01:41:11.649: INFO: 
May 11 01:41:11.711: INFO: 
... skipping 102 lines ...
/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:175
  [Testpattern: Dynamic PV (filesystem volmode)] multiVolume [Slow]
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    should concurrently access the single read-only volume from pods on the same node [It]
    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/multivolume.go:337

    Unexpected error:
        <*errors.errorString | 0xc0003bf030>: {
            s: "pod \"pod-d8979626-32d7-4518-ab85-97f6e36b50bb\" is not Running: timed out waiting for the condition",
        }
        pod "pod-d8979626-32d7-4518-ab85-97f6e36b50bb" is not Running: timed out waiting for the condition
    occurred

... skipping 41 lines ...
May 11 01:41:12.513: INFO: At 2022-05-11 01:35:24 +0000 UTC - event for pvc-8p9xg: {ebs.csi.aws.com_ebs-csi-controller-65f7fb9696-j8nqp_23e52550-a198-4e6b-86aa-7a440fbfd693 } Provisioning: External provisioner is provisioning volume for claim "topology-9247/pvc-8p9xg"
May 11 01:41:12.513: INFO: At 2022-05-11 01:35:24 +0000 UTC - event for pvc-8p9xg: {persistentvolume-controller } WaitForFirstConsumer: waiting for first consumer to be created before binding
May 11 01:41:12.513: INFO: At 2022-05-11 01:35:24 +0000 UTC - event for pvc-8p9xg: {persistentvolume-controller } ExternalProvisioning: waiting for a volume to be created, either by external provisioner "ebs.csi.aws.com" or manually created by system administrator
May 11 01:41:12.513: INFO: At 2022-05-11 01:35:27 +0000 UTC - event for pvc-8p9xg: {ebs.csi.aws.com_ebs-csi-controller-65f7fb9696-j8nqp_23e52550-a198-4e6b-86aa-7a440fbfd693 } ProvisioningSucceeded: Successfully provisioned volume pvc-29339c1f-067d-404d-b403-8720f98ae3a2
May 11 01:41:12.513: INFO: At 2022-05-11 01:35:28 +0000 UTC - event for pod-d97e80af-ac05-4773-a8d2-6b514a8366a2: {default-scheduler } Scheduled: Successfully assigned topology-9247/pod-d97e80af-ac05-4773-a8d2-6b514a8366a2 to ip-172-20-61-6.us-west-2.compute.internal
May 11 01:41:12.513: INFO: At 2022-05-11 01:35:30 +0000 UTC - event for pod-d97e80af-ac05-4773-a8d2-6b514a8366a2: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-29339c1f-067d-404d-b403-8720f98ae3a2" 
May 11 01:41:12.513: INFO: At 2022-05-11 01:35:44 +0000 UTC - event for pod-d97e80af-ac05-4773-a8d2-6b514a8366a2: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: MountVolume.MountDevice failed for volume "pvc-29339c1f-067d-404d-b403-8720f98ae3a2" : rpc error: code = Internal desc = could not format "/dev/nvme2n1" and mount it at "/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-29339c1f-067d-404d-b403-8720f98ae3a2/globalmount": format of disk "/dev/nvme2n1" failed: type:("ext4") target:("/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-29339c1f-067d-404d-b403-8720f98ae3a2/globalmount") options:("defaults") errcode:(exit status 127) output:(mkfs.ext4: symbol lookup error: /lib/x86_64-linux-gnu/libpthread.so.0: undefined symbol: __libc_vfork, version GLIBC_PRIVATE
) 
May 11 01:41:12.513: INFO: At 2022-05-11 01:37:31 +0000 UTC - event for pod-d97e80af-ac05-4773-a8d2-6b514a8366a2: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[volume1], unattached volumes=[volume1 default-token-s5j9b]: timed out waiting for the condition
May 11 01:41:12.581: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
May 11 01:41:12.581: INFO: 
May 11 01:41:12.647: INFO: 
Logging node info for node ip-172-20-126-84.us-west-2.compute.internal
... skipping 101 lines ...
/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:175
  [Testpattern: Dynamic PV (delayed binding)] topology
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    should provision a volume and schedule a pod with AllowedTopologies [It]
    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/topology.go:164

    Unexpected error:
        <*errors.errorString | 0xc00022e200>: {
            s: "timed out waiting for the condition",
        }
        timed out waiting for the condition
    occurred

... skipping 18 lines ...

    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:263
------------------------------
S
------------------------------
External Storage [Driver: ebs.csi.aws.com] [Testpattern: Dynamic PV (delayed binding)] topology 
  should fail to schedule a pod which has topologies that conflict with AllowedTopologies
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/topology.go:192

[BeforeEach] [Testpattern: Dynamic PV (delayed binding)] topology
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Dynamic PV (delayed binding)] topology
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/framework/framework.go:185
STEP: Creating a kubernetes client
May 11 01:41:13.789: INFO: >>> kubeConfig: /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/hack/e2e/csi-test-artifacts/test-cluster-28361.k8s.local.kops.kubeconfig
STEP: Building a namespace api object, basename topology
STEP: Waiting for a default service account to be provisioned in namespace
[It] should fail to schedule a pod which has topologies that conflict with AllowedTopologies
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/topology.go:192
May 11 01:41:14.154: INFO: found topology map[topology.ebs.csi.aws.com/zone:us-west-2c]
May 11 01:41:14.154: INFO: found topology map[topology.ebs.csi.aws.com/zone:us-west-2a]
May 11 01:41:14.154: INFO: Creating storage class object and pvc object for driver - sc: &StorageClass{ObjectMeta:{topology-801-e2e-scc6lb8      0 0001-01-01 00:00:00 +0000 UTC <nil> <nil> map[] map[] [] []  []},Provisioner:ebs.csi.aws.com,Parameters:map[string]string{},ReclaimPolicy:nil,MountOptions:[],AllowVolumeExpansion:nil,VolumeBindingMode:*WaitForFirstConsumer,AllowedTopologies:[]TopologySelectorTerm{{[{topology.ebs.csi.aws.com/zone [us-west-2a]}]},},}, pvc: &PersistentVolumeClaim{ObjectMeta:{ pvc- topology-801    0 0001-01-01 00:00:00 +0000 UTC <nil> <nil> map[] map[] [] []  []},Spec:PersistentVolumeClaimSpec{AccessModes:[ReadWriteOnce],Resources:ResourceRequirements{Limits:ResourceList{},Requests:ResourceList{storage: {{1073741824 0} {<nil>} 1Gi BinarySI},},},VolumeName:,Selector:nil,StorageClassName:*topology-801-e2e-scc6lb8,VolumeMode:nil,DataSource:nil,},Status:PersistentVolumeClaimStatus{Phase:,AccessModes:[],Capacity:ResourceList{},Conditions:[]PersistentVolumeClaimCondition{},},}
STEP: Creating sc
STEP: Creating pvc
... skipping 23 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: ebs.csi.aws.com]
/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:175
  [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    should fail if subpath with backstepping is outside the volume [Slow][LinuxOnly] [BeforeEach]
    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:278

    Driver ebs.csi.aws.com doesn't support ntfs -- skipping

    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:121
------------------------------
... skipping 149 lines ...
May 11 01:41:26.835: INFO: At 2022-05-11 01:35:35 +0000 UTC - event for ebs.csi.aws.comzd5ml: {ebs.csi.aws.com_ebs-csi-controller-65f7fb9696-j8nqp_23e52550-a198-4e6b-86aa-7a440fbfd693 } Provisioning: External provisioner is provisioning volume for claim "multivolume-7957/ebs.csi.aws.comzd5ml"
May 11 01:41:26.835: INFO: At 2022-05-11 01:35:38 +0000 UTC - event for ebs.csi.aws.comkxmpq: {ebs.csi.aws.com_ebs-csi-controller-65f7fb9696-j8nqp_23e52550-a198-4e6b-86aa-7a440fbfd693 } ProvisioningSucceeded: Successfully provisioned volume pvc-4b1bf007-39bc-4b38-95b7-d84bc83da001
May 11 01:41:26.835: INFO: At 2022-05-11 01:35:38 +0000 UTC - event for ebs.csi.aws.comzd5ml: {ebs.csi.aws.com_ebs-csi-controller-65f7fb9696-j8nqp_23e52550-a198-4e6b-86aa-7a440fbfd693 } ProvisioningSucceeded: Successfully provisioned volume pvc-ecdb1769-fcb6-42b6-9005-f5bf2f78f2b6
May 11 01:41:26.835: INFO: At 2022-05-11 01:35:39 +0000 UTC - event for pod-c926b8f2-7754-4f7e-97f7-3c34f9dc474b: {default-scheduler } Scheduled: Successfully assigned multivolume-7957/pod-c926b8f2-7754-4f7e-97f7-3c34f9dc474b to ip-172-20-61-6.us-west-2.compute.internal
May 11 01:41:26.835: INFO: At 2022-05-11 01:35:40 +0000 UTC - event for pod-c926b8f2-7754-4f7e-97f7-3c34f9dc474b: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-ecdb1769-fcb6-42b6-9005-f5bf2f78f2b6" 
May 11 01:41:26.835: INFO: At 2022-05-11 01:35:41 +0000 UTC - event for pod-c926b8f2-7754-4f7e-97f7-3c34f9dc474b: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-4b1bf007-39bc-4b38-95b7-d84bc83da001" 
May 11 01:41:26.835: INFO: At 2022-05-11 01:35:46 +0000 UTC - event for pod-c926b8f2-7754-4f7e-97f7-3c34f9dc474b: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMapVolume: MapVolume.MapPodDevice failed for volume "pvc-4b1bf007-39bc-4b38-95b7-d84bc83da001" : rpc error: code = Internal desc = Could not mount "/dev/nvme4n1" at "/var/lib/kubelet/plugins/kubernetes.io/csi/volumeDevices/publish/pvc-4b1bf007-39bc-4b38-95b7-d84bc83da001/aa43ecb0-a193-435a-ab7e-77c10c37cf3b": mount failed: exec: "mount": executable file not found in $PATH
Mounting command: mount
Mounting arguments:  -o bind /dev/nvme4n1 /var/lib/kubelet/plugins/kubernetes.io/csi/volumeDevices/publish/pvc-4b1bf007-39bc-4b38-95b7-d84bc83da001/aa43ecb0-a193-435a-ab7e-77c10c37cf3b
Output: 
May 11 01:41:26.835: INFO: At 2022-05-11 01:35:46 +0000 UTC - event for pod-c926b8f2-7754-4f7e-97f7-3c34f9dc474b: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMapVolume: MapVolume.MapPodDevice failed for volume "pvc-ecdb1769-fcb6-42b6-9005-f5bf2f78f2b6" : rpc error: code = Internal desc = Could not mount "/dev/nvme5n1" at "/var/lib/kubelet/plugins/kubernetes.io/csi/volumeDevices/publish/pvc-ecdb1769-fcb6-42b6-9005-f5bf2f78f2b6/aa43ecb0-a193-435a-ab7e-77c10c37cf3b": mount failed: exec: "mount": executable file not found in $PATH
Mounting command: mount
Mounting arguments:  -o bind /dev/nvme5n1 /var/lib/kubelet/plugins/kubernetes.io/csi/volumeDevices/publish/pvc-ecdb1769-fcb6-42b6-9005-f5bf2f78f2b6/aa43ecb0-a193-435a-ab7e-77c10c37cf3b
Output: 
May 11 01:41:26.835: INFO: At 2022-05-11 01:37:42 +0000 UTC - event for pod-c926b8f2-7754-4f7e-97f7-3c34f9dc474b: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[volume2 volume1], unattached volumes=[default-token-sx27w volume2 volume1]: timed out waiting for the condition
May 11 01:41:26.835: INFO: At 2022-05-11 01:40:00 +0000 UTC - event for pod-c926b8f2-7754-4f7e-97f7-3c34f9dc474b: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[volume1 volume2], unattached volumes=[default-token-sx27w volume1 volume2]: timed out waiting for the condition
May 11 01:41:26.898: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
... skipping 106 lines ...
/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:175
  [Testpattern: Dynamic PV (block volmode)] multiVolume [Slow]
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    should access to two volumes with the same volume mode and retain data across pod recreation on the same node [LinuxOnly] [It]
    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/multivolume.go:134

    Unexpected error:
        <*errors.errorString | 0xc0011dad80>: {
            s: "pod \"pod-c926b8f2-7754-4f7e-97f7-3c34f9dc474b\" is not Running: timed out waiting for the condition",
        }
        pod "pod-c926b8f2-7754-4f7e-97f7-3c34f9dc474b" is not Running: timed out waiting for the condition
    occurred

... skipping 10 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: ebs.csi.aws.com]
/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:175
  [Testpattern: Pre-provisioned PV (default fs)] subPath
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    should fail if subpath with backstepping is outside the volume [Slow][LinuxOnly] [BeforeEach]
    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:278

    Driver "ebs.csi.aws.com" does not support volume type "PreprovisionedPV" - skipping

    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:263
------------------------------
SS
------------------------------
External Storage [Driver: ebs.csi.aws.com] [Testpattern: Dynamic PV (filesystem volmode)] volumeMode 
  should fail to use a volume in a pod with mismatched mode [Slow]
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/volumemode.go:297

[BeforeEach] [Testpattern: Dynamic PV (filesystem volmode)] volumeMode
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Dynamic PV (filesystem volmode)] volumeMode
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/framework/framework.go:185
STEP: Creating a kubernetes client
May 11 01:41:14.859: INFO: >>> kubeConfig: /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/hack/e2e/csi-test-artifacts/test-cluster-28361.k8s.local.kops.kubeconfig
STEP: Building a namespace api object, basename volumemode
STEP: Waiting for a default service account to be provisioned in namespace
[It] should fail to use a volume in a pod with mismatched mode [Slow]
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/volumemode.go:297
May 11 01:41:15.162: INFO: Creating resource for dynamic PV
May 11 01:41:15.162: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(ebs.csi.aws.com) supported size:{ 1Mi} 
STEP: creating a StorageClass volumemode-5977-e2e-schz5qr
STEP: creating a claim
STEP: Creating pod
STEP: Waiting for the pod to fail
May 11 01:41:21.594: INFO: Deleting pod "pod-2fb29db0-81a1-4365-a3e8-84824b094bb9" in namespace "volumemode-5977"
May 11 01:41:21.656: INFO: Wait up to 5m0s for pod "pod-2fb29db0-81a1-4365-a3e8-84824b094bb9" to be fully deleted
STEP: Deleting pvc
May 11 01:41:25.901: INFO: Deleting PersistentVolumeClaim "ebs.csi.aws.comb4clz"
May 11 01:41:25.962: INFO: Waiting up to 5m0s for PersistentVolume pvc-6e1b31c3-14f5-4393-b234-352f0dd812cf to get deleted
May 11 01:41:26.031: INFO: PersistentVolume pvc-6e1b31c3-14f5-4393-b234-352f0dd812cf found and phase=Bound (68.468978ms)
... skipping 7 lines ...

• [SLOW TEST:16.428 seconds]
External Storage [Driver: ebs.csi.aws.com]
/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:175
  [Testpattern: Dynamic PV (filesystem volmode)] volumeMode
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    should fail to use a volume in a pod with mismatched mode [Slow]
    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/volumemode.go:297
------------------------------
SSSSSSSSSSS
------------------------------
[BeforeEach] [Testpattern: Dynamic PV (ext3)] volumes
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:51
... skipping 14 lines ...

    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:121
------------------------------
S
------------------------------
External Storage [Driver: ebs.csi.aws.com] [Testpattern: Dynamic PV (block volmode)] volumeMode 
  should fail to use a volume in a pod with mismatched mode [Slow]
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/volumemode.go:297

[BeforeEach] [Testpattern: Dynamic PV (block volmode)] volumeMode
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Dynamic PV (block volmode)] volumeMode
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/framework/framework.go:185
STEP: Creating a kubernetes client
May 11 01:41:31.306: INFO: >>> kubeConfig: /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/hack/e2e/csi-test-artifacts/test-cluster-28361.k8s.local.kops.kubeconfig
STEP: Building a namespace api object, basename volumemode
STEP: Waiting for a default service account to be provisioned in namespace
[It] should fail to use a volume in a pod with mismatched mode [Slow]
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/volumemode.go:297
May 11 01:41:31.610: INFO: Creating resource for dynamic PV
May 11 01:41:31.610: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(ebs.csi.aws.com) supported size:{ 1Mi} 
STEP: creating a StorageClass volumemode-7442-e2e-sc42jl8
STEP: creating a claim
STEP: Creating pod
STEP: Waiting for the pod to fail
May 11 01:41:38.042: INFO: Deleting pod "pod-509058ee-754b-4f9f-81e6-6f25ec1b73d9" in namespace "volumemode-7442"
May 11 01:41:38.106: INFO: Wait up to 5m0s for pod "pod-509058ee-754b-4f9f-81e6-6f25ec1b73d9" to be fully deleted
STEP: Deleting pvc
May 11 01:41:46.349: INFO: Deleting PersistentVolumeClaim "ebs.csi.aws.comnj4cp"
May 11 01:41:46.417: INFO: Waiting up to 5m0s for PersistentVolume pvc-2c3ff63b-3edc-41f8-a5da-073f646f0c1f to get deleted
May 11 01:41:46.477: INFO: PersistentVolume pvc-2c3ff63b-3edc-41f8-a5da-073f646f0c1f found and phase=Released (60.726942ms)
... skipping 7 lines ...

• [SLOW TEST:20.426 seconds]
External Storage [Driver: ebs.csi.aws.com]
/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:175
  [Testpattern: Dynamic PV (block volmode)] volumeMode
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    should fail to use a volume in a pod with mismatched mode [Slow]
    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/volumemode.go:297
------------------------------
[BeforeEach] [Testpattern: Inline-volume (ext4)] volumes
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:51
May 11 01:41:51.733: INFO: Driver "ebs.csi.aws.com" does not support volume type "InlineVolume" - skipping
[AfterEach] [Testpattern: Inline-volume (ext4)] volumes
... skipping 64 lines ...
May 11 01:46:30.062: INFO: At 2022-05-11 01:41:29 +0000 UTC - event for pvc-4sf9s: {ebs.csi.aws.com_ebs-csi-controller-65f7fb9696-j8nqp_23e52550-a198-4e6b-86aa-7a440fbfd693 } Provisioning: External provisioner is provisioning volume for claim "provisioning-4553/pvc-4sf9s"
May 11 01:46:30.062: INFO: At 2022-05-11 01:41:29 +0000 UTC - event for pvc-4sf9s: {persistentvolume-controller } WaitForFirstConsumer: waiting for first consumer to be created before binding
May 11 01:46:30.062: INFO: At 2022-05-11 01:41:29 +0000 UTC - event for pvc-4sf9s: {persistentvolume-controller } ExternalProvisioning: waiting for a volume to be created, either by external provisioner "ebs.csi.aws.com" or manually created by system administrator
May 11 01:46:30.062: INFO: At 2022-05-11 01:41:32 +0000 UTC - event for pvc-4sf9s: {ebs.csi.aws.com_ebs-csi-controller-65f7fb9696-j8nqp_23e52550-a198-4e6b-86aa-7a440fbfd693 } ProvisioningSucceeded: Successfully provisioned volume pvc-744e5b69-9b66-4a5e-8f11-f0b77228e7a2
May 11 01:46:30.062: INFO: At 2022-05-11 01:41:33 +0000 UTC - event for pod-4fbf4752-d893-4920-9a05-78ddade51c06: {default-scheduler } Scheduled: Successfully assigned provisioning-4553/pod-4fbf4752-d893-4920-9a05-78ddade51c06 to ip-172-20-61-6.us-west-2.compute.internal
May 11 01:46:30.062: INFO: At 2022-05-11 01:41:35 +0000 UTC - event for pod-4fbf4752-d893-4920-9a05-78ddade51c06: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-744e5b69-9b66-4a5e-8f11-f0b77228e7a2" 
May 11 01:46:30.062: INFO: At 2022-05-11 01:41:37 +0000 UTC - event for pod-4fbf4752-d893-4920-9a05-78ddade51c06: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: MountVolume.MountDevice failed for volume "pvc-744e5b69-9b66-4a5e-8f11-f0b77228e7a2" : rpc error: code = Internal desc = could not format "/dev/nvme2n1" and mount it at "/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-744e5b69-9b66-4a5e-8f11-f0b77228e7a2/globalmount": format of disk "/dev/nvme2n1" failed: type:("ext4") target:("/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-744e5b69-9b66-4a5e-8f11-f0b77228e7a2/globalmount") options:("dirsync,defaults") errcode:(exit status 127) output:(mkfs.ext4: symbol lookup error: /lib/x86_64-linux-gnu/libpthread.so.0: undefined symbol: __libc_vfork, version GLIBC_PRIVATE
) 
May 11 01:46:30.062: INFO: At 2022-05-11 01:43:36 +0000 UTC - event for pod-4fbf4752-d893-4920-9a05-78ddade51c06: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[volume1], unattached volumes=[volume1 default-token-l7tcs]: timed out waiting for the condition
May 11 01:46:30.124: INFO: POD                                       NODE                                       PHASE    GRACE  CONDITIONS
May 11 01:46:30.125: INFO: pod-4fbf4752-d893-4920-9a05-78ddade51c06  ip-172-20-61-6.us-west-2.compute.internal  Pending         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2022-05-11 01:41:33 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2022-05-11 01:41:33 +0000 UTC ContainersNotReady containers with unready status: [write-pod]} {ContainersReady False 0001-01-01 00:00:00 +0000 UTC 2022-05-11 01:41:33 +0000 UTC ContainersNotReady containers with unready status: [write-pod]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2022-05-11 01:41:33 +0000 UTC  }]
May 11 01:46:30.125: INFO: 
May 11 01:46:30.194: INFO: 
... skipping 106 lines ...
/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:175
  [Testpattern: Dynamic PV (default fs)] provisioning
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    should provision storage with mount options [It]
    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/provisioning.go:179

    Unexpected error:
        <*errors.errorString | 0xc000de37f0>: {
            s: "pod \"pod-4fbf4752-d893-4920-9a05-78ddade51c06\" is not Running: timed out waiting for the condition",
        }
        pod "pod-4fbf4752-d893-4920-9a05-78ddade51c06" is not Running: timed out waiting for the condition
    occurred

... skipping 87 lines ...
May 11 01:46:35.930: INFO: At 2022-05-11 01:41:15 +0000 UTC - event for pod-8088c074-1d83-4420-8f78-eed93bd3b92c: {default-scheduler } FailedScheduling: 0/4 nodes are available: 4 pod has unbound immediate PersistentVolumeClaims.
May 11 01:46:35.930: INFO: At 2022-05-11 01:41:15 +0000 UTC - event for pvc-xslms: {ebs.csi.aws.com_ebs-csi-controller-65f7fb9696-j8nqp_23e52550-a198-4e6b-86aa-7a440fbfd693 } Provisioning: External provisioner is provisioning volume for claim "topology-5718/pvc-xslms"
May 11 01:46:35.930: INFO: At 2022-05-11 01:41:15 +0000 UTC - event for pvc-xslms: {persistentvolume-controller } ExternalProvisioning: waiting for a volume to be created, either by external provisioner "ebs.csi.aws.com" or manually created by system administrator
May 11 01:46:35.930: INFO: At 2022-05-11 01:41:19 +0000 UTC - event for pvc-xslms: {ebs.csi.aws.com_ebs-csi-controller-65f7fb9696-j8nqp_23e52550-a198-4e6b-86aa-7a440fbfd693 } ProvisioningSucceeded: Successfully provisioned volume pvc-168209ad-a326-4c51-93bb-ec87b4df6446
May 11 01:46:35.930: INFO: At 2022-05-11 01:41:22 +0000 UTC - event for pod-8088c074-1d83-4420-8f78-eed93bd3b92c: {default-scheduler } Scheduled: Successfully assigned topology-5718/pod-8088c074-1d83-4420-8f78-eed93bd3b92c to ip-172-20-126-84.us-west-2.compute.internal
May 11 01:46:35.930: INFO: At 2022-05-11 01:41:23 +0000 UTC - event for pod-8088c074-1d83-4420-8f78-eed93bd3b92c: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-168209ad-a326-4c51-93bb-ec87b4df6446" 
May 11 01:46:35.930: INFO: At 2022-05-11 01:41:25 +0000 UTC - event for pod-8088c074-1d83-4420-8f78-eed93bd3b92c: {kubelet ip-172-20-126-84.us-west-2.compute.internal} FailedMount: MountVolume.MountDevice failed for volume "pvc-168209ad-a326-4c51-93bb-ec87b4df6446" : rpc error: code = Internal desc = could not format "/dev/nvme1n1" and mount it at "/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-168209ad-a326-4c51-93bb-ec87b4df6446/globalmount": format of disk "/dev/nvme1n1" failed: type:("ext4") target:("/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-168209ad-a326-4c51-93bb-ec87b4df6446/globalmount") options:("defaults") errcode:(exit status 127) output:(mkfs.ext4: symbol lookup error: /lib/x86_64-linux-gnu/libpthread.so.0: undefined symbol: __libc_vfork, version GLIBC_PRIVATE
) 
May 11 01:46:35.930: INFO: At 2022-05-11 01:43:25 +0000 UTC - event for pod-8088c074-1d83-4420-8f78-eed93bd3b92c: {kubelet ip-172-20-126-84.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[volume1], unattached volumes=[default-token-ptqn4 volume1]: timed out waiting for the condition
May 11 01:46:35.930: INFO: At 2022-05-11 01:45:41 +0000 UTC - event for pod-8088c074-1d83-4420-8f78-eed93bd3b92c: {kubelet ip-172-20-126-84.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[volume1], unattached volumes=[volume1 default-token-ptqn4]: timed out waiting for the condition
May 11 01:46:35.994: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
May 11 01:46:35.994: INFO: 
May 11 01:46:36.060: INFO: 
... skipping 106 lines ...
/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:175
  [Testpattern: Dynamic PV (immediate binding)] topology
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    should provision a volume and schedule a pod with AllowedTopologies [It]
    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/topology.go:164

    Unexpected error:
        <*errors.errorString | 0xc00022e200>: {
            s: "timed out waiting for the condition",
        }
        timed out waiting for the condition
    occurred

... skipping 50 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: ebs.csi.aws.com]
/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:175
  [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    should fail if subpath file is outside the volume [Slow][LinuxOnly] [BeforeEach]
    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:256

    Driver ebs.csi.aws.com doesn't support ntfs -- skipping

    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:121
------------------------------
... skipping 34 lines ...
May 11 01:46:38.449: INFO: Using claimSize:1Gi, test suite supported size:{ 1Gi}, driver(ebs.csi.aws.com) supported size:{ 1Gi} 
STEP: creating a StorageClass volume-expand-7384-e2e-sc7z7vd
STEP: creating a claim
May 11 01:46:38.514: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
STEP: Expanding non-expandable pvc
May 11 01:46:38.646: INFO: currentPvcSize {{1073741824 0} {<nil>} 1Gi BinarySI}, newSize {{2147483648 0} {<nil>}  BinarySI}
May 11 01:46:38.776: INFO: Error updating pvc ebs.csi.aws.comf9k6s: PersistentVolumeClaim "ebs.csi.aws.comf9k6s" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 5 lines ...
  	},
  	VolumeName:       "",
  	StorageClassName: &"volume-expand-7384-e2e-sc7z7vd",
  	... // 2 identical fields
  }

May 11 01:46:40.906: INFO: Error updating pvc ebs.csi.aws.comf9k6s: PersistentVolumeClaim "ebs.csi.aws.comf9k6s" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 5 lines ...
  	},
  	VolumeName:       "",
  	StorageClassName: &"volume-expand-7384-e2e-sc7z7vd",
  	... // 2 identical fields
  }

May 11 01:46:42.906: INFO: Error updating pvc ebs.csi.aws.comf9k6s: PersistentVolumeClaim "ebs.csi.aws.comf9k6s" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 5 lines ...
  	},
  	VolumeName:       "",
  	StorageClassName: &"volume-expand-7384-e2e-sc7z7vd",
  	... // 2 identical fields
  }

May 11 01:46:44.907: INFO: Error updating pvc ebs.csi.aws.comf9k6s: PersistentVolumeClaim "ebs.csi.aws.comf9k6s" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 5 lines ...
  	},
  	VolumeName:       "",
  	StorageClassName: &"volume-expand-7384-e2e-sc7z7vd",
  	... // 2 identical fields
  }

May 11 01:46:46.906: INFO: Error updating pvc ebs.csi.aws.comf9k6s: PersistentVolumeClaim "ebs.csi.aws.comf9k6s" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 5 lines ...
  	},
  	VolumeName:       "",
  	StorageClassName: &"volume-expand-7384-e2e-sc7z7vd",
  	... // 2 identical fields
  }

May 11 01:46:48.910: INFO: Error updating pvc ebs.csi.aws.comf9k6s: PersistentVolumeClaim "ebs.csi.aws.comf9k6s" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 5 lines ...
  	},
  	VolumeName:       "",
  	StorageClassName: &"volume-expand-7384-e2e-sc7z7vd",
  	... // 2 identical fields
  }

May 11 01:46:50.908: INFO: Error updating pvc ebs.csi.aws.comf9k6s: PersistentVolumeClaim "ebs.csi.aws.comf9k6s" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 5 lines ...
  	},
  	VolumeName:       "",
  	StorageClassName: &"volume-expand-7384-e2e-sc7z7vd",
  	... // 2 identical fields
  }

May 11 01:46:52.914: INFO: Error updating pvc ebs.csi.aws.comf9k6s: PersistentVolumeClaim "ebs.csi.aws.comf9k6s" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 5 lines ...
  	},
  	VolumeName:       "",
  	StorageClassName: &"volume-expand-7384-e2e-sc7z7vd",
  	... // 2 identical fields
  }

May 11 01:46:54.911: INFO: Error updating pvc ebs.csi.aws.comf9k6s: PersistentVolumeClaim "ebs.csi.aws.comf9k6s" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 5 lines ...
  	},
  	VolumeName:       "",
  	StorageClassName: &"volume-expand-7384-e2e-sc7z7vd",
  	... // 2 identical fields
  }

May 11 01:46:56.909: INFO: Error updating pvc ebs.csi.aws.comf9k6s: PersistentVolumeClaim "ebs.csi.aws.comf9k6s" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 5 lines ...
  	},
  	VolumeName:       "",
  	StorageClassName: &"volume-expand-7384-e2e-sc7z7vd",
  	... // 2 identical fields
  }

May 11 01:46:58.906: INFO: Error updating pvc ebs.csi.aws.comf9k6s: PersistentVolumeClaim "ebs.csi.aws.comf9k6s" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 5 lines ...
  	},
  	VolumeName:       "",
  	StorageClassName: &"volume-expand-7384-e2e-sc7z7vd",
  	... // 2 identical fields
  }

May 11 01:47:00.906: INFO: Error updating pvc ebs.csi.aws.comf9k6s: PersistentVolumeClaim "ebs.csi.aws.comf9k6s" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 5 lines ...
  	},
  	VolumeName:       "",
  	StorageClassName: &"volume-expand-7384-e2e-sc7z7vd",
  	... // 2 identical fields
  }

May 11 01:47:02.908: INFO: Error updating pvc ebs.csi.aws.comf9k6s: PersistentVolumeClaim "ebs.csi.aws.comf9k6s" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 5 lines ...
  	},
  	VolumeName:       "",
  	StorageClassName: &"volume-expand-7384-e2e-sc7z7vd",
  	... // 2 identical fields
  }

May 11 01:47:04.912: INFO: Error updating pvc ebs.csi.aws.comf9k6s: PersistentVolumeClaim "ebs.csi.aws.comf9k6s" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 5 lines ...
  	},
  	VolumeName:       "",
  	StorageClassName: &"volume-expand-7384-e2e-sc7z7vd",
  	... // 2 identical fields
  }

May 11 01:47:06.911: INFO: Error updating pvc ebs.csi.aws.comf9k6s: PersistentVolumeClaim "ebs.csi.aws.comf9k6s" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 5 lines ...
  	},
  	VolumeName:       "",
  	StorageClassName: &"volume-expand-7384-e2e-sc7z7vd",
  	... // 2 identical fields
  }

May 11 01:47:08.907: INFO: Error updating pvc ebs.csi.aws.comf9k6s: PersistentVolumeClaim "ebs.csi.aws.comf9k6s" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 5 lines ...
  	},
  	VolumeName:       "",
  	StorageClassName: &"volume-expand-7384-e2e-sc7z7vd",
  	... // 2 identical fields
  }

May 11 01:47:09.038: INFO: Error updating pvc ebs.csi.aws.comf9k6s: PersistentVolumeClaim "ebs.csi.aws.comf9k6s" is invalid: spec: Forbidden: spec is immutable after creation except resources.requests for bound claims
  core.PersistentVolumeClaimSpec{
  	AccessModes: {"ReadWriteOnce"},
  	Selector:    nil,
  	Resources: core.ResourceRequirements{
  		Limits: nil,
- 		Requests: core.ResourceList{
... skipping 160 lines ...
May 11 01:51:56.618: INFO: At 2022-05-11 01:41:52 +0000 UTC - event for ebs.csi.aws.comm2mq6: {persistentvolume-controller } WaitForFirstConsumer: waiting for first consumer to be created before binding
May 11 01:51:56.618: INFO: At 2022-05-11 01:41:52 +0000 UTC - event for ebs.csi.aws.comm2mq6: {persistentvolume-controller } ExternalProvisioning: waiting for a volume to be created, either by external provisioner "ebs.csi.aws.com" or manually created by system administrator
May 11 01:51:56.618: INFO: At 2022-05-11 01:41:52 +0000 UTC - event for ebs.csi.aws.comm2mq6: {ebs.csi.aws.com_ebs-csi-controller-65f7fb9696-j8nqp_23e52550-a198-4e6b-86aa-7a440fbfd693 } Provisioning: External provisioner is provisioning volume for claim "fsgroupchangepolicy-2275/ebs.csi.aws.comm2mq6"
May 11 01:51:56.618: INFO: At 2022-05-11 01:41:55 +0000 UTC - event for ebs.csi.aws.comm2mq6: {ebs.csi.aws.com_ebs-csi-controller-65f7fb9696-j8nqp_23e52550-a198-4e6b-86aa-7a440fbfd693 } ProvisioningSucceeded: Successfully provisioned volume pvc-278fcd10-d99f-4e78-aa39-b5ecf29cc6a9
May 11 01:51:56.618: INFO: At 2022-05-11 01:41:56 +0000 UTC - event for pod-b5439bb6-2850-4463-a5de-9cd2e9017980: {default-scheduler } Scheduled: Successfully assigned fsgroupchangepolicy-2275/pod-b5439bb6-2850-4463-a5de-9cd2e9017980 to ip-172-20-61-6.us-west-2.compute.internal
May 11 01:51:56.618: INFO: At 2022-05-11 01:41:58 +0000 UTC - event for pod-b5439bb6-2850-4463-a5de-9cd2e9017980: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-278fcd10-d99f-4e78-aa39-b5ecf29cc6a9" 
May 11 01:51:56.618: INFO: At 2022-05-11 01:42:00 +0000 UTC - event for pod-b5439bb6-2850-4463-a5de-9cd2e9017980: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: MountVolume.MountDevice failed for volume "pvc-278fcd10-d99f-4e78-aa39-b5ecf29cc6a9" : rpc error: code = Internal desc = could not format "/dev/nvme3n1" and mount it at "/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-278fcd10-d99f-4e78-aa39-b5ecf29cc6a9/globalmount": format of disk "/dev/nvme3n1" failed: type:("ext4") target:("/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-278fcd10-d99f-4e78-aa39-b5ecf29cc6a9/globalmount") options:("defaults") errcode:(exit status 127) output:(mkfs.ext4: symbol lookup error: /lib/x86_64-linux-gnu/libpthread.so.0: undefined symbol: __libc_vfork, version GLIBC_PRIVATE
) 
May 11 01:51:56.618: INFO: At 2022-05-11 01:43:59 +0000 UTC - event for pod-b5439bb6-2850-4463-a5de-9cd2e9017980: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[volume1], unattached volumes=[volume1 default-token-57k49]: timed out waiting for the condition
May 11 01:51:56.618: INFO: At 2022-05-11 01:48:39 +0000 UTC - event for pod-b5439bb6-2850-4463-a5de-9cd2e9017980: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[volume1], unattached volumes=[default-token-57k49 volume1]: error processing PVC fsgroupchangepolicy-2275/ebs.csi.aws.comm2mq6: PVC is being deleted
May 11 01:51:56.618: INFO: At 2022-05-11 01:48:54 +0000 UTC - event for pod-b5439bb6-2850-4463-a5de-9cd2e9017980: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[volume1], unattached volumes=[volume1 default-token-57k49]: error processing PVC fsgroupchangepolicy-2275/ebs.csi.aws.comm2mq6: PVC is being deleted
May 11 01:51:56.679: INFO: POD                                       NODE                                       PHASE    GRACE  CONDITIONS
May 11 01:51:56.679: INFO: pod-b5439bb6-2850-4463-a5de-9cd2e9017980  ip-172-20-61-6.us-west-2.compute.internal  Pending         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2022-05-11 01:41:56 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2022-05-11 01:41:56 +0000 UTC ContainersNotReady containers with unready status: [write-pod]} {ContainersReady False 0001-01-01 00:00:00 +0000 UTC 2022-05-11 01:41:56 +0000 UTC ContainersNotReady containers with unready status: [write-pod]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2022-05-11 01:41:56 +0000 UTC  }]
May 11 01:51:56.679: INFO: 
May 11 01:51:56.741: INFO: 
Logging node info for node ip-172-20-126-84.us-west-2.compute.internal
May 11 01:51:56.804: INFO: Node Info: &Node{ObjectMeta:{ip-172-20-126-84.us-west-2.compute.internal    db5e920b-df68-4db9-8773-4aaee7bba798 7285 0 2022-05-11 01:22:01 +0000 UTC <nil> <nil> map[beta.kubernetes.io/arch:amd64 beta.kubernetes.io/instance-type:c5.large beta.kubernetes.io/os:linux failure-domain.beta.kubernetes.io/region:us-west-2 failure-domain.beta.kubernetes.io/zone:us-west-2c kops.k8s.io/instancegroup:nodes-us-west-2c kubernetes.io/arch:amd64 kubernetes.io/hostname:ip-172-20-126-84.us-west-2.compute.internal kubernetes.io/os:linux kubernetes.io/role:node node-role.kubernetes.io/node: node.kubernetes.io/instance-type:c5.large topology.ebs.csi.aws.com/zone:us-west-2c topology.kubernetes.io/region:us-west-2 topology.kubernetes.io/zone:us-west-2c] map[csi.volume.kubernetes.io/nodeid:{"ebs.csi.aws.com":"i-0afa6e52b1c8e40f6"} node.alpha.kubernetes.io/ttl:0 volumes.kubernetes.io/controller-managed-attach-detach:true] [] []  [{kops-controller Update v1 2022-05-11 01:22:01 +0000 UTC FieldsV1 {"f:metadata":{"f:labels":{"f:kops.k8s.io/instancegroup":{},"f:kubernetes.io/role":{},"f:node-role.kubernetes.io/node":{}}}}} {kube-controller-manager Update v1 2022-05-11 01:41:23 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:node.alpha.kubernetes.io/ttl":{}}},"f:spec":{"f:podCIDR":{},"f:podCIDRs":{".":{},"v:\"100.96.1.0/24\"":{}}},"f:status":{"f:conditions":{"k:{\"type\":\"NetworkUnavailable\"}":{".":{},"f:lastHeartbeatTime":{},"f:lastTransitionTime":{},"f:message":{},"f:reason":{},"f:status":{},"f:type":{}}}}}} {kubelet Update v1 2022-05-11 01:46:25 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{".":{},"f:csi.volume.kubernetes.io/nodeid":{},"f:volumes.kubernetes.io/controller-managed-attach-detach":{}},"f:labels":{".":{},"f:beta.kubernetes.io/arch":{},"f:beta.kubernetes.io/instance-type":{},"f:beta.kubernetes.io/os":{},"f:failure-domain.beta.kubernetes.io/region":{},"f:failure-domain.beta.kubernetes.io/zone":{},"f:kubernetes.io/arch":{},"f:kubernetes.io/hostname":{},"f:kubernetes.io/os":{},"f:node.kubernetes.io/instance-type":{},"f:topology.ebs.csi.aws.com/zone":{},"f:topology.kubernetes.io/region":{},"f:topology.kubernetes.io/zone":{}}},"f:spec":{"f:providerID":{}},"f:status":{"f:addresses":{".":{},"k:{\"type\":\"ExternalDNS\"}":{".":{},"f:address":{},"f:type":{}},"k:{\"type\":\"ExternalIP\"}":{".":{},"f:address":{},"f:type":{}},"k:{\"type\":\"Hostname\"}":{".":{},"f:address":{},"f:type":{}},"k:{\"type\":\"InternalDNS\"}":{".":{},"f:address":{},"f:type":{}},"k:{\"type\":\"InternalIP\"}":{".":{},"f:address":{},"f:type":{}}},"f:allocatable":{".":{},"f:attachable-volumes-aws-ebs":{},"f:cpu":{},"f:ephemeral-storage":{},"f:hugepages-1Gi":{},"f:hugepages-2Mi":{},"f:memory":{},"f:pods":{}},"f:capacity":{".":{},"f:attachable-volumes-aws-ebs":{},"f:cpu":{},"f:ephemeral-storage":{},"f:hugepages-1Gi":{},"f:hugepages-2Mi":{},"f:memory":{},"f:pods":{}},"f:conditions":{".":{},"k:{\"type\":\"DiskPressure\"}":{".":{},"f:lastHeartbeatTime":{},"f:lastTransitionTime":{},"f:message":{},"f:reason":{},"f:status":{},"f:type":{}},"k:{\"type\":\"MemoryPressure\"}":{".":{},"f:lastHeartbeatTime":{},"f:lastTransitionTime":{},"f:message":{},"f:reason":{},"f:status":{},"f:type":{}},"k:{\"type\":\"PIDPressure\"}":{".":{},"f:lastHeartbeatTime":{},"f:lastTransitionTime":{},"f:message":{},"f:reason":{},"f:status":{},"f:type":{}},"k:{\"type\":\"Ready\"}":{".":{},"f:lastHeartbeatTime":{},"f:lastTransitionTime":{},"f:message":{},"f:reason":{},"f:status":{},"f:type":{}}},"f:daemonEndpoints":{"f:kubeletEndpoint":{"f:Port":{}}},"f:images":{},"f:nodeInfo":{"f:architecture":{},"f:bootID":{},"f:containerRuntimeVersion":{},"f:kernelVersion":{},"f:kubeProxyVersion":{},"f:kubeletVersion":{},"f:machineID":{},"f:operatingSystem":{},"f:osImage":{},"f:systemUUID":{}}}}}]},Spec:NodeSpec{PodCIDR:100.96.1.0/24,DoNotUseExternalID:,ProviderID:aws:///us-west-2c/i-0afa6e52b1c8e40f6,Unschedulable:false,Taints:[]Taint{},ConfigSource:nil,PodCIDRs:[100.96.1.0/24],},Status:NodeStatus{Capacity:ResourceList{attachable-volumes-aws-ebs: {{25 0} {<nil>} 25 DecimalSI},cpu: {{2 0} {<nil>} 2 DecimalSI},ephemeral-storage: {{133167038464 0} {<nil>}  BinarySI},hugepages-1Gi: {{0 0} {<nil>} 0 DecimalSI},hugepages-2Mi: {{0 0} {<nil>} 0 DecimalSI},memory: {{3894337536 0} {<nil>}  BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Allocatable:ResourceList{attachable-volumes-aws-ebs: {{25 0} {<nil>} 25 DecimalSI},cpu: {{2 0} {<nil>} 2 DecimalSI},ephemeral-storage: {{119850334420 0} {<nil>} 119850334420 DecimalSI},hugepages-1Gi: {{0 0} {<nil>} 0 DecimalSI},hugepages-2Mi: {{0 0} {<nil>} 0 DecimalSI},memory: {{3789479936 0} {<nil>}  BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Phase:,Conditions:[]NodeCondition{NodeCondition{Type:NetworkUnavailable,Status:False,LastHeartbeatTime:2022-05-11 01:22:12 +0000 UTC,LastTransitionTime:2022-05-11 01:22:12 +0000 UTC,Reason:RouteCreated,Message:RouteController created a route,},NodeCondition{Type:MemoryPressure,Status:False,LastHeartbeatTime:2022-05-11 01:51:27 +0000 UTC,LastTransitionTime:2022-05-11 01:22:01 +0000 UTC,Reason:KubeletHasSufficientMemory,Message:kubelet has sufficient memory available,},NodeCondition{Type:DiskPressure,Status:False,LastHeartbeatTime:2022-05-11 01:51:27 +0000 UTC,LastTransitionTime:2022-05-11 01:22:01 +0000 UTC,Reason:KubeletHasNoDiskPressure,Message:kubelet has no disk pressure,},NodeCondition{Type:PIDPressure,Status:False,LastHeartbeatTime:2022-05-11 01:51:27 +0000 UTC,LastTransitionTime:2022-05-11 01:22:01 +0000 UTC,Reason:KubeletHasSufficientPID,Message:kubelet has sufficient PID available,},NodeCondition{Type:Ready,Status:True,LastHeartbeatTime:2022-05-11 01:51:27 +0000 UTC,LastTransitionTime:2022-05-11 01:22:11 +0000 UTC,Reason:KubeletReady,Message:kubelet is posting ready status. AppArmor enabled,},},Addresses:[]NodeAddress{NodeAddress{Type:InternalIP,Address:172.20.126.84,},NodeAddress{Type:ExternalIP,Address:54.149.104.74,},NodeAddress{Type:Hostname,Address:ip-172-20-126-84.us-west-2.compute.internal,},NodeAddress{Type:InternalDNS,Address:ip-172-20-126-84.us-west-2.compute.internal,},NodeAddress{Type:ExternalDNS,Address:ec2-54-149-104-74.us-west-2.compute.amazonaws.com,},},DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:ec21592570561574460d4eef892edd78,SystemUUID:ec215925-7056-1574-460d-4eef892edd78,BootID:cd9c789b-9623-415f-8742-9581bab9d1b6,KernelVersion:5.13.0-1021-aws,OSImage:Ubuntu 20.04.4 LTS,ContainerRuntimeVersion:containerd://1.4.6,KubeletVersion:v1.20.8,KubeProxyVersion:v1.20.8,OperatingSystem:linux,Architecture:amd64,},Images:[]ContainerImage{ContainerImage{Names:[k8s.gcr.io/kube-proxy@sha256:0c867c82a0a8ce6d093595f9d2e4b10517d6c9c26323075de9d82d9f7d056bfc k8s.gcr.io/kube-proxy:v1.20.8],SizeBytes:52056682,},ContainerImage{Names:[607362164682.dkr.ecr.us-west-2.amazonaws.com/aws-ebs-csi-driver@sha256:15e75c3933b02190748eff0c7c2cc8c658797d33efae3a0a7e5cb550080b2a00 607362164682.dkr.ecr.us-west-2.amazonaws.com/aws-ebs-csi-driver:28361],SizeBytes:25259258,},ContainerImage{Names:[k8s.gcr.io/sig-storage/csi-provisioner@sha256:695505fcfcc69f1cf35665dce487aad447adbb9af69b796d6437f869015d1157 k8s.gcr.io/sig-storage/csi-provisioner:v2.1.1],SizeBytes:21212251,},ContainerImage{Names:[k8s.gcr.io/sig-storage/csi-attacher@sha256:50c3cfd458fc8e0bf3c8c521eac39172009382fc66dc5044a330d137c6ed0b09 k8s.gcr.io/sig-storage/csi-attacher:v3.1.0],SizeBytes:20103959,},ContainerImage{Names:[k8s.gcr.io/sig-storage/csi-resizer@sha256:7a5ba58a44e0d749e0767e4e37315bcf6a61f33ce3185c1991848af4db0fb70a k8s.gcr.io/sig-storage/csi-resizer:v1.1.0],SizeBytes:20096832,},ContainerImage{Names:[k8s.gcr.io/sig-storage/csi-snapshotter@sha256:9af9bf28430b00a0cedeb2ec29acadce45e6afcecd8bdf31c793c624cfa75fa7 k8s.gcr.io/sig-storage/csi-snapshotter:v3.0.3],SizeBytes:19500777,},ContainerImage{Names:[k8s.gcr.io/cpa/cluster-proportional-autoscaler@sha256:67640771ad9fc56f109d5b01e020f0c858e7c890bb0eb15ba0ebd325df3285e7 k8s.gcr.io/cpa/cluster-proportional-autoscaler:1.8.3],SizeBytes:15191740,},ContainerImage{Names:[docker.io/coredns/coredns@sha256:642ff9910da6ea9a8624b0234eef52af9ca75ecbec474c5507cb096bdfbae4e5 docker.io/coredns/coredns:1.8.3],SizeBytes:12893350,},ContainerImage{Names:[k8s.gcr.io/sig-storage/csi-node-driver-registrar@sha256:a61d309da54641db41fb8f35718f744e9f730d4d0384f8c4b186ddc9f06cbd5f k8s.gcr.io/sig-storage/csi-node-driver-registrar:v2.1.0],SizeBytes:9068367,},ContainerImage{Names:[k8s.gcr.io/sig-storage/livenessprobe@sha256:529be2c9770add0cdd0c989115222ea9fc1be430c11095eb9f6dafcf98a36e2b k8s.gcr.io/sig-storage/livenessprobe:v2.4.0],SizeBytes:7960518,},ContainerImage{Names:[k8s.gcr.io/pause@sha256:927d98197ec1141a368550822d18fa1c60bdae27b78b0c004f705f548c07814f k8s.gcr.io/pause:3.2],SizeBytes:299513,},},VolumesInUse:[],VolumesAttached:[]AttachedVolume{},Config:nil,},}
... skipping 106 lines ...
/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:175
  [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    (OnRootMismatch)[LinuxOnly], pod created with an initial fsgroup, volume contents ownership changed in first pod, new pod with same fsgroup skips ownership changes to the volume contents [It]
    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/fsgroupchangepolicy.go:208

    Unexpected error:
        <*errors.errorString | 0xc000f26b50>: {
            s: "pod \"pod-b5439bb6-2850-4463-a5de-9cd2e9017980\" is not Running: timed out waiting for the condition",
        }
        pod "pod-b5439bb6-2850-4463-a5de-9cd2e9017980" is not Running: timed out waiting for the condition
    occurred

... skipping 71 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: ebs.csi.aws.com]
/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:175
  [Testpattern: Pre-provisioned PV (block volmode)] volumeMode
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    should fail to use a volume in a pod with mismatched mode [Slow] [BeforeEach]
    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/volumemode.go:297

    Driver "ebs.csi.aws.com" does not support volume type "PreprovisionedPV" - skipping

    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:263
------------------------------
... skipping 36 lines ...
May 11 01:52:01.379: INFO: At 2022-05-11 01:46:33 +0000 UTC - event for ebs.csi.aws.comzv4x6: {persistentvolume-controller } WaitForFirstConsumer: waiting for first consumer to be created before binding
May 11 01:52:01.379: INFO: At 2022-05-11 01:46:33 +0000 UTC - event for ebs.csi.aws.comzv4x6: {persistentvolume-controller } ExternalProvisioning: waiting for a volume to be created, either by external provisioner "ebs.csi.aws.com" or manually created by system administrator
May 11 01:52:01.379: INFO: At 2022-05-11 01:46:33 +0000 UTC - event for ebs.csi.aws.comzv4x6: {ebs.csi.aws.com_ebs-csi-controller-65f7fb9696-j8nqp_23e52550-a198-4e6b-86aa-7a440fbfd693 } Provisioning: External provisioner is provisioning volume for claim "provisioning-9165/ebs.csi.aws.comzv4x6"
May 11 01:52:01.379: INFO: At 2022-05-11 01:46:36 +0000 UTC - event for ebs.csi.aws.comzv4x6: {ebs.csi.aws.com_ebs-csi-controller-65f7fb9696-j8nqp_23e52550-a198-4e6b-86aa-7a440fbfd693 } ProvisioningSucceeded: Successfully provisioned volume pvc-6d27dd67-c7bc-490f-807c-e087cf6d6b25
May 11 01:52:01.379: INFO: At 2022-05-11 01:46:37 +0000 UTC - event for pod-subpath-test-dynamicpv-4vhr: {default-scheduler } Scheduled: Successfully assigned provisioning-9165/pod-subpath-test-dynamicpv-4vhr to ip-172-20-61-6.us-west-2.compute.internal
May 11 01:52:01.379: INFO: At 2022-05-11 01:46:39 +0000 UTC - event for pod-subpath-test-dynamicpv-4vhr: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-6d27dd67-c7bc-490f-807c-e087cf6d6b25" 
May 11 01:52:01.379: INFO: At 2022-05-11 01:46:53 +0000 UTC - event for pod-subpath-test-dynamicpv-4vhr: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: MountVolume.MountDevice failed for volume "pvc-6d27dd67-c7bc-490f-807c-e087cf6d6b25" : rpc error: code = Internal desc = could not format "/dev/nvme4n1" and mount it at "/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-6d27dd67-c7bc-490f-807c-e087cf6d6b25/globalmount": format of disk "/dev/nvme4n1" failed: type:("ext4") target:("/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-6d27dd67-c7bc-490f-807c-e087cf6d6b25/globalmount") options:("defaults") errcode:(exit status 127) output:(mkfs.ext4: symbol lookup error: /lib/x86_64-linux-gnu/libpthread.so.0: undefined symbol: __libc_vfork, version GLIBC_PRIVATE
) 
May 11 01:52:01.379: INFO: At 2022-05-11 01:48:40 +0000 UTC - event for pod-subpath-test-dynamicpv-4vhr: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[test-volume], unattached volumes=[test-volume liveness-probe-volume default-token-t2lrz]: timed out waiting for the condition
May 11 01:52:01.448: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
May 11 01:52:01.448: INFO: 
May 11 01:52:01.524: INFO: 
Logging node info for node ip-172-20-126-84.us-west-2.compute.internal
... skipping 108 lines ...
  [Testpattern: Dynamic PV (default fs)] subPath
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    should support restarting containers using directory as subpath [Slow] [It]
    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:320

    while waiting for pod to be running
    Unexpected error:
        <*errors.errorString | 0xc00022e200>: {
            s: "timed out waiting for the condition",
        }
        timed out waiting for the condition
    occurred

... skipping 38 lines ...
May 11 01:47:09.705: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(ebs.csi.aws.com) supported size:{ 1Mi} 
STEP: creating a StorageClass provisioning-6625-e2e-sc4mtwf
STEP: creating a claim
May 11 01:47:09.770: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
STEP: Creating pod pod-subpath-test-dynamicpv-9flq
STEP: Creating a pod to test subpath
May 11 01:47:09.967: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-9flq" in namespace "provisioning-6625" to be "Succeeded or Failed"
May 11 01:47:10.031: INFO: Pod "pod-subpath-test-dynamicpv-9flq": Phase="Pending", Reason="", readiness=false. Elapsed: 64.049231ms
May 11 01:47:12.096: INFO: Pod "pod-subpath-test-dynamicpv-9flq": Phase="Pending", Reason="", readiness=false. Elapsed: 2.128789952s
May 11 01:47:14.162: INFO: Pod "pod-subpath-test-dynamicpv-9flq": Phase="Pending", Reason="", readiness=false. Elapsed: 4.194535083s
May 11 01:47:16.233: INFO: Pod "pod-subpath-test-dynamicpv-9flq": Phase="Pending", Reason="", readiness=false. Elapsed: 6.265430241s
May 11 01:47:18.298: INFO: Pod "pod-subpath-test-dynamicpv-9flq": Phase="Pending", Reason="", readiness=false. Elapsed: 8.330752463s
May 11 01:47:20.364: INFO: Pod "pod-subpath-test-dynamicpv-9flq": Phase="Pending", Reason="", readiness=false. Elapsed: 10.396648577s
... skipping 134 lines ...
May 11 01:51:59.266: INFO: Pod "pod-subpath-test-dynamicpv-9flq": Phase="Pending", Reason="", readiness=false. Elapsed: 4m49.299160539s
May 11 01:52:01.331: INFO: Pod "pod-subpath-test-dynamicpv-9flq": Phase="Pending", Reason="", readiness=false. Elapsed: 4m51.363604235s
May 11 01:52:03.397: INFO: Pod "pod-subpath-test-dynamicpv-9flq": Phase="Pending", Reason="", readiness=false. Elapsed: 4m53.429555614s
May 11 01:52:05.463: INFO: Pod "pod-subpath-test-dynamicpv-9flq": Phase="Pending", Reason="", readiness=false. Elapsed: 4m55.495546891s
May 11 01:52:07.527: INFO: Pod "pod-subpath-test-dynamicpv-9flq": Phase="Pending", Reason="", readiness=false. Elapsed: 4m57.560062539s
May 11 01:52:09.592: INFO: Pod "pod-subpath-test-dynamicpv-9flq": Phase="Pending", Reason="", readiness=false. Elapsed: 4m59.624913256s
May 11 01:52:11.725: INFO: Failed to get logs from node "ip-172-20-61-6.us-west-2.compute.internal" pod "pod-subpath-test-dynamicpv-9flq" container "init-volume-dynamicpv-9flq": the server rejected our request for an unknown reason (get pods pod-subpath-test-dynamicpv-9flq)
May 11 01:52:11.790: INFO: Failed to get logs from node "ip-172-20-61-6.us-west-2.compute.internal" pod "pod-subpath-test-dynamicpv-9flq" container "test-init-subpath-dynamicpv-9flq": the server rejected our request for an unknown reason (get pods pod-subpath-test-dynamicpv-9flq)
May 11 01:52:11.870: INFO: Failed to get logs from node "ip-172-20-61-6.us-west-2.compute.internal" pod "pod-subpath-test-dynamicpv-9flq" container "test-container-subpath-dynamicpv-9flq": the server rejected our request for an unknown reason (get pods pod-subpath-test-dynamicpv-9flq)
STEP: delete the pod
May 11 01:52:11.937: INFO: Waiting for pod pod-subpath-test-dynamicpv-9flq to disappear
May 11 01:52:12.002: INFO: Pod pod-subpath-test-dynamicpv-9flq still exists
May 11 01:52:14.003: INFO: Waiting for pod pod-subpath-test-dynamicpv-9flq to disappear
May 11 01:52:14.068: INFO: Pod pod-subpath-test-dynamicpv-9flq still exists
May 11 01:52:16.002: INFO: Waiting for pod pod-subpath-test-dynamicpv-9flq to disappear
... skipping 15 lines ...
May 11 01:52:31.720: INFO: At 2022-05-11 01:47:09 +0000 UTC - event for ebs.csi.aws.compczdc: {persistentvolume-controller } WaitForFirstConsumer: waiting for first consumer to be created before binding
May 11 01:52:31.720: INFO: At 2022-05-11 01:47:09 +0000 UTC - event for ebs.csi.aws.compczdc: {persistentvolume-controller } ExternalProvisioning: waiting for a volume to be created, either by external provisioner "ebs.csi.aws.com" or manually created by system administrator
May 11 01:52:31.720: INFO: At 2022-05-11 01:47:09 +0000 UTC - event for ebs.csi.aws.compczdc: {ebs.csi.aws.com_ebs-csi-controller-65f7fb9696-j8nqp_23e52550-a198-4e6b-86aa-7a440fbfd693 } Provisioning: External provisioner is provisioning volume for claim "provisioning-6625/ebs.csi.aws.compczdc"
May 11 01:52:31.720: INFO: At 2022-05-11 01:47:13 +0000 UTC - event for ebs.csi.aws.compczdc: {ebs.csi.aws.com_ebs-csi-controller-65f7fb9696-j8nqp_23e52550-a198-4e6b-86aa-7a440fbfd693 } ProvisioningSucceeded: Successfully provisioned volume pvc-84226b75-eb37-4b6f-b34c-1a86a4b027d6
May 11 01:52:31.720: INFO: At 2022-05-11 01:47:13 +0000 UTC - event for pod-subpath-test-dynamicpv-9flq: {default-scheduler } Scheduled: Successfully assigned provisioning-6625/pod-subpath-test-dynamicpv-9flq to ip-172-20-61-6.us-west-2.compute.internal
May 11 01:52:31.720: INFO: At 2022-05-11 01:47:15 +0000 UTC - event for pod-subpath-test-dynamicpv-9flq: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-84226b75-eb37-4b6f-b34c-1a86a4b027d6" 
May 11 01:52:31.720: INFO: At 2022-05-11 01:47:17 +0000 UTC - event for pod-subpath-test-dynamicpv-9flq: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: MountVolume.MountDevice failed for volume "pvc-84226b75-eb37-4b6f-b34c-1a86a4b027d6" : rpc error: code = Internal desc = could not format "/dev/nvme2n1" and mount it at "/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-84226b75-eb37-4b6f-b34c-1a86a4b027d6/globalmount": format of disk "/dev/nvme2n1" failed: type:("ext4") target:("/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-84226b75-eb37-4b6f-b34c-1a86a4b027d6/globalmount") options:("defaults") errcode:(exit status 127) output:(mkfs.ext4: symbol lookup error: /lib/x86_64-linux-gnu/libpthread.so.0: undefined symbol: __libc_vfork, version GLIBC_PRIVATE
) 
May 11 01:52:31.720: INFO: At 2022-05-11 01:49:16 +0000 UTC - event for pod-subpath-test-dynamicpv-9flq: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[test-volume], unattached volumes=[test-volume liveness-probe-volume default-token-dswxh]: timed out waiting for the condition
May 11 01:52:31.784: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
May 11 01:52:31.784: INFO: 
May 11 01:52:31.850: INFO: 
Logging node info for node ip-172-20-126-84.us-west-2.compute.internal
... skipping 105 lines ...
/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:175
  [Testpattern: Dynamic PV (default fs)] subPath
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    should support existing directories when readOnly specified in the volumeSource [It]
    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:399

    Unexpected error:
        <*errors.errorString | 0xc000940e00>: {
            s: "expected pod \"pod-subpath-test-dynamicpv-9flq\" success: Gave up after waiting 5m0s for pod \"pod-subpath-test-dynamicpv-9flq\" to be \"Succeeded or Failed\"",
        }
        expected pod "pod-subpath-test-dynamicpv-9flq" success: Gave up after waiting 5m0s for pod "pod-subpath-test-dynamicpv-9flq" to be "Succeeded or Failed"
    occurred

    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/framework/util.go:742
------------------------------
SSSS
------------------------------
... skipping 26 lines ...

    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/provisioning.go:240
------------------------------
SSSSS
------------------------------
External Storage [Driver: ebs.csi.aws.com] [Testpattern: Dynamic PV (immediate binding)] topology 
  should fail to schedule a pod which has topologies that conflict with AllowedTopologies
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/topology.go:192

[BeforeEach] [Testpattern: Dynamic PV (immediate binding)] topology
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Dynamic PV (immediate binding)] topology
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/framework/framework.go:185
STEP: Creating a kubernetes client
May 11 01:52:34.366: INFO: >>> kubeConfig: /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/hack/e2e/csi-test-artifacts/test-cluster-28361.k8s.local.kops.kubeconfig
STEP: Building a namespace api object, basename topology
STEP: Waiting for a default service account to be provisioned in namespace
[It] should fail to schedule a pod which has topologies that conflict with AllowedTopologies
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/topology.go:192
May 11 01:52:34.756: INFO: found topology map[topology.ebs.csi.aws.com/zone:us-west-2c]
May 11 01:52:34.756: INFO: found topology map[topology.ebs.csi.aws.com/zone:us-west-2a]
May 11 01:52:34.757: INFO: Creating storage class object and pvc object for driver - sc: &StorageClass{ObjectMeta:{topology-8289-e2e-sc8hjkk      0 0001-01-01 00:00:00 +0000 UTC <nil> <nil> map[] map[] [] []  []},Provisioner:ebs.csi.aws.com,Parameters:map[string]string{},ReclaimPolicy:nil,MountOptions:[],AllowVolumeExpansion:nil,VolumeBindingMode:*Immediate,AllowedTopologies:[]TopologySelectorTerm{{[{topology.ebs.csi.aws.com/zone [us-west-2a]}]},},}, pvc: &PersistentVolumeClaim{ObjectMeta:{ pvc- topology-8289    0 0001-01-01 00:00:00 +0000 UTC <nil> <nil> map[] map[] [] []  []},Spec:PersistentVolumeClaimSpec{AccessModes:[ReadWriteOnce],Resources:ResourceRequirements{Limits:ResourceList{},Requests:ResourceList{storage: {{1073741824 0} {<nil>} 1Gi BinarySI},},},VolumeName:,Selector:nil,StorageClassName:*topology-8289-e2e-sc8hjkk,VolumeMode:nil,DataSource:nil,},Status:PersistentVolumeClaimStatus{Phase:,AccessModes:[],Capacity:ResourceList{},Conditions:[]PersistentVolumeClaimCondition{},},}
STEP: Creating sc
STEP: Creating pvc
... skipping 159 lines ...
May 11 01:39:59.147: INFO: Creating resource for dynamic PV
May 11 01:39:59.147: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(ebs.csi.aws.com) supported size:{ 1Mi} 
STEP: creating a StorageClass snapshotting-5417-e2e-scbsclq
STEP: creating a claim
May 11 01:39:59.211: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
STEP: [init] starting a pod to use the claim
May 11 01:39:59.410: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-ncntb" in namespace "snapshotting-5417" to be "Succeeded or Failed"
May 11 01:39:59.474: INFO: Pod "pvc-snapshottable-tester-ncntb": Phase="Pending", Reason="", readiness=false. Elapsed: 63.97873ms
May 11 01:40:01.538: INFO: Pod "pvc-snapshottable-tester-ncntb": Phase="Pending", Reason="", readiness=false. Elapsed: 2.127860031s
May 11 01:40:03.601: INFO: Pod "pvc-snapshottable-tester-ncntb": Phase="Pending", Reason="", readiness=false. Elapsed: 4.191374002s
May 11 01:40:05.666: INFO: Pod "pvc-snapshottable-tester-ncntb": Phase="Pending", Reason="", readiness=false. Elapsed: 6.255725333s
May 11 01:40:07.729: INFO: Pod "pvc-snapshottable-tester-ncntb": Phase="Pending", Reason="", readiness=false. Elapsed: 8.319611709s
May 11 01:40:09.793: INFO: Pod "pvc-snapshottable-tester-ncntb": Phase="Pending", Reason="", readiness=false. Elapsed: 10.383109601s
... skipping 424 lines ...
May 11 01:54:47.622: INFO: Pod "pvc-snapshottable-tester-ncntb": Phase="Pending", Reason="", readiness=false. Elapsed: 14m48.211643466s
May 11 01:54:49.692: INFO: Pod "pvc-snapshottable-tester-ncntb": Phase="Pending", Reason="", readiness=false. Elapsed: 14m50.282256849s
May 11 01:54:51.756: INFO: Pod "pvc-snapshottable-tester-ncntb": Phase="Pending", Reason="", readiness=false. Elapsed: 14m52.346549337s
May 11 01:54:53.822: INFO: Pod "pvc-snapshottable-tester-ncntb": Phase="Pending", Reason="", readiness=false. Elapsed: 14m54.4120512s
May 11 01:54:55.891: INFO: Pod "pvc-snapshottable-tester-ncntb": Phase="Pending", Reason="", readiness=false. Elapsed: 14m56.481060785s
May 11 01:54:57.955: INFO: Pod "pvc-snapshottable-tester-ncntb": Phase="Pending", Reason="", readiness=false. Elapsed: 14m58.545503423s
May 11 01:55:00.082: INFO: Error getting logs for pod pvc-snapshottable-tester-ncntb: the server rejected our request for an unknown reason (get pods pvc-snapshottable-tester-ncntb)
May 11 01:55:00.082: INFO: Deleting pod "pvc-snapshottable-tester-ncntb" in namespace "snapshotting-5417"
May 11 01:55:00.173: INFO: Wait up to 5m0s for pod "pvc-snapshottable-tester-ncntb" to be fully deleted
[AfterEach] volume snapshot controller
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/snapshottable.go:223
STEP: Deleting pvc
May 11 01:55:06.439: INFO: Deleting PersistentVolumeClaim "ebs.csi.aws.com2r95p"
... skipping 10 lines ...
May 11 01:55:21.911: INFO: At 2022-05-11 01:39:59 +0000 UTC - event for ebs.csi.aws.com2r95p: {persistentvolume-controller } WaitForFirstConsumer: waiting for first consumer to be created before binding
May 11 01:55:21.911: INFO: At 2022-05-11 01:39:59 +0000 UTC - event for ebs.csi.aws.com2r95p: {persistentvolume-controller } ExternalProvisioning: waiting for a volume to be created, either by external provisioner "ebs.csi.aws.com" or manually created by system administrator
May 11 01:55:21.911: INFO: At 2022-05-11 01:39:59 +0000 UTC - event for ebs.csi.aws.com2r95p: {ebs.csi.aws.com_ebs-csi-controller-65f7fb9696-j8nqp_23e52550-a198-4e6b-86aa-7a440fbfd693 } Provisioning: External provisioner is provisioning volume for claim "snapshotting-5417/ebs.csi.aws.com2r95p"
May 11 01:55:21.911: INFO: At 2022-05-11 01:40:02 +0000 UTC - event for ebs.csi.aws.com2r95p: {ebs.csi.aws.com_ebs-csi-controller-65f7fb9696-j8nqp_23e52550-a198-4e6b-86aa-7a440fbfd693 } ProvisioningSucceeded: Successfully provisioned volume pvc-9654faac-ea41-4af9-92be-8bd61963c729
May 11 01:55:21.911: INFO: At 2022-05-11 01:40:03 +0000 UTC - event for pvc-snapshottable-tester-ncntb: {default-scheduler } Scheduled: Successfully assigned snapshotting-5417/pvc-snapshottable-tester-ncntb to ip-172-20-61-6.us-west-2.compute.internal
May 11 01:55:21.911: INFO: At 2022-05-11 01:40:05 +0000 UTC - event for pvc-snapshottable-tester-ncntb: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-9654faac-ea41-4af9-92be-8bd61963c729" 
May 11 01:55:21.911: INFO: At 2022-05-11 01:40:07 +0000 UTC - event for pvc-snapshottable-tester-ncntb: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: MountVolume.MountDevice failed for volume "pvc-9654faac-ea41-4af9-92be-8bd61963c729" : rpc error: code = Internal desc = could not format "/dev/nvme1n1" and mount it at "/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-9654faac-ea41-4af9-92be-8bd61963c729/globalmount": format of disk "/dev/nvme1n1" failed: type:("ext4") target:("/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-9654faac-ea41-4af9-92be-8bd61963c729/globalmount") options:("defaults") errcode:(exit status 127) output:(mkfs.ext4: symbol lookup error: /lib/x86_64-linux-gnu/libpthread.so.0: undefined symbol: __libc_vfork, version GLIBC_PRIVATE
) 
May 11 01:55:21.911: INFO: At 2022-05-11 01:42:06 +0000 UTC - event for pvc-snapshottable-tester-ncntb: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[my-volume], unattached volumes=[default-token-qhrkq my-volume]: timed out waiting for the condition
May 11 01:55:21.911: INFO: At 2022-05-11 01:44:21 +0000 UTC - event for pvc-snapshottable-tester-ncntb: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[my-volume], unattached volumes=[my-volume default-token-qhrkq]: timed out waiting for the condition
May 11 01:55:21.975: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
May 11 01:55:21.975: INFO: 
May 11 01:55:22.040: INFO: 
... skipping 110 lines ...
    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/snapshottable.go:108
       [BeforeEach]
      /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/snapshottable.go:227
        should check snapshot fields, check restore correctly works after modifying source data, check deletion
        /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/snapshottable.go:245

        Unexpected error:
            <*errors.errorString | 0xc001412e40>: {
                s: "Gave up after waiting 15m0s for pod \"pvc-snapshottable-tester-ncntb\" to be \"Succeeded or Failed\"",
            }
            Gave up after waiting 15m0s for pod "pvc-snapshottable-tester-ncntb" to be "Succeeded or Failed"
        occurred

        /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/provisioning.go:675
------------------------------
External Storage [Driver: ebs.csi.aws.com] [Testpattern: Dynamic PV (filesystem volmode)] multiVolume [Slow] 
  should access to two volumes with the same volume mode and retain data across pod recreation on the same node [LinuxOnly]
... skipping 46 lines ...
May 11 01:57:26.950: INFO: At 2022-05-11 01:51:59 +0000 UTC - event for ebs.csi.aws.comhhtjk: {persistentvolume-controller } ExternalProvisioning: waiting for a volume to be created, either by external provisioner "ebs.csi.aws.com" or manually created by system administrator
May 11 01:57:26.950: INFO: At 2022-05-11 01:52:02 +0000 UTC - event for ebs.csi.aws.comhhtjk: {ebs.csi.aws.com_ebs-csi-controller-65f7fb9696-j8nqp_23e52550-a198-4e6b-86aa-7a440fbfd693 } ProvisioningSucceeded: Successfully provisioned volume pvc-eaff1df5-0715-462d-9b18-d75edcf84633
May 11 01:57:26.950: INFO: At 2022-05-11 01:52:03 +0000 UTC - event for ebs.csi.aws.com287w9: {ebs.csi.aws.com_ebs-csi-controller-65f7fb9696-j8nqp_23e52550-a198-4e6b-86aa-7a440fbfd693 } ProvisioningSucceeded: Successfully provisioned volume pvc-15cb51ac-4517-4afc-84d3-4438e3b3f291
May 11 01:57:26.950: INFO: At 2022-05-11 01:52:03 +0000 UTC - event for pod-4473283a-8fe1-4265-b6a3-9402a1b3afd3: {default-scheduler } Scheduled: Successfully assigned multivolume-8803/pod-4473283a-8fe1-4265-b6a3-9402a1b3afd3 to ip-172-20-61-6.us-west-2.compute.internal
May 11 01:57:26.950: INFO: At 2022-05-11 01:52:05 +0000 UTC - event for pod-4473283a-8fe1-4265-b6a3-9402a1b3afd3: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-eaff1df5-0715-462d-9b18-d75edcf84633" 
May 11 01:57:26.950: INFO: At 2022-05-11 01:52:05 +0000 UTC - event for pod-4473283a-8fe1-4265-b6a3-9402a1b3afd3: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-15cb51ac-4517-4afc-84d3-4438e3b3f291" 
May 11 01:57:26.950: INFO: At 2022-05-11 01:52:11 +0000 UTC - event for pod-4473283a-8fe1-4265-b6a3-9402a1b3afd3: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: MountVolume.MountDevice failed for volume "pvc-15cb51ac-4517-4afc-84d3-4438e3b3f291" : rpc error: code = Internal desc = could not format "/dev/nvme5n1" and mount it at "/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-15cb51ac-4517-4afc-84d3-4438e3b3f291/globalmount": format of disk "/dev/nvme5n1" failed: type:("ext4") target:("/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-15cb51ac-4517-4afc-84d3-4438e3b3f291/globalmount") options:("defaults") errcode:(exit status 127) output:(mkfs.ext4: symbol lookup error: /lib/x86_64-linux-gnu/libpthread.so.0: undefined symbol: __libc_vfork, version GLIBC_PRIVATE
) 
May 11 01:57:26.950: INFO: At 2022-05-11 01:52:11 +0000 UTC - event for pod-4473283a-8fe1-4265-b6a3-9402a1b3afd3: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: MountVolume.MountDevice failed for volume "pvc-eaff1df5-0715-462d-9b18-d75edcf84633" : rpc error: code = Internal desc = could not format "/dev/nvme4n1" and mount it at "/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-eaff1df5-0715-462d-9b18-d75edcf84633/globalmount": format of disk "/dev/nvme4n1" failed: type:("ext4") target:("/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-eaff1df5-0715-462d-9b18-d75edcf84633/globalmount") options:("defaults") errcode:(exit status 127) output:(mkfs.ext4: symbol lookup error: /lib/x86_64-linux-gnu/libpthread.so.0: undefined symbol: __libc_vfork, version GLIBC_PRIVATE
) 
May 11 01:57:26.950: INFO: At 2022-05-11 01:54:06 +0000 UTC - event for pod-4473283a-8fe1-4265-b6a3-9402a1b3afd3: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[volume1 volume2], unattached volumes=[volume1 volume2 default-token-x8h9r]: timed out waiting for the condition
May 11 01:57:26.950: INFO: At 2022-05-11 01:56:23 +0000 UTC - event for pod-4473283a-8fe1-4265-b6a3-9402a1b3afd3: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[volume2 volume1], unattached volumes=[volume2 default-token-x8h9r volume1]: timed out waiting for the condition
May 11 01:57:27.012: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
May 11 01:57:27.012: INFO: 
May 11 01:57:27.074: INFO: 
... skipping 106 lines ...
/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:175
  [Testpattern: Dynamic PV (filesystem volmode)] multiVolume [Slow]
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    should access to two volumes with the same volume mode and retain data across pod recreation on the same node [LinuxOnly] [It]
    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/multivolume.go:134

    Unexpected error:
        <*errors.errorString | 0xc000a919f0>: {
            s: "pod \"pod-4473283a-8fe1-4265-b6a3-9402a1b3afd3\" is not Running: timed out waiting for the condition",
        }
        pod "pod-4473283a-8fe1-4265-b6a3-9402a1b3afd3" is not Running: timed out waiting for the condition
    occurred

... skipping 124 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: ebs.csi.aws.com]
/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:175
  [Testpattern: Inline-volume (default fs)] subPath
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    should fail if subpath with backstepping is outside the volume [Slow][LinuxOnly] [BeforeEach]
    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:278

    Driver "ebs.csi.aws.com" does not support volume type "InlineVolume" - skipping

    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:263
------------------------------
... skipping 8 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: ebs.csi.aws.com]
/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:175
  [Testpattern: Inline-volume (default fs)] subPath
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    should fail if subpath directory is outside the volume [Slow][LinuxOnly] [BeforeEach]
    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:240

    Driver "ebs.csi.aws.com" does not support volume type "InlineVolume" - skipping

    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:263
------------------------------
... skipping 27 lines ...
May 11 01:57:42.942: INFO: Waiting for pod external-injector to disappear
May 11 01:57:43.007: INFO: Pod external-injector still exists
May 11 01:57:44.942: INFO: Waiting for pod external-injector to disappear
May 11 01:57:45.007: INFO: Pod external-injector still exists
May 11 01:57:46.944: INFO: Waiting for pod external-injector to disappear
May 11 01:57:47.009: INFO: Pod external-injector no longer exists
May 11 01:57:47.010: FAIL: Failed to create injector pod: timed out waiting for the condition

Full Stack Trace
k8s.io/kubernetes/test/e2e/storage/testsuites.(*volumesTestSuite).DefineTests.func3()
	/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/volumes.go:186 +0x485
github.com/kubernetes-sigs/aws-ebs-csi-driver/tests/e2e-kubernetes.TestEBSCSI(0x0?)
	/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/tests/e2e-kubernetes/e2e_test.go:82 +0x311
... skipping 17 lines ...
May 11 01:58:02.606: INFO: At 2022-05-11 01:52:36 +0000 UTC - event for ebs.csi.aws.comgrgd7: {persistentvolume-controller } WaitForFirstConsumer: waiting for first consumer to be created before binding
May 11 01:58:02.606: INFO: At 2022-05-11 01:52:36 +0000 UTC - event for ebs.csi.aws.comgrgd7: {persistentvolume-controller } ExternalProvisioning: waiting for a volume to be created, either by external provisioner "ebs.csi.aws.com" or manually created by system administrator
May 11 01:58:02.606: INFO: At 2022-05-11 01:52:36 +0000 UTC - event for ebs.csi.aws.comgrgd7: {ebs.csi.aws.com_ebs-csi-controller-65f7fb9696-j8nqp_23e52550-a198-4e6b-86aa-7a440fbfd693 } Provisioning: External provisioner is provisioning volume for claim "volume-5030/ebs.csi.aws.comgrgd7"
May 11 01:58:02.606: INFO: At 2022-05-11 01:52:39 +0000 UTC - event for ebs.csi.aws.comgrgd7: {ebs.csi.aws.com_ebs-csi-controller-65f7fb9696-j8nqp_23e52550-a198-4e6b-86aa-7a440fbfd693 } ProvisioningSucceeded: Successfully provisioned volume pvc-c3bb8159-75e0-4910-9ef3-d9605bb600e8
May 11 01:58:02.606: INFO: At 2022-05-11 01:52:40 +0000 UTC - event for external-injector: {default-scheduler } Scheduled: Successfully assigned volume-5030/external-injector to ip-172-20-61-6.us-west-2.compute.internal
May 11 01:58:02.606: INFO: At 2022-05-11 01:52:42 +0000 UTC - event for external-injector: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-c3bb8159-75e0-4910-9ef3-d9605bb600e8" 
May 11 01:58:02.606: INFO: At 2022-05-11 01:52:56 +0000 UTC - event for external-injector: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: MountVolume.MountDevice failed for volume "pvc-c3bb8159-75e0-4910-9ef3-d9605bb600e8" : rpc error: code = Internal desc = could not format "/dev/nvme2n1" and mount it at "/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-c3bb8159-75e0-4910-9ef3-d9605bb600e8/globalmount": format of disk "/dev/nvme2n1" failed: type:("ext4") target:("/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-c3bb8159-75e0-4910-9ef3-d9605bb600e8/globalmount") options:("defaults") errcode:(exit status 127) output:(mkfs.ext4: symbol lookup error: /lib/x86_64-linux-gnu/libpthread.so.0: undefined symbol: __libc_vfork, version GLIBC_PRIVATE
) 
May 11 01:58:02.606: INFO: At 2022-05-11 01:54:43 +0000 UTC - event for external-injector: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[external-volume-0], unattached volumes=[external-volume-0 default-token-lf88x]: timed out waiting for the condition
May 11 01:58:02.672: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
May 11 01:58:02.672: INFO: 
May 11 01:58:02.738: INFO: 
Logging node info for node ip-172-20-126-84.us-west-2.compute.internal
... skipping 105 lines ...
/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:175
  [Testpattern: Dynamic PV (ext4)] volumes
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    should store data [It]
    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/volumes.go:159

    May 11 01:57:47.010: Failed to create injector pod: timed out waiting for the condition

    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/volumes.go:186
------------------------------
SSSSSS
------------------------------
[BeforeEach] [Testpattern: Inline-volume (default fs)] subPath
... skipping 5 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: ebs.csi.aws.com]
/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:175
  [Testpattern: Inline-volume (default fs)] subPath
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    should fail if non-existent subpath is outside the volume [Slow][LinuxOnly] [BeforeEach]
    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:267

    Driver "ebs.csi.aws.com" does not support volume type "InlineVolume" - skipping

    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:263
------------------------------
... skipping 38 lines ...
May 11 02:00:52.716: INFO: At 2022-05-11 01:55:24 +0000 UTC - event for ebs.csi.aws.combcd9c: {persistentvolume-controller } WaitForFirstConsumer: waiting for first consumer to be created before binding
May 11 02:00:52.716: INFO: At 2022-05-11 01:55:24 +0000 UTC - event for ebs.csi.aws.combcd9c: {persistentvolume-controller } ExternalProvisioning: waiting for a volume to be created, either by external provisioner "ebs.csi.aws.com" or manually created by system administrator
May 11 02:00:52.716: INFO: At 2022-05-11 01:55:24 +0000 UTC - event for ebs.csi.aws.combcd9c: {ebs.csi.aws.com_ebs-csi-controller-65f7fb9696-j8nqp_23e52550-a198-4e6b-86aa-7a440fbfd693 } Provisioning: External provisioner is provisioning volume for claim "volume-expand-3763/ebs.csi.aws.combcd9c"
May 11 02:00:52.716: INFO: At 2022-05-11 01:55:27 +0000 UTC - event for ebs.csi.aws.combcd9c: {ebs.csi.aws.com_ebs-csi-controller-65f7fb9696-j8nqp_23e52550-a198-4e6b-86aa-7a440fbfd693 } ProvisioningSucceeded: Successfully provisioned volume pvc-aa69756f-fcd6-4e96-bc56-f4887fe7ed7c
May 11 02:00:52.716: INFO: At 2022-05-11 01:55:28 +0000 UTC - event for pod-113a742d-eb15-4300-8a8a-f486da66bdf9: {default-scheduler } Scheduled: Successfully assigned volume-expand-3763/pod-113a742d-eb15-4300-8a8a-f486da66bdf9 to ip-172-20-61-6.us-west-2.compute.internal
May 11 02:00:52.716: INFO: At 2022-05-11 01:55:30 +0000 UTC - event for pod-113a742d-eb15-4300-8a8a-f486da66bdf9: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-aa69756f-fcd6-4e96-bc56-f4887fe7ed7c" 
May 11 02:00:52.716: INFO: At 2022-05-11 01:55:32 +0000 UTC - event for pod-113a742d-eb15-4300-8a8a-f486da66bdf9: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: MountVolume.MountDevice failed for volume "pvc-aa69756f-fcd6-4e96-bc56-f4887fe7ed7c" : rpc error: code = Internal desc = could not format "/dev/nvme1n1" and mount it at "/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-aa69756f-fcd6-4e96-bc56-f4887fe7ed7c/globalmount": format of disk "/dev/nvme1n1" failed: type:("ext4") target:("/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-aa69756f-fcd6-4e96-bc56-f4887fe7ed7c/globalmount") options:("defaults") errcode:(exit status 127) output:(mkfs.ext4: symbol lookup error: /lib/x86_64-linux-gnu/libpthread.so.0: undefined symbol: __libc_vfork, version GLIBC_PRIVATE
) 
May 11 02:00:52.716: INFO: At 2022-05-11 01:57:31 +0000 UTC - event for pod-113a742d-eb15-4300-8a8a-f486da66bdf9: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[volume1], unattached volumes=[default-token-8c46m volume1]: timed out waiting for the condition
May 11 02:00:52.716: INFO: At 2022-05-11 01:59:48 +0000 UTC - event for pod-113a742d-eb15-4300-8a8a-f486da66bdf9: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[volume1], unattached volumes=[volume1 default-token-8c46m]: timed out waiting for the condition
May 11 02:00:52.780: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
May 11 02:00:52.780: INFO: 
May 11 02:00:52.850: INFO: 
... skipping 108 lines ...
  [Testpattern: Dynamic PV (default fs)(allowExpansion)] volume-expand
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    Verify if offline PVC expansion works [It]
    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/volume_expand.go:174

    While creating pods for resizing
    Unexpected error:
        <*errors.errorString | 0xc0011ef0c0>: {
            s: "pod \"pod-113a742d-eb15-4300-8a8a-f486da66bdf9\" is not Running: timed out waiting for the condition",
        }
        pod "pod-113a742d-eb15-4300-8a8a-f486da66bdf9" is not Running: timed out waiting for the condition
    occurred

... skipping 38 lines ...
May 11 02:03:28.101: INFO: At 2022-05-11 01:57:56 +0000 UTC - event for ebs.csi.aws.comjkq8g: {persistentvolume-controller } WaitForFirstConsumer: waiting for first consumer to be created before binding
May 11 02:03:28.101: INFO: At 2022-05-11 01:57:57 +0000 UTC - event for ebs.csi.aws.comjkq8g: {persistentvolume-controller } ExternalProvisioning: waiting for a volume to be created, either by external provisioner "ebs.csi.aws.com" or manually created by system administrator
May 11 02:03:28.101: INFO: At 2022-05-11 01:57:57 +0000 UTC - event for ebs.csi.aws.comjkq8g: {ebs.csi.aws.com_ebs-csi-controller-65f7fb9696-j8nqp_23e52550-a198-4e6b-86aa-7a440fbfd693 } Provisioning: External provisioner is provisioning volume for claim "volume-expand-7205/ebs.csi.aws.comjkq8g"
May 11 02:03:28.101: INFO: At 2022-05-11 01:58:00 +0000 UTC - event for ebs.csi.aws.comjkq8g: {ebs.csi.aws.com_ebs-csi-controller-65f7fb9696-j8nqp_23e52550-a198-4e6b-86aa-7a440fbfd693 } ProvisioningSucceeded: Successfully provisioned volume pvc-f70b7806-41e4-4fc7-ab58-bff7fae791da
May 11 02:03:28.101: INFO: At 2022-05-11 01:58:01 +0000 UTC - event for pod-623ce888-ab64-43b5-b514-3fd1f4bc2959: {default-scheduler } Scheduled: Successfully assigned volume-expand-7205/pod-623ce888-ab64-43b5-b514-3fd1f4bc2959 to ip-172-20-61-6.us-west-2.compute.internal
May 11 02:03:28.101: INFO: At 2022-05-11 01:58:02 +0000 UTC - event for pod-623ce888-ab64-43b5-b514-3fd1f4bc2959: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-f70b7806-41e4-4fc7-ab58-bff7fae791da" 
May 11 02:03:28.101: INFO: At 2022-05-11 01:58:16 +0000 UTC - event for pod-623ce888-ab64-43b5-b514-3fd1f4bc2959: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMapVolume: MapVolume.MapPodDevice failed for volume "pvc-f70b7806-41e4-4fc7-ab58-bff7fae791da" : rpc error: code = Internal desc = Could not mount "/dev/nvme2n1" at "/var/lib/kubelet/plugins/kubernetes.io/csi/volumeDevices/publish/pvc-f70b7806-41e4-4fc7-ab58-bff7fae791da/31efade5-bfe1-483e-829b-8ae847831109": mount failed: exec: "mount": executable file not found in $PATH
Mounting command: mount
Mounting arguments:  -o bind /dev/nvme2n1 /var/lib/kubelet/plugins/kubernetes.io/csi/volumeDevices/publish/pvc-f70b7806-41e4-4fc7-ab58-bff7fae791da/31efade5-bfe1-483e-829b-8ae847831109
Output: 
May 11 02:03:28.101: INFO: At 2022-05-11 02:00:04 +0000 UTC - event for pod-623ce888-ab64-43b5-b514-3fd1f4bc2959: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[volume1], unattached volumes=[default-token-mb5cx volume1]: timed out waiting for the condition
May 11 02:03:28.164: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
May 11 02:03:28.164: INFO: 
... skipping 106 lines ...
  [Testpattern: Dynamic PV (block volmode)(allowExpansion)] volume-expand
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    Verify if offline PVC expansion works [It]
    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/volume_expand.go:174

    While creating pods for resizing
    Unexpected error:
        <*errors.errorString | 0xc000eea460>: {
            s: "pod \"pod-623ce888-ab64-43b5-b514-3fd1f4bc2959\" is not Running: timed out waiting for the condition",
        }
        pod "pod-623ce888-ab64-43b5-b514-3fd1f4bc2959" is not Running: timed out waiting for the condition
    occurred

... skipping 201 lines ...

    Driver ebs.csi.aws.com doesn't support ntfs -- skipping

    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:121
------------------------------
External Storage [Driver: ebs.csi.aws.com] [Testpattern: Dynamic PV (default fs)] subPath 
  should fail if subpath directory is outside the volume [Slow][LinuxOnly]
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:240

[BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/framework/framework.go:185
STEP: Creating a kubernetes client
May 11 01:58:04.887: INFO: >>> kubeConfig: /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/hack/e2e/csi-test-artifacts/test-cluster-28361.k8s.local.kops.kubeconfig
STEP: Building a namespace api object, basename provisioning
STEP: Waiting for a default service account to be provisioned in namespace
[It] should fail if subpath directory is outside the volume [Slow][LinuxOnly]
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:240
May 11 01:58:05.213: INFO: Creating resource for dynamic PV
May 11 01:58:05.213: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(ebs.csi.aws.com) supported size:{ 1Mi} 
STEP: creating a StorageClass provisioning-9028-e2e-sc7sfw4
STEP: creating a claim
May 11 01:58:05.280: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
STEP: Creating pod pod-subpath-test-dynamicpv-xhlt
STEP: Checking for subpath error in container status
May 11 02:03:05.680: INFO: Deleting pod "pod-subpath-test-dynamicpv-xhlt" in namespace "provisioning-9028"
May 11 02:03:05.749: INFO: Wait up to 5m0s for pod "pod-subpath-test-dynamicpv-xhlt" to be fully deleted
STEP: Deleting pod
May 11 02:03:15.883: INFO: Deleting pod "pod-subpath-test-dynamicpv-xhlt" in namespace "provisioning-9028"
STEP: Deleting pvc
May 11 02:03:16.077: INFO: Deleting PersistentVolumeClaim "ebs.csi.aws.commpt5v"
... skipping 10 lines ...
May 11 02:03:31.548: INFO: At 2022-05-11 01:58:05 +0000 UTC - event for ebs.csi.aws.commpt5v: {persistentvolume-controller } WaitForFirstConsumer: waiting for first consumer to be created before binding
May 11 02:03:31.548: INFO: At 2022-05-11 01:58:05 +0000 UTC - event for ebs.csi.aws.commpt5v: {persistentvolume-controller } ExternalProvisioning: waiting for a volume to be created, either by external provisioner "ebs.csi.aws.com" or manually created by system administrator
May 11 02:03:31.548: INFO: At 2022-05-11 01:58:05 +0000 UTC - event for ebs.csi.aws.commpt5v: {ebs.csi.aws.com_ebs-csi-controller-65f7fb9696-j8nqp_23e52550-a198-4e6b-86aa-7a440fbfd693 } Provisioning: External provisioner is provisioning volume for claim "provisioning-9028/ebs.csi.aws.commpt5v"
May 11 02:03:31.548: INFO: At 2022-05-11 01:58:08 +0000 UTC - event for ebs.csi.aws.commpt5v: {ebs.csi.aws.com_ebs-csi-controller-65f7fb9696-j8nqp_23e52550-a198-4e6b-86aa-7a440fbfd693 } ProvisioningSucceeded: Successfully provisioned volume pvc-6be19183-e347-49e6-8bab-3687baa2ecd4
May 11 02:03:31.548: INFO: At 2022-05-11 01:58:09 +0000 UTC - event for pod-subpath-test-dynamicpv-xhlt: {default-scheduler } Scheduled: Successfully assigned provisioning-9028/pod-subpath-test-dynamicpv-xhlt to ip-172-20-61-6.us-west-2.compute.internal
May 11 02:03:31.548: INFO: At 2022-05-11 01:58:11 +0000 UTC - event for pod-subpath-test-dynamicpv-xhlt: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-6be19183-e347-49e6-8bab-3687baa2ecd4" 
May 11 02:03:31.548: INFO: At 2022-05-11 01:58:13 +0000 UTC - event for pod-subpath-test-dynamicpv-xhlt: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: MountVolume.MountDevice failed for volume "pvc-6be19183-e347-49e6-8bab-3687baa2ecd4" : rpc error: code = Internal desc = could not format "/dev/nvme3n1" and mount it at "/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-6be19183-e347-49e6-8bab-3687baa2ecd4/globalmount": format of disk "/dev/nvme3n1" failed: type:("ext4") target:("/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-6be19183-e347-49e6-8bab-3687baa2ecd4/globalmount") options:("defaults") errcode:(exit status 127) output:(mkfs.ext4: symbol lookup error: /lib/x86_64-linux-gnu/libpthread.so.0: undefined symbol: __libc_vfork, version GLIBC_PRIVATE
) 
May 11 02:03:31.548: INFO: At 2022-05-11 02:00:12 +0000 UTC - event for pod-subpath-test-dynamicpv-xhlt: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[test-volume], unattached volumes=[test-volume liveness-probe-volume default-token-wrmxx]: timed out waiting for the condition
May 11 02:03:31.612: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
May 11 02:03:31.612: INFO: 
May 11 02:03:31.677: INFO: 
Logging node info for node ip-172-20-126-84.us-west-2.compute.internal
... skipping 100 lines ...

• Failure [328.839 seconds]
External Storage [Driver: ebs.csi.aws.com]
/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:175
  [Testpattern: Dynamic PV (default fs)] subPath
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50
    should fail if subpath directory is outside the volume [Slow][LinuxOnly] [It]
    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:240

    while waiting for subpath failure
    Unexpected error:
        <*errors.errorString | 0xc000f945d0>: {
            s: "error waiting for pod subpath error to occur: timed out waiting for the condition",
        }
        error waiting for pod subpath error to occur: timed out waiting for the condition
    occurred

    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:718
------------------------------
[BeforeEach] [Testpattern: Generic Ephemeral-volume (default fs) (immediate-binding)] ephemeral
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:51
... skipping 102 lines ...
May 11 01:52:04.178: INFO: Creating resource for dynamic PV
May 11 01:52:04.178: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(ebs.csi.aws.com) supported size:{ 1Mi} 
STEP: creating a StorageClass snapshotting-9621-e2e-sc6bvn6
STEP: creating a claim
May 11 01:52:04.241: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
STEP: [init] starting a pod to use the claim
May 11 01:52:04.436: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-kc6sf" in namespace "snapshotting-9621" to be "Succeeded or Failed"
May 11 01:52:04.498: INFO: Pod "pvc-snapshottable-tester-kc6sf": Phase="Pending", Reason="", readiness=false. Elapsed: 62.099058ms
May 11 01:52:06.561: INFO: Pod "pvc-snapshottable-tester-kc6sf": Phase="Pending", Reason="", readiness=false. Elapsed: 2.125239509s
May 11 01:52:08.624: INFO: Pod "pvc-snapshottable-tester-kc6sf": Phase="Pending", Reason="", readiness=false. Elapsed: 4.188708252s
May 11 01:52:10.690: INFO: Pod "pvc-snapshottable-tester-kc6sf": Phase="Pending", Reason="", readiness=false. Elapsed: 6.254019767s
May 11 01:52:12.763: INFO: Pod "pvc-snapshottable-tester-kc6sf": Phase="Pending", Reason="", readiness=false. Elapsed: 8.327690156s
May 11 01:52:14.830: INFO: Pod "pvc-snapshottable-tester-kc6sf": Phase="Pending", Reason="", readiness=false. Elapsed: 10.393937375s
... skipping 424 lines ...
May 11 02:06:52.721: INFO: Pod "pvc-snapshottable-tester-kc6sf": Phase="Pending", Reason="", readiness=false. Elapsed: 14m48.285469978s
May 11 02:06:54.788: INFO: Pod "pvc-snapshottable-tester-kc6sf": Phase="Pending", Reason="", readiness=false. Elapsed: 14m50.351813857s
May 11 02:06:56.853: INFO: Pod "pvc-snapshottable-tester-kc6sf": Phase="Pending", Reason="", readiness=false. Elapsed: 14m52.417016517s
May 11 02:06:58.918: INFO: Pod "pvc-snapshottable-tester-kc6sf": Phase="Pending", Reason="", readiness=false. Elapsed: 14m54.482230182s
May 11 02:07:00.984: INFO: Pod "pvc-snapshottable-tester-kc6sf": Phase="Pending", Reason="", readiness=false. Elapsed: 14m56.548133092s
May 11 02:07:03.050: INFO: Pod "pvc-snapshottable-tester-kc6sf": Phase="Pending", Reason="", readiness=false. Elapsed: 14m58.614196794s
May 11 02:07:05.122: INFO: Error getting logs for pod pvc-snapshottable-tester-kc6sf: the server rejected our request for an unknown reason (get pods pvc-snapshottable-tester-kc6sf)
May 11 02:07:05.122: INFO: Deleting pod "pvc-snapshottable-tester-kc6sf" in namespace "snapshotting-9621"
May 11 02:07:05.190: INFO: Wait up to 5m0s for pod "pvc-snapshottable-tester-kc6sf" to be fully deleted
[AfterEach] volume snapshot controller
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/snapshottable.go:223
STEP: Deleting pvc
May 11 02:07:17.453: INFO: Deleting PersistentVolumeClaim "ebs.csi.aws.comr2952"
... skipping 10 lines ...
May 11 02:07:32.920: INFO: At 2022-05-11 01:52:04 +0000 UTC - event for ebs.csi.aws.comr2952: {persistentvolume-controller } WaitForFirstConsumer: waiting for first consumer to be created before binding
May 11 02:07:32.920: INFO: At 2022-05-11 01:52:04 +0000 UTC - event for ebs.csi.aws.comr2952: {persistentvolume-controller } ExternalProvisioning: waiting for a volume to be created, either by external provisioner "ebs.csi.aws.com" or manually created by system administrator
May 11 02:07:32.920: INFO: At 2022-05-11 01:52:04 +0000 UTC - event for ebs.csi.aws.comr2952: {ebs.csi.aws.com_ebs-csi-controller-65f7fb9696-j8nqp_23e52550-a198-4e6b-86aa-7a440fbfd693 } Provisioning: External provisioner is provisioning volume for claim "snapshotting-9621/ebs.csi.aws.comr2952"
May 11 02:07:32.920: INFO: At 2022-05-11 01:52:07 +0000 UTC - event for ebs.csi.aws.comr2952: {ebs.csi.aws.com_ebs-csi-controller-65f7fb9696-j8nqp_23e52550-a198-4e6b-86aa-7a440fbfd693 } ProvisioningSucceeded: Successfully provisioned volume pvc-58e2e415-b874-419f-a7a8-7f1bc3852330
May 11 02:07:32.920: INFO: At 2022-05-11 01:52:08 +0000 UTC - event for pvc-snapshottable-tester-kc6sf: {default-scheduler } Scheduled: Successfully assigned snapshotting-9621/pvc-snapshottable-tester-kc6sf to ip-172-20-61-6.us-west-2.compute.internal
May 11 02:07:32.920: INFO: At 2022-05-11 01:52:10 +0000 UTC - event for pvc-snapshottable-tester-kc6sf: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-58e2e415-b874-419f-a7a8-7f1bc3852330" 
May 11 02:07:32.920: INFO: At 2022-05-11 01:52:24 +0000 UTC - event for pvc-snapshottable-tester-kc6sf: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: MountVolume.MountDevice failed for volume "pvc-58e2e415-b874-419f-a7a8-7f1bc3852330" : rpc error: code = Internal desc = could not format "/dev/nvme6n1" and mount it at "/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-58e2e415-b874-419f-a7a8-7f1bc3852330/globalmount": format of disk "/dev/nvme6n1" failed: type:("ext4") target:("/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-58e2e415-b874-419f-a7a8-7f1bc3852330/globalmount") options:("defaults") errcode:(exit status 127) output:(mkfs.ext4: symbol lookup error: /lib/x86_64-linux-gnu/libpthread.so.0: undefined symbol: __libc_vfork, version GLIBC_PRIVATE
) 
May 11 02:07:32.920: INFO: At 2022-05-11 01:54:11 +0000 UTC - event for pvc-snapshottable-tester-kc6sf: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[my-volume], unattached volumes=[my-volume default-token-5cxjf]: timed out waiting for the condition
May 11 02:07:32.920: INFO: At 2022-05-11 01:56:25 +0000 UTC - event for pvc-snapshottable-tester-kc6sf: {kubelet ip-172-20-61-6.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[my-volume], unattached volumes=[default-token-5cxjf my-volume]: timed out waiting for the condition
May 11 02:07:32.987: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
May 11 02:07:32.988: INFO: 
May 11 02:07:33.055: INFO: 
... skipping 113 lines ...
    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/snapshottable.go:108
       [BeforeEach]
      /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/snapshottable.go:227
        should check snapshot fields, check restore correctly works after modifying source data, check deletion
        /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/snapshottable.go:245

        Unexpected error:
            <*errors.errorString | 0xc000806ef0>: {
                s: "Gave up after waiting 15m0s for pod \"pvc-snapshottable-tester-kc6sf\" to be \"Succeeded or Failed\"",
            }
            Gave up after waiting 15m0s for pod "pvc-snapshottable-tester-kc6sf" to be "Succeeded or Failed"
        occurred

        /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/provisioning.go:675
------------------------------
S
------------------------------
... skipping 81 lines ...