I0430 14:30:59.061975       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0430 14:30:59.062087       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0430 14:30:59.062100       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0430 14:30:59.062104       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0430 14:30:59.062106       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0430 14:30:59.062109       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0430 14:30:59.062113       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0430 14:30:59.062116       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0430 14:30:59.062118       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0430 14:30:59.062122       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0430 14:30:59.062574       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0430 14:30:59.062739       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0430 14:31:01.961821       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0430 14:31:01.963632       1 utils.go:199] ID: 1 GRPC request: {}
I0430 14:31:01.963861       1 utils.go:205] ID: 1 GRPC response: {}
I0430 14:31:01.966242       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0430 14:31:01.966357       1 utils.go:199] ID: 2 GRPC request: {}
I0430 14:31:01.966388       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0430 14:31:01.966471       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0430 14:31:01.968020       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0430 14:31:01.968192       1 utils.go:199] ID: 3 GRPC request: {}
I0430 14:31:01.968220       1 utils.go:205] ID: 3 GRPC response: {}
I0430 14:31:01.968658       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0430 14:31:01.968749       1 utils.go:199] ID: 4 GRPC request: {}
I0430 14:31:01.969063       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0430 14:31:01.969881       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0430 14:31:01.970068       1 utils.go:199] ID: 5 GRPC request: {}
I0430 14:31:01.970085       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0430 14:31:01.970342       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}}}]}
I0430 14:31:04.330001       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0430 14:31:04.330123       1 utils.go:199] ID: 6 GRPC request: {}
I0430 14:31:04.330173       1 utils.go:205] ID: 6 GRPC response: {}
I0430 14:31:04.331752       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0430 14:31:04.331985       1 utils.go:199] ID: 7 GRPC request: {}
I0430 14:31:04.332034       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0430 14:31:04.332551       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0430 14:31:04.334860       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0430 14:31:04.334929       1 utils.go:199] ID: 8 GRPC request: {}
I0430 14:31:04.334994       1 utils.go:205] ID: 8 GRPC response: {}
I0430 14:31:04.336879       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0430 14:31:04.336944       1 utils.go:199] ID: 9 GRPC request: {}
I0430 14:31:04.337184       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0430 14:31:04.338299       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0430 14:31:04.338335       1 utils.go:199] ID: 10 GRPC request: {}
I0430 14:31:04.338342       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0430 14:31:04.338408       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}}}]}
I0430 14:31:04.338921       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0430 14:31:04.338934       1 utils.go:199] ID: 11 GRPC request: {}
I0430 14:31:04.338938       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0430 14:31:04.338987       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}}}]}
I0430 14:31:04.339380       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0430 14:31:04.339393       1 utils.go:199] ID: 12 GRPC request: {}
I0430 14:31:04.339397       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0430 14:31:04.339457       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}}}]}
I0430 14:31:05.764418       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0430 14:31:05.764452       1 utils.go:199] ID: 13 GRPC request: {}
I0430 14:31:05.764461       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0430 14:31:05.764498       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0430 14:31:05.768752       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0430 14:31:05.768788       1 utils.go:199] ID: 14 GRPC request: {}
I0430 14:31:05.768807       1 utils.go:205] ID: 14 GRPC response: {}
I0430 14:31:05.769265       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0430 14:31:05.769302       1 utils.go:199] ID: 15 GRPC request: {}
I0430 14:31:05.769320       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0430 14:31:05.769448       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}}}]}
I0430 14:31:07.028196       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0430 14:31:07.028243       1 utils.go:199] ID: 16 GRPC request: {}
I0430 14:31:07.028259       1 utils.go:205] ID: 16 GRPC response: {}
I0430 14:31:07.030115       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0430 14:31:07.030136       1 utils.go:199] ID: 17 GRPC request: {}
I0430 14:31:07.030143       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0430 14:31:07.030172       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0430 14:31:07.036387       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0430 14:31:07.036428       1 utils.go:199] ID: 18 GRPC request: {}
I0430 14:31:07.036439       1 utils.go:205] ID: 18 GRPC response: {}
I0430 14:31:07.036899       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0430 14:31:07.036916       1 utils.go:199] ID: 19 GRPC request: {}
I0430 14:31:07.037017       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0430 14:31:07.037641       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0430 14:31:07.037711       1 utils.go:199] ID: 20 GRPC request: {}
I0430 14:31:07.037723       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0430 14:31:07.037826       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}}}]}
I0430 14:32:07.266489       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0430 14:32:07.266540       1 utils.go:199] ID: 21 GRPC request: {}
I0430 14:32:07.266563       1 utils.go:205] ID: 21 GRPC response: {}
I0430 14:33:07.221015       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0430 14:33:07.221189       1 utils.go:199] ID: 22 GRPC request: {}
I0430 14:33:07.221211       1 utils.go:205] ID: 22 GRPC response: {}
I0430 14:34:07.275327       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0430 14:34:07.275381       1 utils.go:199] ID: 23 GRPC request: {}
I0430 14:34:07.275402       1 utils.go:205] ID: 23 GRPC response: {}
I0430 14:34:17.109855       1 utils.go:198] ID: 24 Req-ID: pvc-b636ca96-13f4-4a5b-b138-9aaa3a947aa8 GRPC call: /csi.v1.Controller/CreateVolume
I0430 14:34:17.110302       1 utils.go:199] ID: 24 Req-ID: pvc-b636ca96-13f4-4a5b-b138-9aaa3a947aa8 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-b636ca96-13f4-4a5b-b138-9aaa3a947aa8","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-b636ca96-13f4-4a5b-b138-9aaa3a947aa8","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}}]}
I0430 14:34:17.110593       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-b636ca96-13f4-4a5b-b138-9aaa3a947aa8 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0430 14:34:17.128534       1 omap.go:80] ID: 24 Req-ID: pvc-b636ca96-13f4-4a5b-b138-9aaa3a947aa8 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0430 14:34:17.143167       1 omap.go:159] ID: 24 Req-ID: pvc-b636ca96-13f4-4a5b-b138-9aaa3a947aa8 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-b636ca96-13f4-4a5b-b138-9aaa3a947aa8:66d3b609-f8da-4673-b184-bf9443ba53ca])
I0430 14:34:17.148422       1 omap.go:159] ID: 24 Req-ID: pvc-b636ca96-13f4-4a5b-b138-9aaa3a947aa8 set omap keys (pool="kube", namespace="", name="csi.volume.66d3b609-f8da-4673-b184-bf9443ba53ca"): map[csi.imagename:csi-vol-66d3b609-f8da-4673-b184-bf9443ba53ca csi.volname:pvc-b636ca96-13f4-4a5b-b138-9aaa3a947aa8 csi.volume.owner:default])
I0430 14:34:17.148452       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-b636ca96-13f4-4a5b-b138-9aaa3a947aa8 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-66d3b609-f8da-4673-b184-bf9443ba53ca) and image name (csi-vol-66d3b609-f8da-4673-b184-bf9443ba53ca) for request name (pvc-b636ca96-13f4-4a5b-b138-9aaa3a947aa8)
I0430 14:34:17.148528       1 rbd_util.go:423] ID: 24 Req-ID: pvc-b636ca96-13f4-4a5b-b138-9aaa3a947aa8 rbd: create kube/csi-vol-66d3b609-f8da-4673-b184-bf9443ba53ca size 5120M (features: [layering]) using mon 199.204.45.49
I0430 14:34:17.148573       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-b636ca96-13f4-4a5b-b138-9aaa3a947aa8 setting image options on kube/csi-vol-66d3b609-f8da-4673-b184-bf9443ba53ca
I0430 14:34:19.034093       1 controllerserver.go:763] ID: 24 Req-ID: pvc-b636ca96-13f4-4a5b-b138-9aaa3a947aa8 created image kube/csi-vol-66d3b609-f8da-4673-b184-bf9443ba53ca backed for request name pvc-b636ca96-13f4-4a5b-b138-9aaa3a947aa8
I0430 14:34:19.076671       1 omap.go:159] ID: 24 Req-ID: pvc-b636ca96-13f4-4a5b-b138-9aaa3a947aa8 set omap keys (pool="kube", namespace="", name="csi.volume.66d3b609-f8da-4673-b184-bf9443ba53ca"): map[csi.imageid:37d9a539b49e])
I0430 14:34:19.156065       1 utils.go:205] ID: 24 Req-ID: pvc-b636ca96-13f4-4a5b-b138-9aaa3a947aa8 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-66d3b609-f8da-4673-b184-bf9443ba53ca","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-66d3b609-f8da-4673-b184-bf9443ba53ca"}}
I0430 14:35:07.235092       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0430 14:35:07.235176       1 utils.go:199] ID: 25 GRPC request: {}
I0430 14:35:07.235210       1 utils.go:205] ID: 25 GRPC response: {}