I0922 02:06:57.876359       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0922 02:06:57.876536       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0922 02:06:57.876962       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0922 02:06:57.876986       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0922 02:06:57.876999       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0922 02:06:57.877012       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0922 02:06:57.877027       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0922 02:06:57.877057       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0922 02:06:57.877075       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0922 02:06:57.877087       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0922 02:06:57.877391       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0922 02:06:57.877395       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0922 02:07:00.946776       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0922 02:07:00.949054       1 utils.go:199] ID: 1 GRPC request: {}
I0922 02:07:00.949186       1 utils.go:205] ID: 1 GRPC response: {}
I0922 02:07:00.954072       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0922 02:07:00.954242       1 utils.go:199] ID: 2 GRPC request: {}
I0922 02:07:00.954305       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0922 02:07:00.954409       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0922 02:07:00.956700       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0922 02:07:00.956760       1 utils.go:199] ID: 3 GRPC request: {}
I0922 02:07:00.956974       1 utils.go:205] ID: 3 GRPC response: {}
I0922 02:07:00.957647       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0922 02:07:00.957948       1 utils.go:199] ID: 4 GRPC request: {}
I0922 02:07:00.958285       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0922 02:07:00.959348       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0922 02:07:00.959476       1 utils.go:199] ID: 5 GRPC request: {}
I0922 02:07:00.959528       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0922 02:07:00.959719       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}}}]}
I0922 02:07:02.587389       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0922 02:07:02.587438       1 utils.go:199] ID: 6 GRPC request: {}
I0922 02:07:02.587479       1 utils.go:205] ID: 6 GRPC response: {}
I0922 02:07:02.591803       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0922 02:07:02.591877       1 utils.go:199] ID: 7 GRPC request: {}
I0922 02:07:02.591891       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0922 02:07:02.591991       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0922 02:07:02.594497       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0922 02:07:02.594538       1 utils.go:199] ID: 8 GRPC request: {}
I0922 02:07:02.594579       1 utils.go:205] ID: 8 GRPC response: {}
I0922 02:07:02.595147       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0922 02:07:02.595181       1 utils.go:199] ID: 9 GRPC request: {}
I0922 02:07:02.595346       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0922 02:07:02.596247       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0922 02:07:02.596278       1 utils.go:199] ID: 10 GRPC request: {}
I0922 02:07:02.596288       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0922 02:07:02.596409       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}}}]}
I0922 02:07:02.597243       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0922 02:07:02.597278       1 utils.go:199] ID: 11 GRPC request: {}
I0922 02:07:02.597292       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0922 02:07:02.597445       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}}}]}
I0922 02:07:02.598064       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0922 02:07:02.598092       1 utils.go:199] ID: 12 GRPC request: {}
I0922 02:07:02.598101       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0922 02:07:02.598207       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}}}]}
I0922 02:07:04.208487       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0922 02:07:04.208531       1 utils.go:199] ID: 13 GRPC request: {}
I0922 02:07:04.208540       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0922 02:07:04.208595       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0922 02:07:04.212053       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0922 02:07:04.212086       1 utils.go:199] ID: 14 GRPC request: {}
I0922 02:07:04.212110       1 utils.go:205] ID: 14 GRPC response: {}
I0922 02:07:04.213811       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0922 02:07:04.213859       1 utils.go:199] ID: 15 GRPC request: {}
I0922 02:07:04.213874       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0922 02:07:04.214027       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}}}]}
I0922 02:07:05.741767       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0922 02:07:05.741818       1 utils.go:199] ID: 16 GRPC request: {}
I0922 02:07:05.741841       1 utils.go:205] ID: 16 GRPC response: {}
I0922 02:07:05.745156       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0922 02:07:05.745208       1 utils.go:199] ID: 17 GRPC request: {}
I0922 02:07:05.745221       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0922 02:07:05.745448       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0922 02:07:05.748137       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0922 02:07:05.748169       1 utils.go:199] ID: 18 GRPC request: {}
I0922 02:07:05.748185       1 utils.go:205] ID: 18 GRPC response: {}
I0922 02:07:05.748771       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0922 02:07:05.748819       1 utils.go:199] ID: 19 GRPC request: {}
I0922 02:07:05.748972       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0922 02:07:05.749854       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0922 02:07:05.749884       1 utils.go:199] ID: 20 GRPC request: {}
I0922 02:07:05.749895       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0922 02:07:05.750150       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}}}]}
I0922 02:08:06.033865       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0922 02:08:06.033911       1 utils.go:199] ID: 21 GRPC request: {}
I0922 02:08:06.033942       1 utils.go:205] ID: 21 GRPC response: {}
I0922 02:09:05.996895       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0922 02:09:05.997515       1 utils.go:199] ID: 22 GRPC request: {}
I0922 02:09:05.997702       1 utils.go:205] ID: 22 GRPC response: {}
I0922 02:10:05.995677       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0922 02:10:05.995729       1 utils.go:199] ID: 23 GRPC request: {}
I0922 02:10:05.995754       1 utils.go:205] ID: 23 GRPC response: {}
I0922 02:11:06.007537       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0922 02:11:06.007599       1 utils.go:199] ID: 24 GRPC request: {}
I0922 02:11:06.007623       1 utils.go:205] ID: 24 GRPC response: {}
I0922 02:11:23.011408       1 utils.go:198] ID: 25 Req-ID: pvc-9078fe79-171a-41c1-9fe7-21aa32649286 GRPC call: /csi.v1.Controller/CreateVolume
I0922 02:11:23.011936       1 utils.go:199] ID: 25 Req-ID: pvc-9078fe79-171a-41c1-9fe7-21aa32649286 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-9078fe79-171a-41c1-9fe7-21aa32649286","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-9078fe79-171a-41c1-9fe7-21aa32649286","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}}]}
I0922 02:11:23.012308       1 rbd_util.go:1315] ID: 25 Req-ID: pvc-9078fe79-171a-41c1-9fe7-21aa32649286 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0922 02:11:23.035837       1 omap.go:80] ID: 25 Req-ID: pvc-9078fe79-171a-41c1-9fe7-21aa32649286 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0922 02:11:23.059610       1 omap.go:159] ID: 25 Req-ID: pvc-9078fe79-171a-41c1-9fe7-21aa32649286 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-9078fe79-171a-41c1-9fe7-21aa32649286:d7c3440f-3bb7-478c-931b-4b2f32eafa2d])
I0922 02:11:23.069206       1 omap.go:159] ID: 25 Req-ID: pvc-9078fe79-171a-41c1-9fe7-21aa32649286 set omap keys (pool="kube", namespace="", name="csi.volume.d7c3440f-3bb7-478c-931b-4b2f32eafa2d"): map[csi.imagename:csi-vol-d7c3440f-3bb7-478c-931b-4b2f32eafa2d csi.volname:pvc-9078fe79-171a-41c1-9fe7-21aa32649286 csi.volume.owner:default])
I0922 02:11:23.069240       1 rbd_journal.go:491] ID: 25 Req-ID: pvc-9078fe79-171a-41c1-9fe7-21aa32649286 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-d7c3440f-3bb7-478c-931b-4b2f32eafa2d) and image name (csi-vol-d7c3440f-3bb7-478c-931b-4b2f32eafa2d) for request name (pvc-9078fe79-171a-41c1-9fe7-21aa32649286)
I0922 02:11:23.069330       1 rbd_util.go:423] ID: 25 Req-ID: pvc-9078fe79-171a-41c1-9fe7-21aa32649286 rbd: create kube/csi-vol-d7c3440f-3bb7-478c-931b-4b2f32eafa2d size 5120M (features: [layering]) using mon 162.253.55.25
I0922 02:11:23.069384       1 rbd_util.go:1563] ID: 25 Req-ID: pvc-9078fe79-171a-41c1-9fe7-21aa32649286 setting image options on kube/csi-vol-d7c3440f-3bb7-478c-931b-4b2f32eafa2d
I0922 02:11:23.132845       1 controllerserver.go:763] ID: 25 Req-ID: pvc-9078fe79-171a-41c1-9fe7-21aa32649286 created image kube/csi-vol-d7c3440f-3bb7-478c-931b-4b2f32eafa2d backed for request name pvc-9078fe79-171a-41c1-9fe7-21aa32649286
I0922 02:11:23.218804       1 omap.go:159] ID: 25 Req-ID: pvc-9078fe79-171a-41c1-9fe7-21aa32649286 set omap keys (pool="kube", namespace="", name="csi.volume.d7c3440f-3bb7-478c-931b-4b2f32eafa2d"): map[csi.imageid:37f47abc2151])
I0922 02:11:23.315238       1 utils.go:205] ID: 25 Req-ID: pvc-9078fe79-171a-41c1-9fe7-21aa32649286 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-d7c3440f-3bb7-478c-931b-4b2f32eafa2d","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-d7c3440f-3bb7-478c-931b-4b2f32eafa2d"}}
I0922 02:12:05.996075       1 utils.go:198] ID: 26 GRPC call: /csi.v1.Identity/Probe
I0922 02:12:05.996400       1 utils.go:199] ID: 26 GRPC request: {}
I0922 02:12:05.996441       1 utils.go:205] ID: 26 GRPC response: {}