I0515 21:24:24.771453       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0515 21:24:24.771589       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0515 21:24:24.771603       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0515 21:24:24.771608       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0515 21:24:24.771612       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0515 21:24:24.771616       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0515 21:24:24.771621       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0515 21:24:24.771626       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0515 21:24:24.771630       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0515 21:24:24.771634       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0515 21:24:24.772038       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0515 21:24:24.772072       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0515 21:24:27.486693       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0515 21:24:27.489208       1 utils.go:199] ID: 1 GRPC request: {}
I0515 21:24:27.489400       1 utils.go:205] ID: 1 GRPC response: {}
I0515 21:24:27.491628       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0515 21:24:27.491813       1 utils.go:199] ID: 2 GRPC request: {}
I0515 21:24:27.491841       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0515 21:24:27.491968       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0515 21:24:27.493241       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0515 21:24:27.493279       1 utils.go:199] ID: 3 GRPC request: {}
I0515 21:24:27.493298       1 utils.go:205] ID: 3 GRPC response: {}
I0515 21:24:27.493947       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0515 21:24:27.494173       1 utils.go:199] ID: 4 GRPC request: {}
I0515 21:24:27.494463       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0515 21:24:27.496205       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0515 21:24:27.496262       1 utils.go:199] ID: 5 GRPC request: {}
I0515 21:24:27.496272       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0515 21:24:27.496398       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}}}]}
I0515 21:24:30.034336       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0515 21:24:30.034399       1 utils.go:199] ID: 6 GRPC request: {}
I0515 21:24:30.034426       1 utils.go:205] ID: 6 GRPC response: {}
I0515 21:24:30.038520       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0515 21:24:30.038545       1 utils.go:199] ID: 7 GRPC request: {}
I0515 21:24:30.038570       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0515 21:24:30.038597       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0515 21:24:30.040399       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0515 21:24:30.040419       1 utils.go:199] ID: 8 GRPC request: {}
I0515 21:24:30.040476       1 utils.go:205] ID: 8 GRPC response: {}
I0515 21:24:30.041004       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0515 21:24:30.041031       1 utils.go:199] ID: 9 GRPC request: {}
I0515 21:24:30.041151       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0515 21:24:30.041913       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0515 21:24:30.041933       1 utils.go:199] ID: 10 GRPC request: {}
I0515 21:24:30.041956       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0515 21:24:30.042049       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}}}]}
I0515 21:24:30.042560       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0515 21:24:30.042592       1 utils.go:199] ID: 11 GRPC request: {}
I0515 21:24:30.042598       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0515 21:24:30.042664       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}}}]}
I0515 21:24:30.042997       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0515 21:24:30.043030       1 utils.go:199] ID: 12 GRPC request: {}
I0515 21:24:30.043036       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0515 21:24:30.043110       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}}}]}
I0515 21:24:31.297336       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0515 21:24:31.297373       1 utils.go:199] ID: 13 GRPC request: {}
I0515 21:24:31.297394       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0515 21:24:31.297458       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0515 21:24:31.299234       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0515 21:24:31.299254       1 utils.go:199] ID: 14 GRPC request: {}
I0515 21:24:31.299299       1 utils.go:205] ID: 14 GRPC response: {}
I0515 21:24:31.299658       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0515 21:24:31.299677       1 utils.go:199] ID: 15 GRPC request: {}
I0515 21:24:31.299686       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0515 21:24:31.299793       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}}}]}
I0515 21:24:32.796159       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0515 21:24:32.796226       1 utils.go:199] ID: 16 GRPC request: {}
I0515 21:24:32.796268       1 utils.go:205] ID: 16 GRPC response: {}
I0515 21:24:32.799035       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0515 21:24:32.799056       1 utils.go:199] ID: 17 GRPC request: {}
I0515 21:24:32.799062       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0515 21:24:32.799178       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0515 21:24:32.801168       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0515 21:24:32.801235       1 utils.go:199] ID: 18 GRPC request: {}
I0515 21:24:32.801301       1 utils.go:205] ID: 18 GRPC response: {}
I0515 21:24:32.801593       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0515 21:24:32.801659       1 utils.go:199] ID: 19 GRPC request: {}
I0515 21:24:32.801786       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0515 21:24:32.802286       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0515 21:24:32.802370       1 utils.go:199] ID: 20 GRPC request: {}
I0515 21:24:32.802396       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0515 21:24:32.802506       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}}}]}
I0515 21:25:32.991479       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0515 21:25:32.991551       1 utils.go:199] ID: 21 GRPC request: {}
I0515 21:25:32.991578       1 utils.go:205] ID: 21 GRPC response: {}
I0515 21:26:32.993907       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0515 21:26:32.993965       1 utils.go:199] ID: 22 GRPC request: {}
I0515 21:26:32.994042       1 utils.go:205] ID: 22 GRPC response: {}
I0515 21:27:32.990797       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0515 21:27:32.990879       1 utils.go:199] ID: 23 GRPC request: {}
I0515 21:27:32.990953       1 utils.go:205] ID: 23 GRPC response: {}
I0515 21:27:35.924735       1 utils.go:198] ID: 24 Req-ID: pvc-c14ae01a-642f-42a6-bfde-ad003f743ef9 GRPC call: /csi.v1.Controller/CreateVolume
I0515 21:27:35.926203       1 utils.go:199] ID: 24 Req-ID: pvc-c14ae01a-642f-42a6-bfde-ad003f743ef9 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-c14ae01a-642f-42a6-bfde-ad003f743ef9","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-c14ae01a-642f-42a6-bfde-ad003f743ef9","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}}]}
I0515 21:27:35.926856       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-c14ae01a-642f-42a6-bfde-ad003f743ef9 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0515 21:27:35.948127       1 omap.go:80] ID: 24 Req-ID: pvc-c14ae01a-642f-42a6-bfde-ad003f743ef9 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0515 21:27:35.963369       1 omap.go:159] ID: 24 Req-ID: pvc-c14ae01a-642f-42a6-bfde-ad003f743ef9 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-c14ae01a-642f-42a6-bfde-ad003f743ef9:ce16f488-5194-4822-9ec7-014211198609])
I0515 21:27:35.969083       1 omap.go:159] ID: 24 Req-ID: pvc-c14ae01a-642f-42a6-bfde-ad003f743ef9 set omap keys (pool="kube", namespace="", name="csi.volume.ce16f488-5194-4822-9ec7-014211198609"): map[csi.imagename:csi-vol-ce16f488-5194-4822-9ec7-014211198609 csi.volname:pvc-c14ae01a-642f-42a6-bfde-ad003f743ef9 csi.volume.owner:default])
I0515 21:27:35.969192       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-c14ae01a-642f-42a6-bfde-ad003f743ef9 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-ce16f488-5194-4822-9ec7-014211198609) and image name (csi-vol-ce16f488-5194-4822-9ec7-014211198609) for request name (pvc-c14ae01a-642f-42a6-bfde-ad003f743ef9)
I0515 21:27:35.969463       1 rbd_util.go:423] ID: 24 Req-ID: pvc-c14ae01a-642f-42a6-bfde-ad003f743ef9 rbd: create kube/csi-vol-ce16f488-5194-4822-9ec7-014211198609 size 5120M (features: [layering]) using mon 199.204.45.23
I0515 21:27:35.969636       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-c14ae01a-642f-42a6-bfde-ad003f743ef9 setting image options on kube/csi-vol-ce16f488-5194-4822-9ec7-014211198609
I0515 21:27:37.975736       1 controllerserver.go:763] ID: 24 Req-ID: pvc-c14ae01a-642f-42a6-bfde-ad003f743ef9 created image kube/csi-vol-ce16f488-5194-4822-9ec7-014211198609 backed for request name pvc-c14ae01a-642f-42a6-bfde-ad003f743ef9
I0515 21:27:38.009406       1 omap.go:159] ID: 24 Req-ID: pvc-c14ae01a-642f-42a6-bfde-ad003f743ef9 set omap keys (pool="kube", namespace="", name="csi.volume.ce16f488-5194-4822-9ec7-014211198609"): map[csi.imageid:37d87f368775])
I0515 21:27:38.104430       1 utils.go:205] ID: 24 Req-ID: pvc-c14ae01a-642f-42a6-bfde-ad003f743ef9 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-ce16f488-5194-4822-9ec7-014211198609","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-ce16f488-5194-4822-9ec7-014211198609"}}
I0515 21:28:33.005030       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0515 21:28:33.005110       1 utils.go:199] ID: 25 GRPC request: {}
I0515 21:28:33.005149       1 utils.go:205] ID: 25 GRPC response: {}