I0427 19:44:18.931984       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0427 19:44:18.932158       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0427 19:44:18.932177       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0427 19:44:18.932193       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0427 19:44:18.932197       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0427 19:44:18.932199       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0427 19:44:18.932205       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0427 19:44:18.932208       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0427 19:44:18.932213       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0427 19:44:18.932216       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0427 19:44:18.932579       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0427 19:44:18.932664       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0427 19:44:21.784976       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0427 19:44:21.787103       1 utils.go:199] ID: 1 GRPC request: {}
I0427 19:44:21.787239       1 utils.go:205] ID: 1 GRPC response: {}
I0427 19:44:21.789610       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0427 19:44:21.789834       1 utils.go:199] ID: 2 GRPC request: {}
I0427 19:44:21.789898       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0427 19:44:21.790046       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0427 19:44:21.793747       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0427 19:44:21.793789       1 utils.go:199] ID: 3 GRPC request: {}
I0427 19:44:21.793815       1 utils.go:205] ID: 3 GRPC response: {}
I0427 19:44:21.794383       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0427 19:44:21.794489       1 utils.go:199] ID: 4 GRPC request: {}
I0427 19:44:21.794719       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0427 19:44:21.795765       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0427 19:44:21.795836       1 utils.go:199] ID: 5 GRPC request: {}
I0427 19:44:21.795850       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0427 19:44:21.796022       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 19:44:23.476419       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0427 19:44:23.476459       1 utils.go:199] ID: 6 GRPC request: {}
I0427 19:44:23.476474       1 utils.go:205] ID: 6 GRPC response: {}
I0427 19:44:23.480316       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0427 19:44:23.480342       1 utils.go:199] ID: 7 GRPC request: {}
I0427 19:44:23.480348       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0427 19:44:23.480368       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0427 19:44:23.481991       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0427 19:44:23.482011       1 utils.go:199] ID: 8 GRPC request: {}
I0427 19:44:23.482021       1 utils.go:205] ID: 8 GRPC response: {}
I0427 19:44:23.482548       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0427 19:44:23.482707       1 utils.go:199] ID: 9 GRPC request: {}
I0427 19:44:23.482871       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0427 19:44:23.483726       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0427 19:44:23.483751       1 utils.go:199] ID: 10 GRPC request: {}
I0427 19:44:23.483760       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0427 19:44:23.483869       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 19:44:23.484509       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0427 19:44:23.484547       1 utils.go:199] ID: 11 GRPC request: {}
I0427 19:44:23.484635       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0427 19:44:23.484888       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 19:44:23.485271       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0427 19:44:23.485303       1 utils.go:199] ID: 12 GRPC request: {}
I0427 19:44:23.485311       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0427 19:44:23.485397       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 19:44:24.790983       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0427 19:44:24.791070       1 utils.go:199] ID: 13 GRPC request: {}
I0427 19:44:24.791087       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0427 19:44:24.791131       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0427 19:44:24.793667       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0427 19:44:24.793688       1 utils.go:199] ID: 14 GRPC request: {}
I0427 19:44:24.793704       1 utils.go:205] ID: 14 GRPC response: {}
I0427 19:44:24.794165       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0427 19:44:24.794188       1 utils.go:199] ID: 15 GRPC request: {}
I0427 19:44:24.794198       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0427 19:44:24.794315       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 19:44:26.849810       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0427 19:44:26.849864       1 utils.go:199] ID: 16 GRPC request: {}
I0427 19:44:26.849887       1 utils.go:205] ID: 16 GRPC response: {}
I0427 19:44:26.853132       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0427 19:44:26.853167       1 utils.go:199] ID: 17 GRPC request: {}
I0427 19:44:26.853177       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0427 19:44:26.853208       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0427 19:44:26.855464       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0427 19:44:26.855485       1 utils.go:199] ID: 18 GRPC request: {}
I0427 19:44:26.855497       1 utils.go:205] ID: 18 GRPC response: {}
I0427 19:44:26.855825       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0427 19:44:26.855853       1 utils.go:199] ID: 19 GRPC request: {}
I0427 19:44:26.855959       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0427 19:44:26.856647       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0427 19:44:26.856670       1 utils.go:199] ID: 20 GRPC request: {}
I0427 19:44:26.856680       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0427 19:44:26.856778       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 19:45:27.217430       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0427 19:45:27.217513       1 utils.go:199] ID: 21 GRPC request: {}
I0427 19:45:27.217539       1 utils.go:205] ID: 21 GRPC response: {}
I0427 19:46:27.165415       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0427 19:46:27.165522       1 utils.go:199] ID: 22 GRPC request: {}
I0427 19:46:27.165551       1 utils.go:205] ID: 22 GRPC response: {}
I0427 19:47:27.162200       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0427 19:47:27.162267       1 utils.go:199] ID: 23 GRPC request: {}
I0427 19:47:27.162292       1 utils.go:205] ID: 23 GRPC response: {}
I0427 19:47:41.763934       1 utils.go:198] ID: 24 Req-ID: pvc-4ee6a5fa-7cbd-4942-a88f-f894de840a09 GRPC call: /csi.v1.Controller/CreateVolume
I0427 19:47:41.764514       1 utils.go:199] ID: 24 Req-ID: pvc-4ee6a5fa-7cbd-4942-a88f-f894de840a09 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-4ee6a5fa-7cbd-4942-a88f-f894de840a09","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-4ee6a5fa-7cbd-4942-a88f-f894de840a09","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 19:47:41.764856       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-4ee6a5fa-7cbd-4942-a88f-f894de840a09 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0427 19:47:41.784592       1 omap.go:80] ID: 24 Req-ID: pvc-4ee6a5fa-7cbd-4942-a88f-f894de840a09 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0427 19:47:41.809557       1 omap.go:159] ID: 24 Req-ID: pvc-4ee6a5fa-7cbd-4942-a88f-f894de840a09 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-4ee6a5fa-7cbd-4942-a88f-f894de840a09:9456c836-1fdf-4bc9-8b6c-6a5971f2987a])
I0427 19:47:41.814730       1 omap.go:159] ID: 24 Req-ID: pvc-4ee6a5fa-7cbd-4942-a88f-f894de840a09 set omap keys (pool="kube", namespace="", name="csi.volume.9456c836-1fdf-4bc9-8b6c-6a5971f2987a"): map[csi.imagename:csi-vol-9456c836-1fdf-4bc9-8b6c-6a5971f2987a csi.volname:pvc-4ee6a5fa-7cbd-4942-a88f-f894de840a09 csi.volume.owner:default])
I0427 19:47:41.814772       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-4ee6a5fa-7cbd-4942-a88f-f894de840a09 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-9456c836-1fdf-4bc9-8b6c-6a5971f2987a) and image name (csi-vol-9456c836-1fdf-4bc9-8b6c-6a5971f2987a) for request name (pvc-4ee6a5fa-7cbd-4942-a88f-f894de840a09)
I0427 19:47:41.814893       1 rbd_util.go:423] ID: 24 Req-ID: pvc-4ee6a5fa-7cbd-4942-a88f-f894de840a09 rbd: create kube/csi-vol-9456c836-1fdf-4bc9-8b6c-6a5971f2987a size 5120M (features: [layering]) using mon 199.19.213.207
I0427 19:47:41.814947       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-4ee6a5fa-7cbd-4942-a88f-f894de840a09 setting image options on kube/csi-vol-9456c836-1fdf-4bc9-8b6c-6a5971f2987a
I0427 19:47:43.273865       1 controllerserver.go:763] ID: 24 Req-ID: pvc-4ee6a5fa-7cbd-4942-a88f-f894de840a09 created image kube/csi-vol-9456c836-1fdf-4bc9-8b6c-6a5971f2987a backed for request name pvc-4ee6a5fa-7cbd-4942-a88f-f894de840a09
I0427 19:47:43.316276       1 omap.go:159] ID: 24 Req-ID: pvc-4ee6a5fa-7cbd-4942-a88f-f894de840a09 set omap keys (pool="kube", namespace="", name="csi.volume.9456c836-1fdf-4bc9-8b6c-6a5971f2987a"): map[csi.imageid:37d91b8c472])
I0427 19:47:43.417904       1 utils.go:205] ID: 24 Req-ID: pvc-4ee6a5fa-7cbd-4942-a88f-f894de840a09 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-9456c836-1fdf-4bc9-8b6c-6a5971f2987a","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-9456c836-1fdf-4bc9-8b6c-6a5971f2987a"}}
I0427 19:48:27.175725       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0427 19:48:27.175961       1 utils.go:199] ID: 25 GRPC request: {}
I0427 19:48:27.176317       1 utils.go:205] ID: 25 GRPC response: {}