Can't create a snapshot from a pvc

[michaelcourcy]

Following the examples in https://github.com/nutanix/csi-plugin/tree/master/example/ABS

When I create a volumesnapshot

apiVersion: snapshot.storage.k8s.io/v1beta1
kind: VolumeSnapshot
metadata:
  name: snapshot1
spec:
  volumeSnapshotClassName: acs-abs-snapshot-class
  source:
    persistentVolumeClaimName: claim1

The volume snapshot never get ready :

kubectl get pvc,volumesnapshot -n test
NAME                           STATUS   VOLUME                                     CAPACITY   ACCESS MODES   STORAGECLASS           AGE
persistentvolumeclaim/claim1   Bound    pvc-0185b8b7-28e8-44ed-8de4-d0b71ffe6719   3Gi        RWO            default-storageclass   42m

NAME                                               READYTOUSE   SOURCEPVC   SOURCESNAPSHOTCONTENT   RESTORESIZE   SNAPSHOTCLASS            SNAPSHOTCONTENT   CREATIONTIME   AGE
volumesnapshot.snapshot.storage.k8s.io/snapshot1                claim1                                            acs-abs-snapshot-class                                    41m

From this point I check the logs in the kube-system and the ntnx-system but could not see any error related to snapshot. The only thing I found so far was

kubectl logs -n ntnx-system csi-provisioner-ntnx-plugin-0 ntnx-csi-plugin |grep -i snap
I0112 07:39:36.008779       1 ntnx_driver.go:93] Enabling controller service capability: CREATE_DELETE_SNAPSHOT

kubectl logs  -n ntnx-system csi-node-ntnx-plugin-9v2rj  csi-node-ntnx-plugin |grep -i snap
I0112 07:39:36.203566       1 ntnx_driver.go:93] Enabling controller service capability: CREATE_DELETE_SNAPSHOT

kubectl logs  -n ntnx-system csi-node-ntnx-plugin-lzphp  csi-node-ntnx-plugin |grep -i snap
I0112 07:39:29.659416       1 ntnx_driver.go:93] Enabling controller service capability: CREATE_DELETE_SNAPSHOT

Some information about my csi install may help :

kubectl describe -n ntnx-system po csi-node-ntnx-plugin-9v2rj |grep Image:
    Image:         quay.io/karbon/csi-node-driver-registrar:v1.0.1
    Image:         quay.io/karbon/ntnx-csi:v2.2.0
    Image:         quay.io/karbon/livenessprobe:v1.1.0
kubectl describe -n ntnx-system po csi-provisioner-ntnx-plugin-0  |grep Image:
    Image:         quay.io/karbon/csi-provisioner:v1.5.0
    Image:         quay.io/karbon/csi-resizer:v0.3.0
    Image:         quay.io/karbon/ntnx-csi:v2.2.0
    Image:         quay.io/karbon/livenessprobe:v1.1.0

[subodh01]

Have you followed these additional steps to enable volume snapshot ? https://github.com/nutanix/csi-plugin/blob/master/csi-v2.0.0.md#volume-snapshot-and-restore

-Subodh

[michaelcourcy]

Hi @subodh01

I was just going to say that I forgot this steps

kubectl create -f snapshot-controller-rbac.yaml -f snapshot-controller-setup.yaml

But I did the rest and now I have this result

oc get volumesnapshot -n test
NAME        READYTOUSE   SOURCEPVC   SOURCESNAPSHOTCONTENT   RESTORESIZE   SNAPSHOTCLASS            SNAPSHOTCONTENT                                    CREATIONTIME   AGE
snapshot1   false        claim1                                            acs-abs-snapshot-class   snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243                  6m51s

checking the logs I can't see obvious problem

 oc logs -n kube-system snapshot-controller-0
I0119 00:26:01.293250       1 main.go:70] Version: v2.0.1-0-g69da5b8d
I0119 00:26:01.296741       1 main.go:97] Start NewCSISnapshotController with kubeconfig [] resyncPeriod [1m0s]
I0119 00:26:01.297761       1 snapshot_controller_base.go:143] Starting snapshot controller
I0119 00:26:01.298511       1 reflector.go:153] Starting reflector *v1beta1.VolumeSnapshot (1m0s) from github.com/kubernetes-csi/external-snapshotter/pkg/client/informers/externalversions/factory.go:117
I0119 00:26:01.298589       1 reflector.go:188] Listing and watching *v1beta1.VolumeSnapshot from github.com/kubernetes-csi/external-snapshotter/pkg/client/informers/externalversions/factory.go:117
I0119 00:26:01.298632       1 reflector.go:153] Starting reflector *v1beta1.VolumeSnapshotClass (1m0s) from github.com/kubernetes-csi/external-snapshotter/pkg/client/informers/externalversions/factory.go:117
I0119 00:26:01.298652       1 reflector.go:188] Listing and watching *v1beta1.VolumeSnapshotClass from github.com/kubernetes-csi/external-snapshotter/pkg/client/informers/externalversions/factory.go:117
I0119 00:26:01.298773       1 reflector.go:153] Starting reflector *v1beta1.VolumeSnapshotContent (1m0s) from github.com/kubernetes-csi/external-snapshotter/pkg/client/informers/externalversions/factory.go:117
I0119 00:26:01.298796       1 reflector.go:188] Listing and watching *v1beta1.VolumeSnapshotContent from github.com/kubernetes-csi/external-snapshotter/pkg/client/informers/externalversions/factory.go:117
I0119 00:26:01.299016       1 reflector.go:153] Starting reflector *v1.PersistentVolumeClaim (1m0s) from k8s.io/client-go/informers/factory.go:135
I0119 00:26:01.299056       1 reflector.go:188] Listing and watching *v1.PersistentVolumeClaim from k8s.io/client-go/informers/factory.go:135
I0119 00:26:01.397990       1 shared_informer.go:227] caches populated
I0119 00:26:01.398084       1 snapshot_controller_base.go:465] controller initialized
I0119 00:27:01.313615       1 reflector.go:278] github.com/kubernetes-csi/external-snapshotter/pkg/client/informers/externalversions/factory.go:117: forcing resync
I0119 00:27:01.314267       1 reflector.go:278] github.com/kubernetes-csi/external-snapshotter/pkg/client/informers/externalversions/factory.go:117: forcing resync
I0119 00:28:01.314835       1 reflector.go:278] github.com/kubernetes-csi/external-snapshotter/pkg/client/informers/externalversions/factory.go:117: forcing resync
I0119 00:28:01.314968       1 reflector.go:278] github.com/kubernetes-csi/external-snapshotter/pkg/client/informers/externalversions/factory.go:117: forcing resync
I0119 00:28:06.719402       1 snapshot_controller_base.go:173] enqueued "test/snapshot1" for sync
I0119 00:28:06.719462       1 snapshot_controller_base.go:205] snapshotWorker[test/snapshot1]
I0119 00:28:06.719474       1 snapshot_controller_base.go:208] snapshotWorker: snapshot namespace [test] name [snapshot1]
I0119 00:28:06.719511       1 snapshot_controller_base.go:327] checkAndUpdateSnapshotClass [snapshot1]: VolumeSnapshotClassName [acs-abs-snapshot-class]
I0119 00:28:06.719576       1 snapshot_controller.go:1086] getSnapshotClass: VolumeSnapshotClassName [acs-abs-snapshot-class]
I0119 00:28:06.719589       1 snapshot_controller_base.go:346] VolumeSnapshotClass [acs-abs-snapshot-class] Driver [csi.nutanix.com]
I0119 00:28:06.719597       1 snapshot_controller_base.go:219] passed checkAndUpdateSnapshotClass for snapshot "test/snapshot1"
I0119 00:28:06.719611       1 snapshot_controller_base.go:356] updateSnapshot "test/snapshot1"
I0119 00:28:06.719641       1 util.go:119] storeObjectUpdate: adding snapshot "test/snapshot1", version 1391481
I0119 00:28:06.719673       1 snapshot_controller.go:157] synchronizing VolumeSnapshot[test/snapshot1]: bound to: "", Completed: false
I0119 00:28:06.719685       1 snapshot_controller.go:159] syncSnapshot [test/snapshot1]: check if we should remove finalizer on snapshot PVC source and remove it if we can
I0119 00:28:06.719724       1 snapshot_controller.go:820] checkandRemovePVCFinalizer for snapshot [snapshot1]: snapshot status [(*v1beta1.VolumeSnapshotStatus)(nil)]
I0119 00:28:06.719791       1 snapshot_controller.go:175] syncSnapshot[test/snapshot1]: check if we should add finalizers on snapshot
I0119 00:28:06.719815       1 snapshot_controller.go:299] checkandAddSnapshotFinalizers: Add Finalizer for VolumeSnapshot[test/snapshot1]
I0119 00:28:06.724087       1 snapshot_controller_base.go:173] enqueued "test/snapshot1" for sync
I0119 00:28:06.724430       1 util.go:147] storeObjectUpdate updating snapshot "test/snapshot1" with version 1391481
I0119 00:28:06.724472       1 snapshot_controller.go:1210] Added protection finalizer to volume snapshot test/snapshot1
I0119 00:28:06.724513       1 snapshot_controller.go:342] syncUnreadySnapshot test/snapshot1
I0119 00:28:06.724539       1 snapshot_controller.go:377] before getMatchSnapshotContent for snapshot test/snapshot1
I0119 00:28:06.724604       1 snapshot_controller.go:604] No VolumeSnapshotContent for VolumeSnapshot test/snapshot1 found
I0119 00:28:06.724628       1 snapshot_controller.go:465] createSnapshotContent: Creating content for snapshot test/snapshot1 through the plugin ...
I0119 00:28:06.724638       1 snapshot_controller.go:468] createSnapshotContent: Check if PVC is not being deleted and add Finalizer for source of snapshot [snapshot1] if needed
I0119 00:28:06.730604       1 snapshot_controller.go:755] Added protection finalizer to persistent volume claim claim1
I0119 00:28:06.730633       1 snapshot_controller.go:552] getCreateSnapshotInput [snapshot1]
I0119 00:28:06.730641       1 snapshot_controller.go:1086] getSnapshotClass: VolumeSnapshotClassName [acs-abs-snapshot-class]
I0119 00:28:06.736027       1 snapshot_controller.go:1039] getVolumeFromVolumeSnapshot: snapshot [snapshot1] PV name [pvc-458125d9-e8a8-4c38-8c65-fb39dc311bad]
I0119 00:28:06.736068       1 util.go:250] GetSecretReference namespaceTemplate kube-system, namespaceParams: map[volumesnapshot.namespace:test volumesnapshotcontent.name:snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243], resolved kube-system
I0119 00:28:06.736192       1 util.go:279] GetSecretReference validated Secret: &SecretReference{Name:ntnx-secret-0005a02b-37b3-3cbb-0000-000000003114,Namespace:kube-system,}
I0119 00:28:06.736283       1 snapshot_controller.go:506] createSnapshotContent: set annotation [snapshot.storage.kubernetes.io/deletion-secret-name] on content [snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243].
I0119 00:28:06.736320       1 snapshot_controller.go:509] createSnapshotContent: set annotation [snapshot.storage.kubernetes.io/deletion-secret-namespace] on content [snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243].
I0119 00:28:06.736333       1 snapshot_controller.go:514] volume snapshot content &v1beta1.VolumeSnapshotContent{TypeMeta:v1.TypeMeta{Kind:"", APIVersion:""}, ObjectMeta:v1.ObjectMeta{Name:"snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243", GenerateName:"", Namespace:"", SelfLink:"", UID:"", ResourceVersion:"", Generation:0, CreationTimestamp:v1.Time{Time:time.Time{wall:0x0, ext:0, loc:(*time.Location)(nil)}}, DeletionTimestamp:(*v1.Time)(nil), DeletionGracePeriodSeconds:(*int64)(nil), Labels:map[string]string(nil), Annotations:map[string]string{"snapshot.storage.kubernetes.io/deletion-secret-name":"ntnx-secret-0005a02b-37b3-3cbb-0000-000000003114", "snapshot.storage.kubernetes.io/deletion-secret-namespace":"kube-system"}, OwnerReferences:[]v1.OwnerReference(nil), Finalizers:[]string(nil), ClusterName:"", ManagedFields:[]v1.ManagedFieldsEntry(nil)}, Spec:v1beta1.VolumeSnapshotContentSpec{VolumeSnapshotRef:v1.ObjectReference{Kind:"VolumeSnapshot", Namespace:"test", Name:"snapshot1", UID:"e1875527-f688-42ac-9d08-1e6a88c6f243", APIVersion:"snapshot.storage.k8s.io/v1beta1", ResourceVersion:"1391481", FieldPath:""}, DeletionPolicy:"Delete", Driver:"csi.nutanix.com", VolumeSnapshotClassName:(*string)(0xc0005303e0), Source:v1beta1.VolumeSnapshotContentSource{VolumeHandle:(*string)(0xc000121390), SnapshotHandle:(*string)(nil)}}, Status:(*v1beta1.VolumeSnapshotContentStatus)(nil)}
I0119 00:28:06.736446       1 snapshot_controller.go:517] createSnapshotContent [test/snapshot1]: trying to save volume snapshot content snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243
I0119 00:28:06.743169       1 snapshot_controller_base.go:190] enqueued "snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243" for sync
I0119 00:28:06.743246       1 snapshot_controller_base.go:270] contentWorker[snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243]
I0119 00:28:06.743265       1 util.go:119] storeObjectUpdate: adding content "snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243", version 1391484
I0119 00:28:06.743289       1 snapshot_controller.go:86] synchronizing VolumeSnapshotContent[snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243]: content is bound to snapshot test/snapshot1
I0119 00:28:06.743296       1 snapshot_controller.go:96] syncContent: Add Finalizer for VolumeSnapshotContent[snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243]
I0119 00:28:06.744068       1 snapshot_controller.go:525] volume snapshot content "snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243" for snapshot "test/snapshot1" saved, &{{ } {snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243      0 0001-01-01 00:00:00 +0000 UTC <nil> <nil> map[] map[snapshot.storage.kubernetes.io/deletion-secret-name:ntnx-secret-0005a02b-37b3-3cbb-0000-000000003114 snapshot.storage.kubernetes.io/deletion-secret-namespace:kube-system] [] []  []} {{VolumeSnapshot test snapshot1 e1875527-f688-42ac-9d08-1e6a88c6f243 snapshot.storage.k8s.io/v1beta1 1391481 } Delete csi.nutanix.com 0xc0005303e0 {0xc000121390 <nil>}} <nil>}
I0119 00:28:06.744277       1 util.go:147] storeObjectUpdate updating content "snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243" with version 1391484
I0119 00:28:06.744322       1 snapshot_controller.go:413] syncUnreadySnapshot [test/snapshot1]: trying to update snapshot status
I0119 00:28:06.744350       1 snapshot_controller.go:942] updateSnapshotStatus[test/snapshot1]
I0119 00:28:06.744393       1 snapshot_controller.go:959] updateSnapshotStatus: updating VolumeSnapshot [&{TypeMeta:{Kind: APIVersion:} ObjectMeta:{Name:snapshot1 GenerateName: Namespace:test SelfLink:/apis/snapshot.storage.k8s.io/v1beta1/namespaces/test/volumesnapshots/snapshot1 UID:e1875527-f688-42ac-9d08-1e6a88c6f243 ResourceVersion:1391481 Generation:1 CreationTimestamp:2021-01-19 00:28:06 +0000 UTC DeletionTimestamp:<nil> DeletionGracePeriodSeconds:<nil> Labels:map[] Annotations:map[] OwnerReferences:[] Finalizers:[] ClusterName: ManagedFields:[]} Spec:{Source:{PersistentVolumeClaimName:0xc000391d80 VolumeSnapshotContentName:<nil>} VolumeSnapshotClassName:0xc000391d90} Status:<nil>}] based on VolumeSnapshotContentStatus [<nil>]
I0119 00:28:06.770449       1 snapshot_controller_base.go:190] enqueued "snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243" for sync
I0119 00:28:06.770623       1 util.go:147] storeObjectUpdate updating content "snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243" with version 1391484
I0119 00:28:06.770657       1 snapshot_controller.go:699] Added protection finalizer to volume snapshot content snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243
I0119 00:28:06.770699       1 snapshot_controller_base.go:270] contentWorker[snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243]
I0119 00:28:06.770729       1 util.go:147] storeObjectUpdate updating content "snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243" with version 1391485
I0119 00:28:06.770770       1 snapshot_controller.go:86] synchronizing VolumeSnapshotContent[snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243]: content is bound to snapshot test/snapshot1
I0119 00:28:06.770794       1 snapshot_controller.go:1288] getSnapshotFromStore: snapshot test/snapshot1 found
I0119 00:28:06.770851       1 snapshot_controller.go:910] needsUpdateSnapshotStatus[test/snapshot1]
I0119 00:28:06.773860       1 snapshot_controller_base.go:205] snapshotWorker[test/snapshot1]
I0119 00:28:06.773877       1 snapshot_controller_base.go:208] snapshotWorker: snapshot namespace [test] name [snapshot1]
I0119 00:28:06.773887       1 snapshot_controller_base.go:327] checkAndUpdateSnapshotClass [snapshot1]: VolumeSnapshotClassName [acs-abs-snapshot-class]
I0119 00:28:06.773893       1 snapshot_controller.go:1086] getSnapshotClass: VolumeSnapshotClassName [acs-abs-snapshot-class]
I0119 00:28:06.773901       1 snapshot_controller_base.go:346] VolumeSnapshotClass [acs-abs-snapshot-class] Driver [csi.nutanix.com]
I0119 00:28:06.773908       1 snapshot_controller_base.go:219] passed checkAndUpdateSnapshotClass for snapshot "test/snapshot1"
I0119 00:28:06.773916       1 snapshot_controller_base.go:356] updateSnapshot "test/snapshot1"
I0119 00:28:06.773925       1 util.go:147] storeObjectUpdate updating snapshot "test/snapshot1" with version 1391482
I0119 00:28:06.773936       1 snapshot_controller.go:157] synchronizing VolumeSnapshot[test/snapshot1]: bound to: "", Completed: false
I0119 00:28:06.773938       1 snapshot_controller_base.go:173] enqueued "test/snapshot1" for sync
I0119 00:28:06.773942       1 snapshot_controller.go:159] syncSnapshot [test/snapshot1]: check if we should remove finalizer on snapshot PVC source and remove it if we can
I0119 00:28:06.773978       1 snapshot_controller.go:820] checkandRemovePVCFinalizer for snapshot [snapshot1]: snapshot status [(*v1beta1.VolumeSnapshotStatus)(nil)]
I0119 00:28:06.774015       1 snapshot_controller.go:780] Checking isPVCBeingUsed for snapshot [test/snapshot1]
I0119 00:28:06.774039       1 snapshot_controller.go:796] Keeping PVC test/claim1, it is used by snapshot test/snapshot1
I0119 00:28:06.774048       1 snapshot_controller.go:175] syncSnapshot[test/snapshot1]: check if we should add finalizers on snapshot
I0119 00:28:06.774056       1 snapshot_controller.go:202] processFinalizersAndCheckandDeleteContent: Content [snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243] deletion policy [Delete] is delete.
I0119 00:28:06.774076       1 snapshot_controller.go:342] syncUnreadySnapshot test/snapshot1
I0119 00:28:06.774083       1 snapshot_controller.go:377] before getMatchSnapshotContent for snapshot test/snapshot1
I0119 00:28:06.774092       1 snapshot_controller.go:388] Found VolumeSnapshotContent object snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243 for snapshot test/snapshot1
I0119 00:28:06.774101       1 snapshot_controller.go:871] bindandUpdateVolumeSnapshot for snapshot [snapshot1]: snapshotContent [snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243]
I0119 00:28:06.776434       1 snapshot_controller.go:882] bindandUpdateVolumeSnapshot [test/snapshot1]: trying to update snapshot status
I0119 00:28:06.776455       1 snapshot_controller.go:942] updateSnapshotStatus[test/snapshot1]
I0119 00:28:06.776463       1 snapshot_controller.go:959] updateSnapshotStatus: updating VolumeSnapshot [&{TypeMeta:{Kind: APIVersion:} ObjectMeta:{Name:snapshot1 GenerateName: Namespace:test SelfLink:/apis/snapshot.storage.k8s.io/v1beta1/namespaces/test/volumesnapshots/snapshot1 UID:e1875527-f688-42ac-9d08-1e6a88c6f243 ResourceVersion:1391486 Generation:1 CreationTimestamp:2021-01-19 00:28:06 +0000 UTC DeletionTimestamp:<nil> DeletionGracePeriodSeconds:<nil> Labels:map[] Annotations:map[] OwnerReferences:[] Finalizers:[snapshot.storage.kubernetes.io/volumesnapshot-as-source-protection] ClusterName: ManagedFields:[]} Spec:{Source:{PersistentVolumeClaimName:0xc0002d95c0 VolumeSnapshotContentName:<nil>} VolumeSnapshotClassName:0xc0002d95d0} Status:0xc0003fb5f0}] based on VolumeSnapshotContentStatus [<nil>]
I0119 00:28:06.778932       1 util.go:147] storeObjectUpdate updating snapshot "test/snapshot1" with version 1391486
I0119 00:28:06.778958       1 snapshot_controller.go:903] bindandUpdateVolumeSnapshot for snapshot completed [&v1beta1.VolumeSnapshot{TypeMeta:v1.TypeMeta{Kind:"", APIVersion:""}, ObjectMeta:v1.ObjectMeta{Name:"snapshot1", GenerateName:"", Namespace:"test", SelfLink:"/apis/snapshot.storage.k8s.io/v1beta1/namespaces/test/volumesnapshots/snapshot1", UID:"e1875527-f688-42ac-9d08-1e6a88c6f243", ResourceVersion:"1391486", Generation:1, CreationTimestamp:v1.Time{Time:time.Time{wall:0x0, ext:63746612886, loc:(*time.Location)(0x1ff3780)}}, DeletionTimestamp:(*v1.Time)(nil), DeletionGracePeriodSeconds:(*int64)(nil), Labels:map[string]string(nil), Annotations:map[string]string(nil), OwnerReferences:[]v1.OwnerReference(nil), Finalizers:[]string{"snapshot.storage.kubernetes.io/volumesnapshot-as-source-protection"}, ClusterName:"", ManagedFields:[]v1.ManagedFieldsEntry(nil)}, Spec:v1beta1.VolumeSnapshotSpec{Source:v1beta1.VolumeSnapshotSource{PersistentVolumeClaimName:(*string)(0xc0002d9870), VolumeSnapshotContentName:(*string)(nil)}, VolumeSnapshotClassName:(*string)(0xc0002d9880)}, Status:(*v1beta1.VolumeSnapshotStatus)(0xc0003fba10)}]
I0119 00:28:06.779004       1 snapshot_controller.go:397] bindandUpdateVolumeSnapshot &{{ } {snapshot1  test /apis/snapshot.storage.k8s.io/v1beta1/namespaces/test/volumesnapshots/snapshot1 e1875527-f688-42ac-9d08-1e6a88c6f243 1391486 1 2021-01-19 00:28:06 +0000 UTC <nil> <nil> map[] map[] [] [snapshot.storage.kubernetes.io/volumesnapshot-as-source-protection]  []} {{0xc0002d9870 <nil>} 0xc0002d9880} 0xc0003fba10}
I0119 00:28:06.779060       1 snapshot_controller_base.go:205] snapshotWorker[test/snapshot1]
I0119 00:28:06.779069       1 snapshot_controller_base.go:208] snapshotWorker: snapshot namespace [test] name [snapshot1]
I0119 00:28:06.779088       1 snapshot_controller_base.go:327] checkAndUpdateSnapshotClass [snapshot1]: VolumeSnapshotClassName [acs-abs-snapshot-class]
I0119 00:28:06.779095       1 snapshot_controller.go:1086] getSnapshotClass: VolumeSnapshotClassName [acs-abs-snapshot-class]
I0119 00:28:06.779101       1 snapshot_controller_base.go:346] VolumeSnapshotClass [acs-abs-snapshot-class] Driver [csi.nutanix.com]
I0119 00:28:06.779108       1 snapshot_controller_base.go:219] passed checkAndUpdateSnapshotClass for snapshot "test/snapshot1"
I0119 00:28:06.779115       1 snapshot_controller_base.go:356] updateSnapshot "test/snapshot1"
I0119 00:28:06.779147       1 util.go:147] storeObjectUpdate updating snapshot "test/snapshot1" with version 1391486
I0119 00:28:06.779161       1 snapshot_controller.go:157] synchronizing VolumeSnapshot[test/snapshot1]: bound to: "snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243", Completed: false
I0119 00:28:06.779183       1 snapshot_controller.go:159] syncSnapshot [test/snapshot1]: check if we should remove finalizer on snapshot PVC source and remove it if we can
I0119 00:28:06.779191       1 snapshot_controller.go:820] checkandRemovePVCFinalizer for snapshot [snapshot1]: snapshot status [&v1beta1.VolumeSnapshotStatus{BoundVolumeSnapshotContentName:(*string)(0xc0002d94d0), CreationTime:(*v1.Time)(nil), ReadyToUse:(*bool)(0xc000486b2a), RestoreSize:(*resource.Quantity)(nil), Error:(*v1beta1.VolumeSnapshotError)(nil)}]
I0119 00:28:06.779207       1 snapshot_controller.go:780] Checking isPVCBeingUsed for snapshot [test/snapshot1]
I0119 00:28:06.779217       1 snapshot_controller.go:796] Keeping PVC test/claim1, it is used by snapshot test/snapshot1
I0119 00:28:06.779224       1 snapshot_controller.go:175] syncSnapshot[test/snapshot1]: check if we should add finalizers on snapshot
I0119 00:28:06.779230       1 snapshot_controller.go:202] processFinalizersAndCheckandDeleteContent: Content [snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243] deletion policy [Delete] is delete.
I0119 00:28:06.779237       1 snapshot_controller.go:209] syncSnapshot: VolumeSnapshot snapshot1 is bound to volumeSnapshotContent [snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243]
I0119 00:28:06.779243       1 snapshot_controller.go:299] checkandAddSnapshotFinalizers: Add Finalizer for VolumeSnapshot[test/snapshot1]
I0119 00:28:06.784758       1 snapshot_controller_base.go:173] enqueued "test/snapshot1" for sync
I0119 00:28:06.785385       1 util.go:147] storeObjectUpdate updating snapshot "test/snapshot1" with version 1391486
I0119 00:28:06.785417       1 snapshot_controller.go:1210] Added protection finalizer to volume snapshot test/snapshot1
I0119 00:28:06.785432       1 snapshot_controller.go:342] syncUnreadySnapshot test/snapshot1
I0119 00:28:06.785445       1 snapshot_controller.go:377] before getMatchSnapshotContent for snapshot test/snapshot1
I0119 00:28:06.785462       1 snapshot_controller.go:388] Found VolumeSnapshotContent object snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243 for snapshot test/snapshot1
I0119 00:28:06.785494       1 snapshot_controller.go:871] bindandUpdateVolumeSnapshot for snapshot [snapshot1]: snapshotContent [snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243]
I0119 00:28:06.788109       1 snapshot_controller.go:882] bindandUpdateVolumeSnapshot [test/snapshot1]: trying to update snapshot status
I0119 00:28:06.788149       1 snapshot_controller.go:942] updateSnapshotStatus[test/snapshot1]
I0119 00:28:06.788158       1 snapshot_controller.go:959] updateSnapshotStatus: updating VolumeSnapshot [&{TypeMeta:{Kind: APIVersion:} ObjectMeta:{Name:snapshot1 GenerateName: Namespace:test SelfLink:/apis/snapshot.storage.k8s.io/v1beta1/namespaces/test/volumesnapshots/snapshot1 UID:e1875527-f688-42ac-9d08-1e6a88c6f243 ResourceVersion:1391487 Generation:1 CreationTimestamp:2021-01-19 00:28:06 +0000 UTC DeletionTimestamp:<nil> DeletionGracePeriodSeconds:<nil> Labels:map[] Annotations:map[] OwnerReferences:[] Finalizers:[snapshot.storage.kubernetes.io/volumesnapshot-as-source-protection snapshot.storage.kubernetes.io/volumesnapshot-bound-protection] ClusterName: ManagedFields:[]} Spec:{Source:{PersistentVolumeClaimName:0xc0003053f0 VolumeSnapshotContentName:<nil>} VolumeSnapshotClassName:0xc000305400} Status:0xc000382a80}] based on VolumeSnapshotContentStatus [<nil>]
I0119 00:28:06.790619       1 util.go:147] storeObjectUpdate updating snapshot "test/snapshot1" with version 1391487
I0119 00:28:06.790660       1 snapshot_controller.go:903] bindandUpdateVolumeSnapshot for snapshot completed [&v1beta1.VolumeSnapshot{TypeMeta:v1.TypeMeta{Kind:"", APIVersion:""}, ObjectMeta:v1.ObjectMeta{Name:"snapshot1", GenerateName:"", Namespace:"test", SelfLink:"/apis/snapshot.storage.k8s.io/v1beta1/namespaces/test/volumesnapshots/snapshot1", UID:"e1875527-f688-42ac-9d08-1e6a88c6f243", ResourceVersion:"1391487", Generation:1, CreationTimestamp:v1.Time{Time:time.Time{wall:0x0, ext:63746612886, loc:(*time.Location)(0x1ff3780)}}, DeletionTimestamp:(*v1.Time)(nil), DeletionGracePeriodSeconds:(*int64)(nil), Labels:map[string]string(nil), Annotations:map[string]string(nil), OwnerReferences:[]v1.OwnerReference(nil), Finalizers:[]string{"snapshot.storage.kubernetes.io/volumesnapshot-as-source-protection", "snapshot.storage.kubernetes.io/volumesnapshot-bound-protection"}, ClusterName:"", ManagedFields:[]v1.ManagedFieldsEntry(nil)}, Spec:v1beta1.VolumeSnapshotSpec{Source:v1beta1.VolumeSnapshotSource{PersistentVolumeClaimName:(*string)(0xc000305720), VolumeSnapshotContentName:(*string)(nil)}, VolumeSnapshotClassName:(*string)(0xc000305730)}, Status:(*v1beta1.VolumeSnapshotStatus)(0xc000382ed0)}]
I0119 00:28:06.790723       1 snapshot_controller.go:397] bindandUpdateVolumeSnapshot &{{ } {snapshot1  test /apis/snapshot.storage.k8s.io/v1beta1/namespaces/test/volumesnapshots/snapshot1 e1875527-f688-42ac-9d08-1e6a88c6f243 1391487 1 2021-01-19 00:28:06 +0000 UTC <nil> <nil> map[] map[] [] [snapshot.storage.kubernetes.io/volumesnapshot-as-source-protection snapshot.storage.kubernetes.io/volumesnapshot-bound-protection]  []} {{0xc000305720 <nil>} 0xc000305730} 0xc000382ed0}
I0119 00:28:06.790821       1 snapshot_controller_base.go:205] snapshotWorker[test/snapshot1]
I0119 00:28:06.790831       1 snapshot_controller_base.go:208] snapshotWorker: snapshot namespace [test] name [snapshot1]
I0119 00:28:06.790838       1 snapshot_controller_base.go:327] checkAndUpdateSnapshotClass [snapshot1]: VolumeSnapshotClassName [acs-abs-snapshot-class]
I0119 00:28:06.790844       1 snapshot_controller.go:1086] getSnapshotClass: VolumeSnapshotClassName [acs-abs-snapshot-class]
I0119 00:28:06.790858       1 snapshot_controller_base.go:346] VolumeSnapshotClass [acs-abs-snapshot-class] Driver [csi.nutanix.com]
I0119 00:28:06.790866       1 snapshot_controller_base.go:219] passed checkAndUpdateSnapshotClass for snapshot "test/snapshot1"
I0119 00:28:06.790872       1 snapshot_controller_base.go:356] updateSnapshot "test/snapshot1"
I0119 00:28:06.790881       1 util.go:147] storeObjectUpdate updating snapshot "test/snapshot1" with version 1391487
I0119 00:28:06.790898       1 snapshot_controller.go:157] synchronizing VolumeSnapshot[test/snapshot1]: bound to: "snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243", Completed: false
I0119 00:28:06.790922       1 snapshot_controller.go:159] syncSnapshot [test/snapshot1]: check if we should remove finalizer on snapshot PVC source and remove it if we can
I0119 00:28:06.790930       1 snapshot_controller.go:820] checkandRemovePVCFinalizer for snapshot [snapshot1]: snapshot status [&v1beta1.VolumeSnapshotStatus{BoundVolumeSnapshotContentName:(*string)(0xc000304fa0), CreationTime:(*v1.Time)(nil), ReadyToUse:(*bool)(0xc0002a3bba), RestoreSize:(*resource.Quantity)(nil), Error:(*v1beta1.VolumeSnapshotError)(nil)}]
I0119 00:28:06.790947       1 snapshot_controller.go:780] Checking isPVCBeingUsed for snapshot [test/snapshot1]
I0119 00:28:06.790958       1 snapshot_controller.go:796] Keeping PVC test/claim1, it is used by snapshot test/snapshot1
I0119 00:28:06.790969       1 snapshot_controller.go:175] syncSnapshot[test/snapshot1]: check if we should add finalizers on snapshot
I0119 00:28:06.790986       1 snapshot_controller.go:202] processFinalizersAndCheckandDeleteContent: Content [snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243] deletion policy [Delete] is delete.
I0119 00:28:06.790993       1 snapshot_controller.go:209] syncSnapshot: VolumeSnapshot snapshot1 is bound to volumeSnapshotContent [snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243]
I0119 00:28:06.791000       1 snapshot_controller.go:342] syncUnreadySnapshot test/snapshot1
I0119 00:28:06.791019       1 snapshot_controller.go:377] before getMatchSnapshotContent for snapshot test/snapshot1
I0119 00:28:06.791029       1 snapshot_controller.go:388] Found VolumeSnapshotContent object snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243 for snapshot test/snapshot1
I0119 00:28:06.791034       1 snapshot_controller.go:871] bindandUpdateVolumeSnapshot for snapshot [snapshot1]: snapshotContent [snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243]
I0119 00:28:06.920480       1 request.go:565] Throttling request took 129.357364ms, request: GET:https://172.19.0.1:443/apis/snapshot.storage.k8s.io/v1beta1/namespaces/test/volumesnapshots/snapshot1
I0119 00:28:06.924701       1 snapshot_controller.go:882] bindandUpdateVolumeSnapshot [test/snapshot1]: trying to update snapshot status
I0119 00:28:06.924729       1 snapshot_controller.go:942] updateSnapshotStatus[test/snapshot1]
I0119 00:28:06.924742       1 snapshot_controller.go:959] updateSnapshotStatus: updating VolumeSnapshot [&{TypeMeta:{Kind: APIVersion:} ObjectMeta:{Name:snapshot1 GenerateName: Namespace:test SelfLink:/apis/snapshot.storage.k8s.io/v1beta1/namespaces/test/volumesnapshots/snapshot1 UID:e1875527-f688-42ac-9d08-1e6a88c6f243 ResourceVersion:1391487 Generation:1 CreationTimestamp:2021-01-19 00:28:06 +0000 UTC DeletionTimestamp:<nil> DeletionGracePeriodSeconds:<nil> Labels:map[] Annotations:map[] OwnerReferences:[] Finalizers:[snapshot.storage.kubernetes.io/volumesnapshot-as-source-protection snapshot.storage.kubernetes.io/volumesnapshot-bound-protection] ClusterName: ManagedFields:[]} Spec:{Source:{PersistentVolumeClaimName:0xc000305e10 VolumeSnapshotContentName:<nil>} VolumeSnapshotClassName:0xc000305e20} Status:0xc0003833b0}] based on VolumeSnapshotContentStatus [<nil>]
I0119 00:28:07.120500       1 request.go:565] Throttling request took 195.545175ms, request: GET:https://172.19.0.1:443/apis/snapshot.storage.k8s.io/v1beta1/namespaces/test/volumesnapshots/snapshot1
I0119 00:28:07.124437       1 util.go:147] storeObjectUpdate updating snapshot "test/snapshot1" with version 1391487
I0119 00:28:07.124472       1 snapshot_controller.go:903] bindandUpdateVolumeSnapshot for snapshot completed [&v1beta1.VolumeSnapshot{TypeMeta:v1.TypeMeta{Kind:"", APIVersion:""}, ObjectMeta:v1.ObjectMeta{Name:"snapshot1", GenerateName:"", Namespace:"test", SelfLink:"/apis/snapshot.storage.k8s.io/v1beta1/namespaces/test/volumesnapshots/snapshot1", UID:"e1875527-f688-42ac-9d08-1e6a88c6f243", ResourceVersion:"1391487", Generation:1, CreationTimestamp:v1.Time{Time:time.Time{wall:0x0, ext:63746612886, loc:(*time.Location)(0x1ff3780)}}, DeletionTimestamp:(*v1.Time)(nil), DeletionGracePeriodSeconds:(*int64)(nil), Labels:map[string]string(nil), Annotations:map[string]string(nil), OwnerReferences:[]v1.OwnerReference(nil), Finalizers:[]string{"snapshot.storage.kubernetes.io/volumesnapshot-as-source-protection", "snapshot.storage.kubernetes.io/volumesnapshot-bound-protection"}, ClusterName:"", ManagedFields:[]v1.ManagedFieldsEntry(nil)}, Spec:v1beta1.VolumeSnapshotSpec{Source:v1beta1.VolumeSnapshotSource{PersistentVolumeClaimName:(*string)(0xc0001d4070), VolumeSnapshotContentName:(*string)(nil)}, VolumeSnapshotClassName:(*string)(0xc0001d4080)}, Status:(*v1beta1.VolumeSnapshotStatus)(0xc0004a0090)}]
I0119 00:28:07.124606       1 snapshot_controller.go:397] bindandUpdateVolumeSnapshot &{{ } {snapshot1  test /apis/snapshot.storage.k8s.io/v1beta1/namespaces/test/volumesnapshots/snapshot1 e1875527-f688-42ac-9d08-1e6a88c6f243 1391487 1 2021-01-19 00:28:06 +0000 UTC <nil> <nil> map[] map[] [] [snapshot.storage.kubernetes.io/volumesnapshot-as-source-protection snapshot.storage.kubernetes.io/volumesnapshot-bound-protection]  []} {{0xc0001d4070 <nil>} 0xc0001d4080} 0xc0004a0090}
I0119 00:29:01.314999       1 reflector.go:278] github.com/kubernetes-csi/external-snapshotter/pkg/client/informers/externalversions/factory.go:117: forcing resync
I0119 00:29:01.315187       1 reflector.go:278] github.com/kubernetes-csi/external-snapshotter/pkg/client/informers/externalversions/factory.go:117: forcing resync
I0119 00:29:01.315249       1 snapshot_controller_base.go:190] enqueued "snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243" for sync
I0119 00:29:01.315257       1 snapshot_controller_base.go:173] enqueued "test/snapshot1" for sync
I0119 00:29:01.315279       1 snapshot_controller_base.go:270] contentWorker[snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243]
I0119 00:29:01.315288       1 snapshot_controller_base.go:205] snapshotWorker[test/snapshot1]
I0119 00:29:01.315295       1 util.go:147] storeObjectUpdate updating content "snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243" with version 1391485
I0119 00:29:01.315313       1 snapshot_controller_base.go:208] snapshotWorker: snapshot namespace [test] name [snapshot1]
I0119 00:29:01.315318       1 snapshot_controller.go:86] synchronizing VolumeSnapshotContent[snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243]: content is bound to snapshot test/snapshot1
I0119 00:29:01.315382       1 snapshot_controller.go:1288] getSnapshotFromStore: snapshot test/snapshot1 found
I0119 00:29:01.315431       1 snapshot_controller.go:910] needsUpdateSnapshotStatus[test/snapshot1]
I0119 00:29:01.315329       1 snapshot_controller_base.go:327] checkAndUpdateSnapshotClass [snapshot1]: VolumeSnapshotClassName [acs-abs-snapshot-class]
I0119 00:29:01.315459       1 snapshot_controller.go:1086] getSnapshotClass: VolumeSnapshotClassName [acs-abs-snapshot-class]
I0119 00:29:01.315470       1 snapshot_controller_base.go:346] VolumeSnapshotClass [acs-abs-snapshot-class] Driver [csi.nutanix.com]
I0119 00:29:01.315482       1 snapshot_controller_base.go:219] passed checkAndUpdateSnapshotClass for snapshot "test/snapshot1"
I0119 00:29:01.315504       1 snapshot_controller_base.go:356] updateSnapshot "test/snapshot1"
I0119 00:29:01.315518       1 util.go:147] storeObjectUpdate updating snapshot "test/snapshot1" with version 1391487
I0119 00:29:01.315578       1 snapshot_controller.go:157] synchronizing VolumeSnapshot[test/snapshot1]: bound to: "snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243", Completed: false
I0119 00:29:01.315594       1 snapshot_controller.go:159] syncSnapshot [test/snapshot1]: check if we should remove finalizer on snapshot PVC source and remove it if we can
I0119 00:29:01.315611       1 snapshot_controller.go:820] checkandRemovePVCFinalizer for snapshot [snapshot1]: snapshot status [&v1beta1.VolumeSnapshotStatus{BoundVolumeSnapshotContentName:(*string)(0xc000304fa0), CreationTime:(*v1.Time)(nil), ReadyToUse:(*bool)(0xc0002a3bba), RestoreSize:(*resource.Quantity)(nil), Error:(*v1beta1.VolumeSnapshotError)(nil)}]
I0119 00:29:01.315755       1 snapshot_controller.go:780] Checking isPVCBeingUsed for snapshot [test/snapshot1]
I0119 00:29:01.315806       1 snapshot_controller.go:796] Keeping PVC test/claim1, it is used by snapshot test/snapshot1
I0119 00:29:01.315836       1 snapshot_controller.go:175] syncSnapshot[test/snapshot1]: check if we should add finalizers on snapshot
I0119 00:29:01.315850       1 snapshot_controller.go:202] processFinalizersAndCheckandDeleteContent: Content [snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243] deletion policy [Delete] is delete.
I0119 00:29:01.315873       1 snapshot_controller.go:209] syncSnapshot: VolumeSnapshot snapshot1 is bound to volumeSnapshotContent [snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243]
I0119 00:29:01.315888       1 snapshot_controller.go:342] syncUnreadySnapshot test/snapshot1
I0119 00:29:01.315902       1 snapshot_controller.go:377] before getMatchSnapshotContent for snapshot test/snapshot1
I0119 00:29:01.315920       1 snapshot_controller.go:388] Found VolumeSnapshotContent object snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243 for snapshot test/snapshot1
I0119 00:29:01.315931       1 snapshot_controller.go:871] bindandUpdateVolumeSnapshot for snapshot [snapshot1]: snapshotContent [snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243]
I0119 00:29:01.320776       1 snapshot_controller.go:882] bindandUpdateVolumeSnapshot [test/snapshot1]: trying to update snapshot status
I0119 00:29:01.320804       1 snapshot_controller.go:942] updateSnapshotStatus[test/snapshot1]
I0119 00:29:01.320813       1 snapshot_controller.go:959] updateSnapshotStatus: updating VolumeSnapshot [&{TypeMeta:{Kind: APIVersion:} ObjectMeta:{Name:snapshot1 GenerateName: Namespace:test SelfLink:/apis/snapshot.storage.k8s.io/v1beta1/namespaces/test/volumesnapshots/snapshot1 UID:e1875527-f688-42ac-9d08-1e6a88c6f243 ResourceVersion:1391487 Generation:1 CreationTimestamp:2021-01-19 00:28:06 +0000 UTC DeletionTimestamp:<nil> DeletionGracePeriodSeconds:<nil> Labels:map[] Annotations:map[] OwnerReferences:[] Finalizers:[snapshot.storage.kubernetes.io/volumesnapshot-as-source-protection snapshot.storage.kubernetes.io/volumesnapshot-bound-protection] ClusterName: ManagedFields:[]} Spec:{Source:{PersistentVolumeClaimName:0xc0001c8780 VolumeSnapshotContentName:<nil>} VolumeSnapshotClassName:0xc0001c8790} Status:0xc0001df500}] based on VolumeSnapshotContentStatus [<nil>]
I0119 00:29:01.323588       1 util.go:147] storeObjectUpdate updating snapshot "test/snapshot1" with version 1391487
I0119 00:29:01.323631       1 snapshot_controller.go:903] bindandUpdateVolumeSnapshot for snapshot completed [&v1beta1.VolumeSnapshot{TypeMeta:v1.TypeMeta{Kind:"", APIVersion:""}, ObjectMeta:v1.ObjectMeta{Name:"snapshot1", GenerateName:"", Namespace:"test", SelfLink:"/apis/snapshot.storage.k8s.io/v1beta1/namespaces/test/volumesnapshots/snapshot1", UID:"e1875527-f688-42ac-9d08-1e6a88c6f243", ResourceVersion:"1391487", Generation:1, CreationTimestamp:v1.Time{Time:time.Time{wall:0x0, ext:63746612886, loc:(*time.Location)(0x1ff3780)}}, DeletionTimestamp:(*v1.Time)(nil), DeletionGracePeriodSeconds:(*int64)(nil), Labels:map[string]string(nil), Annotations:map[string]string(nil), OwnerReferences:[]v1.OwnerReference(nil), Finalizers:[]string{"snapshot.storage.kubernetes.io/volumesnapshot-as-source-protection", "snapshot.storage.kubernetes.io/volumesnapshot-bound-protection"}, ClusterName:"", ManagedFields:[]v1.ManagedFieldsEntry(nil)}, Spec:v1beta1.VolumeSnapshotSpec{Source:v1beta1.VolumeSnapshotSource{PersistentVolumeClaimName:(*string)(0xc0001c8b10), VolumeSnapshotContentName:(*string)(nil)}, VolumeSnapshotClassName:(*string)(0xc0001c8b20)}, Status:(*v1beta1.VolumeSnapshotStatus)(0xc0001df950)}]
I0119 00:29:01.323683       1 snapshot_controller.go:397] bindandUpdateVolumeSnapshot &{{ } {snapshot1  test /apis/snapshot.storage.k8s.io/v1beta1/namespaces/test/volumesnapshots/snapshot1 e1875527-f688-42ac-9d08-1e6a88c6f243 1391487 1 2021-01-19 00:28:06 +0000 UTC <nil> <nil> map[] map[] [] [snapshot.storage.kubernetes.io/volumesnapshot-as-source-protection snapshot.storage.kubernetes.io/volumesnapshot-bound-protection]  []} {{0xc0001c8b10 <nil>} 0xc0001c8b20} 0xc0001df950}
I0119 00:30:01.316388       1 reflector.go:278] github.com/kubernetes-csi/external-snapshotter/pkg/client/informers/externalversions/factory.go:117: forcing resync
I0119 00:30:01.316598       1 snapshot_controller_base.go:190] enqueued "snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243" for sync
I0119 00:30:01.316612       1 reflector.go:278] github.com/kubernetes-csi/external-snapshotter/pkg/client/informers/externalversions/factory.go:117: forcing resync
I0119 00:30:01.316872       1 snapshot_controller_base.go:173] enqueued "test/snapshot1" for sync
I0119 00:30:01.316902       1 snapshot_controller_base.go:205] snapshotWorker[test/snapshot1]
I0119 00:30:01.316912       1 snapshot_controller_base.go:208] snapshotWorker: snapshot namespace [test] name [snapshot1]
I0119 00:30:01.316928       1 snapshot_controller_base.go:327] checkAndUpdateSnapshotClass [snapshot1]: VolumeSnapshotClassName [acs-abs-snapshot-class]
I0119 00:30:01.316936       1 snapshot_controller.go:1086] getSnapshotClass: VolumeSnapshotClassName [acs-abs-snapshot-class]
I0119 00:30:01.316944       1 snapshot_controller_base.go:346] VolumeSnapshotClass [acs-abs-snapshot-class] Driver [csi.nutanix.com]
I0119 00:30:01.316953       1 snapshot_controller_base.go:219] passed checkAndUpdateSnapshotClass for snapshot "test/snapshot1"
I0119 00:30:01.316962       1 snapshot_controller_base.go:356] updateSnapshot "test/snapshot1"
I0119 00:30:01.316976       1 util.go:147] storeObjectUpdate updating snapshot "test/snapshot1" with version 1391487
I0119 00:30:01.316879       1 snapshot_controller_base.go:270] contentWorker[snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243]
I0119 00:30:01.317012       1 util.go:147] storeObjectUpdate updating content "snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243" with version 1391485
I0119 00:30:01.317029       1 snapshot_controller.go:86] synchronizing VolumeSnapshotContent[snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243]: content is bound to snapshot test/snapshot1
I0119 00:30:01.317038       1 snapshot_controller.go:1288] getSnapshotFromStore: snapshot test/snapshot1 found
I0119 00:30:01.317047       1 snapshot_controller.go:910] needsUpdateSnapshotStatus[test/snapshot1]
I0119 00:30:01.316997       1 snapshot_controller.go:157] synchronizing VolumeSnapshot[test/snapshot1]: bound to: "snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243", Completed: false
I0119 00:30:01.317061       1 snapshot_controller.go:159] syncSnapshot [test/snapshot1]: check if we should remove finalizer on snapshot PVC source and remove it if we can
I0119 00:30:01.317073       1 snapshot_controller.go:820] checkandRemovePVCFinalizer for snapshot [snapshot1]: snapshot status [&v1beta1.VolumeSnapshotStatus{BoundVolumeSnapshotContentName:(*string)(0xc000304fa0), CreationTime:(*v1.Time)(nil), ReadyToUse:(*bool)(0xc0002a3bba), RestoreSize:(*resource.Quantity)(nil), Error:(*v1beta1.VolumeSnapshotError)(nil)}]
I0119 00:30:01.317198       1 snapshot_controller.go:780] Checking isPVCBeingUsed for snapshot [test/snapshot1]
I0119 00:30:01.317225       1 snapshot_controller.go:796] Keeping PVC test/claim1, it is used by snapshot test/snapshot1
I0119 00:30:01.317243       1 snapshot_controller.go:175] syncSnapshot[test/snapshot1]: check if we should add finalizers on snapshot
I0119 00:30:01.317261       1 snapshot_controller.go:202] processFinalizersAndCheckandDeleteContent: Content [snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243] deletion policy [Delete] is delete.
I0119 00:30:01.317289       1 snapshot_controller.go:209] syncSnapshot: VolumeSnapshot snapshot1 is bound to volumeSnapshotContent [snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243]
I0119 00:30:01.317318       1 snapshot_controller.go:342] syncUnreadySnapshot test/snapshot1
I0119 00:30:01.317341       1 snapshot_controller.go:377] before getMatchSnapshotContent for snapshot test/snapshot1
I0119 00:30:01.317351       1 snapshot_controller.go:388] Found VolumeSnapshotContent object snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243 for snapshot test/snapshot1
I0119 00:30:01.317358       1 snapshot_controller.go:871] bindandUpdateVolumeSnapshot for snapshot [snapshot1]: snapshotContent [snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243]
I0119 00:30:01.321201       1 snapshot_controller.go:882] bindandUpdateVolumeSnapshot [test/snapshot1]: trying to update snapshot status
I0119 00:30:01.321224       1 snapshot_controller.go:942] updateSnapshotStatus[test/snapshot1]
I0119 00:30:01.321231       1 snapshot_controller.go:959] updateSnapshotStatus: updating VolumeSnapshot [&{TypeMeta:{Kind: APIVersion:} ObjectMeta:{Name:snapshot1 GenerateName: Namespace:test SelfLink:/apis/snapshot.storage.k8s.io/v1beta1/namespaces/test/volumesnapshots/snapshot1 UID:e1875527-f688-42ac-9d08-1e6a88c6f243 ResourceVersion:1391487 Generation:1 CreationTimestamp:2021-01-19 00:28:06 +0000 UTC DeletionTimestamp:<nil> DeletionGracePeriodSeconds:<nil> Labels:map[] Annotations:map[] OwnerReferences:[] Finalizers:[snapshot.storage.kubernetes.io/volumesnapshot-as-source-protection snapshot.storage.kubernetes.io/volumesnapshot-bound-protection] ClusterName: ManagedFields:[]} Spec:{Source:{PersistentVolumeClaimName:0xc0002bc120 VolumeSnapshotContentName:<nil>} VolumeSnapshotClassName:0xc0002bc130} Status:0xc0003941b0}] based on VolumeSnapshotContentStatus [<nil>]
I0119 00:30:01.323708       1 util.go:147] storeObjectUpdate updating snapshot "test/snapshot1" with version 1391487
I0119 00:30:01.323742       1 snapshot_controller.go:903] bindandUpdateVolumeSnapshot for snapshot completed [&v1beta1.VolumeSnapshot{TypeMeta:v1.TypeMeta{Kind:"", APIVersion:""}, ObjectMeta:v1.ObjectMeta{Name:"snapshot1", GenerateName:"", Namespace:"test", SelfLink:"/apis/snapshot.storage.k8s.io/v1beta1/namespaces/test/volumesnapshots/snapshot1", UID:"e1875527-f688-42ac-9d08-1e6a88c6f243", ResourceVersion:"1391487", Generation:1, CreationTimestamp:v1.Time{Time:time.Time{wall:0x0, ext:63746612886, loc:(*time.Location)(0x1ff3780)}}, DeletionTimestamp:(*v1.Time)(nil), DeletionGracePeriodSeconds:(*int64)(nil), Labels:map[string]string(nil), Annotations:map[string]string(nil), OwnerReferences:[]v1.OwnerReference(nil), Finalizers:[]string{"snapshot.storage.kubernetes.io/volumesnapshot-as-source-protection", "snapshot.storage.kubernetes.io/volumesnapshot-bound-protection"}, ClusterName:"", ManagedFields:[]v1.ManagedFieldsEntry(nil)}, Spec:v1beta1.VolumeSnapshotSpec{Source:v1beta1.VolumeSnapshotSource{PersistentVolumeClaimName:(*string)(0xc00058a050), VolumeSnapshotContentName:(*string)(nil)}, VolumeSnapshotClassName:(*string)(0xc00058a060)}, Status:(*v1beta1.VolumeSnapshotStatus)(0xc00057a0c0)}]
I0119 00:30:01.323801       1 snapshot_controller.go:397] bindandUpdateVolumeSnapshot &{{ } {snapshot1  test /apis/snapshot.storage.k8s.io/v1beta1/namespaces/test/volumesnapshots/snapshot1 e1875527-f688-42ac-9d08-1e6a88c6f243 1391487 1 2021-01-19 00:28:06 +0000 UTC <nil> <nil> map[] map[] [] [snapshot.storage.kubernetes.io/volumesnapshot-as-source-protection snapshot.storage.kubernetes.io/volumesnapshot-bound-protection]  []} {{0xc00058a050 <nil>} 0xc00058a060} 0xc00057a0c0}
I0119 00:31:01.316663       1 reflector.go:278] github.com/kubernetes-csi/external-snapshotter/pkg/client/informers/externalversions/factory.go:117: forcing resync
I0119 00:31:01.316742       1 snapshot_controller_base.go:190] enqueued "snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243" for sync
I0119 00:31:01.316763       1 snapshot_controller_base.go:270] contentWorker[snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243]
I0119 00:31:01.316776       1 util.go:147] storeObjectUpdate updating content "snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243" with version 1391485
I0119 00:31:01.316787       1 snapshot_controller.go:86] synchronizing VolumeSnapshotContent[snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243]: content is bound to snapshot test/snapshot1
I0119 00:31:01.316794       1 snapshot_controller.go:1288] getSnapshotFromStore: snapshot test/snapshot1 found
I0119 00:31:01.316802       1 snapshot_controller.go:910] needsUpdateSnapshotStatus[test/snapshot1]
I0119 00:31:01.316983       1 reflector.go:278] github.com/kubernetes-csi/external-snapshotter/pkg/client/informers/externalversions/factory.go:117: forcing resync
I0119 00:31:01.317027       1 snapshot_controller_base.go:173] enqueued "test/snapshot1" for sync
I0119 00:31:01.317041       1 snapshot_controller_base.go:205] snapshotWorker[test/snapshot1]
I0119 00:31:01.317049       1 snapshot_controller_base.go:208] snapshotWorker: snapshot namespace [test] name [snapshot1]
I0119 00:31:01.317057       1 snapshot_controller_base.go:327] checkAndUpdateSnapshotClass [snapshot1]: VolumeSnapshotClassName [acs-abs-snapshot-class]
I0119 00:31:01.317071       1 snapshot_controller.go:1086] getSnapshotClass: VolumeSnapshotClassName [acs-abs-snapshot-class]
I0119 00:31:01.317079       1 snapshot_controller_base.go:346] VolumeSnapshotClass [acs-abs-snapshot-class] Driver [csi.nutanix.com]
I0119 00:31:01.317086       1 snapshot_controller_base.go:219] passed checkAndUpdateSnapshotClass for snapshot "test/snapshot1"
I0119 00:31:01.317093       1 snapshot_controller_base.go:356] updateSnapshot "test/snapshot1"
I0119 00:31:01.317102       1 util.go:147] storeObjectUpdate updating snapshot "test/snapshot1" with version 1391487
I0119 00:31:01.317113       1 snapshot_controller.go:157] synchronizing VolumeSnapshot[test/snapshot1]: bound to: "snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243", Completed: false
I0119 00:31:01.317148       1 snapshot_controller.go:159] syncSnapshot [test/snapshot1]: check if we should remove finalizer on snapshot PVC source and remove it if we can
I0119 00:31:01.317161       1 snapshot_controller.go:820] checkandRemovePVCFinalizer for snapshot [snapshot1]: snapshot status [&v1beta1.VolumeSnapshotStatus{BoundVolumeSnapshotContentName:(*string)(0xc000304fa0), CreationTime:(*v1.Time)(nil), ReadyToUse:(*bool)(0xc0002a3bba), RestoreSize:(*resource.Quantity)(nil), Error:(*v1beta1.VolumeSnapshotError)(nil)}]
I0119 00:31:01.317233       1 snapshot_controller.go:780] Checking isPVCBeingUsed for snapshot [test/snapshot1]
I0119 00:31:01.317247       1 snapshot_controller.go:796] Keeping PVC test/claim1, it is used by snapshot test/snapshot1
I0119 00:31:01.317253       1 snapshot_controller.go:175] syncSnapshot[test/snapshot1]: check if we should add finalizers on snapshot
I0119 00:31:01.317261       1 snapshot_controller.go:202] processFinalizersAndCheckandDeleteContent: Content [snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243] deletion policy [Delete] is delete.
I0119 00:31:01.317268       1 snapshot_controller.go:209] syncSnapshot: VolumeSnapshot snapshot1 is bound to volumeSnapshotContent [snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243]
I0119 00:31:01.317276       1 snapshot_controller.go:342] syncUnreadySnapshot test/snapshot1
I0119 00:31:01.317283       1 snapshot_controller.go:377] before getMatchSnapshotContent for snapshot test/snapshot1
I0119 00:31:01.317292       1 snapshot_controller.go:388] Found VolumeSnapshotContent object snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243 for snapshot test/snapshot1
I0119 00:31:01.317297       1 snapshot_controller.go:871] bindandUpdateVolumeSnapshot for snapshot [snapshot1]: snapshotContent [snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243]
I0119 00:31:01.320848       1 snapshot_controller.go:882] bindandUpdateVolumeSnapshot [test/snapshot1]: trying to update snapshot status
I0119 00:31:01.320871       1 snapshot_controller.go:942] updateSnapshotStatus[test/snapshot1]
I0119 00:31:01.320879       1 snapshot_controller.go:959] updateSnapshotStatus: updating VolumeSnapshot [&{TypeMeta:{Kind: APIVersion:} ObjectMeta:{Name:snapshot1 GenerateName: Namespace:test SelfLink:/apis/snapshot.storage.k8s.io/v1beta1/namespaces/test/volumesnapshots/snapshot1 UID:e1875527-f688-42ac-9d08-1e6a88c6f243 ResourceVersion:1391487 Generation:1 CreationTimestamp:2021-01-19 00:28:06 +0000 UTC DeletionTimestamp:<nil> DeletionGracePeriodSeconds:<nil> Labels:map[] Annotations:map[] OwnerReferences:[] Finalizers:[snapshot.storage.kubernetes.io/volumesnapshot-as-source-protection snapshot.storage.kubernetes.io/volumesnapshot-bound-protection] ClusterName: ManagedFields:[]} Spec:{Source:{PersistentVolumeClaimName:0xc00058a380 VolumeSnapshotContentName:<nil>} VolumeSnapshotClassName:0xc00058a390} Status:0xc00057a360}] based on VolumeSnapshotContentStatus [<nil>]
I0119 00:31:01.322981       1 util.go:147] storeObjectUpdate updating snapshot "test/snapshot1" with version 1391487
I0119 00:31:01.323022       1 snapshot_controller.go:903] bindandUpdateVolumeSnapshot for snapshot completed [&v1beta1.VolumeSnapshot{TypeMeta:v1.TypeMeta{Kind:"", APIVersion:""}, ObjectMeta:v1.ObjectMeta{Name:"snapshot1", GenerateName:"", Namespace:"test", SelfLink:"/apis/snapshot.storage.k8s.io/v1beta1/namespaces/test/volumesnapshots/snapshot1", UID:"e1875527-f688-42ac-9d08-1e6a88c6f243", ResourceVersion:"1391487", Generation:1, CreationTimestamp:v1.Time{Time:time.Time{wall:0x0, ext:63746612886, loc:(*time.Location)(0x1ff3780)}}, DeletionTimestamp:(*v1.Time)(nil), DeletionGracePeriodSeconds:(*int64)(nil), Labels:map[string]string(nil), Annotations:map[string]string(nil), OwnerReferences:[]v1.OwnerReference(nil), Finalizers:[]string{"snapshot.storage.kubernetes.io/volumesnapshot-as-source-protection", "snapshot.storage.kubernetes.io/volumesnapshot-bound-protection"}, ClusterName:"", ManagedFields:[]v1.ManagedFieldsEntry(nil)}, Spec:v1beta1.VolumeSnapshotSpec{Source:v1beta1.VolumeSnapshotSource{PersistentVolumeClaimName:(*string)(0xc00058a6d0), VolumeSnapshotContentName:(*string)(nil)}, VolumeSnapshotClassName:(*string)(0xc00058a6e0)}, Status:(*v1beta1.VolumeSnapshotStatus)(0xc00057a7e0)}]
I0119 00:31:01.323087       1 snapshot_controller.go:397] bindandUpdateVolumeSnapshot &{{ } {snapshot1  test /apis/snapshot.storage.k8s.io/v1beta1/namespaces/test/volumesnapshots/snapshot1 e1875527-f688-42ac-9d08-1e6a88c6f243 1391487 1 2021-01-19 00:28:06 +0000 UTC <nil> <nil> map[] map[] [] [snapshot.storage.kubernetes.io/volumesnapshot-as-source-protection snapshot.storage.kubernetes.io/volumesnapshot-bound-protection]  []} {{0xc00058a6d0 <nil>} 0xc00058a6e0} 0xc00057a7e0}
I0119 00:32:01.316934       1 reflector.go:278] github.com/kubernetes-csi/external-snapshotter/pkg/client/informers/externalversions/factory.go:117: forcing resync
I0119 00:32:01.318241       1 snapshot_controller_base.go:190] enqueued "snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243" for sync
I0119 00:32:01.318264       1 snapshot_controller_base.go:270] contentWorker[snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243]
I0119 00:32:01.318277       1 reflector.go:278] github.com/kubernetes-csi/external-snapshotter/pkg/client/informers/externalversions/factory.go:117: forcing resync
I0119 00:32:01.318278       1 util.go:147] storeObjectUpdate updating content "snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243" with version 1391485
I0119 00:32:01.318349       1 snapshot_controller.go:86] synchronizing VolumeSnapshotContent[snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243]: content is bound to snapshot test/snapshot1
I0119 00:32:01.318357       1 snapshot_controller.go:1288] getSnapshotFromStore: snapshot test/snapshot1 found
I0119 00:32:01.318365       1 snapshot_controller.go:910] needsUpdateSnapshotStatus[test/snapshot1]
I0119 00:32:01.318399       1 snapshot_controller_base.go:173] enqueued "test/snapshot1" for sync
I0119 00:32:01.318412       1 snapshot_controller_base.go:205] snapshotWorker[test/snapshot1]
I0119 00:32:01.318419       1 snapshot_controller_base.go:208] snapshotWorker: snapshot namespace [test] name [snapshot1]
I0119 00:32:01.318427       1 snapshot_controller_base.go:327] checkAndUpdateSnapshotClass [snapshot1]: VolumeSnapshotClassName [acs-abs-snapshot-class]
I0119 00:32:01.318433       1 snapshot_controller.go:1086] getSnapshotClass: VolumeSnapshotClassName [acs-abs-snapshot-class]
I0119 00:32:01.318439       1 snapshot_controller_base.go:346] VolumeSnapshotClass [acs-abs-snapshot-class] Driver [csi.nutanix.com]
I0119 00:32:01.318447       1 snapshot_controller_base.go:219] passed checkAndUpdateSnapshotClass for snapshot "test/snapshot1"
I0119 00:32:01.318464       1 snapshot_controller_base.go:356] updateSnapshot "test/snapshot1"
I0119 00:32:01.318472       1 util.go:147] storeObjectUpdate updating snapshot "test/snapshot1" with version 1391487
I0119 00:32:01.318483       1 snapshot_controller.go:157] synchronizing VolumeSnapshot[test/snapshot1]: bound to: "snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243", Completed: false
I0119 00:32:01.318490       1 snapshot_controller.go:159] syncSnapshot [test/snapshot1]: check if we should remove finalizer on snapshot PVC source and remove it if we can
I0119 00:32:01.318499       1 snapshot_controller.go:820] checkandRemovePVCFinalizer for snapshot [snapshot1]: snapshot status [&v1beta1.VolumeSnapshotStatus{BoundVolumeSnapshotContentName:(*string)(0xc000304fa0), CreationTime:(*v1.Time)(nil), ReadyToUse:(*bool)(0xc0002a3bba), RestoreSize:(*resource.Quantity)(nil), Error:(*v1beta1.VolumeSnapshotError)(nil)}]
I0119 00:32:01.318558       1 snapshot_controller.go:780] Checking isPVCBeingUsed for snapshot [test/snapshot1]
I0119 00:32:01.318570       1 snapshot_controller.go:796] Keeping PVC test/claim1, it is used by snapshot test/snapshot1
I0119 00:32:01.318604       1 snapshot_controller.go:175] syncSnapshot[test/snapshot1]: check if we should add finalizers on snapshot
I0119 00:32:01.318612       1 snapshot_controller.go:202] processFinalizersAndCheckandDeleteContent: Content [snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243] deletion policy [Delete] is delete.
I0119 00:32:01.318624       1 snapshot_controller.go:209] syncSnapshot: VolumeSnapshot snapshot1 is bound to volumeSnapshotContent [snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243]
I0119 00:32:01.318706       1 snapshot_controller.go:342] syncUnreadySnapshot test/snapshot1
I0119 00:32:01.318714       1 snapshot_controller.go:377] before getMatchSnapshotContent for snapshot test/snapshot1
I0119 00:32:01.318733       1 snapshot_controller.go:388] Found VolumeSnapshotContent object snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243 for snapshot test/snapshot1
I0119 00:32:01.318747       1 snapshot_controller.go:871] bindandUpdateVolumeSnapshot for snapshot [snapshot1]: snapshotContent [snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243]
I0119 00:32:01.322476       1 snapshot_controller.go:882] bindandUpdateVolumeSnapshot [test/snapshot1]: trying to update snapshot status
I0119 00:32:01.322498       1 snapshot_controller.go:942] updateSnapshotStatus[test/snapshot1]
I0119 00:32:01.322506       1 snapshot_controller.go:959] updateSnapshotStatus: updating VolumeSnapshot [&{TypeMeta:{Kind: APIVersion:} ObjectMeta:{Name:snapshot1 GenerateName: Namespace:test SelfLink:/apis/snapshot.storage.k8s.io/v1beta1/namespaces/test/volumesnapshots/snapshot1 UID:e1875527-f688-42ac-9d08-1e6a88c6f243 ResourceVersion:1391487 Generation:1 CreationTimestamp:2021-01-19 00:28:06 +0000 UTC DeletionTimestamp:<nil> DeletionGracePeriodSeconds:<nil> Labels:map[] Annotations:map[] OwnerReferences:[] Finalizers:[snapshot.storage.kubernetes.io/volumesnapshot-as-source-protection snapshot.storage.kubernetes.io/volumesnapshot-bound-protection] ClusterName: ManagedFields:[]} Spec:{Source:{PersistentVolumeClaimName:0xc0002bc120 VolumeSnapshotContentName:<nil>} VolumeSnapshotClassName:0xc0002bc130} Status:0xc0003fa2d0}] based on VolumeSnapshotContentStatus [<nil>]
I0119 00:32:01.324857       1 util.go:147] storeObjectUpdate updating snapshot "test/snapshot1" with version 1391487
I0119 00:32:01.324886       1 snapshot_controller.go:903] bindandUpdateVolumeSnapshot for snapshot completed [&v1beta1.VolumeSnapshot{TypeMeta:v1.TypeMeta{Kind:"", APIVersion:""}, ObjectMeta:v1.ObjectMeta{Name:"snapshot1", GenerateName:"", Namespace:"test", SelfLink:"/apis/snapshot.storage.k8s.io/v1beta1/namespaces/test/volumesnapshots/snapshot1", UID:"e1875527-f688-42ac-9d08-1e6a88c6f243", ResourceVersion:"1391487", Generation:1, CreationTimestamp:v1.Time{Time:time.Time{wall:0x0, ext:63746612886, loc:(*time.Location)(0x1ff3780)}}, DeletionTimestamp:(*v1.Time)(nil), DeletionGracePeriodSeconds:(*int64)(nil), Labels:map[string]string(nil), Annotations:map[string]string(nil), OwnerReferences:[]v1.OwnerReference(nil), Finalizers:[]string{"snapshot.storage.kubernetes.io/volumesnapshot-as-source-protection", "snapshot.storage.kubernetes.io/volumesnapshot-bound-protection"}, ClusterName:"", ManagedFields:[]v1.ManagedFieldsEntry(nil)}, Spec:v1beta1.VolumeSnapshotSpec{Source:v1beta1.VolumeSnapshotSource{PersistentVolumeClaimName:(*string)(0xc0002d8050), VolumeSnapshotContentName:(*string)(nil)}, VolumeSnapshotClassName:(*string)(0xc0002d8060)}, Status:(*v1beta1.VolumeSnapshotStatus)(0xc0002c00c0)}]
I0119 00:32:01.324929       1 snapshot_controller.go:397] bindandUpdateVolumeSnapshot &{{ } {snapshot1  test /apis/snapshot.storage.k8s.io/v1beta1/namespaces/test/volumesnapshots/snapshot1 e1875527-f688-42ac-9d08-1e6a88c6f243 1391487 1 2021-01-19 00:28:06 +0000 UTC <nil> <nil> map[] map[] [] [snapshot.storage.kubernetes.io/volumesnapshot-as-source-protection snapshot.storage.kubernetes.io/volumesnapshot-bound-protection]  []} {{0xc0002d8050 <nil>} 0xc0002d8060} 0xc0002c00c0}
I0119 00:33:01.317470       1 reflector.go:278] github.com/kubernetes-csi/external-snapshotter/pkg/client/informers/externalversions/factory.go:117: forcing resync
I0119 00:33:01.317577       1 snapshot_controller_base.go:190] enqueued "snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243" for sync
I0119 00:33:01.317599       1 snapshot_controller_base.go:270] contentWorker[snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243]
I0119 00:33:01.317613       1 util.go:147] storeObjectUpdate updating content "snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243" with version 1391485
I0119 00:33:01.317624       1 snapshot_controller.go:86] synchronizing VolumeSnapshotContent[snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243]: content is bound to snapshot test/snapshot1
I0119 00:33:01.317632       1 snapshot_controller.go:1288] getSnapshotFromStore: snapshot test/snapshot1 found
I0119 00:33:01.317639       1 snapshot_controller.go:910] needsUpdateSnapshotStatus[test/snapshot1]
I0119 00:33:01.318488       1 reflector.go:278] github.com/kubernetes-csi/external-snapshotter/pkg/client/informers/externalversions/factory.go:117: forcing resync
I0119 00:33:01.318527       1 snapshot_controller_base.go:173] enqueued "test/snapshot1" for sync
I0119 00:33:01.318554       1 snapshot_controller_base.go:205] snapshotWorker[test/snapshot1]
I0119 00:33:01.318563       1 snapshot_controller_base.go:208] snapshotWorker: snapshot namespace [test] name [snapshot1]
I0119 00:33:01.318570       1 snapshot_controller_base.go:327] checkAndUpdateSnapshotClass [snapshot1]: VolumeSnapshotClassName [acs-abs-snapshot-class]
I0119 00:33:01.318583       1 snapshot_controller.go:1086] getSnapshotClass: VolumeSnapshotClassName [acs-abs-snapshot-class]
I0119 00:33:01.318589       1 snapshot_controller_base.go:346] VolumeSnapshotClass [acs-abs-snapshot-class] Driver [csi.nutanix.com]
I0119 00:33:01.318597       1 snapshot_controller_base.go:219] passed checkAndUpdateSnapshotClass for snapshot "test/snapshot1"
I0119 00:33:01.318607       1 snapshot_controller_base.go:356] updateSnapshot "test/snapshot1"
I0119 00:33:01.318616       1 util.go:147] storeObjectUpdate updating snapshot "test/snapshot1" with version 1391487
I0119 00:33:01.318627       1 snapshot_controller.go:157] synchronizing VolumeSnapshot[test/snapshot1]: bound to: "snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243", Completed: false
I0119 00:33:01.318633       1 snapshot_controller.go:159] syncSnapshot [test/snapshot1]: check if we should remove finalizer on snapshot PVC source and remove it if we can
I0119 00:33:01.318642       1 snapshot_controller.go:820] checkandRemovePVCFinalizer for snapshot [snapshot1]: snapshot status [&v1beta1.VolumeSnapshotStatus{BoundVolumeSnapshotContentName:(*string)(0xc000304fa0), CreationTime:(*v1.Time)(nil), ReadyToUse:(*bool)(0xc0002a3bba), RestoreSize:(*resource.Quantity)(nil), Error:(*v1beta1.VolumeSnapshotError)(nil)}]
I0119 00:33:01.318693       1 snapshot_controller.go:780] Checking isPVCBeingUsed for snapshot [test/snapshot1]
I0119 00:33:01.318705       1 snapshot_controller.go:796] Keeping PVC test/claim1, it is used by snapshot test/snapshot1
I0119 00:33:01.318713       1 snapshot_controller.go:175] syncSnapshot[test/snapshot1]: check if we should add finalizers on snapshot
I0119 00:33:01.318720       1 snapshot_controller.go:202] processFinalizersAndCheckandDeleteContent: Content [snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243] deletion policy [Delete] is delete.
I0119 00:33:01.318727       1 snapshot_controller.go:209] syncSnapshot: VolumeSnapshot snapshot1 is bound to volumeSnapshotContent [snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243]
I0119 00:33:01.318735       1 snapshot_controller.go:342] syncUnreadySnapshot test/snapshot1
I0119 00:33:01.318744       1 snapshot_controller.go:377] before getMatchSnapshotContent for snapshot test/snapshot1
I0119 00:33:01.318753       1 snapshot_controller.go:388] Found VolumeSnapshotContent object snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243 for snapshot test/snapshot1
I0119 00:33:01.318759       1 snapshot_controller.go:871] bindandUpdateVolumeSnapshot for snapshot [snapshot1]: snapshotContent [snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243]
I0119 00:33:01.322622       1 snapshot_controller.go:882] bindandUpdateVolumeSnapshot [test/snapshot1]: trying to update snapshot status
I0119 00:33:01.322644       1 snapshot_controller.go:942] updateSnapshotStatus[test/snapshot1]
I0119 00:33:01.322652       1 snapshot_controller.go:959] updateSnapshotStatus: updating VolumeSnapshot [&{TypeMeta:{Kind: APIVersion:} ObjectMeta:{Name:snapshot1 GenerateName: Namespace:test SelfLink:/apis/snapshot.storage.k8s.io/v1beta1/namespaces/test/volumesnapshots/snapshot1 UID:e1875527-f688-42ac-9d08-1e6a88c6f243 ResourceVersion:1391487 Generation:1 CreationTimestamp:2021-01-19 00:28:06 +0000 UTC DeletionTimestamp:<nil> DeletionGracePeriodSeconds:<nil> Labels:map[] Annotations:map[] OwnerReferences:[] Finalizers:[snapshot.storage.kubernetes.io/volumesnapshot-as-source-protection snapshot.storage.kubernetes.io/volumesnapshot-bound-protection] ClusterName: ManagedFields:[]} Spec:{Source:{PersistentVolumeClaimName:0xc0002d8a40 VolumeSnapshotContentName:<nil>} VolumeSnapshotClassName:0xc0002d8a80} Status:0xc0002c0660}] based on VolumeSnapshotContentStatus [<nil>]
I0119 00:33:01.324707       1 util.go:147] storeObjectUpdate updating snapshot "test/snapshot1" with version 1391487
I0119 00:33:01.324733       1 snapshot_controller.go:903] bindandUpdateVolumeSnapshot for snapshot completed [&v1beta1.VolumeSnapshot{TypeMeta:v1.TypeMeta{Kind:"", APIVersion:""}, ObjectMeta:v1.ObjectMeta{Name:"snapshot1", GenerateName:"", Namespace:"test", SelfLink:"/apis/snapshot.storage.k8s.io/v1beta1/namespaces/test/volumesnapshots/snapshot1", UID:"e1875527-f688-42ac-9d08-1e6a88c6f243", ResourceVersion:"1391487", Generation:1, CreationTimestamp:v1.Time{Time:time.Time{wall:0x0, ext:63746612886, loc:(*time.Location)(0x1ff3780)}}, DeletionTimestamp:(*v1.Time)(nil), DeletionGracePeriodSeconds:(*int64)(nil), Labels:map[string]string(nil), Annotations:map[string]string(nil), OwnerReferences:[]v1.OwnerReference(nil), Finalizers:[]string{"snapshot.storage.kubernetes.io/volumesnapshot-as-source-protection", "snapshot.storage.kubernetes.io/volumesnapshot-bound-protection"}, ClusterName:"", ManagedFields:[]v1.ManagedFieldsEntry(nil)}, Spec:v1beta1.VolumeSnapshotSpec{Source:v1beta1.VolumeSnapshotSource{PersistentVolumeClaimName:(*string)(0xc0002d8da0), VolumeSnapshotContentName:(*string)(nil)}, VolumeSnapshotClassName:(*string)(0xc0002d8db0)}, Status:(*v1beta1.VolumeSnapshotStatus)(0xc0002c0ab0)}]
I0119 00:33:01.324771       1 snapshot_controller.go:397] bindandUpdateVolumeSnapshot &{{ } {snapshot1  test /apis/snapshot.storage.k8s.io/v1beta1/namespaces/test/volumesnapshots/snapshot1 e1875527-f688-42ac-9d08-1e6a88c6f243 1391487 1 2021-01-19 00:28:06 +0000 UTC <nil> <nil> map[] map[] [] [snapshot.storage.kubernetes.io/volumesnapshot-as-source-protection snapshot.storage.kubernetes.io/volumesnapshot-bound-protection]  []} {{0xc0002d8da0 <nil>} 0xc0002d8db0} 0xc0002c0ab0}
I0119 00:33:12.315987       1 reflector.go:432] k8s.io/client-go/informers/factory.go:135: Watch close - *v1.PersistentVolumeClaim total 6 items received
I0119 00:34:01.317695       1 reflector.go:278] github.com/kubernetes-csi/external-snapshotter/pkg/client/informers/externalversions/factory.go:117: forcing resync
I0119 00:34:01.317787       1 snapshot_controller_base.go:190] enqueued "snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243" for sync
I0119 00:34:01.317826       1 snapshot_controller_base.go:270] contentWorker[snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243]
I0119 00:34:01.317845       1 util.go:147] storeObjectUpdate updating content "snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243" with version 1391485
I0119 00:34:01.317863       1 snapshot_controller.go:86] synchronizing VolumeSnapshotContent[snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243]: content is bound to snapshot test/snapshot1
I0119 00:34:01.317884       1 snapshot_controller.go:1288] getSnapshotFromStore: snapshot test/snapshot1 found
I0119 00:34:01.317896       1 snapshot_controller.go:910] needsUpdateSnapshotStatus[test/snapshot1]
I0119 00:34:01.318659       1 reflector.go:278] github.com/kubernetes-csi/external-snapshotter/pkg/client/informers/externalversions/factory.go:117: forcing resync
I0119 00:34:01.320557       1 snapshot_controller_base.go:173] enqueued "test/snapshot1" for sync
I0119 00:34:01.320645       1 snapshot_controller_base.go:205] snapshotWorker[test/snapshot1]
I0119 00:34:01.320656       1 snapshot_controller_base.go:208] snapshotWorker: snapshot namespace [test] name [snapshot1]
I0119 00:34:01.320665       1 snapshot_controller_base.go:327] checkAndUpdateSnapshotClass [snapshot1]: VolumeSnapshotClassName [acs-abs-snapshot-class]
I0119 00:34:01.320671       1 snapshot_controller.go:1086] getSnapshotClass: VolumeSnapshotClassName [acs-abs-snapshot-class]
I0119 00:34:01.320678       1 snapshot_controller_base.go:346] VolumeSnapshotClass [acs-abs-snapshot-class] Driver [csi.nutanix.com]
I0119 00:34:01.320686       1 snapshot_controller_base.go:219] passed checkAndUpdateSnapshotClass for snapshot "test/snapshot1"
I0119 00:34:01.320699       1 snapshot_controller_base.go:356] updateSnapshot "test/snapshot1"
I0119 00:34:01.320714       1 util.go:147] storeObjectUpdate updating snapshot "test/snapshot1" with version 1391487
I0119 00:34:01.320744       1 snapshot_controller.go:157] synchronizing VolumeSnapshot[test/snapshot1]: bound to: "snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243", Completed: false
I0119 00:34:01.320758       1 snapshot_controller.go:159] syncSnapshot [test/snapshot1]: check if we should remove finalizer on snapshot PVC source and remove it if we can
I0119 00:34:01.320771       1 snapshot_controller.go:820] checkandRemovePVCFinalizer for snapshot [snapshot1]: snapshot status [&v1beta1.VolumeSnapshotStatus{BoundVolumeSnapshotContentName:(*string)(0xc000304fa0), CreationTime:(*v1.Time)(nil), ReadyToUse:(*bool)(0xc0002a3bba), RestoreSize:(*resource.Quantity)(nil), Error:(*v1beta1.VolumeSnapshotError)(nil)}]
I0119 00:34:01.320827       1 snapshot_controller.go:780] Checking isPVCBeingUsed for snapshot [test/snapshot1]
I0119 00:34:01.320840       1 snapshot_controller.go:796] Keeping PVC test/claim1, it is used by snapshot test/snapshot1
I0119 00:34:01.320848       1 snapshot_controller.go:175] syncSnapshot[test/snapshot1]: check if we should add finalizers on snapshot
I0119 00:34:01.320855       1 snapshot_controller.go:202] processFinalizersAndCheckandDeleteContent: Content [snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243] deletion policy [Delete] is delete.
I0119 00:34:01.320870       1 snapshot_controller.go:209] syncSnapshot: VolumeSnapshot snapshot1 is bound to volumeSnapshotContent [snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243]
I0119 00:34:01.320880       1 snapshot_controller.go:342] syncUnreadySnapshot test/snapshot1
I0119 00:34:01.320895       1 snapshot_controller.go:377] before getMatchSnapshotContent for snapshot test/snapshot1
I0119 00:34:01.320918       1 snapshot_controller.go:388] Found VolumeSnapshotContent object snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243 for snapshot test/snapshot1
I0119 00:34:01.320940       1 snapshot_controller.go:871] bindandUpdateVolumeSnapshot for snapshot [snapshot1]: snapshotContent [snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243]
I0119 00:34:01.325404       1 snapshot_controller.go:882] bindandUpdateVolumeSnapshot [test/snapshot1]: trying to update snapshot status
I0119 00:34:01.325433       1 snapshot_controller.go:942] updateSnapshotStatus[test/snapshot1]
I0119 00:34:01.325446       1 snapshot_controller.go:959] updateSnapshotStatus: updating VolumeSnapshot [&{TypeMeta:{Kind: APIVersion:} ObjectMeta:{Name:snapshot1 GenerateName: Namespace:test SelfLink:/apis/snapshot.storage.k8s.io/v1beta1/namespaces/test/volumesnapshots/snapshot1 UID:e1875527-f688-42ac-9d08-1e6a88c6f243 ResourceVersion:1391487 Generation:1 CreationTimestamp:2021-01-19 00:28:06 +0000 UTC DeletionTimestamp:<nil> DeletionGracePeriodSeconds:<nil> Labels:map[] Annotations:map[] OwnerReferences:[] Finalizers:[snapshot.storage.kubernetes.io/volumesnapshot-as-source-protection snapshot.storage.kubernetes.io/volumesnapshot-bound-protection] ClusterName: ManagedFields:[]} Spec:{Source:{PersistentVolumeClaimName:0xc0001c80f0 VolumeSnapshotContentName:<nil>} VolumeSnapshotClassName:0xc0001c8100} Status:0xc000394210}] based on VolumeSnapshotContentStatus [<nil>]
I0119 00:34:01.327713       1 util.go:147] storeObjectUpdate updating snapshot "test/snapshot1" with version 1391487
I0119 00:34:01.327751       1 snapshot_controller.go:903] bindandUpdateVolumeSnapshot for snapshot completed [&v1beta1.VolumeSnapshot{TypeMeta:v1.TypeMeta{Kind:"", APIVersion:""}, ObjectMeta:v1.ObjectMeta{Name:"snapshot1", GenerateName:"", Namespace:"test", SelfLink:"/apis/snapshot.storage.k8s.io/v1beta1/namespaces/test/volumesnapshots/snapshot1", UID:"e1875527-f688-42ac-9d08-1e6a88c6f243", ResourceVersion:"1391487", Generation:1, CreationTimestamp:v1.Time{Time:time.Time{wall:0x0, ext:63746612886, loc:(*time.Location)(0x1ff3780)}}, DeletionTimestamp:(*v1.Time)(nil), DeletionGracePeriodSeconds:(*int64)(nil), Labels:map[string]string(nil), Annotations:map[string]string(nil), OwnerReferences:[]v1.OwnerReference(nil), Finalizers:[]string{"snapshot.storage.kubernetes.io/volumesnapshot-as-source-protection", "snapshot.storage.kubernetes.io/volumesnapshot-bound-protection"}, ClusterName:"", ManagedFields:[]v1.ManagedFieldsEntry(nil)}, Spec:v1beta1.VolumeSnapshotSpec{Source:v1beta1.VolumeSnapshotSource{PersistentVolumeClaimName:(*string)(0xc0001c8450), VolumeSnapshotContentName:(*string)(nil)}, VolumeSnapshotClassName:(*string)(0xc0001c8460)}, Status:(*v1beta1.VolumeSnapshotStatus)(0xc0003946f0)}]
I0119 00:34:01.327814       1 snapshot_controller.go:397] bindandUpdateVolumeSnapshot &{{ } {snapshot1  test /apis/snapshot.storage.k8s.io/v1beta1/namespaces/test/volumesnapshots/snapshot1 e1875527-f688-42ac-9d08-1e6a88c6f243 1391487 1 2021-01-19 00:28:06 +0000 UTC <nil> <nil> map[] map[] [] [snapshot.storage.kubernetes.io/volumesnapshot-as-source-protection snapshot.storage.kubernetes.io/volumesnapshot-bound-protection]  []} {{0xc0001c8450 <nil>} 0xc0001c8460} 0xc0003946f0}
I0119 00:34:02.314597       1 reflector.go:432] github.com/kubernetes-csi/external-snapshotter/pkg/client/informers/externalversions/factory.go:117: Watch close - *v1beta1.VolumeSnapshotClass total 0 items received
I0119 00:34:20.315670       1 reflector.go:432] github.com/kubernetes-csi/external-snapshotter/pkg/client/informers/externalversions/factory.go:117: Watch close - *v1beta1.VolumeSnapshotContent total 3 items received
I0119 00:35:01.317867       1 reflector.go:278] github.com/kubernetes-csi/external-snapshotter/pkg/client/informers/externalversions/factory.go:117: forcing resync
I0119 00:35:01.317959       1 snapshot_controller_base.go:190] enqueued "snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243" for sync
I0119 00:35:01.317990       1 snapshot_controller_base.go:270] contentWorker[snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243]
I0119 00:35:01.318003       1 util.go:147] storeObjectUpdate updating content "snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243" with version 1391485
I0119 00:35:01.318018       1 snapshot_controller.go:86] synchronizing VolumeSnapshotContent[snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243]: content is bound to snapshot test/snapshot1
I0119 00:35:01.318027       1 snapshot_controller.go:1288] getSnapshotFromStore: snapshot test/snapshot1 found
I0119 00:35:01.318035       1 snapshot_controller.go:910] needsUpdateSnapshotStatus[test/snapshot1]
I0119 00:35:01.319178       1 reflector.go:278] github.com/kubernetes-csi/external-snapshotter/pkg/client/informers/externalversions/factory.go:117: forcing resync
I0119 00:35:01.319217       1 snapshot_controller_base.go:173] enqueued "test/snapshot1" for sync
I0119 00:35:01.319230       1 snapshot_controller_base.go:205] snapshotWorker[test/snapshot1]
I0119 00:35:01.319237       1 snapshot_controller_base.go:208] snapshotWorker: snapshot namespace [test] name [snapshot1]
I0119 00:35:01.319245       1 snapshot_controller_base.go:327] checkAndUpdateSnapshotClass [snapshot1]: VolumeSnapshotClassName [acs-abs-snapshot-class]
I0119 00:35:01.319261       1 snapshot_controller.go:1086] getSnapshotClass: VolumeSnapshotClassName [acs-abs-snapshot-class]
I0119 00:35:01.319269       1 snapshot_controller_base.go:346] VolumeSnapshotClass [acs-abs-snapshot-class] Driver [csi.nutanix.com]
I0119 00:35:01.319277       1 snapshot_controller_base.go:219] passed checkAndUpdateSnapshotClass for snapshot "test/snapshot1"
I0119 00:35:01.319283       1 snapshot_controller_base.go:356] updateSnapshot "test/snapshot1"
I0119 00:35:01.319292       1 util.go:147] storeObjectUpdate updating snapshot "test/snapshot1" with version 1391487
I0119 00:35:01.319306       1 snapshot_controller.go:157] synchronizing VolumeSnapshot[test/snapshot1]: bound to: "snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243", Completed: false
I0119 00:35:01.319312       1 snapshot_controller.go:159] syncSnapshot [test/snapshot1]: check if we should remove finalizer on snapshot PVC source and remove it if we can
I0119 00:35:01.319321       1 snapshot_controller.go:820] checkandRemovePVCFinalizer for snapshot [snapshot1]: snapshot status [&v1beta1.VolumeSnapshotStatus{BoundVolumeSnapshotContentName:(*string)(0xc000304fa0), CreationTime:(*v1.Time)(nil), ReadyToUse:(*bool)(0xc0002a3bba), RestoreSize:(*resource.Quantity)(nil), Error:(*v1beta1.VolumeSnapshotError)(nil)}]
I0119 00:35:01.319371       1 snapshot_controller.go:780] Checking isPVCBeingUsed for snapshot [test/snapshot1]
I0119 00:35:01.319383       1 snapshot_controller.go:796] Keeping PVC test/claim1, it is used by snapshot test/snapshot1
I0119 00:35:01.319390       1 snapshot_controller.go:175] syncSnapshot[test/snapshot1]: check if we should add finalizers on snapshot
I0119 00:35:01.319403       1 snapshot_controller.go:202] processFinalizersAndCheckandDeleteContent: Content [snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243] deletion policy [Delete] is delete.
I0119 00:35:01.319411       1 snapshot_controller.go:209] syncSnapshot: VolumeSnapshot snapshot1 is bound to volumeSnapshotContent [snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243]
I0119 00:35:01.319419       1 snapshot_controller.go:342] syncUnreadySnapshot test/snapshot1
I0119 00:35:01.319427       1 snapshot_controller.go:377] before getMatchSnapshotContent for snapshot test/snapshot1
I0119 00:35:01.319435       1 snapshot_controller.go:388] Found VolumeSnapshotContent object snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243 for snapshot test/snapshot1
I0119 00:35:01.319441       1 snapshot_controller.go:871] bindandUpdateVolumeSnapshot for snapshot [snapshot1]: snapshotContent [snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243]
I0119 00:35:01.323260       1 snapshot_controller.go:882] bindandUpdateVolumeSnapshot [test/snapshot1]: trying to update snapshot status
I0119 00:35:01.323288       1 snapshot_controller.go:942] updateSnapshotStatus[test/snapshot1]
I0119 00:35:01.323296       1 snapshot_controller.go:959] updateSnapshotStatus: updating VolumeSnapshot [&{TypeMeta:{Kind: APIVersion:} ObjectMeta:{Name:snapshot1 GenerateName: Namespace:test SelfLink:/apis/snapshot.storage.k8s.io/v1beta1/namespaces/test/volumesnapshots/snapshot1 UID:e1875527-f688-42ac-9d08-1e6a88c6f243 ResourceVersion:1391487 Generation:1 CreationTimestamp:2021-01-19 00:28:06 +0000 UTC DeletionTimestamp:<nil> DeletionGracePeriodSeconds:<nil> Labels:map[] Annotations:map[] OwnerReferences:[] Finalizers:[snapshot.storage.kubernetes.io/volumesnapshot-as-source-protection snapshot.storage.kubernetes.io/volumesnapshot-bound-protection] ClusterName: ManagedFields:[]} Spec:{Source:{PersistentVolumeClaimName:0xc0001c9110 VolumeSnapshotContentName:<nil>} VolumeSnapshotClassName:0xc0001c9120} Status:0xc000395080}] based on VolumeSnapshotContentStatus [<nil>]
I0119 00:35:01.325735       1 util.go:147] storeObjectUpdate updating snapshot "test/snapshot1" with version 1391487
I0119 00:35:01.325778       1 snapshot_controller.go:903] bindandUpdateVolumeSnapshot for snapshot completed [&v1beta1.VolumeSnapshot{TypeMeta:v1.TypeMeta{Kind:"", APIVersion:""}, ObjectMeta:v1.ObjectMeta{Name:"snapshot1", GenerateName:"", Namespace:"test", SelfLink:"/apis/snapshot.storage.k8s.io/v1beta1/namespaces/test/volumesnapshots/snapshot1", UID:"e1875527-f688-42ac-9d08-1e6a88c6f243", ResourceVersion:"1391487", Generation:1, CreationTimestamp:v1.Time{Time:time.Time{wall:0x0, ext:63746612886, loc:(*time.Location)(0x1ff3780)}}, DeletionTimestamp:(*v1.Time)(nil), DeletionGracePeriodSeconds:(*int64)(nil), Labels:map[string]string(nil), Annotations:map[string]string(nil), OwnerReferences:[]v1.OwnerReference(nil), Finalizers:[]string{"snapshot.storage.kubernetes.io/volumesnapshot-as-source-protection", "snapshot.storage.kubernetes.io/volumesnapshot-bound-protection"}, ClusterName:"", ManagedFields:[]v1.ManagedFieldsEntry(nil)}, Spec:v1beta1.VolumeSnapshotSpec{Source:v1beta1.VolumeSnapshotSource{PersistentVolumeClaimName:(*string)(0xc00058a050), VolumeSnapshotContentName:(*string)(nil)}, VolumeSnapshotClassName:(*string)(0xc00058a060)}, Status:(*v1beta1.VolumeSnapshotStatus)(0xc0003fa090)}]
I0119 00:35:01.325850       1 snapshot_controller.go:397] bindandUpdateVolumeSnapshot &{{ } {snapshot1  test /apis/snapshot.storage.k8s.io/v1beta1/namespaces/test/volumesnapshots/snapshot1 e1875527-f688-42ac-9d08-1e6a88c6f243 1391487 1 2021-01-19 00:28:06 +0000 UTC <nil> <nil> map[] map[] [] [snapshot.storage.kubernetes.io/volumesnapshot-as-source-protection snapshot.storage.kubernetes.io/volumesnapshot-bound-protection]  []} {{0xc00058a050 <nil>} 0xc00058a060} 0xc0003fa090}
I0119 00:35:43.315015       1 reflector.go:432] github.com/kubernetes-csi/external-snapshotter/pkg/client/informers/externalversions/factory.go:117: Watch close - *v1beta1.VolumeSnapshot total 5 items received
I0119 00:36:01.318069       1 reflector.go:278] github.com/kubernetes-csi/external-snapshotter/pkg/client/informers/externalversions/factory.go:117: forcing resync
I0119 00:36:01.318180       1 snapshot_controller_base.go:190] enqueued "snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243" for sync
I0119 00:36:01.318203       1 snapshot_controller_base.go:270] contentWorker[snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243]
I0119 00:36:01.318217       1 util.go:147] storeObjectUpdate updating content "snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243" with version 1391485
I0119 00:36:01.318228       1 snapshot_controller.go:86] synchronizing VolumeSnapshotContent[snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243]: content is bound to snapshot test/snapshot1
I0119 00:36:01.318235       1 snapshot_controller.go:1288] getSnapshotFromStore: snapshot test/snapshot1 found
I0119 00:36:01.318248       1 snapshot_controller.go:910] needsUpdateSnapshotStatus[test/snapshot1]
I0119 00:36:01.319317       1 reflector.go:278] github.com/kubernetes-csi/external-snapshotter/pkg/client/informers/externalversions/factory.go:117: forcing resync
I0119 00:36:01.319380       1 snapshot_controller_base.go:173] enqueued "test/snapshot1" for sync
I0119 00:36:01.319401       1 snapshot_controller_base.go:205] snapshotWorker[test/snapshot1]
I0119 00:36:01.319414       1 snapshot_controller_base.go:208] snapshotWorker: snapshot namespace [test] name [snapshot1]
I0119 00:36:01.319423       1 snapshot_controller_base.go:327] checkAndUpdateSnapshotClass [snapshot1]: VolumeSnapshotClassName [acs-abs-snapshot-class]
I0119 00:36:01.319430       1 snapshot_controller.go:1086] getSnapshotClass: VolumeSnapshotClassName [acs-abs-snapshot-class]
I0119 00:36:01.319436       1 snapshot_controller_base.go:346] VolumeSnapshotClass [acs-abs-snapshot-class] Driver [csi.nutanix.com]
I0119 00:36:01.319444       1 snapshot_controller_base.go:219] passed checkAndUpdateSnapshotClass for snapshot "test/snapshot1"
I0119 00:36:01.319451       1 snapshot_controller_base.go:356] updateSnapshot "test/snapshot1"
I0119 00:36:01.319460       1 util.go:147] storeObjectUpdate updating snapshot "test/snapshot1" with version 1391487
I0119 00:36:01.319473       1 snapshot_controller.go:157] synchronizing VolumeSnapshot[test/snapshot1]: bound to: "snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243", Completed: false
I0119 00:36:01.319480       1 snapshot_controller.go:159] syncSnapshot [test/snapshot1]: check if we should remove finalizer on snapshot PVC source and remove it if we can
I0119 00:36:01.319489       1 snapshot_controller.go:820] checkandRemovePVCFinalizer for snapshot [snapshot1]: snapshot status [&v1beta1.VolumeSnapshotStatus{BoundVolumeSnapshotContentName:(*string)(0xc000304fa0), CreationTime:(*v1.Time)(nil), ReadyToUse:(*bool)(0xc0002a3bba), RestoreSize:(*resource.Quantity)(nil), Error:(*v1beta1.VolumeSnapshotError)(nil)}]
I0119 00:36:01.319556       1 snapshot_controller.go:780] Checking isPVCBeingUsed for snapshot [test/snapshot1]
I0119 00:36:01.319571       1 snapshot_controller.go:796] Keeping PVC test/claim1, it is used by snapshot test/snapshot1
I0119 00:36:01.319582       1 snapshot_controller.go:175] syncSnapshot[test/snapshot1]: check if we should add finalizers on snapshot
I0119 00:36:01.319590       1 snapshot_controller.go:202] processFinalizersAndCheckandDeleteContent: Content [snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243] deletion policy [Delete] is delete.
I0119 00:36:01.319597       1 snapshot_controller.go:209] syncSnapshot: VolumeSnapshot snapshot1 is bound to volumeSnapshotContent [snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243]
I0119 00:36:01.319606       1 snapshot_controller.go:342] syncUnreadySnapshot test/snapshot1
I0119 00:36:01.319613       1 snapshot_controller.go:377] before getMatchSnapshotContent for snapshot test/snapshot1
I0119 00:36:01.319622       1 snapshot_controller.go:388] Found VolumeSnapshotContent object snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243 for snapshot test/snapshot1
I0119 00:36:01.319628       1 snapshot_controller.go:871] bindandUpdateVolumeSnapshot for snapshot [snapshot1]: snapshotContent [snapcontent-e1875527-f688-42ac-9d08-1e6a88c6f243]
I0119 00:36:01.325774       1 snapshot_controller.go:882] bindandUpdateVolumeSnapshot [test/snapshot1]: trying to update snapshot status
I0119 00:36:01.325805       1 snapshot_controller.go:942] updateSnapshotStatus[test/snapshot1]
I0119 00:36:01.325813       1 snapshot_controller.go:959] updateSnapshotStatus: updating VolumeSnapshot [&{TypeMeta:{Kind: APIVersion:} ObjectMeta:{Name:snapshot1 GenerateName: Namespace:test SelfLink:/apis/snapshot.storage.k8s.io/v1beta1/namespaces/test/volumesnapshots/snapshot1 UID:e1875527-f688-42ac-9d08-1e6a88c6f243 ResourceVersion:1391487 Generation:1 CreationTimestamp:2021-01-19 00:28:06 +0000 UTC DeletionTimestamp:<nil> DeletionGracePeriodSeconds:<nil> Labels:map[] Annotations:map[] OwnerReferences:[] Finalizers:[snapshot.storage.kubernetes.io/volumesnapshot-as-source-protection snapshot.storage.kubernetes.io/volumesnapshot-bound-protection] ClusterName: ManagedFields:[]} Spec:{Source:{PersistentVolumeClaimName:0xc0002bc090 VolumeSnapshotContentName:<nil>} VolumeSnapshotClassName:0xc0002bc0a0} Status:0xc0002c0060}] based on VolumeSnapshotContentStatus [<nil>]
I0119 00:36:01.329209       1 util.go:147] storeObjectUpdate updating snapshot "test/snapshot1" with version 1391487
I0119 00:36:01.329249       1 snapshot_controller.go:903] bindandUpdateVolumeSnapshot for snapshot completed [&v1beta1.VolumeSnapshot{TypeMeta:v1.TypeMeta{Kind:"", APIVersion:""}, ObjectMeta:v1.ObjectMeta{Name:"snapshot1", GenerateName:"", Namespace:"test", SelfLink:"/apis/snapshot.storage.k8s.io/v1beta1/namespaces/test/volumesnapshots/snapshot1", UID:"e1875527-f688-42ac-9d08-1e6a88c6f243", ResourceVersion:"1391487", Generation:1, CreationTimestamp:v1.Time{Time:time.Time{wall:0x0, ext:63746612886, loc:(*time.Location)(0x1ff3780)}}, DeletionTimestamp:(*v1.Time)(nil), DeletionGracePeriodSeconds:(*int64)(nil), Labels:map[string]string(nil), Annotations:map[string]string(nil), OwnerReferences:[]v1.OwnerReference(nil), Finalizers:[]string{"snapshot.storage.kubernetes.io/volumesnapshot-as-source-protection", "snapshot.storage.kubernetes.io/volumesnapshot-bound-protection"}, ClusterName:"", ManagedFields:[]v1.ManagedFieldsEntry(nil)}, Spec:v1beta1.VolumeSnapshotSpec{Source:v1beta1.VolumeSnapshotSource{PersistentVolumeClaimName:(*string)(0xc0002bc3d0), VolumeSnapshotContentName:(*string)(nil)}, VolumeSnapshotClassName:(*string)(0xc0002bc3e0)}, Status:(*v1beta1.VolumeSnapshotStatus)(0xc0002c0630)}]
I0119 00:36:01.329323       1 snapshot_controller.go:397] bindandUpdateVolumeSnapshot &{{ } {snapshot1  test /apis/snapshot.storage.k8s.io/v1beta1/namespaces/test/volumesnapshots/snapshot1 e1875527-f688-42ac-9d08-1e6a88c6f243 1391487 1 2021-01-19 00:28:06 +0000 UTC <nil> <nil> map[] map[] [] [snapshot.storage.kubernetes.io/volumesnapshot-as-source-protection snapshot.storage.kubernetes.io/volumesnapshot-bound-protection]  []} {{0xc0002bc3d0 <nil>} 0xc0002bc3e0} 0xc0002c0630}

[michaelcourcy]

All my driver are installed in a different namespace ntnx-system but in deploy all is in kube-system I need to revisit the whole install for me.

I'm very new to nutanix as well and I wonder if something can block the creation of the snapshot on the nutanix side.

[michaelcourcy]

The doc you point is 2.0.0 but my image are 2.2.0, can you confirm that should not be an issue ?

[tuxtof]

Hello @michaelcourcy , please contact me directly and we can check that together. Ask my number to Gatien.

[tuxtof]

Problem solved Due to install not fully completed

[AlexZhenWang]

Hi, any detail about this issue, get the same issue. @tuxtof what's the not completed part for michaelcourcy ? How to make the install fully completed?

I am following the doc and installed the crd and controllers

[tuxtof]

Hello @AlexZhenWang can you give more information what is your k8s platform ? CSI version ? which doc did you follow ? what did you try to achieve ?