I0922 01:35:37.714520       1 controller.go:1258] "shouldDelete" PV="pvc-2fee841a-7c7e-40ab-8b84-13ada77e3420"
I0922 01:35:37.714543       1 controller.go:1288] "shouldDelete is true" PV="pvc-2fee841a-7c7e-40ab-8b84-13ada77e3420"
I0922 01:35:37.714561       1 controller.go:1132] "shouldDelete" PV="pvc-2fee841a-7c7e-40ab-8b84-13ada77e3420"
I0922 01:35:37.714579       1 controller.go:1548] "Started" PV="pvc-2fee841a-7c7e-40ab-8b84-13ada77e3420"
I0922 01:35:37.714605       1 controller.go:1312] volume pvc-2fee841a-7c7e-40ab-8b84-13ada77e3420 does not need any deletion secrets
E0922 01:35:37.714656       1 controller.go:1558] "Volume deletion failed" err="persistentvolume pvc-2fee841a-7c7e-40ab-8b84-13ada77e3420 is still attached to node latest-worker2" PV="pvc-2fee841a-7c7e-40ab-8b84-13ada77e3420"
I0922 01:35:37.714723       1 controller.go:1007] "Retrying syncing volume" key="pvc-2fee841a-7c7e-40ab-8b84-13ada77e3420" failures=1
E0922 01:35:37.714770       1 controller.go:1025] "Unhandled Error" err="error syncing volume \"pvc-2fee841a-7c7e-40ab-8b84-13ada77e3420\": persistentvolume pvc-2fee841a-7c7e-40ab-8b84-13ada77e3420 is still attached to node latest-worker2" logger="UnhandledError"
I0922 01:35:37.714877       1 event.go:389] "Event occurred" object="pvc-2fee841a-7c7e-40ab-8b84-13ada77e3420" fieldPath="" kind="PersistentVolume" apiVersion="v1" type="Warning" reason="VolumeFailedDelete" message="persistentvolume pvc-2fee841a-7c7e-40ab-8b84-13ada77e3420 is still attached to node latest-worker2"
I0922 01:35:39.716123       1 controller.go:1171] "handleProtectionFinalizer" PV="&PersistentVolume{ObjectMeta:{pvc-2fee841a-7c7e-40ab-8b84-13ada77e3420    cfaac6f3-fedc-4826-aa4d-db4b2eff0ab0 6000408 0 2025-09-22 01:31:30 +0000 UTC <nil> <nil> map[] map[pv.kubernetes.io/provisioned-by:csi-mock-mutable-allocatable-mock-8613 volume.kubernetes.io/provisioner-deletion-secret-name: volume.kubernetes.io/provisioner-deletion-secret-namespace:] [] [external-provisioner.volume.kubernetes.io/finalizer kubernetes.io/pv-protection external-attacher/csi-mock-mutable-allocatable-mock-8613] [{csi-provisioner Update v1 2025-09-22 01:31:30 +0000 UTC FieldsV1 {\"f:metadata\":{\"f:annotations\":{\".\":{},\"f:pv.kubernetes.io/provisioned-by\":{},\"f:volume.kubernetes.io/provisioner-deletion-secret-name\":{},\"f:volume.kubernetes.io/provisioner-deletion-secret-namespace\":{}},\"f:finalizers\":{\".\":{},\"v:\\\"external-provisioner.volume.kubernetes.io/finalizer\\\"\":{}}},\"f:spec\":{\"f:accessModes\":{},\"f:capacity\":{\".\":{},\"f:storage\":{}},\"f:claimRef\":{\".\":{},\"f:apiVersion\":{},\"f:kind\":{},\"f:name\":{},\"f:namespace\":{},\"f:resourceVersion\":{},\"f:uid\":{}},\"f:csi\":{\".\":{},\"f:driver\":{},\"f:fsType\":{},\"f:volumeAttributes\":{\".\":{},\"f:name\":{},\"f:storage.kubernetes.io/csiProvisionerIdentity\":{}},\"f:volumeHandle\":{}},\"f:persistentVolumeReclaimPolicy\":{},\"f:storageClassName\":{},\"f:volumeMode\":{}}} } {csi-attacher Update v1 2025-09-22 01:31:32 +0000 UTC FieldsV1 {\"f:metadata\":{\"f:finalizers\":{\"v:\\\"external-attacher/csi-mock-mutable-allocatable-mock-8613\\\"\":{}}}} } {kube-controller-manager Update v1 2025-09-22 01:35:36 +0000 UTC FieldsV1 {\"f:status\":{\"f:phase\":{}}} status}]},Spec:PersistentVolumeSpec{Capacity:ResourceList{storage: {{1073741824 0} {<nil>} 1Gi BinarySI},},PersistentVolumeSource:PersistentVolumeSource{GCEPersistentDisk:nil,AWSElasticBlockStore:nil,HostPath:nil,Glusterfs:nil,NFS:nil,RBD:nil,ISCSI:nil,Cinder:nil,CephFS:nil,FC:nil,Flocker:nil,FlexVolume:nil,AzureFile:nil,VsphereVolume:nil,Quobyte:nil,AzureDisk:nil,PhotonPersistentDisk:nil,PortworxVolume:nil,ScaleIO:nil,Local:nil,StorageOS:nil,CSI:&CSIPersistentVolumeSource{Driver:csi-mock-mutable-allocatable-mock-8613,VolumeHandle:4,ReadOnly:false,FSType:ext4,VolumeAttributes:map[string]string{name: pvc-2fee841a-7c7e-40ab-8b84-13ada77e3420,storage.kubernetes.io/csiProvisionerIdentity: 1758504690074-7658-csi-mock-mutable-allocatable-mock-8613,},ControllerPublishSecretRef:nil,NodeStageSecretRef:nil,NodePublishSecretRef:nil,ControllerExpandSecretRef:nil,NodeExpandSecretRef:nil,},},AccessModes:[ReadWriteOnce],ClaimRef:&ObjectReference{Kind:PersistentVolumeClaim,Namespace:mutable-allocatable-mock-8613,Name:pvc-4gpbr,UID:2fee841a-7c7e-40ab-8b84-13ada77e3420,APIVersion:v1,ResourceVersion:5994023,FieldPath:,},PersistentVolumeReclaimPolicy:Delete,StorageClassName:mutable-allocatable-mock-8613-scmjzrs,MountOptions:[],VolumeMode:*Filesystem,NodeAffinity:nil,VolumeAttributesClassName:nil,},Status:PersistentVolumeStatus{Phase:Released,Message:,Reason:,LastPhaseTransitionTime:2025-09-22 01:35:36 +0000 UTC,},}"
I0922 01:35:39.716178       1 controller.go:1258] "shouldDelete" PV="pvc-2fee841a-7c7e-40ab-8b84-13ada77e3420"
I0922 01:35:39.716201       1 controller.go:1288] "shouldDelete is true" PV="pvc-2fee841a-7c7e-40ab-8b84-13ada77e3420"
I0922 01:35:39.716215       1 controller.go:1132] "shouldDelete" PV="pvc-2fee841a-7c7e-40ab-8b84-13ada77e3420"
I0922 01:35:39.716241       1 controller.go:1548] "Started" PV="pvc-2fee841a-7c7e-40ab-8b84-13ada77e3420"
I0922 01:35:39.716271       1 controller.go:1312] volume pvc-2fee841a-7c7e-40ab-8b84-13ada77e3420 does not need any deletion secrets
E0922 01:35:39.716330       1 controller.go:1558] "Volume deletion failed" err="persistentvolume pvc-2fee841a-7c7e-40ab-8b84-13ada77e3420 is still attached to node latest-worker2" PV="pvc-2fee841a-7c7e-40ab-8b84-13ada77e3420"
I0922 01:35:39.716396       1 controller.go:1007] "Retrying syncing volume" key="pvc-2fee841a-7c7e-40ab-8b84-13ada77e3420" failures=2
E0922 01:35:39.716444       1 controller.go:1025] "Unhandled Error" err="error syncing volume \"pvc-2fee841a-7c7e-40ab-8b84-13ada77e3420\": persistentvolume pvc-2fee841a-7c7e-40ab-8b84-13ada77e3420 is still attached to node latest-worker2" logger="UnhandledError"
I0922 01:35:39.716565       1 event.go:389] "Event occurred" object="pvc-2fee841a-7c7e-40ab-8b84-13ada77e3420" fieldPath="" kind="PersistentVolume" apiVersion="v1" type="Warning" reason="VolumeFailedDelete" message="persistentvolume pvc-2fee841a-7c7e-40ab-8b84-13ada77e3420 is still attached to node latest-worker2"
I0922 01:35:43.717813       1 controller.go:1171] "handleProtectionFinalizer" PV="&PersistentVolume{ObjectMeta:{pvc-2fee841a-7c7e-40ab-8b84-13ada77e3420    cfaac6f3-fedc-4826-aa4d-db4b2eff0ab0 6000408 0 2025-09-22 01:31:30 +0000 UTC <nil> <nil> map[] map[pv.kubernetes.io/provisioned-by:csi-mock-mutable-allocatable-mock-8613 volume.kubernetes.io/provisioner-deletion-secret-name: volume.kubernetes.io/provisioner-deletion-secret-namespace:] [] [external-provisioner.volume.kubernetes.io/finalizer kubernetes.io/pv-protection external-attacher/csi-mock-mutable-allocatable-mock-8613] [{csi-provisioner Update v1 2025-09-22 01:31:30 +0000 UTC FieldsV1 {\"f:metadata\":{\"f:annotations\":{\".\":{},\"f:pv.kubernetes.io/provisioned-by\":{},\"f:volume.kubernetes.io/provisioner-deletion-secret-name\":{},\"f:volume.kubernetes.io/provisioner-deletion-secret-namespace\":{}},\"f:finalizers\":{\".\":{},\"v:\\\"external-provisioner.volume.kubernetes.io/finalizer\\\"\":{}}},\"f:spec\":{\"f:accessModes\":{},\"f:capacity\":{\".\":{},\"f:storage\":{}},\"f:claimRef\":{\".\":{},\"f:apiVersion\":{},\"f:kind\":{},\"f:name\":{},\"f:namespace\":{},\"f:resourceVersion\":{},\"f:uid\":{}},\"f:csi\":{\".\":{},\"f:driver\":{},\"f:fsType\":{},\"f:volumeAttributes\":{\".\":{},\"f:name\":{},\"f:storage.kubernetes.io/csiProvisionerIdentity\":{}},\"f:volumeHandle\":{}},\"f:persistentVolumeReclaimPolicy\":{},\"f:storageClassName\":{},\"f:volumeMode\":{}}} } {csi-attacher Update v1 2025-09-22 01:31:32 +0000 UTC FieldsV1 {\"f:metadata\":{\"f:finalizers\":{\"v:\\\"external-attacher/csi-mock-mutable-allocatable-mock-8613\\\"\":{}}}} } {kube-controller-manager Update v1 2025-09-22 01:35:36 +0000 UTC FieldsV1 {\"f:status\":{\"f:phase\":{}}} status}]},Spec:PersistentVolumeSpec{Capacity:ResourceList{storage: {{1073741824 0} {<nil>} 1Gi BinarySI},},PersistentVolumeSource:PersistentVolumeSource{GCEPersistentDisk:nil,AWSElasticBlockStore:nil,HostPath:nil,Glusterfs:nil,NFS:nil,RBD:nil,ISCSI:nil,Cinder:nil,CephFS:nil,FC:nil,Flocker:nil,FlexVolume:nil,AzureFile:nil,VsphereVolume:nil,Quobyte:nil,AzureDisk:nil,PhotonPersistentDisk:nil,PortworxVolume:nil,ScaleIO:nil,Local:nil,StorageOS:nil,CSI:&CSIPersistentVolumeSource{Driver:csi-mock-mutable-allocatable-mock-8613,VolumeHandle:4,ReadOnly:false,FSType:ext4,VolumeAttributes:map[string]string{name: pvc-2fee841a-7c7e-40ab-8b84-13ada77e3420,storage.kubernetes.io/csiProvisionerIdentity: 1758504690074-7658-csi-mock-mutable-allocatable-mock-8613,},ControllerPublishSecretRef:nil,NodeStageSecretRef:nil,NodePublishSecretRef:nil,ControllerExpandSecretRef:nil,NodeExpandSecretRef:nil,},},AccessModes:[ReadWriteOnce],ClaimRef:&ObjectReference{Kind:PersistentVolumeClaim,Namespace:mutable-allocatable-mock-8613,Name:pvc-4gpbr,UID:2fee841a-7c7e-40ab-8b84-13ada77e3420,APIVersion:v1,ResourceVersion:5994023,FieldPath:,},PersistentVolumeReclaimPolicy:Delete,StorageClassName:mutable-allocatable-mock-8613-scmjzrs,MountOptions:[],VolumeMode:*Filesystem,NodeAffinity:nil,VolumeAttributesClassName:nil,},Status:PersistentVolumeStatus{Phase:Released,Message:,Reason:,LastPhaseTransitionTime:2025-09-22 01:35:36 +0000 UTC,},}"
I0922 01:35:43.717873       1 controller.go:1258] "shouldDelete" PV="pvc-2fee841a-7c7e-40ab-8b84-13ada77e3420"
I0922 01:35:43.717895       1 controller.go:1288] "shouldDelete is true" PV="pvc-2fee841a-7c7e-40ab-8b84-13ada77e3420"
I0922 01:35:43.717910       1 controller.go:1132] "shouldDelete" PV="pvc-2fee841a-7c7e-40ab-8b84-13ada77e3420"
I0922 01:35:43.717933       1 controller.go:1548] "Started" PV="pvc-2fee841a-7c7e-40ab-8b84-13ada77e3420"
I0922 01:35:43.717960       1 controller.go:1312] volume pvc-2fee841a-7c7e-40ab-8b84-13ada77e3420 does not need any deletion secrets
I0922 01:35:43.718199       1 connection.go:264] "GRPC call" method="/csi.v1.Controller/DeleteVolume" request="{\"volume_id\":\"4\"}"
I0922 01:35:43.720644       1 connection.go:270] "GRPC response" response="{}" err=null
I0922 01:35:43.720684       1 controller.go:1563] "Volume deleted" PV="pvc-2fee841a-7c7e-40ab-8b84-13ada77e3420"
I0922 01:35:43.739252       1 controller.go:1606] "PersistentVolume deleted succeeded" PV="pvc-2fee841a-7c7e-40ab-8b84-13ada77e3420"
I0922 01:35:43.739546       1 controller.go:1171] "handleProtectionFinalizer" PV="&PersistentVolume{ObjectMeta:{pvc-2fee841a-7c7e-40ab-8b84-13ada77e3420    cfaac6f3-fedc-4826-aa4d-db4b2eff0ab0 6000729 0 2025-09-22 01:31:30 +0000 UTC 2025-09-22 01:35:43 +0000 UTC 0xc000335d28 map[] map[pv.kubernetes.io/provisioned-by:csi-mock-mutable-allocatable-mock-8613 volume.kubernetes.io/provisioner-deletion-secret-name: volume.kubernetes.io/provisioner-deletion-secret-namespace:] [] [external-provisioner.volume.kubernetes.io/finalizer external-attacher/csi-mock-mutable-allocatable-mock-8613] [{csi-provisioner Update v1 2025-09-22 01:31:30 +0000 UTC FieldsV1 {\"f:metadata\":{\"f:annotations\":{\".\":{},\"f:pv.kubernetes.io/provisioned-by\":{},\"f:volume.kubernetes.io/provisioner-deletion-secret-name\":{},\"f:volume.kubernetes.io/provisioner-deletion-secret-namespace\":{}},\"f:finalizers\":{\".\":{},\"v:\\\"external-provisioner.volume.kubernetes.io/finalizer\\\"\":{}}},\"f:spec\":{\"f:accessModes\":{},\"f:capacity\":{\".\":{},\"f:storage\":{}},\"f:claimRef\":{\".\":{},\"f:apiVersion\":{},\"f:kind\":{},\"f:name\":{},\"f:namespace\":{},\"f:resourceVersion\":{},\"f:uid\":{}},\"f:csi\":{\".\":{},\"f:driver\":{},\"f:fsType\":{},\"f:volumeAttributes\":{\".\":{},\"f:name\":{},\"f:storage.kubernetes.io/csiProvisionerIdentity\":{}},\"f:volumeHandle\":{}},\"f:persistentVolumeReclaimPolicy\":{},\"f:storageClassName\":{},\"f:volumeMode\":{}}} } {csi-attacher Update v1 2025-09-22 01:31:32 +0000 UTC FieldsV1 {\"f:metadata\":{\"f:finalizers\":{\"v:\\\"external-attacher/csi-mock-mutable-allocatable-mock-8613\\\"\":{}}}} } {kube-controller-manager Update v1 2025-09-22 01:35:36 +0000 UTC FieldsV1 {\"f:status\":{\"f:phase\":{}}} status}]},Spec:PersistentVolumeSpec{Capacity:ResourceList{storage: {{1073741824 0} {<nil>} 1Gi BinarySI},},PersistentVolumeSource:PersistentVolumeSource{GCEPersistentDisk:nil,AWSElasticBlockStore:nil,HostPath:nil,Glusterfs:nil,NFS:nil,RBD:nil,ISCSI:nil,Cinder:nil,CephFS:nil,FC:nil,Flocker:nil,FlexVolume:nil,AzureFile:nil,VsphereVolume:nil,Quobyte:nil,AzureDisk:nil,PhotonPersistentDisk:nil,PortworxVolume:nil,ScaleIO:nil,Local:nil,StorageOS:nil,CSI:&CSIPersistentVolumeSource{Driver:csi-mock-mutable-allocatable-mock-8613,VolumeHandle:4,ReadOnly:false,FSType:ext4,VolumeAttributes:map[string]string{name: pvc-2fee841a-7c7e-40ab-8b84-13ada77e3420,storage.kubernetes.io/csiProvisionerIdentity: 1758504690074-7658-csi-mock-mutable-allocatable-mock-8613,},ControllerPublishSecretRef:nil,NodeStageSecretRef:nil,NodePublishSecretRef:nil,ControllerExpandSecretRef:nil,NodeExpandSecretRef:nil,},},AccessModes:[ReadWriteOnce],ClaimRef:&ObjectReference{Kind:PersistentVolumeClaim,Namespace:mutable-allocatable-mock-8613,Name:pvc-4gpbr,UID:2fee841a-7c7e-40ab-8b84-13ada77e3420,APIVersion:v1,ResourceVersion:5994023,FieldPath:,},PersistentVolumeReclaimPolicy:Delete,StorageClassName:mutable-allocatable-mock-8613-scmjzrs,MountOptions:[],VolumeMode:*Filesystem,NodeAffinity:nil,VolumeAttributesClassName:nil,},Status:PersistentVolumeStatus{Phase:Released,Message:,Reason:,LastPhaseTransitionTime:2025-09-22 01:35:36 +0000 UTC,},}"
I0922 01:35:43.739592       1 controller.go:1258] "shouldDelete" PV="pvc-2fee841a-7c7e-40ab-8b84-13ada77e3420"
I0922 01:35:43.739613       1 controller.go:1288] "shouldDelete is true" PV="pvc-2fee841a-7c7e-40ab-8b84-13ada77e3420"
I0922 01:35:43.739627       1 controller.go:1132] "shouldDelete" PV="pvc-2fee841a-7c7e-40ab-8b84-13ada77e3420"
I0922 01:35:43.739642       1 controller.go:1548] "Started" PV="pvc-2fee841a-7c7e-40ab-8b84-13ada77e3420"
I0922 01:35:43.739661       1 controller.go:1312] volume pvc-2fee841a-7c7e-40ab-8b84-13ada77e3420 does not need any deletion secrets
I0922 01:35:43.739734       1 connection.go:264] "GRPC call" method="/csi.v1.Controller/DeleteVolume" request="{\"volume_id\":\"4\"}"
I0922 01:35:43.741916       1 connection.go:270] "GRPC response" response="{}" err=null
I0922 01:35:43.741972       1 controller.go:1563] "Volume deleted" PV="pvc-2fee841a-7c7e-40ab-8b84-13ada77e3420"
I0922 01:35:43.746768       1 controller.go:1606] "PersistentVolume deleted succeeded" PV="pvc-2fee841a-7c7e-40ab-8b84-13ada77e3420"
I0922 01:35:43.747026       1 controller.go:1171] "handleProtectionFinalizer" PV="&PersistentVolume{ObjectMeta:{pvc-2fee841a-7c7e-40ab-8b84-13ada77e3420    cfaac6f3-fedc-4826-aa4d-db4b2eff0ab0 6000730 0 2025-09-22 01:31:30 +0000 UTC 2025-09-22 01:35:43 +0000 UTC 0xc0001c5d98 map[] map[pv.kubernetes.io/provisioned-by:csi-mock-mutable-allocatable-mock-8613 volume.kubernetes.io/provisioner-deletion-secret-name: volume.kubernetes.io/provisioner-deletion-secret-namespace:] [] [external-attacher/csi-mock-mutable-allocatable-mock-8613] [{csi-provisioner Update v1 2025-09-22 01:31:30 +0000 UTC FieldsV1 {\"f:metadata\":{\"f:annotations\":{\".\":{},\"f:pv.kubernetes.io/provisioned-by\":{},\"f:volume.kubernetes.io/provisioner-deletion-secret-name\":{},\"f:volume.kubernetes.io/provisioner-deletion-secret-namespace\":{}},\"f:finalizers\":{}},\"f:spec\":{\"f:accessModes\":{},\"f:capacity\":{\".\":{},\"f:storage\":{}},\"f:claimRef\":{\".\":{},\"f:apiVersion\":{},\"f:kind\":{},\"f:name\":{},\"f:namespace\":{},\"f:resourceVersion\":{},\"f:uid\":{}},\"f:csi\":{\".\":{},\"f:driver\":{},\"f:fsType\":{},\"f:volumeAttributes\":{\".\":{},\"f:name\":{},\"f:storage.kubernetes.io/csiProvisionerIdentity\":{}},\"f:volumeHandle\":{}},\"f:persistentVolumeReclaimPolicy\":{},\"f:storageClassName\":{},\"f:volumeMode\":{}}} } {csi-attacher Update v1 2025-09-22 01:31:32 +0000 UTC FieldsV1 {\"f:metadata\":{\"f:finalizers\":{\"v:\\\"external-attacher/csi-mock-mutable-allocatable-mock-8613\\\"\":{}}}} } {kube-controller-manager Update v1 2025-09-22 01:35:36 +0000 UTC FieldsV1 {\"f:status\":{\"f:phase\":{}}} status}]},Spec:PersistentVolumeSpec{Capacity:ResourceList{storage: {{1073741824 0} {<nil>} 1Gi BinarySI},},PersistentVolumeSource:PersistentVolumeSource{GCEPersistentDisk:nil,AWSElasticBlockStore:nil,HostPath:nil,Glusterfs:nil,NFS:nil,RBD:nil,ISCSI:nil,Cinder:nil,CephFS:nil,FC:nil,Flocker:nil,FlexVolume:nil,AzureFile:nil,VsphereVolume:nil,Quobyte:nil,AzureDisk:nil,PhotonPersistentDisk:nil,PortworxVolume:nil,ScaleIO:nil,Local:nil,StorageOS:nil,CSI:&CSIPersistentVolumeSource{Driver:csi-mock-mutable-allocatable-mock-8613,VolumeHandle:4,ReadOnly:false,FSType:ext4,VolumeAttributes:map[string]string{name: pvc-2fee841a-7c7e-40ab-8b84-13ada77e3420,storage.kubernetes.io/csiProvisionerIdentity: 1758504690074-7658-csi-mock-mutable-allocatable-mock-8613,},ControllerPublishSecretRef:nil,NodeStageSecretRef:nil,NodePublishSecretRef:nil,ControllerExpandSecretRef:nil,NodeExpandSecretRef:nil,},},AccessModes:[ReadWriteOnce],ClaimRef:&ObjectReference{Kind:PersistentVolumeClaim,Namespace:mutable-allocatable-mock-8613,Name:pvc-4gpbr,UID:2fee841a-7c7e-40ab-8b84-13ada77e3420,APIVersion:v1,ResourceVersion:5994023,FieldPath:,},PersistentVolumeReclaimPolicy:Delete,StorageClassName:mutable-allocatable-mock-8613-scmjzrs,MountOptions:[],VolumeMode:*Filesystem,NodeAffinity:nil,VolumeAttributesClassName:nil,},Status:PersistentVolumeStatus{Phase:Released,Message:,Reason:,LastPhaseTransitionTime:2025-09-22 01:35:36 +0000 UTC,},}"
I0922 01:35:43.747059       1 controller.go:1258] "shouldDelete" PV="pvc-2fee841a-7c7e-40ab-8b84-13ada77e3420"
I0922 01:35:43.747083       1 controller.go:1268] "shouldDelete is false: finalizer already removed from volume" PV="pvc-2fee841a-7c7e-40ab-8b84-13ada77e3420"