I0224 04:36:44.257665       1 feature_gate.go:245] feature gates: &{map[]}
I0224 04:36:44.257714       1 csi-provisioner.go:139] Version: v3.1.0
I0224 04:36:44.257718       1 csi-provisioner.go:162] Building kube configs for running in cluster...
I0224 04:36:44.258118       1 connection.go:154] Connecting to unix:///csi/csi-provisioner.sock
W0224 04:36:54.258971       1 connection.go:173] Still connecting to unix:///csi/csi-provisioner.sock
W0224 04:37:04.258921       1 connection.go:173] Still connecting to unix:///csi/csi-provisioner.sock
I0224 04:37:05.628113       1 common.go:111] Probing CSI driver for readiness
I0224 04:37:05.628174       1 connection.go:183] GRPC call: /csi.v1.Identity/Probe
I0224 04:37:05.628188       1 connection.go:184] GRPC request: {}
I0224 04:37:05.633573       1 connection.go:186] GRPC response: {}
I0224 04:37:05.633672       1 connection.go:187] GRPC error: <nil>
I0224 04:37:05.633684       1 connection.go:183] GRPC call: /csi.v1.Identity/GetPluginInfo
I0224 04:37:05.633689       1 connection.go:184] GRPC request: {}
I0224 04:37:05.634535       1 connection.go:186] GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.5.1"}
I0224 04:37:05.634647       1 connection.go:187] GRPC error: <nil>
I0224 04:37:05.634664       1 csi-provisioner.go:206] Detected CSI driver rbd.csi.ceph.com
I0224 04:37:05.634677       1 csi-provisioner.go:216] Supports migration from in-tree plugin: kubernetes.io/rbd
I0224 04:37:05.634807       1 connection.go:154] Connecting to unix:///csi/csi-provisioner.sock
I0224 04:37:05.635242       1 common.go:111] Probing CSI driver for readiness
I0224 04:37:05.635285       1 connection.go:183] GRPC call: /csi.v1.Identity/Probe
I0224 04:37:05.635289       1 connection.go:184] GRPC request: {}
I0224 04:37:05.635876       1 connection.go:186] GRPC response: {}
I0224 04:37:05.635902       1 connection.go:187] GRPC error: <nil>
I0224 04:37:05.635911       1 connection.go:183] GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0224 04:37:05.635930       1 connection.go:184] GRPC request: {}
I0224 04:37:05.637762       1 connection.go:186] GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0224 04:37:05.638664       1 connection.go:187] GRPC error: <nil>
I0224 04:37:05.638742       1 connection.go:183] GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0224 04:37:05.638760       1 connection.go:184] GRPC request: {}
I0224 04:37:05.639760       1 connection.go:186] GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}}]}
I0224 04:37:05.639893       1 connection.go:187] GRPC error: <nil>
I0224 04:37:05.639980       1 csi-provisioner.go:278] CSI driver does not support PUBLISH_UNPUBLISH_VOLUME, not watching VolumeAttachments
I0224 04:37:05.640453       1 controller.go:732] Using saving PVs to API server in background
I0224 04:37:05.640892       1 leaderelection.go:248] attempting to acquire leader lease kube-system/rbd-csi-ceph-com...
I0224 04:37:05.698609       1 leaderelection.go:258] successfully acquired lease kube-system/rbd-csi-ceph-com
I0224 04:37:05.698672       1 leader_election.go:212] new leader detected, current leader: ceph-csi-rbd-provisioner-5d8ff44fc9-jqq5b
I0224 04:37:05.698763       1 leader_election.go:205] became leader, starting
I0224 04:37:05.699022       1 reflector.go:219] Starting reflector *v1.StorageClass (1h0m0s) from k8s.io/client-go/informers/factory.go:134
I0224 04:37:05.699096       1 reflector.go:255] Listing and watching *v1.StorageClass from k8s.io/client-go/informers/factory.go:134
I0224 04:37:05.699148       1 reflector.go:219] Starting reflector *v1.PersistentVolumeClaim (15m0s) from k8s.io/client-go/informers/factory.go:134
I0224 04:37:05.699177       1 reflector.go:255] Listing and watching *v1.PersistentVolumeClaim from k8s.io/client-go/informers/factory.go:134
I0224 04:37:05.773825       1 leaderelection.go:278] successfully renewed lease kube-system/rbd-csi-ceph-com
I0224 04:37:05.799876       1 shared_informer.go:270] caches populated
I0224 04:37:05.799944       1 shared_informer.go:270] caches populated
I0224 04:37:05.799963       1 controller.go:811] Starting provisioner controller rbd.csi.ceph.com_ceph-csi-rbd-provisioner-5d8ff44fc9-jqq5b_f4c7d450-3720-4acc-99d5-73368e2ce053!
I0224 04:37:05.799983       1 clone_controller.go:66] Starting CloningProtection controller
I0224 04:37:05.800022       1 clone_controller.go:82] Started CloningProtection controller
I0224 04:37:05.800028       1 volume_store.go:97] Starting save volume queue
I0224 04:37:05.800213       1 reflector.go:219] Starting reflector *v1.PersistentVolume (15m0s) from sigs.k8s.io/sig-storage-lib-external-provisioner/v8/controller/controller.go:845
I0224 04:37:05.800226       1 reflector.go:255] Listing and watching *v1.PersistentVolume from sigs.k8s.io/sig-storage-lib-external-provisioner/v8/controller/controller.go:845
I0224 04:37:05.800365       1 reflector.go:219] Starting reflector *v1.StorageClass (15m0s) from sigs.k8s.io/sig-storage-lib-external-provisioner/v8/controller/controller.go:848
I0224 04:37:05.800412       1 reflector.go:255] Listing and watching *v1.StorageClass from sigs.k8s.io/sig-storage-lib-external-provisioner/v8/controller/controller.go:848
I0224 04:37:05.901057       1 shared_informer.go:270] caches populated
I0224 04:37:05.901658       1 controller.go:860] Started provisioner controller rbd.csi.ceph.com_ceph-csi-rbd-provisioner-5d8ff44fc9-jqq5b_f4c7d450-3720-4acc-99d5-73368e2ce053!
I0224 04:37:10.784868       1 leaderelection.go:278] successfully renewed lease kube-system/rbd-csi-ceph-com
I0224 04:37:15.793194       1 leaderelection.go:278] successfully renewed lease kube-system/rbd-csi-ceph-com
I0224 04:37:20.801179       1 leaderelection.go:278] successfully renewed lease kube-system/rbd-csi-ceph-com
I0224 04:37:25.809696       1 leaderelection.go:278] successfully renewed lease kube-system/rbd-csi-ceph-com
I0224 04:37:30.819340       1 leaderelection.go:278] successfully renewed lease kube-system/rbd-csi-ceph-com
I0224 04:37:35.830503       1 leaderelection.go:278] successfully renewed lease kube-system/rbd-csi-ceph-com
I0224 04:37:40.839093       1 leaderelection.go:278] successfully renewed lease kube-system/rbd-csi-ceph-com
I0224 04:37:45.847837       1 leaderelection.go:278] successfully renewed lease kube-system/rbd-csi-ceph-com
I0224 04:37:50.856161       1 leaderelection.go:278] successfully renewed lease kube-system/rbd-csi-ceph-com
I0224 04:37:55.863440       1 leaderelection.go:278] successfully renewed lease kube-system/rbd-csi-ceph-com
I0224 04:38:00.870530       1 leaderelection.go:278] successfully renewed lease kube-system/rbd-csi-ceph-com
I0224 04:38:05.879344       1 leaderelection.go:278] successfully renewed lease kube-system/rbd-csi-ceph-com
I0224 04:38:10.887898       1 leaderelection.go:278] successfully renewed lease kube-system/rbd-csi-ceph-com
I0224 04:38:15.895325       1 leaderelection.go:278] successfully renewed lease kube-system/rbd-csi-ceph-com
I0224 04:38:20.908096       1 leaderelection.go:278] successfully renewed lease kube-system/rbd-csi-ceph-com
I0224 04:38:25.916841       1 leaderelection.go:278] successfully renewed lease kube-system/rbd-csi-ceph-com
I0224 04:38:30.926186       1 leaderelection.go:278] successfully renewed lease kube-system/rbd-csi-ceph-com
I0224 04:38:35.934786       1 leaderelection.go:278] successfully renewed lease kube-system/rbd-csi-ceph-com
I0224 04:38:40.942638       1 leaderelection.go:278] successfully renewed lease kube-system/rbd-csi-ceph-com
I0224 04:38:45.951968       1 leaderelection.go:278] successfully renewed lease kube-system/rbd-csi-ceph-com
I0224 04:38:50.960092       1 leaderelection.go:278] successfully renewed lease kube-system/rbd-csi-ceph-com
I0224 04:38:55.967396       1 leaderelection.go:278] successfully renewed lease kube-system/rbd-csi-ceph-com
I0224 04:39:00.976236       1 leaderelection.go:278] successfully renewed lease kube-system/rbd-csi-ceph-com
I0224 04:39:05.983412       1 leaderelection.go:278] successfully renewed lease kube-system/rbd-csi-ceph-com
I0224 04:39:10.992469       1 leaderelection.go:278] successfully renewed lease kube-system/rbd-csi-ceph-com
I0224 04:39:16.001915       1 leaderelection.go:278] successfully renewed lease kube-system/rbd-csi-ceph-com
I0224 04:39:21.008089       1 leaderelection.go:278] successfully renewed lease kube-system/rbd-csi-ceph-com
I0224 04:39:26.015970       1 leaderelection.go:278] successfully renewed lease kube-system/rbd-csi-ceph-com
I0224 04:39:31.023126       1 leaderelection.go:278] successfully renewed lease kube-system/rbd-csi-ceph-com
I0224 04:39:36.034140       1 leaderelection.go:278] successfully renewed lease kube-system/rbd-csi-ceph-com
I0224 04:39:41.046387       1 leaderelection.go:278] successfully renewed lease kube-system/rbd-csi-ceph-com
I0224 04:39:46.052809       1 leaderelection.go:278] successfully renewed lease kube-system/rbd-csi-ceph-com
I0224 04:39:51.059296       1 leaderelection.go:278] successfully renewed lease kube-system/rbd-csi-ceph-com
I0224 04:39:56.066422       1 leaderelection.go:278] successfully renewed lease kube-system/rbd-csi-ceph-com
I0224 04:40:01.074556       1 leaderelection.go:278] successfully renewed lease kube-system/rbd-csi-ceph-com
I0224 04:40:02.931423       1 controller.go:1337] provision "default/test-pvc" class "general": started
I0224 04:40:02.931485       1 controller.go:528] skip translation of storage class for plugin: rbd.csi.ceph.com
I0224 04:40:02.931941       1 event.go:285] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"default", Name:"test-pvc", UID:"7b2e0fc2-5493-45fa-915a-8614a169c758", APIVersion:"v1", ResourceVersion:"1786", FieldPath:""}): type: 'Normal' reason: 'Provisioning' External provisioner is provisioning volume for claim "default/test-pvc"
I0224 04:40:02.933679       1 connection.go:183] GRPC call: /csi.v1.Controller/CreateVolume
I0224 04:40:02.933695       1 connection.go:184] GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-7b2e0fc2-5493-45fa-915a-8614a169c758","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-7b2e0fc2-5493-45fa-915a-8614a169c758","csi.storage.k8s.io/pvc/name":"test-pvc","csi.storage.k8s.io/pvc/namespace":"default","imageFeatures":"layering","pool":"kube","thickProvision":"false"},"secrets":"***stripped***","volume_capabilities":[{"AccessType":{"Mount":{"fs_type":"ext4","mount_flags":["discard"]}},"access_mode":{"mode":1}}]}
I0224 04:40:04.182846       1 connection.go:186] GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-7b2e0fc2-5493-45fa-915a-8614a169c758","csi.storage.k8s.io/pvc/name":"test-pvc","csi.storage.k8s.io/pvc/namespace":"default","imageFeatures":"layering","imageName":"csi-vol-e2692dcc-113a-11f1-a2c2-ea816f880149","journalPool":"kube","pool":"kube","thickProvision":"false"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-e2692dcc-113a-11f1-a2c2-ea816f880149"}}
I0224 04:40:04.182980       1 connection.go:187] GRPC error: <nil>
I0224 04:40:04.182988       1 controller.go:774] create volume rep: {CapacityBytes:5368709120 VolumeId:0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-e2692dcc-113a-11f1-a2c2-ea816f880149 VolumeContext:map[clusterID:4837cbf8-4f90-4300-b3f6-726c9b9f89b4 csi.storage.k8s.io/pv/name:pvc-7b2e0fc2-5493-45fa-915a-8614a169c758 csi.storage.k8s.io/pvc/name:test-pvc csi.storage.k8s.io/pvc/namespace:default imageFeatures:layering imageName:csi-vol-e2692dcc-113a-11f1-a2c2-ea816f880149 journalPool:kube pool:kube thickProvision:false] ContentSource:<nil> AccessibleTopology:[] XXX_NoUnkeyedLiteral:{} XXX_unrecognized:[] XXX_sizecache:0}
I0224 04:40:04.183024       1 controller.go:858] successfully created PV pvc-7b2e0fc2-5493-45fa-915a-8614a169c758 for PVC test-pvc and csi volume name 0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-e2692dcc-113a-11f1-a2c2-ea816f880149
I0224 04:40:04.183034       1 controller.go:874] successfully created PV {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:rbd.csi.ceph.com,VolumeHandle:0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-e2692dcc-113a-11f1-a2c2-ea816f880149,ReadOnly:false,FSType:ext4,VolumeAttributes:map[string]string{clusterID: 4837cbf8-4f90-4300-b3f6-726c9b9f89b4,csi.storage.k8s.io/pv/name: pvc-7b2e0fc2-5493-45fa-915a-8614a169c758,csi.storage.k8s.io/pvc/name: test-pvc,csi.storage.k8s.io/pvc/namespace: default,imageFeatures: layering,imageName: csi-vol-e2692dcc-113a-11f1-a2c2-ea816f880149,journalPool: kube,pool: kube,storage.kubernetes.io/csiProvisionerIdentity: 1771907825639-8081-rbd.csi.ceph.com,thickProvision: false,},ControllerPublishSecretRef:nil,NodeStageSecretRef:&SecretReference{Name:csi-rbd-secret,Namespace:kube-system,},NodePublishSecretRef:nil,ControllerExpandSecretRef:&SecretReference{Name:csi-rbd-secret,Namespace:kube-system,},}}
I0224 04:40:04.183298       1 controller.go:1442] provision "default/test-pvc" class "general": volume "pvc-7b2e0fc2-5493-45fa-915a-8614a169c758" provisioned
I0224 04:40:04.183429       1 controller.go:1455] provision "default/test-pvc" class "general": succeeded
I0224 04:40:04.183441       1 volume_store.go:154] Saving volume pvc-7b2e0fc2-5493-45fa-915a-8614a169c758
I0224 04:40:04.194057       1 volume_store.go:157] Volume pvc-7b2e0fc2-5493-45fa-915a-8614a169c758 saved
I0224 04:40:04.194301       1 event.go:285] Event(v1.ObjectReference{Kind:"PersistentVolumeClaim", Namespace:"default", Name:"test-pvc", UID:"7b2e0fc2-5493-45fa-915a-8614a169c758", APIVersion:"v1", ResourceVersion:"1786", FieldPath:""}): type: 'Normal' reason: 'ProvisioningSucceeded' Successfully provisioned volume pvc-7b2e0fc2-5493-45fa-915a-8614a169c758
I0224 04:40:04.194509       1 controller.go:1069] Claim processing succeeded, removing PVC 7b2e0fc2-5493-45fa-915a-8614a169c758 from claims in progress
I0224 04:40:06.082951       1 leaderelection.go:278] successfully renewed lease kube-system/rbd-csi-ceph-com
I0224 04:40:11.092353       1 leaderelection.go:278] successfully renewed lease kube-system/rbd-csi-ceph-com
I0224 04:40:16.102344       1 leaderelection.go:278] successfully renewed lease kube-system/rbd-csi-ceph-com
I0224 04:40:21.110415       1 leaderelection.go:278] successfully renewed lease kube-system/rbd-csi-ceph-com
I0224 04:40:26.118584       1 leaderelection.go:278] successfully renewed lease kube-system/rbd-csi-ceph-com
I0224 04:40:31.125833       1 leaderelection.go:278] successfully renewed lease kube-system/rbd-csi-ceph-com
I0224 04:40:36.133890       1 leaderelection.go:278] successfully renewed lease kube-system/rbd-csi-ceph-com
I0224 04:40:41.142512       1 leaderelection.go:278] successfully renewed lease kube-system/rbd-csi-ceph-com
I0224 04:40:46.150508       1 leaderelection.go:278] successfully renewed lease kube-system/rbd-csi-ceph-com