I0521 19:34:20.406047       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0521 19:34:20.406182       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0521 19:34:20.406196       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0521 19:34:20.406200       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0521 19:34:20.406203       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0521 19:34:20.406206       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0521 19:34:20.406209       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0521 19:34:20.406212       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0521 19:34:20.406216       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0521 19:34:20.406219       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0521 19:34:20.406509       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0521 19:34:20.406549       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0521 19:34:24.093980       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0521 19:34:24.095835       1 utils.go:199] ID: 1 GRPC request: {}
I0521 19:34:24.095915       1 utils.go:205] ID: 1 GRPC response: {}
I0521 19:34:24.099755       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0521 19:34:24.099994       1 utils.go:199] ID: 2 GRPC request: {}
I0521 19:34:24.100019       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0521 19:34:24.100211       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0521 19:34:24.101709       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0521 19:34:24.101736       1 utils.go:199] ID: 3 GRPC request: {}
I0521 19:34:24.101835       1 utils.go:205] ID: 3 GRPC response: {}
I0521 19:34:24.102585       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0521 19:34:24.102778       1 utils.go:199] ID: 4 GRPC request: {}
I0521 19:34:24.103023       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0521 19:34:24.103929       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0521 19:34:24.104067       1 utils.go:199] ID: 5 GRPC request: {}
I0521 19:34:24.104089       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0521 19:34:24.104402       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}}}]}
I0521 19:34:29.562901       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0521 19:34:29.562957       1 utils.go:199] ID: 6 GRPC request: {}
I0521 19:34:29.562978       1 utils.go:205] ID: 6 GRPC response: {}
I0521 19:34:29.566788       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0521 19:34:29.566820       1 utils.go:199] ID: 7 GRPC request: {}
I0521 19:34:29.566831       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0521 19:34:29.566866       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0521 19:34:29.569579       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0521 19:34:29.569610       1 utils.go:199] ID: 8 GRPC request: {}
I0521 19:34:29.569624       1 utils.go:205] ID: 8 GRPC response: {}
I0521 19:34:29.570215       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0521 19:34:29.570246       1 utils.go:199] ID: 9 GRPC request: {}
I0521 19:34:29.570437       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0521 19:34:29.571297       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0521 19:34:29.571333       1 utils.go:199] ID: 10 GRPC request: {}
I0521 19:34:29.571347       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0521 19:34:29.571526       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}}}]}
I0521 19:34:29.572362       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0521 19:34:29.572382       1 utils.go:199] ID: 11 GRPC request: {}
I0521 19:34:29.572388       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0521 19:34:29.572475       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}}}]}
I0521 19:34:29.577283       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0521 19:34:29.577346       1 utils.go:199] ID: 12 GRPC request: {}
I0521 19:34:29.577377       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0521 19:34:29.577545       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}}}]}
I0521 19:34:30.908166       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0521 19:34:30.908198       1 utils.go:199] ID: 13 GRPC request: {}
I0521 19:34:30.908205       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0521 19:34:30.908224       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0521 19:34:30.913681       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0521 19:34:30.913695       1 utils.go:199] ID: 14 GRPC request: {}
I0521 19:34:30.913707       1 utils.go:205] ID: 14 GRPC response: {}
I0521 19:34:30.914372       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0521 19:34:30.914387       1 utils.go:199] ID: 15 GRPC request: {}
I0521 19:34:30.914393       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0521 19:34:30.914454       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}}}]}
I0521 19:34:32.275303       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0521 19:34:32.275352       1 utils.go:199] ID: 16 GRPC request: {}
I0521 19:34:32.275374       1 utils.go:205] ID: 16 GRPC response: {}
I0521 19:34:32.277380       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0521 19:34:32.277410       1 utils.go:199] ID: 17 GRPC request: {}
I0521 19:34:32.277421       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0521 19:34:32.277452       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0521 19:34:32.279333       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0521 19:34:32.279564       1 utils.go:199] ID: 18 GRPC request: {}
I0521 19:34:32.279696       1 utils.go:205] ID: 18 GRPC response: {}
I0521 19:34:32.280402       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0521 19:34:32.280423       1 utils.go:199] ID: 19 GRPC request: {}
I0521 19:34:32.280521       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0521 19:34:32.281296       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0521 19:34:32.281405       1 utils.go:199] ID: 20 GRPC request: {}
I0521 19:34:32.281494       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0521 19:34:32.281842       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}}}]}
I0521 19:35:32.502158       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0521 19:35:32.502223       1 utils.go:199] ID: 21 GRPC request: {}
I0521 19:35:32.502245       1 utils.go:205] ID: 21 GRPC response: {}
I0521 19:36:32.470118       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0521 19:36:32.472143       1 utils.go:199] ID: 22 GRPC request: {}
I0521 19:36:32.472171       1 utils.go:205] ID: 22 GRPC response: {}
I0521 19:37:32.465884       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0521 19:37:32.466009       1 utils.go:199] ID: 23 GRPC request: {}
I0521 19:37:32.466035       1 utils.go:205] ID: 23 GRPC response: {}
I0521 19:38:06.131014       1 utils.go:198] ID: 24 Req-ID: pvc-29f6abaa-6408-41a1-81d2-5ce85136fd6b GRPC call: /csi.v1.Controller/CreateVolume
I0521 19:38:06.131475       1 utils.go:199] ID: 24 Req-ID: pvc-29f6abaa-6408-41a1-81d2-5ce85136fd6b GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-29f6abaa-6408-41a1-81d2-5ce85136fd6b","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-29f6abaa-6408-41a1-81d2-5ce85136fd6b","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}}]}
I0521 19:38:06.131695       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-29f6abaa-6408-41a1-81d2-5ce85136fd6b setting disableInUseChecks: false image features: [layering] mounter: rbd
E0521 19:38:06.146934       1 omap.go:80] ID: 24 Req-ID: pvc-29f6abaa-6408-41a1-81d2-5ce85136fd6b omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0521 19:38:06.164917       1 omap.go:159] ID: 24 Req-ID: pvc-29f6abaa-6408-41a1-81d2-5ce85136fd6b set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-29f6abaa-6408-41a1-81d2-5ce85136fd6b:27c26e43-e3f5-4cc3-b277-36fa2c843991])
I0521 19:38:06.174453       1 omap.go:159] ID: 24 Req-ID: pvc-29f6abaa-6408-41a1-81d2-5ce85136fd6b set omap keys (pool="kube", namespace="", name="csi.volume.27c26e43-e3f5-4cc3-b277-36fa2c843991"): map[csi.imagename:csi-vol-27c26e43-e3f5-4cc3-b277-36fa2c843991 csi.volname:pvc-29f6abaa-6408-41a1-81d2-5ce85136fd6b csi.volume.owner:default])
I0521 19:38:06.174507       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-29f6abaa-6408-41a1-81d2-5ce85136fd6b generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-27c26e43-e3f5-4cc3-b277-36fa2c843991) and image name (csi-vol-27c26e43-e3f5-4cc3-b277-36fa2c843991) for request name (pvc-29f6abaa-6408-41a1-81d2-5ce85136fd6b)
I0521 19:38:06.174569       1 rbd_util.go:423] ID: 24 Req-ID: pvc-29f6abaa-6408-41a1-81d2-5ce85136fd6b rbd: create kube/csi-vol-27c26e43-e3f5-4cc3-b277-36fa2c843991 size 5120M (features: [layering]) using mon 199.19.213.180
I0521 19:38:06.174612       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-29f6abaa-6408-41a1-81d2-5ce85136fd6b setting image options on kube/csi-vol-27c26e43-e3f5-4cc3-b277-36fa2c843991
I0521 19:38:06.207823       1 controllerserver.go:763] ID: 24 Req-ID: pvc-29f6abaa-6408-41a1-81d2-5ce85136fd6b created image kube/csi-vol-27c26e43-e3f5-4cc3-b277-36fa2c843991 backed for request name pvc-29f6abaa-6408-41a1-81d2-5ce85136fd6b
I0521 19:38:06.240058       1 omap.go:159] ID: 24 Req-ID: pvc-29f6abaa-6408-41a1-81d2-5ce85136fd6b set omap keys (pool="kube", namespace="", name="csi.volume.27c26e43-e3f5-4cc3-b277-36fa2c843991"): map[csi.imageid:37ede67ac8])
I0521 19:38:06.339457       1 utils.go:205] ID: 24 Req-ID: pvc-29f6abaa-6408-41a1-81d2-5ce85136fd6b GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-27c26e43-e3f5-4cc3-b277-36fa2c843991","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-27c26e43-e3f5-4cc3-b277-36fa2c843991"}}
I0521 19:38:32.478254       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0521 19:38:32.478310       1 utils.go:199] ID: 25 GRPC request: {}
I0521 19:38:32.478334       1 utils.go:205] ID: 25 GRPC response: {}