I0226 19:35:46.884200       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0226 19:35:46.884297       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0226 19:35:46.884313       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0226 19:35:46.884316       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0226 19:35:46.884319       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0226 19:35:46.884322       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0226 19:35:46.884325       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0226 19:35:46.884327       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0226 19:35:46.884330       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0226 19:35:46.884333       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0226 19:35:46.884553       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0226 19:35:46.884614       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0226 19:35:50.444962       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0226 19:35:50.446383       1 utils.go:199] ID: 1 GRPC request: {}
I0226 19:35:50.446455       1 utils.go:205] ID: 1 GRPC response: {}
I0226 19:35:50.448772       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0226 19:35:50.448921       1 utils.go:199] ID: 2 GRPC request: {}
I0226 19:35:50.448949       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0226 19:35:50.449041       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0226 19:35:50.450814       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0226 19:35:50.450848       1 utils.go:199] ID: 3 GRPC request: {}
I0226 19:35:50.450965       1 utils.go:205] ID: 3 GRPC response: {}
I0226 19:35:50.451451       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0226 19:35:50.451600       1 utils.go:199] ID: 4 GRPC request: {}
I0226 19:35:50.451817       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0226 19:35:50.453982       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0226 19:35:50.454094       1 utils.go:199] ID: 5 GRPC request: {}
I0226 19:35:50.454107       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0226 19:35:50.454309       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}}}]}
I0226 19:35:52.510017       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0226 19:35:52.510051       1 utils.go:199] ID: 6 GRPC request: {}
I0226 19:35:52.510086       1 utils.go:205] ID: 6 GRPC response: {}
I0226 19:35:52.514850       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0226 19:35:52.514880       1 utils.go:199] ID: 7 GRPC request: {}
I0226 19:35:52.514895       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0226 19:35:52.514940       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0226 19:35:52.517092       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0226 19:35:52.517114       1 utils.go:199] ID: 8 GRPC request: {}
I0226 19:35:52.517138       1 utils.go:205] ID: 8 GRPC response: {}
I0226 19:35:52.517657       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0226 19:35:52.517683       1 utils.go:199] ID: 9 GRPC request: {}
I0226 19:35:52.517823       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0226 19:35:52.518617       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0226 19:35:52.518637       1 utils.go:199] ID: 10 GRPC request: {}
I0226 19:35:52.518644       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0226 19:35:52.518734       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}}}]}
I0226 19:35:52.519352       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0226 19:35:52.519411       1 utils.go:199] ID: 11 GRPC request: {}
I0226 19:35:52.519432       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0226 19:35:52.519575       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}}}]}
I0226 19:35:52.520085       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0226 19:35:52.520212       1 utils.go:199] ID: 12 GRPC request: {}
I0226 19:35:52.520226       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0226 19:35:52.520374       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}}}]}
I0226 19:35:53.948103       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0226 19:35:53.948144       1 utils.go:199] ID: 13 GRPC request: {}
I0226 19:35:53.948153       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0226 19:35:53.948178       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0226 19:35:53.952864       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0226 19:35:53.952896       1 utils.go:199] ID: 14 GRPC request: {}
I0226 19:35:53.952921       1 utils.go:205] ID: 14 GRPC response: {}
I0226 19:35:53.953683       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0226 19:35:53.953721       1 utils.go:199] ID: 15 GRPC request: {}
I0226 19:35:53.953732       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0226 19:35:53.953881       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}}}]}
I0226 19:35:56.226455       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0226 19:35:56.226541       1 utils.go:199] ID: 16 GRPC request: {}
I0226 19:35:56.226561       1 utils.go:205] ID: 16 GRPC response: {}
I0226 19:35:56.229178       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0226 19:35:56.229209       1 utils.go:199] ID: 17 GRPC request: {}
I0226 19:35:56.229220       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0226 19:35:56.229263       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0226 19:35:56.230794       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0226 19:35:56.230874       1 utils.go:199] ID: 18 GRPC request: {}
I0226 19:35:56.230906       1 utils.go:205] ID: 18 GRPC response: {}
I0226 19:35:56.231404       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0226 19:35:56.231449       1 utils.go:199] ID: 19 GRPC request: {}
I0226 19:35:56.231639       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0226 19:35:56.232179       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0226 19:35:56.232229       1 utils.go:199] ID: 20 GRPC request: {}
I0226 19:35:56.232248       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0226 19:35:56.232375       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}}}]}
I0226 19:36:57.109609       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0226 19:36:57.109664       1 utils.go:199] ID: 21 GRPC request: {}
I0226 19:36:57.109687       1 utils.go:205] ID: 21 GRPC response: {}
I0226 19:37:57.066716       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0226 19:37:57.066809       1 utils.go:199] ID: 22 GRPC request: {}
I0226 19:37:57.066837       1 utils.go:205] ID: 22 GRPC response: {}
I0226 19:38:41.561673       1 utils.go:198] ID: 23 Req-ID: pvc-ff6418cb-b43e-4f82-8324-512403c035ef GRPC call: /csi.v1.Controller/CreateVolume
I0226 19:38:41.561932       1 utils.go:199] ID: 23 Req-ID: pvc-ff6418cb-b43e-4f82-8324-512403c035ef GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-ff6418cb-b43e-4f82-8324-512403c035ef","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-ff6418cb-b43e-4f82-8324-512403c035ef","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}}]}
I0226 19:38:41.562125       1 rbd_util.go:1315] ID: 23 Req-ID: pvc-ff6418cb-b43e-4f82-8324-512403c035ef setting disableInUseChecks: false image features: [layering] mounter: rbd
E0226 19:38:41.579055       1 omap.go:80] ID: 23 Req-ID: pvc-ff6418cb-b43e-4f82-8324-512403c035ef omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0226 19:38:41.595938       1 omap.go:159] ID: 23 Req-ID: pvc-ff6418cb-b43e-4f82-8324-512403c035ef set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-ff6418cb-b43e-4f82-8324-512403c035ef:de97897b-7337-4cea-b14d-d68656bf57f2])
I0226 19:38:41.603105       1 omap.go:159] ID: 23 Req-ID: pvc-ff6418cb-b43e-4f82-8324-512403c035ef set omap keys (pool="kube", namespace="", name="csi.volume.de97897b-7337-4cea-b14d-d68656bf57f2"): map[csi.imagename:csi-vol-de97897b-7337-4cea-b14d-d68656bf57f2 csi.volname:pvc-ff6418cb-b43e-4f82-8324-512403c035ef csi.volume.owner:default])
I0226 19:38:41.603160       1 rbd_journal.go:491] ID: 23 Req-ID: pvc-ff6418cb-b43e-4f82-8324-512403c035ef generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-de97897b-7337-4cea-b14d-d68656bf57f2) and image name (csi-vol-de97897b-7337-4cea-b14d-d68656bf57f2) for request name (pvc-ff6418cb-b43e-4f82-8324-512403c035ef)
I0226 19:38:41.603236       1 rbd_util.go:423] ID: 23 Req-ID: pvc-ff6418cb-b43e-4f82-8324-512403c035ef rbd: create kube/csi-vol-de97897b-7337-4cea-b14d-d68656bf57f2 size 5120M (features: [layering]) using mon 162.253.55.207
I0226 19:38:41.603293       1 rbd_util.go:1563] ID: 23 Req-ID: pvc-ff6418cb-b43e-4f82-8324-512403c035ef setting image options on kube/csi-vol-de97897b-7337-4cea-b14d-d68656bf57f2
I0226 19:38:43.062525       1 controllerserver.go:763] ID: 23 Req-ID: pvc-ff6418cb-b43e-4f82-8324-512403c035ef created image kube/csi-vol-de97897b-7337-4cea-b14d-d68656bf57f2 backed for request name pvc-ff6418cb-b43e-4f82-8324-512403c035ef
I0226 19:38:43.102875       1 omap.go:159] ID: 23 Req-ID: pvc-ff6418cb-b43e-4f82-8324-512403c035ef set omap keys (pool="kube", namespace="", name="csi.volume.de97897b-7337-4cea-b14d-d68656bf57f2"): map[csi.imageid:37d7587fa689])
I0226 19:38:43.193644       1 utils.go:205] ID: 23 Req-ID: pvc-ff6418cb-b43e-4f82-8324-512403c035ef GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-de97897b-7337-4cea-b14d-d68656bf57f2","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-de97897b-7337-4cea-b14d-d68656bf57f2"}}
I0226 19:38:57.115198       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0226 19:38:57.115251       1 utils.go:199] ID: 24 GRPC request: {}
I0226 19:38:57.115274       1 utils.go:205] ID: 24 GRPC response: {}