I0420 12:04:00.992918       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0420 12:04:00.993628       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0420 12:04:00.993690       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0420 12:04:00.993712       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0420 12:04:00.993726       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0420 12:04:00.993755       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0420 12:04:00.993782       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0420 12:04:00.993857       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0420 12:04:00.993885       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0420 12:04:00.993919       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0420 12:04:00.994618       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0420 12:04:00.994743       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0420 12:04:03.369030       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0420 12:04:03.370460       1 utils.go:199] ID: 1 GRPC request: {}
I0420 12:04:03.370503       1 utils.go:205] ID: 1 GRPC response: {}
I0420 12:04:03.372617       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0420 12:04:03.372778       1 utils.go:199] ID: 2 GRPC request: {}
I0420 12:04:03.372808       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0420 12:04:03.372895       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0420 12:04:03.374585       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0420 12:04:03.374727       1 utils.go:199] ID: 3 GRPC request: {}
I0420 12:04:03.374750       1 utils.go:205] ID: 3 GRPC response: {}
I0420 12:04:03.375352       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0420 12:04:03.375454       1 utils.go:199] ID: 4 GRPC request: {}
I0420 12:04:03.375625       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0420 12:04:03.377220       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0420 12:04:03.377313       1 utils.go:199] ID: 5 GRPC request: {}
I0420 12:04:03.377378       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0420 12:04:03.377547       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}}}]}
I0420 12:04:04.404998       1 utils.go:198] ID: 6 Req-ID: pvc-9d77df0e-291a-413a-af61-bcf62bdb1575 GRPC call: /csi.v1.Controller/CreateVolume
I0420 12:04:04.405594       1 utils.go:199] ID: 6 Req-ID: pvc-9d77df0e-291a-413a-af61-bcf62bdb1575 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-9d77df0e-291a-413a-af61-bcf62bdb1575","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-9d77df0e-291a-413a-af61-bcf62bdb1575","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}}]}
I0420 12:04:04.406609       1 rbd_util.go:1315] ID: 6 Req-ID: pvc-9d77df0e-291a-413a-af61-bcf62bdb1575 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0420 12:04:04.437927       1 omap.go:80] ID: 6 Req-ID: pvc-9d77df0e-291a-413a-af61-bcf62bdb1575 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0420 12:04:04.466655       1 omap.go:159] ID: 6 Req-ID: pvc-9d77df0e-291a-413a-af61-bcf62bdb1575 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-9d77df0e-291a-413a-af61-bcf62bdb1575:92298dde-cfed-4b7e-9326-e468c921df74])
I0420 12:04:04.473639       1 omap.go:159] ID: 6 Req-ID: pvc-9d77df0e-291a-413a-af61-bcf62bdb1575 set omap keys (pool="kube", namespace="", name="csi.volume.92298dde-cfed-4b7e-9326-e468c921df74"): map[csi.imagename:csi-vol-92298dde-cfed-4b7e-9326-e468c921df74 csi.volname:pvc-9d77df0e-291a-413a-af61-bcf62bdb1575 csi.volume.owner:default])
I0420 12:04:04.473680       1 rbd_journal.go:491] ID: 6 Req-ID: pvc-9d77df0e-291a-413a-af61-bcf62bdb1575 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-92298dde-cfed-4b7e-9326-e468c921df74) and image name (csi-vol-92298dde-cfed-4b7e-9326-e468c921df74) for request name (pvc-9d77df0e-291a-413a-af61-bcf62bdb1575)
I0420 12:04:04.473783       1 rbd_util.go:423] ID: 6 Req-ID: pvc-9d77df0e-291a-413a-af61-bcf62bdb1575 rbd: create kube/csi-vol-92298dde-cfed-4b7e-9326-e468c921df74 size 5120M (features: [layering]) using mon 199.19.213.134
I0420 12:04:04.473827       1 rbd_util.go:1563] ID: 6 Req-ID: pvc-9d77df0e-291a-413a-af61-bcf62bdb1575 setting image options on kube/csi-vol-92298dde-cfed-4b7e-9326-e468c921df74
I0420 12:04:04.552721       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/Probe
I0420 12:04:04.552777       1 utils.go:199] ID: 7 GRPC request: {}
I0420 12:04:04.552803       1 utils.go:205] ID: 7 GRPC response: {}
I0420 12:04:04.556041       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/GetPluginInfo
I0420 12:04:04.556102       1 utils.go:199] ID: 8 GRPC request: {}
I0420 12:04:04.556131       1 identityserver-default.go:40] ID: 8 Using default GetPluginInfo
I0420 12:04:04.556178       1 utils.go:205] ID: 8 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0420 12:04:04.559218       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/Probe
I0420 12:04:04.559268       1 utils.go:199] ID: 9 GRPC request: {}
I0420 12:04:04.559309       1 utils.go:205] ID: 9 GRPC response: {}
I0420 12:04:04.560054       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0420 12:04:04.560109       1 utils.go:199] ID: 10 GRPC request: {}
I0420 12:04:04.560227       1 utils.go:205] ID: 10 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0420 12:04:04.562264       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0420 12:04:04.562305       1 utils.go:199] ID: 11 GRPC request: {}
I0420 12:04:04.562316       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0420 12:04:04.562520       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}}}]}
I0420 12:04:04.563168       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0420 12:04:04.563194       1 utils.go:199] ID: 12 GRPC request: {}
I0420 12:04:04.563202       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0420 12:04:04.563485       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}}}]}
I0420 12:04:04.563897       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0420 12:04:04.563952       1 utils.go:199] ID: 13 GRPC request: {}
I0420 12:04:04.563978       1 controllerserver-default.go:42] ID: 13 Using default ControllerGetCapabilities
I0420 12:04:04.564107       1 utils.go:205] ID: 13 GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}}]}
I0420 12:04:07.018045       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/GetPluginInfo
I0420 12:04:07.018102       1 utils.go:199] ID: 14 GRPC request: {}
I0420 12:04:07.018115       1 identityserver-default.go:40] ID: 14 Using default GetPluginInfo
I0420 12:04:07.018240       1 utils.go:205] ID: 14 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0420 12:04:07.021046       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Identity/Probe
I0420 12:04:07.021094       1 utils.go:199] ID: 15 GRPC request: {}
I0420 12:04:07.021108       1 utils.go:205] ID: 15 GRPC response: {}
I0420 12:04:07.021785       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0420 12:04:07.021805       1 utils.go:199] ID: 16 GRPC request: {}
I0420 12:04:07.021812       1 controllerserver-default.go:42] ID: 16 Using default ControllerGetCapabilities
I0420 12:04:07.021924       1 utils.go:205] ID: 16 GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}}]}
I0420 12:04:07.190597       1 controllerserver.go:763] ID: 6 Req-ID: pvc-9d77df0e-291a-413a-af61-bcf62bdb1575 created image kube/csi-vol-92298dde-cfed-4b7e-9326-e468c921df74 backed for request name pvc-9d77df0e-291a-413a-af61-bcf62bdb1575
I0420 12:04:07.818322       1 omap.go:159] ID: 6 Req-ID: pvc-9d77df0e-291a-413a-af61-bcf62bdb1575 set omap keys (pool="kube", namespace="", name="csi.volume.92298dde-cfed-4b7e-9326-e468c921df74"): map[csi.imageid:37b51f2f003e])
I0420 12:04:08.096235       1 utils.go:205] ID: 6 Req-ID: pvc-9d77df0e-291a-413a-af61-bcf62bdb1575 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-92298dde-cfed-4b7e-9326-e468c921df74","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-92298dde-cfed-4b7e-9326-e468c921df74"}}
I0420 12:04:08.963524       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/Probe
I0420 12:04:08.963559       1 utils.go:199] ID: 17 GRPC request: {}
I0420 12:04:08.963576       1 utils.go:205] ID: 17 GRPC response: {}
I0420 12:04:08.965885       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/GetPluginInfo
I0420 12:04:08.965924       1 utils.go:199] ID: 18 GRPC request: {}
I0420 12:04:08.965933       1 identityserver-default.go:40] ID: 18 Using default GetPluginInfo
I0420 12:04:08.965964       1 utils.go:205] ID: 18 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0420 12:04:08.969877       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/Probe
I0420 12:04:08.969925       1 utils.go:199] ID: 19 GRPC request: {}
I0420 12:04:08.969954       1 utils.go:205] ID: 19 GRPC response: {}
I0420 12:04:08.970381       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0420 12:04:08.970432       1 utils.go:199] ID: 20 GRPC request: {}
I0420 12:04:08.970537       1 utils.go:205] ID: 20 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0420 12:04:08.971083       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0420 12:04:08.971105       1 utils.go:199] ID: 21 GRPC request: {}
I0420 12:04:08.971117       1 controllerserver-default.go:42] ID: 21 Using default ControllerGetCapabilities
I0420 12:04:08.971190       1 utils.go:205] ID: 21 GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}}]}