I0413 17:45:16.294006       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0413 17:45:16.294149       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0413 17:45:16.294172       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0413 17:45:16.294176       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0413 17:45:16.294179       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0413 17:45:16.294181       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0413 17:45:16.294185       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0413 17:45:16.294188       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0413 17:45:16.294191       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0413 17:45:16.294194       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0413 17:45:16.294455       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0413 17:45:16.294548       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0413 17:45:19.134313       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0413 17:45:19.135227       1 utils.go:199] ID: 1 GRPC request: {}
I0413 17:45:19.135273       1 utils.go:205] ID: 1 GRPC response: {}
I0413 17:45:19.137235       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0413 17:45:19.137433       1 utils.go:199] ID: 2 GRPC request: {}
I0413 17:45:19.137467       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0413 17:45:19.137590       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0413 17:45:19.139089       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0413 17:45:19.139125       1 utils.go:199] ID: 3 GRPC request: {}
I0413 17:45:19.139145       1 utils.go:205] ID: 3 GRPC response: {}
I0413 17:45:19.139720       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0413 17:45:19.139762       1 utils.go:199] ID: 4 GRPC request: {}
I0413 17:45:19.140031       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0413 17:45:19.140860       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0413 17:45:19.140941       1 utils.go:199] ID: 5 GRPC request: {}
I0413 17:45:19.140957       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0413 17:45:19.141106       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}}}]}
I0413 17:45:22.426802       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0413 17:45:22.426842       1 utils.go:199] ID: 6 GRPC request: {}
I0413 17:45:22.426857       1 utils.go:205] ID: 6 GRPC response: {}
I0413 17:45:22.428802       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0413 17:45:22.428821       1 utils.go:199] ID: 7 GRPC request: {}
I0413 17:45:22.428828       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0413 17:45:22.428850       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0413 17:45:22.431940       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0413 17:45:22.431993       1 utils.go:199] ID: 8 GRPC request: {}
I0413 17:45:22.432012       1 utils.go:205] ID: 8 GRPC response: {}
I0413 17:45:22.432908       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0413 17:45:22.432939       1 utils.go:199] ID: 9 GRPC request: {}
I0413 17:45:22.433132       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0413 17:45:22.433820       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0413 17:45:22.433850       1 utils.go:199] ID: 10 GRPC request: {}
I0413 17:45:22.433861       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0413 17:45:22.434043       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}}}]}
I0413 17:45:22.434637       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0413 17:45:22.434670       1 utils.go:199] ID: 11 GRPC request: {}
I0413 17:45:22.434678       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0413 17:45:22.434816       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}}}]}
I0413 17:45:22.435225       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0413 17:45:22.435240       1 utils.go:199] ID: 12 GRPC request: {}
I0413 17:45:22.435244       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0413 17:45:22.435298       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}}}]}
I0413 17:45:23.634127       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0413 17:45:23.634173       1 utils.go:199] ID: 13 GRPC request: {}
I0413 17:45:23.634185       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0413 17:45:23.634221       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0413 17:45:23.636653       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0413 17:45:23.636680       1 utils.go:199] ID: 14 GRPC request: {}
I0413 17:45:23.636698       1 utils.go:205] ID: 14 GRPC response: {}
I0413 17:45:23.637786       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0413 17:45:23.637822       1 utils.go:199] ID: 15 GRPC request: {}
I0413 17:45:23.637831       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0413 17:45:23.637912       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}}}]}
I0413 17:45:24.788249       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0413 17:45:24.788280       1 utils.go:199] ID: 16 GRPC request: {}
I0413 17:45:24.788859       1 utils.go:205] ID: 16 GRPC response: {}
I0413 17:45:24.793637       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0413 17:45:24.793689       1 utils.go:199] ID: 17 GRPC request: {}
I0413 17:45:24.793706       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0413 17:45:24.793746       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0413 17:45:24.796852       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0413 17:45:24.796884       1 utils.go:199] ID: 18 GRPC request: {}
I0413 17:45:24.796902       1 utils.go:205] ID: 18 GRPC response: {}
I0413 17:45:24.797187       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0413 17:45:24.797215       1 utils.go:199] ID: 19 GRPC request: {}
I0413 17:45:24.797327       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0413 17:45:24.797895       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0413 17:45:24.797925       1 utils.go:199] ID: 20 GRPC request: {}
I0413 17:45:24.797936       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0413 17:45:24.798026       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}}}]}
I0413 17:46:25.030700       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0413 17:46:25.030809       1 utils.go:199] ID: 21 GRPC request: {}
I0413 17:46:25.030841       1 utils.go:205] ID: 21 GRPC response: {}
I0413 17:47:24.970511       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0413 17:47:24.971239       1 utils.go:199] ID: 22 GRPC request: {}
I0413 17:47:24.971267       1 utils.go:205] ID: 22 GRPC response: {}
I0413 17:48:24.971124       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0413 17:48:24.971184       1 utils.go:199] ID: 23 GRPC request: {}
I0413 17:48:24.971206       1 utils.go:205] ID: 23 GRPC response: {}
I0413 17:48:30.448947       1 utils.go:198] ID: 24 Req-ID: pvc-194368e4-e771-4429-a0dc-f6f86986161d GRPC call: /csi.v1.Controller/CreateVolume
I0413 17:48:30.449229       1 utils.go:199] ID: 24 Req-ID: pvc-194368e4-e771-4429-a0dc-f6f86986161d GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-194368e4-e771-4429-a0dc-f6f86986161d","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-194368e4-e771-4429-a0dc-f6f86986161d","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}}]}
I0413 17:48:30.449444       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-194368e4-e771-4429-a0dc-f6f86986161d setting disableInUseChecks: false image features: [layering] mounter: rbd
E0413 17:48:30.470585       1 omap.go:80] ID: 24 Req-ID: pvc-194368e4-e771-4429-a0dc-f6f86986161d omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0413 17:48:30.486116       1 omap.go:159] ID: 24 Req-ID: pvc-194368e4-e771-4429-a0dc-f6f86986161d set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-194368e4-e771-4429-a0dc-f6f86986161d:0e2f591e-d0f4-40a6-8957-97307610b8ba])
I0413 17:48:30.492826       1 omap.go:159] ID: 24 Req-ID: pvc-194368e4-e771-4429-a0dc-f6f86986161d set omap keys (pool="kube", namespace="", name="csi.volume.0e2f591e-d0f4-40a6-8957-97307610b8ba"): map[csi.imagename:csi-vol-0e2f591e-d0f4-40a6-8957-97307610b8ba csi.volname:pvc-194368e4-e771-4429-a0dc-f6f86986161d csi.volume.owner:default])
I0413 17:48:30.492855       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-194368e4-e771-4429-a0dc-f6f86986161d generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-0e2f591e-d0f4-40a6-8957-97307610b8ba) and image name (csi-vol-0e2f591e-d0f4-40a6-8957-97307610b8ba) for request name (pvc-194368e4-e771-4429-a0dc-f6f86986161d)
I0413 17:48:30.492988       1 rbd_util.go:423] ID: 24 Req-ID: pvc-194368e4-e771-4429-a0dc-f6f86986161d rbd: create kube/csi-vol-0e2f591e-d0f4-40a6-8957-97307610b8ba size 5120M (features: [layering]) using mon 199.204.45.155
I0413 17:48:30.493062       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-194368e4-e771-4429-a0dc-f6f86986161d setting image options on kube/csi-vol-0e2f591e-d0f4-40a6-8957-97307610b8ba
I0413 17:48:32.474992       1 controllerserver.go:763] ID: 24 Req-ID: pvc-194368e4-e771-4429-a0dc-f6f86986161d created image kube/csi-vol-0e2f591e-d0f4-40a6-8957-97307610b8ba backed for request name pvc-194368e4-e771-4429-a0dc-f6f86986161d
I0413 17:48:32.509583       1 omap.go:159] ID: 24 Req-ID: pvc-194368e4-e771-4429-a0dc-f6f86986161d set omap keys (pool="kube", namespace="", name="csi.volume.0e2f591e-d0f4-40a6-8957-97307610b8ba"): map[csi.imageid:37d9a5383bfb])
I0413 17:48:32.609034       1 utils.go:205] ID: 24 Req-ID: pvc-194368e4-e771-4429-a0dc-f6f86986161d GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-0e2f591e-d0f4-40a6-8957-97307610b8ba","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-0e2f591e-d0f4-40a6-8957-97307610b8ba"}}
I0413 17:49:24.983174       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0413 17:49:24.983221       1 utils.go:199] ID: 25 GRPC request: {}
I0413 17:49:24.983234       1 utils.go:205] ID: 25 GRPC response: {}