I0219 02:58:13.443619       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0219 02:58:13.443790       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0219 02:58:13.443818       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0219 02:58:13.443841       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0219 02:58:13.443859       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0219 02:58:13.443875       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0219 02:58:13.443892       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0219 02:58:13.443909       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0219 02:58:13.443933       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0219 02:58:13.443956       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0219 02:58:13.444233       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0219 02:58:13.444243       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0219 02:58:16.299036       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0219 02:58:16.300538       1 utils.go:199] ID: 1 GRPC request: {}
I0219 02:58:16.300698       1 utils.go:205] ID: 1 GRPC response: {}
I0219 02:58:16.302886       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0219 02:58:16.303112       1 utils.go:199] ID: 2 GRPC request: {}
I0219 02:58:16.303121       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0219 02:58:16.303242       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0219 02:58:16.304553       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0219 02:58:16.304587       1 utils.go:199] ID: 3 GRPC request: {}
I0219 02:58:16.304600       1 utils.go:205] ID: 3 GRPC response: {}
I0219 02:58:16.304870       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0219 02:58:16.304971       1 utils.go:199] ID: 4 GRPC request: {}
I0219 02:58:16.305152       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0219 02:58:16.305798       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0219 02:58:16.305837       1 utils.go:199] ID: 5 GRPC request: {}
I0219 02:58:16.306175       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0219 02:58:16.306296       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}}}]}
I0219 02:58:19.854821       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0219 02:58:19.854875       1 utils.go:199] ID: 6 GRPC request: {}
I0219 02:58:19.854891       1 utils.go:205] ID: 6 GRPC response: {}
I0219 02:58:19.857730       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0219 02:58:19.857757       1 utils.go:199] ID: 7 GRPC request: {}
I0219 02:58:19.857768       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0219 02:58:19.857799       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0219 02:58:19.859854       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0219 02:58:19.859874       1 utils.go:199] ID: 8 GRPC request: {}
I0219 02:58:19.859920       1 utils.go:205] ID: 8 GRPC response: {}
I0219 02:58:19.860492       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0219 02:58:19.860651       1 utils.go:199] ID: 9 GRPC request: {}
I0219 02:58:19.860827       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0219 02:58:19.861616       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0219 02:58:19.861638       1 utils.go:199] ID: 10 GRPC request: {}
I0219 02:58:19.861646       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0219 02:58:19.861768       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}}}]}
I0219 02:58:19.862313       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0219 02:58:19.862370       1 utils.go:199] ID: 11 GRPC request: {}
I0219 02:58:19.862393       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0219 02:58:19.862491       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}}}]}
I0219 02:58:19.862867       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0219 02:58:19.862890       1 utils.go:199] ID: 12 GRPC request: {}
I0219 02:58:19.862896       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0219 02:58:19.862991       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}}}]}
I0219 02:58:21.741484       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0219 02:58:21.741525       1 utils.go:199] ID: 13 GRPC request: {}
I0219 02:58:21.741535       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0219 02:58:21.741567       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0219 02:58:21.743563       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0219 02:58:21.743695       1 utils.go:199] ID: 14 GRPC request: {}
I0219 02:58:21.743833       1 utils.go:205] ID: 14 GRPC response: {}
I0219 02:58:21.744286       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0219 02:58:21.744330       1 utils.go:199] ID: 15 GRPC request: {}
I0219 02:58:21.744344       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0219 02:58:21.744482       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}}}]}
I0219 02:58:23.688398       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0219 02:58:23.688449       1 utils.go:199] ID: 16 GRPC request: {}
I0219 02:58:23.688463       1 utils.go:205] ID: 16 GRPC response: {}
I0219 02:58:23.692262       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0219 02:58:23.692332       1 utils.go:199] ID: 17 GRPC request: {}
I0219 02:58:23.692355       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0219 02:58:23.692413       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0219 02:58:23.695077       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0219 02:58:23.695116       1 utils.go:199] ID: 18 GRPC request: {}
I0219 02:58:23.695134       1 utils.go:205] ID: 18 GRPC response: {}
I0219 02:58:23.695735       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0219 02:58:23.695755       1 utils.go:199] ID: 19 GRPC request: {}
I0219 02:58:23.695847       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0219 02:58:23.696652       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0219 02:58:23.696702       1 utils.go:199] ID: 20 GRPC request: {}
I0219 02:58:23.696711       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0219 02:58:23.696825       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}}}]}
I0219 02:59:23.883858       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0219 02:59:23.883915       1 utils.go:199] ID: 21 GRPC request: {}
I0219 02:59:23.883939       1 utils.go:205] ID: 21 GRPC response: {}
I0219 03:00:23.883909       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0219 03:00:23.884153       1 utils.go:199] ID: 22 GRPC request: {}
I0219 03:00:23.884239       1 utils.go:205] ID: 22 GRPC response: {}
I0219 03:01:21.337366       1 utils.go:198] ID: 23 Req-ID: pvc-7e2b96e7-177c-469f-9785-9e73d857cf5f GRPC call: /csi.v1.Controller/CreateVolume
I0219 03:01:21.337789       1 utils.go:199] ID: 23 Req-ID: pvc-7e2b96e7-177c-469f-9785-9e73d857cf5f GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-7e2b96e7-177c-469f-9785-9e73d857cf5f","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-7e2b96e7-177c-469f-9785-9e73d857cf5f","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}}]}
I0219 03:01:21.338085       1 rbd_util.go:1315] ID: 23 Req-ID: pvc-7e2b96e7-177c-469f-9785-9e73d857cf5f setting disableInUseChecks: false image features: [layering] mounter: rbd
E0219 03:01:21.353845       1 omap.go:80] ID: 23 Req-ID: pvc-7e2b96e7-177c-469f-9785-9e73d857cf5f omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0219 03:01:21.371164       1 omap.go:159] ID: 23 Req-ID: pvc-7e2b96e7-177c-469f-9785-9e73d857cf5f set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-7e2b96e7-177c-469f-9785-9e73d857cf5f:7ca1eecf-dd1c-4da4-9f0d-f1d1c2334578])
I0219 03:01:21.377375       1 omap.go:159] ID: 23 Req-ID: pvc-7e2b96e7-177c-469f-9785-9e73d857cf5f set omap keys (pool="kube", namespace="", name="csi.volume.7ca1eecf-dd1c-4da4-9f0d-f1d1c2334578"): map[csi.imagename:csi-vol-7ca1eecf-dd1c-4da4-9f0d-f1d1c2334578 csi.volname:pvc-7e2b96e7-177c-469f-9785-9e73d857cf5f csi.volume.owner:default])
I0219 03:01:21.377408       1 rbd_journal.go:491] ID: 23 Req-ID: pvc-7e2b96e7-177c-469f-9785-9e73d857cf5f generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-7ca1eecf-dd1c-4da4-9f0d-f1d1c2334578) and image name (csi-vol-7ca1eecf-dd1c-4da4-9f0d-f1d1c2334578) for request name (pvc-7e2b96e7-177c-469f-9785-9e73d857cf5f)
I0219 03:01:21.377576       1 rbd_util.go:423] ID: 23 Req-ID: pvc-7e2b96e7-177c-469f-9785-9e73d857cf5f rbd: create kube/csi-vol-7ca1eecf-dd1c-4da4-9f0d-f1d1c2334578 size 5120M (features: [layering]) using mon 199.19.213.203
I0219 03:01:21.377699       1 rbd_util.go:1563] ID: 23 Req-ID: pvc-7e2b96e7-177c-469f-9785-9e73d857cf5f setting image options on kube/csi-vol-7ca1eecf-dd1c-4da4-9f0d-f1d1c2334578
I0219 03:01:22.788767       1 controllerserver.go:763] ID: 23 Req-ID: pvc-7e2b96e7-177c-469f-9785-9e73d857cf5f created image kube/csi-vol-7ca1eecf-dd1c-4da4-9f0d-f1d1c2334578 backed for request name pvc-7e2b96e7-177c-469f-9785-9e73d857cf5f
I0219 03:01:22.825278       1 omap.go:159] ID: 23 Req-ID: pvc-7e2b96e7-177c-469f-9785-9e73d857cf5f set omap keys (pool="kube", namespace="", name="csi.volume.7ca1eecf-dd1c-4da4-9f0d-f1d1c2334578"): map[csi.imageid:37d881c290a4])
I0219 03:01:22.960529       1 utils.go:205] ID: 23 Req-ID: pvc-7e2b96e7-177c-469f-9785-9e73d857cf5f GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-7ca1eecf-dd1c-4da4-9f0d-f1d1c2334578","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-7ca1eecf-dd1c-4da4-9f0d-f1d1c2334578"}}
I0219 03:01:23.883244       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0219 03:01:23.883296       1 utils.go:199] ID: 24 GRPC request: {}
I0219 03:01:23.883320       1 utils.go:205] ID: 24 GRPC response: {}