I0212 17:06:52.210768       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0212 17:06:52.210954       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0212 17:06:52.211046       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0212 17:06:52.211052       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0212 17:06:52.211055       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0212 17:06:52.211057       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0212 17:06:52.211061       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0212 17:06:52.211063       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0212 17:06:52.211066       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0212 17:06:52.211069       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0212 17:06:52.211510       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0212 17:06:52.211629       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0212 17:07:06.973511       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0212 17:07:06.976316       1 utils.go:199] ID: 1 GRPC request: {}
I0212 17:07:06.976537       1 utils.go:205] ID: 1 GRPC response: {}
I0212 17:07:06.978606       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0212 17:07:06.978662       1 utils.go:199] ID: 2 GRPC request: {}
I0212 17:07:06.978680       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0212 17:07:06.979990       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0212 17:07:06.981338       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0212 17:07:06.981364       1 utils.go:199] ID: 3 GRPC request: {}
I0212 17:07:06.981373       1 utils.go:205] ID: 3 GRPC response: {}
I0212 17:07:06.983047       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0212 17:07:06.983166       1 utils.go:199] ID: 4 GRPC request: {}
I0212 17:07:06.983472       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0212 17:07:06.984455       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0212 17:07:06.984541       1 utils.go:199] ID: 5 GRPC request: {}
I0212 17:07:06.984551       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0212 17:07:06.984698       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}}}]}
I0212 17:07:10.673808       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0212 17:07:10.673855       1 utils.go:199] ID: 6 GRPC request: {}
I0212 17:07:10.673873       1 utils.go:205] ID: 6 GRPC response: {}
I0212 17:07:10.676078       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0212 17:07:10.676120       1 utils.go:199] ID: 7 GRPC request: {}
I0212 17:07:10.676135       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0212 17:07:10.676163       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0212 17:07:10.677304       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0212 17:07:10.677368       1 utils.go:199] ID: 8 GRPC request: {}
I0212 17:07:10.677382       1 utils.go:205] ID: 8 GRPC response: {}
I0212 17:07:10.677681       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0212 17:07:10.677695       1 utils.go:199] ID: 9 GRPC request: {}
I0212 17:07:10.677782       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0212 17:07:10.678442       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0212 17:07:10.678461       1 utils.go:199] ID: 10 GRPC request: {}
I0212 17:07:10.678467       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0212 17:07:10.678510       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}}}]}
I0212 17:07:10.694460       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0212 17:07:10.694478       1 utils.go:199] ID: 11 GRPC request: {}
I0212 17:07:10.694488       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0212 17:07:10.694544       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}}}]}
I0212 17:07:10.694826       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0212 17:07:10.694856       1 utils.go:199] ID: 12 GRPC request: {}
I0212 17:07:10.694864       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0212 17:07:10.694903       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}}}]}
I0212 17:07:19.327977       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0212 17:07:19.328139       1 utils.go:199] ID: 13 GRPC request: {}
I0212 17:07:19.328205       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0212 17:07:19.328315       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0212 17:07:19.338466       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0212 17:07:19.339519       1 utils.go:199] ID: 14 GRPC request: {}
I0212 17:07:19.339543       1 utils.go:205] ID: 14 GRPC response: {}
I0212 17:07:19.340862       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0212 17:07:19.340882       1 utils.go:199] ID: 15 GRPC request: {}
I0212 17:07:19.340892       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0212 17:07:19.342138       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}}}]}
I0212 17:07:27.679594       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0212 17:07:27.679659       1 utils.go:199] ID: 16 GRPC request: {}
I0212 17:07:27.679683       1 utils.go:205] ID: 16 GRPC response: {}
I0212 17:07:27.701350       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0212 17:07:27.701382       1 utils.go:199] ID: 17 GRPC request: {}
I0212 17:07:27.701598       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0212 17:07:27.701668       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0212 17:07:27.710404       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0212 17:07:27.710435       1 utils.go:199] ID: 18 GRPC request: {}
I0212 17:07:27.710447       1 utils.go:205] ID: 18 GRPC response: {}
I0212 17:07:27.712899       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0212 17:07:27.712929       1 utils.go:199] ID: 19 GRPC request: {}
I0212 17:07:27.713035       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0212 17:07:27.714299       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0212 17:07:27.714313       1 utils.go:199] ID: 20 GRPC request: {}
I0212 17:07:27.714320       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0212 17:07:27.714365       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}}}]}
I0212 17:08:28.067601       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0212 17:08:28.067900       1 utils.go:199] ID: 21 GRPC request: {}
I0212 17:08:28.067972       1 utils.go:205] ID: 21 GRPC response: {}
I0212 17:09:28.022695       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0212 17:09:28.022733       1 utils.go:199] ID: 22 GRPC request: {}
I0212 17:09:28.022748       1 utils.go:205] ID: 22 GRPC response: {}
I0212 17:10:28.008135       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0212 17:10:28.008186       1 utils.go:199] ID: 23 GRPC request: {}
I0212 17:10:28.008209       1 utils.go:205] ID: 23 GRPC response: {}
I0212 17:10:31.159108       1 utils.go:198] ID: 24 Req-ID: pvc-48ae8f04-ae5b-4dc6-a936-47f8c6cb7dea GRPC call: /csi.v1.Controller/CreateVolume
I0212 17:10:31.159580       1 utils.go:199] ID: 24 Req-ID: pvc-48ae8f04-ae5b-4dc6-a936-47f8c6cb7dea GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-48ae8f04-ae5b-4dc6-a936-47f8c6cb7dea","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-48ae8f04-ae5b-4dc6-a936-47f8c6cb7dea","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}}]}
I0212 17:10:31.160049       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-48ae8f04-ae5b-4dc6-a936-47f8c6cb7dea setting disableInUseChecks: false image features: [layering] mounter: rbd
E0212 17:10:31.189886       1 omap.go:80] ID: 24 Req-ID: pvc-48ae8f04-ae5b-4dc6-a936-47f8c6cb7dea omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0212 17:10:31.208830       1 omap.go:159] ID: 24 Req-ID: pvc-48ae8f04-ae5b-4dc6-a936-47f8c6cb7dea set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-48ae8f04-ae5b-4dc6-a936-47f8c6cb7dea:2d564dff-fd68-4794-8b1a-a7750ee49dcb])
I0212 17:10:31.216871       1 omap.go:159] ID: 24 Req-ID: pvc-48ae8f04-ae5b-4dc6-a936-47f8c6cb7dea set omap keys (pool="kube", namespace="", name="csi.volume.2d564dff-fd68-4794-8b1a-a7750ee49dcb"): map[csi.imagename:csi-vol-2d564dff-fd68-4794-8b1a-a7750ee49dcb csi.volname:pvc-48ae8f04-ae5b-4dc6-a936-47f8c6cb7dea csi.volume.owner:default])
I0212 17:10:31.217070       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-48ae8f04-ae5b-4dc6-a936-47f8c6cb7dea generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-2d564dff-fd68-4794-8b1a-a7750ee49dcb) and image name (csi-vol-2d564dff-fd68-4794-8b1a-a7750ee49dcb) for request name (pvc-48ae8f04-ae5b-4dc6-a936-47f8c6cb7dea)
I0212 17:10:31.217227       1 rbd_util.go:423] ID: 24 Req-ID: pvc-48ae8f04-ae5b-4dc6-a936-47f8c6cb7dea rbd: create kube/csi-vol-2d564dff-fd68-4794-8b1a-a7750ee49dcb size 5120M (features: [layering]) using mon 199.19.213.115
I0212 17:10:31.217357       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-48ae8f04-ae5b-4dc6-a936-47f8c6cb7dea setting image options on kube/csi-vol-2d564dff-fd68-4794-8b1a-a7750ee49dcb
I0212 17:10:32.478556       1 controllerserver.go:763] ID: 24 Req-ID: pvc-48ae8f04-ae5b-4dc6-a936-47f8c6cb7dea created image kube/csi-vol-2d564dff-fd68-4794-8b1a-a7750ee49dcb backed for request name pvc-48ae8f04-ae5b-4dc6-a936-47f8c6cb7dea
I0212 17:10:32.530918       1 omap.go:159] ID: 24 Req-ID: pvc-48ae8f04-ae5b-4dc6-a936-47f8c6cb7dea set omap keys (pool="kube", namespace="", name="csi.volume.2d564dff-fd68-4794-8b1a-a7750ee49dcb"): map[csi.imageid:37d6a288675e])
I0212 17:10:32.656400       1 utils.go:205] ID: 24 Req-ID: pvc-48ae8f04-ae5b-4dc6-a936-47f8c6cb7dea GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-2d564dff-fd68-4794-8b1a-a7750ee49dcb","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-2d564dff-fd68-4794-8b1a-a7750ee49dcb"}}
I0212 17:11:28.050390       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0212 17:11:28.050440       1 utils.go:199] ID: 25 GRPC request: {}
I0212 17:11:28.050716       1 utils.go:205] ID: 25 GRPC response: {}