I0520 11:31:53.670719       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0520 11:31:53.670889       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0520 11:31:53.670914       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0520 11:31:53.670919       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0520 11:31:53.670923       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0520 11:31:53.670930       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0520 11:31:53.670937       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0520 11:31:53.670946       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0520 11:31:53.670951       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0520 11:31:53.670955       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0520 11:31:53.671347       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0520 11:31:53.671410       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0520 11:31:58.516238       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0520 11:31:58.518305       1 utils.go:199] ID: 1 GRPC request: {}
I0520 11:31:58.518428       1 utils.go:205] ID: 1 GRPC response: {}
I0520 11:31:58.521595       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0520 11:31:58.521749       1 utils.go:199] ID: 2 GRPC request: {}
I0520 11:31:58.521779       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0520 11:31:58.521851       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0520 11:31:58.524487       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0520 11:31:58.524523       1 utils.go:199] ID: 3 GRPC request: {}
I0520 11:31:58.524546       1 utils.go:205] ID: 3 GRPC response: {}
I0520 11:31:58.525648       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0520 11:31:58.525717       1 utils.go:199] ID: 4 GRPC request: {}
I0520 11:31:58.526086       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0520 11:31:58.528439       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0520 11:31:58.528582       1 utils.go:199] ID: 5 GRPC request: {}
I0520 11:31:58.528597       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0520 11:31:58.528807       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}}}]}
I0520 11:32:00.659321       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0520 11:32:00.659424       1 utils.go:199] ID: 6 GRPC request: {}
I0520 11:32:00.659482       1 utils.go:205] ID: 6 GRPC response: {}
I0520 11:32:00.663539       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0520 11:32:00.663579       1 utils.go:199] ID: 7 GRPC request: {}
I0520 11:32:00.663664       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0520 11:32:00.663743       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0520 11:32:00.666322       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0520 11:32:00.666353       1 utils.go:199] ID: 8 GRPC request: {}
I0520 11:32:00.666404       1 utils.go:205] ID: 8 GRPC response: {}
I0520 11:32:00.667041       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0520 11:32:00.667091       1 utils.go:199] ID: 9 GRPC request: {}
I0520 11:32:00.667223       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0520 11:32:00.668232       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0520 11:32:00.668254       1 utils.go:199] ID: 10 GRPC request: {}
I0520 11:32:00.668262       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0520 11:32:00.668408       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}}}]}
I0520 11:32:00.669078       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0520 11:32:00.669128       1 utils.go:199] ID: 11 GRPC request: {}
I0520 11:32:00.669138       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0520 11:32:00.669246       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}}}]}
I0520 11:32:00.669596       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0520 11:32:00.669612       1 utils.go:199] ID: 12 GRPC request: {}
I0520 11:32:00.669616       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0520 11:32:00.669690       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}}}]}
I0520 11:32:02.161669       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0520 11:32:02.161729       1 utils.go:199] ID: 13 GRPC request: {}
I0520 11:32:02.161740       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0520 11:32:02.161778       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0520 11:32:02.164812       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0520 11:32:02.164864       1 utils.go:199] ID: 14 GRPC request: {}
I0520 11:32:02.164887       1 utils.go:205] ID: 14 GRPC response: {}
I0520 11:32:02.166030       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0520 11:32:02.166053       1 utils.go:199] ID: 15 GRPC request: {}
I0520 11:32:02.166063       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0520 11:32:02.166166       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}}}]}
I0520 11:32:05.526825       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0520 11:32:05.526890       1 utils.go:199] ID: 16 GRPC request: {}
I0520 11:32:05.526918       1 utils.go:205] ID: 16 GRPC response: {}
I0520 11:32:05.529836       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0520 11:32:05.529859       1 utils.go:199] ID: 17 GRPC request: {}
I0520 11:32:05.529869       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0520 11:32:05.529898       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0520 11:32:05.532308       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0520 11:32:05.532370       1 utils.go:199] ID: 18 GRPC request: {}
I0520 11:32:05.532399       1 utils.go:205] ID: 18 GRPC response: {}
I0520 11:32:05.532945       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0520 11:32:05.532993       1 utils.go:199] ID: 19 GRPC request: {}
I0520 11:32:05.533094       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0520 11:32:05.533755       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0520 11:32:05.533772       1 utils.go:199] ID: 20 GRPC request: {}
I0520 11:32:05.533782       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0520 11:32:05.533835       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}}}]}
I0520 11:33:05.717452       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0520 11:33:05.717620       1 utils.go:199] ID: 21 GRPC request: {}
I0520 11:33:05.717698       1 utils.go:205] ID: 21 GRPC response: {}
I0520 11:34:05.718474       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0520 11:34:05.718650       1 utils.go:199] ID: 22 GRPC request: {}
I0520 11:34:05.718834       1 utils.go:205] ID: 22 GRPC response: {}
I0520 11:35:05.715863       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0520 11:35:05.715949       1 utils.go:199] ID: 23 GRPC request: {}
I0520 11:35:05.715980       1 utils.go:205] ID: 23 GRPC response: {}
I0520 11:35:47.354283       1 utils.go:198] ID: 24 Req-ID: pvc-bdca82d6-374d-4cf5-b082-1b42c45ad208 GRPC call: /csi.v1.Controller/CreateVolume
I0520 11:35:47.354673       1 utils.go:199] ID: 24 Req-ID: pvc-bdca82d6-374d-4cf5-b082-1b42c45ad208 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-bdca82d6-374d-4cf5-b082-1b42c45ad208","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-bdca82d6-374d-4cf5-b082-1b42c45ad208","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}}]}
I0520 11:35:47.354917       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-bdca82d6-374d-4cf5-b082-1b42c45ad208 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0520 11:35:47.374608       1 omap.go:80] ID: 24 Req-ID: pvc-bdca82d6-374d-4cf5-b082-1b42c45ad208 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0520 11:35:47.389232       1 omap.go:159] ID: 24 Req-ID: pvc-bdca82d6-374d-4cf5-b082-1b42c45ad208 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-bdca82d6-374d-4cf5-b082-1b42c45ad208:d3746b3a-68f7-4a41-bd25-229b9a9d26b8])
I0520 11:35:47.397988       1 omap.go:159] ID: 24 Req-ID: pvc-bdca82d6-374d-4cf5-b082-1b42c45ad208 set omap keys (pool="kube", namespace="", name="csi.volume.d3746b3a-68f7-4a41-bd25-229b9a9d26b8"): map[csi.imagename:csi-vol-d3746b3a-68f7-4a41-bd25-229b9a9d26b8 csi.volname:pvc-bdca82d6-374d-4cf5-b082-1b42c45ad208 csi.volume.owner:default])
I0520 11:35:47.398037       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-bdca82d6-374d-4cf5-b082-1b42c45ad208 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-d3746b3a-68f7-4a41-bd25-229b9a9d26b8) and image name (csi-vol-d3746b3a-68f7-4a41-bd25-229b9a9d26b8) for request name (pvc-bdca82d6-374d-4cf5-b082-1b42c45ad208)
I0520 11:35:47.398135       1 rbd_util.go:423] ID: 24 Req-ID: pvc-bdca82d6-374d-4cf5-b082-1b42c45ad208 rbd: create kube/csi-vol-d3746b3a-68f7-4a41-bd25-229b9a9d26b8 size 5120M (features: [layering]) using mon 199.204.45.169
I0520 11:35:47.398212       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-bdca82d6-374d-4cf5-b082-1b42c45ad208 setting image options on kube/csi-vol-d3746b3a-68f7-4a41-bd25-229b9a9d26b8
I0520 11:35:47.425167       1 controllerserver.go:763] ID: 24 Req-ID: pvc-bdca82d6-374d-4cf5-b082-1b42c45ad208 created image kube/csi-vol-d3746b3a-68f7-4a41-bd25-229b9a9d26b8 backed for request name pvc-bdca82d6-374d-4cf5-b082-1b42c45ad208
I0520 11:35:47.460004       1 omap.go:159] ID: 24 Req-ID: pvc-bdca82d6-374d-4cf5-b082-1b42c45ad208 set omap keys (pool="kube", namespace="", name="csi.volume.d3746b3a-68f7-4a41-bd25-229b9a9d26b8"): map[csi.imageid:37edbf10a910])
I0520 11:35:47.567607       1 utils.go:205] ID: 24 Req-ID: pvc-bdca82d6-374d-4cf5-b082-1b42c45ad208 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-d3746b3a-68f7-4a41-bd25-229b9a9d26b8","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-d3746b3a-68f7-4a41-bd25-229b9a9d26b8"}}
I0520 11:36:05.727330       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0520 11:36:05.727429       1 utils.go:199] ID: 25 GRPC request: {}
I0520 11:36:05.727466       1 utils.go:205] ID: 25 GRPC response: {}