I0427 12:05:59.053308       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0427 12:05:59.053472       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0427 12:05:59.053493       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0427 12:05:59.053497       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0427 12:05:59.053500       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0427 12:05:59.053503       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0427 12:05:59.053507       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0427 12:05:59.053510       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0427 12:05:59.053512       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0427 12:05:59.053515       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0427 12:05:59.053875       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0427 12:05:59.053955       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0427 12:06:04.824701       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0427 12:06:04.826175       1 utils.go:199] ID: 1 GRPC request: {}
I0427 12:06:04.826242       1 utils.go:205] ID: 1 GRPC response: {}
I0427 12:06:04.830282       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0427 12:06:04.830326       1 utils.go:199] ID: 2 GRPC request: {}
I0427 12:06:04.830341       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0427 12:06:04.830387       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0427 12:06:04.834443       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0427 12:06:04.834938       1 utils.go:199] ID: 3 GRPC request: {}
I0427 12:06:04.835003       1 utils.go:205] ID: 3 GRPC response: {}
I0427 12:06:04.835767       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0427 12:06:04.836018       1 utils.go:199] ID: 4 GRPC request: {}
I0427 12:06:04.836507       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0427 12:06:04.838239       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0427 12:06:04.838447       1 utils.go:199] ID: 5 GRPC request: {}
I0427 12:06:04.838601       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0427 12:06:04.838926       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}}}]}
I0427 12:06:06.019837       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0427 12:06:06.019930       1 utils.go:199] ID: 6 GRPC request: {}
I0427 12:06:06.019968       1 utils.go:205] ID: 6 GRPC response: {}
I0427 12:06:06.022376       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0427 12:06:06.022461       1 utils.go:199] ID: 7 GRPC request: {}
I0427 12:06:06.022477       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0427 12:06:06.022529       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0427 12:06:06.025963       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0427 12:06:06.026083       1 utils.go:199] ID: 8 GRPC request: {}
I0427 12:06:06.026170       1 utils.go:205] ID: 8 GRPC response: {}
I0427 12:06:06.026873       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0427 12:06:06.026902       1 utils.go:199] ID: 9 GRPC request: {}
I0427 12:06:06.027079       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0427 12:06:06.028197       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0427 12:06:06.028306       1 utils.go:199] ID: 10 GRPC request: {}
I0427 12:06:06.028421       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0427 12:06:06.028685       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}}}]}
I0427 12:06:06.029895       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0427 12:06:06.029923       1 utils.go:199] ID: 11 GRPC request: {}
I0427 12:06:06.029932       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0427 12:06:06.030041       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}}}]}
I0427 12:06:06.030727       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0427 12:06:06.030837       1 utils.go:199] ID: 12 GRPC request: {}
I0427 12:06:06.030914       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0427 12:06:06.031097       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}}}]}
I0427 12:06:07.370754       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0427 12:06:07.370812       1 utils.go:199] ID: 13 GRPC request: {}
I0427 12:06:07.370823       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0427 12:06:07.370858       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0427 12:06:07.374879       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0427 12:06:07.374919       1 utils.go:199] ID: 14 GRPC request: {}
I0427 12:06:07.374938       1 utils.go:205] ID: 14 GRPC response: {}
I0427 12:06:07.375754       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0427 12:06:07.375787       1 utils.go:199] ID: 15 GRPC request: {}
I0427 12:06:07.375804       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0427 12:06:07.376156       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}}}]}
I0427 12:06:08.562913       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0427 12:06:08.563105       1 utils.go:199] ID: 16 GRPC request: {}
I0427 12:06:08.563182       1 utils.go:205] ID: 16 GRPC response: {}
I0427 12:06:08.567035       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0427 12:06:08.567182       1 utils.go:199] ID: 17 GRPC request: {}
I0427 12:06:08.567240       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0427 12:06:08.567309       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0427 12:06:08.569966       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0427 12:06:08.569993       1 utils.go:199] ID: 18 GRPC request: {}
I0427 12:06:08.570011       1 utils.go:205] ID: 18 GRPC response: {}
I0427 12:06:08.570482       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0427 12:06:08.570543       1 utils.go:199] ID: 19 GRPC request: {}
I0427 12:06:08.570676       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0427 12:06:08.572470       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0427 12:06:08.572490       1 utils.go:199] ID: 20 GRPC request: {}
I0427 12:06:08.572499       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0427 12:06:08.572575       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}}}]}
I0427 12:07:08.819008       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0427 12:07:08.819175       1 utils.go:199] ID: 21 GRPC request: {}
I0427 12:07:08.819253       1 utils.go:205] ID: 21 GRPC response: {}
I0427 12:08:08.775521       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0427 12:08:08.775614       1 utils.go:199] ID: 22 GRPC request: {}
I0427 12:08:08.775660       1 utils.go:205] ID: 22 GRPC response: {}
I0427 12:09:08.771185       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0427 12:09:08.771247       1 utils.go:199] ID: 23 GRPC request: {}
I0427 12:09:08.771276       1 utils.go:205] ID: 23 GRPC response: {}
I0427 12:09:22.991233       1 utils.go:198] ID: 24 Req-ID: pvc-ebcea6cd-f961-4941-92d4-40f6855d365d GRPC call: /csi.v1.Controller/CreateVolume
I0427 12:09:22.991684       1 utils.go:199] ID: 24 Req-ID: pvc-ebcea6cd-f961-4941-92d4-40f6855d365d GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-ebcea6cd-f961-4941-92d4-40f6855d365d","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-ebcea6cd-f961-4941-92d4-40f6855d365d","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}}]}
I0427 12:09:22.991993       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-ebcea6cd-f961-4941-92d4-40f6855d365d setting disableInUseChecks: false image features: [layering] mounter: rbd
E0427 12:09:23.013723       1 omap.go:80] ID: 24 Req-ID: pvc-ebcea6cd-f961-4941-92d4-40f6855d365d omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0427 12:09:23.030756       1 omap.go:159] ID: 24 Req-ID: pvc-ebcea6cd-f961-4941-92d4-40f6855d365d set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-ebcea6cd-f961-4941-92d4-40f6855d365d:8ee68f30-d8ed-4119-8870-f59c868ada60])
I0427 12:09:23.038403       1 omap.go:159] ID: 24 Req-ID: pvc-ebcea6cd-f961-4941-92d4-40f6855d365d set omap keys (pool="kube", namespace="", name="csi.volume.8ee68f30-d8ed-4119-8870-f59c868ada60"): map[csi.imagename:csi-vol-8ee68f30-d8ed-4119-8870-f59c868ada60 csi.volname:pvc-ebcea6cd-f961-4941-92d4-40f6855d365d csi.volume.owner:default])
I0427 12:09:23.038463       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-ebcea6cd-f961-4941-92d4-40f6855d365d generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-8ee68f30-d8ed-4119-8870-f59c868ada60) and image name (csi-vol-8ee68f30-d8ed-4119-8870-f59c868ada60) for request name (pvc-ebcea6cd-f961-4941-92d4-40f6855d365d)
I0427 12:09:23.038599       1 rbd_util.go:423] ID: 24 Req-ID: pvc-ebcea6cd-f961-4941-92d4-40f6855d365d rbd: create kube/csi-vol-8ee68f30-d8ed-4119-8870-f59c868ada60 size 5120M (features: [layering]) using mon 199.19.213.157
I0427 12:09:23.038684       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-ebcea6cd-f961-4941-92d4-40f6855d365d setting image options on kube/csi-vol-8ee68f30-d8ed-4119-8870-f59c868ada60
I0427 12:09:24.378797       1 controllerserver.go:763] ID: 24 Req-ID: pvc-ebcea6cd-f961-4941-92d4-40f6855d365d created image kube/csi-vol-8ee68f30-d8ed-4119-8870-f59c868ada60 backed for request name pvc-ebcea6cd-f961-4941-92d4-40f6855d365d
I0427 12:09:24.413306       1 omap.go:159] ID: 24 Req-ID: pvc-ebcea6cd-f961-4941-92d4-40f6855d365d set omap keys (pool="kube", namespace="", name="csi.volume.8ee68f30-d8ed-4119-8870-f59c868ada60"): map[csi.imageid:37d9a10fe7c0])
I0427 12:09:24.510427       1 utils.go:205] ID: 24 Req-ID: pvc-ebcea6cd-f961-4941-92d4-40f6855d365d GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-8ee68f30-d8ed-4119-8870-f59c868ada60","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-8ee68f30-d8ed-4119-8870-f59c868ada60"}}
I0427 12:10:08.791397       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0427 12:10:08.791483       1 utils.go:199] ID: 25 GRPC request: {}
I0427 12:10:08.791542       1 utils.go:205] ID: 25 GRPC response: {}