I0615 19:09:08.385114       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0615 19:09:08.385284       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0615 19:09:08.385304       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0615 19:09:08.385311       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0615 19:09:08.385317       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0615 19:09:08.385322       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0615 19:09:08.385327       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0615 19:09:08.385331       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0615 19:09:08.385336       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0615 19:09:08.385340       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0615 19:09:08.385651       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0615 19:09:08.385722       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0615 19:09:14.600996       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0615 19:09:14.602626       1 utils.go:199] ID: 1 GRPC request: {}
I0615 19:09:14.602719       1 utils.go:205] ID: 1 GRPC response: {}
I0615 19:09:14.606553       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0615 19:09:14.606675       1 utils.go:199] ID: 2 GRPC request: {}
I0615 19:09:14.606696       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0615 19:09:14.606766       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0615 19:09:14.611268       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0615 19:09:14.611301       1 utils.go:199] ID: 3 GRPC request: {}
I0615 19:09:14.611328       1 utils.go:205] ID: 3 GRPC response: {}
I0615 19:09:14.611831       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0615 19:09:14.611933       1 utils.go:199] ID: 4 GRPC request: {}
I0615 19:09:14.612077       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0615 19:09:14.613039       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0615 19:09:14.613091       1 utils.go:199] ID: 5 GRPC request: {}
I0615 19:09:14.613105       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0615 19:09:14.613226       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}}}]}
I0615 19:09:16.408629       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0615 19:09:16.408672       1 utils.go:199] ID: 6 GRPC request: {}
I0615 19:09:16.408688       1 utils.go:205] ID: 6 GRPC response: {}
I0615 19:09:16.410574       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0615 19:09:16.410618       1 utils.go:199] ID: 7 GRPC request: {}
I0615 19:09:16.410633       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0615 19:09:16.410664       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0615 19:09:16.413397       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0615 19:09:16.413596       1 utils.go:199] ID: 8 GRPC request: {}
I0615 19:09:16.413622       1 utils.go:205] ID: 8 GRPC response: {}
I0615 19:09:16.414501       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0615 19:09:16.414647       1 utils.go:199] ID: 9 GRPC request: {}
I0615 19:09:16.414859       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0615 19:09:16.415546       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0615 19:09:16.415584       1 utils.go:199] ID: 10 GRPC request: {}
I0615 19:09:16.415606       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0615 19:09:16.415722       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}}}]}
I0615 19:09:16.416203       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0615 19:09:16.416316       1 utils.go:199] ID: 11 GRPC request: {}
I0615 19:09:16.416337       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0615 19:09:16.416591       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}}}]}
I0615 19:09:16.417190       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0615 19:09:16.417208       1 utils.go:199] ID: 12 GRPC request: {}
I0615 19:09:16.417214       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0615 19:09:16.417368       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}}}]}
I0615 19:09:17.977921       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0615 19:09:17.977964       1 utils.go:199] ID: 13 GRPC request: {}
I0615 19:09:17.977971       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0615 19:09:17.978000       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0615 19:09:17.981270       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0615 19:09:17.981291       1 utils.go:199] ID: 14 GRPC request: {}
I0615 19:09:17.981305       1 utils.go:205] ID: 14 GRPC response: {}
I0615 19:09:17.981980       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0615 19:09:17.982018       1 utils.go:199] ID: 15 GRPC request: {}
I0615 19:09:17.982027       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0615 19:09:17.982119       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}}}]}
I0615 19:09:19.529143       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0615 19:09:19.529177       1 utils.go:199] ID: 16 GRPC request: {}
I0615 19:09:19.529194       1 utils.go:205] ID: 16 GRPC response: {}
I0615 19:09:19.531843       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0615 19:09:19.531884       1 utils.go:199] ID: 17 GRPC request: {}
I0615 19:09:19.531893       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0615 19:09:19.531925       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0615 19:09:19.533245       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0615 19:09:19.533264       1 utils.go:199] ID: 18 GRPC request: {}
I0615 19:09:19.533278       1 utils.go:205] ID: 18 GRPC response: {}
I0615 19:09:19.535300       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0615 19:09:19.535343       1 utils.go:199] ID: 19 GRPC request: {}
I0615 19:09:19.535454       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0615 19:09:19.536434       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0615 19:09:19.536457       1 utils.go:199] ID: 20 GRPC request: {}
I0615 19:09:19.536466       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0615 19:09:19.536563       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}}}]}
I0615 19:10:19.766554       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0615 19:10:19.766589       1 utils.go:199] ID: 21 GRPC request: {}
I0615 19:10:19.766604       1 utils.go:205] ID: 21 GRPC response: {}
I0615 19:11:19.708432       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0615 19:11:19.708556       1 utils.go:199] ID: 22 GRPC request: {}
I0615 19:11:19.708584       1 utils.go:205] ID: 22 GRPC response: {}
I0615 19:12:19.707363       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0615 19:12:19.707410       1 utils.go:199] ID: 23 GRPC request: {}
I0615 19:12:19.707431       1 utils.go:205] ID: 23 GRPC response: {}
I0615 19:13:01.757205       1 utils.go:198] ID: 24 Req-ID: pvc-948e2f97-6e89-4080-8d12-df5e349b5d47 GRPC call: /csi.v1.Controller/CreateVolume
I0615 19:13:01.757458       1 utils.go:199] ID: 24 Req-ID: pvc-948e2f97-6e89-4080-8d12-df5e349b5d47 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-948e2f97-6e89-4080-8d12-df5e349b5d47","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-948e2f97-6e89-4080-8d12-df5e349b5d47","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}}]}
I0615 19:13:01.757625       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-948e2f97-6e89-4080-8d12-df5e349b5d47 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0615 19:13:01.772129       1 omap.go:80] ID: 24 Req-ID: pvc-948e2f97-6e89-4080-8d12-df5e349b5d47 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0615 19:13:01.785466       1 omap.go:159] ID: 24 Req-ID: pvc-948e2f97-6e89-4080-8d12-df5e349b5d47 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-948e2f97-6e89-4080-8d12-df5e349b5d47:be93b35a-e01a-416e-849a-364e01a5cca6])
I0615 19:13:01.792992       1 omap.go:159] ID: 24 Req-ID: pvc-948e2f97-6e89-4080-8d12-df5e349b5d47 set omap keys (pool="kube", namespace="", name="csi.volume.be93b35a-e01a-416e-849a-364e01a5cca6"): map[csi.imagename:csi-vol-be93b35a-e01a-416e-849a-364e01a5cca6 csi.volname:pvc-948e2f97-6e89-4080-8d12-df5e349b5d47 csi.volume.owner:default])
I0615 19:13:01.793039       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-948e2f97-6e89-4080-8d12-df5e349b5d47 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-be93b35a-e01a-416e-849a-364e01a5cca6) and image name (csi-vol-be93b35a-e01a-416e-849a-364e01a5cca6) for request name (pvc-948e2f97-6e89-4080-8d12-df5e349b5d47)
I0615 19:13:01.793140       1 rbd_util.go:423] ID: 24 Req-ID: pvc-948e2f97-6e89-4080-8d12-df5e349b5d47 rbd: create kube/csi-vol-be93b35a-e01a-416e-849a-364e01a5cca6 size 5120M (features: [layering]) using mon 199.19.213.68
I0615 19:13:01.793224       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-948e2f97-6e89-4080-8d12-df5e349b5d47 setting image options on kube/csi-vol-be93b35a-e01a-416e-849a-364e01a5cca6
I0615 19:13:01.826182       1 controllerserver.go:763] ID: 24 Req-ID: pvc-948e2f97-6e89-4080-8d12-df5e349b5d47 created image kube/csi-vol-be93b35a-e01a-416e-849a-364e01a5cca6 backed for request name pvc-948e2f97-6e89-4080-8d12-df5e349b5d47
I0615 19:13:01.861031       1 omap.go:159] ID: 24 Req-ID: pvc-948e2f97-6e89-4080-8d12-df5e349b5d47 set omap keys (pool="kube", namespace="", name="csi.volume.be93b35a-e01a-416e-849a-364e01a5cca6"): map[csi.imageid:37edbe4db69d])
I0615 19:13:01.951600       1 utils.go:205] ID: 24 Req-ID: pvc-948e2f97-6e89-4080-8d12-df5e349b5d47 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-be93b35a-e01a-416e-849a-364e01a5cca6","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-be93b35a-e01a-416e-849a-364e01a5cca6"}}
I0615 19:13:19.800492       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0615 19:13:19.800533       1 utils.go:199] ID: 25 GRPC request: {}
I0615 19:13:19.800549       1 utils.go:205] ID: 25 GRPC response: {}