I0918 15:25:45.376408       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0918 15:25:45.376595       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0918 15:25:45.376623       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0918 15:25:45.376631       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0918 15:25:45.376637       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0918 15:25:45.376642       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0918 15:25:45.376648       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0918 15:25:45.376656       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0918 15:25:45.376659       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0918 15:25:45.376664       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0918 15:25:45.377064       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0918 15:25:45.377081       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0918 15:25:48.656411       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0918 15:25:48.663390       1 utils.go:199] ID: 1 GRPC request: {}
I0918 15:25:48.663460       1 utils.go:205] ID: 1 GRPC response: {}
I0918 15:25:48.668406       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0918 15:25:48.668551       1 utils.go:199] ID: 2 GRPC request: {}
I0918 15:25:48.668569       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0918 15:25:48.668662       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0918 15:25:48.671364       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0918 15:25:48.671399       1 utils.go:199] ID: 3 GRPC request: {}
I0918 15:25:48.671414       1 utils.go:205] ID: 3 GRPC response: {}
I0918 15:25:48.671998       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0918 15:25:48.672073       1 utils.go:199] ID: 4 GRPC request: {}
I0918 15:25:48.675275       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0918 15:25:48.677045       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0918 15:25:48.677138       1 utils.go:199] ID: 5 GRPC request: {}
I0918 15:25:48.677153       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0918 15:25:48.677297       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}}}]}
I0918 15:25:51.107001       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0918 15:25:51.107053       1 utils.go:199] ID: 6 GRPC request: {}
I0918 15:25:51.107079       1 utils.go:205] ID: 6 GRPC response: {}
I0918 15:25:51.109550       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0918 15:25:51.109569       1 utils.go:199] ID: 7 GRPC request: {}
I0918 15:25:51.109578       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0918 15:25:51.109609       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0918 15:25:51.111497       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0918 15:25:51.111518       1 utils.go:199] ID: 8 GRPC request: {}
I0918 15:25:51.111531       1 utils.go:205] ID: 8 GRPC response: {}
I0918 15:25:51.111948       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0918 15:25:51.111995       1 utils.go:199] ID: 9 GRPC request: {}
I0918 15:25:51.112162       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0918 15:25:51.112931       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0918 15:25:51.112954       1 utils.go:199] ID: 10 GRPC request: {}
I0918 15:25:51.112965       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0918 15:25:51.113059       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}}}]}
I0918 15:25:51.113686       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0918 15:25:51.113734       1 utils.go:199] ID: 11 GRPC request: {}
I0918 15:25:51.113756       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0918 15:25:51.113903       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}}}]}
I0918 15:25:51.114331       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0918 15:25:51.114347       1 utils.go:199] ID: 12 GRPC request: {}
I0918 15:25:51.114353       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0918 15:25:51.114412       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}}}]}
I0918 15:25:53.213657       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0918 15:25:53.213737       1 utils.go:199] ID: 13 GRPC request: {}
I0918 15:25:53.213758       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0918 15:25:53.213815       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0918 15:25:53.216714       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0918 15:25:53.216798       1 utils.go:199] ID: 14 GRPC request: {}
I0918 15:25:53.216833       1 utils.go:205] ID: 14 GRPC response: {}
I0918 15:25:53.217283       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0918 15:25:53.217331       1 utils.go:199] ID: 15 GRPC request: {}
I0918 15:25:53.217352       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0918 15:25:53.217444       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}}}]}
I0918 15:25:54.752620       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0918 15:25:54.752663       1 utils.go:199] ID: 16 GRPC request: {}
I0918 15:25:54.752680       1 utils.go:205] ID: 16 GRPC response: {}
I0918 15:25:54.757151       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0918 15:25:54.757192       1 utils.go:199] ID: 17 GRPC request: {}
I0918 15:25:54.757212       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0918 15:25:54.757245       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0918 15:25:54.759439       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0918 15:25:54.759476       1 utils.go:199] ID: 18 GRPC request: {}
I0918 15:25:54.759496       1 utils.go:205] ID: 18 GRPC response: {}
I0918 15:25:54.759930       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0918 15:25:54.760008       1 utils.go:199] ID: 19 GRPC request: {}
I0918 15:25:54.760151       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0918 15:25:54.760989       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0918 15:25:54.761014       1 utils.go:199] ID: 20 GRPC request: {}
I0918 15:25:54.761022       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0918 15:25:54.761148       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}}}]}
I0918 15:26:55.067600       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0918 15:26:55.067660       1 utils.go:199] ID: 21 GRPC request: {}
I0918 15:26:55.067682       1 utils.go:205] ID: 21 GRPC response: {}
I0918 15:27:55.008555       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0918 15:27:55.008616       1 utils.go:199] ID: 22 GRPC request: {}
I0918 15:27:55.008637       1 utils.go:205] ID: 22 GRPC response: {}
I0918 15:28:55.007905       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0918 15:28:55.007957       1 utils.go:199] ID: 23 GRPC request: {}
I0918 15:28:55.007975       1 utils.go:205] ID: 23 GRPC response: {}
I0918 15:29:55.018644       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0918 15:29:55.018743       1 utils.go:199] ID: 24 GRPC request: {}
I0918 15:29:55.018767       1 utils.go:205] ID: 24 GRPC response: {}
I0918 15:30:25.975898       1 utils.go:198] ID: 25 Req-ID: pvc-bcb0b7ae-dd36-4b81-9a4b-3e66fb91286d GRPC call: /csi.v1.Controller/CreateVolume
I0918 15:30:25.976362       1 utils.go:199] ID: 25 Req-ID: pvc-bcb0b7ae-dd36-4b81-9a4b-3e66fb91286d GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-bcb0b7ae-dd36-4b81-9a4b-3e66fb91286d","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-bcb0b7ae-dd36-4b81-9a4b-3e66fb91286d","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}}]}
I0918 15:30:25.976675       1 rbd_util.go:1315] ID: 25 Req-ID: pvc-bcb0b7ae-dd36-4b81-9a4b-3e66fb91286d setting disableInUseChecks: false image features: [layering] mounter: rbd
E0918 15:30:25.997247       1 omap.go:80] ID: 25 Req-ID: pvc-bcb0b7ae-dd36-4b81-9a4b-3e66fb91286d omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0918 15:30:26.011241       1 omap.go:159] ID: 25 Req-ID: pvc-bcb0b7ae-dd36-4b81-9a4b-3e66fb91286d set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-bcb0b7ae-dd36-4b81-9a4b-3e66fb91286d:54f04f56-7e38-4a85-a9e0-35d9bb1ec136])
I0918 15:30:26.017714       1 omap.go:159] ID: 25 Req-ID: pvc-bcb0b7ae-dd36-4b81-9a4b-3e66fb91286d set omap keys (pool="kube", namespace="", name="csi.volume.54f04f56-7e38-4a85-a9e0-35d9bb1ec136"): map[csi.imagename:csi-vol-54f04f56-7e38-4a85-a9e0-35d9bb1ec136 csi.volname:pvc-bcb0b7ae-dd36-4b81-9a4b-3e66fb91286d csi.volume.owner:default])
I0918 15:30:26.017749       1 rbd_journal.go:491] ID: 25 Req-ID: pvc-bcb0b7ae-dd36-4b81-9a4b-3e66fb91286d generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-54f04f56-7e38-4a85-a9e0-35d9bb1ec136) and image name (csi-vol-54f04f56-7e38-4a85-a9e0-35d9bb1ec136) for request name (pvc-bcb0b7ae-dd36-4b81-9a4b-3e66fb91286d)
I0918 15:30:26.017920       1 rbd_util.go:423] ID: 25 Req-ID: pvc-bcb0b7ae-dd36-4b81-9a4b-3e66fb91286d rbd: create kube/csi-vol-54f04f56-7e38-4a85-a9e0-35d9bb1ec136 size 5120M (features: [layering]) using mon 162.253.55.27
I0918 15:30:26.018027       1 rbd_util.go:1563] ID: 25 Req-ID: pvc-bcb0b7ae-dd36-4b81-9a4b-3e66fb91286d setting image options on kube/csi-vol-54f04f56-7e38-4a85-a9e0-35d9bb1ec136
I0918 15:30:26.058655       1 controllerserver.go:763] ID: 25 Req-ID: pvc-bcb0b7ae-dd36-4b81-9a4b-3e66fb91286d created image kube/csi-vol-54f04f56-7e38-4a85-a9e0-35d9bb1ec136 backed for request name pvc-bcb0b7ae-dd36-4b81-9a4b-3e66fb91286d
I0918 15:30:26.093324       1 omap.go:159] ID: 25 Req-ID: pvc-bcb0b7ae-dd36-4b81-9a4b-3e66fb91286d set omap keys (pool="kube", namespace="", name="csi.volume.54f04f56-7e38-4a85-a9e0-35d9bb1ec136"): map[csi.imageid:37f47e1e4267])
I0918 15:30:26.217021       1 utils.go:205] ID: 25 Req-ID: pvc-bcb0b7ae-dd36-4b81-9a4b-3e66fb91286d GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-54f04f56-7e38-4a85-a9e0-35d9bb1ec136","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-54f04f56-7e38-4a85-a9e0-35d9bb1ec136"}}
I0918 15:30:55.007908       1 utils.go:198] ID: 26 GRPC call: /csi.v1.Identity/Probe
I0918 15:30:55.007967       1 utils.go:199] ID: 26 GRPC request: {}
I0918 15:30:55.007997       1 utils.go:205] ID: 26 GRPC response: {}