vmware-archive / kubernetes-archived

This repository is archived. Please file in-tree vSphere Cloud Provider issues at https://github.com/kubernetes/kubernetes/issues . CSI Driver for vSphere is available at https://github.com/kubernetes/cloud-provider-vsphere
Apache License 2.0
46 stars 31 forks source link

Statefulset with PVC via vSphere volume plugin takes long per set despite disk having been created in vSphere #486

Open jerryhwg opened 6 years ago

jerryhwg commented 6 years ago

/kind bug

What happened:

When we deploy a stateful set that does PVC for each POD, it takes 3+ minutes for each POD to be in Running state. We can see the VMDK get created immediately and PV/PVC bind is quick too, but there is a long delay before the disk gets attached to the VM. As a result, we're waiting 15 minutes or more for StatefulSet with 5 replicas to come online. This issue happens regardless of the size of disk claim.

During the deployment of stateful set, as we watch syslog on the worker VM, it appears that the kubelet process isn't allowed to mount volume and add PV pvc-e7ed1fee-53b3-11e8-8ae5-005056ba190c to the list of VolumesInUse.

2018-05-09T18:07:47.733895Z - kubelet E0509 18:07:47.183726 769 nestedpendingoperations.go:263] Operation for "\"kubernetes.io/vsphere-volume/[vsanDatastore] 62d0e15a-f1a1-23e7-eaee-246e961e43e0/kubernetes-dynamic-pvc-e7ed1fee-53b3-11e8-8ae5-005056ba190c.vmdk\"" failed. No retries permitted until 2018-05-09 18:07:47.683649502 +0000 UTC m=+6375.115354545 (durationBeforeRetry 500ms). Error: "Volume has not been added to the list of VolumesInUse in the node's volume status for volume \"pvc-e7ed1fee-53b3-11e8-8ae5-005056ba190c\" (UniqueName: \"kubernetes.io/vsphere-volume/[vsanDatastore] 62d0e15a-f1a1-23e7-eaee-246e961e43e0/kubernetes-dynamic-pvc-e7ed1fee-53b3-11e8-8ae5-005056ba190c.vmdk\") pod \"web-7\" (UID: \"e7ee8904-53b3-11e8-8ae5-005056ba190c\") "

Each time this error occurs, the backoff time doubles before allowing retry.

What you expected to happen:

It shouldn't take that long.

How to reproduce it (as minimally and precisely as possible):

Here is an open issue on kubernetes side. https://github.com/kubernetes/kubernetes/issues/62817 this provides some details analysis.

Referenced https://vmware.github.io/vsphere-storage-for-kubernetes/documentation/index.html

Anything else we need to know?:

I think this issue is more on the vsphere side.

Here "reconciler.go:287] attacherDetacher.AttachVolume started for volume", we see it waits a long time(2mins + 22seconds) after starting to attach volume. the function is to ensure volumes that should be attached are attached.

at the time: we found in the Edit Settings of VM in vSphere and also see that the disk is not available/attached

in the worker node, pvc-f1a3fbc1-57a3-11e8-8357-005056ba40ad.vmdk is missing from volumesAttached array

There is a simiiar issue https://github.com/vmware/kubernetes/issues/476 that's about continuous pending per permission setting, however the issue I report here is about longer delayed attachment (so eventually mounted (after 3+ min per each pod)).

Environment:

ben-schumacher commented 6 years ago

@divyenpatel, I'd like to add that during the initial create of StatefulSet, we've watched all http traffic flowing between master node in k8s cluster and vCenter. After analyzing pcap trace in Wireshark, we can see a complete stall in communication between master node and vCenter for over two minutes. This is after the VMDK is created, but before the VM is reconfigured to have the new disk attached. Once the http request finally comes into vCenter to reconfigure the VM, it only takes seconds for the operation to complete. I'm leaning more towards this slowness coming from k8s as vCenter appears to be processing requests very fast once they finally come in from k8s. Why is k8s taking so long to reconfigure the VM after the disk (VMDK) is created?

image