Replace k8s client get requests with volume cache #83

RaunakShah · 2020-06-30T16:25:24Z

This change replaces API server Get() requests with access to the volume cache.
Addresses #82

Testing:
~2x increase in throughput of external-provisioner. "Throttling ..." messages due to lib-external-provisioner no longer seen due to Get() requests to API server.
With a dummy CSI controller that returns success for every CreateVolume and DeleteVolume call
Use 64-threads to create and delete PVCs in a loop for 5 minutes. Tracking the number of operations successfully executed within this time helps calculate the throughput.

Without this change:
Operations completed - 728
Ops/sec - 2.435
With this change:
Operations completed - 1280
Ops/sec - 4.281

$ make test 
go mod tidy
go test ./controller
ok  	sigs.k8s.io/sig-storage-lib-external-provisioner/v5/controller	14.030s
go test ./allocator
ok  	sigs.k8s.io/sig-storage-lib-external-provisioner/v5/allocator	0.134s

wongma7 · 2020-06-30T19:06:56Z

These Gets intentionally bypass the cache to avoid duplicating subsequent Create/Delete calls. In terms of apiserver load/throttling, it seems obvious that they should be removed.

Keep the Get call: the controller will always call 1 Get + 1 Create/Delete.
Remove the Get call: the controller will usually call 1 Create/Delete;
and if the cache is stale and the controller has been waiting for the lock will sometimes call 2 Create/Delete (the second of which will no-op/return error anyway)

The reason these Gets are here is to mimic the in-tree controller: https://github.com/kubernetes/kubernetes/blob/master/pkg/controller/volume/persistentvolume/pv_controller.go#L1214

@jsafrane do you think we still need these Get calls? IMO no.

wongma7 · 2020-06-30T19:10:26Z

Also, I don't think the 'waiting for locks' scenario is even possible anymore ever since we moved to a workqueue model

jsafrane · 2020-07-01T17:55:31Z

The comment about locks is probably obsolete.

Still, direct GET is useful. Consider this scenario:

The provisioner provisions a PVC, saves the provisioned PV to API server
The provisioner gets "PVC changed" event for the same PVC (e.g. something adds a label or an annotation)
To the provisioner it looks like an unprovisioned PVC, so it tries to provision it again. It may not have the PV in its informer cache yet, so ti GETs it from the API server to be 100% sure it does not exist yet.

If you make sure that the provisioner has cache composed both from the informer / API server watch and list of recently provisioned volumes, then yes, you can remove the GET call. I am not sure how safe it is to adds items directly to informer's Store (volumes.Add()), maybe it's worth exploring.

jsafrane · 2020-07-01T17:57:12Z

controller/controller.go

@@ -187,6 +188,8 @@ type ProvisionController struct {
 	claimsInProgress sync.Map

 	volumeStore VolumeStore
+
+	volumeLister corelisters.PersistentVolumeLister


Why volumeLister? There is volumeInformer and volumes already available.

Looks like i totally missed volumes. I've only tested this with an explicit lister so will try that out and update the commit.

RaunakShah · 2020-07-02T05:28:33Z

@jsafrane @wongma7 does CSI spec dictating that CreateVolume needs to be idempotent have any bearing here? In the situation that @jsafrane described - if the PV is not found in the cache, external-provisioner will try to create the volume again. Since that's supposed to be idempotent, the CSI driver should respond with a successful message. The subsequent attempt to Create() the PV on the API server will return a success since it already exists (https://github.com/kubernetes-sigs/sig-storage-lib-external-provisioner/blob/master/controller/volume_store.go#L155)

jsafrane · 2020-07-03T13:54:18Z

Yes, CSI should be idempotent, however, we should not exercise it too often as calling CreateVolume may be an expensive operation for some storage backends (far more expensive than Kubernetes API call).

Did you check if it's possible to add newly provisioned PV into volumes directly? That could be a pretty cheap solution.

RaunakShah · 2020-07-07T18:01:27Z

controller/controller.go

@@ -1449,20 +1454,7 @@ func (ctrl *ProvisionController) deleteVolumeOperation(ctx context.Context, volu
 	operation := fmt.Sprintf("delete %q", volume.Name)
 	glog.Info(logOperation(operation, "started"))

-	// This method may have been waiting for a volume lock for some time.


Removed this due to the earlier discussion on locks. deleteVolumeOperation takes the volume object as an input parameter

RaunakShah · 2020-07-07T18:03:40Z

@jsafrane i've changed the PR to use the volumes cache instead of lister, please take a look!

controller/controller.go

jsafrane · 2020-07-08T07:27:07Z

controller/controller.go

@@ -705,7 +705,13 @@ func NewProvisionController(
 	// PersistentVolumes

 	volumeHandler := cache.ResourceEventHandlerFuncs{
-		AddFunc:    func(obj interface{}) { controller.enqueueVolume(obj) },
+		AddFunc: func(obj interface{}) {
+			if err = controller.volumes.Add(obj); err != nil {


The volume coming from informer already is in the informer cache, you don't need to add it again.

What you need to do is to add the volume to the store after the provisioner saved the volume to the API server here

sig-storage-lib-external-provisioner/controller/volume_store.go

Line 157 in 904215e

klog.V(5).Infof("Volume %s saved", volume.Name)

and here

sig-storage-lib-external-provisioner/controller/volume_store.go

Line 215 in 904215e

// Save succeeded.

I actually moved it here https://github.com/kubernetes-sigs/sig-storage-lib-external-provisioner/blob/master/controller/controller.go#L1440
because 'volumes' is a member of 'ProvisionController`

RaunakShah · 2020-07-09T18:12:10Z

That's weird, the tests are passing locally:

go test ./controller
ok      sigs.k8s.io/sig-storage-lib-external-provisioner/v6/controller  14.219s
go test ./allocator
ok      sigs.k8s.io/sig-storage-lib-external-provisioner/v6/allocator   (cached)

RaunakShah · 2020-07-16T22:00:25Z

/retest

jsafrane · 2020-07-20T11:52:02Z

I'm afraid the unit test error is genuine - please check what did you change in the provisioner metrics.

RaunakShah · 2020-07-21T22:50:42Z

@jsafrane actually i think it may just be a flaky test!
I'm able to reproduce the failure on ToT as well. 4/10 attempts fail with the same error:

--- FAIL: TestController (6.61s)
    --- FAIL: TestController/try_to_provision_for_claim-1_but_fail_to_save_the_pv_object (0.21s)
        controller_test.go:684: expected metrics:
             {provisioned:map[class-1:{success:0 failed:1}] deleted:map[]}
             but got:
             {provisioned:map[] deleted:map[]}

jsafrane · 2020-07-24T13:39:55Z

/retest

jsafrane · 2020-07-28T10:27:49Z

controller/controller.go

@@ -1437,6 +1437,9 @@ func (ctrl *ProvisionController) provisionClaimOperation(ctx context.Context, cl
 	glog.Info(logOperation(operation, "succeeded"))

 	if err := ctrl.volumeStore.StoreVolume(claim, volume); err != nil {
+		if volumAddErr := ctrl.volumes.Add(volume.Name); volumAddErr != nil {


You should add the volume to cache on StoreVolume success, not after failure.

Fixed! I have no idea how it got in there

RaunakShah · 2020-07-28T17:31:21Z

/test pull-sig-storage-lib-external-provisioner-unit

jsafrane · 2020-07-30T13:05:15Z

/lgtm
/approve

k8s-ci-robot · 2020-07-30T13:05:24Z

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: jsafrane, RaunakShah

The full list of commands accepted by this bot can be found here.

The pull request process is described here

Needs approval from an approver in each of these files:

~~OWNERS~~ [jsafrane]

Approvers can indicate their approval by writing /approve in a comment
Approvers can cancel approval by writing /approve cancel in a comment

pohly · 2020-10-08T10:12:15Z

controller/controller.go

@@ -1439,6 +1439,9 @@ func (ctrl *ProvisionController) provisionClaimOperation(ctx context.Context, cl
 	if err := ctrl.volumeStore.StoreVolume(claim, volume); err != nil {
 		return ProvisioningFinished, err
 	}
+	if err = ctrl.volumes.Add(volume.Name); err != nil {
+		utilruntime.HandleError(err)
+	}


This Add fails all the time with:

couldn't create key for object pvc-17e4c2d0-114d-4260-b587-c39a86c8dfe5: object has no meta: object does not implement the Object interfaces

You need to add the volume object, not its name...

Fix is in #92

pohly · 2020-10-08T10:12:35Z

controller/controller.go

@@ -1523,6 +1517,9 @@ func (ctrl *ProvisionController) deleteVolumeOperation(ctx context.Context, volu

 	glog.Info(logOperation(operation, "persistentvolume deleted"))

+	if err = ctrl.volumes.Delete(volume.Name); err != nil {
+		utilruntime.HandleError(err)
+	}


k8s-ci-robot added the cncf-cla: yes Indicates the PR's author has signed the CNCF CLA. label Jun 30, 2020

k8s-ci-robot requested review from jsafrane and wongma7 June 30, 2020 16:25

k8s-ci-robot added the size/S Denotes a PR that changes 10-29 lines, ignoring generated files. label Jun 30, 2020

jsafrane reviewed Jul 1, 2020

View reviewed changes

k8s-ci-robot added the needs-rebase Indicates a PR cannot be merged because it has merge conflicts with HEAD. label Jul 1, 2020

RaunakShah force-pushed the add_pvlister branch from 57c1282 to 4282c13 Compare July 7, 2020 17:32

k8s-ci-robot added size/M Denotes a PR that changes 30-99 lines, ignoring generated files. and removed size/S Denotes a PR that changes 10-29 lines, ignoring generated files. labels Jul 7, 2020

RaunakShah force-pushed the add_pvlister branch from 84edfe8 to 3413520 Compare July 7, 2020 17:50

k8s-ci-robot removed the needs-rebase Indicates a PR cannot be merged because it has merge conflicts with HEAD. label Jul 7, 2020

RaunakShah commented Jul 7, 2020

View reviewed changes

controller/controller.go Outdated Show resolved Hide resolved

jsafrane reviewed Jul 8, 2020

View reviewed changes

RaunakShah force-pushed the add_pvlister branch 2 times, most recently from 4a08db9 to 6fd1e9f Compare July 9, 2020 18:01

RaunakShah changed the title ~~Replace k8s client get requests with volume lister~~ Replace k8s client get requests with volume cache Jul 15, 2020

jsafrane reviewed Jul 28, 2020

View reviewed changes

RaunakShah force-pushed the add_pvlister branch from 6fd1e9f to fc234b0 Compare July 28, 2020 17:24

Replace k8s client get requests with volume cache

935885b

RaunakShah force-pushed the add_pvlister branch from fc234b0 to 935885b Compare July 28, 2020 17:26

k8s-ci-robot assigned jsafrane Jul 30, 2020

k8s-ci-robot added the lgtm "Looks good to me", indicates that a PR is ready to be merged. label Jul 30, 2020

k8s-ci-robot added the approved Indicates a PR has been approved by an approver from all required OWNERS files. label Jul 30, 2020

k8s-ci-robot merged commit bb73692 into kubernetes-sigs:master Jul 30, 2020

gnufied mentioned this pull request Aug 12, 2020

We need to ensure that we are not reading stale PV objects kubernetes-csi/external-resizer#96

Merged

pohly reviewed Oct 8, 2020

View reviewed changes

Replace k8s client get requests with volume cache #83

Replace k8s client get requests with volume cache #83

Uh oh!

Conversation

RaunakShah commented Jun 30, 2020 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

wongma7 commented Jun 30, 2020 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

wongma7 commented Jun 30, 2020

Uh oh!

jsafrane commented Jul 1, 2020

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

RaunakShah commented Jul 2, 2020

Uh oh!

jsafrane commented Jul 3, 2020

Uh oh!

Choose a reason for hiding this comment

Uh oh!

RaunakShah commented Jul 7, 2020

Uh oh!

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

RaunakShah commented Jul 9, 2020

Uh oh!

RaunakShah commented Jul 16, 2020

Uh oh!

jsafrane commented Jul 20, 2020

Uh oh!

RaunakShah commented Jul 21, 2020

Uh oh!

jsafrane commented Jul 24, 2020

Uh oh!

jsafrane Jul 28, 2020 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

RaunakShah commented Jul 28, 2020

Uh oh!

jsafrane commented Jul 30, 2020

Uh oh!

k8s-ci-robot commented Jul 30, 2020

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

RaunakShah commented Jun 30, 2020 •

edited

Loading

wongma7 commented Jun 30, 2020 •

edited

Loading

jsafrane Jul 28, 2020 •

edited

Loading