I0611 02:07:48.234043       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0611 02:07:48.234179       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0611 02:07:48.234197       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0611 02:07:48.234212       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0611 02:07:48.234215       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0611 02:07:48.234218       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0611 02:07:48.234224       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0611 02:07:48.234227       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0611 02:07:48.234230       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0611 02:07:48.234233       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0611 02:07:48.234569       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0611 02:07:48.234672       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0611 02:07:52.141557       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0611 02:07:52.143942       1 utils.go:199] ID: 1 GRPC request: {}
I0611 02:07:52.144144       1 utils.go:205] ID: 1 GRPC response: {}
I0611 02:07:52.149405       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0611 02:07:52.149467       1 utils.go:199] ID: 2 GRPC request: {}
I0611 02:07:52.149483       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0611 02:07:52.149751       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0611 02:07:52.157205       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0611 02:07:52.157264       1 utils.go:199] ID: 3 GRPC request: {}
I0611 02:07:52.157285       1 utils.go:205] ID: 3 GRPC response: {}
I0611 02:07:52.159543       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0611 02:07:52.159753       1 utils.go:199] ID: 4 GRPC request: {}
I0611 02:07:52.160055       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0611 02:07:52.164513       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0611 02:07:52.164645       1 utils.go:199] ID: 5 GRPC request: {}
I0611 02:07:52.164685       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0611 02:07:52.164864       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}}}]}
I0611 02:07:57.318260       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0611 02:07:57.318307       1 utils.go:199] ID: 6 GRPC request: {}
I0611 02:07:57.318338       1 utils.go:205] ID: 6 GRPC response: {}
I0611 02:07:57.326970       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0611 02:07:57.327029       1 utils.go:199] ID: 7 GRPC request: {}
I0611 02:07:57.327047       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0611 02:07:57.327080       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0611 02:07:57.329321       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0611 02:07:57.329362       1 utils.go:199] ID: 8 GRPC request: {}
I0611 02:07:57.329387       1 utils.go:205] ID: 8 GRPC response: {}
I0611 02:07:57.329989       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0611 02:07:57.330017       1 utils.go:199] ID: 9 GRPC request: {}
I0611 02:07:57.330201       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0611 02:07:57.333420       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0611 02:07:57.333445       1 utils.go:199] ID: 10 GRPC request: {}
I0611 02:07:57.333454       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0611 02:07:57.333545       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}}}]}
I0611 02:07:57.336888       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0611 02:07:57.336929       1 utils.go:199] ID: 11 GRPC request: {}
I0611 02:07:57.336942       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0611 02:07:57.337335       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}}}]}
I0611 02:07:57.339192       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0611 02:07:57.339215       1 utils.go:199] ID: 12 GRPC request: {}
I0611 02:07:57.339222       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0611 02:07:57.339295       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}}}]}
I0611 02:07:58.713134       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0611 02:07:58.713188       1 utils.go:199] ID: 13 GRPC request: {}
I0611 02:07:58.713199       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0611 02:07:58.713234       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0611 02:07:58.716578       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0611 02:07:58.716634       1 utils.go:199] ID: 14 GRPC request: {}
I0611 02:07:58.716665       1 utils.go:205] ID: 14 GRPC response: {}
I0611 02:07:58.717288       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0611 02:07:58.717315       1 utils.go:199] ID: 15 GRPC request: {}
I0611 02:07:58.717326       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0611 02:07:58.717496       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}}}]}
I0611 02:08:00.087026       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0611 02:08:00.087073       1 utils.go:199] ID: 16 GRPC request: {}
I0611 02:08:00.087101       1 utils.go:205] ID: 16 GRPC response: {}
I0611 02:08:00.090053       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0611 02:08:00.090073       1 utils.go:199] ID: 17 GRPC request: {}
I0611 02:08:00.090082       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0611 02:08:00.090198       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0611 02:08:00.092066       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0611 02:08:00.092105       1 utils.go:199] ID: 18 GRPC request: {}
I0611 02:08:00.092117       1 utils.go:205] ID: 18 GRPC response: {}
I0611 02:08:00.092485       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0611 02:08:00.092622       1 utils.go:199] ID: 19 GRPC request: {}
I0611 02:08:00.095906       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0611 02:08:00.100466       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0611 02:08:00.100532       1 utils.go:199] ID: 20 GRPC request: {}
I0611 02:08:00.100547       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0611 02:08:00.100684       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}}}]}
I0611 02:09:00.283367       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0611 02:09:00.283469       1 utils.go:199] ID: 21 GRPC request: {}
I0611 02:09:00.283498       1 utils.go:205] ID: 21 GRPC response: {}
I0611 02:10:00.283144       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0611 02:10:00.283246       1 utils.go:199] ID: 22 GRPC request: {}
I0611 02:10:00.283278       1 utils.go:205] ID: 22 GRPC response: {}
I0611 02:11:00.281486       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0611 02:11:00.281549       1 utils.go:199] ID: 23 GRPC request: {}
I0611 02:11:00.281573       1 utils.go:205] ID: 23 GRPC response: {}
I0611 02:11:53.371656       1 utils.go:198] ID: 24 Req-ID: pvc-955283fb-fc47-42f3-9d70-9919286fb4a7 GRPC call: /csi.v1.Controller/CreateVolume
I0611 02:11:53.372069       1 utils.go:199] ID: 24 Req-ID: pvc-955283fb-fc47-42f3-9d70-9919286fb4a7 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-955283fb-fc47-42f3-9d70-9919286fb4a7","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-955283fb-fc47-42f3-9d70-9919286fb4a7","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}}]}
I0611 02:11:53.372400       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-955283fb-fc47-42f3-9d70-9919286fb4a7 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0611 02:11:53.390656       1 omap.go:80] ID: 24 Req-ID: pvc-955283fb-fc47-42f3-9d70-9919286fb4a7 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0611 02:11:53.405782       1 omap.go:159] ID: 24 Req-ID: pvc-955283fb-fc47-42f3-9d70-9919286fb4a7 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-955283fb-fc47-42f3-9d70-9919286fb4a7:345f5cc1-d328-4eaa-9c80-3680046358ff])
I0611 02:11:53.414380       1 omap.go:159] ID: 24 Req-ID: pvc-955283fb-fc47-42f3-9d70-9919286fb4a7 set omap keys (pool="kube", namespace="", name="csi.volume.345f5cc1-d328-4eaa-9c80-3680046358ff"): map[csi.imagename:csi-vol-345f5cc1-d328-4eaa-9c80-3680046358ff csi.volname:pvc-955283fb-fc47-42f3-9d70-9919286fb4a7 csi.volume.owner:default])
I0611 02:11:53.414409       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-955283fb-fc47-42f3-9d70-9919286fb4a7 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-345f5cc1-d328-4eaa-9c80-3680046358ff) and image name (csi-vol-345f5cc1-d328-4eaa-9c80-3680046358ff) for request name (pvc-955283fb-fc47-42f3-9d70-9919286fb4a7)
I0611 02:11:53.414460       1 rbd_util.go:423] ID: 24 Req-ID: pvc-955283fb-fc47-42f3-9d70-9919286fb4a7 rbd: create kube/csi-vol-345f5cc1-d328-4eaa-9c80-3680046358ff size 5120M (features: [layering]) using mon 199.204.45.25
I0611 02:11:53.414505       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-955283fb-fc47-42f3-9d70-9919286fb4a7 setting image options on kube/csi-vol-345f5cc1-d328-4eaa-9c80-3680046358ff
I0611 02:11:53.444925       1 controllerserver.go:763] ID: 24 Req-ID: pvc-955283fb-fc47-42f3-9d70-9919286fb4a7 created image kube/csi-vol-345f5cc1-d328-4eaa-9c80-3680046358ff backed for request name pvc-955283fb-fc47-42f3-9d70-9919286fb4a7
I0611 02:11:53.480485       1 omap.go:159] ID: 24 Req-ID: pvc-955283fb-fc47-42f3-9d70-9919286fb4a7 set omap keys (pool="kube", namespace="", name="csi.volume.345f5cc1-d328-4eaa-9c80-3680046358ff"): map[csi.imageid:37ed57a109e3])
I0611 02:11:53.571300       1 utils.go:205] ID: 24 Req-ID: pvc-955283fb-fc47-42f3-9d70-9919286fb4a7 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-345f5cc1-d328-4eaa-9c80-3680046358ff","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-345f5cc1-d328-4eaa-9c80-3680046358ff"}}
I0611 02:12:00.295100       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0611 02:12:00.295182       1 utils.go:199] ID: 25 GRPC request: {}
I0611 02:12:00.295214       1 utils.go:205] ID: 25 GRPC response: {}