I0922 02:08:57.363369       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0922 02:08:57.363484       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0922 02:08:57.363498       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0922 02:08:57.363504       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0922 02:08:57.363507       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0922 02:08:57.363511       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0922 02:08:57.363518       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0922 02:08:57.363521       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0922 02:08:57.363524       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0922 02:08:57.363527       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0922 02:08:57.364045       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0922 02:08:57.364148       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0922 02:09:00.744216       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0922 02:09:00.745981       1 utils.go:199] ID: 1 GRPC request: {}
I0922 02:09:00.746127       1 utils.go:205] ID: 1 GRPC response: {}
I0922 02:09:00.749473       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0922 02:09:00.749529       1 utils.go:199] ID: 2 GRPC request: {}
I0922 02:09:00.749543       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0922 02:09:00.749574       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0922 02:09:00.751810       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0922 02:09:00.751824       1 utils.go:199] ID: 3 GRPC request: {}
I0922 02:09:00.751832       1 utils.go:205] ID: 3 GRPC response: {}
I0922 02:09:00.752404       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0922 02:09:00.752455       1 utils.go:199] ID: 4 GRPC request: {}
I0922 02:09:00.752563       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0922 02:09:00.753637       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0922 02:09:00.753741       1 utils.go:199] ID: 5 GRPC request: {}
I0922 02:09:00.753783       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0922 02:09:00.753973       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}}}]}
I0922 02:09:02.491221       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0922 02:09:02.491265       1 utils.go:199] ID: 6 GRPC request: {}
I0922 02:09:02.491382       1 utils.go:205] ID: 6 GRPC response: {}
I0922 02:09:02.494860       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0922 02:09:02.494958       1 utils.go:199] ID: 7 GRPC request: {}
I0922 02:09:02.494992       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0922 02:09:02.495091       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0922 02:09:02.498117       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0922 02:09:02.498152       1 utils.go:199] ID: 8 GRPC request: {}
I0922 02:09:02.498168       1 utils.go:205] ID: 8 GRPC response: {}
I0922 02:09:02.498800       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0922 02:09:02.498846       1 utils.go:199] ID: 9 GRPC request: {}
I0922 02:09:02.498965       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0922 02:09:02.500106       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0922 02:09:02.500169       1 utils.go:199] ID: 10 GRPC request: {}
I0922 02:09:02.500215       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0922 02:09:02.500479       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}}}]}
I0922 02:09:02.501638       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0922 02:09:02.501670       1 utils.go:199] ID: 11 GRPC request: {}
I0922 02:09:02.501682       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0922 02:09:02.501787       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}}}]}
I0922 02:09:02.503731       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0922 02:09:02.503789       1 utils.go:199] ID: 12 GRPC request: {}
I0922 02:09:02.503802       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0922 02:09:02.503948       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}}}]}
I0922 02:09:04.030666       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0922 02:09:04.031226       1 utils.go:199] ID: 13 GRPC request: {}
I0922 02:09:04.031290       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0922 02:09:04.031453       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0922 02:09:04.033944       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0922 02:09:04.033991       1 utils.go:199] ID: 14 GRPC request: {}
I0922 02:09:04.034026       1 utils.go:205] ID: 14 GRPC response: {}
I0922 02:09:04.034611       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0922 02:09:04.034634       1 utils.go:199] ID: 15 GRPC request: {}
I0922 02:09:04.034644       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0922 02:09:04.034743       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}}}]}
I0922 02:09:05.495189       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0922 02:09:05.495259       1 utils.go:199] ID: 16 GRPC request: {}
I0922 02:09:05.495287       1 utils.go:205] ID: 16 GRPC response: {}
I0922 02:09:05.498720       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0922 02:09:05.498789       1 utils.go:199] ID: 17 GRPC request: {}
I0922 02:09:05.498820       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0922 02:09:05.498858       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0922 02:09:05.500508       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0922 02:09:05.500545       1 utils.go:199] ID: 18 GRPC request: {}
I0922 02:09:05.500565       1 utils.go:205] ID: 18 GRPC response: {}
I0922 02:09:05.500978       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0922 02:09:05.501009       1 utils.go:199] ID: 19 GRPC request: {}
I0922 02:09:05.501282       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0922 02:09:05.501902       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0922 02:09:05.502110       1 utils.go:199] ID: 20 GRPC request: {}
I0922 02:09:05.502254       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0922 02:09:05.502466       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}}}]}
I0922 02:10:05.697715       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0922 02:10:05.697763       1 utils.go:199] ID: 21 GRPC request: {}
I0922 02:10:05.697865       1 utils.go:205] ID: 21 GRPC response: {}
I0922 02:11:05.698698       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0922 02:11:05.698808       1 utils.go:199] ID: 22 GRPC request: {}
I0922 02:11:05.698867       1 utils.go:205] ID: 22 GRPC response: {}
I0922 02:12:05.697251       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0922 02:12:05.697314       1 utils.go:199] ID: 23 GRPC request: {}
I0922 02:12:05.697338       1 utils.go:205] ID: 23 GRPC response: {}
I0922 02:13:05.711089       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0922 02:13:05.711301       1 utils.go:199] ID: 24 GRPC request: {}
I0922 02:13:05.711387       1 utils.go:205] ID: 24 GRPC response: {}
I0922 02:13:39.012873       1 utils.go:198] ID: 25 Req-ID: pvc-c0b2c9e4-b9df-40db-9f00-658f249866e5 GRPC call: /csi.v1.Controller/CreateVolume
I0922 02:13:39.013479       1 utils.go:199] ID: 25 Req-ID: pvc-c0b2c9e4-b9df-40db-9f00-658f249866e5 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-c0b2c9e4-b9df-40db-9f00-658f249866e5","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-c0b2c9e4-b9df-40db-9f00-658f249866e5","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}}]}
I0922 02:13:39.013866       1 rbd_util.go:1315] ID: 25 Req-ID: pvc-c0b2c9e4-b9df-40db-9f00-658f249866e5 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0922 02:13:39.039337       1 omap.go:80] ID: 25 Req-ID: pvc-c0b2c9e4-b9df-40db-9f00-658f249866e5 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0922 02:13:39.057174       1 omap.go:159] ID: 25 Req-ID: pvc-c0b2c9e4-b9df-40db-9f00-658f249866e5 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-c0b2c9e4-b9df-40db-9f00-658f249866e5:46181641-c0d1-4d41-9045-0432c2d66c91])
I0922 02:13:39.068689       1 omap.go:159] ID: 25 Req-ID: pvc-c0b2c9e4-b9df-40db-9f00-658f249866e5 set omap keys (pool="kube", namespace="", name="csi.volume.46181641-c0d1-4d41-9045-0432c2d66c91"): map[csi.imagename:csi-vol-46181641-c0d1-4d41-9045-0432c2d66c91 csi.volname:pvc-c0b2c9e4-b9df-40db-9f00-658f249866e5 csi.volume.owner:default])
I0922 02:13:39.068773       1 rbd_journal.go:491] ID: 25 Req-ID: pvc-c0b2c9e4-b9df-40db-9f00-658f249866e5 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-46181641-c0d1-4d41-9045-0432c2d66c91) and image name (csi-vol-46181641-c0d1-4d41-9045-0432c2d66c91) for request name (pvc-c0b2c9e4-b9df-40db-9f00-658f249866e5)
I0922 02:13:39.068947       1 rbd_util.go:423] ID: 25 Req-ID: pvc-c0b2c9e4-b9df-40db-9f00-658f249866e5 rbd: create kube/csi-vol-46181641-c0d1-4d41-9045-0432c2d66c91 size 5120M (features: [layering]) using mon 162.253.55.153
I0922 02:13:39.068988       1 rbd_util.go:1563] ID: 25 Req-ID: pvc-c0b2c9e4-b9df-40db-9f00-658f249866e5 setting image options on kube/csi-vol-46181641-c0d1-4d41-9045-0432c2d66c91
I0922 02:13:39.105232       1 controllerserver.go:763] ID: 25 Req-ID: pvc-c0b2c9e4-b9df-40db-9f00-658f249866e5 created image kube/csi-vol-46181641-c0d1-4d41-9045-0432c2d66c91 backed for request name pvc-c0b2c9e4-b9df-40db-9f00-658f249866e5
I0922 02:13:39.138930       1 omap.go:159] ID: 25 Req-ID: pvc-c0b2c9e4-b9df-40db-9f00-658f249866e5 set omap keys (pool="kube", namespace="", name="csi.volume.46181641-c0d1-4d41-9045-0432c2d66c91"): map[csi.imageid:37f4b27a6275])
I0922 02:13:39.236366       1 utils.go:205] ID: 25 Req-ID: pvc-c0b2c9e4-b9df-40db-9f00-658f249866e5 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-46181641-c0d1-4d41-9045-0432c2d66c91","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-46181641-c0d1-4d41-9045-0432c2d66c91"}}
I0922 02:14:05.752028       1 utils.go:198] ID: 26 GRPC call: /csi.v1.Identity/Probe
I0922 02:14:05.752076       1 utils.go:199] ID: 26 GRPC request: {}
I0922 02:14:05.752098       1 utils.go:205] ID: 26 GRPC response: {}