I0409 17:37:03.444071       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0409 17:37:03.444234       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0409 17:37:03.444247       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0409 17:37:03.444251       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0409 17:37:03.444264       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0409 17:37:03.444267       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0409 17:37:03.444271       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0409 17:37:03.444275       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0409 17:37:03.444278       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0409 17:37:03.444281       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0409 17:37:03.444691       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0409 17:37:03.444721       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0409 17:37:08.937614       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0409 17:37:08.938703       1 utils.go:199] ID: 1 GRPC request: {}
I0409 17:37:08.938768       1 utils.go:205] ID: 1 GRPC response: {}
I0409 17:37:08.941484       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0409 17:37:08.941648       1 utils.go:199] ID: 2 GRPC request: {}
I0409 17:37:08.941683       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0409 17:37:08.941754       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0409 17:37:08.943458       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0409 17:37:08.943551       1 utils.go:199] ID: 3 GRPC request: {}
I0409 17:37:08.943596       1 utils.go:205] ID: 3 GRPC response: {}
I0409 17:37:08.944371       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0409 17:37:08.944480       1 utils.go:199] ID: 4 GRPC request: {}
I0409 17:37:08.944650       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0409 17:37:08.945696       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0409 17:37:08.945809       1 utils.go:199] ID: 5 GRPC request: {}
I0409 17:37:08.945828       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0409 17:37:08.946017       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}}}]}
I0409 17:37:10.256324       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0409 17:37:10.256371       1 utils.go:199] ID: 6 GRPC request: {}
I0409 17:37:10.256392       1 utils.go:205] ID: 6 GRPC response: {}
I0409 17:37:10.262091       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0409 17:37:10.262206       1 utils.go:199] ID: 7 GRPC request: {}
I0409 17:37:10.262245       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0409 17:37:10.262287       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0409 17:37:10.264795       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0409 17:37:10.264857       1 utils.go:199] ID: 8 GRPC request: {}
I0409 17:37:10.264884       1 utils.go:205] ID: 8 GRPC response: {}
I0409 17:37:10.265788       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0409 17:37:10.265815       1 utils.go:199] ID: 9 GRPC request: {}
I0409 17:37:10.266033       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0409 17:37:10.267096       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0409 17:37:10.267119       1 utils.go:199] ID: 10 GRPC request: {}
I0409 17:37:10.267129       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0409 17:37:10.267241       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}}}]}
I0409 17:37:10.268162       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0409 17:37:10.268222       1 utils.go:199] ID: 11 GRPC request: {}
I0409 17:37:10.268239       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0409 17:37:10.268395       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}}}]}
I0409 17:37:10.268832       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0409 17:37:10.268855       1 utils.go:199] ID: 12 GRPC request: {}
I0409 17:37:10.268861       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0409 17:37:10.268938       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}}}]}
I0409 17:37:11.581490       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0409 17:37:11.581885       1 utils.go:199] ID: 13 GRPC request: {}
I0409 17:37:11.581948       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0409 17:37:11.582031       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0409 17:37:11.584957       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0409 17:37:11.585015       1 utils.go:199] ID: 14 GRPC request: {}
I0409 17:37:11.585037       1 utils.go:205] ID: 14 GRPC response: {}
I0409 17:37:11.585751       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0409 17:37:11.585891       1 utils.go:199] ID: 15 GRPC request: {}
I0409 17:37:11.585924       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0409 17:37:11.586197       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}}}]}
I0409 17:37:13.055775       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0409 17:37:13.055845       1 utils.go:199] ID: 16 GRPC request: {}
I0409 17:37:13.055878       1 utils.go:205] ID: 16 GRPC response: {}
I0409 17:37:13.058554       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0409 17:37:13.058615       1 utils.go:199] ID: 17 GRPC request: {}
I0409 17:37:13.058628       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0409 17:37:13.058674       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0409 17:37:13.065228       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0409 17:37:13.065501       1 utils.go:199] ID: 18 GRPC request: {}
I0409 17:37:13.065620       1 utils.go:205] ID: 18 GRPC response: {}
I0409 17:37:13.066212       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0409 17:37:13.066250       1 utils.go:199] ID: 19 GRPC request: {}
I0409 17:37:13.066464       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0409 17:37:13.067207       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0409 17:37:13.067236       1 utils.go:199] ID: 20 GRPC request: {}
I0409 17:37:13.067248       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0409 17:37:13.067379       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}}}]}
I0409 17:38:13.502893       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0409 17:38:13.502969       1 utils.go:199] ID: 21 GRPC request: {}
I0409 17:38:13.503002       1 utils.go:205] ID: 21 GRPC response: {}
I0409 17:39:13.456446       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0409 17:39:13.456543       1 utils.go:199] ID: 22 GRPC request: {}
I0409 17:39:13.456805       1 utils.go:205] ID: 22 GRPC response: {}
I0409 17:40:13.453268       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0409 17:40:13.453402       1 utils.go:199] ID: 23 GRPC request: {}
I0409 17:40:13.453510       1 utils.go:205] ID: 23 GRPC response: {}
I0409 17:40:26.961324       1 utils.go:198] ID: 24 Req-ID: pvc-da5381be-e12a-415e-a477-f07b6c191835 GRPC call: /csi.v1.Controller/CreateVolume
I0409 17:40:26.961821       1 utils.go:199] ID: 24 Req-ID: pvc-da5381be-e12a-415e-a477-f07b6c191835 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-da5381be-e12a-415e-a477-f07b6c191835","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-da5381be-e12a-415e-a477-f07b6c191835","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}}]}
I0409 17:40:26.962263       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-da5381be-e12a-415e-a477-f07b6c191835 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0409 17:40:26.978306       1 omap.go:80] ID: 24 Req-ID: pvc-da5381be-e12a-415e-a477-f07b6c191835 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0409 17:40:26.993702       1 omap.go:159] ID: 24 Req-ID: pvc-da5381be-e12a-415e-a477-f07b6c191835 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-da5381be-e12a-415e-a477-f07b6c191835:6ed76bcc-ba05-4774-a1a8-4f0ae7a72fc1])
I0409 17:40:27.001798       1 omap.go:159] ID: 24 Req-ID: pvc-da5381be-e12a-415e-a477-f07b6c191835 set omap keys (pool="kube", namespace="", name="csi.volume.6ed76bcc-ba05-4774-a1a8-4f0ae7a72fc1"): map[csi.imagename:csi-vol-6ed76bcc-ba05-4774-a1a8-4f0ae7a72fc1 csi.volname:pvc-da5381be-e12a-415e-a477-f07b6c191835 csi.volume.owner:default])
I0409 17:40:27.001843       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-da5381be-e12a-415e-a477-f07b6c191835 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-6ed76bcc-ba05-4774-a1a8-4f0ae7a72fc1) and image name (csi-vol-6ed76bcc-ba05-4774-a1a8-4f0ae7a72fc1) for request name (pvc-da5381be-e12a-415e-a477-f07b6c191835)
I0409 17:40:27.001942       1 rbd_util.go:423] ID: 24 Req-ID: pvc-da5381be-e12a-415e-a477-f07b6c191835 rbd: create kube/csi-vol-6ed76bcc-ba05-4774-a1a8-4f0ae7a72fc1 size 5120M (features: [layering]) using mon 199.19.213.116
I0409 17:40:27.002014       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-da5381be-e12a-415e-a477-f07b6c191835 setting image options on kube/csi-vol-6ed76bcc-ba05-4774-a1a8-4f0ae7a72fc1
I0409 17:40:28.810722       1 controllerserver.go:763] ID: 24 Req-ID: pvc-da5381be-e12a-415e-a477-f07b6c191835 created image kube/csi-vol-6ed76bcc-ba05-4774-a1a8-4f0ae7a72fc1 backed for request name pvc-da5381be-e12a-415e-a477-f07b6c191835
I0409 17:40:28.852403       1 omap.go:159] ID: 24 Req-ID: pvc-da5381be-e12a-415e-a477-f07b6c191835 set omap keys (pool="kube", namespace="", name="csi.volume.6ed76bcc-ba05-4774-a1a8-4f0ae7a72fc1"): map[csi.imageid:37d93af9aa5a])
I0409 17:40:28.964657       1 utils.go:205] ID: 24 Req-ID: pvc-da5381be-e12a-415e-a477-f07b6c191835 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-6ed76bcc-ba05-4774-a1a8-4f0ae7a72fc1","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-6ed76bcc-ba05-4774-a1a8-4f0ae7a72fc1"}}
I0409 17:41:13.467254       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0409 17:41:13.467330       1 utils.go:199] ID: 25 GRPC request: {}
I0409 17:41:13.467357       1 utils.go:205] ID: 25 GRPC response: {}