kubernetes-sigs/aws-ebs-csi-driver PR #1233 pull-aws-ebs-csi-driver-external-test #1524165512651608064
Recent runs || View in Spyglass
Recent runs || View in Spyglass
| PR | torredil: Use minimal base image for linux builds |
| Result | ABORTED |
| Tests | 0 failed / 0 succeeded |
| Started | |
| Elapsed | 59m8s |
| Revision | 72a890e0d0ad131d4b02e5131172b6a77132f4bc |
| Refs |
1233 |
... 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 ... [36m[1mS [SKIPPING] in Spec Setup (BeforeEach) [0.003 seconds][0m External Storage [Driver: ebs.csi.aws.com] [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:175[0m [Testpattern: Pre-provisioned PV (default fs)] subPath [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50[0m [36m[1mshould fail if subpath directory is outside the volume [Slow][LinuxOnly] [BeforeEach][0m [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:240[0m [36mDriver "ebs.csi.aws.com" does not support volume type "PreprovisionedPV" - skipping[0m /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:263 [90m------------------------------[0m ... 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 ... [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:175[0m [Testpattern: Dynamic PV (filesystem volmode)] multiVolume [Slow] [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50[0m [91m[1mshould concurrently access the single read-only volume from pods on the same node [It][0m [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/multivolume.go:337[0m [91mUnexpected 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[0m ... 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 [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50[0m [91m[1mVerify if offline PVC expansion works [It][0m [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/volume_expand.go:174[0m [91mWhile 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[0m ... 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 [90m------------------------------[0m [36mS[0m[36mS[0m[36mS[0m[36mS[0m[36mS[0m [90m------------------------------[0m [0mExternal Storage [Driver: ebs.csi.aws.com][0m [90m[Testpattern: Dynamic PV (immediate binding)] topology[0m [1mshould fail to schedule a pod which has topologies that conflict with AllowedTopologies[0m [37m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/topology.go:192[0m [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 [1mSTEP[0m: 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 [1mSTEP[0m: Building a namespace api object, basename topology [1mSTEP[0m: 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{},},} [1mSTEP[0m: Creating sc [1mSTEP[0m: 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 ... [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:175[0m [Testpattern: Dynamic PV (filesystem volmode)] multiVolume [Slow] [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50[0m [91m[1mshould access to two volumes with the same volume mode and retain data across pod recreation on the same node [LinuxOnly] [It][0m [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/multivolume.go:134[0m [91mUnexpected 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[0m ... 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 ... [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:175[0m [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50[0m [91m[1m(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][0m [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/fsgroupchangepolicy.go:208[0m [91mUnexpected 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[0m ... 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} [1mSTEP[0m: creating a StorageClass provisioning-7721-e2e-sc58vlx [1mSTEP[0m: creating a claim May 10 23:27:03.112: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil [1mSTEP[0m: Creating pod pod-subpath-test-dynamicpv-skf7 [1mSTEP[0m: 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) [1mSTEP[0m: 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 ... [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:175[0m [Testpattern: Dynamic PV (default fs)] subPath [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50[0m [91m[1mshould support readOnly directory specified in the volumeMount [It][0m [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:369[0m [91mUnexpected 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[0m /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/framework/util.go:742 [90m------------------------------[0m [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} [1mSTEP[0m: creating a StorageClass volume-7440-e2e-scv6kqd [1mSTEP[0m: creating a claim May 10 23:27:24.883: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil [1mSTEP[0m: Creating pod exec-volume-test-dynamicpv-8qg2 [1mSTEP[0m: 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) [1mSTEP[0m: 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 ... [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:175[0m [Testpattern: Dynamic PV (default fs)] volumes [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50[0m [91m[1mshould allow exec of files on the volume [It][0m [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/volumes.go:196[0m [91mUnexpected 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[0m /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/framework/util.go:742 [90m------------------------------[0m [0mExternal Storage [Driver: ebs.csi.aws.com][0m [90m[Testpattern: Dynamic PV (block volmode)] multiVolume [Slow][0m [1mshould access to two volumes with different volume mode and retain data across pod recreation on the same node [LinuxOnly][0m ... 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 ... [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:175[0m [Testpattern: Dynamic PV (block volmode)] multiVolume [Slow] [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50[0m [91m[1mshould access to two volumes with different volume mode and retain data across pod recreation on the same node [LinuxOnly] [It][0m [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/multivolume.go:214[0m [91mUnexpected 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[0m ... 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 ... [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:175[0m [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50[0m [91m[1m(Always)[LinuxOnly], pod created with an initial fsgroup, new pod fsgroup applied to volume contents [It][0m [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/fsgroupchangepolicy.go:208[0m [91mUnexpected 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[0m /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/fsgroupchangepolicy.go:250 [90m------------------------------[0m [0mExternal Storage [Driver: ebs.csi.aws.com][0m [90m[Testpattern: Dynamic PV (filesystem volmode)] volumeMode[0m [1mshould fail to use a volume in a pod with mismatched mode [Slow][0m [37m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/volumemode.go:297[0m [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 [1mSTEP[0m: 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 [1mSTEP[0m: Building a namespace api object, basename volumemode [1mSTEP[0m: 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} [1mSTEP[0m: creating a StorageClass volumemode-8470-e2e-scvmncg [1mSTEP[0m: creating a claim [1mSTEP[0m: Creating pod [1mSTEP[0m: 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 [1mSTEP[0m: 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 ... [32m• [SLOW TEST:22.568 seconds][0m External Storage [Driver: ebs.csi.aws.com] [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:175[0m [Testpattern: Dynamic PV (filesystem volmode)] volumeMode [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50[0m should fail to use a volume in a pod with mismatched mode [Slow] [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/volumemode.go:297[0m [90m------------------------------[0m [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 [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50[0m [91m[1mshould support restarting containers using file as subpath [Slow][LinuxOnly] [It][0m [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:335[0m [91mwhile 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[0m ... 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 [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50[0m [91m[1mshould be able to unmount after the subpath directory is deleted [LinuxOnly] [It][0m [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:449[0m [91mwhile 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[0m ... skipping 119 lines ... [36m[1mS [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds][0m External Storage [Driver: ebs.csi.aws.com] [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:175[0m [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50[0m [36m[1mshould fail if subpath directory is outside the volume [Slow][LinuxOnly] [BeforeEach][0m [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:240[0m [36mDriver ebs.csi.aws.com doesn't support ntfs -- skipping[0m /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:121 [90m------------------------------[0m ... 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 [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50[0m [91m[1mVerify if offline PVC expansion works [It][0m [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/volume_expand.go:174[0m [91mWhile 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[0m ... 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 ... [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:175[0m [Testpattern: Dynamic PV (xfs)][Slow] volumes [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50[0m [91m[1mshould store data [It][0m [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/volumes.go:159[0m [91mMay 10 23:43:03.801: Failed to create injector pod: timed out waiting for the condition[0m /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/volumes.go:186 [90m------------------------------[0m [0mExternal Storage [Driver: ebs.csi.aws.com][0m [90m[Testpattern: Dynamic PV (block volmode)] multiVolume [Slow][0m [1mshould access to two volumes with the same volume mode and retain data across pod recreation on the same node [LinuxOnly][0m [37m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/multivolume.go:134[0m ... 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 ... [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:175[0m [Testpattern: Dynamic PV (block volmode)] multiVolume [Slow] [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50[0m [91m[1mshould access to two volumes with the same volume mode and retain data across pod recreation on the same node [LinuxOnly] [It][0m [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/multivolume.go:134[0m [91mUnexpected 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[0m ... skipping 52 lines ... [36m[1mS [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds][0m External Storage [Driver: ebs.csi.aws.com] [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:175[0m [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50[0m [36m[1mshould fail if subpath with backstepping is outside the volume [Slow][LinuxOnly] [BeforeEach][0m [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:278[0m [36mDriver ebs.csi.aws.com doesn't support ntfs -- skipping[0m /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:121 [90m------------------------------[0m ... skipping 6 lines ... [36m[1mS [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds][0m External Storage [Driver: ebs.csi.aws.com] [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:175[0m [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50[0m [36m[1mshould fail if subpath file is outside the volume [Slow][LinuxOnly] [BeforeEach][0m [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:256[0m [36mDriver ebs.csi.aws.com doesn't support ntfs -- skipping[0m /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:121 [90m------------------------------[0m ... 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} [1mSTEP[0m: creating a StorageClass volume-1429-e2e-sc6j4fv [1mSTEP[0m: creating a claim May 10 23:38:23.424: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil [1mSTEP[0m: Creating pod exec-volume-test-dynamicpv-vrht [1mSTEP[0m: 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) [1mSTEP[0m: 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 ... [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:175[0m [Testpattern: Dynamic PV (ext4)] volumes [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50[0m [91m[1mshould allow exec of files on the volume [It][0m [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/volumes.go:196[0m [91mUnexpected 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[0m /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/framework/util.go:742 [90m------------------------------[0m [36mS[0m[36mS[0m [90m------------------------------[0m ... 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} [1mSTEP[0m: creating a StorageClass volume-expand-2367-e2e-sc4gblh [1mSTEP[0m: creating a claim [1mSTEP[0m: 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} [1mSTEP[0m: creating a StorageClass provisioning-7469-e2e-sc4777x [1mSTEP[0m: creating a claim May 10 23:42:58.501: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil [1mSTEP[0m: Creating pod pod-subpath-test-dynamicpv-rk5d [1mSTEP[0m: 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) [1mSTEP[0m: 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 ... [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:175[0m [Testpattern: Dynamic PV (default fs)] subPath [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50[0m [91m[1mshould support creating multiple subpath from same volumes [Slow] [It][0m [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/subpath.go:294[0m [91mUnexpected 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[0m /home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/framework/util.go:742 [90m------------------------------[0m [36mS[0m [90m------------------------------[0m ... 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 [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50[0m [91m[1mshould resize volume when PVC is edited while pod is using it [It][0m [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/volume_expand.go:246[0m [91mWhile 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[0m ... 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 ... [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/external/external.go:175[0m [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/framework/testsuite.go:50[0m [91m[1m(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][0m [90m/home/prow/go/src/github.com/kubernetes-sigs/aws-ebs-csi-driver/vendor/k8s.io/kubernetes/test/e2e/storage/testsuites/fsgroupchangepolicy.go:208[0m [91mUnexpected 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[0m ... skipping 3 lines ...