I0417 00:37:42.873626       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0417 00:37:42.873735       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0417 00:37:42.873746       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0417 00:37:42.873749       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0417 00:37:42.873752       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0417 00:37:42.873754       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0417 00:37:42.873758       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0417 00:37:42.873799       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0417 00:37:42.873801       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0417 00:37:42.873804       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0417 00:37:42.874592       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0417 00:37:42.874616       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0417 00:37:50.077156       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0417 00:37:50.078546       1 utils.go:199] ID: 1 GRPC request: {}
I0417 00:37:50.078641       1 utils.go:205] ID: 1 GRPC response: {}
I0417 00:37:50.084638       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0417 00:37:50.084823       1 utils.go:199] ID: 2 GRPC request: {}
I0417 00:37:50.084864       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0417 00:37:50.084951       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0417 00:37:50.086777       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0417 00:37:50.086885       1 utils.go:199] ID: 3 GRPC request: {}
I0417 00:37:50.086910       1 utils.go:205] ID: 3 GRPC response: {}
I0417 00:37:50.087423       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0417 00:37:50.087478       1 utils.go:199] ID: 4 GRPC request: {}
I0417 00:37:50.087618       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0417 00:37:50.088503       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0417 00:37:50.088642       1 utils.go:199] ID: 5 GRPC request: {}
I0417 00:37:50.088683       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0417 00:37:50.088864       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}}}]}
I0417 00:37:59.648456       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0417 00:37:59.648572       1 utils.go:199] ID: 6 GRPC request: {}
I0417 00:37:59.648643       1 utils.go:205] ID: 6 GRPC response: {}
I0417 00:37:59.651536       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0417 00:37:59.651570       1 utils.go:199] ID: 7 GRPC request: {}
I0417 00:37:59.651576       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0417 00:37:59.651619       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0417 00:37:59.653881       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0417 00:37:59.653903       1 utils.go:199] ID: 8 GRPC request: {}
I0417 00:37:59.653918       1 utils.go:205] ID: 8 GRPC response: {}
I0417 00:37:59.654550       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0417 00:37:59.654574       1 utils.go:199] ID: 9 GRPC request: {}
I0417 00:37:59.654735       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0417 00:37:59.655375       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0417 00:37:59.655409       1 utils.go:199] ID: 10 GRPC request: {}
I0417 00:37:59.655430       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0417 00:37:59.655588       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}}}]}
I0417 00:37:59.656422       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0417 00:37:59.656447       1 utils.go:199] ID: 11 GRPC request: {}
I0417 00:37:59.656465       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0417 00:37:59.656570       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}}}]}
I0417 00:37:59.657180       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0417 00:37:59.657234       1 utils.go:199] ID: 12 GRPC request: {}
I0417 00:37:59.657250       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0417 00:37:59.657377       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}}}]}
I0417 00:38:02.829723       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0417 00:38:02.829775       1 utils.go:199] ID: 13 GRPC request: {}
I0417 00:38:02.829784       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0417 00:38:02.829839       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0417 00:38:02.832818       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0417 00:38:02.832853       1 utils.go:199] ID: 14 GRPC request: {}
I0417 00:38:02.832872       1 utils.go:205] ID: 14 GRPC response: {}
I0417 00:38:02.833225       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0417 00:38:02.833251       1 utils.go:199] ID: 15 GRPC request: {}
I0417 00:38:02.833259       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0417 00:38:02.833372       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}}}]}
I0417 00:38:04.906684       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0417 00:38:04.906751       1 utils.go:199] ID: 16 GRPC request: {}
I0417 00:38:04.906767       1 utils.go:205] ID: 16 GRPC response: {}
I0417 00:38:04.909704       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0417 00:38:04.909754       1 utils.go:199] ID: 17 GRPC request: {}
I0417 00:38:04.909763       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0417 00:38:04.909837       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0417 00:38:04.911984       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0417 00:38:04.912007       1 utils.go:199] ID: 18 GRPC request: {}
I0417 00:38:04.912192       1 utils.go:205] ID: 18 GRPC response: {}
I0417 00:38:04.912719       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0417 00:38:04.912752       1 utils.go:199] ID: 19 GRPC request: {}
I0417 00:38:04.912832       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0417 00:38:04.913419       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0417 00:38:04.913436       1 utils.go:199] ID: 20 GRPC request: {}
I0417 00:38:04.913444       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0417 00:38:04.913506       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}}}]}
I0417 00:39:06.021706       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0417 00:39:06.021942       1 utils.go:199] ID: 21 GRPC request: {}
I0417 00:39:06.022056       1 utils.go:205] ID: 21 GRPC response: {}
I0417 00:40:05.987737       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0417 00:40:05.988079       1 utils.go:199] ID: 22 GRPC request: {}
I0417 00:40:05.988198       1 utils.go:205] ID: 22 GRPC response: {}
I0417 00:41:03.123653       1 utils.go:198] ID: 23 Req-ID: pvc-54b1ed2b-6981-4ed0-9eca-b4688167d0cf GRPC call: /csi.v1.Controller/CreateVolume
I0417 00:41:03.124281       1 utils.go:199] ID: 23 Req-ID: pvc-54b1ed2b-6981-4ed0-9eca-b4688167d0cf GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-54b1ed2b-6981-4ed0-9eca-b4688167d0cf","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-54b1ed2b-6981-4ed0-9eca-b4688167d0cf","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}}]}
I0417 00:41:03.124621       1 rbd_util.go:1315] ID: 23 Req-ID: pvc-54b1ed2b-6981-4ed0-9eca-b4688167d0cf setting disableInUseChecks: false image features: [layering] mounter: rbd
E0417 00:41:03.140496       1 omap.go:80] ID: 23 Req-ID: pvc-54b1ed2b-6981-4ed0-9eca-b4688167d0cf omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0417 00:41:03.154657       1 omap.go:159] ID: 23 Req-ID: pvc-54b1ed2b-6981-4ed0-9eca-b4688167d0cf set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-54b1ed2b-6981-4ed0-9eca-b4688167d0cf:8c1b063e-850c-46da-8e8c-d3b770295a7c])
I0417 00:41:03.160675       1 omap.go:159] ID: 23 Req-ID: pvc-54b1ed2b-6981-4ed0-9eca-b4688167d0cf set omap keys (pool="kube", namespace="", name="csi.volume.8c1b063e-850c-46da-8e8c-d3b770295a7c"): map[csi.imagename:csi-vol-8c1b063e-850c-46da-8e8c-d3b770295a7c csi.volname:pvc-54b1ed2b-6981-4ed0-9eca-b4688167d0cf csi.volume.owner:default])
I0417 00:41:03.160727       1 rbd_journal.go:491] ID: 23 Req-ID: pvc-54b1ed2b-6981-4ed0-9eca-b4688167d0cf generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-8c1b063e-850c-46da-8e8c-d3b770295a7c) and image name (csi-vol-8c1b063e-850c-46da-8e8c-d3b770295a7c) for request name (pvc-54b1ed2b-6981-4ed0-9eca-b4688167d0cf)
I0417 00:41:03.160813       1 rbd_util.go:423] ID: 23 Req-ID: pvc-54b1ed2b-6981-4ed0-9eca-b4688167d0cf rbd: create kube/csi-vol-8c1b063e-850c-46da-8e8c-d3b770295a7c size 5120M (features: [layering]) using mon 199.204.45.25
I0417 00:41:03.160930       1 rbd_util.go:1563] ID: 23 Req-ID: pvc-54b1ed2b-6981-4ed0-9eca-b4688167d0cf setting image options on kube/csi-vol-8c1b063e-850c-46da-8e8c-d3b770295a7c
I0417 00:41:04.519243       1 controllerserver.go:763] ID: 23 Req-ID: pvc-54b1ed2b-6981-4ed0-9eca-b4688167d0cf created image kube/csi-vol-8c1b063e-850c-46da-8e8c-d3b770295a7c backed for request name pvc-54b1ed2b-6981-4ed0-9eca-b4688167d0cf
I0417 00:41:04.560084       1 omap.go:159] ID: 23 Req-ID: pvc-54b1ed2b-6981-4ed0-9eca-b4688167d0cf set omap keys (pool="kube", namespace="", name="csi.volume.8c1b063e-850c-46da-8e8c-d3b770295a7c"): map[csi.imageid:37d9bfceecfb])
I0417 00:41:04.716531       1 utils.go:205] ID: 23 Req-ID: pvc-54b1ed2b-6981-4ed0-9eca-b4688167d0cf GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-8c1b063e-850c-46da-8e8c-d3b770295a7c","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-8c1b063e-850c-46da-8e8c-d3b770295a7c"}}
I0417 00:41:05.982618       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0417 00:41:05.982758       1 utils.go:199] ID: 24 GRPC request: {}
I0417 00:41:05.982781       1 utils.go:205] ID: 24 GRPC response: {}