I0422 13:13:46.089853       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0422 13:13:46.089988       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0422 13:13:46.089999       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0422 13:13:46.090005       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0422 13:13:46.090008       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0422 13:13:46.090011       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0422 13:13:46.090099       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0422 13:13:46.090107       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0422 13:13:46.090111       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0422 13:13:46.090114       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0422 13:13:46.090420       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0422 13:13:46.090455       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0422 13:13:48.384227       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0422 13:13:48.385656       1 utils.go:199] ID: 1 GRPC request: {}
I0422 13:13:48.385766       1 utils.go:205] ID: 1 GRPC response: {}
I0422 13:13:48.387963       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0422 13:13:48.388128       1 utils.go:199] ID: 2 GRPC request: {}
I0422 13:13:48.388157       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0422 13:13:48.388221       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0422 13:13:48.389652       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0422 13:13:48.389684       1 utils.go:199] ID: 3 GRPC request: {}
I0422 13:13:48.389828       1 utils.go:205] ID: 3 GRPC response: {}
I0422 13:13:48.392877       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0422 13:13:48.392997       1 utils.go:199] ID: 4 GRPC request: {}
I0422 13:13:48.393275       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0422 13:13:48.394599       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0422 13:13:48.394697       1 utils.go:199] ID: 5 GRPC request: {}
I0422 13:13:48.394711       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0422 13:13:48.394864       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}}}]}
I0422 13:13:49.694441       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0422 13:13:49.694496       1 utils.go:199] ID: 6 GRPC request: {}
I0422 13:13:49.694519       1 utils.go:205] ID: 6 GRPC response: {}
I0422 13:13:49.698613       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0422 13:13:49.698635       1 utils.go:199] ID: 7 GRPC request: {}
I0422 13:13:49.698661       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0422 13:13:49.698688       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0422 13:13:49.701244       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0422 13:13:49.701468       1 utils.go:199] ID: 8 GRPC request: {}
I0422 13:13:49.701527       1 utils.go:205] ID: 8 GRPC response: {}
I0422 13:13:49.702186       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0422 13:13:49.702214       1 utils.go:199] ID: 9 GRPC request: {}
I0422 13:13:49.702367       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0422 13:13:49.703060       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0422 13:13:49.703083       1 utils.go:199] ID: 10 GRPC request: {}
I0422 13:13:49.703092       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0422 13:13:49.703197       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}}}]}
I0422 13:13:49.703940       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0422 13:13:49.704055       1 utils.go:199] ID: 11 GRPC request: {}
I0422 13:13:49.704071       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0422 13:13:49.704580       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}}}]}
I0422 13:13:49.705137       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0422 13:13:49.705156       1 utils.go:199] ID: 12 GRPC request: {}
I0422 13:13:49.705161       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0422 13:13:49.705210       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}}}]}
I0422 13:13:51.086339       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0422 13:13:51.086404       1 utils.go:199] ID: 13 GRPC request: {}
I0422 13:13:51.086428       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0422 13:13:51.086482       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0422 13:13:51.089183       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0422 13:13:51.089223       1 utils.go:199] ID: 14 GRPC request: {}
I0422 13:13:51.089246       1 utils.go:205] ID: 14 GRPC response: {}
I0422 13:13:51.089814       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0422 13:13:51.089909       1 utils.go:199] ID: 15 GRPC request: {}
I0422 13:13:51.089923       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0422 13:13:51.090063       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}}}]}
I0422 13:13:52.321453       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0422 13:13:52.321486       1 utils.go:199] ID: 16 GRPC request: {}
I0422 13:13:52.321510       1 utils.go:205] ID: 16 GRPC response: {}
I0422 13:13:52.324028       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0422 13:13:52.324050       1 utils.go:199] ID: 17 GRPC request: {}
I0422 13:13:52.324058       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0422 13:13:52.324092       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0422 13:13:52.326246       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0422 13:13:52.326294       1 utils.go:199] ID: 18 GRPC request: {}
I0422 13:13:52.326317       1 utils.go:205] ID: 18 GRPC response: {}
I0422 13:13:52.326725       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0422 13:13:52.326745       1 utils.go:199] ID: 19 GRPC request: {}
I0422 13:13:52.326853       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0422 13:13:52.327407       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0422 13:13:52.327427       1 utils.go:199] ID: 20 GRPC request: {}
I0422 13:13:52.327437       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0422 13:13:52.327503       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}}}]}
I0422 13:14:52.570687       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0422 13:14:52.570761       1 utils.go:199] ID: 21 GRPC request: {}
I0422 13:14:52.570783       1 utils.go:205] ID: 21 GRPC response: {}
I0422 13:15:52.518319       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0422 13:15:52.518411       1 utils.go:199] ID: 22 GRPC request: {}
I0422 13:15:52.518463       1 utils.go:205] ID: 22 GRPC response: {}
I0422 13:16:52.567502       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0422 13:16:52.567564       1 utils.go:199] ID: 23 GRPC request: {}
I0422 13:16:52.567595       1 utils.go:205] ID: 23 GRPC response: {}
I0422 13:17:01.251017       1 utils.go:198] ID: 24 Req-ID: pvc-49b1a606-983d-46e9-8852-074442fbd767 GRPC call: /csi.v1.Controller/CreateVolume
I0422 13:17:01.252851       1 utils.go:199] ID: 24 Req-ID: pvc-49b1a606-983d-46e9-8852-074442fbd767 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-49b1a606-983d-46e9-8852-074442fbd767","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-49b1a606-983d-46e9-8852-074442fbd767","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}}]}
I0422 13:17:01.253689       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-49b1a606-983d-46e9-8852-074442fbd767 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0422 13:17:01.274171       1 omap.go:80] ID: 24 Req-ID: pvc-49b1a606-983d-46e9-8852-074442fbd767 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0422 13:17:01.290552       1 omap.go:159] ID: 24 Req-ID: pvc-49b1a606-983d-46e9-8852-074442fbd767 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-49b1a606-983d-46e9-8852-074442fbd767:0540fc81-d505-4f25-a4ae-cd174057c8fe])
I0422 13:17:01.297057       1 omap.go:159] ID: 24 Req-ID: pvc-49b1a606-983d-46e9-8852-074442fbd767 set omap keys (pool="kube", namespace="", name="csi.volume.0540fc81-d505-4f25-a4ae-cd174057c8fe"): map[csi.imagename:csi-vol-0540fc81-d505-4f25-a4ae-cd174057c8fe csi.volname:pvc-49b1a606-983d-46e9-8852-074442fbd767 csi.volume.owner:default])
I0422 13:17:01.297096       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-49b1a606-983d-46e9-8852-074442fbd767 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-0540fc81-d505-4f25-a4ae-cd174057c8fe) and image name (csi-vol-0540fc81-d505-4f25-a4ae-cd174057c8fe) for request name (pvc-49b1a606-983d-46e9-8852-074442fbd767)
I0422 13:17:01.297292       1 rbd_util.go:423] ID: 24 Req-ID: pvc-49b1a606-983d-46e9-8852-074442fbd767 rbd: create kube/csi-vol-0540fc81-d505-4f25-a4ae-cd174057c8fe size 5120M (features: [layering]) using mon 199.204.45.113
I0422 13:17:01.297473       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-49b1a606-983d-46e9-8852-074442fbd767 setting image options on kube/csi-vol-0540fc81-d505-4f25-a4ae-cd174057c8fe
I0422 13:17:03.184952       1 controllerserver.go:763] ID: 24 Req-ID: pvc-49b1a606-983d-46e9-8852-074442fbd767 created image kube/csi-vol-0540fc81-d505-4f25-a4ae-cd174057c8fe backed for request name pvc-49b1a606-983d-46e9-8852-074442fbd767
I0422 13:17:03.220178       1 omap.go:159] ID: 24 Req-ID: pvc-49b1a606-983d-46e9-8852-074442fbd767 set omap keys (pool="kube", namespace="", name="csi.volume.0540fc81-d505-4f25-a4ae-cd174057c8fe"): map[csi.imageid:37d9b784bd5e])
I0422 13:17:03.320540       1 utils.go:205] ID: 24 Req-ID: pvc-49b1a606-983d-46e9-8852-074442fbd767 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-0540fc81-d505-4f25-a4ae-cd174057c8fe","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-0540fc81-d505-4f25-a4ae-cd174057c8fe"}}
I0422 13:17:52.521838       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0422 13:17:52.521894       1 utils.go:199] ID: 25 GRPC request: {}
I0422 13:17:52.521919       1 utils.go:205] ID: 25 GRPC response: {}