I0319 17:52:09.573380       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0319 17:52:09.573509       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0319 17:52:09.573520       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0319 17:52:09.573526       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0319 17:52:09.573529       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0319 17:52:09.573532       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0319 17:52:09.573535       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0319 17:52:09.573538       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0319 17:52:09.573541       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0319 17:52:09.573544       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0319 17:52:09.573848       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0319 17:52:09.573879       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0319 17:52:11.966872       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0319 17:52:11.967862       1 utils.go:199] ID: 1 GRPC request: {}
I0319 17:52:11.967905       1 utils.go:205] ID: 1 GRPC response: {}
I0319 17:52:11.970301       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0319 17:52:11.970440       1 utils.go:199] ID: 2 GRPC request: {}
I0319 17:52:11.970478       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0319 17:52:11.970549       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0319 17:52:11.972171       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0319 17:52:11.972199       1 utils.go:199] ID: 3 GRPC request: {}
I0319 17:52:11.972218       1 utils.go:205] ID: 3 GRPC response: {}
I0319 17:52:11.972605       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0319 17:52:11.972673       1 utils.go:199] ID: 4 GRPC request: {}
I0319 17:52:11.972874       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0319 17:52:11.973674       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0319 17:52:11.973735       1 utils.go:199] ID: 5 GRPC request: {}
I0319 17:52:11.973746       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0319 17:52:11.973854       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}}}]}
I0319 17:52:14.946288       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0319 17:52:14.946339       1 utils.go:199] ID: 6 GRPC request: {}
I0319 17:52:14.946394       1 utils.go:205] ID: 6 GRPC response: {}
I0319 17:52:14.950065       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0319 17:52:14.950094       1 utils.go:199] ID: 7 GRPC request: {}
I0319 17:52:14.950104       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0319 17:52:14.950225       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0319 17:52:14.952879       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0319 17:52:14.952907       1 utils.go:199] ID: 8 GRPC request: {}
I0319 17:52:14.953013       1 utils.go:205] ID: 8 GRPC response: {}
I0319 17:52:14.953542       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0319 17:52:14.953566       1 utils.go:199] ID: 9 GRPC request: {}
I0319 17:52:14.953799       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0319 17:52:14.954499       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0319 17:52:14.954549       1 utils.go:199] ID: 10 GRPC request: {}
I0319 17:52:14.954564       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0319 17:52:14.954710       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}}}]}
I0319 17:52:14.955563       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0319 17:52:14.955622       1 utils.go:199] ID: 11 GRPC request: {}
I0319 17:52:14.955639       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0319 17:52:14.955808       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}}}]}
I0319 17:52:14.956535       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0319 17:52:14.956580       1 utils.go:199] ID: 12 GRPC request: {}
I0319 17:52:14.956593       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0319 17:52:14.956737       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}}}]}
I0319 17:52:16.454222       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0319 17:52:16.454260       1 utils.go:199] ID: 13 GRPC request: {}
I0319 17:52:16.454267       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0319 17:52:16.454306       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0319 17:52:16.456986       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0319 17:52:16.457043       1 utils.go:199] ID: 14 GRPC request: {}
I0319 17:52:16.457062       1 utils.go:205] ID: 14 GRPC response: {}
I0319 17:52:16.457906       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0319 17:52:16.457968       1 utils.go:199] ID: 15 GRPC request: {}
I0319 17:52:16.457984       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0319 17:52:16.458135       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}}}]}
I0319 17:52:17.633037       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0319 17:52:17.633097       1 utils.go:199] ID: 16 GRPC request: {}
I0319 17:52:17.633129       1 utils.go:205] ID: 16 GRPC response: {}
I0319 17:52:17.634859       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0319 17:52:17.634927       1 utils.go:199] ID: 17 GRPC request: {}
I0319 17:52:17.634940       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0319 17:52:17.634977       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0319 17:52:17.636770       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0319 17:52:17.636802       1 utils.go:199] ID: 18 GRPC request: {}
I0319 17:52:17.636823       1 utils.go:205] ID: 18 GRPC response: {}
I0319 17:52:17.637337       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0319 17:52:17.637375       1 utils.go:199] ID: 19 GRPC request: {}
I0319 17:52:17.637511       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0319 17:52:17.638349       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0319 17:52:17.638383       1 utils.go:199] ID: 20 GRPC request: {}
I0319 17:52:17.638395       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0319 17:52:17.638515       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}}}]}
I0319 17:53:17.871612       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0319 17:53:17.871659       1 utils.go:199] ID: 21 GRPC request: {}
I0319 17:53:17.871680       1 utils.go:205] ID: 21 GRPC response: {}
I0319 17:54:17.823472       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0319 17:54:17.823530       1 utils.go:199] ID: 22 GRPC request: {}
I0319 17:54:17.823574       1 utils.go:205] ID: 22 GRPC response: {}
I0319 17:55:15.831045       1 utils.go:198] ID: 23 Req-ID: pvc-43e3901d-284e-4e21-a4b5-005eb5fff56e GRPC call: /csi.v1.Controller/CreateVolume
I0319 17:55:15.831336       1 utils.go:199] ID: 23 Req-ID: pvc-43e3901d-284e-4e21-a4b5-005eb5fff56e GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-43e3901d-284e-4e21-a4b5-005eb5fff56e","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-43e3901d-284e-4e21-a4b5-005eb5fff56e","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}}]}
I0319 17:55:15.831539       1 rbd_util.go:1315] ID: 23 Req-ID: pvc-43e3901d-284e-4e21-a4b5-005eb5fff56e setting disableInUseChecks: false image features: [layering] mounter: rbd
E0319 17:55:15.851117       1 omap.go:80] ID: 23 Req-ID: pvc-43e3901d-284e-4e21-a4b5-005eb5fff56e omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0319 17:55:15.865959       1 omap.go:159] ID: 23 Req-ID: pvc-43e3901d-284e-4e21-a4b5-005eb5fff56e set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-43e3901d-284e-4e21-a4b5-005eb5fff56e:94c2187c-37da-4bba-9955-bb2a55f9d7fc])
I0319 17:55:15.871885       1 omap.go:159] ID: 23 Req-ID: pvc-43e3901d-284e-4e21-a4b5-005eb5fff56e set omap keys (pool="kube", namespace="", name="csi.volume.94c2187c-37da-4bba-9955-bb2a55f9d7fc"): map[csi.imagename:csi-vol-94c2187c-37da-4bba-9955-bb2a55f9d7fc csi.volname:pvc-43e3901d-284e-4e21-a4b5-005eb5fff56e csi.volume.owner:default])
I0319 17:55:15.871915       1 rbd_journal.go:491] ID: 23 Req-ID: pvc-43e3901d-284e-4e21-a4b5-005eb5fff56e generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-94c2187c-37da-4bba-9955-bb2a55f9d7fc) and image name (csi-vol-94c2187c-37da-4bba-9955-bb2a55f9d7fc) for request name (pvc-43e3901d-284e-4e21-a4b5-005eb5fff56e)
I0319 17:55:15.872016       1 rbd_util.go:423] ID: 23 Req-ID: pvc-43e3901d-284e-4e21-a4b5-005eb5fff56e rbd: create kube/csi-vol-94c2187c-37da-4bba-9955-bb2a55f9d7fc size 5120M (features: [layering]) using mon 199.19.213.100
I0319 17:55:15.872060       1 rbd_util.go:1563] ID: 23 Req-ID: pvc-43e3901d-284e-4e21-a4b5-005eb5fff56e setting image options on kube/csi-vol-94c2187c-37da-4bba-9955-bb2a55f9d7fc
I0319 17:55:16.965744       1 controllerserver.go:763] ID: 23 Req-ID: pvc-43e3901d-284e-4e21-a4b5-005eb5fff56e created image kube/csi-vol-94c2187c-37da-4bba-9955-bb2a55f9d7fc backed for request name pvc-43e3901d-284e-4e21-a4b5-005eb5fff56e
I0319 17:55:17.003533       1 omap.go:159] ID: 23 Req-ID: pvc-43e3901d-284e-4e21-a4b5-005eb5fff56e set omap keys (pool="kube", namespace="", name="csi.volume.94c2187c-37da-4bba-9955-bb2a55f9d7fc"): map[csi.imageid:37d9d6e239e])
I0319 17:55:17.102921       1 utils.go:205] ID: 23 Req-ID: pvc-43e3901d-284e-4e21-a4b5-005eb5fff56e GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-94c2187c-37da-4bba-9955-bb2a55f9d7fc","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-94c2187c-37da-4bba-9955-bb2a55f9d7fc"}}
I0319 17:55:17.822843       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0319 17:55:17.822902       1 utils.go:199] ID: 24 GRPC request: {}
I0319 17:55:17.822951       1 utils.go:205] ID: 24 GRPC response: {}