I0401 23:29:37.147365       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0401 23:29:37.147523       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0401 23:29:37.147543       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0401 23:29:37.147550       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0401 23:29:37.147556       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0401 23:29:37.147561       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0401 23:29:37.147569       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0401 23:29:37.147574       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0401 23:29:37.147714       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0401 23:29:37.147728       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0401 23:29:37.148582       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0401 23:29:37.148612       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0401 23:29:39.913932       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0401 23:29:39.915921       1 utils.go:199] ID: 1 GRPC request: {}
I0401 23:29:39.916008       1 utils.go:205] ID: 1 GRPC response: {}
I0401 23:29:39.919631       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0401 23:29:39.919734       1 utils.go:199] ID: 2 GRPC request: {}
I0401 23:29:39.919775       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0401 23:29:39.919866       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0401 23:29:39.921379       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0401 23:29:39.921447       1 utils.go:199] ID: 3 GRPC request: {}
I0401 23:29:39.921475       1 utils.go:205] ID: 3 GRPC response: {}
I0401 23:29:39.922020       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0401 23:29:39.922105       1 utils.go:199] ID: 4 GRPC request: {}
I0401 23:29:39.922337       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0401 23:29:39.923259       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0401 23:29:39.923355       1 utils.go:199] ID: 5 GRPC request: {}
I0401 23:29:39.923397       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0401 23:29:39.923573       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}}}]}
I0401 23:29:42.402898       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0401 23:29:42.402963       1 utils.go:199] ID: 6 GRPC request: {}
I0401 23:29:42.402984       1 utils.go:205] ID: 6 GRPC response: {}
I0401 23:29:42.404926       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0401 23:29:42.404946       1 utils.go:199] ID: 7 GRPC request: {}
I0401 23:29:42.404953       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0401 23:29:42.405001       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0401 23:29:42.406670       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0401 23:29:42.406688       1 utils.go:199] ID: 8 GRPC request: {}
I0401 23:29:42.406750       1 utils.go:205] ID: 8 GRPC response: {}
I0401 23:29:42.407165       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0401 23:29:42.407185       1 utils.go:199] ID: 9 GRPC request: {}
I0401 23:29:42.407332       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0401 23:29:42.407900       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0401 23:29:42.407917       1 utils.go:199] ID: 10 GRPC request: {}
I0401 23:29:42.407950       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0401 23:29:42.408040       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}}}]}
I0401 23:29:42.408704       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0401 23:29:42.408719       1 utils.go:199] ID: 11 GRPC request: {}
I0401 23:29:42.408745       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0401 23:29:42.408834       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}}}]}
I0401 23:29:42.409261       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0401 23:29:42.409304       1 utils.go:199] ID: 12 GRPC request: {}
I0401 23:29:42.409316       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0401 23:29:42.409409       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}}}]}
I0401 23:29:43.612370       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0401 23:29:43.612404       1 utils.go:199] ID: 13 GRPC request: {}
I0401 23:29:43.612412       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0401 23:29:43.612436       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0401 23:29:43.615242       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0401 23:29:43.615263       1 utils.go:199] ID: 14 GRPC request: {}
I0401 23:29:43.615276       1 utils.go:205] ID: 14 GRPC response: {}
I0401 23:29:43.615680       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0401 23:29:43.615734       1 utils.go:199] ID: 15 GRPC request: {}
I0401 23:29:43.615763       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0401 23:29:43.615900       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}}}]}
I0401 23:29:44.719631       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0401 23:29:44.719666       1 utils.go:199] ID: 16 GRPC request: {}
I0401 23:29:44.719679       1 utils.go:205] ID: 16 GRPC response: {}
I0401 23:29:44.723118       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0401 23:29:44.723137       1 utils.go:199] ID: 17 GRPC request: {}
I0401 23:29:44.723143       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0401 23:29:44.723160       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0401 23:29:44.725946       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0401 23:29:44.725965       1 utils.go:199] ID: 18 GRPC request: {}
I0401 23:29:44.725975       1 utils.go:205] ID: 18 GRPC response: {}
I0401 23:29:44.726756       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0401 23:29:44.726811       1 utils.go:199] ID: 19 GRPC request: {}
I0401 23:29:44.726937       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0401 23:29:44.727729       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0401 23:29:44.727754       1 utils.go:199] ID: 20 GRPC request: {}
I0401 23:29:44.727762       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0401 23:29:44.727847       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}}}]}
I0401 23:30:45.028278       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0401 23:30:45.028345       1 utils.go:199] ID: 21 GRPC request: {}
I0401 23:30:45.028367       1 utils.go:205] ID: 21 GRPC response: {}
I0401 23:31:44.981057       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0401 23:31:44.981141       1 utils.go:199] ID: 22 GRPC request: {}
I0401 23:31:44.981187       1 utils.go:205] ID: 22 GRPC response: {}
I0401 23:32:44.980012       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0401 23:32:44.980071       1 utils.go:199] ID: 23 GRPC request: {}
I0401 23:32:44.980094       1 utils.go:205] ID: 23 GRPC response: {}
I0401 23:32:47.226663       1 utils.go:198] ID: 24 Req-ID: pvc-449a90b7-6532-49f1-b06e-5f9a08a61c78 GRPC call: /csi.v1.Controller/CreateVolume
I0401 23:32:47.227052       1 utils.go:199] ID: 24 Req-ID: pvc-449a90b7-6532-49f1-b06e-5f9a08a61c78 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-449a90b7-6532-49f1-b06e-5f9a08a61c78","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-449a90b7-6532-49f1-b06e-5f9a08a61c78","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}}]}
I0401 23:32:47.227339       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-449a90b7-6532-49f1-b06e-5f9a08a61c78 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0401 23:32:47.246387       1 omap.go:80] ID: 24 Req-ID: pvc-449a90b7-6532-49f1-b06e-5f9a08a61c78 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0401 23:32:47.271002       1 omap.go:159] ID: 24 Req-ID: pvc-449a90b7-6532-49f1-b06e-5f9a08a61c78 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-449a90b7-6532-49f1-b06e-5f9a08a61c78:b492c91b-855c-4bd4-8e92-8facd73b4c34])
I0401 23:32:47.295105       1 omap.go:159] ID: 24 Req-ID: pvc-449a90b7-6532-49f1-b06e-5f9a08a61c78 set omap keys (pool="kube", namespace="", name="csi.volume.b492c91b-855c-4bd4-8e92-8facd73b4c34"): map[csi.imagename:csi-vol-b492c91b-855c-4bd4-8e92-8facd73b4c34 csi.volname:pvc-449a90b7-6532-49f1-b06e-5f9a08a61c78 csi.volume.owner:default])
I0401 23:32:47.295149       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-449a90b7-6532-49f1-b06e-5f9a08a61c78 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-b492c91b-855c-4bd4-8e92-8facd73b4c34) and image name (csi-vol-b492c91b-855c-4bd4-8e92-8facd73b4c34) for request name (pvc-449a90b7-6532-49f1-b06e-5f9a08a61c78)
I0401 23:32:47.295214       1 rbd_util.go:423] ID: 24 Req-ID: pvc-449a90b7-6532-49f1-b06e-5f9a08a61c78 rbd: create kube/csi-vol-b492c91b-855c-4bd4-8e92-8facd73b4c34 size 5120M (features: [layering]) using mon 199.204.45.74
I0401 23:32:47.295279       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-449a90b7-6532-49f1-b06e-5f9a08a61c78 setting image options on kube/csi-vol-b492c91b-855c-4bd4-8e92-8facd73b4c34
I0401 23:32:49.535711       1 controllerserver.go:763] ID: 24 Req-ID: pvc-449a90b7-6532-49f1-b06e-5f9a08a61c78 created image kube/csi-vol-b492c91b-855c-4bd4-8e92-8facd73b4c34 backed for request name pvc-449a90b7-6532-49f1-b06e-5f9a08a61c78
I0401 23:32:49.651932       1 omap.go:159] ID: 24 Req-ID: pvc-449a90b7-6532-49f1-b06e-5f9a08a61c78 set omap keys (pool="kube", namespace="", name="csi.volume.b492c91b-855c-4bd4-8e92-8facd73b4c34"): map[csi.imageid:37d99ecb716c])
I0401 23:32:49.928213       1 utils.go:205] ID: 24 Req-ID: pvc-449a90b7-6532-49f1-b06e-5f9a08a61c78 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-b492c91b-855c-4bd4-8e92-8facd73b4c34","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-b492c91b-855c-4bd4-8e92-8facd73b4c34"}}
I0401 23:33:44.991922       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0401 23:33:44.992594       1 utils.go:199] ID: 25 GRPC request: {}
I0401 23:33:44.992668       1 utils.go:205] ID: 25 GRPC response: {}