I0311 20:32:18.210729       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0311 20:32:18.210862       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0311 20:32:18.211012       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0311 20:32:18.211022       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0311 20:32:18.211025       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0311 20:32:18.211028       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0311 20:32:18.211031       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0311 20:32:18.211035       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0311 20:32:18.211038       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0311 20:32:18.211041       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0311 20:32:18.211337       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0311 20:32:18.211348       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0311 20:32:25.308465       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0311 20:32:25.309761       1 utils.go:199] ID: 1 GRPC request: {}
I0311 20:32:25.309817       1 utils.go:205] ID: 1 GRPC response: {}
I0311 20:32:25.311795       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0311 20:32:25.311840       1 utils.go:199] ID: 2 GRPC request: {}
I0311 20:32:25.311856       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0311 20:32:25.311895       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0311 20:32:25.313152       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0311 20:32:25.313175       1 utils.go:199] ID: 3 GRPC request: {}
I0311 20:32:25.313186       1 utils.go:205] ID: 3 GRPC response: {}
I0311 20:32:25.316182       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0311 20:32:25.316278       1 utils.go:199] ID: 4 GRPC request: {}
I0311 20:32:25.316415       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0311 20:32:25.318109       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0311 20:32:25.318173       1 utils.go:199] ID: 5 GRPC request: {}
I0311 20:32:25.318185       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0311 20:32:25.318290       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}}}]}
I0311 20:32:33.602267       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0311 20:32:33.602298       1 utils.go:199] ID: 6 GRPC request: {}
I0311 20:32:33.602311       1 utils.go:205] ID: 6 GRPC response: {}
I0311 20:32:33.605551       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0311 20:32:33.605566       1 utils.go:199] ID: 7 GRPC request: {}
I0311 20:32:33.605572       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0311 20:32:33.605593       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0311 20:32:33.607578       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0311 20:32:33.607587       1 utils.go:199] ID: 8 GRPC request: {}
I0311 20:32:33.607595       1 utils.go:205] ID: 8 GRPC response: {}
I0311 20:32:33.608237       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0311 20:32:33.608283       1 utils.go:199] ID: 9 GRPC request: {}
I0311 20:32:33.608447       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0311 20:32:33.609404       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0311 20:32:33.609462       1 utils.go:199] ID: 10 GRPC request: {}
I0311 20:32:33.609475       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0311 20:32:33.609631       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}}}]}
I0311 20:32:33.610190       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0311 20:32:33.610218       1 utils.go:199] ID: 11 GRPC request: {}
I0311 20:32:33.610226       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0311 20:32:33.610297       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}}}]}
I0311 20:32:33.610717       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0311 20:32:33.610753       1 utils.go:199] ID: 12 GRPC request: {}
I0311 20:32:33.610772       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0311 20:32:33.610925       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}}}]}
I0311 20:32:35.026688       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0311 20:32:35.026812       1 utils.go:199] ID: 13 GRPC request: {}
I0311 20:32:35.026869       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0311 20:32:35.026959       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0311 20:32:35.028986       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0311 20:32:35.029046       1 utils.go:199] ID: 14 GRPC request: {}
I0311 20:32:35.029086       1 utils.go:205] ID: 14 GRPC response: {}
I0311 20:32:35.029900       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0311 20:32:35.029935       1 utils.go:199] ID: 15 GRPC request: {}
I0311 20:32:35.029956       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0311 20:32:35.030103       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}}}]}
I0311 20:32:36.721528       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0311 20:32:36.721574       1 utils.go:199] ID: 16 GRPC request: {}
I0311 20:32:36.721593       1 utils.go:205] ID: 16 GRPC response: {}
I0311 20:32:36.723287       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0311 20:32:36.723316       1 utils.go:199] ID: 17 GRPC request: {}
I0311 20:32:36.723325       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0311 20:32:36.723350       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0311 20:32:36.726006       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0311 20:32:36.726028       1 utils.go:199] ID: 18 GRPC request: {}
I0311 20:32:36.726046       1 utils.go:205] ID: 18 GRPC response: {}
I0311 20:32:36.726378       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0311 20:32:36.726407       1 utils.go:199] ID: 19 GRPC request: {}
I0311 20:32:36.726494       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0311 20:32:36.727044       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0311 20:32:36.727064       1 utils.go:199] ID: 20 GRPC request: {}
I0311 20:32:36.727074       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0311 20:32:36.727159       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}}}]}
I0311 20:33:36.960305       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0311 20:33:36.960466       1 utils.go:199] ID: 21 GRPC request: {}
I0311 20:33:36.960527       1 utils.go:205] ID: 21 GRPC response: {}
I0311 20:34:36.950227       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0311 20:34:36.950278       1 utils.go:199] ID: 22 GRPC request: {}
I0311 20:34:36.950299       1 utils.go:205] ID: 22 GRPC response: {}
I0311 20:35:21.887290       1 utils.go:198] ID: 23 Req-ID: pvc-5fcc232c-142c-4465-b281-dbaa366b8032 GRPC call: /csi.v1.Controller/CreateVolume
I0311 20:35:21.887877       1 utils.go:199] ID: 23 Req-ID: pvc-5fcc232c-142c-4465-b281-dbaa366b8032 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-5fcc232c-142c-4465-b281-dbaa366b8032","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-5fcc232c-142c-4465-b281-dbaa366b8032","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}}]}
I0311 20:35:21.888209       1 rbd_util.go:1315] ID: 23 Req-ID: pvc-5fcc232c-142c-4465-b281-dbaa366b8032 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0311 20:35:21.907181       1 omap.go:80] ID: 23 Req-ID: pvc-5fcc232c-142c-4465-b281-dbaa366b8032 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0311 20:35:21.924387       1 omap.go:159] ID: 23 Req-ID: pvc-5fcc232c-142c-4465-b281-dbaa366b8032 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-5fcc232c-142c-4465-b281-dbaa366b8032:0b1ccd04-251f-44da-a732-b442f2f46ef1])
I0311 20:35:21.932205       1 omap.go:159] ID: 23 Req-ID: pvc-5fcc232c-142c-4465-b281-dbaa366b8032 set omap keys (pool="kube", namespace="", name="csi.volume.0b1ccd04-251f-44da-a732-b442f2f46ef1"): map[csi.imagename:csi-vol-0b1ccd04-251f-44da-a732-b442f2f46ef1 csi.volname:pvc-5fcc232c-142c-4465-b281-dbaa366b8032 csi.volume.owner:default])
I0311 20:35:21.932242       1 rbd_journal.go:491] ID: 23 Req-ID: pvc-5fcc232c-142c-4465-b281-dbaa366b8032 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-0b1ccd04-251f-44da-a732-b442f2f46ef1) and image name (csi-vol-0b1ccd04-251f-44da-a732-b442f2f46ef1) for request name (pvc-5fcc232c-142c-4465-b281-dbaa366b8032)
I0311 20:35:21.932316       1 rbd_util.go:423] ID: 23 Req-ID: pvc-5fcc232c-142c-4465-b281-dbaa366b8032 rbd: create kube/csi-vol-0b1ccd04-251f-44da-a732-b442f2f46ef1 size 5120M (features: [layering]) using mon 162.253.55.195
I0311 20:35:21.932539       1 rbd_util.go:1563] ID: 23 Req-ID: pvc-5fcc232c-142c-4465-b281-dbaa366b8032 setting image options on kube/csi-vol-0b1ccd04-251f-44da-a732-b442f2f46ef1
I0311 20:35:23.110476       1 controllerserver.go:763] ID: 23 Req-ID: pvc-5fcc232c-142c-4465-b281-dbaa366b8032 created image kube/csi-vol-0b1ccd04-251f-44da-a732-b442f2f46ef1 backed for request name pvc-5fcc232c-142c-4465-b281-dbaa366b8032
I0311 20:35:23.147316       1 omap.go:159] ID: 23 Req-ID: pvc-5fcc232c-142c-4465-b281-dbaa366b8032 set omap keys (pool="kube", namespace="", name="csi.volume.0b1ccd04-251f-44da-a732-b442f2f46ef1"): map[csi.imageid:37d9ca898592])
I0311 20:35:23.244974       1 utils.go:205] ID: 23 Req-ID: pvc-5fcc232c-142c-4465-b281-dbaa366b8032 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-0b1ccd04-251f-44da-a732-b442f2f46ef1","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-0b1ccd04-251f-44da-a732-b442f2f46ef1"}}
I0311 20:35:36.950152       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0311 20:35:36.950204       1 utils.go:199] ID: 24 GRPC request: {}
I0311 20:35:36.950228       1 utils.go:205] ID: 24 GRPC response: {}