I0526 20:27:32.902777       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0526 20:27:32.902909       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0526 20:27:32.902921       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0526 20:27:32.902927       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0526 20:27:32.902930       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0526 20:27:32.902933       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0526 20:27:32.902936       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0526 20:27:32.902939       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0526 20:27:32.902942       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0526 20:27:32.902944       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0526 20:27:32.903193       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0526 20:27:32.903218       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0526 20:27:38.357767       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0526 20:27:38.358671       1 utils.go:199] ID: 1 GRPC request: {}
I0526 20:27:38.358714       1 utils.go:205] ID: 1 GRPC response: {}
I0526 20:27:38.363143       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0526 20:27:38.363224       1 utils.go:199] ID: 2 GRPC request: {}
I0526 20:27:38.363241       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0526 20:27:38.363288       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0526 20:27:38.364822       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0526 20:27:38.364849       1 utils.go:199] ID: 3 GRPC request: {}
I0526 20:27:38.364861       1 utils.go:205] ID: 3 GRPC response: {}
I0526 20:27:38.365242       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0526 20:27:38.365289       1 utils.go:199] ID: 4 GRPC request: {}
I0526 20:27:38.365430       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0526 20:27:38.366254       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0526 20:27:38.366304       1 utils.go:199] ID: 5 GRPC request: {}
I0526 20:27:38.366319       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0526 20:27:38.366485       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 20:27:40.029394       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0526 20:27:40.029428       1 utils.go:199] ID: 6 GRPC request: {}
I0526 20:27:40.029441       1 utils.go:205] ID: 6 GRPC response: {}
I0526 20:27:40.031679       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0526 20:27:40.031701       1 utils.go:199] ID: 7 GRPC request: {}
I0526 20:27:40.031709       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0526 20:27:40.031731       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0526 20:27:40.034196       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0526 20:27:40.034257       1 utils.go:199] ID: 8 GRPC request: {}
I0526 20:27:40.034286       1 utils.go:205] ID: 8 GRPC response: {}
I0526 20:27:40.034668       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0526 20:27:40.034691       1 utils.go:199] ID: 9 GRPC request: {}
I0526 20:27:40.034788       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0526 20:27:40.035541       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0526 20:27:40.035687       1 utils.go:199] ID: 10 GRPC request: {}
I0526 20:27:40.035714       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0526 20:27:40.035926       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 20:27:40.036585       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0526 20:27:40.036606       1 utils.go:199] ID: 11 GRPC request: {}
I0526 20:27:40.036616       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0526 20:27:40.036691       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 20:27:40.036964       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0526 20:27:40.036976       1 utils.go:199] ID: 12 GRPC request: {}
I0526 20:27:40.036981       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0526 20:27:40.037032       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 20:27:43.037204       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0526 20:27:43.037253       1 utils.go:199] ID: 13 GRPC request: {}
I0526 20:27:43.037259       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0526 20:27:43.037278       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0526 20:27:43.039606       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0526 20:27:43.039664       1 utils.go:199] ID: 14 GRPC request: {}
I0526 20:27:43.039689       1 utils.go:205] ID: 14 GRPC response: {}
I0526 20:27:43.040031       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0526 20:27:43.040062       1 utils.go:199] ID: 15 GRPC request: {}
I0526 20:27:43.040075       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0526 20:27:43.040166       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 20:27:45.775090       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0526 20:27:45.775138       1 utils.go:199] ID: 16 GRPC request: {}
I0526 20:27:45.775184       1 utils.go:205] ID: 16 GRPC response: {}
I0526 20:27:45.777069       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0526 20:27:45.777088       1 utils.go:199] ID: 17 GRPC request: {}
I0526 20:27:45.777098       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0526 20:27:45.777128       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0526 20:27:45.779966       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0526 20:27:45.780024       1 utils.go:199] ID: 18 GRPC request: {}
I0526 20:27:45.780048       1 utils.go:205] ID: 18 GRPC response: {}
I0526 20:27:45.780756       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0526 20:27:45.780782       1 utils.go:199] ID: 19 GRPC request: {}
I0526 20:27:45.780896       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0526 20:27:45.782012       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0526 20:27:45.782070       1 utils.go:199] ID: 20 GRPC request: {}
I0526 20:27:45.782082       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0526 20:27:45.782283       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 20:28:46.117642       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0526 20:28:46.117710       1 utils.go:199] ID: 21 GRPC request: {}
I0526 20:28:46.117927       1 utils.go:205] ID: 21 GRPC response: {}
I0526 20:29:46.137686       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0526 20:29:46.137740       1 utils.go:199] ID: 22 GRPC request: {}
I0526 20:29:46.137765       1 utils.go:205] ID: 22 GRPC response: {}
I0526 20:30:46.126510       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0526 20:30:46.126544       1 utils.go:199] ID: 23 GRPC request: {}
I0526 20:30:46.126557       1 utils.go:205] ID: 23 GRPC response: {}
I0526 20:31:20.112179       1 utils.go:198] ID: 24 Req-ID: pvc-67f61f4b-1b46-4b38-ae95-39e23865b286 GRPC call: /csi.v1.Controller/CreateVolume
I0526 20:31:20.112441       1 utils.go:199] ID: 24 Req-ID: pvc-67f61f4b-1b46-4b38-ae95-39e23865b286 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-67f61f4b-1b46-4b38-ae95-39e23865b286","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-67f61f4b-1b46-4b38-ae95-39e23865b286","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 20:31:20.112639       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-67f61f4b-1b46-4b38-ae95-39e23865b286 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0526 20:31:20.132396       1 omap.go:80] ID: 24 Req-ID: pvc-67f61f4b-1b46-4b38-ae95-39e23865b286 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0526 20:31:20.148696       1 omap.go:159] ID: 24 Req-ID: pvc-67f61f4b-1b46-4b38-ae95-39e23865b286 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-67f61f4b-1b46-4b38-ae95-39e23865b286:301ef95d-204d-4eee-aae9-e55a35df014d])
I0526 20:31:20.157626       1 omap.go:159] ID: 24 Req-ID: pvc-67f61f4b-1b46-4b38-ae95-39e23865b286 set omap keys (pool="kube", namespace="", name="csi.volume.301ef95d-204d-4eee-aae9-e55a35df014d"): map[csi.imagename:csi-vol-301ef95d-204d-4eee-aae9-e55a35df014d csi.volname:pvc-67f61f4b-1b46-4b38-ae95-39e23865b286 csi.volume.owner:default])
I0526 20:31:20.157672       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-67f61f4b-1b46-4b38-ae95-39e23865b286 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-301ef95d-204d-4eee-aae9-e55a35df014d) and image name (csi-vol-301ef95d-204d-4eee-aae9-e55a35df014d) for request name (pvc-67f61f4b-1b46-4b38-ae95-39e23865b286)
I0526 20:31:20.157890       1 rbd_util.go:423] ID: 24 Req-ID: pvc-67f61f4b-1b46-4b38-ae95-39e23865b286 rbd: create kube/csi-vol-301ef95d-204d-4eee-aae9-e55a35df014d size 5120M (features: [layering]) using mon 199.204.45.89
I0526 20:31:20.157974       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-67f61f4b-1b46-4b38-ae95-39e23865b286 setting image options on kube/csi-vol-301ef95d-204d-4eee-aae9-e55a35df014d
I0526 20:31:20.187490       1 controllerserver.go:763] ID: 24 Req-ID: pvc-67f61f4b-1b46-4b38-ae95-39e23865b286 created image kube/csi-vol-301ef95d-204d-4eee-aae9-e55a35df014d backed for request name pvc-67f61f4b-1b46-4b38-ae95-39e23865b286
I0526 20:31:20.223811       1 omap.go:159] ID: 24 Req-ID: pvc-67f61f4b-1b46-4b38-ae95-39e23865b286 set omap keys (pool="kube", namespace="", name="csi.volume.301ef95d-204d-4eee-aae9-e55a35df014d"): map[csi.imageid:37ed4ed61476])
I0526 20:31:20.313402       1 utils.go:205] ID: 24 Req-ID: pvc-67f61f4b-1b46-4b38-ae95-39e23865b286 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-301ef95d-204d-4eee-aae9-e55a35df014d","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-301ef95d-204d-4eee-aae9-e55a35df014d"}}
I0526 20:31:46.083234       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0526 20:31:46.083271       1 utils.go:199] ID: 25 GRPC request: {}
I0526 20:31:46.083284       1 utils.go:205] ID: 25 GRPC response: {}