I0526 01:33:49.156942       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0526 01:33:49.157071       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0526 01:33:49.157084       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0526 01:33:49.157089       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0526 01:33:49.157092       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0526 01:33:49.157096       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0526 01:33:49.157102       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0526 01:33:49.157107       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0526 01:33:49.157111       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0526 01:33:49.157115       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0526 01:33:49.157446       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0526 01:33:49.157647       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0526 01:33:51.185045       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0526 01:33:51.186320       1 utils.go:199] ID: 1 GRPC request: {}
I0526 01:33:51.186380       1 utils.go:205] ID: 1 GRPC response: {}
I0526 01:33:51.193643       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0526 01:33:51.193723       1 utils.go:199] ID: 2 GRPC request: {}
I0526 01:33:51.193737       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0526 01:33:51.193786       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0526 01:33:51.195545       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0526 01:33:51.195580       1 utils.go:199] ID: 3 GRPC request: {}
I0526 01:33:51.195592       1 utils.go:205] ID: 3 GRPC response: {}
I0526 01:33:51.196673       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0526 01:33:51.196832       1 utils.go:199] ID: 4 GRPC request: {}
I0526 01:33:51.197159       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0526 01:33:51.198149       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0526 01:33:51.198319       1 utils.go:199] ID: 5 GRPC request: {}
I0526 01:33:51.198338       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0526 01:33:51.198583       1 utils.go:205] ID: 5 GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}}]}
I0526 01:33:56.162326       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0526 01:33:56.162365       1 utils.go:199] ID: 6 GRPC request: {}
I0526 01:33:56.162382       1 utils.go:205] ID: 6 GRPC response: {}
I0526 01:33:56.164697       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0526 01:33:56.164741       1 utils.go:199] ID: 7 GRPC request: {}
I0526 01:33:56.164762       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0526 01:33:56.164800       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0526 01:33:56.168372       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0526 01:33:56.168444       1 utils.go:199] ID: 8 GRPC request: {}
I0526 01:33:56.168471       1 utils.go:205] ID: 8 GRPC response: {}
I0526 01:33:56.169472       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0526 01:33:56.169495       1 utils.go:199] ID: 9 GRPC request: {}
I0526 01:33:56.169616       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0526 01:33:56.170243       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0526 01:33:56.170265       1 utils.go:199] ID: 10 GRPC request: {}
I0526 01:33:56.170274       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0526 01:33:56.170383       1 utils.go:205] ID: 10 GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}}]}
I0526 01:33:56.170898       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0526 01:33:56.170920       1 utils.go:199] ID: 11 GRPC request: {}
I0526 01:33:56.170926       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0526 01:33:56.171011       1 utils.go:205] ID: 11 GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}}]}
I0526 01:33:56.171463       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0526 01:33:56.171507       1 utils.go:199] ID: 12 GRPC request: {}
I0526 01:33:56.171522       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0526 01:33:56.171613       1 utils.go:205] ID: 12 GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}}]}
I0526 01:33:57.390463       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0526 01:33:57.390503       1 utils.go:199] ID: 13 GRPC request: {}
I0526 01:33:57.390513       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0526 01:33:57.390543       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0526 01:33:57.393161       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0526 01:33:57.393208       1 utils.go:199] ID: 14 GRPC request: {}
I0526 01:33:57.393222       1 utils.go:205] ID: 14 GRPC response: {}
I0526 01:33:57.393650       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0526 01:33:57.393674       1 utils.go:199] ID: 15 GRPC request: {}
I0526 01:33:57.393683       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0526 01:33:57.393791       1 utils.go:205] ID: 15 GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}}]}
I0526 01:33:58.591120       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0526 01:33:58.591161       1 utils.go:199] ID: 16 GRPC request: {}
I0526 01:33:58.591180       1 utils.go:205] ID: 16 GRPC response: {}
I0526 01:33:58.593225       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0526 01:33:58.593246       1 utils.go:199] ID: 17 GRPC request: {}
I0526 01:33:58.593254       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0526 01:33:58.593338       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0526 01:33:58.595400       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0526 01:33:58.595422       1 utils.go:199] ID: 18 GRPC request: {}
I0526 01:33:58.595435       1 utils.go:205] ID: 18 GRPC response: {}
I0526 01:33:58.595707       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0526 01:33:58.595730       1 utils.go:199] ID: 19 GRPC request: {}
I0526 01:33:58.595839       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0526 01:33:58.596530       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0526 01:33:58.596549       1 utils.go:199] ID: 20 GRPC request: {}
I0526 01:33:58.596556       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0526 01:33:58.596656       1 utils.go:205] ID: 20 GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}}]}
I0526 01:34:58.812396       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0526 01:34:58.812460       1 utils.go:199] ID: 21 GRPC request: {}
I0526 01:34:58.812517       1 utils.go:205] ID: 21 GRPC response: {}
I0526 01:35:58.764402       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0526 01:35:58.764471       1 utils.go:199] ID: 22 GRPC request: {}
I0526 01:35:58.764512       1 utils.go:205] ID: 22 GRPC response: {}
I0526 01:36:58.763046       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0526 01:36:58.763096       1 utils.go:199] ID: 23 GRPC request: {}
I0526 01:36:58.763119       1 utils.go:205] ID: 23 GRPC response: {}
I0526 01:37:37.267777       1 utils.go:198] ID: 24 Req-ID: pvc-ab638b12-9b6d-49f1-8c8e-58ca99bae3be GRPC call: /csi.v1.Controller/CreateVolume
I0526 01:37:37.268063       1 utils.go:199] ID: 24 Req-ID: pvc-ab638b12-9b6d-49f1-8c8e-58ca99bae3be GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-ab638b12-9b6d-49f1-8c8e-58ca99bae3be","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-ab638b12-9b6d-49f1-8c8e-58ca99bae3be","csi.storage.k8s.io/pvc/name":"test-pvc","csi.storage.k8s.io/pvc/namespace":"default","imageFeatures":"layering","pool":"kube"},"secrets":"***stripped***","volume_capabilities":[{"AccessType":{"Mount":{"fs_type":"ext4","mount_flags":["discard"]}},"access_mode":{"mode":1}}]}
I0526 01:37:37.268523       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-ab638b12-9b6d-49f1-8c8e-58ca99bae3be setting disableInUseChecks: false image features: [layering] mounter: rbd
E0526 01:37:37.284837       1 omap.go:80] ID: 24 Req-ID: pvc-ab638b12-9b6d-49f1-8c8e-58ca99bae3be omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0526 01:37:37.299840       1 omap.go:159] ID: 24 Req-ID: pvc-ab638b12-9b6d-49f1-8c8e-58ca99bae3be set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-ab638b12-9b6d-49f1-8c8e-58ca99bae3be:dfb90c86-fd1b-4bee-850f-9a476a924ad3])
I0526 01:37:37.306606       1 omap.go:159] ID: 24 Req-ID: pvc-ab638b12-9b6d-49f1-8c8e-58ca99bae3be set omap keys (pool="kube", namespace="", name="csi.volume.dfb90c86-fd1b-4bee-850f-9a476a924ad3"): map[csi.imagename:csi-vol-dfb90c86-fd1b-4bee-850f-9a476a924ad3 csi.volname:pvc-ab638b12-9b6d-49f1-8c8e-58ca99bae3be csi.volume.owner:default])
I0526 01:37:37.306653       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-ab638b12-9b6d-49f1-8c8e-58ca99bae3be generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-dfb90c86-fd1b-4bee-850f-9a476a924ad3) and image name (csi-vol-dfb90c86-fd1b-4bee-850f-9a476a924ad3) for request name (pvc-ab638b12-9b6d-49f1-8c8e-58ca99bae3be)
I0526 01:37:37.306751       1 rbd_util.go:423] ID: 24 Req-ID: pvc-ab638b12-9b6d-49f1-8c8e-58ca99bae3be rbd: create kube/csi-vol-dfb90c86-fd1b-4bee-850f-9a476a924ad3 size 5120M (features: [layering]) using mon 199.204.45.116
I0526 01:37:37.306917       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-ab638b12-9b6d-49f1-8c8e-58ca99bae3be setting image options on kube/csi-vol-dfb90c86-fd1b-4bee-850f-9a476a924ad3
I0526 01:37:37.340456       1 controllerserver.go:763] ID: 24 Req-ID: pvc-ab638b12-9b6d-49f1-8c8e-58ca99bae3be created image kube/csi-vol-dfb90c86-fd1b-4bee-850f-9a476a924ad3 backed for request name pvc-ab638b12-9b6d-49f1-8c8e-58ca99bae3be
I0526 01:37:37.373074       1 omap.go:159] ID: 24 Req-ID: pvc-ab638b12-9b6d-49f1-8c8e-58ca99bae3be set omap keys (pool="kube", namespace="", name="csi.volume.dfb90c86-fd1b-4bee-850f-9a476a924ad3"): map[csi.imageid:37edc11a971a])
I0526 01:37:37.472081       1 utils.go:205] ID: 24 Req-ID: pvc-ab638b12-9b6d-49f1-8c8e-58ca99bae3be GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-dfb90c86-fd1b-4bee-850f-9a476a924ad3","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-dfb90c86-fd1b-4bee-850f-9a476a924ad3"}}
I0526 01:37:58.788088       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0526 01:37:58.788125       1 utils.go:199] ID: 25 GRPC request: {}
I0526 01:37:58.788138       1 utils.go:205] ID: 25 GRPC response: {}