I0424 01:27:08.307496       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0424 01:27:08.307615       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0424 01:27:08.307628       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0424 01:27:08.307631       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0424 01:27:08.307634       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0424 01:27:08.307636       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0424 01:27:08.307639       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0424 01:27:08.307642       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0424 01:27:08.307645       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0424 01:27:08.307648       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0424 01:27:08.308063       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0424 01:27:08.308107       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0424 01:27:10.287103       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0424 01:27:10.288391       1 utils.go:199] ID: 1 GRPC request: {}
I0424 01:27:10.288448       1 utils.go:205] ID: 1 GRPC response: {}
I0424 01:27:10.292660       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0424 01:27:10.292871       1 utils.go:199] ID: 2 GRPC request: {}
I0424 01:27:10.292965       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0424 01:27:10.293089       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0424 01:27:10.294608       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0424 01:27:10.294631       1 utils.go:199] ID: 3 GRPC request: {}
I0424 01:27:10.294642       1 utils.go:205] ID: 3 GRPC response: {}
I0424 01:27:10.295053       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0424 01:27:10.295100       1 utils.go:199] ID: 4 GRPC request: {}
I0424 01:27:10.295224       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0424 01:27:10.295929       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0424 01:27:10.295970       1 utils.go:199] ID: 5 GRPC request: {}
I0424 01:27:10.295982       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0424 01:27:10.296071       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}}}]}
I0424 01:27:11.941146       1 utils.go:198] ID: 6 Req-ID: pvc-02c6cc1f-6974-4c55-8154-fad919975931 GRPC call: /csi.v1.Controller/CreateVolume
I0424 01:27:11.941445       1 utils.go:199] ID: 6 Req-ID: pvc-02c6cc1f-6974-4c55-8154-fad919975931 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-02c6cc1f-6974-4c55-8154-fad919975931","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-02c6cc1f-6974-4c55-8154-fad919975931","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}}]}
I0424 01:27:11.941885       1 rbd_util.go:1315] ID: 6 Req-ID: pvc-02c6cc1f-6974-4c55-8154-fad919975931 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0424 01:27:11.963045       1 omap.go:80] ID: 6 Req-ID: pvc-02c6cc1f-6974-4c55-8154-fad919975931 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0424 01:27:12.240876       1 omap.go:159] ID: 6 Req-ID: pvc-02c6cc1f-6974-4c55-8154-fad919975931 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-02c6cc1f-6974-4c55-8154-fad919975931:f3078e23-5468-4be1-87c5-c388749f5358])
I0424 01:27:12.591824       1 omap.go:159] ID: 6 Req-ID: pvc-02c6cc1f-6974-4c55-8154-fad919975931 set omap keys (pool="kube", namespace="", name="csi.volume.f3078e23-5468-4be1-87c5-c388749f5358"): map[csi.imagename:csi-vol-f3078e23-5468-4be1-87c5-c388749f5358 csi.volname:pvc-02c6cc1f-6974-4c55-8154-fad919975931 csi.volume.owner:default])
I0424 01:27:12.591855       1 rbd_journal.go:491] ID: 6 Req-ID: pvc-02c6cc1f-6974-4c55-8154-fad919975931 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-f3078e23-5468-4be1-87c5-c388749f5358) and image name (csi-vol-f3078e23-5468-4be1-87c5-c388749f5358) for request name (pvc-02c6cc1f-6974-4c55-8154-fad919975931)
I0424 01:27:12.591941       1 rbd_util.go:423] ID: 6 Req-ID: pvc-02c6cc1f-6974-4c55-8154-fad919975931 rbd: create kube/csi-vol-f3078e23-5468-4be1-87c5-c388749f5358 size 5120M (features: [layering]) using mon 199.204.45.223
I0424 01:27:12.591978       1 rbd_util.go:1563] ID: 6 Req-ID: pvc-02c6cc1f-6974-4c55-8154-fad919975931 setting image options on kube/csi-vol-f3078e23-5468-4be1-87c5-c388749f5358
I0424 01:27:13.003144       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/Probe
I0424 01:27:13.003196       1 utils.go:199] ID: 7 GRPC request: {}
I0424 01:27:13.003245       1 utils.go:205] ID: 7 GRPC response: {}
I0424 01:27:13.004651       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/GetPluginInfo
I0424 01:27:13.004731       1 utils.go:199] ID: 8 GRPC request: {}
I0424 01:27:13.004780       1 identityserver-default.go:40] ID: 8 Using default GetPluginInfo
I0424 01:27:13.004840       1 utils.go:205] ID: 8 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0424 01:27:13.006918       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/Probe
I0424 01:27:13.006938       1 utils.go:199] ID: 9 GRPC request: {}
I0424 01:27:13.006952       1 utils.go:205] ID: 9 GRPC response: {}
I0424 01:27:13.007469       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0424 01:27:13.007488       1 utils.go:199] ID: 10 GRPC request: {}
I0424 01:27:13.007603       1 utils.go:205] ID: 10 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0424 01:27:13.008127       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0424 01:27:13.008146       1 utils.go:199] ID: 11 GRPC request: {}
I0424 01:27:13.008154       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0424 01:27:13.008233       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}}}]}
I0424 01:27:13.008871       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0424 01:27:13.008894       1 utils.go:199] ID: 12 GRPC request: {}
I0424 01:27:13.008902       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0424 01:27:13.008989       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}}}]}
I0424 01:27:13.010184       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0424 01:27:13.010201       1 utils.go:199] ID: 13 GRPC request: {}
I0424 01:27:13.010208       1 controllerserver-default.go:42] ID: 13 Using default ControllerGetCapabilities
I0424 01:27:13.010269       1 utils.go:205] ID: 13 GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}}]}
I0424 01:27:14.262746       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/GetPluginInfo
I0424 01:27:14.262811       1 utils.go:199] ID: 14 GRPC request: {}
I0424 01:27:14.262821       1 identityserver-default.go:40] ID: 14 Using default GetPluginInfo
I0424 01:27:14.262844       1 utils.go:205] ID: 14 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0424 01:27:14.268333       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Identity/Probe
I0424 01:27:14.268363       1 utils.go:199] ID: 15 GRPC request: {}
I0424 01:27:14.268378       1 utils.go:205] ID: 15 GRPC response: {}
I0424 01:27:14.268915       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0424 01:27:14.268953       1 utils.go:199] ID: 16 GRPC request: {}
I0424 01:27:14.268966       1 controllerserver-default.go:42] ID: 16 Using default ControllerGetCapabilities
I0424 01:27:14.269049       1 utils.go:205] ID: 16 GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}}]}
I0424 01:27:14.292956       1 controllerserver.go:763] ID: 6 Req-ID: pvc-02c6cc1f-6974-4c55-8154-fad919975931 created image kube/csi-vol-f3078e23-5468-4be1-87c5-c388749f5358 backed for request name pvc-02c6cc1f-6974-4c55-8154-fad919975931
I0424 01:27:14.318631       1 omap.go:159] ID: 6 Req-ID: pvc-02c6cc1f-6974-4c55-8154-fad919975931 set omap keys (pool="kube", namespace="", name="csi.volume.f3078e23-5468-4be1-87c5-c388749f5358"): map[csi.imageid:37b5b3451a5d])
I0424 01:27:14.409385       1 utils.go:205] ID: 6 Req-ID: pvc-02c6cc1f-6974-4c55-8154-fad919975931 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-f3078e23-5468-4be1-87c5-c388749f5358","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-f3078e23-5468-4be1-87c5-c388749f5358"}}
I0424 01:27:15.556879       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/Probe
I0424 01:27:15.556923       1 utils.go:199] ID: 17 GRPC request: {}
I0424 01:27:15.557144       1 utils.go:205] ID: 17 GRPC response: {}
I0424 01:27:15.560499       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/GetPluginInfo
I0424 01:27:15.560521       1 utils.go:199] ID: 18 GRPC request: {}
I0424 01:27:15.560528       1 identityserver-default.go:40] ID: 18 Using default GetPluginInfo
I0424 01:27:15.560561       1 utils.go:205] ID: 18 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0424 01:27:15.565299       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/Probe
I0424 01:27:15.565385       1 utils.go:199] ID: 19 GRPC request: {}
I0424 01:27:15.565407       1 utils.go:205] ID: 19 GRPC response: {}
I0424 01:27:15.565987       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0424 01:27:15.566024       1 utils.go:199] ID: 20 GRPC request: {}
I0424 01:27:15.566107       1 utils.go:205] ID: 20 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0424 01:27:15.567251       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0424 01:27:15.567299       1 utils.go:199] ID: 21 GRPC request: {}
I0424 01:27:15.567317       1 controllerserver-default.go:42] ID: 21 Using default ControllerGetCapabilities
I0424 01:27:15.567436       1 utils.go:205] ID: 21 GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}}]}