I0521 14:37:27.041266       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0521 14:37:27.041376       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0521 14:37:27.041392       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0521 14:37:27.041395       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0521 14:37:27.041398       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0521 14:37:27.041402       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0521 14:37:27.041405       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0521 14:37:27.041408       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0521 14:37:27.041410       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0521 14:37:27.041413       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0521 14:37:27.041652       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0521 14:37:27.041670       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0521 14:37:28.988546       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0521 14:37:28.990631       1 utils.go:199] ID: 1 GRPC request: {}
I0521 14:37:28.990690       1 utils.go:205] ID: 1 GRPC response: {}
I0521 14:37:28.992711       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0521 14:37:28.992790       1 utils.go:199] ID: 2 GRPC request: {}
I0521 14:37:28.992802       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0521 14:37:28.992843       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0521 14:37:28.995240       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0521 14:37:28.995491       1 utils.go:199] ID: 3 GRPC request: {}
I0521 14:37:28.995693       1 utils.go:205] ID: 3 GRPC response: {}
I0521 14:37:28.996343       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0521 14:37:28.996394       1 utils.go:199] ID: 4 GRPC request: {}
I0521 14:37:28.996528       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0521 14:37:28.997541       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0521 14:37:28.997839       1 utils.go:199] ID: 5 GRPC request: {}
I0521 14:37:28.998049       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0521 14:37:28.998436       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 14:37:31.564041       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0521 14:37:31.564097       1 utils.go:199] ID: 6 GRPC request: {}
I0521 14:37:31.564120       1 utils.go:205] ID: 6 GRPC response: {}
I0521 14:37:31.567707       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0521 14:37:31.567758       1 utils.go:199] ID: 7 GRPC request: {}
I0521 14:37:31.567772       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0521 14:37:31.567800       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0521 14:37:31.570105       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0521 14:37:31.570130       1 utils.go:199] ID: 8 GRPC request: {}
I0521 14:37:31.570148       1 utils.go:205] ID: 8 GRPC response: {}
I0521 14:37:31.570597       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0521 14:37:31.570632       1 utils.go:199] ID: 9 GRPC request: {}
I0521 14:37:31.570860       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0521 14:37:31.571734       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0521 14:37:31.571796       1 utils.go:199] ID: 10 GRPC request: {}
I0521 14:37:31.571813       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0521 14:37:31.571959       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 14:37:31.572507       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0521 14:37:31.572539       1 utils.go:199] ID: 11 GRPC request: {}
I0521 14:37:31.572550       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0521 14:37:31.572694       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 14:37:31.573138       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0521 14:37:31.573156       1 utils.go:199] ID: 12 GRPC request: {}
I0521 14:37:31.573163       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0521 14:37:31.573232       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 14:37:32.841633       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0521 14:37:32.841766       1 utils.go:199] ID: 13 GRPC request: {}
I0521 14:37:32.841853       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0521 14:37:32.841953       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0521 14:37:32.844786       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0521 14:37:32.844842       1 utils.go:199] ID: 14 GRPC request: {}
I0521 14:37:32.844869       1 utils.go:205] ID: 14 GRPC response: {}
I0521 14:37:32.845289       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0521 14:37:32.845313       1 utils.go:199] ID: 15 GRPC request: {}
I0521 14:37:32.845322       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0521 14:37:32.845422       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 14:37:34.142000       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0521 14:37:34.142043       1 utils.go:199] ID: 16 GRPC request: {}
I0521 14:37:34.142063       1 utils.go:205] ID: 16 GRPC response: {}
I0521 14:37:34.146098       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0521 14:37:34.146229       1 utils.go:199] ID: 17 GRPC request: {}
I0521 14:37:34.146277       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0521 14:37:34.146347       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0521 14:37:34.151274       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0521 14:37:34.151312       1 utils.go:199] ID: 18 GRPC request: {}
I0521 14:37:34.151326       1 utils.go:205] ID: 18 GRPC response: {}
I0521 14:37:34.151976       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0521 14:37:34.152011       1 utils.go:199] ID: 19 GRPC request: {}
I0521 14:37:34.152091       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0521 14:37:34.153872       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0521 14:37:34.153918       1 utils.go:199] ID: 20 GRPC request: {}
I0521 14:37:34.153945       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0521 14:37:34.154104       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 14:38:34.321390       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0521 14:38:34.321459       1 utils.go:199] ID: 21 GRPC request: {}
I0521 14:38:34.321488       1 utils.go:205] ID: 21 GRPC response: {}
I0521 14:39:34.321182       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0521 14:39:34.321299       1 utils.go:199] ID: 22 GRPC request: {}
I0521 14:39:34.321335       1 utils.go:205] ID: 22 GRPC response: {}
I0521 14:40:34.320354       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0521 14:40:34.320423       1 utils.go:199] ID: 23 GRPC request: {}
I0521 14:40:34.320451       1 utils.go:205] ID: 23 GRPC response: {}
I0521 14:41:28.475650       1 utils.go:198] ID: 24 Req-ID: pvc-23aed94a-8ec0-4702-a01a-5173dcd60e19 GRPC call: /csi.v1.Controller/CreateVolume
I0521 14:41:28.476216       1 utils.go:199] ID: 24 Req-ID: pvc-23aed94a-8ec0-4702-a01a-5173dcd60e19 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-23aed94a-8ec0-4702-a01a-5173dcd60e19","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-23aed94a-8ec0-4702-a01a-5173dcd60e19","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 14:41:28.476934       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-23aed94a-8ec0-4702-a01a-5173dcd60e19 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0521 14:41:28.496162       1 omap.go:80] ID: 24 Req-ID: pvc-23aed94a-8ec0-4702-a01a-5173dcd60e19 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0521 14:41:28.510598       1 omap.go:159] ID: 24 Req-ID: pvc-23aed94a-8ec0-4702-a01a-5173dcd60e19 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-23aed94a-8ec0-4702-a01a-5173dcd60e19:99074673-0197-4e3d-9f9a-2f944ea45502])
I0521 14:41:28.517986       1 omap.go:159] ID: 24 Req-ID: pvc-23aed94a-8ec0-4702-a01a-5173dcd60e19 set omap keys (pool="kube", namespace="", name="csi.volume.99074673-0197-4e3d-9f9a-2f944ea45502"): map[csi.imagename:csi-vol-99074673-0197-4e3d-9f9a-2f944ea45502 csi.volname:pvc-23aed94a-8ec0-4702-a01a-5173dcd60e19 csi.volume.owner:default])
I0521 14:41:28.518016       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-23aed94a-8ec0-4702-a01a-5173dcd60e19 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-99074673-0197-4e3d-9f9a-2f944ea45502) and image name (csi-vol-99074673-0197-4e3d-9f9a-2f944ea45502) for request name (pvc-23aed94a-8ec0-4702-a01a-5173dcd60e19)
I0521 14:41:28.518126       1 rbd_util.go:423] ID: 24 Req-ID: pvc-23aed94a-8ec0-4702-a01a-5173dcd60e19 rbd: create kube/csi-vol-99074673-0197-4e3d-9f9a-2f944ea45502 size 5120M (features: [layering]) using mon 199.204.45.115
I0521 14:41:28.518195       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-23aed94a-8ec0-4702-a01a-5173dcd60e19 setting image options on kube/csi-vol-99074673-0197-4e3d-9f9a-2f944ea45502
I0521 14:41:28.547358       1 controllerserver.go:763] ID: 24 Req-ID: pvc-23aed94a-8ec0-4702-a01a-5173dcd60e19 created image kube/csi-vol-99074673-0197-4e3d-9f9a-2f944ea45502 backed for request name pvc-23aed94a-8ec0-4702-a01a-5173dcd60e19
I0521 14:41:28.578384       1 omap.go:159] ID: 24 Req-ID: pvc-23aed94a-8ec0-4702-a01a-5173dcd60e19 set omap keys (pool="kube", namespace="", name="csi.volume.99074673-0197-4e3d-9f9a-2f944ea45502"): map[csi.imageid:37edd59e0fc8])
I0521 14:41:28.677512       1 utils.go:205] ID: 24 Req-ID: pvc-23aed94a-8ec0-4702-a01a-5173dcd60e19 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-99074673-0197-4e3d-9f9a-2f944ea45502","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-99074673-0197-4e3d-9f9a-2f944ea45502"}}
I0521 14:41:34.331142       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0521 14:41:34.331206       1 utils.go:199] ID: 25 GRPC request: {}
I0521 14:41:34.331246       1 utils.go:205] ID: 25 GRPC response: {}