I0715 09:51:28.185050       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0715 09:51:28.185152       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0715 09:51:28.185165       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0715 09:51:28.185169       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0715 09:51:28.185173       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0715 09:51:28.185180       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0715 09:51:28.185184       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0715 09:51:28.185189       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0715 09:51:28.185193       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0715 09:51:28.185196       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0715 09:51:28.185509       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0715 09:51:28.185602       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0715 09:51:32.401970       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0715 09:51:32.403194       1 utils.go:199] ID: 1 GRPC request: {}
I0715 09:51:32.403301       1 utils.go:205] ID: 1 GRPC response: {}
I0715 09:51:32.406664       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0715 09:51:32.406845       1 utils.go:199] ID: 2 GRPC request: {}
I0715 09:51:32.406873       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0715 09:51:32.407077       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0715 09:51:32.408587       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0715 09:51:32.408644       1 utils.go:199] ID: 3 GRPC request: {}
I0715 09:51:32.408667       1 utils.go:205] ID: 3 GRPC response: {}
I0715 09:51:32.409080       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0715 09:51:32.409297       1 utils.go:199] ID: 4 GRPC request: {}
I0715 09:51:32.409566       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0715 09:51:32.410375       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0715 09:51:32.410435       1 utils.go:199] ID: 5 GRPC request: {}
I0715 09:51:32.410454       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0715 09:51:32.410557       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}}}]}
I0715 09:51:33.930648       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0715 09:51:33.930682       1 utils.go:199] ID: 6 GRPC request: {}
I0715 09:51:33.930701       1 utils.go:205] ID: 6 GRPC response: {}
I0715 09:51:33.933621       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0715 09:51:33.933682       1 utils.go:199] ID: 7 GRPC request: {}
I0715 09:51:33.933694       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0715 09:51:33.933726       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0715 09:51:33.938905       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0715 09:51:33.941074       1 utils.go:199] ID: 8 GRPC request: {}
I0715 09:51:33.941225       1 utils.go:205] ID: 8 GRPC response: {}
I0715 09:51:33.942102       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0715 09:51:33.942129       1 utils.go:199] ID: 9 GRPC request: {}
I0715 09:51:33.942217       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0715 09:51:33.942955       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0715 09:51:33.943030       1 utils.go:199] ID: 10 GRPC request: {}
I0715 09:51:33.943138       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0715 09:51:33.943462       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}}}]}
I0715 09:51:33.944708       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0715 09:51:33.944727       1 utils.go:199] ID: 11 GRPC request: {}
I0715 09:51:33.944733       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0715 09:51:33.944786       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}}}]}
I0715 09:51:33.945438       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0715 09:51:33.945456       1 utils.go:199] ID: 12 GRPC request: {}
I0715 09:51:33.945464       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0715 09:51:33.945544       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}}}]}
I0715 09:51:35.450760       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0715 09:51:35.450810       1 utils.go:199] ID: 13 GRPC request: {}
I0715 09:51:35.450823       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0715 09:51:35.450902       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0715 09:51:35.456089       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0715 09:51:35.456134       1 utils.go:199] ID: 14 GRPC request: {}
I0715 09:51:35.456161       1 utils.go:205] ID: 14 GRPC response: {}
I0715 09:51:35.458085       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0715 09:51:35.458128       1 utils.go:199] ID: 15 GRPC request: {}
I0715 09:51:35.458140       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0715 09:51:35.458265       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}}}]}
I0715 09:51:36.933983       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0715 09:51:36.934020       1 utils.go:199] ID: 16 GRPC request: {}
I0715 09:51:36.934045       1 utils.go:205] ID: 16 GRPC response: {}
I0715 09:51:36.938573       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0715 09:51:36.938668       1 utils.go:199] ID: 17 GRPC request: {}
I0715 09:51:36.938703       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0715 09:51:36.938756       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0715 09:51:36.941860       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0715 09:51:36.941889       1 utils.go:199] ID: 18 GRPC request: {}
I0715 09:51:36.941904       1 utils.go:205] ID: 18 GRPC response: {}
I0715 09:51:36.942320       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0715 09:51:36.942358       1 utils.go:199] ID: 19 GRPC request: {}
I0715 09:51:36.942703       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0715 09:51:36.943493       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0715 09:51:36.943693       1 utils.go:199] ID: 20 GRPC request: {}
I0715 09:51:36.943820       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0715 09:51:36.944082       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}}}]}
I0715 09:52:37.119992       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0715 09:52:37.120041       1 utils.go:199] ID: 21 GRPC request: {}
I0715 09:52:37.120062       1 utils.go:205] ID: 21 GRPC response: {}
I0715 09:53:37.121887       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0715 09:53:37.121942       1 utils.go:199] ID: 22 GRPC request: {}
I0715 09:53:37.121964       1 utils.go:205] ID: 22 GRPC response: {}
I0715 09:54:37.119941       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0715 09:54:37.120003       1 utils.go:199] ID: 23 GRPC request: {}
I0715 09:54:37.120032       1 utils.go:205] ID: 23 GRPC response: {}
I0715 09:55:37.130235       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0715 09:55:37.130280       1 utils.go:199] ID: 24 GRPC request: {}
I0715 09:55:37.130302       1 utils.go:205] ID: 24 GRPC response: {}
I0715 09:55:48.151714       1 utils.go:198] ID: 25 Req-ID: pvc-3be2fd6e-c671-4b57-b3d5-96875adececb GRPC call: /csi.v1.Controller/CreateVolume
I0715 09:55:48.152525       1 utils.go:199] ID: 25 Req-ID: pvc-3be2fd6e-c671-4b57-b3d5-96875adececb GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-3be2fd6e-c671-4b57-b3d5-96875adececb","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-3be2fd6e-c671-4b57-b3d5-96875adececb","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}}]}
I0715 09:55:48.152832       1 rbd_util.go:1315] ID: 25 Req-ID: pvc-3be2fd6e-c671-4b57-b3d5-96875adececb setting disableInUseChecks: false image features: [layering] mounter: rbd
E0715 09:55:48.171463       1 omap.go:80] ID: 25 Req-ID: pvc-3be2fd6e-c671-4b57-b3d5-96875adececb omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0715 09:55:48.189530       1 omap.go:159] ID: 25 Req-ID: pvc-3be2fd6e-c671-4b57-b3d5-96875adececb set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-3be2fd6e-c671-4b57-b3d5-96875adececb:ebda131b-61d1-4866-91ba-7d2413716401])
I0715 09:55:48.199582       1 omap.go:159] ID: 25 Req-ID: pvc-3be2fd6e-c671-4b57-b3d5-96875adececb set omap keys (pool="kube", namespace="", name="csi.volume.ebda131b-61d1-4866-91ba-7d2413716401"): map[csi.imagename:csi-vol-ebda131b-61d1-4866-91ba-7d2413716401 csi.volname:pvc-3be2fd6e-c671-4b57-b3d5-96875adececb csi.volume.owner:default])
I0715 09:55:48.199624       1 rbd_journal.go:491] ID: 25 Req-ID: pvc-3be2fd6e-c671-4b57-b3d5-96875adececb generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-ebda131b-61d1-4866-91ba-7d2413716401) and image name (csi-vol-ebda131b-61d1-4866-91ba-7d2413716401) for request name (pvc-3be2fd6e-c671-4b57-b3d5-96875adececb)
I0715 09:55:48.199730       1 rbd_util.go:423] ID: 25 Req-ID: pvc-3be2fd6e-c671-4b57-b3d5-96875adececb rbd: create kube/csi-vol-ebda131b-61d1-4866-91ba-7d2413716401 size 5120M (features: [layering]) using mon 199.19.213.102
I0715 09:55:48.199835       1 rbd_util.go:1563] ID: 25 Req-ID: pvc-3be2fd6e-c671-4b57-b3d5-96875adececb setting image options on kube/csi-vol-ebda131b-61d1-4866-91ba-7d2413716401
I0715 09:55:48.232705       1 controllerserver.go:763] ID: 25 Req-ID: pvc-3be2fd6e-c671-4b57-b3d5-96875adececb created image kube/csi-vol-ebda131b-61d1-4866-91ba-7d2413716401 backed for request name pvc-3be2fd6e-c671-4b57-b3d5-96875adececb
I0715 09:55:48.265830       1 omap.go:159] ID: 25 Req-ID: pvc-3be2fd6e-c671-4b57-b3d5-96875adececb set omap keys (pool="kube", namespace="", name="csi.volume.ebda131b-61d1-4866-91ba-7d2413716401"): map[csi.imageid:37f4a7e12985])
I0715 09:55:48.351824       1 utils.go:205] ID: 25 Req-ID: pvc-3be2fd6e-c671-4b57-b3d5-96875adececb GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-ebda131b-61d1-4866-91ba-7d2413716401","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-ebda131b-61d1-4866-91ba-7d2413716401"}}