Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

volume mode "Persistent" not supported by driver ebs.csi.aws.com (only supports []) #419

Closed
glotzerhotze opened this issue Nov 25, 2019 · 17 comments
Labels
kind/bug Categorizes issue or PR as related to a bug. lifecycle/rotten Denotes an issue or PR that has aged beyond stale and will be auto-closed.

Comments

@glotzerhotze
Copy link

glotzerhotze commented Nov 25, 2019

/kind bug

What happened?
We want to upgrade our current kubernetes cluster running on debian-9-stretch (backports kernel 4.19.0) from v1.15.3 to v1.16.3

To test this - in a non-destructive way - we spun up an additional spot-worker-node (debian-10-buster based with backports kernel 5.3.0) running kubelet v1.16.3 and added that node without problems to the cluster.

As far as we understand version-skew, this should not be a problem.

But if we now schedule a deployment that needs statically provisioned storage via the the driver: ebs.csi.aws.com onto that v1.16.3 node, we see the below messages appear in the event-log of the pod description:

Events:
  Type     Reason                  Age                  From                                                    Message
  ----     ------                  ----                 ----                                                    -------
  Normal   Scheduled               3m49s                default-scheduler                                       Successfully assigned log/graylog-64948667c5-ksbpk to ip-172-31-50-37.eu-central-1.compute.internal
  Warning  FailedAttachVolume      3m48s                attachdetach-controller                                 Multi-Attach error for volume "csi-graylog-journal-volume" Volume is already exclusively attached to one node and can't be attached to another
  Normal   SuccessfulAttachVolume  3m26s                attachdetach-controller                                 AttachVolume.Attach succeeded for volume "csi-graylog-journal-volume"
  Warning  FailedMount             106s                 kubelet, ip-172-31-50-37.eu-central-1.compute.internal  Unable to attach or mount volumes: unmounted volumes=[csi-graylog-journal-storage], unattached volumes=[csi-graylog-journal-storage default-token-pggvh]: timed out waiting for the condition
  Warning  FailedMount             69s (x9 over 3m17s)  kubelet, ip-172-31-50-37.eu-central-1.compute.internal  MountVolume.NewMounter initialization failed for volume "csi-graylog-journal-volume" : volume mode "Persistent" not supported by driver ebs.csi.aws.com (only supports [])

kubelet is throwing these errors at us:

Nov 25 19:43:50 ip-172-31-50-37 kubelet[11593]: E1125 19:43:50.499920   11593 nestedpendingoperations.go:270] Operation for "\"kubernetes.io/csi/ebs.csi.aws.com^vol-0af6b92ab477dbbaa\"" failed. No retries permitted until 2019-11-25 19:44:54.499886377 +0000 UTC m=+16342.936456533 (durationBeforeRetry 1m4s). Error: "MountVolume.NewMounter initialization failed for volume \"csi-graylog-journal-volume\" (UniqueName: \"kubernetes.io/csi/ebs.csi.aws.com^vol-0af6b92ab477dbbaa\") pod \"graylog-64948667c5-ksbpk\" (UID: \"e012ee7a-5d80-43bc-901b-27fba0ecedb4\") : volume mode \"Persistent\" not supported by driver ebs.csi.aws.com (only supports [])"
Nov 25 19:44:17 ip-172-31-50-37 kubelet[11593]: E1125 19:44:17.959000   11593 kubelet.go:1682] Unable to attach or mount volumes for pod "graylog-64948667c5-ksbpk_log(e012ee7a-5d80-43bc-901b-27fba0ecedb4)": unmounted volumes=[csi-graylog-journal-storage], unattached volumes=[csi-graylog-journal-storage default-token-pggvh]: timed out waiting for the condition; skipping pod
Nov 25 19:44:17 ip-172-31-50-37 kubelet[11593]: E1125 19:44:17.959065   11593 pod_workers.go:191] Error syncing pod e012ee7a-5d80-43bc-901b-27fba0ecedb4 ("graylog-64948667c5-ksbpk_log(e012ee7a-5d80-43bc-901b-27fba0ecedb4)"), skipping: unmounted volumes=[csi-graylog-journal-storage], unattached volumes=[csi-graylog-journal-storage default-token-pggvh]: timed out waiting for the condition
Nov 25 19:44:25 ip-172-31-50-37 kubelet[11593]: I1125 19:44:25.419035   11593 operation_generator.go:193] parsed scheme: ""
Nov 25 19:44:25 ip-172-31-50-37 kubelet[11593]: I1125 19:44:25.419064   11593 operation_generator.go:193] scheme "" not registered, fallback to default scheme
Nov 25 19:44:25 ip-172-31-50-37 kubelet[11593]: I1125 19:44:25.419084   11593 passthrough.go:48] ccResolverWrapper: sending update to cc: {[{/var/lib/kubelet/plugins/ebs.csi.aws.com/csi.sock 0  <nil>}] <nil>}
Nov 25 19:44:25 ip-172-31-50-37 kubelet[11593]: I1125 19:44:25.419097   11593 clientconn.go:577] ClientConn switching balancer to "pick_first"
Nov 25 19:44:25 ip-172-31-50-37 kubelet[11593]: E1125 19:44:25.420080   11593 goroutinemap.go:150] Operation for "/var/lib/kubelet/plugins/ebs.csi.aws.com/csi.sock" failed. No retries permitted until 2019-11-25 19:46:27.420054331 +0000 UTC m=+16435.856624589 (durationBeforeRetry 2m2s). Error: "RegisterPlugin error -- failed to get plugin info using RPC GetInfo at socket /var/lib/kubelet/plugins/ebs.csi.aws.com/csi.sock, err: rpc error: code = Unimplemented desc = unknown service pluginregistration.Registration"
Nov 25 19:44:37 ip-172-31-50-37 kubelet[11593]: W1125 19:44:37.385851   11593 reflector.go:299] object-"3a"/"preflight": watch of *v1.ConfigMap ended with: too old resource version: 62981370 (62981737)
Nov 25 19:44:54 ip-172-31-50-37 kubelet[11593]: E1125 19:44:54.597875   11593 nestedpendingoperations.go:270] Operation for "\"kubernetes.io/csi/ebs.csi.aws.com^vol-0af6b92ab477dbbaa\"" failed. No retries permitted until 2019-11-25 19:46:56.597848943 +0000 UTC m=+16465.034419009 (durationBeforeRetry 2m2s). Error: "MountVolume.NewMounter initialization failed for volume \"csi-graylog-journal-volume\" (UniqueName: \"kubernetes.io/csi/ebs.csi.aws.com^vol-0af6b92ab477dbbaa\") pod \"graylog-64948667c5-ksbpk\" (UID: \"e012ee7a-5d80-43bc-901b-27fba0ecedb4\") : volume mode \"Persistent\" not supported by driver ebs.csi.aws.com (only supports [])"

The pod gets stuck in ContainerCreating and is never spawned. As soon as the deployment gets scheduled onto a debian-stretch based v1.15.3 worker, disks get attached and mounted without a problem.

What you expected to happen?
Expectation would be that with a cluster-update from v1.15.3 to v1.16.x the aws-ebs-csi plugin would continue to function without problems - as was the case with earlier releases (here: v1.15.3)

Attaching and mounting disk was working for our setup without major problems. The process might take a while - we also had a few cases of manual kubelet restarts needed (every other month due to unplanned disruption of services having storage mounted)

General stability of the driver was given for us, up until moving to v1.16.3

How to reproduce it (as minimally and precisely as possible)?
Provision a small cluster with kubernetes v1.15.x (patchlevel 3 in our case - we haven't tried newer 1.15.x releases so far) - we use latest stable cilium-1.6.3 (CRD backed solution) as CNI.

Bootstrap the cluster with an InitConfiguration object that declares cloud-provider: external to the kubeletExtraArgs: via nodeRegistration: mechanism. Each worker- and control-plane-node gets the same cloud-provider: external declaration via the respective JoinConfiguration object.

Spawn a daemon-set for the AWS cloud-controller-manager and register the aws-ebs-csi-driver with the cluster.

Create a storage class and statical (aka. pre-) provision a volume (we created ebs-volumes from snapshots for example). Make sure the volume object gets registered within the cluster.

Declare a deployment and a PVC to consume the storage created in the last step. You should now have a deployment that uses the PV and it should be bound to the deployment via the claiming PVC object. All this is running on v1.15.x worker-nodes.

Watch the description of the pod (created by the storage-consuming deployment / replica-set) to see the pre-provisioned volume get attached and mounted successfully into the pod.

Now add a v1.16.3 worker to the cluster. Watch kube-proxy / CNI / aws-ebs-csi daemonsets spawn pods on the node. After these are running, stateless deployments get scheduled onto the node and their workloads run without a slightest problem.

Things start to fall apart, when we schedule a deployment which wants to consume storage via aws.ebs.csi.driver While the pod gets scheduled onto the v1.16.x node and the pod is in state ContainerCreating - it will get stuck and sit forever there complaining about not being able to mount the volume into the pod - as can be seen here:

Warning  FailedMount             106s                 kubelet, ip-172-31-50-37.eu-central-1.compute.internal  Unable to attach or mount volumes: unmounted volumes=[csi-graylog-journal-storage], unattached volumes=[csi-graylog-journal-storage default-token-pggvh]: timed out waiting for the condition
Warning  FailedMount             69s (x9 over 3m17s)  kubelet, ip-172-31-50-37.eu-central-1.compute.internal  MountVolume.NewMounter initialization failed for volume "csi-graylog-journal-volume" : volume mode "Persistent" not supported by driver ebs.csi.aws.com (only supports [])

Anything else we need to know?:
current v1.15.3 cluster runs on plain ec2-instances using debian stretch.
future v1.16.x cluster should run on plain ec2-instances utilizing debian buster.

v1.16.x nodes run fine in another testing cluster where we switched to an all-buster-setup already - once you work around the edges of the OS (like iptables-legacy) it's just debian and we are very confident that problems are not related to the different versions of the OS.

We also noticed that there is only k8s.gcr.io/cloud-controller-manager:v1.15.x provided - there seems to be no v1.16.x for cloud-controller-manager - here we just stuck to the v1.15.3 version as the new v1.16.3 node was registered with the CCM without problems upon joining the cluster and we did not notice any odd behaviour.

Environment
about 15-20 (medium to large sized) AWS EC2 instances running debian stretch / buster - utilizing distro-specific latest backports kernel.

on top of that we used kubeadm to bootstrap and manage the v1.15.3 cluster. CNI (aka. networking) is implemented by (latest stable) cilium-1.6.3 (running no k/v-store).

cloud-provider-aws (aka. external cloud-controller-manager) is running with v1.15.3 - aws-ebs-csi-driver is v0.4.0 - I just updated our cluster according to the docs here

  helm template --name-template aws-ebs-csi-driver \                                                             <<<
  --set enableVolumeScheduling=true \
  --set enableVolumeResizing=true \
  --set enableVolumeSnapshot=true \
  https://github.com/kubernetes-sigs/aws-ebs-csi-driver/releases/download/v0.4.0/helm-chart.tgz > manifest.yaml

was used to generate all the several objects, as I had to delete some objects that would not allow to change immutable fields (aka. the DaemonSet and StatefulSet objects) when trying to apply the manifest directly.

  • Kubernetes version (use kubectl version):
Client Version: version.Info{Major:"1", Minor:"16", GitVersion:"v1.16.3", GitCommit:"b3cbbae08ec52a7fc73d334838e18d17e8512749", GitTreeState:"clean", BuildDate:"2019-11-14T04:24:29Z", GoVersion:"go1.12.13", Compiler:"gc", Platform:"darwin/amd64"}
Server Version: version.Info{Major:"1", Minor:"15", GitVersion:"v1.15.3", GitCommit:"2d3c76f9091b6bec110a5e63777c332469e0cba2", GitTreeState:"clean", BuildDate:"2019-08-19T11:05:50Z", GoVersion:"go1.12.9", Compiler:"gc", Platform:"linux/amd64"}
  • Driver version:
    https://github.com/kubernetes-sigs/aws-ebs-csi-driver/releases/download/v0.4.0/helm-chart.tgz
@k8s-ci-robot k8s-ci-robot added the kind/bug Categorizes issue or PR as related to a bug. label Nov 25, 2019
@leakingtapan
Copy link
Contributor

leakingtapan commented Nov 26, 2019

This seems an issue related to volume lifecycle mode that got added since 1.16.

In this case an existing CSIDriver object doesn't declare a VolumeLifecycleModes should be defaulted to Perisistent but got error stating:

volume mode \"Persistent\" not supported by driver ebs.csi.aws.com (only supports [])

@leakingtapan
Copy link
Contributor

leakingtapan commented Nov 27, 2019

I suspect the problem is due to the defaulting logic was only added since 1.16. So that a CSIDriver object got created earlier was not defaulted correctly.

What's the output of kubectl get csidriver -o yaml?

And could you try reinstall the CSI driver and see if it works? You might want to check the CSIDriver object again too see whether the defaulting kicks in

I also see your master node is still 1.15.3, you should upgrade master to 1.16 before upgrading worker nodes.

@glotzerhotze
Copy link
Author

glotzerhotze commented Nov 29, 2019

Hi leakingtapan - thanks for looking into this subject and giving some insights as to what is going wrong.

It took me a few days to get back to this and replicate the problem with a 4 node testing cluster. So I can confirm that the same error message shows up when joining a 1.16.3 worker node to a functional 1.15.6 cluster (1 master - 2 workers) - so far, no news.

Since I learned that when upgrading the whole cluster, starting with the master-nodes usually is the safer route to go down - as a master might be "more" backwards-compatible than a client - I did just that this time.

I updated the only master node to v1.16.3 and then joined the v1.16.3 worker-node to the cluster again - giving me 2 workers on v1.15.6, 1 worker and 1 control-plane-node on v1.16.3.

Now trying to schedule a pod with storage (aka. utilizing the aws-ebs-csi-driver) onto the v1.16.3 worker will not show the error message from the title, but rather just error out with the below message and again, the pod is stuck in ContainerCreating and not doing anything for the rest of the universe it seems - until one kills it of course.

For a static provisioned pod these events show up:

Events:
  Type     Reason              Age                   From                                                     Message
  ----     ------              ----                  ----                                                     -------
  Normal   Scheduled           45m                   default-scheduler                                        Successfully assigned default/aws-csi-static to ip-172-31-60-228.eu-central-1.compute.internal
  Warning  FailedMount         2m55s (x14 over 43m)  kubelet, ip-172-31-60-228.eu-central-1.compute.internal  Unable to attach or mount volumes: unmounted volumes=[aws-csi-static-volume], unattached volumes=[aws-csi-static-volume default-token-lrnp9]: timed out waiting for the condition
  Warning  FailedAttachVolume  108s (x23 over 45m)   attachdetach-controller                                  AttachVolume.Attach failed for volume "aws-csi-static-volume" : rpc error: code = DeadlineExceeded desc = context deadline exceeded
  Warning  FailedMount         39s (x6 over 41m)     kubelet, ip-172-31-60-228.eu-central-1.compute.internal  Unable to attach or mount volumes: unmounted volumes=[aws-csi-static-volume], unattached volumes=[default-token-lrnp9 aws-csi-static-volume]: timed out waiting for the condition

And this shows up for a dynamically provisioned pod:

Events:
  Type     Reason              Age                  From                                                     Message
  ----     ------              ----                 ----                                                     -------
  Normal   Scheduled           3m6s                 default-scheduler                                        Successfully assigned default/aws-csi-dynamic to ip-172-31-60-228.eu-central-1.compute.internal
  Warning  FailedMount         63s                  kubelet, ip-172-31-60-228.eu-central-1.compute.internal  Unable to attach or mount volumes: unmounted volumes=[persistent-storage], unattached volumes=[persistent-storage default-token-lrnp9]: timed out waiting for the condition
  Warning  FailedAttachVolume  42s (x9 over 2m51s)  attachdetach-controller                                  AttachVolume.Attach failed for volume "pvc-5a6e6e99-c51a-48bf-b650-60693b4cdb62" : rpc error: code = DeadlineExceeded desc = context deadline exceeded

Now I had an expectation (or more a gut feeling) that these pods would not run on v1.16.3 worker nodes after the update - but what really puzzles me right now is: they won't even get scheduled onto one of the old 1.15.6 workers (of which we still got two in the cluster by now)

Below you can see the kubectl journal from the v1.15.6 node that was not able to schedule the aws-ebs-csi-driver backed pods that ran on the same node perfectly while the cluster was still at v1.15.6.

Nov 29 18:32:30 ip-172-31-60-52 kubelet[12507]: I1129 18:32:30.651352   12507 reconciler.go:203] operationExecutor.VerifyControllerAttachedVolume started for volume "aws-csi-static-volume" (UniqueName: "kubernetes.io/csi/ebs.csi.aws.com^vol-0f20307a465e42e70") pod "aws-csi-static" (UID: "892ea406-f3b6-4223-8f2a-66ab8be44824")
Nov 29 18:32:30 ip-172-31-60-52 kubelet[12507]: E1129 18:32:30.653611   12507 nestedpendingoperations.go:270] Operation for "\"kubernetes.io/csi/ebs.csi.aws.com^vol-0f20307a465e42e70\"" failed. No retries permitted until 2019-11-29 18:34:32.653584536 +0000 UTC m=+22866.533319733 (durationBeforeRetry 2m2s). Error: "Volume not attached according to node status for volume \"aws-csi-static-volume\" (UniqueName: \"kubernetes.io/csi/ebs.csi.aws.com^vol-0f20307a465e42e70\") pod \"aws-csi-static\" (UID: \"892ea406-f3b6-4223-8f2a-66ab8be44824\") "
Nov 29 18:32:30 ip-172-31-60-52 kubelet[12507]: E1129 18:32:30.984539   12507 kubelet_volumes.go:154] Orphaned pod "e2ae9889-9763-40fe-b1e3-02f84360708c" found, but volume paths are still present on disk : There were a total of 1 errors similar to this. Turn up verbosity to see them.
Nov 29 18:32:32 ip-172-31-60-52 kubelet[12507]: E1129 18:32:32.989669   12507 kubelet_volumes.go:154] Orphaned pod "e2ae9889-9763-40fe-b1e3-02f84360708c" found, but volume paths are still present on disk : There were a total of 1 errors similar to this. Turn up verbosity to see them.
Nov 29 18:32:34 ip-172-31-60-52 kubelet[12507]: E1129 18:32:34.978589   12507 kubelet_volumes.go:154] Orphaned pod "e2ae9889-9763-40fe-b1e3-02f84360708c" found, but volume paths are still present on disk : There were a total of 1 errors similar to this. Turn up verbosity to see them.
Nov 29 18:32:36 ip-172-31-60-52 kubelet[12507]: E1129 18:32:36.980965   12507 kubelet_volumes.go:154] Orphaned pod "e2ae9889-9763-40fe-b1e3-02f84360708c" found, but volume paths are still present on disk : There were a total of 1 errors similar to this. Turn up verbosity to see them.
Nov 29 18:32:38 ip-172-31-60-52 kubelet[12507]: E1129 18:32:38.982873   12507 kubelet_volumes.go:154] Orphaned pod "e2ae9889-9763-40fe-b1e3-02f84360708c" found, but volume paths are still present on disk : There were a total of 1 errors similar to this. Turn up verbosity to see them.
Nov 29 18:32:40 ip-172-31-60-52 kubelet[12507]: I1129 18:32:40.780659   12507 reconciler.go:203] operationExecutor.VerifyControllerAttachedVolume started for volume "pvc-5a6e6e99-c51a-48bf-b650-60693b4cdb62" (UniqueName: "kubernetes.io/csi/ebs.csi.aws.com^vol-04480f15de0c3747e") pod "aws-csi-dynamic" (UID: "a2b4b8fb-8f3d-4666-a361-35cdd3a88964")
Nov 29 18:32:40 ip-172-31-60-52 kubelet[12507]: E1129 18:32:40.783173   12507 nestedpendingoperations.go:270] Operation for "\"kubernetes.io/csi/ebs.csi.aws.com^vol-04480f15de0c3747e\"" failed. No retries permitted until 2019-11-29 18:33:44.783150975 +0000 UTC m=+22818.662886174 (durationBeforeRetry 1m4s). Error: "Volume not attached according to node status for volume \"pvc-5a6e6e99-c51a-48bf-b650-60693b4cdb62\" (UniqueName: \"kubernetes.io/csi/ebs.csi.aws.com^vol-04480f15de0c3747e\") pod \"aws-csi-dynamic\" (UID: \"a2b4b8fb-8f3d-4666-a361-35cdd3a88964\") "
Nov 29 18:32:40 ip-172-31-60-52 kubelet[12507]: E1129 18:32:40.979027   12507 kubelet_volumes.go:154] Orphaned pod "e2ae9889-9763-40fe-b1e3-02f84360708c" found, but volume paths are still present on disk : There were a total of 1 errors similar to this. Turn up verbosity to see them.
Nov 29 18:32:42 ip-172-31-60-52 kubelet[12507]: E1129 18:32:42.981905   12507 kubelet_volumes.go:154] Orphaned pod "e2ae9889-9763-40fe-b1e3-02f84360708c" found, but volume paths are still present on disk : There were a total of 1 errors similar to this. Turn up verbosity to see them.
Nov 29 18:32:44 ip-172-31-60-52 kubelet[12507]: E1129 18:32:44.982380   12507 kubelet_volumes.go:154] Orphaned pod "e2ae9889-9763-40fe-b1e3-02f84360708c" found, but volume paths are still present on disk : There were a total of 1 errors similar to this. Turn up verbosity to see them.
Nov 29 18:32:46 ip-172-31-60-52 kubelet[12507]: E1129 18:32:46.977939   12507 kubelet_volumes.go:154] Orphaned pod "e2ae9889-9763-40fe-b1e3-02f84360708c" found, but volume paths are still present on disk : There were a total of 1 errors similar to this. Turn up verbosity to see them.
Nov 29 18:32:48 ip-172-31-60-52 kubelet[12507]: E1129 18:32:48.984404   12507 kubelet_volumes.go:154] Orphaned pod "e2ae9889-9763-40fe-b1e3-02f84360708c" found, but volume paths are still present on disk : There were a total of 1 errors similar to this. Turn up verbosity to see them.
Nov 29 18:32:50 ip-172-31-60-52 kubelet[12507]: E1129 18:32:50.977429   12507 kubelet_volumes.go:154] Orphaned pod "e2ae9889-9763-40fe-b1e3-02f84360708c" found, but volume paths are still present on disk : There were a total of 1 errors similar to this. Turn up verbosity to see them.
Nov 29 18:32:51 ip-172-31-60-52 kubelet[12507]: E1129 18:32:51.971930   12507 kubelet.go:1669] Unable to mount volumes for pod "aws-csi-static_default(892ea406-f3b6-4223-8f2a-66ab8be44824)": timeout expired waiting for volumes to attach or mount for pod "default"/"aws-csi-static". list of unmounted volumes=[aws-csi-static-volume]. list of unattached volumes=[aws-csi-static-volume default-token-lrnp9]; skipping pod
Nov 29 18:32:51 ip-172-31-60-52 kubelet[12507]: E1129 18:32:51.972567   12507 pod_workers.go:190] Error syncing pod 892ea406-f3b6-4223-8f2a-66ab8be44824 ("aws-csi-static_default(892ea406-f3b6-4223-8f2a-66ab8be44824)"), skipping: timeout expired waiting for volumes to attach or mount for pod "default"/"aws-csi-static". list of unmounted volumes=[aws-csi-static-volume]. list of unattached volumes=[aws-csi-static-volume default-token-lrnp9]

Up until now the v1.15.6 deployed aws-ebs-csi-driver version is still running in the cluster - and was not touched after the installation was confirmed to be working and (statically and dynamically) provisioning storage on a v1.15.6 cluster

kubectl get csidriver -o yaml gives this output - albeit after already updating the master-node to v1.16.3:

apiVersion: v1
items:
- apiVersion: storage.k8s.io/v1beta1
  kind: CSIDriver
  metadata:
    annotations:
      kubectl.kubernetes.io/last-applied-configuration: |
        {"apiVersion":"storage.k8s.io/v1beta1","kind":"CSIDriver","metadata":{"annotations":{},"name":"ebs.csi.aws.com"},"spec":{"attachRequired":true,"podInfoOnMount":false}}
    creationTimestamp: "2019-11-29T12:19:00Z"
    name: ebs.csi.aws.com
    resourceVersion: "2009"
    selfLink: /apis/storage.k8s.io/v1beta1/csidrivers/ebs.csi.aws.com
    uid: a9102300-2270-4961-ba16-90b833303afd
  spec:
    attachRequired: true
    podInfoOnMount: false
    volumeLifecycleModes:
    - Persistent
kind: List
metadata:
  resourceVersion: ""
  selfLink: ""

Applying the helm-generated aws-ebs-csi manifest again gives this (correct - as nothing changed!) output:

serviceaccount/ebs-csi-controller-sa unchanged
clusterrole.rbac.authorization.k8s.io/ebs-external-attacher-role unchanged
clusterrole.rbac.authorization.k8s.io/ebs-external-resizer-role unchanged
clusterrole.rbac.authorization.k8s.io/ebs-external-provisioner-role unchanged
clusterrole.rbac.authorization.k8s.io/ebs-external-snapshotter-role unchanged
clusterrolebinding.rbac.authorization.k8s.io/ebs-csi-provisioner-binding unchanged
clusterrolebinding.rbac.authorization.k8s.io/ebs-csi-resizer-binding unchanged
clusterrolebinding.rbac.authorization.k8s.io/ebs-csi-attacher-binding unchanged
clusterrolebinding.rbac.authorization.k8s.io/ebs-csi-snapshotter-binding unchanged
daemonset.apps/ebs-csi-node unchanged
statefulset.apps/ebs-csi-controller unchanged
csidriver.storage.k8s.io/ebs.csi.aws.com unchanged

So the next step was to delete the whole csi-manifest from the cluster via kubectl delete -f manifest.yaml and then re-apply it, hoping that the new 1.16.x defaults would be written with that - and while following the advice to try to reinstall the CSI driver and see if it works

this is what kubectl get csidriver -o yaml gives this time:

apiVersion: v1
items:
- apiVersion: storage.k8s.io/v1beta1
  kind: CSIDriver
  metadata:
    annotations:
      kubectl.kubernetes.io/last-applied-configuration: |
        {"apiVersion":"storage.k8s.io/v1beta1","kind":"CSIDriver","metadata":{"annotations":{},"name":"ebs.csi.aws.com"},"spec":{"attachRequired":true,"podInfoOnMount":false}}
    creationTimestamp: "2019-11-29T18:54:44Z"
    name: ebs.csi.aws.com
    resourceVersion: "52311"
    selfLink: /apis/storage.k8s.io/v1beta1/csidrivers/ebs.csi.aws.com
    uid: 395d3f3b-fe4a-4e47-9823-8d6c9fdab56e
  spec:
    attachRequired: true
    podInfoOnMount: false
    volumeLifecycleModes:
    - Persistent
kind: List
metadata:
  resourceVersion: ""
  selfLink: ""

so, nothing really changed here - but the problem persists. it actually got worse, since no pod at all will be able to get scheduled. only thing I noticed is the difference in the event logs - depending on if it is a statically or dynamically provisioned pod.

Events of the static provisioned pod:

Events:
  Type     Reason              Age                    From                                                     Message
  ----     ------              ----                   ----                                                     -------
  Normal   Scheduled           4m4s                   default-scheduler                                        Successfully assigned default/aws-csi-static to ip-172-31-60-228.eu-central-1.compute.internal
  Warning  FailedAttachVolume  3m59s (x25 over 4m4s)  attachdetach-controller                                  AttachVolume.Attach failed for volume "aws-csi-static-volume" : volume attachment is being deleted
  Warning  FailedMount         2m1s                   kubelet, ip-172-31-60-228.eu-central-1.compute.internal  Unable to attach or mount volumes: unmounted volumes=[aws-csi-static-volume], unattached volumes=[default-token-lrnp9 aws-csi-static-volume]: timed out waiting for the condition

Events of the dynamic provisioned pod:

Events:
  Type     Reason              Age                     From                                                     Message
  ----     ------              ----                    ----                                                     -------
  Normal   Scheduled           4m27s                   default-scheduler                                        Successfully assigned default/aws-csi-dynamic to ip-172-31-60-228.eu-central-1.compute.internal
  Warning  FailedAttachVolume  3m58s (x25 over 4m12s)  attachdetach-controller                                  AttachVolume.Attach failed for volume "pvc-5a6e6e99-c51a-48bf-b650-60693b4cdb62" : rpc error: code = DeadlineExceeded desc = context deadline exceeded
  Warning  FailedMount         8s (x2 over 2m24s)      kubelet, ip-172-31-60-228.eu-central-1.compute.internal  Unable to attach or mount volumes: unmounted volumes=[persistent-storage], unattached volumes=[persistent-storage default-token-lrnp9]: timed out waiting for the condition

So - after all of this - we arrive again at the point where upgrading from v1.15.x to v1.16.x will break aws-ebs-csi-drivers functionality for our cluster.

I also don't see where our setup would have that special, snow-flakey component build into it, the one that would break the whole setup we came up with in really mysterious ways.

If you need me to post more information or perform further troubleshooting steps - please let me know and I'd be more than happy to help out in any way I can - I will let this cluster sit as it is for now, as it was purely build for testing this weird behaviour.

I'll probably try to bootstrap a v1.16.x cluster and see if I get lucky with the csi-storage for AWS when starting fresh on a green field.

@leakingtapan
Copy link
Contributor

Now trying to schedule a pod with storage (aka. utilizing the aws-ebs-csi-driver) onto the v1.16.3 worker will not show the error message from the title

Looks like the original problem is gone by upgrading master node to 1.16 first.

For the following error:

AttachVolume.Attach failed for volume "aws-csi-static-volume" : rpc error: code = DeadlineExceeded desc = context deadline exceeded

Feels something wrong with volume attachment. What's the log of ebs-csi-controller-xxx where the pod ID being the leader controller service. You can find the leader using kubectl get leases -n kube-system. Do you see any ControllerPublishVolume call for this specific volume? If not, check the csi-attacher sidecar log within the same Pod to see if external attacher is even attempting the attachment.

And Im assuming you are running v0.4 driver on both 1.15 and 1.16 worker nodes?

@gini-schorsch
Copy link

gini-schorsch commented Jan 27, 2020

So the cluster is on v1.17.0 already, as I tried to resolve the problem via updating the setup a few weeks back already. It is still the same 4-node single master setup I initially started with as described above.

We are running these components in the cluster:

  • ebs-csi-controller (statefulset)
    • amazon/aws-ebs-csi-driver:v0.4.0
    • quay.io/k8scsi/csi-provisioner:v1.5.0
    • quay.io/k8scsi/csi-attacher:v1.2.0
    • quay.io/k8scsi/csi-snapshotter:v2.0.0
    • quay.io/k8scsi/csi-resizer:v0.4.0
  • cloud-controller-manager (daemonset)
    • k8s.gcr.io/cloud-controller-manager:v1.15.6
  • ebs-csi-node (daemonset)
    • amazon/aws-ebs-csi-driver:v0.4.0
    • quay.io/k8scsi/csi-node-driver-registrar:v1.2.0
  • cilium:v1.6.3 (daemonset)

Trying to deploy a dynamic volume-claim via this code does not work:

apiVersion: v1
kind: Pod
metadata:
  name: aws-csi-dynamic
spec:
  nodeSelector:
    kubernetes.io/hostname: ip-172-31-60-52.eu-central-1.compute.internal
  containers:
  - name: app
    image: centos
    command: ["/bin/sh"]
    args: ["-c", "while true; do echo $(date -u) >> /data/out.txt; sleep 5; done"]
    volumeMounts:
    - name: persistent-storage
      mountPath: /data
  volumes:
  - name: persistent-storage
    persistentVolumeClaim:
      claimName: aws-csi-dynamic-claim

---
apiVersion: v1
kind: PersistentVolumeClaim
metadata:
  name: aws-csi-dynamic-claim
spec:
  accessModes:
  - ReadWriteOnce
  storageClassName: ebs-sc
  resources:
    requests:
      storage: 1Gi

Trying to do the above, I get these logs from the ebs-csi-controller pod:

kube-system/ebs-csi-controller-0[liveness-probe]: I0127 08:00:42.724812       1 main.go:53] Sending probe request to CSI driver "ebs.csi.aws.com"
kube-system/ebs-csi-controller-0[ebs-plugin]: I0127 08:00:42.725096       1 identity.go:61] Probe: called with args {XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
kube-system/ebs-csi-controller-0[liveness-probe]: I0127 08:00:42.725296       1 main.go:71] Health check succeeded
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:00:45.458768       1 controller.go:1199] provision "default/aws-csi-dynamic-claim" class "ebs-sc": started
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:00:45.459443       1 round_trippers.go:423] curl -k -v -XGET  -H "Accept: application/json, */*" -H "User-Agent: csi-provisioner/v0.0.0 (linux/amd64) kubernetes/$Format" -H "Authorization: <TOKEN>" 'https://10.96.0.1:443/api/v1/persistentvolumes/pvc-df76833f-a9c8-4de6-861c-f367c7169615'
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:00:45.464003       1 round_trippers.go:443] GET https://10.96.0.1:443/api/v1/persistentvolumes/pvc-df76833f-a9c8-4de6-861c-f367c7169615 404 Not Found in 4 milliseconds
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:00:45.464079       1 round_trippers.go:449] Response Headers:
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:00:45.464313       1 round_trippers.go:452]     Content-Type: application/json
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:00:45.464407       1 round_trippers.go:452]     Content-Length: 274
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:00:45.464470       1 round_trippers.go:452]     Date: Mon, 27 Jan 2020 08:00:45 GMT
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:00:45.464544       1 request.go:1017] Response Body: {"kind":"Status","apiVersion":"v1","metadata":{},"status":"Failure","message":"persistentvolumes \"pvc-df76833f-a9c8-4de6-861c-f367c7169615\" not found","reason":"NotFound","details":{"name":"pvc-df76833f-a9c8-4de6-861c-f367c7169615","kind":"persistentvolumes"},"code":404}
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:00:45.465241       1 round_trippers.go:423] curl -k -v -XGET  -H "Authorization: <TOKEN>" -H "Accept: application/json, */*" -H "User-Agent: csi-provisioner/v0.0.0 (linux/amd64) kubernetes/$Format" 'https://10.96.0.1:443/api/v1/nodes/ip-172-31-60-52.eu-central-1.compute.internal'
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:00:45.467047       1 round_trippers.go:443] GET https://10.96.0.1:443/api/v1/nodes/ip-172-31-60-52.eu-central-1.compute.internal 200 OK in 1 milliseconds
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:00:45.467113       1 round_trippers.go:449] Response Headers:
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:00:45.467131       1 round_trippers.go:452]     Content-Type: application/json
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:00:45.467174       1 round_trippers.go:452]     Date: Mon, 27 Jan 2020 08:00:45 GMT
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:00:45.467312       1 request.go:1017] Response Body: {"kind":"Node","apiVersion":"v1","metadata":{"name":"ip-172-31-60-52.eu-central-1.compute.internal","selfLink":"/api/v1/nodes/ip-172-31-60-52.eu-central-1.compute.internal","uid":"8ddb41e2-e7f9-4501-81ae-8e8912852c65","resourceVersion":"11466693","creationTimestamp":"2019-11-29T12:13:40Z","labels":{"beta.kubernetes.io/arch":"amd64","beta.kubernetes.io/instance-type":"t3.medium","beta.kubernetes.io/os":"linux","failure-domain.beta.kubernetes.io/region":"eu-central-1","failure-domain.beta.kubernetes.io/zone":"eu-central-1b","gini.net/spotable":"true","kubernetes.io/arch":"amd64","kubernetes.io/hostname":"ip-172-31-60-52.eu-central-1.compute.internal","kubernetes.io/os":"linux","role.node.kubernetes.io/spot":"","topology.ebs.csi.aws.com/zone":"eu-central-1b"},"annotations":{"csi.volume.kubernetes.io/nodeid":"{\"ebs.csi.aws.com\":\"i-0f84c7af21000b2e2\"}","io.cilium.network.ipv4-cilium-host":"10.23.2.165","io.cilium.network.ipv4-health-ip":"10.23.2.197","io.cilium.network.ipv4-pod-cidr":"10.23.2.0/24","kubeadm.alpha.kubernetes.io/cri-socket":"/var/run/dockershim.sock","node.alpha.kubernetes.io/ttl":"0","volumes.kubernetes.io/controller-managed-attach-detach":"true"}},"spec":{"podCIDR":"10.23.2.0/24","podCIDRs":["10.23.2.0/24"],"providerID":"aws:///eu-central-1b/i-0f84c7af21000b2e2"},"status":{"capacity":{"cpu":"2","ephemeral-storage":"154623428Ki","hugepages-1Gi":"0","hugepages-2Mi":"0","memory":"3976336Ki","pods":"110"},"allocatable":{"cpu":"2","ephemeral-storage":"142500951009","hugepages-1Gi":"0","hugepages-2Mi":"0","memory":"3873936Ki","pods":"110"},"conditions":[{"type":"NetworkUnavailable","status":"False","lastHeartbeatTime":"2020-01-10T15:24:32Z","lastTransitionTime":"2020-01-10T15:24:32Z","reason":"CiliumIsUp","message":"Cilium is running on this node"},{"type":"MemoryPressure","status":"False","lastHeartbeatTime":"2020-01-27T08:00:24Z","lastTransitionTime":"2019-11-29T12:13:40Z","reason":"KubeletHasSufficientMemory","message":"kubelet has sufficient memory available"},{"type":"DiskPressure","status":"False","lastHeartbeatTime":"2020-01-27T08:00:24Z","lastTransitionTime":"2019-11-29T12:13:40Z","reason":"KubeletHasNoDiskPressure","message":"kubelet has no disk pressure"},{"type":"PIDPressure","status":"False","lastHeartbeatTime":"2020-01-27T08:00:24Z","lastTransitionTime":"2019-11-29T12:13:40Z","reason":"KubeletHasSufficientPID","message":"kubelet has sufficient PID available"},{"type":"Ready","status":"True","lastHeartbeatTime":"2020-01-27T08:00:24Z","lastTransitionTime":"2020-01-10T15:40:26Z","reason":"KubeletReady","message":"kubelet is posting ready status. AppArmor enabled"}],"addresses":[{"type":"InternalIP","address":"172.31.60.52"},{"type":"InternalDNS","address":"ip-172-31-60-52.eu-central-1.compute.internal"},{"type":"Hostname","address":"ip-172-31-60-52.eu-central-1.compute.internal"}],"daemonEndpoints":{"kubeletEndpoint":{"Port":10250}},"nodeInfo":{"machineID":"34b39cd01a914ced946add0e6f91244d","systemUUID":"ec200add-d083-1136-1bb1-ae0e13a6a073","bootID":"8b5d711a-2220-4e09-9951-10da0f6e3269","kernelVersion":"5.3.0-0.bpo.2-cloud-amd64","osImage":"Debian GNU/Linux 10 (buster)","containerRuntimeVersion":"docker://18.9.9","kubeletVersion":"v1.17.0","kubeProxyVersion":"v1.17.0","operatingSystem":"linux","architecture":"amd64"},"images":[{"names":["cilium/cilium@sha256:9ed1858afbd66280f605bc204baabe5b7275fce3f19e632e4e59f9631040b725","cilium/cilium:v1.6.3"],"sizeBytes":726368277},{"names":["hub.i.gini.net/amazon/aws-ebs-csi-driver@sha256:04a84276a642a94d7772dcc3730cb35a01b09f3a119cfc78ac8b4de21de0d915","hub.i.gini.net/amazon/aws-ebs-csi-driver:v0.5.0"],"sizeBytes":431146167},{"names":["amazon/aws-ebs-csi-driver@sha256:8e136febb53e2bc2af52e85bb17420385e2697bba6830bb350c9672f862e1e27","amazon/aws-ebs-csi-driver:latest"],"sizeBytes":430518530},{"names":["amazon/aws-ebs-csi-driver@sha256:6c3dd19e3b4f5c14795bf68f9873c1981f90472bde93a3878b2eedbdb369e71c","amazon/aws-ebs-csi-driver:v0.4.0"],"sizeBytes":404637430},{"names":["centos@sha256:f94c1d992c193b3dc09e297ffd54d8a4f1dc946c37cbeceb26d35ce1647f88d9","centos:latest"],"sizeBytes":219583055},{"names":["k8s.gcr.io/kube-proxy@sha256:b2ba9441af30261465e5c41be63e462d0050b09ad280001ae731f399b2b00b75","k8s.gcr.io/kube-proxy:v1.17.0"],"sizeBytes":115960823},{"names":["k8s.gcr.io/kube-proxy@sha256:6c09387bbee4e58eb923695da4fdfa3c37adec632862e79f419f0b5b16865f34","k8s.gcr.io/kube-proxy:v1.16.3"],"sizeBytes":86065116},{"names":["k8s.gcr.io/kube-proxy@sha256:ef245ddefef697c8b42611c237603acf41bfdb2b7ec3e434b7c3592864dcfff8","k8s.gcr.io/kube-proxy:v1.15.6"],"sizeBytes":82412380},{"names":["k8s.gcr.io/coredns@sha256:12eb885b8685b1b13a04ecf5c23bc809c2e57917252fd7b0be9e9c00644e8ee5","k8s.gcr.io/coredns:1.6.2"],"sizeBytes":44100963},{"names":["k8s.gcr.io/coredns@sha256:7ec975f167d815311a7136c32e70735f0d00b73781365df1befd46ed35bd4fe7","k8s.gcr.io/coredns:1.6.5"],"sizeBytes":41578211},{"names":["quay.io/k8scsi/csi-node-driver-registrar@sha256:89cdb2a20bdec89b75e2fbd82a67567ea90b719524990e772f2704b19757188d","quay.io/k8scsi/csi-node-driver-registrar:v1.2.0"],"sizeBytes":17057647},{"names":["quay.io/k8scsi/csi-node-driver-registrar@sha256:13daf82fb99e951a4bff8ae5fc7c17c3a8fe7130be6400990d8f6076c32d4599","quay.io/k8scsi/csi-node-driver-registrar:v1.1.0"],"sizeBytes":15815995},{"names":["quay.io/k8scsi/livenessprobe@sha256:dde617756e0f602adc566ab71fd885f1dad451ad3fb063ac991c95a2ff47aea5","quay.io/k8scsi/livenessprobe:v1.1.0"],"sizeBytes":14967303},{"names":["k8s.gcr.io/pause@sha256:f78411e19d84a252e53bff71a4407a5686c46983a2c2eeed83929b888179acea","k8s.gcr.io/pause:3.1"],"sizeBytes":742472}],"config":{}}}
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:00:45.467765       1 controller.go:425] skip translation of storage class for plugin: ebs.csi.aws.com
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:00:45.467912       1 controller.go:523] CreateVolumeRequest {Name:pvc-df76833f-a9c8-4de6-861c-f367c7169615 CapacityRange:required_bytes:1073741824  VolumeCapabilities:[mount:<fs_type:"ext4" > access_mode:<mode:SINGLE_NODE_WRITER > ] Parameters:map[type:gp2] Secrets:map[] VolumeContentSource:<nil> AccessibilityRequirements:requisite:<segments:<key:"topology.ebs.csi.aws.com/zone" value:"eu-central-1b" > > preferred:<segments:<key:"topology.ebs.csi.aws.com/zone" value:"eu-central-1b" > >  XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:00:45.468226       1 connection.go:182] GRPC call: /csi.v1.Controller/CreateVolume
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:00:45.470705       1 request.go:1017] Request Body: {"kind":"Event","apiVersion":"v1","metadata":{"name":"aws-csi-dynamic-claim.15edaf88976bc8e2","namespace":"default","creationTimestamp":null},"involvedObject":{"kind":"PersistentVolumeClaim","namespace":"default","name":"aws-csi-dynamic-claim","uid":"df76833f-a9c8-4de6-861c-f367c7169615","apiVersion":"v1","resourceVersion":"11466761"},"reason":"Provisioning","message":"External provisioner is provisioning volume for claim \"default/aws-csi-dynamic-claim\"","source":{"component":"ebs.csi.aws.com_ebs-csi-controller-0_85b9be00-484e-43b8-85e1-307531138a05"},"firstTimestamp":"2020-01-27T08:00:45Z","lastTimestamp":"2020-01-27T08:00:45Z","count":1,"type":"Normal","eventTime":null,"reportingComponent":"","reportingInstance":""}
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:00:45.470985       1 round_trippers.go:423] curl -k -v -XPOST  -H "Accept: application/json, */*" -H "Content-Type: application/json" -H "User-Agent: csi-provisioner/v0.0.0 (linux/amd64) kubernetes/$Format" -H "Authorization: <TOKEN>" 'https://10.96.0.1:443/api/v1/namespaces/default/events'
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:00:45.471151       1 event.go:281] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"default", Name:"aws-csi-dynamic-claim", UID:"df76833f-a9c8-4de6-861c-f367c7169615", APIVersion:"v1", ResourceVersion:"11466761", FieldPath:""}): type: 'Normal' reason: 'Provisioning' External provisioner is provisioning volume for claim "default/aws-csi-dynamic-claim"
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:00:45.473355       1 round_trippers.go:443] POST https://10.96.0.1:443/api/v1/namespaces/default/events 201 Created in 2 milliseconds
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:00:45.473860       1 round_trippers.go:449] Response Headers:
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:00:45.473919       1 round_trippers.go:452]     Content-Type: application/json
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:00:45.473985       1 round_trippers.go:452]     Content-Length: 908
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:00:45.474035       1 round_trippers.go:452]     Date: Mon, 27 Jan 2020 08:00:45 GMT
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:00:45.474146       1 request.go:1017] Response Body: {"kind":"Event","apiVersion":"v1","metadata":{"name":"aws-csi-dynamic-claim.15edaf88976bc8e2","namespace":"default","selfLink":"/api/v1/namespaces/default/events/aws-csi-dynamic-claim.15edaf88976bc8e2","uid":"020ce3ae-aff2-4708-a2c0-8c377e62c457","resourceVersion":"11466764","creationTimestamp":"2020-01-27T08:00:45Z"},"involvedObject":{"kind":"PersistentVolumeClaim","namespace":"default","name":"aws-csi-dynamic-claim","uid":"df76833f-a9c8-4de6-861c-f367c7169615","apiVersion":"v1","resourceVersion":"11466761"},"reason":"Provisioning","message":"External provisioner is provisioning volume for claim \"default/aws-csi-dynamic-claim\"","source":{"component":"ebs.csi.aws.com_ebs-csi-controller-0_85b9be00-484e-43b8-85e1-307531138a05"},"firstTimestamp":"2020-01-27T08:00:45Z","lastTimestamp":"2020-01-27T08:00:45Z","count":1,"type":"Normal","eventTime":null,"reportingComponent":"","reportingInstance":""}
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:00:45.468284       1 connection.go:183] GRPC request: {"accessibility_requirements":{"preferred":[{"segments":{"topology.ebs.csi.aws.com/zone":"eu-central-1b"}}],"requisite":[{"segments":{"topology.ebs.csi.aws.com/zone":"eu-central-1b"}}]},"capacity_range":{"required_bytes":1073741824},"name":"pvc-df76833f-a9c8-4de6-861c-f367c7169615","parameters":{"type":"gp2"},"volume_capabilities":[{"AccessType":{"Mount":{"fs_type":"ext4"}},"access_mode":{"mode":1}}]}
kube-system/ebs-csi-controller-0[ebs-plugin]: I0127 08:00:45.483468       1 controller.go:72] CreateVolume: called with args {Name:pvc-df76833f-a9c8-4de6-861c-f367c7169615 CapacityRange:required_bytes:1073741824  VolumeCapabilities:[mount:<fs_type:"ext4" > access_mode:<mode:SINGLE_NODE_WRITER > ] Parameters:map[type:gp2] Secrets:map[] VolumeContentSource:<nil> AccessibilityRequirements:requisite:<segments:<key:"topology.ebs.csi.aws.com/zone" value:"eu-central-1b" > > preferred:<segments:<key:"topology.ebs.csi.aws.com/zone" value:"eu-central-1b" > >  XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
kube-system/ebs-csi-controller-0[csi-attacher]: I0127 08:00:50.083232       1 reflector.go:370] k8s.io/client-go/informers/factory.go:133: Watch close - *v1.PersistentVolume total 3 items received
kube-system/ebs-csi-controller-0[csi-attacher]: I0127 08:00:50.083546       1 round_trippers.go:419] curl -k -v -XGET  -H "Accept: application/json, */*" -H "User-Agent: csi-attacher/v0.0.0 (linux/amd64) kubernetes/$Format" -H "Authorization: <TOKEN>" 'https://10.96.0.1:443/api/v1/persistentvolumes?resourceVersion=11466265&timeout=7m24s&timeoutSeconds=444&watch=true'
kube-system/ebs-csi-controller-0[csi-attacher]: I0127 08:00:50.087253       1 round_trippers.go:438] GET https://10.96.0.1:443/api/v1/persistentvolumes?resourceVersion=11466265&timeout=7m24s&timeoutSeconds=444&watch=true 200 OK in 3 milliseconds
kube-system/ebs-csi-controller-0[csi-attacher]: I0127 08:00:50.087276       1 round_trippers.go:444] Response Headers:
kube-system/ebs-csi-controller-0[csi-attacher]: I0127 08:00:50.087281       1 round_trippers.go:447]     Content-Type: application/json
kube-system/ebs-csi-controller-0[csi-attacher]: I0127 08:00:50.087286       1 round_trippers.go:447]     Date: Mon, 27 Jan 2020 08:00:50 GMT
kube-system/ebs-csi-controller-0[liveness-probe]: I0127 08:00:52.724759       1 main.go:53] Sending probe request to CSI driver "ebs.csi.aws.com"
kube-system/ebs-csi-controller-0[ebs-plugin]: I0127 08:00:52.725080       1 identity.go:61] Probe: called with args {XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
kube-system/ebs-csi-controller-0[liveness-probe]: I0127 08:00:52.725389       1 main.go:71] Health check succeeded
kube-system/ebs-csi-controller-0[liveness-probe]: I0127 08:01:02.724673       1 main.go:53] Sending probe request to CSI driver "ebs.csi.aws.com"
kube-system/ebs-csi-controller-0[ebs-plugin]: I0127 08:01:02.724961       1 identity.go:61] Probe: called with args {XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
kube-system/ebs-csi-controller-0[liveness-probe]: I0127 08:01:02.725183       1 main.go:71] Health check succeeded
kube-system/ebs-csi-controller-0[csi-resizer]: I0127 08:01:05.517944       1 reflector.go:432] k8s.io/client-go/informers/factory.go:135: Watch close - *v1.PersistentVolumeClaim total 6 items received
kube-system/ebs-csi-controller-0[csi-resizer]: I0127 08:01:05.518152       1 round_trippers.go:423] curl -k -v -XGET  -H "Accept: application/json, */*" -H "User-Agent: csi-resizer/v0.0.0 (linux/amd64) kubernetes/$Format" -H "Authorization: <TOKEN>" 'https://10.96.0.1:443/api/v1/persistentvolumeclaims?allowWatchBookmarks=true&resourceVersion=11466761&timeout=9m45s&timeoutSeconds=585&watch=true'
kube-system/ebs-csi-controller-0[csi-resizer]: I0127 08:01:05.520554       1 round_trippers.go:443] GET https://10.96.0.1:443/api/v1/persistentvolumeclaims?allowWatchBookmarks=true&resourceVersion=11466761&timeout=9m45s&timeoutSeconds=585&watch=true 200 OK in 2 milliseconds
kube-system/ebs-csi-controller-0[csi-resizer]: I0127 08:01:05.520727       1 round_trippers.go:449] Response Headers:
kube-system/ebs-csi-controller-0[csi-resizer]: I0127 08:01:05.520874       1 round_trippers.go:452]     Content-Type: application/json
kube-system/ebs-csi-controller-0[csi-resizer]: I0127 08:01:05.521022       1 round_trippers.go:452]     Date: Mon, 27 Jan 2020 08:01:05 GMT
kube-system/ebs-csi-controller-0[ebs-plugin]: E0127 08:01:05.524086       1 driver.go:66] GRPC error: rpc error: code = Internal desc = Could not detach volume "vol-0f20307a465e42e70" from node "i-0f84c7af21000b2e2": error listing AWS instances: "RequestCanceled: request context canceled\ncaused by: context deadline exceeded"
kube-system/ebs-csi-controller-0[csi-attacher]: I0127 08:01:05.522726       1 connection.go:183] GRPC response: {}
kube-system/ebs-csi-controller-0[csi-attacher]: I0127 08:01:05.523384       1 connection.go:184] GRPC error: rpc error: code = DeadlineExceeded desc = context deadline exceeded
kube-system/ebs-csi-controller-0[csi-attacher]: I0127 08:01:05.523401       1 csi_handler.go:422] Saving detach error to "csi-ed61956f40b4c369f01f31455e4bdce6935dde586e629bd78b6c997e616bef3b"
kube-system/ebs-csi-controller-0[csi-attacher]: I0127 08:01:05.523499       1 request.go:942] Request Body: {"kind":"VolumeAttachment","apiVersion":"storage.k8s.io/v1beta1","metadata":{"name":"csi-ed61956f40b4c369f01f31455e4bdce6935dde586e629bd78b6c997e616bef3b","selfLink":"/apis/storage.k8s.io/v1beta1/volumeattachments/csi-ed61956f40b4c369f01f31455e4bdce6935dde586e629bd78b6c997e616bef3b","uid":"d48063b4-55c5-4591-807d-b073d8082cf4","resourceVersion":"11466095","creationTimestamp":"2020-01-24T21:29:30Z","deletionTimestamp":"2020-01-27T07:55:12Z","deletionGracePeriodSeconds":0,"annotations":{"csi.alpha.kubernetes.io/node-id":"i-0f84c7af21000b2e2"},"finalizers":["external-attacher/ebs-csi-aws-com"]},"spec":{"attacher":"ebs.csi.aws.com","source":{"persistentVolumeName":"aws-csi-static-volume"},"nodeName":"ip-172-31-60-52.eu-central-1.compute.internal"},"status":{"attached":false,"attachError":{"time":"2020-01-27T07:55:05Z","message":"rpc error: code = DeadlineExceeded desc = context deadline exceeded"},"detachError":{"time":"2020-01-27T08:01:05Z","message":"rpc error: code = DeadlineExceeded desc = context deadline exceeded"}}}
kube-system/ebs-csi-controller-0[csi-attacher]: I0127 08:01:05.523588       1 round_trippers.go:419] curl -k -v -XPUT  -H "User-Agent: csi-attacher/v0.0.0 (linux/amd64) kubernetes/$Format" -H "Authorization: <TOKEN>" -H "Accept: application/json, */*" -H "Content-Type: application/json" 'https://10.96.0.1:443/apis/storage.k8s.io/v1beta1/volumeattachments/csi-ed61956f40b4c369f01f31455e4bdce6935dde586e629bd78b6c997e616bef3b'
kube-system/ebs-csi-controller-0[csi-attacher]: I0127 08:01:05.526321       1 controller.go:141] Ignoring VolumeAttachment "csi-ed61956f40b4c369f01f31455e4bdce6935dde586e629bd78b6c997e616bef3b" change
kube-system/ebs-csi-controller-0[csi-attacher]: I0127 08:01:05.526398       1 round_trippers.go:438] PUT https://10.96.0.1:443/apis/storage.k8s.io/v1beta1/volumeattachments/csi-ed61956f40b4c369f01f31455e4bdce6935dde586e629bd78b6c997e616bef3b 200 OK in 2 milliseconds
kube-system/ebs-csi-controller-0[csi-attacher]: I0127 08:01:05.526406       1 round_trippers.go:444] Response Headers:
kube-system/ebs-csi-controller-0[csi-attacher]: I0127 08:01:05.526411       1 round_trippers.go:447]     Content-Type: application/json
kube-system/ebs-csi-controller-0[csi-attacher]: I0127 08:01:05.526416       1 round_trippers.go:447]     Content-Length: 1035
kube-system/ebs-csi-controller-0[csi-attacher]: I0127 08:01:05.526421       1 round_trippers.go:447]     Date: Mon, 27 Jan 2020 08:01:05 GMT
kube-system/ebs-csi-controller-0[csi-attacher]: I0127 08:01:05.526448       1 request.go:942] Response Body: {"kind":"VolumeAttachment","apiVersion":"storage.k8s.io/v1beta1","metadata":{"name":"csi-ed61956f40b4c369f01f31455e4bdce6935dde586e629bd78b6c997e616bef3b","selfLink":"/apis/storage.k8s.io/v1beta1/volumeattachments/csi-ed61956f40b4c369f01f31455e4bdce6935dde586e629bd78b6c997e616bef3b","uid":"d48063b4-55c5-4591-807d-b073d8082cf4","resourceVersion":"11466828","creationTimestamp":"2020-01-24T21:29:30Z","deletionTimestamp":"2020-01-27T07:55:12Z","deletionGracePeriodSeconds":0,"annotations":{"csi.alpha.kubernetes.io/node-id":"i-0f84c7af21000b2e2"},"finalizers":["external-attacher/ebs-csi-aws-com"]},"spec":{"attacher":"ebs.csi.aws.com","source":{"persistentVolumeName":"aws-csi-static-volume"},"nodeName":"ip-172-31-60-52.eu-central-1.compute.internal"},"status":{"attached":false,"attachError":{"time":"2020-01-27T07:55:05Z","message":"rpc error: code = DeadlineExceeded desc = context deadline exceeded"},"detachError":{"time":"2020-01-27T08:01:05Z","message":"rpc error: code = DeadlineExceeded desc = context deadline exceeded"}}}
kube-system/ebs-csi-controller-0[csi-attacher]: I0127 08:01:05.526536       1 csi_handler.go:432] Saved detach error to "csi-ed61956f40b4c369f01f31455e4bdce6935dde586e629bd78b6c997e616bef3b"
kube-system/ebs-csi-controller-0[csi-attacher]: I0127 08:01:05.526553       1 csi_handler.go:98] Error processing "csi-ed61956f40b4c369f01f31455e4bdce6935dde586e629bd78b6c997e616bef3b": failed to detach: rpc error: code = DeadlineExceeded desc = context deadline exceeded
kube-system/ebs-csi-controller-0[liveness-probe]: I0127 08:01:12.724708       1 main.go:53] Sending probe request to CSI driver "ebs.csi.aws.com"
kube-system/ebs-csi-controller-0[ebs-plugin]: I0127 08:01:12.724989       1 identity.go:61] Probe: called with args {XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
kube-system/ebs-csi-controller-0[liveness-probe]: I0127 08:01:12.725198       1 main.go:71] Health check succeeded
kube-system/ebs-csi-controller-0[ebs-plugin]: I0127 08:01:22.725030       1 identity.go:61] Probe: called with args {XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
kube-system/ebs-csi-controller-0[liveness-probe]: I0127 08:01:22.724785       1 main.go:53] Sending probe request to CSI driver "ebs.csi.aws.com"
kube-system/ebs-csi-controller-0[liveness-probe]: I0127 08:01:22.725183       1 main.go:71] Health check succeeded
kube-system/ebs-csi-controller-0[ebs-plugin]: I0127 08:01:32.724996       1 identity.go:61] Probe: called with args {XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
kube-system/ebs-csi-controller-0[liveness-probe]: I0127 08:01:32.724674       1 main.go:53] Sending probe request to CSI driver "ebs.csi.aws.com"
kube-system/ebs-csi-controller-0[liveness-probe]: I0127 08:01:32.725189       1 main.go:71] Health check succeeded
kube-system/ebs-csi-controller-0[liveness-probe]: I0127 08:01:42.724718       1 main.go:53] Sending probe request to CSI driver "ebs.csi.aws.com"
kube-system/ebs-csi-controller-0[ebs-plugin]: I0127 08:01:42.725053       1 identity.go:61] Probe: called with args {XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
kube-system/ebs-csi-controller-0[liveness-probe]: I0127 08:01:42.727010       1 main.go:71] Health check succeeded
kube-system/ebs-csi-controller-0[ebs-plugin]: E0127 08:01:45.468607       1 driver.go:66] GRPC error: rpc error: code = Internal desc = RequestCanceled: request context canceled
kube-system/ebs-csi-controller-0[ebs-plugin]: caused by: context canceled
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:01:45.468456       1 connection.go:185] GRPC response: {}
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:01:45.469026       1 connection.go:186] GRPC error: rpc error: code = DeadlineExceeded desc = context deadline exceeded
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:01:45.469074       1 controller.go:1023] Temporary error received, adding PVC df76833f-a9c8-4de6-861c-f367c7169615 to claims in progress
kube-system/ebs-csi-controller-0[csi-provisioner]: W0127 08:01:45.469089       1 controller.go:887] Retrying syncing claim "df76833f-a9c8-4de6-861c-f367c7169615", failure 0
kube-system/ebs-csi-controller-0[csi-provisioner]: E0127 08:01:45.469108       1 controller.go:910] error syncing claim "df76833f-a9c8-4de6-861c-f367c7169615": failed to provision volume with StorageClass "ebs-sc": rpc error: code = DeadlineExceeded desc = context deadline exceeded
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:01:45.469130       1 event.go:281] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"default", Name:"aws-csi-dynamic-claim", UID:"df76833f-a9c8-4de6-861c-f367c7169615", APIVersion:"v1", ResourceVersion:"11466761", FieldPath:""}): type: 'Warning' reason: 'ProvisioningFailed' failed to provision volume with StorageClass "ebs-sc": rpc error: code = DeadlineExceeded desc = context deadline exceeded
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:01:45.469217       1 request.go:1017] Request Body: {"kind":"Event","apiVersion":"v1","metadata":{"name":"aws-csi-dynamic-claim.15edaf968fc70472","namespace":"default","creationTimestamp":null},"involvedObject":{"kind":"PersistentVolumeClaim","namespace":"default","name":"aws-csi-dynamic-claim","uid":"df76833f-a9c8-4de6-861c-f367c7169615","apiVersion":"v1","resourceVersion":"11466761"},"reason":"ProvisioningFailed","message":"failed to provision volume with StorageClass \"ebs-sc\": rpc error: code = DeadlineExceeded desc = context deadline exceeded","source":{"component":"ebs.csi.aws.com_ebs-csi-controller-0_85b9be00-484e-43b8-85e1-307531138a05"},"firstTimestamp":"2020-01-27T08:01:45Z","lastTimestamp":"2020-01-27T08:01:45Z","count":1,"type":"Warning","eventTime":null,"reportingComponent":"","reportingInstance":""}
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:01:45.469370       1 round_trippers.go:423] curl -k -v -XPOST  -H "User-Agent: csi-provisioner/v0.0.0 (linux/amd64) kubernetes/$Format" -H "Authorization: <TOKEN>" -H "Accept: application/json, */*" -H "Content-Type: application/json" 'https://10.96.0.1:443/api/v1/namespaces/default/events'
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:01:45.472905       1 round_trippers.go:443] POST https://10.96.0.1:443/api/v1/namespaces/default/events 201 Created in 3 milliseconds
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:01:45.473440       1 round_trippers.go:449] Response Headers:
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:01:45.473485       1 round_trippers.go:452]     Content-Length: 952
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:01:45.473527       1 round_trippers.go:452]     Date: Mon, 27 Jan 2020 08:01:45 GMT
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:01:45.473551       1 round_trippers.go:452]     Content-Type: application/json
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:01:45.473619       1 request.go:1017] Response Body: {"kind":"Event","apiVersion":"v1","metadata":{"name":"aws-csi-dynamic-claim.15edaf968fc70472","namespace":"default","selfLink":"/api/v1/namespaces/default/events/aws-csi-dynamic-claim.15edaf968fc70472","uid":"fa65bace-d718-4bdd-a5d5-e1280ddca90e","resourceVersion":"11466954","creationTimestamp":"2020-01-27T08:01:45Z"},"involvedObject":{"kind":"PersistentVolumeClaim","namespace":"default","name":"aws-csi-dynamic-claim","uid":"df76833f-a9c8-4de6-861c-f367c7169615","apiVersion":"v1","resourceVersion":"11466761"},"reason":"ProvisioningFailed","message":"failed to provision volume with StorageClass \"ebs-sc\": rpc error: code = DeadlineExceeded desc = context deadline exceeded","source":{"component":"ebs.csi.aws.com_ebs-csi-controller-0_85b9be00-484e-43b8-85e1-307531138a05"},"firstTimestamp":"2020-01-27T08:01:45Z","lastTimestamp":"2020-01-27T08:01:45Z","count":1,"type":"Warning","eventTime":null,"reportingComponent":"","reportingInstance":""}
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:01:46.469394       1 controller.go:1199] provision "default/aws-csi-dynamic-claim" class "ebs-sc": started
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:01:46.470061       1 round_trippers.go:423] curl -k -v -XGET  -H "Authorization: <TOKEN>" -H "Accept: application/json, */*" -H "User-Agent: csi-provisioner/v0.0.0 (linux/amd64) kubernetes/$Format" 'https://10.96.0.1:443/api/v1/persistentvolumes/pvc-df76833f-a9c8-4de6-861c-f367c7169615'
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:01:46.472269       1 round_trippers.go:443] GET https://10.96.0.1:443/api/v1/persistentvolumes/pvc-df76833f-a9c8-4de6-861c-f367c7169615 404 Not Found in 2 milliseconds
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:01:46.472403       1 round_trippers.go:449] Response Headers:
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:01:46.472448       1 round_trippers.go:452]     Content-Type: application/json
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:01:46.472571       1 round_trippers.go:452]     Content-Length: 274
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:01:46.472649       1 round_trippers.go:452]     Date: Mon, 27 Jan 2020 08:01:46 GMT
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:01:46.473027       1 request.go:1017] Response Body: {"kind":"Status","apiVersion":"v1","metadata":{},"status":"Failure","message":"persistentvolumes \"pvc-df76833f-a9c8-4de6-861c-f367c7169615\" not found","reason":"NotFound","details":{"name":"pvc-df76833f-a9c8-4de6-861c-f367c7169615","kind":"persistentvolumes"},"code":404}
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:01:46.473310       1 round_trippers.go:423] curl -k -v -XGET  -H "Accept: application/json, */*" -H "User-Agent: csi-provisioner/v0.0.0 (linux/amd64) kubernetes/$Format" -H "Authorization: <TOKEN>" 'https://10.96.0.1:443/api/v1/nodes/ip-172-31-60-52.eu-central-1.compute.internal'
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:01:46.477284       1 round_trippers.go:443] GET https://10.96.0.1:443/api/v1/nodes/ip-172-31-60-52.eu-central-1.compute.internal 200 OK in 3 milliseconds
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:01:46.477413       1 round_trippers.go:449] Response Headers:
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:01:46.477490       1 round_trippers.go:452]     Content-Type: application/json
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:01:46.477569       1 round_trippers.go:452]     Date: Mon, 27 Jan 2020 08:01:46 GMT
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:01:46.477763       1 request.go:1017] Response Body: {"kind":"Node","apiVersion":"v1","metadata":{"name":"ip-172-31-60-52.eu-central-1.compute.internal","selfLink":"/api/v1/nodes/ip-172-31-60-52.eu-central-1.compute.internal","uid":"8ddb41e2-e7f9-4501-81ae-8e8912852c65","resourceVersion":"11466887","creationTimestamp":"2019-11-29T12:13:40Z","labels":{"beta.kubernetes.io/arch":"amd64","beta.kubernetes.io/instance-type":"t3.medium","beta.kubernetes.io/os":"linux","failure-domain.beta.kubernetes.io/region":"eu-central-1","failure-domain.beta.kubernetes.io/zone":"eu-central-1b","gini.net/spotable":"true","kubernetes.io/arch":"amd64","kubernetes.io/hostname":"ip-172-31-60-52.eu-central-1.compute.internal","kubernetes.io/os":"linux","role.node.kubernetes.io/spot":"","topology.ebs.csi.aws.com/zone":"eu-central-1b"},"annotations":{"csi.volume.kubernetes.io/nodeid":"{\"ebs.csi.aws.com\":\"i-0f84c7af21000b2e2\"}","io.cilium.network.ipv4-cilium-host":"10.23.2.165","io.cilium.network.ipv4-health-ip":"10.23.2.197","io.cilium.network.ipv4-pod-cidr":"10.23.2.0/24","kubeadm.alpha.kubernetes.io/cri-socket":"/var/run/dockershim.sock","node.alpha.kubernetes.io/ttl":"0","volumes.kubernetes.io/controller-managed-attach-detach":"true"}},"spec":{"podCIDR":"10.23.2.0/24","podCIDRs":["10.23.2.0/24"],"providerID":"aws:///eu-central-1b/i-0f84c7af21000b2e2"},"status":{"capacity":{"cpu":"2","ephemeral-storage":"154623428Ki","hugepages-1Gi":"0","hugepages-2Mi":"0","memory":"3976336Ki","pods":"110"},"allocatable":{"cpu":"2","ephemeral-storage":"142500951009","hugepages-1Gi":"0","hugepages-2Mi":"0","memory":"3873936Ki","pods":"110"},"conditions":[{"type":"NetworkUnavailable","status":"False","lastHeartbeatTime":"2020-01-10T15:24:32Z","lastTransitionTime":"2020-01-10T15:24:32Z","reason":"CiliumIsUp","message":"Cilium is running on this node"},{"type":"MemoryPressure","status":"False","lastHeartbeatTime":"2020-01-27T08:01:24Z","lastTransitionTime":"2019-11-29T12:13:40Z","reason":"KubeletHasSufficientMemory","message":"kubelet has sufficient memory available"},{"type":"DiskPressure","status":"False","lastHeartbeatTime":"2020-01-27T08:01:24Z","lastTransitionTime":"2019-11-29T12:13:40Z","reason":"KubeletHasNoDiskPressure","message":"kubelet has no disk pressure"},{"type":"PIDPressure","status":"False","lastHeartbeatTime":"2020-01-27T08:01:24Z","lastTransitionTime":"2019-11-29T12:13:40Z","reason":"KubeletHasSufficientPID","message":"kubelet has sufficient PID available"},{"type":"Ready","status":"True","lastHeartbeatTime":"2020-01-27T08:01:24Z","lastTransitionTime":"2020-01-10T15:40:26Z","reason":"KubeletReady","message":"kubelet is posting ready status. AppArmor enabled"}],"addresses":[{"type":"InternalIP","address":"172.31.60.52"},{"type":"InternalDNS","address":"ip-172-31-60-52.eu-central-1.compute.internal"},{"type":"Hostname","address":"ip-172-31-60-52.eu-central-1.compute.internal"}],"daemonEndpoints":{"kubeletEndpoint":{"Port":10250}},"nodeInfo":{"machineID":"34b39cd01a914ced946add0e6f91244d","systemUUID":"ec200add-d083-1136-1bb1-ae0e13a6a073","bootID":"8b5d711a-2220-4e09-9951-10da0f6e3269","kernelVersion":"5.3.0-0.bpo.2-cloud-amd64","osImage":"Debian GNU/Linux 10 (buster)","containerRuntimeVersion":"docker://18.9.9","kubeletVersion":"v1.17.0","kubeProxyVersion":"v1.17.0","operatingSystem":"linux","architecture":"amd64"},"images":[{"names":["cilium/cilium@sha256:9ed1858afbd66280f605bc204baabe5b7275fce3f19e632e4e59f9631040b725","cilium/cilium:v1.6.3"],"sizeBytes":726368277},{"names":["hub.i.gini.net/amazon/aws-ebs-csi-driver@sha256:04a84276a642a94d7772dcc3730cb35a01b09f3a119cfc78ac8b4de21de0d915","hub.i.gini.net/amazon/aws-ebs-csi-driver:v0.5.0"],"sizeBytes":431146167},{"names":["amazon/aws-ebs-csi-driver@sha256:8e136febb53e2bc2af52e85bb17420385e2697bba6830bb350c9672f862e1e27","amazon/aws-ebs-csi-driver:latest"],"sizeBytes":430518530},{"names":["amazon/aws-ebs-csi-driver@sha256:6c3dd19e3b4f5c14795bf68f9873c1981f90472bde93a3878b2eedbdb369e71c","amazon/aws-ebs-csi-driver:v0.4.0"],"sizeBytes":404637430},{"names":["centos@sha256:f94c1d992c193b3dc09e297ffd54d8a4f1dc946c37cbeceb26d35ce1647f88d9","centos:latest"],"sizeBytes":219583055},{"names":["k8s.gcr.io/kube-proxy@sha256:b2ba9441af30261465e5c41be63e462d0050b09ad280001ae731f399b2b00b75","k8s.gcr.io/kube-proxy:v1.17.0"],"sizeBytes":115960823},{"names":["k8s.gcr.io/kube-proxy@sha256:6c09387bbee4e58eb923695da4fdfa3c37adec632862e79f419f0b5b16865f34","k8s.gcr.io/kube-proxy:v1.16.3"],"sizeBytes":86065116},{"names":["k8s.gcr.io/kube-proxy@sha256:ef245ddefef697c8b42611c237603acf41bfdb2b7ec3e434b7c3592864dcfff8","k8s.gcr.io/kube-proxy:v1.15.6"],"sizeBytes":82412380},{"names":["k8s.gcr.io/coredns@sha256:12eb885b8685b1b13a04ecf5c23bc809c2e57917252fd7b0be9e9c00644e8ee5","k8s.gcr.io/coredns:1.6.2"],"sizeBytes":44100963},{"names":["k8s.gcr.io/coredns@sha256:7ec975f167d815311a7136c32e70735f0d00b73781365df1befd46ed35bd4fe7","k8s.gcr.io/coredns:1.6.5"],"sizeBytes":41578211},{"names":["quay.io/k8scsi/csi-node-driver-registrar@sha256:89cdb2a20bdec89b75e2fbd82a67567ea90b719524990e772f2704b19757188d","quay.io/k8scsi/csi-node-driver-registrar:v1.2.0"],"sizeBytes":17057647},{"names":["quay.io/k8scsi/csi-node-driver-registrar@sha256:13daf82fb99e951a4bff8ae5fc7c17c3a8fe7130be6400990d8f6076c32d4599","quay.io/k8scsi/csi-node-driver-registrar:v1.1.0"],"sizeBytes":15815995},{"names":["quay.io/k8scsi/livenessprobe@sha256:dde617756e0f602adc566ab71fd885f1dad451ad3fb063ac991c95a2ff47aea5","quay.io/k8scsi/livenessprobe:v1.1.0"],"sizeBytes":14967303},{"names":["k8s.gcr.io/pause@sha256:f78411e19d84a252e53bff71a4407a5686c46983a2c2eeed83929b888179acea","k8s.gcr.io/pause:3.1"],"sizeBytes":742472}],"config":{}}}
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:01:46.478301       1 controller.go:425] skip translation of storage class for plugin: ebs.csi.aws.com
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:01:46.478451       1 controller.go:523] CreateVolumeRequest {Name:pvc-df76833f-a9c8-4de6-861c-f367c7169615 CapacityRange:required_bytes:1073741824  VolumeCapabilities:[mount:<fs_type:"ext4" > access_mode:<mode:SINGLE_NODE_WRITER > ] Parameters:map[type:gp2] Secrets:map[] VolumeContentSource:<nil> AccessibilityRequirements:requisite:<segments:<key:"topology.ebs.csi.aws.com/zone" value:"eu-central-1b" > > preferred:<segments:<key:"topology.ebs.csi.aws.com/zone" value:"eu-central-1b" > >  XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:01:46.478594       1 connection.go:182] GRPC call: /csi.v1.Controller/CreateVolume
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:01:46.481096       1 request.go:1017] Request Body: {"count":2,"lastTimestamp":"2020-01-27T08:01:46Z","message":"External provisioner is provisioning volume for claim \"default/aws-csi-dynamic-claim\""}
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:01:46.481393       1 round_trippers.go:423] curl -k -v -XPATCH  -H "Accept: application/json, */*" -H "User-Agent: csi-provisioner/v0.0.0 (linux/amd64) kubernetes/$Format" -H "Authorization: <TOKEN>" -H "Content-Type: application/strategic-merge-patch+json" 'https://10.96.0.1:443/api/v1/namespaces/default/events/aws-csi-dynamic-claim.15edaf88976bc8e2'
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:01:46.481948       1 event.go:281] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"default", Name:"aws-csi-dynamic-claim", UID:"df76833f-a9c8-4de6-861c-f367c7169615", APIVersion:"v1", ResourceVersion:"11466761", FieldPath:""}): type: 'Normal' reason: 'Provisioning' External provisioner is provisioning volume for claim "default/aws-csi-dynamic-claim"
kube-system/ebs-csi-controller-0[ebs-plugin]: I0127 08:01:46.484771       1 controller.go:72] CreateVolume: called with args {Name:pvc-df76833f-a9c8-4de6-861c-f367c7169615 CapacityRange:required_bytes:1073741824  VolumeCapabilities:[mount:<fs_type:"ext4" > access_mode:<mode:SINGLE_NODE_WRITER > ] Parameters:map[type:gp2] Secrets:map[] VolumeContentSource:<nil> AccessibilityRequirements:requisite:<segments:<key:"topology.ebs.csi.aws.com/zone" value:"eu-central-1b" > > preferred:<segments:<key:"topology.ebs.csi.aws.com/zone" value:"eu-central-1b" > >  XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:01:46.484187       1 round_trippers.go:443] PATCH https://10.96.0.1:443/api/v1/namespaces/default/events/aws-csi-dynamic-claim.15edaf88976bc8e2 200 OK in 2 milliseconds
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:01:46.484222       1 round_trippers.go:449] Response Headers:
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:01:46.484228       1 round_trippers.go:452]     Content-Type: application/json
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:01:46.484233       1 round_trippers.go:452]     Content-Length: 908
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:01:46.484237       1 round_trippers.go:452]     Date: Mon, 27 Jan 2020 08:01:46 GMT
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:01:46.484262       1 request.go:1017] Response Body: {"kind":"Event","apiVersion":"v1","metadata":{"name":"aws-csi-dynamic-claim.15edaf88976bc8e2","namespace":"default","selfLink":"/api/v1/namespaces/default/events/aws-csi-dynamic-claim.15edaf88976bc8e2","uid":"020ce3ae-aff2-4708-a2c0-8c377e62c457","resourceVersion":"11466959","creationTimestamp":"2020-01-27T08:00:45Z"},"involvedObject":{"kind":"PersistentVolumeClaim","namespace":"default","name":"aws-csi-dynamic-claim","uid":"df76833f-a9c8-4de6-861c-f367c7169615","apiVersion":"v1","resourceVersion":"11466761"},"reason":"Provisioning","message":"External provisioner is provisioning volume for claim \"default/aws-csi-dynamic-claim\"","source":{"component":"ebs.csi.aws.com_ebs-csi-controller-0_85b9be00-484e-43b8-85e1-307531138a05"},"firstTimestamp":"2020-01-27T08:00:45Z","lastTimestamp":"2020-01-27T08:01:46Z","count":2,"type":"Normal","eventTime":null,"reportingComponent":"","reportingInstance":""}
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:01:46.478606       1 connection.go:183] GRPC request: {"accessibility_requirements":{"preferred":[{"segments":{"topology.ebs.csi.aws.com/zone":"eu-central-1b"}}],"requisite":[{"segments":{"topology.ebs.csi.aws.com/zone":"eu-central-1b"}}]},"capacity_range":{"required_bytes":1073741824},"name":"pvc-df76833f-a9c8-4de6-861c-f367c7169615","parameters":{"type":"gp2"},"volume_capabilities":[{"AccessType":{"Mount":{"fs_type":"ext4"}},"access_mode":{"mode":1}}]}
kube-system/ebs-csi-controller-0[liveness-probe]: I0127 08:01:52.724789       1 main.go:53] Sending probe request to CSI driver "ebs.csi.aws.com"
kube-system/ebs-csi-controller-0[ebs-plugin]: I0127 08:01:52.725498       1 identity.go:61] Probe: called with args {XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
kube-system/ebs-csi-controller-0[liveness-probe]: I0127 08:01:52.727858       1 main.go:71] Health check succeeded
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:01:53.121995       1 reflector.go:432] sigs.k8s.io/sig-storage-lib-external-provisioner/controller/controller.go:804: Watch close - *v1.PersistentVolume total 4 items received
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:01:53.122148       1 round_trippers.go:423] curl -k -v -XGET  -H "Accept: application/json, */*" -H "User-Agent: csi-provisioner/v0.0.0 (linux/amd64) kubernetes/$Format" -H "Authorization: <TOKEN>" 'https://10.96.0.1:443/api/v1/persistentvolumes?allowWatchBookmarks=true&resourceVersion=11466265&timeout=7m25s&timeoutSeconds=445&watch=true'
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:01:53.123136       1 round_trippers.go:443] GET https://10.96.0.1:443/api/v1/persistentvolumes?allowWatchBookmarks=true&resourceVersion=11466265&timeout=7m25s&timeoutSeconds=445&watch=true 200 OK in 0 milliseconds
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:01:53.123154       1 round_trippers.go:449] Response Headers:
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:01:53.123159       1 round_trippers.go:452]     Content-Type: application/json
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:01:53.123164       1 round_trippers.go:452]     Date: Mon, 27 Jan 2020 08:01:53 GMT
kube-system/ebs-csi-controller-0[liveness-probe]: I0127 08:02:02.724669       1 main.go:53] Sending probe request to CSI driver "ebs.csi.aws.com"
kube-system/ebs-csi-controller-0[ebs-plugin]: I0127 08:02:02.724988       1 identity.go:61] Probe: called with args {XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
kube-system/ebs-csi-controller-0[liveness-probe]: I0127 08:02:02.725209       1 main.go:71] Health check succeeded
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:02:08.012574       1 reflector.go:432] k8s.io/client-go/informers/factory.go:135: Watch close - *v1.Node total 38 items received
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:02:08.012727       1 round_trippers.go:423] curl -k -v -XGET  -H "User-Agent: csi-provisioner/v0.0.0 (linux/amd64) kubernetes/$Format" -H "Accept: application/json, */*" -H "Authorization: <TOKEN>" 'https://10.96.0.1:443/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=11466935&timeout=7m51s&timeoutSeconds=471&watch=true'
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:02:08.013605       1 round_trippers.go:443] GET https://10.96.0.1:443/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=11466935&timeout=7m51s&timeoutSeconds=471&watch=true 200 OK in 0 milliseconds
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:02:08.013623       1 round_trippers.go:449] Response Headers:
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:02:08.013646       1 round_trippers.go:452]     Content-Type: application/json
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:02:08.013650       1 round_trippers.go:452]     Date: Mon, 27 Jan 2020 08:02:08 GMT
kube-system/ebs-csi-controller-0[liveness-probe]: I0127 08:02:12.724564       1 main.go:53] Sending probe request to CSI driver "ebs.csi.aws.com"
kube-system/ebs-csi-controller-0[ebs-plugin]: I0127 08:02:12.725327       1 identity.go:61] Probe: called with args {XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
kube-system/ebs-csi-controller-0[liveness-probe]: I0127 08:02:12.727792       1 main.go:71] Health check succeeded
kube-system/ebs-csi-controller-0[ebs-plugin]: I0127 08:02:22.724965       1 identity.go:61] Probe: called with args {XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
kube-system/ebs-csi-controller-0[liveness-probe]: I0127 08:02:22.724707       1 main.go:53] Sending probe request to CSI driver "ebs.csi.aws.com"
kube-system/ebs-csi-controller-0[liveness-probe]: I0127 08:02:22.725183       1 main.go:71] Health check succeeded
kube-system/ebs-csi-controller-0[liveness-probe]: I0127 08:02:32.724754       1 main.go:53] Sending probe request to CSI driver "ebs.csi.aws.com"
kube-system/ebs-csi-controller-0[ebs-plugin]: I0127 08:02:32.725270       1 identity.go:61] Probe: called with args {XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
kube-system/ebs-csi-controller-0[liveness-probe]: I0127 08:02:32.725783       1 main.go:71] Health check succeeded
kube-system/ebs-csi-controller-0[liveness-probe]: I0127 08:02:42.724773       1 main.go:53] Sending probe request to CSI driver "ebs.csi.aws.com"
kube-system/ebs-csi-controller-0[ebs-plugin]: I0127 08:02:42.725126       1 identity.go:61] Probe: called with args {XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
kube-system/ebs-csi-controller-0[liveness-probe]: I0127 08:02:42.725386       1 main.go:71] Health check succeeded
kube-system/ebs-csi-controller-0[csi-attacher]: I0127 08:02:45.080877       1 reflector.go:370] k8s.io/client-go/informers/factory.go:133: Watch close - *v1beta1.VolumeAttachment total 5 items received
kube-system/ebs-csi-controller-0[csi-attacher]: I0127 08:02:45.081330       1 round_trippers.go:419] curl -k -v -XGET  -H "Accept: application/json, */*" -H "User-Agent: csi-attacher/v0.0.0 (linux/amd64) kubernetes/$Format" -H "Authorization: <TOKEN>" 'https://10.96.0.1:443/apis/storage.k8s.io/v1beta1/volumeattachments?resourceVersion=11466828&timeout=5m37s&timeoutSeconds=337&watch=true'
kube-system/ebs-csi-controller-0[csi-attacher]: I0127 08:02:45.082461       1 round_trippers.go:438] GET https://10.96.0.1:443/apis/storage.k8s.io/v1beta1/volumeattachments?resourceVersion=11466828&timeout=5m37s&timeoutSeconds=337&watch=true 200 OK in 1 milliseconds
kube-system/ebs-csi-controller-0[csi-attacher]: I0127 08:02:45.082517       1 round_trippers.go:444] Response Headers:
kube-system/ebs-csi-controller-0[csi-attacher]: I0127 08:02:45.082537       1 round_trippers.go:447]     Content-Type: application/json
kube-system/ebs-csi-controller-0[csi-attacher]: I0127 08:02:45.082557       1 round_trippers.go:447]     Date: Mon, 27 Jan 2020 08:02:45 GMT
kube-system/ebs-csi-controller-0[ebs-plugin]: E0127 08:02:46.478954       1 driver.go:66] GRPC error: rpc error: code = Internal desc = RequestCanceled: request context canceled
kube-system/ebs-csi-controller-0[ebs-plugin]: caused by: context deadline exceeded
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:02:46.478897       1 connection.go:185] GRPC response: {}
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:02:46.479803       1 connection.go:186] GRPC error: rpc error: code = DeadlineExceeded desc = context deadline exceeded
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:02:46.479899       1 controller.go:1023] Temporary error received, adding PVC df76833f-a9c8-4de6-861c-f367c7169615 to claims in progress
kube-system/ebs-csi-controller-0[csi-provisioner]: W0127 08:02:46.479933       1 controller.go:887] Retrying syncing claim "df76833f-a9c8-4de6-861c-f367c7169615", failure 1
kube-system/ebs-csi-controller-0[csi-provisioner]: E0127 08:02:46.479997       1 controller.go:910] error syncing claim "df76833f-a9c8-4de6-861c-f367c7169615": failed to provision volume with StorageClass "ebs-sc": rpc error: code = DeadlineExceeded desc = context deadline exceeded
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:02:46.480367       1 request.go:1017] Request Body: {"count":2,"lastTimestamp":"2020-01-27T08:02:46Z","message":"failed to provision volume with StorageClass \"ebs-sc\": rpc error: code = DeadlineExceeded desc = context deadline exceeded"}
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:02:46.480659       1 round_trippers.go:423] curl -k -v -XPATCH  -H "Content-Type: application/strategic-merge-patch+json" -H "Authorization: <TOKEN>" -H "User-Agent: csi-provisioner/v0.0.0 (linux/amd64) kubernetes/$Format" -H "Accept: application/json, */*" 'https://10.96.0.1:443/api/v1/namespaces/default/events/aws-csi-dynamic-claim.15edaf968fc70472'
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:02:46.481046       1 event.go:281] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"default", Name:"aws-csi-dynamic-claim", UID:"df76833f-a9c8-4de6-861c-f367c7169615", APIVersion:"v1", ResourceVersion:"11466761", FieldPath:""}): type: 'Warning' reason: 'ProvisioningFailed' failed to provision volume with StorageClass "ebs-sc": rpc error: code = DeadlineExceeded desc = context deadline exceeded
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:02:46.484515       1 round_trippers.go:443] PATCH https://10.96.0.1:443/api/v1/namespaces/default/events/aws-csi-dynamic-claim.15edaf968fc70472 200 OK in 3 milliseconds
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:02:46.484556       1 round_trippers.go:449] Response Headers:
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:02:46.484563       1 round_trippers.go:452]     Content-Type: application/json
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:02:46.484568       1 round_trippers.go:452]     Content-Length: 952
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:02:46.484573       1 round_trippers.go:452]     Date: Mon, 27 Jan 2020 08:02:46 GMT
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:02:46.484609       1 request.go:1017] Response Body: {"kind":"Event","apiVersion":"v1","metadata":{"name":"aws-csi-dynamic-claim.15edaf968fc70472","namespace":"default","selfLink":"/api/v1/namespaces/default/events/aws-csi-dynamic-claim.15edaf968fc70472","uid":"fa65bace-d718-4bdd-a5d5-e1280ddca90e","resourceVersion":"11467148","creationTimestamp":"2020-01-27T08:01:45Z"},"involvedObject":{"kind":"PersistentVolumeClaim","namespace":"default","name":"aws-csi-dynamic-claim","uid":"df76833f-a9c8-4de6-861c-f367c7169615","apiVersion":"v1","resourceVersion":"11466761"},"reason":"ProvisioningFailed","message":"failed to provision volume with StorageClass \"ebs-sc\": rpc error: code = DeadlineExceeded desc = context deadline exceeded","source":{"component":"ebs.csi.aws.com_ebs-csi-controller-0_85b9be00-484e-43b8-85e1-307531138a05"},"firstTimestamp":"2020-01-27T08:01:45Z","lastTimestamp":"2020-01-27T08:02:46Z","count":2,"type":"Warning","eventTime":null,"reportingComponent":"","reportingInstance":""}
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:02:48.480159       1 controller.go:1199] provision "default/aws-csi-dynamic-claim" class "ebs-sc": started
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:02:48.480306       1 round_trippers.go:423] curl -k -v -XGET  -H "Accept: application/json, */*" -H "User-Agent: csi-provisioner/v0.0.0 (linux/amd64) kubernetes/$Format" -H "Authorization: <TOKEN>" 'https://10.96.0.1:443/api/v1/persistentvolumes/pvc-df76833f-a9c8-4de6-861c-f367c7169615'
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:02:48.489373       1 round_trippers.go:443] GET https://10.96.0.1:443/api/v1/persistentvolumes/pvc-df76833f-a9c8-4de6-861c-f367c7169615 404 Not Found in 9 milliseconds
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:02:48.489397       1 round_trippers.go:449] Response Headers:
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:02:48.489402       1 round_trippers.go:452]     Content-Type: application/json
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:02:48.489407       1 round_trippers.go:452]     Content-Length: 274
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:02:48.489410       1 round_trippers.go:452]     Date: Mon, 27 Jan 2020 08:02:48 GMT
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:02:48.489439       1 request.go:1017] Response Body: {"kind":"Status","apiVersion":"v1","metadata":{},"status":"Failure","message":"persistentvolumes \"pvc-df76833f-a9c8-4de6-861c-f367c7169615\" not found","reason":"NotFound","details":{"name":"pvc-df76833f-a9c8-4de6-861c-f367c7169615","kind":"persistentvolumes"},"code":404}
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:02:48.489620       1 round_trippers.go:423] curl -k -v -XGET  -H "User-Agent: csi-provisioner/v0.0.0 (linux/amd64) kubernetes/$Format" -H "Accept: application/json, */*" -H "Authorization: <TOKEN>" 'https://10.96.0.1:443/api/v1/nodes/ip-172-31-60-52.eu-central-1.compute.internal'
kube-system/ebs-csi-controller-0[ebs-plugin]: I0127 08:02:48.498506       1 controller.go:72] CreateVolume: called with args {Name:pvc-df76833f-a9c8-4de6-861c-f367c7169615 CapacityRange:required_bytes:1073741824  VolumeCapabilities:[mount:<fs_type:"ext4" > access_mode:<mode:SINGLE_NODE_WRITER > ] Parameters:map[type:gp2] Secrets:map[] VolumeContentSource:<nil> AccessibilityRequirements:requisite:<segments:<key:"topology.ebs.csi.aws.com/zone" value:"eu-central-1b" > > preferred:<segments:<key:"topology.ebs.csi.aws.com/zone" value:"eu-central-1b" > >  XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:02:48.495234       1 round_trippers.go:443] GET https://10.96.0.1:443/api/v1/nodes/ip-172-31-60-52.eu-central-1.compute.internal 200 OK in 5 milliseconds
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:02:48.495248       1 round_trippers.go:449] Response Headers:
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:02:48.495252       1 round_trippers.go:452]     Date: Mon, 27 Jan 2020 08:02:48 GMT
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:02:48.495255       1 round_trippers.go:452]     Content-Type: application/json
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:02:48.495315       1 request.go:1017] Response Body: {"kind":"Node","apiVersion":"v1","metadata":{"name":"ip-172-31-60-52.eu-central-1.compute.internal","selfLink":"/api/v1/nodes/ip-172-31-60-52.eu-central-1.compute.internal","uid":"8ddb41e2-e7f9-4501-81ae-8e8912852c65","resourceVersion":"11467077","creationTimestamp":"2019-11-29T12:13:40Z","labels":{"beta.kubernetes.io/arch":"amd64","beta.kubernetes.io/instance-type":"t3.medium","beta.kubernetes.io/os":"linux","failure-domain.beta.kubernetes.io/region":"eu-central-1","failure-domain.beta.kubernetes.io/zone":"eu-central-1b","gini.net/spotable":"true","kubernetes.io/arch":"amd64","kubernetes.io/hostname":"ip-172-31-60-52.eu-central-1.compute.internal","kubernetes.io/os":"linux","role.node.kubernetes.io/spot":"","topology.ebs.csi.aws.com/zone":"eu-central-1b"},"annotations":{"csi.volume.kubernetes.io/nodeid":"{\"ebs.csi.aws.com\":\"i-0f84c7af21000b2e2\"}","io.cilium.network.ipv4-cilium-host":"10.23.2.165","io.cilium.network.ipv4-health-ip":"10.23.2.197","io.cilium.network.ipv4-pod-cidr":"10.23.2.0/24","kubeadm.alpha.kubernetes.io/cri-socket":"/var/run/dockershim.sock","node.alpha.kubernetes.io/ttl":"0","volumes.kubernetes.io/controller-managed-attach-detach":"true"}},"spec":{"podCIDR":"10.23.2.0/24","podCIDRs":["10.23.2.0/24"],"providerID":"aws:///eu-central-1b/i-0f84c7af21000b2e2"},"status":{"capacity":{"cpu":"2","ephemeral-storage":"154623428Ki","hugepages-1Gi":"0","hugepages-2Mi":"0","memory":"3976336Ki","pods":"110"},"allocatable":{"cpu":"2","ephemeral-storage":"142500951009","hugepages-1Gi":"0","hugepages-2Mi":"0","memory":"3873936Ki","pods":"110"},"conditions":[{"type":"NetworkUnavailable","status":"False","lastHeartbeatTime":"2020-01-10T15:24:32Z","lastTransitionTime":"2020-01-10T15:24:32Z","reason":"CiliumIsUp","message":"Cilium is running on this node"},{"type":"MemoryPressure","status":"False","lastHeartbeatTime":"2020-01-27T08:02:24Z","lastTransitionTime":"2019-11-29T12:13:40Z","reason":"KubeletHasSufficientMemory","message":"kubelet has sufficient memory available"},{"type":"DiskPressure","status":"False","lastHeartbeatTime":"2020-01-27T08:02:24Z","lastTransitionTime":"2019-11-29T12:13:40Z","reason":"KubeletHasNoDiskPressure","message":"kubelet has no disk pressure"},{"type":"PIDPressure","status":"False","lastHeartbeatTime":"2020-01-27T08:02:24Z","lastTransitionTime":"2019-11-29T12:13:40Z","reason":"KubeletHasSufficientPID","message":"kubelet has sufficient PID available"},{"type":"Ready","status":"True","lastHeartbeatTime":"2020-01-27T08:02:24Z","lastTransitionTime":"2020-01-10T15:40:26Z","reason":"KubeletReady","message":"kubelet is posting ready status. AppArmor enabled"}],"addresses":[{"type":"InternalIP","address":"172.31.60.52"},{"type":"InternalDNS","address":"ip-172-31-60-52.eu-central-1.compute.internal"},{"type":"Hostname","address":"ip-172-31-60-52.eu-central-1.compute.internal"}],"daemonEndpoints":{"kubeletEndpoint":{"Port":10250}},"nodeInfo":{"machineID":"34b39cd01a914ced946add0e6f91244d","systemUUID":"ec200add-d083-1136-1bb1-ae0e13a6a073","bootID":"8b5d711a-2220-4e09-9951-10da0f6e3269","kernelVersion":"5.3.0-0.bpo.2-cloud-amd64","osImage":"Debian GNU/Linux 10 (buster)","containerRuntimeVersion":"docker://18.9.9","kubeletVersion":"v1.17.0","kubeProxyVersion":"v1.17.0","operatingSystem":"linux","architecture":"amd64"},"images":[{"names":["cilium/cilium@sha256:9ed1858afbd66280f605bc204baabe5b7275fce3f19e632e4e59f9631040b725","cilium/cilium:v1.6.3"],"sizeBytes":726368277},{"names":["hub.i.gini.net/amazon/aws-ebs-csi-driver@sha256:04a84276a642a94d7772dcc3730cb35a01b09f3a119cfc78ac8b4de21de0d915","hub.i.gini.net/amazon/aws-ebs-csi-driver:v0.5.0"],"sizeBytes":431146167},{"names":["amazon/aws-ebs-csi-driver@sha256:8e136febb53e2bc2af52e85bb17420385e2697bba6830bb350c9672f862e1e27","amazon/aws-ebs-csi-driver:latest"],"sizeBytes":430518530},{"names":["amazon/aws-ebs-csi-driver@sha256:6c3dd19e3b4f5c14795bf68f9873c1981f90472bde93a3878b2eedbdb369e71c","amazon/aws-ebs-csi-driver:v0.4.0"],"sizeBytes":404637430},{"names":["centos@sha256:f94c1d992c193b3dc09e297ffd54d8a4f1dc946c37cbeceb26d35ce1647f88d9","centos:latest"],"sizeBytes":219583055},{"names":["k8s.gcr.io/kube-proxy@sha256:b2ba9441af30261465e5c41be63e462d0050b09ad280001ae731f399b2b00b75","k8s.gcr.io/kube-proxy:v1.17.0"],"sizeBytes":115960823},{"names":["k8s.gcr.io/kube-proxy@sha256:6c09387bbee4e58eb923695da4fdfa3c37adec632862e79f419f0b5b16865f34","k8s.gcr.io/kube-proxy:v1.16.3"],"sizeBytes":86065116},{"names":["k8s.gcr.io/kube-proxy@sha256:ef245ddefef697c8b42611c237603acf41bfdb2b7ec3e434b7c3592864dcfff8","k8s.gcr.io/kube-proxy:v1.15.6"],"sizeBytes":82412380},{"names":["k8s.gcr.io/coredns@sha256:12eb885b8685b1b13a04ecf5c23bc809c2e57917252fd7b0be9e9c00644e8ee5","k8s.gcr.io/coredns:1.6.2"],"sizeBytes":44100963},{"names":["k8s.gcr.io/coredns@sha256:7ec975f167d815311a7136c32e70735f0d00b73781365df1befd46ed35bd4fe7","k8s.gcr.io/coredns:1.6.5"],"sizeBytes":41578211},{"names":["quay.io/k8scsi/csi-node-driver-registrar@sha256:89cdb2a20bdec89b75e2fbd82a67567ea90b719524990e772f2704b19757188d","quay.io/k8scsi/csi-node-driver-registrar:v1.2.0"],"sizeBytes":17057647},{"names":["quay.io/k8scsi/csi-node-driver-registrar@sha256:13daf82fb99e951a4bff8ae5fc7c17c3a8fe7130be6400990d8f6076c32d4599","quay.io/k8scsi/csi-node-driver-registrar:v1.1.0"],"sizeBytes":15815995},{"names":["quay.io/k8scsi/livenessprobe@sha256:dde617756e0f602adc566ab71fd885f1dad451ad3fb063ac991c95a2ff47aea5","quay.io/k8scsi/livenessprobe:v1.1.0"],"sizeBytes":14967303},{"names":["k8s.gcr.io/pause@sha256:f78411e19d84a252e53bff71a4407a5686c46983a2c2eeed83929b888179acea","k8s.gcr.io/pause:3.1"],"sizeBytes":742472}],"config":{}}}
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:02:48.495570       1 controller.go:425] skip translation of storage class for plugin: ebs.csi.aws.com
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:02:48.495623       1 controller.go:523] CreateVolumeRequest {Name:pvc-df76833f-a9c8-4de6-861c-f367c7169615 CapacityRange:required_bytes:1073741824  VolumeCapabilities:[mount:<fs_type:"ext4" > access_mode:<mode:SINGLE_NODE_WRITER > ] Parameters:map[type:gp2] Secrets:map[] VolumeContentSource:<nil> AccessibilityRequirements:requisite:<segments:<key:"topology.ebs.csi.aws.com/zone" value:"eu-central-1b" > > preferred:<segments:<key:"topology.ebs.csi.aws.com/zone" value:"eu-central-1b" > >  XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:02:48.495688       1 connection.go:182] GRPC call: /csi.v1.Controller/CreateVolume
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:02:48.495692       1 connection.go:183] GRPC request: {"accessibility_requirements":{"preferred":[{"segments":{"topology.ebs.csi.aws.com/zone":"eu-central-1b"}}],"requisite":[{"segments":{"topology.ebs.csi.aws.com/zone":"eu-central-1b"}}]},"capacity_range":{"required_bytes":1073741824},"name":"pvc-df76833f-a9c8-4de6-861c-f367c7169615","parameters":{"type":"gp2"},"volume_capabilities":[{"AccessType":{"Mount":{"fs_type":"ext4"}},"access_mode":{"mode":1}}]}
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:02:48.498107       1 request.go:1017] Request Body: {"count":3,"lastTimestamp":"2020-01-27T08:02:48Z","message":"External provisioner is provisioning volume for claim \"default/aws-csi-dynamic-claim\""}
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:02:48.498180       1 round_trippers.go:423] curl -k -v -XPATCH  -H "Content-Type: application/strategic-merge-patch+json" -H "Accept: application/json, */*" -H "User-Agent: csi-provisioner/v0.0.0 (linux/amd64) kubernetes/$Format" -H "Authorization: <TOKEN>" 'https://10.96.0.1:443/api/v1/namespaces/default/events/aws-csi-dynamic-claim.15edaf88976bc8e2'
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:02:48.498285       1 event.go:281] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"default", Name:"aws-csi-dynamic-claim", UID:"df76833f-a9c8-4de6-861c-f367c7169615", APIVersion:"v1", ResourceVersion:"11466761", FieldPath:""}): type: 'Normal' reason: 'Provisioning' External provisioner is provisioning volume for claim "default/aws-csi-dynamic-claim"
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:02:48.506717       1 round_trippers.go:443] PATCH https://10.96.0.1:443/api/v1/namespaces/default/events/aws-csi-dynamic-claim.15edaf88976bc8e2 200 OK in 8 milliseconds
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:02:48.506737       1 round_trippers.go:449] Response Headers:
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:02:48.506743       1 round_trippers.go:452]     Content-Type: application/json
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:02:48.506747       1 round_trippers.go:452]     Content-Length: 908
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:02:48.506751       1 round_trippers.go:452]     Date: Mon, 27 Jan 2020 08:02:48 GMT
kube-system/ebs-csi-controller-0[csi-provisioner]: I0127 08:02:48.506792       1 request.go:1017] Response Body: {"kind":"Event","apiVersion":"v1","metadata":{"name":"aws-csi-dynamic-claim.15edaf88976bc8e2","namespace":"default","selfLink":"/api/v1/namespaces/default/events/aws-csi-dynamic-claim.15edaf88976bc8e2","uid":"020ce3ae-aff2-4708-a2c0-8c377e62c457","resourceVersion":"11467157","creationTimestamp":"2020-01-27T08:00:45Z"},"involvedObject":{"kind":"PersistentVolumeClaim","namespace":"default","name":"aws-csi-dynamic-claim","uid":"df76833f-a9c8-4de6-861c-f367c7169615","apiVersion":"v1","resourceVersion":"11466761"},"reason":"Provisioning","message":"External provisioner is provisioning volume for claim \"default/aws-csi-dynamic-claim\"","source":{"component":"ebs.csi.aws.com_ebs-csi-controller-0_85b9be00-484e-43b8-85e1-307531138a05"},"firstTimestamp":"2020-01-27T08:00:45Z","lastTimestamp":"2020-01-27T08:02:48Z","count":3,"type":"Normal","eventTime":null,"reportingComponent":"","reportingInstance":""}
kube-system/ebs-csi-controller-0[liveness-probe]: I0127 08:02:52.724697       1 main.go:53] Sending probe request to CSI driver "ebs.csi.aws.com"
kube-system/ebs-csi-controller-0[ebs-plugin]: I0127 08:02:52.727125       1 identity.go:61] Probe: called with args {XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
kube-system/ebs-csi-controller-0[liveness-probe]: I0127 08:02:52.727562       1 main.go:71] Health check succeeded
kube-system/ebs-csi-controller-0[liveness-probe]: I0127 08:03:02.724724       1 main.go:53] Sending probe request to CSI driver "ebs.csi.aws.com"
kube-system/ebs-csi-controller-0[liveness-probe]: I0127 08:03:02.725150       1 main.go:71] Health check succeeded
kube-system/ebs-csi-controller-0[ebs-plugin]: I0127 08:03:02.724980       1 identity.go:61] Probe: called with args {XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
kube-system/ebs-csi-controller-0[liveness-probe]: I0127 08:03:12.724836       1 main.go:53] Sending probe request to CSI driver "ebs.csi.aws.com"
kube-system/ebs-csi-controller-0[ebs-plugin]: I0127 08:03:12.725910       1 identity.go:61] Probe: called with args {XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
kube-system/ebs-csi-controller-0[liveness-probe]: I0127 08:03:12.726171       1 main.go:71] Health check succeeded
kube-system/ebs-csi-controller-0[liveness-probe]: I0127 08:03:22.724713       1 main.go:53] Sending probe request to CSI driver "ebs.csi.aws.com"
kube-system/ebs-csi-controller-0[ebs-plugin]: I0127 08:03:22.725010       1 identity.go:61] Probe: called with args {XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
kube-system/ebs-csi-controller-0[liveness-probe]: I0127 08:03:22.725188       1 main.go:71] Health check succeeded

Looking at the dynamic volume-claim, I can see this output:

kubectl describe pvc aws-csi-dynamic-claim

Name:          aws-csi-dynamic-claim
Namespace:     default
StorageClass:  ebs-sc
Status:        Pending
Volume:
Labels:        <none>
Annotations:   kubectl.kubernetes.io/last-applied-configuration:
                 {"apiVersion":"v1","kind":"PersistentVolumeClaim","metadata":{"annotations":{},"name":"aws-csi-dynamic-claim","namespace":"default"},"spec...
               volume.beta.kubernetes.io/storage-provisioner: ebs.csi.aws.com
               volume.kubernetes.io/selected-node: ip-172-31-60-52.eu-central-1.compute.internal
Finalizers:    [kubernetes.io/pvc-protection]
Capacity:
Access Modes:
VolumeMode:    Filesystem
Mounted By:    aws-csi-dynamic
Events:
  Type     Reason                Age                    From                                                                       Message
  ----     ------                ----                   ----                                                                       -------
  Normal   WaitForFirstConsumer  2m43s (x5 over 3m31s)  persistentvolume-controller                                                waiting for first consumer to be created before binding
  Warning  ProvisioningFailed    28s (x2 over 89s)      ebs.csi.aws.com_ebs-csi-controller-0_85b9be00-484e-43b8-85e1-307531138a05  failed to provision volume with StorageClass "ebs-sc": rpc error: code = DeadlineExceeded desc = context deadline exceeded
  Normal   Provisioning          26s (x3 over 2m29s)    ebs.csi.aws.com_ebs-csi-controller-0_85b9be00-484e-43b8-85e1-307531138a05  External provisioner is provisioning volume for claim "default/aws-csi-dynamic-claim"
  Normal   ExternalProvisioning  13s (x11 over 2m29s)   persistentvolume-controller                                                waiting for a volume to be created, either by external provisioner "ebs.csi.aws.com" or manually created by system administrator

Then nothing more happens when trying with dynamic provisioning.

I will add the output for the static volume setup later.

@leakingtapan
Copy link
Contributor

@gini-schorsch
Looks the volume creation timeout after 1 mins:

kube-system/ebs-csi-controller-0[ebs-plugin]: I0127 08:01:46.484771       1 controller.go:72] CreateVolume: called with args {Name:pvc-df76833f-a9c8-4de6-861c-f367c7169615 CapacityRange:required_bytes:1073741824  VolumeCapabilities:[mount:<fs_type:"ext4" > access_mode:<mode:SINGLE_NODE_WRITER > ] Parameters:map[type:gp2] Secrets:map[] VolumeContentSource:<nil> AccessibilityRequirements:requisite:<segments:<key:"topology.ebs.csi.aws.com/zone" value:"eu-central-1b" > > preferred:<segments:<key:"topology.ebs.csi.aws.com/zone" value:"eu-central-1b" > >  XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
kube-system/ebs-csi-controller-0[ebs-plugin]: E0127 08:02:46.478954       1 driver.go:66] GRPC error: rpc error: code = Internal desc = RequestCanceled: request context canceled

How did you setup the IAM permission for the driver?

@bartelsb
Copy link

bartelsb commented Feb 5, 2020

We are also experiencing this issue. We are only deploying the ebs-plugin on our controller nodes. Our IAM permissions for controller nodes look like this:

{
    "Version": "2012-10-17",
    "Statement": [
        {
            "Sid": "",
            "Effect": "Allow",
            "Action": [
                "elasticloadbalancing:*",
                "ecr:ListImages",
                "ecr:GetRepositoryPolicy",
                "ecr:GetDownloadUrlForLayer",
                "ecr:GetAuthorizationToken",
                "ecr:DescribeRepositories",
                "ecr:BatchGetImage",
                "ecr:BatchCheckLayerAvailability",
                "ec2:RevokeSecurityGroupIngress",
                "ec2:ModifyVolume",
                "ec2:ModifyInstanceAttribute",
                "ec2:DetachVolume",
                "ec2:DescribeVolumesModifications",
                "ec2:DescribeVolumes",
                "ec2:DescribeSubnets",
                "ec2:DescribeSecurityGroups",
                "ec2:DescribeRouteTables",
                "ec2:DescribeRegions",
                "ec2:DescribeInstances",
                "ec2:DeleteVolume",
                "ec2:DeleteSecurityGroup",
                "ec2:DeleteRoute",
                "ec2:CreateVolume",
                "ec2:CreateTags",
                "ec2:CreateSecurityGroup",
                "ec2:CreateRoute",
                "ec2:AuthorizeSecurityGroupIngress",
                "ec2:AttachVolume",
                "autoscaling:UpdateAutoScalingGroup",
                "autoscaling:DescribeAutoScalingGroups"
            ],
            "Resource": "*"
        }
    ]
}

We have a slightly different setup than OP (Flannel CNI, using in-tree AWS provider instead of CCM, 3 controller nodes in a 6 node cluster), but otherwise, the details look about the same. All of our volumes are dynamically provisioned. One interesting thing is that one of our deployments (a Prometheus deployment) seems to be running just fine. It consists of 2 pods, each with 1 PVC, and the corresponding volumes for those PVCs are being mounted. However, the other deployments with PVCs we're attempting to deploy do not start up and display the behavior described in the original post:

# kubectl describe po es-client-0 -n kube-system
...
Events:
  Type     Reason       Age                    From                                                Message
  ----     ------       ----                   ----                                                -------
  Warning  FailedMount  21m (x466 over 22h)    kubelet, ip-10-240-2-27.us-west-1.compute.internal  Unable to attach or mount volumes: unmounted volumes=[elasticsearch-data], unattached volumes=[elasticsearch-token-lkl6s elasticsearch-data]: timed out waiting for the condition
  Warning  FailedMount  7m12s (x655 over 22h)  kubelet, ip-10-240-2-27.us-west-1.compute.internal  MountVolume.NewMounter initialization failed for volume "pvc-a5b8779f-49ad-4749-ae43-7e68e7cd08c8" : volume mode "Persistent" not supported by driver ebs.csi.aws.com (only supports [])
  Warning  FailedMount  84s (x118 over 22h)    kubelet, ip-10-240-2-27.us-west-1.compute.internal  Unable to attach or mount volumes: unmounted volumes=[elasticsearch-data], unattached volumes=[elasticsearch-data elasticsearch-token-lkl6s]: timed out waiting for the condition

@leakingtapan
Copy link
Contributor

@bartelsb see some of the above conversations for your context. What's your cluster version and what's your upgrade process look like? The recommended process will be 1) upgrade master node 2) upgrade worker node 3) upgrade addons (eg. CSI driver)

@bartelsb
Copy link

bartelsb commented Feb 5, 2020

We start with k8s 1.15.5. We deploy the CSI driver using the amazon/aws-ebs-csi-driver:latest image (so should be same versions of components or newer as specified above). Next, we upgrade each node of the cluster to k8s 1.17.0, starting with the controller (master) nodes. Finally, we restart all of our workloads, including those mentioned above that have PVCs. Our Prometheus workload is able to mount/attach the volume and start as expected, but our Elasticsearch workload is not. It gets stuck with the errors posted above.

@bartelsb
Copy link

bartelsb commented Feb 5, 2020

We are considering pulling out the CSI driver entirely, so that if this is related to our Kubernetes version in some way, deploying the CSI driver doesn't block us from upgrading to v1.17.

@glotzerhotze
Copy link
Author

so for us the issue was resolved after fixing a misconfigured CNI setup, which prevented inter-node-communication and thus a provisioning of storage never got triggered.

We have not tried upgrading our current working cluster (v1.15.x) to any newer versions, but we can confirm that mounting volumes and provisioning storage works on v1.17.x when starting from scratch (aka. building a new test-cluster in our case).

we are using the specs provided above by @gini-schorsch - but since opening this issue we also moved to the external AWS cloud-controller-manager (aka. aws-cloud-controller-manager)

we have been using the provided IAM profiles for both components (CSI and CCM) and cut them down to the use-cases we require for our operations and did not see any problems with that so far.

@bartelsb can you check again if your network setup is correct? also check security-groups if all ports needed are allowed to reach your endpoints.

@fejta-bot
Copy link

Issues go stale after 90d of inactivity.
Mark the issue as fresh with /remove-lifecycle stale.
Stale issues rot after an additional 30d of inactivity and eventually close.

If this issue is safe to close now please do so with /close.

Send feedback to sig-testing, kubernetes/test-infra and/or fejta.
/lifecycle stale

@k8s-ci-robot k8s-ci-robot added the lifecycle/stale Denotes an issue or PR has remained open with no activity and has become stale. label May 6, 2020
@leakingtapan
Copy link
Contributor

/remove-lifecycle stale

@k8s-ci-robot k8s-ci-robot removed the lifecycle/stale Denotes an issue or PR has remained open with no activity and has become stale. label May 7, 2020
@fejta-bot
Copy link

Issues go stale after 90d of inactivity.
Mark the issue as fresh with /remove-lifecycle stale.
Stale issues rot after an additional 30d of inactivity and eventually close.

If this issue is safe to close now please do so with /close.

Send feedback to sig-testing, kubernetes/test-infra and/or fejta.
/lifecycle stale

@k8s-ci-robot k8s-ci-robot added the lifecycle/stale Denotes an issue or PR has remained open with no activity and has become stale. label Aug 5, 2020
@fejta-bot
Copy link

Stale issues rot after 30d of inactivity.
Mark the issue as fresh with /remove-lifecycle rotten.
Rotten issues close after an additional 30d of inactivity.

If this issue is safe to close now please do so with /close.

Send feedback to sig-testing, kubernetes/test-infra and/or fejta.
/lifecycle rotten

@k8s-ci-robot k8s-ci-robot added lifecycle/rotten Denotes an issue or PR that has aged beyond stale and will be auto-closed. and removed lifecycle/stale Denotes an issue or PR has remained open with no activity and has become stale. labels Sep 4, 2020
@fejta-bot
Copy link

Rotten issues close after 30d of inactivity.
Reopen the issue with /reopen.
Mark the issue as fresh with /remove-lifecycle rotten.

Send feedback to sig-testing, kubernetes/test-infra and/or fejta.
/close

@k8s-ci-robot
Copy link
Contributor

@fejta-bot: Closing this issue.

In response to this:

Rotten issues close after 30d of inactivity.
Reopen the issue with /reopen.
Mark the issue as fresh with /remove-lifecycle rotten.

Send feedback to sig-testing, kubernetes/test-infra and/or fejta.
/close

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
kind/bug Categorizes issue or PR as related to a bug. lifecycle/rotten Denotes an issue or PR that has aged beyond stale and will be auto-closed.
Projects
None yet
Development

No branches or pull requests

6 participants