I0408 10:52:37.166528       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0408 10:52:37.166626       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0408 10:52:37.166640       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0408 10:52:37.166644       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0408 10:52:37.166648       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0408 10:52:37.166651       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0408 10:52:37.166657       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0408 10:52:37.166661       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0408 10:52:37.166664       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0408 10:52:37.166667       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0408 10:52:37.166973       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0408 10:52:37.167010       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0408 10:52:40.918634       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0408 10:52:40.920134       1 utils.go:199] ID: 1 GRPC request: {}
I0408 10:52:40.920204       1 utils.go:205] ID: 1 GRPC response: {}
I0408 10:52:40.923910       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0408 10:52:40.923999       1 utils.go:199] ID: 2 GRPC request: {}
I0408 10:52:40.924014       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0408 10:52:40.924070       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0408 10:52:40.925578       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0408 10:52:40.925613       1 utils.go:199] ID: 3 GRPC request: {}
I0408 10:52:40.925622       1 utils.go:205] ID: 3 GRPC response: {}
I0408 10:52:40.926236       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0408 10:52:40.926385       1 utils.go:199] ID: 4 GRPC request: {}
I0408 10:52:40.929820       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0408 10:52:40.932231       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0408 10:52:40.932328       1 utils.go:199] ID: 5 GRPC request: {}
I0408 10:52:40.932345       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0408 10:52:40.932504       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}}}]}
I0408 10:52:42.438538       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0408 10:52:42.438614       1 utils.go:199] ID: 6 GRPC request: {}
I0408 10:52:42.438651       1 utils.go:205] ID: 6 GRPC response: {}
I0408 10:52:42.440573       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0408 10:52:42.440706       1 utils.go:199] ID: 7 GRPC request: {}
I0408 10:52:42.440728       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0408 10:52:42.440815       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0408 10:52:42.443053       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0408 10:52:42.443114       1 utils.go:199] ID: 8 GRPC request: {}
I0408 10:52:42.443145       1 utils.go:205] ID: 8 GRPC response: {}
I0408 10:52:42.444318       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0408 10:52:42.444350       1 utils.go:199] ID: 9 GRPC request: {}
I0408 10:52:42.444779       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0408 10:52:42.445497       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0408 10:52:42.445517       1 utils.go:199] ID: 10 GRPC request: {}
I0408 10:52:42.445552       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0408 10:52:42.445650       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}}}]}
I0408 10:52:42.448353       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0408 10:52:42.448400       1 utils.go:199] ID: 11 GRPC request: {}
I0408 10:52:42.448412       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0408 10:52:42.448526       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}}}]}
I0408 10:52:42.448992       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0408 10:52:42.449013       1 utils.go:199] ID: 12 GRPC request: {}
I0408 10:52:42.449042       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0408 10:52:42.449134       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}}}]}
I0408 10:52:47.144867       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0408 10:52:47.144929       1 utils.go:199] ID: 13 GRPC request: {}
I0408 10:52:47.144939       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0408 10:52:47.144967       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0408 10:52:47.149413       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0408 10:52:47.149472       1 utils.go:199] ID: 14 GRPC request: {}
I0408 10:52:47.149492       1 utils.go:205] ID: 14 GRPC response: {}
I0408 10:52:47.150025       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0408 10:52:47.150041       1 utils.go:199] ID: 15 GRPC request: {}
I0408 10:52:47.150061       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0408 10:52:47.150154       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}}}]}
I0408 10:52:48.743331       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0408 10:52:48.743379       1 utils.go:199] ID: 16 GRPC request: {}
I0408 10:52:48.743401       1 utils.go:205] ID: 16 GRPC response: {}
I0408 10:52:48.745229       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0408 10:52:48.745249       1 utils.go:199] ID: 17 GRPC request: {}
I0408 10:52:48.745257       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0408 10:52:48.745348       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0408 10:52:48.747472       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0408 10:52:48.747507       1 utils.go:199] ID: 18 GRPC request: {}
I0408 10:52:48.747617       1 utils.go:205] ID: 18 GRPC response: {}
I0408 10:52:48.748121       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0408 10:52:48.748141       1 utils.go:199] ID: 19 GRPC request: {}
I0408 10:52:48.748226       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0408 10:52:48.748839       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0408 10:52:48.748904       1 utils.go:199] ID: 20 GRPC request: {}
I0408 10:52:48.748932       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0408 10:52:48.749024       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}}}]}
I0408 10:53:48.994228       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0408 10:53:48.994277       1 utils.go:199] ID: 21 GRPC request: {}
I0408 10:53:48.994296       1 utils.go:205] ID: 21 GRPC response: {}
I0408 10:54:48.952288       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0408 10:54:48.952329       1 utils.go:199] ID: 22 GRPC request: {}
I0408 10:54:48.952361       1 utils.go:205] ID: 22 GRPC response: {}
I0408 10:55:48.944253       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0408 10:55:48.944304       1 utils.go:199] ID: 23 GRPC request: {}
I0408 10:55:48.944359       1 utils.go:205] ID: 23 GRPC response: {}
I0408 10:55:55.150494       1 utils.go:198] ID: 24 Req-ID: pvc-b1ac1973-045c-4772-b796-5e4df5cfbf26 GRPC call: /csi.v1.Controller/CreateVolume
I0408 10:55:55.151450       1 utils.go:199] ID: 24 Req-ID: pvc-b1ac1973-045c-4772-b796-5e4df5cfbf26 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-b1ac1973-045c-4772-b796-5e4df5cfbf26","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-b1ac1973-045c-4772-b796-5e4df5cfbf26","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}}]}
I0408 10:55:55.151933       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-b1ac1973-045c-4772-b796-5e4df5cfbf26 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0408 10:55:55.170825       1 omap.go:80] ID: 24 Req-ID: pvc-b1ac1973-045c-4772-b796-5e4df5cfbf26 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0408 10:55:55.195852       1 omap.go:159] ID: 24 Req-ID: pvc-b1ac1973-045c-4772-b796-5e4df5cfbf26 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-b1ac1973-045c-4772-b796-5e4df5cfbf26:393e7845-5167-4c55-9917-7a803836c021])
I0408 10:55:55.206101       1 omap.go:159] ID: 24 Req-ID: pvc-b1ac1973-045c-4772-b796-5e4df5cfbf26 set omap keys (pool="kube", namespace="", name="csi.volume.393e7845-5167-4c55-9917-7a803836c021"): map[csi.imagename:csi-vol-393e7845-5167-4c55-9917-7a803836c021 csi.volname:pvc-b1ac1973-045c-4772-b796-5e4df5cfbf26 csi.volume.owner:default])
I0408 10:55:55.206148       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-b1ac1973-045c-4772-b796-5e4df5cfbf26 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-393e7845-5167-4c55-9917-7a803836c021) and image name (csi-vol-393e7845-5167-4c55-9917-7a803836c021) for request name (pvc-b1ac1973-045c-4772-b796-5e4df5cfbf26)
I0408 10:55:55.206242       1 rbd_util.go:423] ID: 24 Req-ID: pvc-b1ac1973-045c-4772-b796-5e4df5cfbf26 rbd: create kube/csi-vol-393e7845-5167-4c55-9917-7a803836c021 size 5120M (features: [layering]) using mon 199.19.213.31
I0408 10:55:55.206297       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-b1ac1973-045c-4772-b796-5e4df5cfbf26 setting image options on kube/csi-vol-393e7845-5167-4c55-9917-7a803836c021
I0408 10:55:57.158138       1 controllerserver.go:763] ID: 24 Req-ID: pvc-b1ac1973-045c-4772-b796-5e4df5cfbf26 created image kube/csi-vol-393e7845-5167-4c55-9917-7a803836c021 backed for request name pvc-b1ac1973-045c-4772-b796-5e4df5cfbf26
I0408 10:55:57.204574       1 omap.go:159] ID: 24 Req-ID: pvc-b1ac1973-045c-4772-b796-5e4df5cfbf26 set omap keys (pool="kube", namespace="", name="csi.volume.393e7845-5167-4c55-9917-7a803836c021"): map[csi.imageid:37d7ac7ceab0])
I0408 10:55:57.320039       1 utils.go:205] ID: 24 Req-ID: pvc-b1ac1973-045c-4772-b796-5e4df5cfbf26 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-393e7845-5167-4c55-9917-7a803836c021","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-393e7845-5167-4c55-9917-7a803836c021"}}
I0408 10:56:48.954809       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0408 10:56:48.954861       1 utils.go:199] ID: 25 GRPC request: {}
I0408 10:56:48.954886       1 utils.go:205] ID: 25 GRPC response: {}