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-10 23:12
Elapsed59m8s
Revision72a890e0d0ad131d4b02e5131172b6a77132f4bc
Refs 1233

No Test Failures!


Error lines from build-log.txt

... skipping 593 lines ...
## Validating cluster test-cluster-3162.k8s.local
#
Using cluster from kubectl context: test-cluster-3162.k8s.local

Validating cluster test-cluster-3162.k8s.local

W0510 23:14:58.508634    9402 validate_cluster.go:173] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-3162-k8s-hbmpaj-333983473.us-west-2.elb.amazonaws.com/api/v1/nodes": dial tcp: lookup api-test-cluster-3162-k8s-hbmpaj-333983473.us-west-2.elb.amazonaws.com on 10.63.240.10:53: no such host
W0510 23:15:08.543395    9402 validate_cluster.go:173] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-3162-k8s-hbmpaj-333983473.us-west-2.elb.amazonaws.com/api/v1/nodes": dial tcp: lookup api-test-cluster-3162-k8s-hbmpaj-333983473.us-west-2.elb.amazonaws.com on 10.63.240.10:53: no such host
W0510 23:15:18.579066    9402 validate_cluster.go:173] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-3162-k8s-hbmpaj-333983473.us-west-2.elb.amazonaws.com/api/v1/nodes": dial tcp: lookup api-test-cluster-3162-k8s-hbmpaj-333983473.us-west-2.elb.amazonaws.com on 10.63.240.10:53: no such host
W0510 23:15:28.619802    9402 validate_cluster.go:173] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-3162-k8s-hbmpaj-333983473.us-west-2.elb.amazonaws.com/api/v1/nodes": dial tcp: lookup api-test-cluster-3162-k8s-hbmpaj-333983473.us-west-2.elb.amazonaws.com on 10.63.240.10:53: no such host
W0510 23:15:38.642664    9402 validate_cluster.go:173] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-3162-k8s-hbmpaj-333983473.us-west-2.elb.amazonaws.com/api/v1/nodes": dial tcp: lookup api-test-cluster-3162-k8s-hbmpaj-333983473.us-west-2.elb.amazonaws.com on 10.63.240.10:53: no such host
W0510 23:15:48.687038    9402 validate_cluster.go:173] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-3162-k8s-hbmpaj-333983473.us-west-2.elb.amazonaws.com/api/v1/nodes": dial tcp: lookup api-test-cluster-3162-k8s-hbmpaj-333983473.us-west-2.elb.amazonaws.com on 10.63.240.10:53: no such host
W0510 23:15:58.721531    9402 validate_cluster.go:173] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-3162-k8s-hbmpaj-333983473.us-west-2.elb.amazonaws.com/api/v1/nodes": dial tcp: lookup api-test-cluster-3162-k8s-hbmpaj-333983473.us-west-2.elb.amazonaws.com on 10.63.240.10:53: no such host
W0510 23:16:08.756483    9402 validate_cluster.go:173] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-3162-k8s-hbmpaj-333983473.us-west-2.elb.amazonaws.com/api/v1/nodes": dial tcp: lookup api-test-cluster-3162-k8s-hbmpaj-333983473.us-west-2.elb.amazonaws.com on 10.63.240.10:53: no such host
W0510 23:16:23.383718    9402 validate_cluster.go:173] (will retry): unexpected error during validation: error listing nodes: Get "https://api-test-cluster-3162-k8s-hbmpaj-333983473.us-west-2.elb.amazonaws.com/api/v1/nodes": dial tcp: lookup api-test-cluster-3162-k8s-hbmpaj-333983473.us-west-2.elb.amazonaws.com on 10.63.240.10:53: no such host
W0510 23:16:45.034324    9402 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)
W0510 23:17:06.596940    9402 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)
W0510 23:17:28.140213    9402 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-085ab4d81bd3331c2				machine "i-085ab4d81bd3331c2" has not yet joined cluster
Machine	i-0918f31c8d7ba5106				machine "i-0918f31c8d7ba5106" has not yet joined cluster
Machine	i-0f19a99d6f747fe4d				machine "i-0f19a99d6f747fe4d" has not yet joined cluster
Node	ip-172-20-58-59.us-west-2.compute.internal	node "ip-172-20-58-59.us-west-2.compute.internal" of role "master" is not ready

Validation Failed
W0510 23:17:42.141311    9402 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 11 lines ...
Node	ip-172-20-58-59.us-west-2.compute.internal	master "ip-172-20-58-59.us-west-2.compute.internal" is missing kube-apiserver pod
Node	ip-172-20-58-59.us-west-2.compute.internal	master "ip-172-20-58-59.us-west-2.compute.internal" is missing kube-controller-manager pod
Node	ip-172-20-58-59.us-west-2.compute.internal	master "ip-172-20-58-59.us-west-2.compute.internal" is missing kube-scheduler pod
Pod	kube-system/coredns-8f5559c9b-rb984		system-cluster-critical pod "coredns-8f5559c9b-rb984" is pending
Pod	kube-system/coredns-autoscaler-6f594f4c58-g4k66	system-cluster-critical pod "coredns-autoscaler-6f594f4c58-g4k66" is pending

Validation Failed
W0510 23:17:54.471471    9402 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 11 lines ...
Node	ip-172-20-58-59.us-west-2.compute.internal	master "ip-172-20-58-59.us-west-2.compute.internal" is missing kube-apiserver pod
Node	ip-172-20-58-59.us-west-2.compute.internal	master "ip-172-20-58-59.us-west-2.compute.internal" is missing kube-controller-manager pod
Node	ip-172-20-58-59.us-west-2.compute.internal	master "ip-172-20-58-59.us-west-2.compute.internal" is missing kube-scheduler pod
Pod	kube-system/coredns-8f5559c9b-rb984		system-cluster-critical pod "coredns-8f5559c9b-rb984" is pending
Pod	kube-system/coredns-autoscaler-6f594f4c58-g4k66	system-cluster-critical pod "coredns-autoscaler-6f594f4c58-g4k66" is pending

Validation Failed
W0510 23:18:06.607064    9402 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 12 lines ...
Node	ip-172-20-58-59.us-west-2.compute.internal				master "ip-172-20-58-59.us-west-2.compute.internal" is missing kube-controller-manager pod
Node	ip-172-20-58-59.us-west-2.compute.internal				master "ip-172-20-58-59.us-west-2.compute.internal" is missing kube-scheduler pod
Pod	kube-system/coredns-8f5559c9b-rb984					system-cluster-critical pod "coredns-8f5559c9b-rb984" is pending
Pod	kube-system/coredns-autoscaler-6f594f4c58-g4k66				system-cluster-critical pod "coredns-autoscaler-6f594f4c58-g4k66" is pending
Pod	kube-system/kube-scheduler-ip-172-20-58-59.us-west-2.compute.internal	system-cluster-critical pod "kube-scheduler-ip-172-20-58-59.us-west-2.compute.internal" is pending

Validation Failed
W0510 23:18:18.601551    9402 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 9 lines ...
Machine	i-0918f31c8d7ba5106				machine "i-0918f31c8d7ba5106" has not yet joined cluster
Machine	i-0f19a99d6f747fe4d				machine "i-0f19a99d6f747fe4d" has not yet joined cluster
Node	ip-172-20-58-59.us-west-2.compute.internal	master "ip-172-20-58-59.us-west-2.compute.internal" is missing kube-apiserver pod
Pod	kube-system/coredns-8f5559c9b-rb984		system-cluster-critical pod "coredns-8f5559c9b-rb984" is pending
Pod	kube-system/coredns-autoscaler-6f594f4c58-g4k66	system-cluster-critical pod "coredns-autoscaler-6f594f4c58-g4k66" is pending

Validation Failed
W0510 23:18:30.747223    9402 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-0f19a99d6f747fe4d							machine "i-0f19a99d6f747fe4d" has not yet joined cluster
Node	ip-172-20-58-59.us-west-2.compute.internal				master "ip-172-20-58-59.us-west-2.compute.internal" is missing kube-apiserver pod
Pod	kube-system/coredns-8f5559c9b-rb984					system-cluster-critical pod "coredns-8f5559c9b-rb984" is pending
Pod	kube-system/coredns-autoscaler-6f594f4c58-g4k66				system-cluster-critical pod "coredns-autoscaler-6f594f4c58-g4k66" is pending
Pod	kube-system/kube-apiserver-ip-172-20-58-59.us-west-2.compute.internal	system-cluster-critical pod "kube-apiserver-ip-172-20-58-59.us-west-2.compute.internal" is pending

Validation Failed
W0510 23:18:42.838376    9402 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 11 lines ...
Node	ip-172-20-56-40.us-west-2.compute.internal	node "ip-172-20-56-40.us-west-2.compute.internal" of role "node" is not ready
Node	ip-172-20-87-221.us-west-2.compute.internal	node "ip-172-20-87-221.us-west-2.compute.internal" of role "node" is not ready
Node	ip-172-20-97-249.us-west-2.compute.internal	node "ip-172-20-97-249.us-west-2.compute.internal" of role "node" is not ready
Pod	kube-system/coredns-8f5559c9b-rb984		system-cluster-critical pod "coredns-8f5559c9b-rb984" is pending
Pod	kube-system/coredns-autoscaler-6f594f4c58-g4k66	system-cluster-critical pod "coredns-autoscaler-6f594f4c58-g4k66" is pending

Validation Failed
W0510 23:18:55.344373    9402 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 11 lines ...
Node	ip-172-20-56-40.us-west-2.compute.internal	node "ip-172-20-56-40.us-west-2.compute.internal" of role "node" is not ready
Node	ip-172-20-87-221.us-west-2.compute.internal	node "ip-172-20-87-221.us-west-2.compute.internal" of role "node" is not ready
Node	ip-172-20-97-249.us-west-2.compute.internal	node "ip-172-20-97-249.us-west-2.compute.internal" of role "node" is not ready
Pod	kube-system/coredns-8f5559c9b-rb984		system-cluster-critical pod "coredns-8f5559c9b-rb984" is pending
Pod	kube-system/coredns-autoscaler-6f594f4c58-g4k66	system-cluster-critical pod "coredns-autoscaler-6f594f4c58-g4k66" is pending

Validation Failed
W0510 23:19:07.423865    9402 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
Pod	kube-system/coredns-8f5559c9b-rb984		system-cluster-critical pod "coredns-8f5559c9b-rb984" is pending
Pod	kube-system/coredns-autoscaler-6f594f4c58-g4k66	system-cluster-critical pod "coredns-autoscaler-6f594f4c58-g4k66" is pending

Validation Failed
W0510 23:19:19.448072    9402 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 9 lines ...
VALIDATION ERRORS
KIND	NAME									MESSAGE
Pod	kube-system/coredns-8f5559c9b-jjlkz					system-cluster-critical pod "coredns-8f5559c9b-jjlkz" is not ready (coredns)
Pod	kube-system/coredns-8f5559c9b-rb984					system-cluster-critical pod "coredns-8f5559c9b-rb984" is not ready (coredns)
Pod	kube-system/kube-proxy-ip-172-20-97-249.us-west-2.compute.internal	system-node-critical pod "kube-proxy-ip-172-20-97-249.us-west-2.compute.internal" is pending

Validation Failed
W0510 23:19:31.565651    9402 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 145 lines ...

S [SKIPPING] in Spec Setup (BeforeEach) [0.003 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 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 "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 10 23:27:00.104: INFO: At 2022-05-10 23:21:33 +0000 UTC - event for ebs.csi.aws.comzd6zl: {persistentvolume-controller } WaitForFirstConsumer: waiting for first consumer to be created before binding
May 10 23:27:00.104: INFO: At 2022-05-10 23:21:34 +0000 UTC - event for ebs.csi.aws.comzd6zl: {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 10 23:27:00.104: INFO: At 2022-05-10 23:21:34 +0000 UTC - event for ebs.csi.aws.comzd6zl: {ebs.csi.aws.com_ebs-csi-controller-d99f59ddb-sgbd9_2a3f19cf-28ce-4bc0-94d5-57006d216d51 } Provisioning: External provisioner is provisioning volume for claim "multivolume-6416/ebs.csi.aws.comzd6zl"
May 10 23:27:00.104: INFO: At 2022-05-10 23:21:40 +0000 UTC - event for ebs.csi.aws.comzd6zl: {ebs.csi.aws.com_ebs-csi-controller-d99f59ddb-sgbd9_2a3f19cf-28ce-4bc0-94d5-57006d216d51 } ProvisioningSucceeded: Successfully provisioned volume pvc-c3168fdb-3cb4-4bfb-b73f-f10731cd144e
May 10 23:27:00.104: INFO: At 2022-05-10 23:21:41 +0000 UTC - event for pod-9f41fce9-7891-4bbc-a86b-16a83e102662: {default-scheduler } Scheduled: Successfully assigned multivolume-6416/pod-9f41fce9-7891-4bbc-a86b-16a83e102662 to ip-172-20-97-249.us-west-2.compute.internal
May 10 23:27:00.104: INFO: At 2022-05-10 23:21:47 +0000 UTC - event for pod-9f41fce9-7891-4bbc-a86b-16a83e102662: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-c3168fdb-3cb4-4bfb-b73f-f10731cd144e" 
May 10 23:27:00.105: INFO: At 2022-05-10 23:21:58 +0000 UTC - event for pod-9f41fce9-7891-4bbc-a86b-16a83e102662: {kubelet ip-172-20-97-249.us-west-2.compute.internal} FailedMount: MountVolume.MountDevice failed for volume "pvc-c3168fdb-3cb4-4bfb-b73f-f10731cd144e" : rpc error: code = Internal desc = could not format "/dev/nvme2n1" and mount it at "/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-c3168fdb-3cb4-4bfb-b73f-f10731cd144e/globalmount": failed to get disk format of disk /dev/nvme2n1: exit status 127
May 10 23:27:00.105: INFO: At 2022-05-10 23:23:44 +0000 UTC - event for pod-9f41fce9-7891-4bbc-a86b-16a83e102662: {kubelet ip-172-20-97-249.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[volume1], unattached volumes=[default-token-jhzf9 volume1]: timed out waiting for the condition
May 10 23:27:00.105: INFO: At 2022-05-10 23:25:58 +0000 UTC - event for pod-9f41fce9-7891-4bbc-a86b-16a83e102662: {kubelet ip-172-20-97-249.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[volume1], unattached volumes=[volume1 default-token-jhzf9]: timed out waiting for the condition
May 10 23:27:00.169: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
May 10 23:27:00.169: INFO: 
May 10 23:27:00.385: INFO: 
Logging node info for node ip-172-20-56-40.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 (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 | 0xc000b58ca0>: {
            s: "pod \"pod-9f41fce9-7891-4bbc-a86b-16a83e102662\" is not Running: timed out waiting for the condition",
        }
        pod "pod-9f41fce9-7891-4bbc-a86b-16a83e102662" is not Running: timed out waiting for the condition
    occurred

... skipping 44 lines ...
May 10 23:27:20.459: INFO: At 2022-05-10 23:21:33 +0000 UTC - event for ebs.csi.aws.comgsj7m: {persistentvolume-controller } WaitForFirstConsumer: waiting for first consumer to be created before binding
May 10 23:27:20.459: INFO: At 2022-05-10 23:21:34 +0000 UTC - event for ebs.csi.aws.comgsj7m: {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 10 23:27:20.459: INFO: At 2022-05-10 23:21:34 +0000 UTC - event for ebs.csi.aws.comgsj7m: {ebs.csi.aws.com_ebs-csi-controller-d99f59ddb-sgbd9_2a3f19cf-28ce-4bc0-94d5-57006d216d51 } Provisioning: External provisioner is provisioning volume for claim "volume-expand-6652/ebs.csi.aws.comgsj7m"
May 10 23:27:20.459: INFO: At 2022-05-10 23:21:40 +0000 UTC - event for ebs.csi.aws.comgsj7m: {ebs.csi.aws.com_ebs-csi-controller-d99f59ddb-sgbd9_2a3f19cf-28ce-4bc0-94d5-57006d216d51 } ProvisioningSucceeded: Successfully provisioned volume pvc-6300a061-0edd-4f5e-a0ed-ed0e9c9c05aa
May 10 23:27:20.459: INFO: At 2022-05-10 23:21:41 +0000 UTC - event for pod-341a6153-bc81-47a1-9438-6ac13525e139: {default-scheduler } Scheduled: Successfully assigned volume-expand-6652/pod-341a6153-bc81-47a1-9438-6ac13525e139 to ip-172-20-97-249.us-west-2.compute.internal
May 10 23:27:20.459: INFO: At 2022-05-10 23:21:46 +0000 UTC - event for pod-341a6153-bc81-47a1-9438-6ac13525e139: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-6300a061-0edd-4f5e-a0ed-ed0e9c9c05aa" 
May 10 23:27:20.459: INFO: At 2022-05-10 23:21:58 +0000 UTC - event for pod-341a6153-bc81-47a1-9438-6ac13525e139: {kubelet ip-172-20-97-249.us-west-2.compute.internal} FailedMapVolume: MapVolume.MapPodDevice failed for volume "pvc-6300a061-0edd-4f5e-a0ed-ed0e9c9c05aa" : rpc error: code = Internal desc = Could not mount "/dev/nvme1n1" at "/var/lib/kubelet/plugins/kubernetes.io/csi/volumeDevices/publish/pvc-6300a061-0edd-4f5e-a0ed-ed0e9c9c05aa/f7a2edd6-4454-4c0a-bc13-cc892fa7dde2": mount failed: exec: "mount": executable file not found in $PATH
Mounting command: mount
Mounting arguments:  -o bind /dev/nvme1n1 /var/lib/kubelet/plugins/kubernetes.io/csi/volumeDevices/publish/pvc-6300a061-0edd-4f5e-a0ed-ed0e9c9c05aa/f7a2edd6-4454-4c0a-bc13-cc892fa7dde2
Output: 
May 10 23:27:20.459: INFO: At 2022-05-10 23:23:44 +0000 UTC - event for pod-341a6153-bc81-47a1-9438-6ac13525e139: {kubelet ip-172-20-97-249.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[volume1], unattached volumes=[volume1 default-token-548zx]: timed out waiting for the condition
May 10 23:27:20.459: INFO: At 2022-05-10 23:26:01 +0000 UTC - event for pod-341a6153-bc81-47a1-9438-6ac13525e139: {kubelet ip-172-20-97-249.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[volume1], unattached volumes=[default-token-548zx volume1]: timed out waiting for the condition
May 10 23:27:20.523: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
... skipping 109 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 | 0xc000bc6120>: {
            s: "pod \"pod-341a6153-bc81-47a1-9438-6ac13525e139\" is not Running: timed out waiting for the condition",
        }
        pod "pod-341a6153-bc81-47a1-9438-6ac13525e139" is not Running: timed out waiting for the condition
    occurred

... skipping 51 lines ...

    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/ephemeral.go:108
------------------------------
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 10 23:27:23.359: INFO: >>> kubeConfig: /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/hack/e2e/csi-test-artifacts/test-cluster-3162.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 10 23:27:23.750: INFO: found topology map[topology.ebs.csi.aws.com/zone:us-west-2a]
May 10 23:27:23.751: INFO: found topology map[topology.ebs.csi.aws.com/zone:us-west-2b]
May 10 23:27:23.751: INFO: Creating storage class object and pvc object for driver - sc: &StorageClass{ObjectMeta:{topology-7845-e2e-sc5q6th      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-7845    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-7845-e2e-sc5q6th,VolumeMode:nil,DataSource:nil,},Status:PersistentVolumeClaimStatus{Phase:,AccessModes:[],Capacity:ResourceList{},Conditions:[]PersistentVolumeClaimCondition{},},}
STEP: Creating sc
STEP: Creating pvc
... skipping 89 lines ...
May 10 23:27:25.998: INFO: At 2022-05-10 23:21:34 +0000 UTC - event for ebs.csi.aws.comr6t2d: {ebs.csi.aws.com_ebs-csi-controller-d99f59ddb-sgbd9_2a3f19cf-28ce-4bc0-94d5-57006d216d51 } Provisioning: External provisioner is provisioning volume for claim "multivolume-3793/ebs.csi.aws.comr6t2d"
May 10 23:27:25.998: INFO: At 2022-05-10 23:21:40 +0000 UTC - event for ebs.csi.aws.com5pvtk: {ebs.csi.aws.com_ebs-csi-controller-d99f59ddb-sgbd9_2a3f19cf-28ce-4bc0-94d5-57006d216d51 } ProvisioningSucceeded: Successfully provisioned volume pvc-a8686c78-7b6b-4208-9029-ef82eafe2c63
May 10 23:27:25.998: INFO: At 2022-05-10 23:21:40 +0000 UTC - event for ebs.csi.aws.comr6t2d: {ebs.csi.aws.com_ebs-csi-controller-d99f59ddb-sgbd9_2a3f19cf-28ce-4bc0-94d5-57006d216d51 } ProvisioningSucceeded: Successfully provisioned volume pvc-6b714691-c0cd-4e61-988e-3b013b8c1f81
May 10 23:27:25.998: INFO: At 2022-05-10 23:21:41 +0000 UTC - event for pod-2a9aac1f-d48a-4edf-aeb0-9777e8f8a5e7: {default-scheduler } Scheduled: Successfully assigned multivolume-3793/pod-2a9aac1f-d48a-4edf-aeb0-9777e8f8a5e7 to ip-172-20-97-249.us-west-2.compute.internal
May 10 23:27:25.998: INFO: At 2022-05-10 23:21:48 +0000 UTC - event for pod-2a9aac1f-d48a-4edf-aeb0-9777e8f8a5e7: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-a8686c78-7b6b-4208-9029-ef82eafe2c63" 
May 10 23:27:25.998: INFO: At 2022-05-10 23:21:48 +0000 UTC - event for pod-2a9aac1f-d48a-4edf-aeb0-9777e8f8a5e7: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-6b714691-c0cd-4e61-988e-3b013b8c1f81" 
May 10 23:27:25.998: INFO: At 2022-05-10 23:21:59 +0000 UTC - event for pod-2a9aac1f-d48a-4edf-aeb0-9777e8f8a5e7: {kubelet ip-172-20-97-249.us-west-2.compute.internal} FailedMount: MountVolume.MountDevice failed for volume "pvc-6b714691-c0cd-4e61-988e-3b013b8c1f81" : rpc error: code = Internal desc = could not format "/dev/nvme4n1" and mount it at "/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-6b714691-c0cd-4e61-988e-3b013b8c1f81/globalmount": failed to get disk format of disk /dev/nvme4n1: exit status 127
May 10 23:27:25.998: INFO: At 2022-05-10 23:21:59 +0000 UTC - event for pod-2a9aac1f-d48a-4edf-aeb0-9777e8f8a5e7: {kubelet ip-172-20-97-249.us-west-2.compute.internal} FailedMount: MountVolume.MountDevice failed for volume "pvc-a8686c78-7b6b-4208-9029-ef82eafe2c63" : rpc error: code = Internal desc = could not format "/dev/nvme5n1" and mount it at "/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-a8686c78-7b6b-4208-9029-ef82eafe2c63/globalmount": failed to get disk format of disk /dev/nvme5n1: exit status 127
May 10 23:27:25.998: INFO: At 2022-05-10 23:23:44 +0000 UTC - event for pod-2a9aac1f-d48a-4edf-aeb0-9777e8f8a5e7: {kubelet ip-172-20-97-249.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[volume1 volume2], unattached volumes=[volume1 volume2 default-token-h96vs]: timed out waiting for the condition
May 10 23:27:26.064: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
May 10 23:27:26.064: INFO: 
May 10 23:27:26.192: INFO: 
Logging node info for node ip-172-20-56-40.us-west-2.compute.internal
May 10 23:27:26.259: INFO: Node Info: &Node{ObjectMeta:{ip-172-20-56-40.us-west-2.compute.internal    81efae28-5da4-4c6e-bded-c2e063ef39a9 2185 0 2022-05-10 23:18:49 +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-2a kops.k8s.io/instancegroup:nodes-us-west-2a kubernetes.io/arch:amd64 kubernetes.io/hostname:ip-172-20-56-40.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-2a topology.kubernetes.io/region:us-west-2 topology.kubernetes.io/zone:us-west-2a] map[csi.volume.kubernetes.io/nodeid:{"ebs.csi.aws.com":"i-0f19a99d6f747fe4d"} node.alpha.kubernetes.io/ttl:0 volumes.kubernetes.io/controller-managed-attach-detach:true] [] []  [{kops-controller Update v1 2022-05-10 23:18:49 +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-10 23:18:53 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:node.alpha.kubernetes.io/ttl":{}}},"f:spec":{"f:podCIDR":{},"f:podCIDRs":{".":{},"v:\"100.96.2.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-10 23:19:58 +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.2.0/24,DoNotUseExternalID:,ProviderID:aws:///us-west-2a/i-0f19a99d6f747fe4d,Unschedulable:false,Taints:[]Taint{},ConfigSource:nil,PodCIDRs:[100.96.2.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: {{3864977408 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: {{3760119808 0} {<nil>}  BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Phase:,Conditions:[]NodeCondition{NodeCondition{Type:NetworkUnavailable,Status:False,LastHeartbeatTime:2022-05-10 23:18:53 +0000 UTC,LastTransitionTime:2022-05-10 23:18:53 +0000 UTC,Reason:RouteCreated,Message:RouteController created a route,},NodeCondition{Type:MemoryPressure,Status:False,LastHeartbeatTime:2022-05-10 23:25:39 +0000 UTC,LastTransitionTime:2022-05-10 23:18:49 +0000 UTC,Reason:KubeletHasSufficientMemory,Message:kubelet has sufficient memory available,},NodeCondition{Type:DiskPressure,Status:False,LastHeartbeatTime:2022-05-10 23:25:39 +0000 UTC,LastTransitionTime:2022-05-10 23:18:49 +0000 UTC,Reason:KubeletHasNoDiskPressure,Message:kubelet has no disk pressure,},NodeCondition{Type:PIDPressure,Status:False,LastHeartbeatTime:2022-05-10 23:25:39 +0000 UTC,LastTransitionTime:2022-05-10 23:18:49 +0000 UTC,Reason:KubeletHasSufficientPID,Message:kubelet has sufficient PID available,},NodeCondition{Type:Ready,Status:True,LastHeartbeatTime:2022-05-10 23:25:39 +0000 UTC,LastTransitionTime:2022-05-10 23:19:09 +0000 UTC,Reason:KubeletReady,Message:kubelet is posting ready status. AppArmor enabled,},},Addresses:[]NodeAddress{NodeAddress{Type:InternalIP,Address:172.20.56.40,},NodeAddress{Type:ExternalIP,Address:54.190.220.105,},NodeAddress{Type:Hostname,Address:ip-172-20-56-40.us-west-2.compute.internal,},NodeAddress{Type:InternalDNS,Address:ip-172-20-56-40.us-west-2.compute.internal,},NodeAddress{Type:ExternalDNS,Address:ec2-54-190-220-105.us-west-2.compute.amazonaws.com,},},DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:ec26677e61ae0ccaf587f5886b593471,SystemUUID:ec26677e-61ae-0cca-f587-f5886b593471,BootID:1e40e8c7-bda2-4e00-8aa5-724badfe046b,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:12229b0c94723be687fe6e42d4e9b401334f275a84072795a72e5fa54ab0f46e 607362164682.dkr.ecr.us-west-2.amazonaws.com/aws-ebs-csi-driver:3162],SizeBytes:26066741,},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 104 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 | 0xc000b132f0>: {
            s: "pod \"pod-2a9aac1f-d48a-4edf-aeb0-9777e8f8a5e7\" is not Running: timed out waiting for the condition",
        }
        pod "pod-2a9aac1f-d48a-4edf-aeb0-9777e8f8a5e7" is not Running: timed out waiting for the condition
    occurred

... skipping 93 lines ...
May 10 23:31:38.417: INFO: At 2022-05-10 23:21:33 +0000 UTC - event for ebs.csi.aws.comkmww2: {persistentvolume-controller } WaitForFirstConsumer: waiting for first consumer to be created before binding
May 10 23:31:38.417: INFO: At 2022-05-10 23:21:34 +0000 UTC - event for ebs.csi.aws.comkmww2: {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 10 23:31:38.417: INFO: At 2022-05-10 23:21:34 +0000 UTC - event for ebs.csi.aws.comkmww2: {ebs.csi.aws.com_ebs-csi-controller-d99f59ddb-sgbd9_2a3f19cf-28ce-4bc0-94d5-57006d216d51 } Provisioning: External provisioner is provisioning volume for claim "fsgroupchangepolicy-1823/ebs.csi.aws.comkmww2"
May 10 23:31:38.417: INFO: At 2022-05-10 23:21:40 +0000 UTC - event for ebs.csi.aws.comkmww2: {ebs.csi.aws.com_ebs-csi-controller-d99f59ddb-sgbd9_2a3f19cf-28ce-4bc0-94d5-57006d216d51 } ProvisioningSucceeded: Successfully provisioned volume pvc-f8d4e3f9-50a8-4350-8a45-086a56e0043a
May 10 23:31:38.417: INFO: At 2022-05-10 23:21:41 +0000 UTC - event for pod-8cbea059-8d3d-4887-9563-efa99f34d216: {default-scheduler } Scheduled: Successfully assigned fsgroupchangepolicy-1823/pod-8cbea059-8d3d-4887-9563-efa99f34d216 to ip-172-20-97-249.us-west-2.compute.internal
May 10 23:31:38.417: INFO: At 2022-05-10 23:21:47 +0000 UTC - event for pod-8cbea059-8d3d-4887-9563-efa99f34d216: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-f8d4e3f9-50a8-4350-8a45-086a56e0043a" 
May 10 23:31:38.417: INFO: At 2022-05-10 23:21:49 +0000 UTC - event for pod-8cbea059-8d3d-4887-9563-efa99f34d216: {kubelet ip-172-20-97-249.us-west-2.compute.internal} FailedMount: MountVolume.MountDevice failed for volume "pvc-f8d4e3f9-50a8-4350-8a45-086a56e0043a" : rpc error: code = Internal desc = could not format "/dev/nvme3n1" and mount it at "/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-f8d4e3f9-50a8-4350-8a45-086a56e0043a/globalmount": failed to get disk format of disk /dev/nvme3n1: exit status 127
May 10 23:31:38.417: INFO: At 2022-05-10 23:23:44 +0000 UTC - event for pod-8cbea059-8d3d-4887-9563-efa99f34d216: {kubelet ip-172-20-97-249.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[volume1], unattached volumes=[volume1 default-token-b8qg2]: timed out waiting for the condition
May 10 23:31:38.417: INFO: At 2022-05-10 23:28:30 +0000 UTC - event for pod-8cbea059-8d3d-4887-9563-efa99f34d216: {kubelet ip-172-20-97-249.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[volume1], unattached volumes=[default-token-b8qg2 volume1]: error processing PVC fsgroupchangepolicy-1823/ebs.csi.aws.comkmww2: PVC is being deleted
May 10 23:31:38.417: INFO: At 2022-05-10 23:28:41 +0000 UTC - event for pod-8cbea059-8d3d-4887-9563-efa99f34d216: {kubelet ip-172-20-97-249.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[volume1], unattached volumes=[volume1 default-token-b8qg2]: error processing PVC fsgroupchangepolicy-1823/ebs.csi.aws.comkmww2: PVC is being deleted
May 10 23:31:38.477: INFO: POD                                       NODE                                         PHASE    GRACE  CONDITIONS
May 10 23:31:38.477: INFO: pod-8cbea059-8d3d-4887-9563-efa99f34d216  ip-172-20-97-249.us-west-2.compute.internal  Pending         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2022-05-10 23:21:41 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2022-05-10 23:21:41 +0000 UTC ContainersNotReady containers with unready status: [write-pod]} {ContainersReady False 0001-01-01 00:00:00 +0000 UTC 2022-05-10 23:21:41 +0000 UTC ContainersNotReady containers with unready status: [write-pod]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2022-05-10 23:21:41 +0000 UTC  }]
May 10 23:31:38.477: INFO: 
May 10 23:31:38.596: INFO: 
Logging node info for node ip-172-20-56-40.us-west-2.compute.internal
May 10 23:31:38.656: INFO: Node Info: &Node{ObjectMeta:{ip-172-20-56-40.us-west-2.compute.internal    81efae28-5da4-4c6e-bded-c2e063ef39a9 3347 0 2022-05-10 23:18:49 +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-2a kops.k8s.io/instancegroup:nodes-us-west-2a kubernetes.io/arch:amd64 kubernetes.io/hostname:ip-172-20-56-40.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-2a topology.kubernetes.io/region:us-west-2 topology.kubernetes.io/zone:us-west-2a] map[csi.volume.kubernetes.io/nodeid:{"ebs.csi.aws.com":"i-0f19a99d6f747fe4d"} node.alpha.kubernetes.io/ttl:0 volumes.kubernetes.io/controller-managed-attach-detach:true] [] []  [{kops-controller Update v1 2022-05-10 23:18:49 +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-10 23:18:53 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:node.alpha.kubernetes.io/ttl":{}}},"f:spec":{"f:podCIDR":{},"f:podCIDRs":{".":{},"v:\"100.96.2.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-10 23:19:58 +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.2.0/24,DoNotUseExternalID:,ProviderID:aws:///us-west-2a/i-0f19a99d6f747fe4d,Unschedulable:false,Taints:[]Taint{},ConfigSource:nil,PodCIDRs:[100.96.2.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: {{3864977408 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: {{3760119808 0} {<nil>}  BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Phase:,Conditions:[]NodeCondition{NodeCondition{Type:NetworkUnavailable,Status:False,LastHeartbeatTime:2022-05-10 23:18:53 +0000 UTC,LastTransitionTime:2022-05-10 23:18:53 +0000 UTC,Reason:RouteCreated,Message:RouteController created a route,},NodeCondition{Type:MemoryPressure,Status:False,LastHeartbeatTime:2022-05-10 23:30:41 +0000 UTC,LastTransitionTime:2022-05-10 23:18:49 +0000 UTC,Reason:KubeletHasSufficientMemory,Message:kubelet has sufficient memory available,},NodeCondition{Type:DiskPressure,Status:False,LastHeartbeatTime:2022-05-10 23:30:41 +0000 UTC,LastTransitionTime:2022-05-10 23:18:49 +0000 UTC,Reason:KubeletHasNoDiskPressure,Message:kubelet has no disk pressure,},NodeCondition{Type:PIDPressure,Status:False,LastHeartbeatTime:2022-05-10 23:30:41 +0000 UTC,LastTransitionTime:2022-05-10 23:18:49 +0000 UTC,Reason:KubeletHasSufficientPID,Message:kubelet has sufficient PID available,},NodeCondition{Type:Ready,Status:True,LastHeartbeatTime:2022-05-10 23:30:41 +0000 UTC,LastTransitionTime:2022-05-10 23:19:09 +0000 UTC,Reason:KubeletReady,Message:kubelet is posting ready status. AppArmor enabled,},},Addresses:[]NodeAddress{NodeAddress{Type:InternalIP,Address:172.20.56.40,},NodeAddress{Type:ExternalIP,Address:54.190.220.105,},NodeAddress{Type:Hostname,Address:ip-172-20-56-40.us-west-2.compute.internal,},NodeAddress{Type:InternalDNS,Address:ip-172-20-56-40.us-west-2.compute.internal,},NodeAddress{Type:ExternalDNS,Address:ec2-54-190-220-105.us-west-2.compute.amazonaws.com,},},DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:ec26677e61ae0ccaf587f5886b593471,SystemUUID:ec26677e-61ae-0cca-f587-f5886b593471,BootID:1e40e8c7-bda2-4e00-8aa5-724badfe046b,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:12229b0c94723be687fe6e42d4e9b401334f275a84072795a72e5fa54ab0f46e 607362164682.dkr.ecr.us-west-2.amazonaws.com/aws-ebs-csi-driver:3162],SizeBytes:26066741,},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 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 (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
    (Always)[LinuxOnly], pod created with an initial fsgroup, volume contents ownership changed in first pod, new pod with different fsgroup applied 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 | 0xc000943f90>: {
            s: "pod \"pod-8cbea059-8d3d-4887-9563-efa99f34d216\" is not Running: timed out waiting for the condition",
        }
        pod "pod-8cbea059-8d3d-4887-9563-efa99f34d216" is not Running: timed out waiting for the condition
    occurred

... skipping 19 lines ...
May 10 23:27:03.035: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(ebs.csi.aws.com) supported size:{ 1Mi} 
STEP: creating a StorageClass provisioning-7721-e2e-sc58vlx
STEP: creating a claim
May 10 23:27:03.112: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
STEP: Creating pod pod-subpath-test-dynamicpv-skf7
STEP: Creating a pod to test subpath
May 10 23:27:03.328: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-skf7" in namespace "provisioning-7721" to be "Succeeded or Failed"
May 10 23:27:03.393: INFO: Pod "pod-subpath-test-dynamicpv-skf7": Phase="Pending", Reason="", readiness=false. Elapsed: 65.203138ms
May 10 23:27:05.459: INFO: Pod "pod-subpath-test-dynamicpv-skf7": Phase="Pending", Reason="", readiness=false. Elapsed: 2.131007553s
May 10 23:27:07.526: INFO: Pod "pod-subpath-test-dynamicpv-skf7": Phase="Pending", Reason="", readiness=false. Elapsed: 4.197563214s
May 10 23:27:09.592: INFO: Pod "pod-subpath-test-dynamicpv-skf7": Phase="Pending", Reason="", readiness=false. Elapsed: 6.263356921s
May 10 23:27:11.659: INFO: Pod "pod-subpath-test-dynamicpv-skf7": Phase="Pending", Reason="", readiness=false. Elapsed: 8.330416496s
May 10 23:27:13.729: INFO: Pod "pod-subpath-test-dynamicpv-skf7": Phase="Pending", Reason="", readiness=false. Elapsed: 10.401089121s
... skipping 134 lines ...
May 10 23:31:52.667: INFO: Pod "pod-subpath-test-dynamicpv-skf7": Phase="Pending", Reason="", readiness=false. Elapsed: 4m49.33824782s
May 10 23:31:54.734: INFO: Pod "pod-subpath-test-dynamicpv-skf7": Phase="Pending", Reason="", readiness=false. Elapsed: 4m51.406169739s
May 10 23:31:56.799: INFO: Pod "pod-subpath-test-dynamicpv-skf7": Phase="Pending", Reason="", readiness=false. Elapsed: 4m53.471001515s
May 10 23:31:58.864: INFO: Pod "pod-subpath-test-dynamicpv-skf7": Phase="Pending", Reason="", readiness=false. Elapsed: 4m55.535857443s
May 10 23:32:00.929: INFO: Pod "pod-subpath-test-dynamicpv-skf7": Phase="Pending", Reason="", readiness=false. Elapsed: 4m57.600538614s
May 10 23:32:02.994: INFO: Pod "pod-subpath-test-dynamicpv-skf7": Phase="Pending", Reason="", readiness=false. Elapsed: 4m59.665851209s
May 10 23:32:05.139: INFO: Failed to get logs from node "ip-172-20-97-249.us-west-2.compute.internal" pod "pod-subpath-test-dynamicpv-skf7" container "init-volume-dynamicpv-skf7": the server rejected our request for an unknown reason (get pods pod-subpath-test-dynamicpv-skf7)
May 10 23:32:05.204: INFO: Failed to get logs from node "ip-172-20-97-249.us-west-2.compute.internal" pod "pod-subpath-test-dynamicpv-skf7" container "test-init-volume-dynamicpv-skf7": the server rejected our request for an unknown reason (get pods pod-subpath-test-dynamicpv-skf7)
May 10 23:32:05.271: INFO: Failed to get logs from node "ip-172-20-97-249.us-west-2.compute.internal" pod "pod-subpath-test-dynamicpv-skf7" container "test-container-subpath-dynamicpv-skf7": the server rejected our request for an unknown reason (get pods pod-subpath-test-dynamicpv-skf7)
STEP: delete the pod
May 10 23:32:05.352: INFO: Waiting for pod pod-subpath-test-dynamicpv-skf7 to disappear
May 10 23:32:05.417: INFO: Pod pod-subpath-test-dynamicpv-skf7 still exists
May 10 23:32:07.418: INFO: Waiting for pod pod-subpath-test-dynamicpv-skf7 to disappear
May 10 23:32:07.482: INFO: Pod pod-subpath-test-dynamicpv-skf7 still exists
May 10 23:32:09.417: INFO: Waiting for pod pod-subpath-test-dynamicpv-skf7 to disappear
... skipping 21 lines ...
May 10 23:32:31.137: INFO: At 2022-05-10 23:27:03 +0000 UTC - event for ebs.csi.aws.comh6lzl: {persistentvolume-controller } WaitForFirstConsumer: waiting for first consumer to be created before binding
May 10 23:32:31.137: INFO: At 2022-05-10 23:27:03 +0000 UTC - event for ebs.csi.aws.comh6lzl: {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 10 23:32:31.137: INFO: At 2022-05-10 23:27:03 +0000 UTC - event for ebs.csi.aws.comh6lzl: {ebs.csi.aws.com_ebs-csi-controller-d99f59ddb-sgbd9_2a3f19cf-28ce-4bc0-94d5-57006d216d51 } Provisioning: External provisioner is provisioning volume for claim "provisioning-7721/ebs.csi.aws.comh6lzl"
May 10 23:32:31.137: INFO: At 2022-05-10 23:27:06 +0000 UTC - event for ebs.csi.aws.comh6lzl: {ebs.csi.aws.com_ebs-csi-controller-d99f59ddb-sgbd9_2a3f19cf-28ce-4bc0-94d5-57006d216d51 } ProvisioningSucceeded: Successfully provisioned volume pvc-6d1c38f0-281b-49c4-a93f-73bede888854
May 10 23:32:31.137: INFO: At 2022-05-10 23:27:07 +0000 UTC - event for pod-subpath-test-dynamicpv-skf7: {default-scheduler } Scheduled: Successfully assigned provisioning-7721/pod-subpath-test-dynamicpv-skf7 to ip-172-20-97-249.us-west-2.compute.internal
May 10 23:32:31.137: INFO: At 2022-05-10 23:27:09 +0000 UTC - event for pod-subpath-test-dynamicpv-skf7: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-6d1c38f0-281b-49c4-a93f-73bede888854" 
May 10 23:32:31.137: INFO: At 2022-05-10 23:27:15 +0000 UTC - event for pod-subpath-test-dynamicpv-skf7: {kubelet ip-172-20-97-249.us-west-2.compute.internal} FailedMount: MountVolume.MountDevice failed for volume "pvc-6d1c38f0-281b-49c4-a93f-73bede888854" : rpc error: code = Internal desc = could not format "/dev/nvme1n1" and mount it at "/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-6d1c38f0-281b-49c4-a93f-73bede888854/globalmount": failed to get disk format of disk /dev/nvme1n1: exit status 127
May 10 23:32:31.137: INFO: At 2022-05-10 23:29:10 +0000 UTC - event for pod-subpath-test-dynamicpv-skf7: {kubelet ip-172-20-97-249.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[test-volume], unattached volumes=[default-token-46jj5 test-volume liveness-probe-volume]: timed out waiting for the condition
May 10 23:32:31.200: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
May 10 23:32:31.200: INFO: 
May 10 23:32:31.265: INFO: 
Logging node info for node ip-172-20-56-40.us-west-2.compute.internal
May 10 23:32:31.329: INFO: Node Info: &Node{ObjectMeta:{ip-172-20-56-40.us-west-2.compute.internal    81efae28-5da4-4c6e-bded-c2e063ef39a9 3347 0 2022-05-10 23:18:49 +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-2a kops.k8s.io/instancegroup:nodes-us-west-2a kubernetes.io/arch:amd64 kubernetes.io/hostname:ip-172-20-56-40.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-2a topology.kubernetes.io/region:us-west-2 topology.kubernetes.io/zone:us-west-2a] map[csi.volume.kubernetes.io/nodeid:{"ebs.csi.aws.com":"i-0f19a99d6f747fe4d"} node.alpha.kubernetes.io/ttl:0 volumes.kubernetes.io/controller-managed-attach-detach:true] [] []  [{kops-controller Update v1 2022-05-10 23:18:49 +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-10 23:18:53 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:node.alpha.kubernetes.io/ttl":{}}},"f:spec":{"f:podCIDR":{},"f:podCIDRs":{".":{},"v:\"100.96.2.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-10 23:19:58 +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.2.0/24,DoNotUseExternalID:,ProviderID:aws:///us-west-2a/i-0f19a99d6f747fe4d,Unschedulable:false,Taints:[]Taint{},ConfigSource:nil,PodCIDRs:[100.96.2.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: {{3864977408 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: {{3760119808 0} {<nil>}  BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Phase:,Conditions:[]NodeCondition{NodeCondition{Type:NetworkUnavailable,Status:False,LastHeartbeatTime:2022-05-10 23:18:53 +0000 UTC,LastTransitionTime:2022-05-10 23:18:53 +0000 UTC,Reason:RouteCreated,Message:RouteController created a route,},NodeCondition{Type:MemoryPressure,Status:False,LastHeartbeatTime:2022-05-10 23:30:41 +0000 UTC,LastTransitionTime:2022-05-10 23:18:49 +0000 UTC,Reason:KubeletHasSufficientMemory,Message:kubelet has sufficient memory available,},NodeCondition{Type:DiskPressure,Status:False,LastHeartbeatTime:2022-05-10 23:30:41 +0000 UTC,LastTransitionTime:2022-05-10 23:18:49 +0000 UTC,Reason:KubeletHasNoDiskPressure,Message:kubelet has no disk pressure,},NodeCondition{Type:PIDPressure,Status:False,LastHeartbeatTime:2022-05-10 23:30:41 +0000 UTC,LastTransitionTime:2022-05-10 23:18:49 +0000 UTC,Reason:KubeletHasSufficientPID,Message:kubelet has sufficient PID available,},NodeCondition{Type:Ready,Status:True,LastHeartbeatTime:2022-05-10 23:30:41 +0000 UTC,LastTransitionTime:2022-05-10 23:19:09 +0000 UTC,Reason:KubeletReady,Message:kubelet is posting ready status. AppArmor enabled,},},Addresses:[]NodeAddress{NodeAddress{Type:InternalIP,Address:172.20.56.40,},NodeAddress{Type:ExternalIP,Address:54.190.220.105,},NodeAddress{Type:Hostname,Address:ip-172-20-56-40.us-west-2.compute.internal,},NodeAddress{Type:InternalDNS,Address:ip-172-20-56-40.us-west-2.compute.internal,},NodeAddress{Type:ExternalDNS,Address:ec2-54-190-220-105.us-west-2.compute.amazonaws.com,},},DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:ec26677e61ae0ccaf587f5886b593471,SystemUUID:ec26677e-61ae-0cca-f587-f5886b593471,BootID:1e40e8c7-bda2-4e00-8aa5-724badfe046b,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:12229b0c94723be687fe6e42d4e9b401334f275a84072795a72e5fa54ab0f46e 607362164682.dkr.ecr.us-west-2.amazonaws.com/aws-ebs-csi-driver:3162],SizeBytes:26066741,},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 104 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 | 0xc000b59e40>: {
            s: "expected pod \"pod-subpath-test-dynamicpv-skf7\" success: Gave up after waiting 5m0s for pod \"pod-subpath-test-dynamicpv-skf7\" to be \"Succeeded or Failed\"",
        }
        expected pod "pod-subpath-test-dynamicpv-skf7" success: Gave up after waiting 5m0s for pod "pod-subpath-test-dynamicpv-skf7" 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: Dynamic PV (ntfs)][Feature:Windows] provisioning
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:51
... skipping 241 lines ...
May 10 23:27:24.817: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(ebs.csi.aws.com) supported size:{ 1Mi} 
STEP: creating a StorageClass volume-7440-e2e-scv6kqd
STEP: creating a claim
May 10 23:27:24.883: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
STEP: Creating pod exec-volume-test-dynamicpv-8qg2
STEP: Creating a pod to test exec-volume-test
May 10 23:27:25.080: INFO: Waiting up to 5m0s for pod "exec-volume-test-dynamicpv-8qg2" in namespace "volume-7440" to be "Succeeded or Failed"
May 10 23:27:25.145: INFO: Pod "exec-volume-test-dynamicpv-8qg2": Phase="Pending", Reason="", readiness=false. Elapsed: 64.342958ms
May 10 23:27:27.212: INFO: Pod "exec-volume-test-dynamicpv-8qg2": Phase="Pending", Reason="", readiness=false. Elapsed: 2.131318268s
May 10 23:27:29.278: INFO: Pod "exec-volume-test-dynamicpv-8qg2": Phase="Pending", Reason="", readiness=false. Elapsed: 4.197480343s
May 10 23:27:31.342: INFO: Pod "exec-volume-test-dynamicpv-8qg2": Phase="Pending", Reason="", readiness=false. Elapsed: 6.262198416s
May 10 23:27:33.408: INFO: Pod "exec-volume-test-dynamicpv-8qg2": Phase="Pending", Reason="", readiness=false. Elapsed: 8.327682581s
May 10 23:27:35.479: INFO: Pod "exec-volume-test-dynamicpv-8qg2": Phase="Pending", Reason="", readiness=false. Elapsed: 10.399053001s
... skipping 134 lines ...
May 10 23:32:14.522: INFO: Pod "exec-volume-test-dynamicpv-8qg2": Phase="Pending", Reason="", readiness=false. Elapsed: 4m49.442001565s
May 10 23:32:16.587: INFO: Pod "exec-volume-test-dynamicpv-8qg2": Phase="Pending", Reason="", readiness=false. Elapsed: 4m51.507156578s
May 10 23:32:18.652: INFO: Pod "exec-volume-test-dynamicpv-8qg2": Phase="Pending", Reason="", readiness=false. Elapsed: 4m53.571598468s
May 10 23:32:20.716: INFO: Pod "exec-volume-test-dynamicpv-8qg2": Phase="Pending", Reason="", readiness=false. Elapsed: 4m55.636156929s
May 10 23:32:22.781: INFO: Pod "exec-volume-test-dynamicpv-8qg2": Phase="Pending", Reason="", readiness=false. Elapsed: 4m57.700978871s
May 10 23:32:24.846: INFO: Pod "exec-volume-test-dynamicpv-8qg2": Phase="Pending", Reason="", readiness=false. Elapsed: 4m59.76594836s
May 10 23:32:26.978: INFO: Failed to get logs from node "ip-172-20-97-249.us-west-2.compute.internal" pod "exec-volume-test-dynamicpv-8qg2" container "exec-container-dynamicpv-8qg2": the server rejected our request for an unknown reason (get pods exec-volume-test-dynamicpv-8qg2)
STEP: delete the pod
May 10 23:32:27.044: INFO: Waiting for pod exec-volume-test-dynamicpv-8qg2 to disappear
May 10 23:32:27.109: INFO: Pod exec-volume-test-dynamicpv-8qg2 still exists
May 10 23:32:29.109: INFO: Waiting for pod exec-volume-test-dynamicpv-8qg2 to disappear
May 10 23:32:29.174: INFO: Pod exec-volume-test-dynamicpv-8qg2 still exists
May 10 23:32:31.109: INFO: Waiting for pod exec-volume-test-dynamicpv-8qg2 to disappear
... skipping 17 lines ...
May 10 23:32:50.771: INFO: At 2022-05-10 23:27:24 +0000 UTC - event for ebs.csi.aws.comqxvzg: {persistentvolume-controller } WaitForFirstConsumer: waiting for first consumer to be created before binding
May 10 23:32:50.771: INFO: At 2022-05-10 23:27:25 +0000 UTC - event for ebs.csi.aws.comqxvzg: {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 10 23:32:50.771: INFO: At 2022-05-10 23:27:25 +0000 UTC - event for ebs.csi.aws.comqxvzg: {ebs.csi.aws.com_ebs-csi-controller-d99f59ddb-sgbd9_2a3f19cf-28ce-4bc0-94d5-57006d216d51 } Provisioning: External provisioner is provisioning volume for claim "volume-7440/ebs.csi.aws.comqxvzg"
May 10 23:32:50.771: INFO: At 2022-05-10 23:27:28 +0000 UTC - event for ebs.csi.aws.comqxvzg: {ebs.csi.aws.com_ebs-csi-controller-d99f59ddb-sgbd9_2a3f19cf-28ce-4bc0-94d5-57006d216d51 } ProvisioningSucceeded: Successfully provisioned volume pvc-fb969705-7bc7-4757-97b2-ce12386dcb75
May 10 23:32:50.771: INFO: At 2022-05-10 23:27:29 +0000 UTC - event for exec-volume-test-dynamicpv-8qg2: {default-scheduler } Scheduled: Successfully assigned volume-7440/exec-volume-test-dynamicpv-8qg2 to ip-172-20-97-249.us-west-2.compute.internal
May 10 23:32:50.771: INFO: At 2022-05-10 23:27:30 +0000 UTC - event for exec-volume-test-dynamicpv-8qg2: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-fb969705-7bc7-4757-97b2-ce12386dcb75" 
May 10 23:32:50.771: INFO: At 2022-05-10 23:27:32 +0000 UTC - event for exec-volume-test-dynamicpv-8qg2: {kubelet ip-172-20-97-249.us-west-2.compute.internal} FailedMount: MountVolume.MountDevice failed for volume "pvc-fb969705-7bc7-4757-97b2-ce12386dcb75" : rpc error: code = Internal desc = could not format "/dev/nvme2n1" and mount it at "/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-fb969705-7bc7-4757-97b2-ce12386dcb75/globalmount": failed to get disk format of disk /dev/nvme2n1: exit status 127
May 10 23:32:50.771: INFO: At 2022-05-10 23:29:32 +0000 UTC - event for exec-volume-test-dynamicpv-8qg2: {kubelet ip-172-20-97-249.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[vol1], unattached volumes=[vol1 default-token-4pdlt]: timed out waiting for the condition
May 10 23:32:50.835: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
May 10 23:32:50.835: INFO: 
May 10 23:32:50.900: INFO: 
Logging node info for node ip-172-20-56-40.us-west-2.compute.internal
May 10 23:32:50.969: INFO: Node Info: &Node{ObjectMeta:{ip-172-20-56-40.us-west-2.compute.internal    81efae28-5da4-4c6e-bded-c2e063ef39a9 3347 0 2022-05-10 23:18:49 +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-2a kops.k8s.io/instancegroup:nodes-us-west-2a kubernetes.io/arch:amd64 kubernetes.io/hostname:ip-172-20-56-40.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-2a topology.kubernetes.io/region:us-west-2 topology.kubernetes.io/zone:us-west-2a] map[csi.volume.kubernetes.io/nodeid:{"ebs.csi.aws.com":"i-0f19a99d6f747fe4d"} node.alpha.kubernetes.io/ttl:0 volumes.kubernetes.io/controller-managed-attach-detach:true] [] []  [{kops-controller Update v1 2022-05-10 23:18:49 +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-10 23:18:53 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:node.alpha.kubernetes.io/ttl":{}}},"f:spec":{"f:podCIDR":{},"f:podCIDRs":{".":{},"v:\"100.96.2.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-10 23:19:58 +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.2.0/24,DoNotUseExternalID:,ProviderID:aws:///us-west-2a/i-0f19a99d6f747fe4d,Unschedulable:false,Taints:[]Taint{},ConfigSource:nil,PodCIDRs:[100.96.2.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: {{3864977408 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: {{3760119808 0} {<nil>}  BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Phase:,Conditions:[]NodeCondition{NodeCondition{Type:NetworkUnavailable,Status:False,LastHeartbeatTime:2022-05-10 23:18:53 +0000 UTC,LastTransitionTime:2022-05-10 23:18:53 +0000 UTC,Reason:RouteCreated,Message:RouteController created a route,},NodeCondition{Type:MemoryPressure,Status:False,LastHeartbeatTime:2022-05-10 23:30:41 +0000 UTC,LastTransitionTime:2022-05-10 23:18:49 +0000 UTC,Reason:KubeletHasSufficientMemory,Message:kubelet has sufficient memory available,},NodeCondition{Type:DiskPressure,Status:False,LastHeartbeatTime:2022-05-10 23:30:41 +0000 UTC,LastTransitionTime:2022-05-10 23:18:49 +0000 UTC,Reason:KubeletHasNoDiskPressure,Message:kubelet has no disk pressure,},NodeCondition{Type:PIDPressure,Status:False,LastHeartbeatTime:2022-05-10 23:30:41 +0000 UTC,LastTransitionTime:2022-05-10 23:18:49 +0000 UTC,Reason:KubeletHasSufficientPID,Message:kubelet has sufficient PID available,},NodeCondition{Type:Ready,Status:True,LastHeartbeatTime:2022-05-10 23:30:41 +0000 UTC,LastTransitionTime:2022-05-10 23:19:09 +0000 UTC,Reason:KubeletReady,Message:kubelet is posting ready status. AppArmor enabled,},},Addresses:[]NodeAddress{NodeAddress{Type:InternalIP,Address:172.20.56.40,},NodeAddress{Type:ExternalIP,Address:54.190.220.105,},NodeAddress{Type:Hostname,Address:ip-172-20-56-40.us-west-2.compute.internal,},NodeAddress{Type:InternalDNS,Address:ip-172-20-56-40.us-west-2.compute.internal,},NodeAddress{Type:ExternalDNS,Address:ec2-54-190-220-105.us-west-2.compute.amazonaws.com,},},DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:ec26677e61ae0ccaf587f5886b593471,SystemUUID:ec26677e-61ae-0cca-f587-f5886b593471,BootID:1e40e8c7-bda2-4e00-8aa5-724badfe046b,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:12229b0c94723be687fe6e42d4e9b401334f275a84072795a72e5fa54ab0f46e 607362164682.dkr.ecr.us-west-2.amazonaws.com/aws-ebs-csi-driver:3162],SizeBytes:26066741,},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)] 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 | 0xc00130b290>: {
            s: "expected pod \"exec-volume-test-dynamicpv-8qg2\" success: Gave up after waiting 5m0s for pod \"exec-volume-test-dynamicpv-8qg2\" to be \"Succeeded or Failed\"",
        }
        expected pod "exec-volume-test-dynamicpv-8qg2" success: Gave up after waiting 5m0s for pod "exec-volume-test-dynamicpv-8qg2" 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 (block volmode)] multiVolume [Slow] 
  should access to two volumes with different volume mode and retain data across pod recreation on the same node [LinuxOnly]
... skipping 47 lines ...
May 10 23:37:19.847: INFO: At 2022-05-10 23:31:41 +0000 UTC - event for ebs.csi.aws.commdn2t: {ebs.csi.aws.com_ebs-csi-controller-d99f59ddb-sgbd9_2a3f19cf-28ce-4bc0-94d5-57006d216d51 } Provisioning: External provisioner is provisioning volume for claim "multivolume-6498/ebs.csi.aws.commdn2t"
May 10 23:37:19.847: INFO: At 2022-05-10 23:31:44 +0000 UTC - event for ebs.csi.aws.comk5d9r: {ebs.csi.aws.com_ebs-csi-controller-d99f59ddb-sgbd9_2a3f19cf-28ce-4bc0-94d5-57006d216d51 } ProvisioningSucceeded: Successfully provisioned volume pvc-65d0ba78-bdc2-4e4c-8aa5-fcc3291a1189
May 10 23:37:19.847: INFO: At 2022-05-10 23:31:45 +0000 UTC - event for ebs.csi.aws.commdn2t: {ebs.csi.aws.com_ebs-csi-controller-d99f59ddb-sgbd9_2a3f19cf-28ce-4bc0-94d5-57006d216d51 } ProvisioningSucceeded: Successfully provisioned volume pvc-ba35ca3c-b124-46e3-9cdc-4d16d86af5cb
May 10 23:37:19.847: INFO: At 2022-05-10 23:31:45 +0000 UTC - event for pod-eaa52f61-268d-491f-9301-e56119997e46: {default-scheduler } Scheduled: Successfully assigned multivolume-6498/pod-eaa52f61-268d-491f-9301-e56119997e46 to ip-172-20-97-249.us-west-2.compute.internal
May 10 23:37:19.847: INFO: At 2022-05-10 23:31:47 +0000 UTC - event for pod-eaa52f61-268d-491f-9301-e56119997e46: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-65d0ba78-bdc2-4e4c-8aa5-fcc3291a1189" 
May 10 23:37:19.847: INFO: At 2022-05-10 23:31:47 +0000 UTC - event for pod-eaa52f61-268d-491f-9301-e56119997e46: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-ba35ca3c-b124-46e3-9cdc-4d16d86af5cb" 
May 10 23:37:19.847: INFO: At 2022-05-10 23:31:53 +0000 UTC - event for pod-eaa52f61-268d-491f-9301-e56119997e46: {kubelet ip-172-20-97-249.us-west-2.compute.internal} FailedMount: MountVolume.MountDevice failed for volume "pvc-ba35ca3c-b124-46e3-9cdc-4d16d86af5cb" : rpc error: code = Internal desc = could not format "/dev/nvme6n1" and mount it at "/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-ba35ca3c-b124-46e3-9cdc-4d16d86af5cb/globalmount": failed to get disk format of disk /dev/nvme6n1: exit status 127
May 10 23:37:19.847: INFO: At 2022-05-10 23:31:53 +0000 UTC - event for pod-eaa52f61-268d-491f-9301-e56119997e46: {kubelet ip-172-20-97-249.us-west-2.compute.internal} FailedMapVolume: MapVolume.MapPodDevice failed for volume "pvc-65d0ba78-bdc2-4e4c-8aa5-fcc3291a1189" : rpc error: code = Internal desc = Could not mount "/dev/nvme5n1" at "/var/lib/kubelet/plugins/kubernetes.io/csi/volumeDevices/publish/pvc-65d0ba78-bdc2-4e4c-8aa5-fcc3291a1189/10d66198-adb3-46c0-aaad-2f0dd516e2c2": 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-65d0ba78-bdc2-4e4c-8aa5-fcc3291a1189/10d66198-adb3-46c0-aaad-2f0dd516e2c2
Output: 
May 10 23:37:19.847: INFO: At 2022-05-10 23:33:48 +0000 UTC - event for pod-eaa52f61-268d-491f-9301-e56119997e46: {kubelet ip-172-20-97-249.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[volume2 volume1], unattached volumes=[volume2 default-token-zl62r volume1]: timed out waiting for the condition
May 10 23:37:19.908: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
May 10 23:37:19.908: INFO: 
... skipping 110 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 different 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:214

    Unexpected error:
        <*errors.errorString | 0xc0010fea10>: {
            s: "pod \"pod-eaa52f61-268d-491f-9301-e56119997e46\" is not Running: timed out waiting for the condition",
        }
        pod "pod-eaa52f61-268d-491f-9301-e56119997e46" is not Running: timed out waiting for the condition
    occurred

... skipping 90 lines ...
May 10 23:37:33.702: INFO: At 2022-05-10 23:27:28 +0000 UTC - event for ebs.csi.aws.com95qm6: {persistentvolume-controller } WaitForFirstConsumer: waiting for first consumer to be created before binding
May 10 23:37:33.702: INFO: At 2022-05-10 23:27:29 +0000 UTC - event for ebs.csi.aws.com95qm6: {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 10 23:37:33.702: INFO: At 2022-05-10 23:27:29 +0000 UTC - event for ebs.csi.aws.com95qm6: {ebs.csi.aws.com_ebs-csi-controller-d99f59ddb-sgbd9_2a3f19cf-28ce-4bc0-94d5-57006d216d51 } Provisioning: External provisioner is provisioning volume for claim "fsgroupchangepolicy-5049/ebs.csi.aws.com95qm6"
May 10 23:37:33.702: INFO: At 2022-05-10 23:27:32 +0000 UTC - event for ebs.csi.aws.com95qm6: {ebs.csi.aws.com_ebs-csi-controller-d99f59ddb-sgbd9_2a3f19cf-28ce-4bc0-94d5-57006d216d51 } ProvisioningSucceeded: Successfully provisioned volume pvc-f01369dc-85ed-4aad-88f2-ed9e2e5ee662
May 10 23:37:33.702: INFO: At 2022-05-10 23:27:33 +0000 UTC - event for pod-d87bb799-b72e-456a-887b-e08afdd00d47: {default-scheduler } Scheduled: Successfully assigned fsgroupchangepolicy-5049/pod-d87bb799-b72e-456a-887b-e08afdd00d47 to ip-172-20-97-249.us-west-2.compute.internal
May 10 23:37:33.702: INFO: At 2022-05-10 23:27:34 +0000 UTC - event for pod-d87bb799-b72e-456a-887b-e08afdd00d47: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-f01369dc-85ed-4aad-88f2-ed9e2e5ee662" 
May 10 23:37:33.702: INFO: At 2022-05-10 23:27:48 +0000 UTC - event for pod-d87bb799-b72e-456a-887b-e08afdd00d47: {kubelet ip-172-20-97-249.us-west-2.compute.internal} FailedMount: MountVolume.MountDevice failed for volume "pvc-f01369dc-85ed-4aad-88f2-ed9e2e5ee662" : rpc error: code = Internal desc = could not format "/dev/nvme4n1" and mount it at "/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-f01369dc-85ed-4aad-88f2-ed9e2e5ee662/globalmount": failed to get disk format of disk /dev/nvme4n1: exit status 127
May 10 23:37:33.702: INFO: At 2022-05-10 23:29:36 +0000 UTC - event for pod-d87bb799-b72e-456a-887b-e08afdd00d47: {kubelet ip-172-20-97-249.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[volume1], unattached volumes=[volume1 default-token-hcxlx]: timed out waiting for the condition
May 10 23:37:33.702: INFO: At 2022-05-10 23:34:21 +0000 UTC - event for pod-d87bb799-b72e-456a-887b-e08afdd00d47: {kubelet ip-172-20-97-249.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[volume1], unattached volumes=[volume1 default-token-hcxlx]: error processing PVC fsgroupchangepolicy-5049/ebs.csi.aws.com95qm6: PVC is being deleted
May 10 23:37:33.702: INFO: At 2022-05-10 23:35:29 +0000 UTC - event for pod-d87bb799-b72e-456a-887b-e08afdd00d47: {kubelet ip-172-20-97-249.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[volume1], unattached volumes=[default-token-hcxlx volume1]: error processing PVC fsgroupchangepolicy-5049/ebs.csi.aws.com95qm6: PVC is being deleted
May 10 23:37:33.767: INFO: POD                                       NODE                                         PHASE    GRACE  CONDITIONS
May 10 23:37:33.767: INFO: pod-d87bb799-b72e-456a-887b-e08afdd00d47  ip-172-20-97-249.us-west-2.compute.internal  Pending         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2022-05-10 23:27:33 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2022-05-10 23:27:33 +0000 UTC ContainersNotReady containers with unready status: [write-pod]} {ContainersReady False 0001-01-01 00:00:00 +0000 UTC 2022-05-10 23:27:33 +0000 UTC ContainersNotReady containers with unready status: [write-pod]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2022-05-10 23:27:33 +0000 UTC  }]
May 10 23:37:33.767: INFO: 
May 10 23:37:33.835: INFO: 
Logging node info for node ip-172-20-56-40.us-west-2.compute.internal
May 10 23:37:33.900: INFO: Node Info: &Node{ObjectMeta:{ip-172-20-56-40.us-west-2.compute.internal    81efae28-5da4-4c6e-bded-c2e063ef39a9 4519 0 2022-05-10 23:18:49 +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-2a kops.k8s.io/instancegroup:nodes-us-west-2a kubernetes.io/arch:amd64 kubernetes.io/hostname:ip-172-20-56-40.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-2a topology.kubernetes.io/region:us-west-2 topology.kubernetes.io/zone:us-west-2a] map[csi.volume.kubernetes.io/nodeid:{"ebs.csi.aws.com":"i-0f19a99d6f747fe4d"} node.alpha.kubernetes.io/ttl:0 volumes.kubernetes.io/controller-managed-attach-detach:true] [] []  [{kops-controller Update v1 2022-05-10 23:18:49 +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-10 23:18:53 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:node.alpha.kubernetes.io/ttl":{}}},"f:spec":{"f:podCIDR":{},"f:podCIDRs":{".":{},"v:\"100.96.2.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-10 23:19:58 +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.2.0/24,DoNotUseExternalID:,ProviderID:aws:///us-west-2a/i-0f19a99d6f747fe4d,Unschedulable:false,Taints:[]Taint{},ConfigSource:nil,PodCIDRs:[100.96.2.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: {{3864977408 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: {{3760119808 0} {<nil>}  BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Phase:,Conditions:[]NodeCondition{NodeCondition{Type:NetworkUnavailable,Status:False,LastHeartbeatTime:2022-05-10 23:18:53 +0000 UTC,LastTransitionTime:2022-05-10 23:18:53 +0000 UTC,Reason:RouteCreated,Message:RouteController created a route,},NodeCondition{Type:MemoryPressure,Status:False,LastHeartbeatTime:2022-05-10 23:35:44 +0000 UTC,LastTransitionTime:2022-05-10 23:18:49 +0000 UTC,Reason:KubeletHasSufficientMemory,Message:kubelet has sufficient memory available,},NodeCondition{Type:DiskPressure,Status:False,LastHeartbeatTime:2022-05-10 23:35:44 +0000 UTC,LastTransitionTime:2022-05-10 23:18:49 +0000 UTC,Reason:KubeletHasNoDiskPressure,Message:kubelet has no disk pressure,},NodeCondition{Type:PIDPressure,Status:False,LastHeartbeatTime:2022-05-10 23:35:44 +0000 UTC,LastTransitionTime:2022-05-10 23:18:49 +0000 UTC,Reason:KubeletHasSufficientPID,Message:kubelet has sufficient PID available,},NodeCondition{Type:Ready,Status:True,LastHeartbeatTime:2022-05-10 23:35:44 +0000 UTC,LastTransitionTime:2022-05-10 23:19:09 +0000 UTC,Reason:KubeletReady,Message:kubelet is posting ready status. AppArmor enabled,},},Addresses:[]NodeAddress{NodeAddress{Type:InternalIP,Address:172.20.56.40,},NodeAddress{Type:ExternalIP,Address:54.190.220.105,},NodeAddress{Type:Hostname,Address:ip-172-20-56-40.us-west-2.compute.internal,},NodeAddress{Type:InternalDNS,Address:ip-172-20-56-40.us-west-2.compute.internal,},NodeAddress{Type:ExternalDNS,Address:ec2-54-190-220-105.us-west-2.compute.amazonaws.com,},},DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:ec26677e61ae0ccaf587f5886b593471,SystemUUID:ec26677e-61ae-0cca-f587-f5886b593471,BootID:1e40e8c7-bda2-4e00-8aa5-724badfe046b,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:12229b0c94723be687fe6e42d4e9b401334f275a84072795a72e5fa54ab0f46e 607362164682.dkr.ecr.us-west-2.amazonaws.com/aws-ebs-csi-driver:3162],SizeBytes:26066741,},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 109 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
    (Always)[LinuxOnly], pod created with an initial fsgroup, new pod fsgroup applied to 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 | 0xc001214bf0>: {
            s: "pod \"pod-d87bb799-b72e-456a-887b-e08afdd00d47\" is not Running: timed out waiting for the condition",
        }
        pod "pod-d87bb799-b72e-456a-887b-e08afdd00d47" is not Running: 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/fsgroupchangepolicy.go:250
------------------------------
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 10 23:37:36.219: INFO: >>> kubeConfig: /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/hack/e2e/csi-test-artifacts/test-cluster-3162.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 10 23:37:36.563: INFO: Creating resource for dynamic PV
May 10 23:37:36.563: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(ebs.csi.aws.com) supported size:{ 1Mi} 
STEP: creating a StorageClass volumemode-8470-e2e-scvmncg
STEP: creating a claim
STEP: Creating pod
STEP: Waiting for the pod to fail
May 10 23:37:43.033: INFO: Deleting pod "pod-3e70b9b6-6f00-4d0d-a137-ab109fbf5813" in namespace "volumemode-8470"
May 10 23:37:43.111: INFO: Wait up to 5m0s for pod "pod-3e70b9b6-6f00-4d0d-a137-ab109fbf5813" to be fully deleted
STEP: Deleting pvc
May 10 23:37:53.380: INFO: Deleting PersistentVolumeClaim "ebs.csi.aws.comdtj7n"
May 10 23:37:53.447: INFO: Waiting up to 5m0s for PersistentVolume pvc-dc4cf6cf-2c21-416c-8d75-a471d313bbdb to get deleted
May 10 23:37:53.513: INFO: PersistentVolume pvc-dc4cf6cf-2c21-416c-8d75-a471d313bbdb found and phase=Released (65.738731ms)
... skipping 7 lines ...

• [SLOW TEST:22.568 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
------------------------------
[BeforeEach] [Testpattern: CSI Ephemeral-volume (default fs)] ephemeral
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:51
May 10 23:37:58.788: INFO: Driver "ebs.csi.aws.com" does not support volume type "CSIInlineVolume" - skipping
[AfterEach] [Testpattern: CSI Ephemeral-volume (default fs)] ephemeral
... skipping 53 lines ...
May 10 23:37:59.523: INFO: At 2022-05-10 23:32:35 +0000 UTC - event for ebs.csi.aws.comfvgwx: {persistentvolume-controller } WaitForFirstConsumer: waiting for first consumer to be created before binding
May 10 23:37:59.523: INFO: At 2022-05-10 23:32:35 +0000 UTC - event for ebs.csi.aws.comfvgwx: {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 10 23:37:59.523: INFO: At 2022-05-10 23:32:35 +0000 UTC - event for ebs.csi.aws.comfvgwx: {ebs.csi.aws.com_ebs-csi-controller-d99f59ddb-sgbd9_2a3f19cf-28ce-4bc0-94d5-57006d216d51 } Provisioning: External provisioner is provisioning volume for claim "provisioning-2480/ebs.csi.aws.comfvgwx"
May 10 23:37:59.523: INFO: At 2022-05-10 23:32:38 +0000 UTC - event for ebs.csi.aws.comfvgwx: {ebs.csi.aws.com_ebs-csi-controller-d99f59ddb-sgbd9_2a3f19cf-28ce-4bc0-94d5-57006d216d51 } ProvisioningSucceeded: Successfully provisioned volume pvc-13a84d36-120f-4573-a479-0135bc27a7bf
May 10 23:37:59.523: INFO: At 2022-05-10 23:32:39 +0000 UTC - event for pod-subpath-test-dynamicpv-f8h4: {default-scheduler } Scheduled: Successfully assigned provisioning-2480/pod-subpath-test-dynamicpv-f8h4 to ip-172-20-97-249.us-west-2.compute.internal
May 10 23:37:59.523: INFO: At 2022-05-10 23:32:41 +0000 UTC - event for pod-subpath-test-dynamicpv-f8h4: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-13a84d36-120f-4573-a479-0135bc27a7bf" 
May 10 23:37:59.523: INFO: At 2022-05-10 23:32:43 +0000 UTC - event for pod-subpath-test-dynamicpv-f8h4: {kubelet ip-172-20-97-249.us-west-2.compute.internal} FailedMount: MountVolume.MountDevice failed for volume "pvc-13a84d36-120f-4573-a479-0135bc27a7bf" : rpc error: code = Internal desc = could not format "/dev/nvme1n1" and mount it at "/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-13a84d36-120f-4573-a479-0135bc27a7bf/globalmount": failed to get disk format of disk /dev/nvme1n1: exit status 127
May 10 23:37:59.523: INFO: At 2022-05-10 23:34:42 +0000 UTC - event for pod-subpath-test-dynamicpv-f8h4: {kubelet ip-172-20-97-249.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[test-volume], unattached volumes=[liveness-probe-volume default-token-bk694 test-volume]: timed out waiting for the condition
May 10 23:37:59.523: INFO: At 2022-05-10 23:36:59 +0000 UTC - event for pod-subpath-test-dynamicpv-f8h4: {kubelet ip-172-20-97-249.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-bk694]: timed out waiting for the condition
May 10 23:37:59.589: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
May 10 23:37:59.589: INFO: 
May 10 23:37:59.656: INFO: 
Logging node info for node ip-172-20-56-40.us-west-2.compute.internal
... skipping 105 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 file as subpath [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:335

    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 83 lines ...
May 10 23:38:19.653: INFO: At 2022-05-10 23:32:53 +0000 UTC - event for ebs.csi.aws.comx24z9: {persistentvolume-controller } WaitForFirstConsumer: waiting for first consumer to be created before binding
May 10 23:38:19.653: INFO: At 2022-05-10 23:32:53 +0000 UTC - event for ebs.csi.aws.comx24z9: {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 10 23:38:19.653: INFO: At 2022-05-10 23:32:53 +0000 UTC - event for ebs.csi.aws.comx24z9: {ebs.csi.aws.com_ebs-csi-controller-d99f59ddb-sgbd9_2a3f19cf-28ce-4bc0-94d5-57006d216d51 } Provisioning: External provisioner is provisioning volume for claim "provisioning-828/ebs.csi.aws.comx24z9"
May 10 23:38:19.653: INFO: At 2022-05-10 23:32:57 +0000 UTC - event for ebs.csi.aws.comx24z9: {ebs.csi.aws.com_ebs-csi-controller-d99f59ddb-sgbd9_2a3f19cf-28ce-4bc0-94d5-57006d216d51 } ProvisioningSucceeded: Successfully provisioned volume pvc-c08ae44a-bd5e-41b3-a0c1-93b2b893e476
May 10 23:38:19.653: INFO: At 2022-05-10 23:32:57 +0000 UTC - event for pod-subpath-test-dynamicpv-tsbc: {default-scheduler } Scheduled: Successfully assigned provisioning-828/pod-subpath-test-dynamicpv-tsbc to ip-172-20-97-249.us-west-2.compute.internal
May 10 23:38:19.653: INFO: At 2022-05-10 23:32:59 +0000 UTC - event for pod-subpath-test-dynamicpv-tsbc: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-c08ae44a-bd5e-41b3-a0c1-93b2b893e476" 
May 10 23:38:19.653: INFO: At 2022-05-10 23:33:05 +0000 UTC - event for pod-subpath-test-dynamicpv-tsbc: {kubelet ip-172-20-97-249.us-west-2.compute.internal} FailedMount: MountVolume.MountDevice failed for volume "pvc-c08ae44a-bd5e-41b3-a0c1-93b2b893e476" : rpc error: code = Internal desc = could not format "/dev/nvme2n1" and mount it at "/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-c08ae44a-bd5e-41b3-a0c1-93b2b893e476/globalmount": failed to get disk format of disk /dev/nvme2n1: exit status 127
May 10 23:38:19.653: INFO: At 2022-05-10 23:35:00 +0000 UTC - event for pod-subpath-test-dynamicpv-tsbc: {kubelet ip-172-20-97-249.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-cxzn7]: timed out waiting for the condition
May 10 23:38:19.653: INFO: At 2022-05-10 23:37:17 +0000 UTC - event for pod-subpath-test-dynamicpv-tsbc: {kubelet ip-172-20-97-249.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[test-volume], unattached volumes=[liveness-probe-volume default-token-cxzn7 test-volume]: timed out waiting for the condition
May 10 23:38:19.719: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
May 10 23:38:19.719: INFO: 
May 10 23:38:19.787: INFO: 
Logging node info for node ip-172-20-56-40.us-west-2.compute.internal
... skipping 106 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 be able to unmount after the subpath directory is deleted [LinuxOnly] [It]
    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:449

    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 119 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 113 lines ...
May 10 23:42:55.654: INFO: At 2022-05-10 23:37:22 +0000 UTC - event for ebs.csi.aws.comzq58q: {persistentvolume-controller } WaitForFirstConsumer: waiting for first consumer to be created before binding
May 10 23:42:55.654: INFO: At 2022-05-10 23:37:22 +0000 UTC - event for ebs.csi.aws.comzq58q: {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 10 23:42:55.654: INFO: At 2022-05-10 23:37:22 +0000 UTC - event for ebs.csi.aws.comzq58q: {ebs.csi.aws.com_ebs-csi-controller-d99f59ddb-sgbd9_2a3f19cf-28ce-4bc0-94d5-57006d216d51 } Provisioning: External provisioner is provisioning volume for claim "volume-expand-2489/ebs.csi.aws.comzq58q"
May 10 23:42:55.654: INFO: At 2022-05-10 23:37:25 +0000 UTC - event for ebs.csi.aws.comzq58q: {ebs.csi.aws.com_ebs-csi-controller-d99f59ddb-sgbd9_2a3f19cf-28ce-4bc0-94d5-57006d216d51 } ProvisioningSucceeded: Successfully provisioned volume pvc-56ed99b9-5bdd-4c5f-9f5d-227232cc7add
May 10 23:42:55.654: INFO: At 2022-05-10 23:37:26 +0000 UTC - event for pod-fe932e24-adc8-4811-b466-b67f30d97423: {default-scheduler } Scheduled: Successfully assigned volume-expand-2489/pod-fe932e24-adc8-4811-b466-b67f30d97423 to ip-172-20-97-249.us-west-2.compute.internal
May 10 23:42:55.654: INFO: At 2022-05-10 23:37:28 +0000 UTC - event for pod-fe932e24-adc8-4811-b466-b67f30d97423: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-56ed99b9-5bdd-4c5f-9f5d-227232cc7add" 
May 10 23:42:55.654: INFO: At 2022-05-10 23:37:42 +0000 UTC - event for pod-fe932e24-adc8-4811-b466-b67f30d97423: {kubelet ip-172-20-97-249.us-west-2.compute.internal} FailedMount: MountVolume.MountDevice failed for volume "pvc-56ed99b9-5bdd-4c5f-9f5d-227232cc7add" : rpc error: code = Internal desc = could not format "/dev/nvme3n1" and mount it at "/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-56ed99b9-5bdd-4c5f-9f5d-227232cc7add/globalmount": failed to get disk format of disk /dev/nvme3n1: exit status 127
May 10 23:42:55.654: INFO: At 2022-05-10 23:39:29 +0000 UTC - event for pod-fe932e24-adc8-4811-b466-b67f30d97423: {kubelet ip-172-20-97-249.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[volume1], unattached volumes=[volume1 default-token-2m8sg]: timed out waiting for the condition
May 10 23:42:55.654: INFO: At 2022-05-10 23:41:44 +0000 UTC - event for pod-fe932e24-adc8-4811-b466-b67f30d97423: {kubelet ip-172-20-97-249.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[volume1], unattached volumes=[default-token-2m8sg volume1]: timed out waiting for the condition
May 10 23:42:55.716: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
May 10 23:42:55.716: INFO: 
May 10 23:42:55.779: INFO: 
Logging node info for node ip-172-20-56-40.us-west-2.compute.internal
... skipping 106 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 | 0xc00108d5b0>: {
            s: "pod \"pod-fe932e24-adc8-4811-b466-b67f30d97423\" is not Running: timed out waiting for the condition",
        }
        pod "pod-fe932e24-adc8-4811-b466-b67f30d97423" is not Running: timed out waiting for the condition
    occurred

... skipping 25 lines ...
May 10 23:42:59.668: INFO: Waiting for pod external-injector to disappear
May 10 23:42:59.734: INFO: Pod external-injector still exists
May 10 23:43:01.735: INFO: Waiting for pod external-injector to disappear
May 10 23:43:01.808: INFO: Pod external-injector still exists
May 10 23:43:03.734: INFO: Waiting for pod external-injector to disappear
May 10 23:43:03.801: INFO: Pod external-injector no longer exists
May 10 23:43:03.801: 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(0x4082b9?)
	/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/tests/e2e-kubernetes/e2e_test.go:82 +0x311
... skipping 17 lines ...
May 10 23:43:19.409: INFO: At 2022-05-10 23:37:59 +0000 UTC - event for ebs.csi.aws.comjgd8s: {persistentvolume-controller } WaitForFirstConsumer: waiting for first consumer to be created before binding
May 10 23:43:19.409: INFO: At 2022-05-10 23:37:59 +0000 UTC - event for ebs.csi.aws.comjgd8s: {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 10 23:43:19.409: INFO: At 2022-05-10 23:37:59 +0000 UTC - event for ebs.csi.aws.comjgd8s: {ebs.csi.aws.com_ebs-csi-controller-d99f59ddb-sgbd9_2a3f19cf-28ce-4bc0-94d5-57006d216d51 } Provisioning: External provisioner is provisioning volume for claim "volume-2287/ebs.csi.aws.comjgd8s"
May 10 23:43:19.409: INFO: At 2022-05-10 23:38:02 +0000 UTC - event for ebs.csi.aws.comjgd8s: {ebs.csi.aws.com_ebs-csi-controller-d99f59ddb-sgbd9_2a3f19cf-28ce-4bc0-94d5-57006d216d51 } ProvisioningSucceeded: Successfully provisioned volume pvc-2a467502-5f18-4540-ad25-b774308e40e9
May 10 23:43:19.409: INFO: At 2022-05-10 23:38:03 +0000 UTC - event for external-injector: {default-scheduler } Scheduled: Successfully assigned volume-2287/external-injector to ip-172-20-97-249.us-west-2.compute.internal
May 10 23:43:19.409: INFO: At 2022-05-10 23:38:05 +0000 UTC - event for external-injector: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-2a467502-5f18-4540-ad25-b774308e40e9" 
May 10 23:43:19.409: INFO: At 2022-05-10 23:38:07 +0000 UTC - event for external-injector: {kubelet ip-172-20-97-249.us-west-2.compute.internal} FailedMount: MountVolume.MountDevice failed for volume "pvc-2a467502-5f18-4540-ad25-b774308e40e9" : rpc error: code = Internal desc = could not format "/dev/nvme1n1" and mount it at "/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-2a467502-5f18-4540-ad25-b774308e40e9/globalmount": failed to get disk format of disk /dev/nvme1n1: exit status 127
May 10 23:43:19.409: INFO: At 2022-05-10 23:40:06 +0000 UTC - event for external-injector: {kubelet ip-172-20-97-249.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[external-volume-0], unattached volumes=[external-volume-0 default-token-htpq6]: timed out waiting for the condition
May 10 23:43:19.474: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
May 10 23:43:19.474: INFO: 
May 10 23:43:19.541: INFO: 
Logging node info for node ip-172-20-56-40.us-west-2.compute.internal
May 10 23:43:19.611: INFO: Node Info: &Node{ObjectMeta:{ip-172-20-56-40.us-west-2.compute.internal    81efae28-5da4-4c6e-bded-c2e063ef39a9 5769 0 2022-05-10 23:18:49 +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-2a kops.k8s.io/instancegroup:nodes-us-west-2a kubernetes.io/arch:amd64 kubernetes.io/hostname:ip-172-20-56-40.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-2a topology.kubernetes.io/region:us-west-2 topology.kubernetes.io/zone:us-west-2a] map[csi.volume.kubernetes.io/nodeid:{"ebs.csi.aws.com":"i-0f19a99d6f747fe4d"} node.alpha.kubernetes.io/ttl:0 volumes.kubernetes.io/controller-managed-attach-detach:true] [] []  [{kops-controller Update v1 2022-05-10 23:18:49 +0000 UTC FieldsV1 {"f:metadata":{"f:labels":{"f:kops.k8s.io/instancegroup":{},"f:kubernetes.io/role":{},"f:node-role.kubernetes.io/node":{}}}}} {kubelet Update v1 2022-05-10 23:19:58 +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":{}}}}} {kube-controller-manager Update v1 2022-05-10 23:37:42 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:node.alpha.kubernetes.io/ttl":{}}},"f:spec":{"f:podCIDR":{},"f:podCIDRs":{".":{},"v:\"100.96.2.0/24\"":{}}},"f:status":{"f:conditions":{"k:{\"type\":\"NetworkUnavailable\"}":{".":{},"f:lastHeartbeatTime":{},"f:lastTransitionTime":{},"f:message":{},"f:reason":{},"f:status":{},"f:type":{}}}}}}]},Spec:NodeSpec{PodCIDR:100.96.2.0/24,DoNotUseExternalID:,ProviderID:aws:///us-west-2a/i-0f19a99d6f747fe4d,Unschedulable:false,Taints:[]Taint{},ConfigSource:nil,PodCIDRs:[100.96.2.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: {{3864977408 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: {{3760119808 0} {<nil>}  BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Phase:,Conditions:[]NodeCondition{NodeCondition{Type:NetworkUnavailable,Status:False,LastHeartbeatTime:2022-05-10 23:18:53 +0000 UTC,LastTransitionTime:2022-05-10 23:18:53 +0000 UTC,Reason:RouteCreated,Message:RouteController created a route,},NodeCondition{Type:MemoryPressure,Status:False,LastHeartbeatTime:2022-05-10 23:40:46 +0000 UTC,LastTransitionTime:2022-05-10 23:18:49 +0000 UTC,Reason:KubeletHasSufficientMemory,Message:kubelet has sufficient memory available,},NodeCondition{Type:DiskPressure,Status:False,LastHeartbeatTime:2022-05-10 23:40:46 +0000 UTC,LastTransitionTime:2022-05-10 23:18:49 +0000 UTC,Reason:KubeletHasNoDiskPressure,Message:kubelet has no disk pressure,},NodeCondition{Type:PIDPressure,Status:False,LastHeartbeatTime:2022-05-10 23:40:46 +0000 UTC,LastTransitionTime:2022-05-10 23:18:49 +0000 UTC,Reason:KubeletHasSufficientPID,Message:kubelet has sufficient PID available,},NodeCondition{Type:Ready,Status:True,LastHeartbeatTime:2022-05-10 23:40:46 +0000 UTC,LastTransitionTime:2022-05-10 23:19:09 +0000 UTC,Reason:KubeletReady,Message:kubelet is posting ready status. AppArmor enabled,},},Addresses:[]NodeAddress{NodeAddress{Type:InternalIP,Address:172.20.56.40,},NodeAddress{Type:ExternalIP,Address:54.190.220.105,},NodeAddress{Type:Hostname,Address:ip-172-20-56-40.us-west-2.compute.internal,},NodeAddress{Type:InternalDNS,Address:ip-172-20-56-40.us-west-2.compute.internal,},NodeAddress{Type:ExternalDNS,Address:ec2-54-190-220-105.us-west-2.compute.amazonaws.com,},},DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:ec26677e61ae0ccaf587f5886b593471,SystemUUID:ec26677e-61ae-0cca-f587-f5886b593471,BootID:1e40e8c7-bda2-4e00-8aa5-724badfe046b,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:12229b0c94723be687fe6e42d4e9b401334f275a84072795a72e5fa54ab0f46e 607362164682.dkr.ecr.us-west-2.amazonaws.com/aws-ebs-csi-driver:3162],SizeBytes:26066741,},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 103 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 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 10 23:43:03.801: 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
------------------------------
External Storage [Driver: ebs.csi.aws.com] [Testpattern: Dynamic PV (block volmode)] multiVolume [Slow] 
  should access to two volumes with the same volume mode and retain data across pod recreation on the same node [LinuxOnly]
  /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/multivolume.go:134
... skipping 45 lines ...
May 10 23:43:35.999: INFO: At 2022-05-10 23:38:02 +0000 UTC - event for ebs.csi.aws.comptxnw: {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 10 23:43:35.999: INFO: At 2022-05-10 23:38:05 +0000 UTC - event for ebs.csi.aws.comptxnw: {ebs.csi.aws.com_ebs-csi-controller-d99f59ddb-sgbd9_2a3f19cf-28ce-4bc0-94d5-57006d216d51 } ProvisioningSucceeded: Successfully provisioned volume pvc-82358d2b-7ec2-4c0b-bb82-da76c63f3a60
May 10 23:43:35.999: INFO: At 2022-05-10 23:38:06 +0000 UTC - event for ebs.csi.aws.com92z8m: {ebs.csi.aws.com_ebs-csi-controller-d99f59ddb-sgbd9_2a3f19cf-28ce-4bc0-94d5-57006d216d51 } ProvisioningSucceeded: Successfully provisioned volume pvc-68a9685d-2488-42c0-a106-b70ce0ffe5df
May 10 23:43:35.999: INFO: At 2022-05-10 23:38:06 +0000 UTC - event for pod-7d7af84b-3e8f-4ad6-9ef0-3a26b3b4cdb7: {default-scheduler } Scheduled: Successfully assigned multivolume-4168/pod-7d7af84b-3e8f-4ad6-9ef0-3a26b3b4cdb7 to ip-172-20-97-249.us-west-2.compute.internal
May 10 23:43:35.999: INFO: At 2022-05-10 23:38:10 +0000 UTC - event for pod-7d7af84b-3e8f-4ad6-9ef0-3a26b3b4cdb7: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-82358d2b-7ec2-4c0b-bb82-da76c63f3a60" 
May 10 23:43:35.999: INFO: At 2022-05-10 23:38:10 +0000 UTC - event for pod-7d7af84b-3e8f-4ad6-9ef0-3a26b3b4cdb7: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-68a9685d-2488-42c0-a106-b70ce0ffe5df" 
May 10 23:43:35.999: INFO: At 2022-05-10 23:38:22 +0000 UTC - event for pod-7d7af84b-3e8f-4ad6-9ef0-3a26b3b4cdb7: {kubelet ip-172-20-97-249.us-west-2.compute.internal} FailedMapVolume: MapVolume.MapPodDevice failed for volume "pvc-82358d2b-7ec2-4c0b-bb82-da76c63f3a60" : rpc error: code = Internal desc = Could not mount "/dev/nvme4n1" at "/var/lib/kubelet/plugins/kubernetes.io/csi/volumeDevices/publish/pvc-82358d2b-7ec2-4c0b-bb82-da76c63f3a60/03954b5d-59d0-4ff0-814d-67acdbf5e198": 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-82358d2b-7ec2-4c0b-bb82-da76c63f3a60/03954b5d-59d0-4ff0-814d-67acdbf5e198
Output: 
May 10 23:43:35.999: INFO: At 2022-05-10 23:38:22 +0000 UTC - event for pod-7d7af84b-3e8f-4ad6-9ef0-3a26b3b4cdb7: {kubelet ip-172-20-97-249.us-west-2.compute.internal} FailedMapVolume: MapVolume.MapPodDevice failed for volume "pvc-68a9685d-2488-42c0-a106-b70ce0ffe5df" : rpc error: code = Internal desc = Could not mount "/dev/nvme2n1" at "/var/lib/kubelet/plugins/kubernetes.io/csi/volumeDevices/publish/pvc-68a9685d-2488-42c0-a106-b70ce0ffe5df/03954b5d-59d0-4ff0-814d-67acdbf5e198": 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-68a9685d-2488-42c0-a106-b70ce0ffe5df/03954b5d-59d0-4ff0-814d-67acdbf5e198
Output: 
May 10 23:43:35.999: INFO: At 2022-05-10 23:40:09 +0000 UTC - event for pod-7d7af84b-3e8f-4ad6-9ef0-3a26b3b4cdb7: {kubelet ip-172-20-97-249.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[volume2 volume1], unattached volumes=[default-token-hsb2d volume2 volume1]: timed out waiting for the condition
May 10 23:43:35.999: INFO: At 2022-05-10 23:42:27 +0000 UTC - event for pod-7d7af84b-3e8f-4ad6-9ef0-3a26b3b4cdb7: {kubelet ip-172-20-97-249.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[volume1 volume2], unattached volumes=[default-token-hsb2d volume1 volume2]: timed out waiting for the condition
May 10 23:43:36.064: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
... skipping 107 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 | 0xc000c187a0>: {
            s: "pod \"pod-7d7af84b-3e8f-4ad6-9ef0-3a26b3b4cdb7\" is not Running: timed out waiting for the condition",
        }
        pod "pod-7d7af84b-3e8f-4ad6-9ef0-3a26b3b4cdb7" is not Running: timed out waiting for the condition
    occurred

... skipping 52 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 6 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 101 lines ...
May 10 23:38:23.356: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(ebs.csi.aws.com) supported size:{ 1Mi} 
STEP: creating a StorageClass volume-1429-e2e-sc6j4fv
STEP: creating a claim
May 10 23:38:23.424: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
STEP: Creating pod exec-volume-test-dynamicpv-vrht
STEP: Creating a pod to test exec-volume-test
May 10 23:38:23.635: INFO: Waiting up to 5m0s for pod "exec-volume-test-dynamicpv-vrht" in namespace "volume-1429" to be "Succeeded or Failed"
May 10 23:38:23.702: INFO: Pod "exec-volume-test-dynamicpv-vrht": Phase="Pending", Reason="", readiness=false. Elapsed: 66.735299ms
May 10 23:38:25.770: INFO: Pod "exec-volume-test-dynamicpv-vrht": Phase="Pending", Reason="", readiness=false. Elapsed: 2.134756361s
May 10 23:38:27.838: INFO: Pod "exec-volume-test-dynamicpv-vrht": Phase="Pending", Reason="", readiness=false. Elapsed: 4.202489921s
May 10 23:38:29.905: INFO: Pod "exec-volume-test-dynamicpv-vrht": Phase="Pending", Reason="", readiness=false. Elapsed: 6.269605329s
May 10 23:38:31.973: INFO: Pod "exec-volume-test-dynamicpv-vrht": Phase="Pending", Reason="", readiness=false. Elapsed: 8.337276641s
May 10 23:38:34.040: INFO: Pod "exec-volume-test-dynamicpv-vrht": Phase="Pending", Reason="", readiness=false. Elapsed: 10.404899454s
... skipping 134 lines ...
May 10 23:43:13.301: INFO: Pod "exec-volume-test-dynamicpv-vrht": Phase="Pending", Reason="", readiness=false. Elapsed: 4m49.666028094s
May 10 23:43:15.370: INFO: Pod "exec-volume-test-dynamicpv-vrht": Phase="Pending", Reason="", readiness=false. Elapsed: 4m51.73447044s
May 10 23:43:17.438: INFO: Pod "exec-volume-test-dynamicpv-vrht": Phase="Pending", Reason="", readiness=false. Elapsed: 4m53.802433569s
May 10 23:43:19.510: INFO: Pod "exec-volume-test-dynamicpv-vrht": Phase="Pending", Reason="", readiness=false. Elapsed: 4m55.874269376s
May 10 23:43:21.577: INFO: Pod "exec-volume-test-dynamicpv-vrht": Phase="Pending", Reason="", readiness=false. Elapsed: 4m57.942032279s
May 10 23:43:23.645: INFO: Pod "exec-volume-test-dynamicpv-vrht": Phase="Pending", Reason="", readiness=false. Elapsed: 5m0.009906596s
May 10 23:43:25.785: INFO: Failed to get logs from node "ip-172-20-97-249.us-west-2.compute.internal" pod "exec-volume-test-dynamicpv-vrht" container "exec-container-dynamicpv-vrht": the server rejected our request for an unknown reason (get pods exec-volume-test-dynamicpv-vrht)
STEP: delete the pod
May 10 23:43:25.854: INFO: Waiting for pod exec-volume-test-dynamicpv-vrht to disappear
May 10 23:43:25.920: INFO: Pod exec-volume-test-dynamicpv-vrht still exists
May 10 23:43:27.921: INFO: Waiting for pod exec-volume-test-dynamicpv-vrht to disappear
May 10 23:43:27.987: INFO: Pod exec-volume-test-dynamicpv-vrht still exists
May 10 23:43:29.921: INFO: Waiting for pod exec-volume-test-dynamicpv-vrht to disappear
... skipping 17 lines ...
May 10 23:43:49.600: INFO: At 2022-05-10 23:38:23 +0000 UTC - event for ebs.csi.aws.comnfzm5: {persistentvolume-controller } WaitForFirstConsumer: waiting for first consumer to be created before binding
May 10 23:43:49.600: INFO: At 2022-05-10 23:38:23 +0000 UTC - event for ebs.csi.aws.comnfzm5: {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 10 23:43:49.600: INFO: At 2022-05-10 23:38:23 +0000 UTC - event for ebs.csi.aws.comnfzm5: {ebs.csi.aws.com_ebs-csi-controller-d99f59ddb-sgbd9_2a3f19cf-28ce-4bc0-94d5-57006d216d51 } Provisioning: External provisioner is provisioning volume for claim "volume-1429/ebs.csi.aws.comnfzm5"
May 10 23:43:49.600: INFO: At 2022-05-10 23:38:26 +0000 UTC - event for ebs.csi.aws.comnfzm5: {ebs.csi.aws.com_ebs-csi-controller-d99f59ddb-sgbd9_2a3f19cf-28ce-4bc0-94d5-57006d216d51 } ProvisioningSucceeded: Successfully provisioned volume pvc-8bc010b4-6351-4be7-90c1-43cecab17e9a
May 10 23:43:49.600: INFO: At 2022-05-10 23:38:27 +0000 UTC - event for exec-volume-test-dynamicpv-vrht: {default-scheduler } Scheduled: Successfully assigned volume-1429/exec-volume-test-dynamicpv-vrht to ip-172-20-97-249.us-west-2.compute.internal
May 10 23:43:49.600: INFO: At 2022-05-10 23:38:29 +0000 UTC - event for exec-volume-test-dynamicpv-vrht: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-8bc010b4-6351-4be7-90c1-43cecab17e9a" 
May 10 23:43:49.600: INFO: At 2022-05-10 23:38:43 +0000 UTC - event for exec-volume-test-dynamicpv-vrht: {kubelet ip-172-20-97-249.us-west-2.compute.internal} FailedMount: MountVolume.MountDevice failed for volume "pvc-8bc010b4-6351-4be7-90c1-43cecab17e9a" : rpc error: code = Internal desc = could not format "/dev/nvme5n1" and mount it at "/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-8bc010b4-6351-4be7-90c1-43cecab17e9a/globalmount": failed to get disk format of disk /dev/nvme5n1: exit status 127
May 10 23:43:49.600: INFO: At 2022-05-10 23:40:30 +0000 UTC - event for exec-volume-test-dynamicpv-vrht: {kubelet ip-172-20-97-249.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[vol1], unattached volumes=[vol1 default-token-mnvkt]: timed out waiting for the condition
May 10 23:43:49.666: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
May 10 23:43:49.666: INFO: 
May 10 23:43:49.733: INFO: 
Logging node info for node ip-172-20-56-40.us-west-2.compute.internal
May 10 23:43:49.799: INFO: Node Info: &Node{ObjectMeta:{ip-172-20-56-40.us-west-2.compute.internal    81efae28-5da4-4c6e-bded-c2e063ef39a9 5769 0 2022-05-10 23:18:49 +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-2a kops.k8s.io/instancegroup:nodes-us-west-2a kubernetes.io/arch:amd64 kubernetes.io/hostname:ip-172-20-56-40.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-2a topology.kubernetes.io/region:us-west-2 topology.kubernetes.io/zone:us-west-2a] map[csi.volume.kubernetes.io/nodeid:{"ebs.csi.aws.com":"i-0f19a99d6f747fe4d"} node.alpha.kubernetes.io/ttl:0 volumes.kubernetes.io/controller-managed-attach-detach:true] [] []  [{kops-controller Update v1 2022-05-10 23:18:49 +0000 UTC FieldsV1 {"f:metadata":{"f:labels":{"f:kops.k8s.io/instancegroup":{},"f:kubernetes.io/role":{},"f:node-role.kubernetes.io/node":{}}}}} {kubelet Update v1 2022-05-10 23:19:58 +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":{}}}}} {kube-controller-manager Update v1 2022-05-10 23:37:42 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:node.alpha.kubernetes.io/ttl":{}}},"f:spec":{"f:podCIDR":{},"f:podCIDRs":{".":{},"v:\"100.96.2.0/24\"":{}}},"f:status":{"f:conditions":{"k:{\"type\":\"NetworkUnavailable\"}":{".":{},"f:lastHeartbeatTime":{},"f:lastTransitionTime":{},"f:message":{},"f:reason":{},"f:status":{},"f:type":{}}}}}}]},Spec:NodeSpec{PodCIDR:100.96.2.0/24,DoNotUseExternalID:,ProviderID:aws:///us-west-2a/i-0f19a99d6f747fe4d,Unschedulable:false,Taints:[]Taint{},ConfigSource:nil,PodCIDRs:[100.96.2.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: {{3864977408 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: {{3760119808 0} {<nil>}  BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Phase:,Conditions:[]NodeCondition{NodeCondition{Type:NetworkUnavailable,Status:False,LastHeartbeatTime:2022-05-10 23:18:53 +0000 UTC,LastTransitionTime:2022-05-10 23:18:53 +0000 UTC,Reason:RouteCreated,Message:RouteController created a route,},NodeCondition{Type:MemoryPressure,Status:False,LastHeartbeatTime:2022-05-10 23:40:46 +0000 UTC,LastTransitionTime:2022-05-10 23:18:49 +0000 UTC,Reason:KubeletHasSufficientMemory,Message:kubelet has sufficient memory available,},NodeCondition{Type:DiskPressure,Status:False,LastHeartbeatTime:2022-05-10 23:40:46 +0000 UTC,LastTransitionTime:2022-05-10 23:18:49 +0000 UTC,Reason:KubeletHasNoDiskPressure,Message:kubelet has no disk pressure,},NodeCondition{Type:PIDPressure,Status:False,LastHeartbeatTime:2022-05-10 23:40:46 +0000 UTC,LastTransitionTime:2022-05-10 23:18:49 +0000 UTC,Reason:KubeletHasSufficientPID,Message:kubelet has sufficient PID available,},NodeCondition{Type:Ready,Status:True,LastHeartbeatTime:2022-05-10 23:40:46 +0000 UTC,LastTransitionTime:2022-05-10 23:19:09 +0000 UTC,Reason:KubeletReady,Message:kubelet is posting ready status. AppArmor enabled,},},Addresses:[]NodeAddress{NodeAddress{Type:InternalIP,Address:172.20.56.40,},NodeAddress{Type:ExternalIP,Address:54.190.220.105,},NodeAddress{Type:Hostname,Address:ip-172-20-56-40.us-west-2.compute.internal,},NodeAddress{Type:InternalDNS,Address:ip-172-20-56-40.us-west-2.compute.internal,},NodeAddress{Type:ExternalDNS,Address:ec2-54-190-220-105.us-west-2.compute.amazonaws.com,},},DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:ec26677e61ae0ccaf587f5886b593471,SystemUUID:ec26677e-61ae-0cca-f587-f5886b593471,BootID:1e40e8c7-bda2-4e00-8aa5-724badfe046b,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:12229b0c94723be687fe6e42d4e9b401334f275a84072795a72e5fa54ab0f46e 607362164682.dkr.ecr.us-west-2.amazonaws.com/aws-ebs-csi-driver:3162],SizeBytes:26066741,},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 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 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 | 0xc00130bad0>: {
            s: "expected pod \"exec-volume-test-dynamicpv-vrht\" success: Gave up after waiting 5m0s for pod \"exec-volume-test-dynamicpv-vrht\" to be \"Succeeded or Failed\"",
        }
        expected pod "exec-volume-test-dynamicpv-vrht" success: Gave up after waiting 5m0s for pod "exec-volume-test-dynamicpv-vrht" 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
------------------------------
SS
------------------------------
... skipping 33 lines ...
May 10 23:43:52.225: INFO: Creating resource for dynamic PV
May 10 23:43:52.225: INFO: Using claimSize:1Gi, test suite supported size:{ 1Gi}, driver(ebs.csi.aws.com) supported size:{ 1Gi} 
STEP: creating a StorageClass volume-expand-2367-e2e-sc4gblh
STEP: creating a claim
STEP: Expanding non-expandable pvc
May 10 23:43:52.428: INFO: currentPvcSize {{1073741824 0} {<nil>} 1Gi BinarySI}, newSize {{2147483648 0} {<nil>}  BinarySI}
May 10 23:43:52.568: INFO: Error updating pvc ebs.csi.aws.comncd4c: PersistentVolumeClaim "ebs.csi.aws.comncd4c" 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-2367-e2e-sc4gblh",
  	... // 2 identical fields
  }

May 10 23:43:54.704: INFO: Error updating pvc ebs.csi.aws.comncd4c: PersistentVolumeClaim "ebs.csi.aws.comncd4c" 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-2367-e2e-sc4gblh",
  	... // 2 identical fields
  }

May 10 23:43:56.704: INFO: Error updating pvc ebs.csi.aws.comncd4c: PersistentVolumeClaim "ebs.csi.aws.comncd4c" 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-2367-e2e-sc4gblh",
  	... // 2 identical fields
  }

May 10 23:43:58.713: INFO: Error updating pvc ebs.csi.aws.comncd4c: PersistentVolumeClaim "ebs.csi.aws.comncd4c" 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-2367-e2e-sc4gblh",
  	... // 2 identical fields
  }

May 10 23:44:00.703: INFO: Error updating pvc ebs.csi.aws.comncd4c: PersistentVolumeClaim "ebs.csi.aws.comncd4c" 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-2367-e2e-sc4gblh",
  	... // 2 identical fields
  }

May 10 23:44:02.704: INFO: Error updating pvc ebs.csi.aws.comncd4c: PersistentVolumeClaim "ebs.csi.aws.comncd4c" 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-2367-e2e-sc4gblh",
  	... // 2 identical fields
  }

May 10 23:44:04.703: INFO: Error updating pvc ebs.csi.aws.comncd4c: PersistentVolumeClaim "ebs.csi.aws.comncd4c" 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-2367-e2e-sc4gblh",
  	... // 2 identical fields
  }

May 10 23:44:06.705: INFO: Error updating pvc ebs.csi.aws.comncd4c: PersistentVolumeClaim "ebs.csi.aws.comncd4c" 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-2367-e2e-sc4gblh",
  	... // 2 identical fields
  }

May 10 23:44:08.705: INFO: Error updating pvc ebs.csi.aws.comncd4c: PersistentVolumeClaim "ebs.csi.aws.comncd4c" 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-2367-e2e-sc4gblh",
  	... // 2 identical fields
  }

May 10 23:44:10.703: INFO: Error updating pvc ebs.csi.aws.comncd4c: PersistentVolumeClaim "ebs.csi.aws.comncd4c" 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-2367-e2e-sc4gblh",
  	... // 2 identical fields
  }

May 10 23:44:12.713: INFO: Error updating pvc ebs.csi.aws.comncd4c: PersistentVolumeClaim "ebs.csi.aws.comncd4c" 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-2367-e2e-sc4gblh",
  	... // 2 identical fields
  }

May 10 23:44:14.705: INFO: Error updating pvc ebs.csi.aws.comncd4c: PersistentVolumeClaim "ebs.csi.aws.comncd4c" 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-2367-e2e-sc4gblh",
  	... // 2 identical fields
  }

May 10 23:44:16.704: INFO: Error updating pvc ebs.csi.aws.comncd4c: PersistentVolumeClaim "ebs.csi.aws.comncd4c" 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-2367-e2e-sc4gblh",
  	... // 2 identical fields
  }

May 10 23:44:18.706: INFO: Error updating pvc ebs.csi.aws.comncd4c: PersistentVolumeClaim "ebs.csi.aws.comncd4c" 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-2367-e2e-sc4gblh",
  	... // 2 identical fields
  }

May 10 23:44:20.706: INFO: Error updating pvc ebs.csi.aws.comncd4c: PersistentVolumeClaim "ebs.csi.aws.comncd4c" 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-2367-e2e-sc4gblh",
  	... // 2 identical fields
  }

May 10 23:44:22.705: INFO: Error updating pvc ebs.csi.aws.comncd4c: PersistentVolumeClaim "ebs.csi.aws.comncd4c" 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-2367-e2e-sc4gblh",
  	... // 2 identical fields
  }

May 10 23:44:22.845: INFO: Error updating pvc ebs.csi.aws.comncd4c: PersistentVolumeClaim "ebs.csi.aws.comncd4c" 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 64 lines ...
May 10 23:42:58.439: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(ebs.csi.aws.com) supported size:{ 1Mi} 
STEP: creating a StorageClass provisioning-7469-e2e-sc4777x
STEP: creating a claim
May 10 23:42:58.501: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
STEP: Creating pod pod-subpath-test-dynamicpv-rk5d
STEP: Creating a pod to test multi_subpath
May 10 23:42:58.691: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-rk5d" in namespace "provisioning-7469" to be "Succeeded or Failed"
May 10 23:42:58.758: INFO: Pod "pod-subpath-test-dynamicpv-rk5d": Phase="Pending", Reason="", readiness=false. Elapsed: 67.018854ms
May 10 23:43:00.820: INFO: Pod "pod-subpath-test-dynamicpv-rk5d": Phase="Pending", Reason="", readiness=false. Elapsed: 2.129090276s
May 10 23:43:02.883: INFO: Pod "pod-subpath-test-dynamicpv-rk5d": Phase="Pending", Reason="", readiness=false. Elapsed: 4.192061083s
May 10 23:43:04.946: INFO: Pod "pod-subpath-test-dynamicpv-rk5d": Phase="Pending", Reason="", readiness=false. Elapsed: 6.25533131s
May 10 23:43:07.007: INFO: Pod "pod-subpath-test-dynamicpv-rk5d": Phase="Pending", Reason="", readiness=false. Elapsed: 8.316690461s
May 10 23:43:09.070: INFO: Pod "pod-subpath-test-dynamicpv-rk5d": Phase="Pending", Reason="", readiness=false. Elapsed: 10.379298642s
... skipping 134 lines ...
May 10 23:47:47.630: INFO: Pod "pod-subpath-test-dynamicpv-rk5d": Phase="Pending", Reason="", readiness=false. Elapsed: 4m48.939479268s
May 10 23:47:49.693: INFO: Pod "pod-subpath-test-dynamicpv-rk5d": Phase="Pending", Reason="", readiness=false. Elapsed: 4m51.002145168s
May 10 23:47:51.756: INFO: Pod "pod-subpath-test-dynamicpv-rk5d": Phase="Pending", Reason="", readiness=false. Elapsed: 4m53.064906141s
May 10 23:47:53.818: INFO: Pod "pod-subpath-test-dynamicpv-rk5d": Phase="Pending", Reason="", readiness=false. Elapsed: 4m55.127786757s
May 10 23:47:55.880: INFO: Pod "pod-subpath-test-dynamicpv-rk5d": Phase="Pending", Reason="", readiness=false. Elapsed: 4m57.189815988s
May 10 23:47:57.945: INFO: Pod "pod-subpath-test-dynamicpv-rk5d": Phase="Pending", Reason="", readiness=false. Elapsed: 4m59.254625095s
May 10 23:48:00.095: INFO: Failed to get logs from node "ip-172-20-97-249.us-west-2.compute.internal" pod "pod-subpath-test-dynamicpv-rk5d" container "init-volume-dynamicpv-rk5d": the server rejected our request for an unknown reason (get pods pod-subpath-test-dynamicpv-rk5d)
May 10 23:48:00.158: INFO: Failed to get logs from node "ip-172-20-97-249.us-west-2.compute.internal" pod "pod-subpath-test-dynamicpv-rk5d" container "test-container-subpath-dynamicpv-rk5d": the server rejected our request for an unknown reason (get pods pod-subpath-test-dynamicpv-rk5d)
STEP: delete the pod
May 10 23:48:00.221: INFO: Waiting for pod pod-subpath-test-dynamicpv-rk5d to disappear
May 10 23:48:00.283: INFO: Pod pod-subpath-test-dynamicpv-rk5d still exists
May 10 23:48:02.283: INFO: Waiting for pod pod-subpath-test-dynamicpv-rk5d to disappear
May 10 23:48:02.345: INFO: Pod pod-subpath-test-dynamicpv-rk5d still exists
May 10 23:48:04.285: INFO: Waiting for pod pod-subpath-test-dynamicpv-rk5d to disappear
... skipping 16 lines ...
May 10 23:48:25.076: INFO: At 2022-05-10 23:42:58 +0000 UTC - event for ebs.csi.aws.comcrd7w: {persistentvolume-controller } WaitForFirstConsumer: waiting for first consumer to be created before binding
May 10 23:48:25.076: INFO: At 2022-05-10 23:42:58 +0000 UTC - event for ebs.csi.aws.comcrd7w: {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 10 23:48:25.076: INFO: At 2022-05-10 23:42:58 +0000 UTC - event for ebs.csi.aws.comcrd7w: {ebs.csi.aws.com_ebs-csi-controller-d99f59ddb-sgbd9_2a3f19cf-28ce-4bc0-94d5-57006d216d51 } Provisioning: External provisioner is provisioning volume for claim "provisioning-7469/ebs.csi.aws.comcrd7w"
May 10 23:48:25.076: INFO: At 2022-05-10 23:43:02 +0000 UTC - event for ebs.csi.aws.comcrd7w: {ebs.csi.aws.com_ebs-csi-controller-d99f59ddb-sgbd9_2a3f19cf-28ce-4bc0-94d5-57006d216d51 } ProvisioningSucceeded: Successfully provisioned volume pvc-d3bcf037-6f6b-4cf5-a218-3aba64576653
May 10 23:48:25.076: INFO: At 2022-05-10 23:43:02 +0000 UTC - event for pod-subpath-test-dynamicpv-rk5d: {default-scheduler } Scheduled: Successfully assigned provisioning-7469/pod-subpath-test-dynamicpv-rk5d to ip-172-20-97-249.us-west-2.compute.internal
May 10 23:48:25.076: INFO: At 2022-05-10 23:43:04 +0000 UTC - event for pod-subpath-test-dynamicpv-rk5d: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-d3bcf037-6f6b-4cf5-a218-3aba64576653" 
May 10 23:48:25.076: INFO: At 2022-05-10 23:43:10 +0000 UTC - event for pod-subpath-test-dynamicpv-rk5d: {kubelet ip-172-20-97-249.us-west-2.compute.internal} FailedMount: MountVolume.MountDevice failed for volume "pvc-d3bcf037-6f6b-4cf5-a218-3aba64576653" : rpc error: code = Internal desc = could not format "/dev/nvme3n1" and mount it at "/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-d3bcf037-6f6b-4cf5-a218-3aba64576653/globalmount": failed to get disk format of disk /dev/nvme3n1: exit status 127
May 10 23:48:25.076: INFO: At 2022-05-10 23:45:05 +0000 UTC - event for pod-subpath-test-dynamicpv-rk5d: {kubelet ip-172-20-97-249.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-9nptc]: timed out waiting for the condition
May 10 23:48:25.137: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
May 10 23:48:25.137: INFO: 
May 10 23:48:25.200: INFO: 
Logging node info for node ip-172-20-56-40.us-west-2.compute.internal
May 10 23:48:25.262: INFO: Node Info: &Node{ObjectMeta:{ip-172-20-56-40.us-west-2.compute.internal    81efae28-5da4-4c6e-bded-c2e063ef39a9 6985 0 2022-05-10 23:18:49 +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-2a kops.k8s.io/instancegroup:nodes-us-west-2a kubernetes.io/arch:amd64 kubernetes.io/hostname:ip-172-20-56-40.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-2a topology.kubernetes.io/region:us-west-2 topology.kubernetes.io/zone:us-west-2a] map[csi.volume.kubernetes.io/nodeid:{"ebs.csi.aws.com":"i-0f19a99d6f747fe4d"} node.alpha.kubernetes.io/ttl:0 volumes.kubernetes.io/controller-managed-attach-detach:true] [] []  [{kops-controller Update v1 2022-05-10 23:18:49 +0000 UTC FieldsV1 {"f:metadata":{"f:labels":{"f:kops.k8s.io/instancegroup":{},"f:kubernetes.io/role":{},"f:node-role.kubernetes.io/node":{}}}}} {kubelet Update v1 2022-05-10 23:19:58 +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":{}}}}} {kube-controller-manager Update v1 2022-05-10 23:37:42 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:node.alpha.kubernetes.io/ttl":{}}},"f:spec":{"f:podCIDR":{},"f:podCIDRs":{".":{},"v:\"100.96.2.0/24\"":{}}},"f:status":{"f:conditions":{"k:{\"type\":\"NetworkUnavailable\"}":{".":{},"f:lastHeartbeatTime":{},"f:lastTransitionTime":{},"f:message":{},"f:reason":{},"f:status":{},"f:type":{}}}}}}]},Spec:NodeSpec{PodCIDR:100.96.2.0/24,DoNotUseExternalID:,ProviderID:aws:///us-west-2a/i-0f19a99d6f747fe4d,Unschedulable:false,Taints:[]Taint{},ConfigSource:nil,PodCIDRs:[100.96.2.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: {{3864977408 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: {{3760119808 0} {<nil>}  BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Phase:,Conditions:[]NodeCondition{NodeCondition{Type:NetworkUnavailable,Status:False,LastHeartbeatTime:2022-05-10 23:18:53 +0000 UTC,LastTransitionTime:2022-05-10 23:18:53 +0000 UTC,Reason:RouteCreated,Message:RouteController created a route,},NodeCondition{Type:MemoryPressure,Status:False,LastHeartbeatTime:2022-05-10 23:45:48 +0000 UTC,LastTransitionTime:2022-05-10 23:18:49 +0000 UTC,Reason:KubeletHasSufficientMemory,Message:kubelet has sufficient memory available,},NodeCondition{Type:DiskPressure,Status:False,LastHeartbeatTime:2022-05-10 23:45:48 +0000 UTC,LastTransitionTime:2022-05-10 23:18:49 +0000 UTC,Reason:KubeletHasNoDiskPressure,Message:kubelet has no disk pressure,},NodeCondition{Type:PIDPressure,Status:False,LastHeartbeatTime:2022-05-10 23:45:48 +0000 UTC,LastTransitionTime:2022-05-10 23:18:49 +0000 UTC,Reason:KubeletHasSufficientPID,Message:kubelet has sufficient PID available,},NodeCondition{Type:Ready,Status:True,LastHeartbeatTime:2022-05-10 23:45:48 +0000 UTC,LastTransitionTime:2022-05-10 23:19:09 +0000 UTC,Reason:KubeletReady,Message:kubelet is posting ready status. AppArmor enabled,},},Addresses:[]NodeAddress{NodeAddress{Type:InternalIP,Address:172.20.56.40,},NodeAddress{Type:ExternalIP,Address:54.190.220.105,},NodeAddress{Type:Hostname,Address:ip-172-20-56-40.us-west-2.compute.internal,},NodeAddress{Type:InternalDNS,Address:ip-172-20-56-40.us-west-2.compute.internal,},NodeAddress{Type:ExternalDNS,Address:ec2-54-190-220-105.us-west-2.compute.amazonaws.com,},},DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:ec26677e61ae0ccaf587f5886b593471,SystemUUID:ec26677e-61ae-0cca-f587-f5886b593471,BootID:1e40e8c7-bda2-4e00-8aa5-724badfe046b,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:12229b0c94723be687fe6e42d4e9b401334f275a84072795a72e5fa54ab0f46e 607362164682.dkr.ecr.us-west-2.amazonaws.com/aws-ebs-csi-driver:3162],SizeBytes:26066741,},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 104 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 creating multiple subpath from same volumes [Slow] [It]
    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:294

    Unexpected error:
        <*errors.errorString | 0xc001146970>: {
            s: "expected pod \"pod-subpath-test-dynamicpv-rk5d\" success: Gave up after waiting 5m0s for pod \"pod-subpath-test-dynamicpv-rk5d\" to be \"Succeeded or Failed\"",
        }
        expected pod "pod-subpath-test-dynamicpv-rk5d" success: Gave up after waiting 5m0s for pod "pod-subpath-test-dynamicpv-rk5d" 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 117 lines ...
May 10 23:48:50.346: INFO: At 2022-05-10 23:43:22 +0000 UTC - event for ebs.csi.aws.com5xp6x: {persistentvolume-controller } WaitForFirstConsumer: waiting for first consumer to be created before binding
May 10 23:48:50.346: INFO: At 2022-05-10 23:43:22 +0000 UTC - event for ebs.csi.aws.com5xp6x: {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 10 23:48:50.346: INFO: At 2022-05-10 23:43:22 +0000 UTC - event for ebs.csi.aws.com5xp6x: {ebs.csi.aws.com_ebs-csi-controller-d99f59ddb-sgbd9_2a3f19cf-28ce-4bc0-94d5-57006d216d51 } Provisioning: External provisioner is provisioning volume for claim "volume-expand-5988/ebs.csi.aws.com5xp6x"
May 10 23:48:50.346: INFO: At 2022-05-10 23:43:25 +0000 UTC - event for ebs.csi.aws.com5xp6x: {ebs.csi.aws.com_ebs-csi-controller-d99f59ddb-sgbd9_2a3f19cf-28ce-4bc0-94d5-57006d216d51 } ProvisioningSucceeded: Successfully provisioned volume pvc-b4ee61bc-5e27-407d-b355-d6215b9c99cc
May 10 23:48:50.346: INFO: At 2022-05-10 23:43:26 +0000 UTC - event for pod-bc28a56b-edb5-47da-94cd-fad32c9943e5: {default-scheduler } Scheduled: Successfully assigned volume-expand-5988/pod-bc28a56b-edb5-47da-94cd-fad32c9943e5 to ip-172-20-97-249.us-west-2.compute.internal
May 10 23:48:50.346: INFO: At 2022-05-10 23:43:28 +0000 UTC - event for pod-bc28a56b-edb5-47da-94cd-fad32c9943e5: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-b4ee61bc-5e27-407d-b355-d6215b9c99cc" 
May 10 23:48:50.346: INFO: At 2022-05-10 23:43:30 +0000 UTC - event for pod-bc28a56b-edb5-47da-94cd-fad32c9943e5: {kubelet ip-172-20-97-249.us-west-2.compute.internal} FailedMapVolume: MapVolume.MapPodDevice failed for volume "pvc-b4ee61bc-5e27-407d-b355-d6215b9c99cc" : rpc error: code = Internal desc = Could not mount "/dev/nvme1n1" at "/var/lib/kubelet/plugins/kubernetes.io/csi/volumeDevices/publish/pvc-b4ee61bc-5e27-407d-b355-d6215b9c99cc/d2b4dca7-96c1-4992-8a79-084c68a2cb8a": mount failed: exec: "mount": executable file not found in $PATH
Mounting command: mount
Mounting arguments:  -o bind /dev/nvme1n1 /var/lib/kubelet/plugins/kubernetes.io/csi/volumeDevices/publish/pvc-b4ee61bc-5e27-407d-b355-d6215b9c99cc/d2b4dca7-96c1-4992-8a79-084c68a2cb8a
Output: 
May 10 23:48:50.346: INFO: At 2022-05-10 23:45:29 +0000 UTC - event for pod-bc28a56b-edb5-47da-94cd-fad32c9943e5: {kubelet ip-172-20-97-249.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[volume1], unattached volumes=[volume1 default-token-lpw8n]: timed out waiting for the condition
May 10 23:48:50.346: INFO: At 2022-05-10 23:47:47 +0000 UTC - event for pod-bc28a56b-edb5-47da-94cd-fad32c9943e5: {kubelet ip-172-20-97-249.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[volume1], unattached volumes=[default-token-lpw8n volume1]: timed out waiting for the condition
May 10 23:48:50.411: INFO: POD  NODE  PHASE  GRACE  CONDITIONS
... skipping 109 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
    should resize volume when PVC is edited while pod is using it [It]
    /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/volume_expand.go:246

    While creating pods for resizing
    Unexpected error:
        <*errors.errorString | 0xc000e02c40>: {
            s: "pod \"pod-bc28a56b-edb5-47da-94cd-fad32c9943e5\" is not Running: timed out waiting for the condition",
        }
        pod "pod-bc28a56b-edb5-47da-94cd-fad32c9943e5" is not Running: timed out waiting for the condition
    occurred

... skipping 92 lines ...
May 10 23:54:28.439: INFO: At 2022-05-10 23:44:23 +0000 UTC - event for ebs.csi.aws.com5xt6c: {persistentvolume-controller } WaitForFirstConsumer: waiting for first consumer to be created before binding
May 10 23:54:28.439: INFO: At 2022-05-10 23:44:23 +0000 UTC - event for ebs.csi.aws.com5xt6c: {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 10 23:54:28.439: INFO: At 2022-05-10 23:44:23 +0000 UTC - event for ebs.csi.aws.com5xt6c: {ebs.csi.aws.com_ebs-csi-controller-d99f59ddb-sgbd9_2a3f19cf-28ce-4bc0-94d5-57006d216d51 } Provisioning: External provisioner is provisioning volume for claim "fsgroupchangepolicy-2018/ebs.csi.aws.com5xt6c"
May 10 23:54:28.439: INFO: At 2022-05-10 23:44:27 +0000 UTC - event for ebs.csi.aws.com5xt6c: {ebs.csi.aws.com_ebs-csi-controller-d99f59ddb-sgbd9_2a3f19cf-28ce-4bc0-94d5-57006d216d51 } ProvisioningSucceeded: Successfully provisioned volume pvc-7d491407-b440-4e2c-97ab-99dc9381c59b
May 10 23:54:28.439: INFO: At 2022-05-10 23:44:27 +0000 UTC - event for pod-f603dd32-9d80-4f0e-8265-cb459843c656: {default-scheduler } Scheduled: Successfully assigned fsgroupchangepolicy-2018/pod-f603dd32-9d80-4f0e-8265-cb459843c656 to ip-172-20-97-249.us-west-2.compute.internal
May 10 23:54:28.439: INFO: At 2022-05-10 23:44:29 +0000 UTC - event for pod-f603dd32-9d80-4f0e-8265-cb459843c656: {attachdetach-controller } SuccessfulAttachVolume: AttachVolume.Attach succeeded for volume "pvc-7d491407-b440-4e2c-97ab-99dc9381c59b" 
May 10 23:54:28.439: INFO: At 2022-05-10 23:44:43 +0000 UTC - event for pod-f603dd32-9d80-4f0e-8265-cb459843c656: {kubelet ip-172-20-97-249.us-west-2.compute.internal} FailedMount: MountVolume.MountDevice failed for volume "pvc-7d491407-b440-4e2c-97ab-99dc9381c59b" : rpc error: code = Internal desc = could not format "/dev/nvme4n1" and mount it at "/var/lib/kubelet/plugins/kubernetes.io/csi/pv/pvc-7d491407-b440-4e2c-97ab-99dc9381c59b/globalmount": failed to get disk format of disk /dev/nvme4n1: exit status 127
May 10 23:54:28.439: INFO: At 2022-05-10 23:46:30 +0000 UTC - event for pod-f603dd32-9d80-4f0e-8265-cb459843c656: {kubelet ip-172-20-97-249.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[volume1], unattached volumes=[default-token-h6s66 volume1]: timed out waiting for the condition
May 10 23:54:28.439: INFO: At 2022-05-10 23:48:46 +0000 UTC - event for pod-f603dd32-9d80-4f0e-8265-cb459843c656: {kubelet ip-172-20-97-249.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[volume1], unattached volumes=[volume1 default-token-h6s66]: timed out waiting for the condition
May 10 23:54:28.439: INFO: At 2022-05-10 23:51:15 +0000 UTC - event for pod-f603dd32-9d80-4f0e-8265-cb459843c656: {kubelet ip-172-20-97-249.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[volume1], unattached volumes=[volume1 default-token-h6s66]: error processing PVC fsgroupchangepolicy-2018/ebs.csi.aws.com5xt6c: PVC is being deleted
May 10 23:54:28.439: INFO: At 2022-05-10 23:52:22 +0000 UTC - event for pod-f603dd32-9d80-4f0e-8265-cb459843c656: {kubelet ip-172-20-97-249.us-west-2.compute.internal} FailedMount: Unable to attach or mount volumes: unmounted volumes=[volume1], unattached volumes=[default-token-h6s66 volume1]: error processing PVC fsgroupchangepolicy-2018/ebs.csi.aws.com5xt6c: PVC is being deleted
May 10 23:54:28.505: INFO: POD                                       NODE                                         PHASE    GRACE  CONDITIONS
May 10 23:54:28.505: INFO: pod-f603dd32-9d80-4f0e-8265-cb459843c656  ip-172-20-97-249.us-west-2.compute.internal  Pending         [{Initialized True 0001-01-01 00:00:00 +0000 UTC 2022-05-10 23:44:27 +0000 UTC  } {Ready False 0001-01-01 00:00:00 +0000 UTC 2022-05-10 23:44:27 +0000 UTC ContainersNotReady containers with unready status: [write-pod]} {ContainersReady False 0001-01-01 00:00:00 +0000 UTC 2022-05-10 23:44:27 +0000 UTC ContainersNotReady containers with unready status: [write-pod]} {PodScheduled True 0001-01-01 00:00:00 +0000 UTC 2022-05-10 23:44:27 +0000 UTC  }]
May 10 23:54:28.505: INFO: 
May 10 23:54:28.572: INFO: 
Logging node info for node ip-172-20-56-40.us-west-2.compute.internal
May 10 23:54:28.638: INFO: Node Info: &Node{ObjectMeta:{ip-172-20-56-40.us-west-2.compute.internal    81efae28-5da4-4c6e-bded-c2e063ef39a9 8064 0 2022-05-10 23:18:49 +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-2a kops.k8s.io/instancegroup:nodes-us-west-2a kubernetes.io/arch:amd64 kubernetes.io/hostname:ip-172-20-56-40.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-2a topology.kubernetes.io/region:us-west-2 topology.kubernetes.io/zone:us-west-2a] map[csi.volume.kubernetes.io/nodeid:{"ebs.csi.aws.com":"i-0f19a99d6f747fe4d"} node.alpha.kubernetes.io/ttl:0 volumes.kubernetes.io/controller-managed-attach-detach:true] [] []  [{kops-controller Update v1 2022-05-10 23:18:49 +0000 UTC FieldsV1 {"f:metadata":{"f:labels":{"f:kops.k8s.io/instancegroup":{},"f:kubernetes.io/role":{},"f:node-role.kubernetes.io/node":{}}}}} {kubelet Update v1 2022-05-10 23:19:58 +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":{}}}}} {kube-controller-manager Update v1 2022-05-10 23:37:42 +0000 UTC FieldsV1 {"f:metadata":{"f:annotations":{"f:node.alpha.kubernetes.io/ttl":{}}},"f:spec":{"f:podCIDR":{},"f:podCIDRs":{".":{},"v:\"100.96.2.0/24\"":{}}},"f:status":{"f:conditions":{"k:{\"type\":\"NetworkUnavailable\"}":{".":{},"f:lastHeartbeatTime":{},"f:lastTransitionTime":{},"f:message":{},"f:reason":{},"f:status":{},"f:type":{}}}}}}]},Spec:NodeSpec{PodCIDR:100.96.2.0/24,DoNotUseExternalID:,ProviderID:aws:///us-west-2a/i-0f19a99d6f747fe4d,Unschedulable:false,Taints:[]Taint{},ConfigSource:nil,PodCIDRs:[100.96.2.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: {{3864977408 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: {{3760119808 0} {<nil>}  BinarySI},pods: {{110 0} {<nil>} 110 DecimalSI},},Phase:,Conditions:[]NodeCondition{NodeCondition{Type:NetworkUnavailable,Status:False,LastHeartbeatTime:2022-05-10 23:18:53 +0000 UTC,LastTransitionTime:2022-05-10 23:18:53 +0000 UTC,Reason:RouteCreated,Message:RouteController created a route,},NodeCondition{Type:MemoryPressure,Status:False,LastHeartbeatTime:2022-05-10 23:50:50 +0000 UTC,LastTransitionTime:2022-05-10 23:18:49 +0000 UTC,Reason:KubeletHasSufficientMemory,Message:kubelet has sufficient memory available,},NodeCondition{Type:DiskPressure,Status:False,LastHeartbeatTime:2022-05-10 23:50:50 +0000 UTC,LastTransitionTime:2022-05-10 23:18:49 +0000 UTC,Reason:KubeletHasNoDiskPressure,Message:kubelet has no disk pressure,},NodeCondition{Type:PIDPressure,Status:False,LastHeartbeatTime:2022-05-10 23:50:50 +0000 UTC,LastTransitionTime:2022-05-10 23:18:49 +0000 UTC,Reason:KubeletHasSufficientPID,Message:kubelet has sufficient PID available,},NodeCondition{Type:Ready,Status:True,LastHeartbeatTime:2022-05-10 23:50:50 +0000 UTC,LastTransitionTime:2022-05-10 23:19:09 +0000 UTC,Reason:KubeletReady,Message:kubelet is posting ready status. AppArmor enabled,},},Addresses:[]NodeAddress{NodeAddress{Type:InternalIP,Address:172.20.56.40,},NodeAddress{Type:ExternalIP,Address:54.190.220.105,},NodeAddress{Type:Hostname,Address:ip-172-20-56-40.us-west-2.compute.internal,},NodeAddress{Type:InternalDNS,Address:ip-172-20-56-40.us-west-2.compute.internal,},NodeAddress{Type:ExternalDNS,Address:ec2-54-190-220-105.us-west-2.compute.amazonaws.com,},},DaemonEndpoints:NodeDaemonEndpoints{KubeletEndpoint:DaemonEndpoint{Port:10250,},},NodeInfo:NodeSystemInfo{MachineID:ec26677e61ae0ccaf587f5886b593471,SystemUUID:ec26677e-61ae-0cca-f587-f5886b593471,BootID:1e40e8c7-bda2-4e00-8aa5-724badfe046b,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:12229b0c94723be687fe6e42d4e9b401334f275a84072795a72e5fa54ab0f46e 607362164682.dkr.ecr.us-west-2.amazonaws.com/aws-ebs-csi-driver:3162],SizeBytes:26066741,},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 different fsgroup applied 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 | 0xc00130b120>: {
            s: "pod \"pod-f603dd32-9d80-4f0e-8265-cb459843c656\" is not Running: timed out waiting for the condition",
        }
        pod "pod-f603dd32-9d80-4f0e-8265-cb459843c656" is not Running: timed out waiting for the condition
    occurred

... skipping 3 lines ...