I0206 18:48:59.482418       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0206 18:48:59.482776       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0206 18:48:59.482848       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0206 18:48:59.482901       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0206 18:48:59.482976       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0206 18:48:59.483028       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0206 18:48:59.483148       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0206 18:48:59.483202       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0206 18:48:59.483246       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0206 18:48:59.483297       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0206 18:48:59.484406       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0206 18:48:59.484543       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0206 18:49:05.924016       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0206 18:49:05.925090       1 utils.go:199] ID: 1 GRPC request: {}
I0206 18:49:05.925228       1 utils.go:205] ID: 1 GRPC response: {}
I0206 18:49:05.926619       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0206 18:49:05.926703       1 utils.go:199] ID: 2 GRPC request: {}
I0206 18:49:05.926769       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0206 18:49:05.926847       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0206 18:49:05.931053       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0206 18:49:05.931168       1 utils.go:199] ID: 3 GRPC request: {}
I0206 18:49:05.931258       1 utils.go:205] ID: 3 GRPC response: {}
I0206 18:49:05.931709       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0206 18:49:05.931857       1 utils.go:199] ID: 4 GRPC request: {}
I0206 18:49:05.932102       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0206 18:49:05.932970       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0206 18:49:05.933183       1 utils.go:199] ID: 5 GRPC request: {}
I0206 18:49:05.933264       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0206 18:49:05.933519       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}}}]}
I0206 18:49:08.515433       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0206 18:49:08.515470       1 utils.go:199] ID: 6 GRPC request: {}
I0206 18:49:08.515500       1 utils.go:205] ID: 6 GRPC response: {}
I0206 18:49:08.519877       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0206 18:49:08.519970       1 utils.go:199] ID: 7 GRPC request: {}
I0206 18:49:08.520028       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0206 18:49:08.520122       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0206 18:49:08.523809       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0206 18:49:08.523890       1 utils.go:199] ID: 8 GRPC request: {}
I0206 18:49:08.523953       1 utils.go:205] ID: 8 GRPC response: {}
I0206 18:49:08.524343       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0206 18:49:08.524438       1 utils.go:199] ID: 9 GRPC request: {}
I0206 18:49:08.524695       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0206 18:49:08.525274       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0206 18:49:08.525382       1 utils.go:199] ID: 10 GRPC request: {}
I0206 18:49:08.525451       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0206 18:49:08.525641       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}}}]}
I0206 18:49:08.526167       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0206 18:49:08.526375       1 utils.go:199] ID: 11 GRPC request: {}
I0206 18:49:08.526456       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0206 18:49:08.526601       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}}}]}
I0206 18:49:08.527015       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0206 18:49:08.527114       1 utils.go:199] ID: 12 GRPC request: {}
I0206 18:49:08.527184       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0206 18:49:08.527310       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}}}]}
I0206 18:49:11.300257       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0206 18:49:11.300300       1 utils.go:199] ID: 13 GRPC request: {}
I0206 18:49:11.300307       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0206 18:49:11.300363       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0206 18:49:11.301913       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0206 18:49:11.301926       1 utils.go:199] ID: 14 GRPC request: {}
I0206 18:49:11.301941       1 utils.go:205] ID: 14 GRPC response: {}
I0206 18:49:11.302373       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0206 18:49:11.302412       1 utils.go:199] ID: 15 GRPC request: {}
I0206 18:49:11.302419       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0206 18:49:11.302495       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}}}]}
I0206 18:49:13.768548       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0206 18:49:13.768665       1 utils.go:199] ID: 16 GRPC request: {}
I0206 18:49:13.768685       1 utils.go:205] ID: 16 GRPC response: {}
I0206 18:49:13.769986       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0206 18:49:13.770005       1 utils.go:199] ID: 17 GRPC request: {}
I0206 18:49:13.770011       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0206 18:49:13.770030       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0206 18:49:13.770971       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0206 18:49:13.771039       1 utils.go:199] ID: 18 GRPC request: {}
I0206 18:49:13.771052       1 utils.go:205] ID: 18 GRPC response: {}
I0206 18:49:13.771302       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0206 18:49:13.771315       1 utils.go:199] ID: 19 GRPC request: {}
I0206 18:49:13.771471       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0206 18:49:13.771973       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0206 18:49:13.772131       1 utils.go:199] ID: 20 GRPC request: {}
I0206 18:49:13.772143       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0206 18:49:13.772252       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}}}]}
I0206 18:50:13.979664       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0206 18:50:13.979799       1 utils.go:199] ID: 21 GRPC request: {}
I0206 18:50:13.979868       1 utils.go:205] ID: 21 GRPC response: {}
I0206 18:51:13.979001       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0206 18:51:13.979044       1 utils.go:199] ID: 22 GRPC request: {}
I0206 18:51:13.979055       1 utils.go:205] ID: 22 GRPC response: {}
I0206 18:52:07.934473       1 utils.go:198] ID: 23 Req-ID: pvc-31775e9e-1ec6-4785-998c-241368dcf56a GRPC call: /csi.v1.Controller/CreateVolume
I0206 18:52:07.935563       1 utils.go:199] ID: 23 Req-ID: pvc-31775e9e-1ec6-4785-998c-241368dcf56a GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-31775e9e-1ec6-4785-998c-241368dcf56a","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-31775e9e-1ec6-4785-998c-241368dcf56a","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}}]}
I0206 18:52:07.935983       1 rbd_util.go:1315] ID: 23 Req-ID: pvc-31775e9e-1ec6-4785-998c-241368dcf56a setting disableInUseChecks: false image features: [layering] mounter: rbd
E0206 18:52:07.958347       1 omap.go:80] ID: 23 Req-ID: pvc-31775e9e-1ec6-4785-998c-241368dcf56a omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0206 18:52:07.971011       1 omap.go:159] ID: 23 Req-ID: pvc-31775e9e-1ec6-4785-998c-241368dcf56a set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-31775e9e-1ec6-4785-998c-241368dcf56a:a63c24d3-c425-4c5a-969a-3c273dff27d5])
I0206 18:52:07.975629       1 omap.go:159] ID: 23 Req-ID: pvc-31775e9e-1ec6-4785-998c-241368dcf56a set omap keys (pool="kube", namespace="", name="csi.volume.a63c24d3-c425-4c5a-969a-3c273dff27d5"): map[csi.imagename:csi-vol-a63c24d3-c425-4c5a-969a-3c273dff27d5 csi.volname:pvc-31775e9e-1ec6-4785-998c-241368dcf56a csi.volume.owner:default])
I0206 18:52:07.975654       1 rbd_journal.go:491] ID: 23 Req-ID: pvc-31775e9e-1ec6-4785-998c-241368dcf56a generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-a63c24d3-c425-4c5a-969a-3c273dff27d5) and image name (csi-vol-a63c24d3-c425-4c5a-969a-3c273dff27d5) for request name (pvc-31775e9e-1ec6-4785-998c-241368dcf56a)
I0206 18:52:07.975770       1 rbd_util.go:423] ID: 23 Req-ID: pvc-31775e9e-1ec6-4785-998c-241368dcf56a rbd: create kube/csi-vol-a63c24d3-c425-4c5a-969a-3c273dff27d5 size 5120M (features: [layering]) using mon 162.253.55.186
I0206 18:52:07.975876       1 rbd_util.go:1563] ID: 23 Req-ID: pvc-31775e9e-1ec6-4785-998c-241368dcf56a setting image options on kube/csi-vol-a63c24d3-c425-4c5a-969a-3c273dff27d5
I0206 18:52:09.261639       1 controllerserver.go:763] ID: 23 Req-ID: pvc-31775e9e-1ec6-4785-998c-241368dcf56a created image kube/csi-vol-a63c24d3-c425-4c5a-969a-3c273dff27d5 backed for request name pvc-31775e9e-1ec6-4785-998c-241368dcf56a
I0206 18:52:09.302660       1 omap.go:159] ID: 23 Req-ID: pvc-31775e9e-1ec6-4785-998c-241368dcf56a set omap keys (pool="kube", namespace="", name="csi.volume.a63c24d3-c425-4c5a-969a-3c273dff27d5"): map[csi.imageid:37d71175149e])
I0206 18:52:09.374954       1 utils.go:205] ID: 23 Req-ID: pvc-31775e9e-1ec6-4785-998c-241368dcf56a GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-a63c24d3-c425-4c5a-969a-3c273dff27d5","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-a63c24d3-c425-4c5a-969a-3c273dff27d5"}}
I0206 18:52:13.978851       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0206 18:52:13.978899       1 utils.go:199] ID: 24 GRPC request: {}
I0206 18:52:13.978920       1 utils.go:205] ID: 24 GRPC response: {}