I0627 08:57:26.059468       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0627 08:57:26.059588       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0627 08:57:26.059600       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0627 08:57:26.059603       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0627 08:57:26.059605       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0627 08:57:26.059608       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0627 08:57:26.059611       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0627 08:57:26.059613       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0627 08:57:26.059616       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0627 08:57:26.059620       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0627 08:57:26.059937       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0627 08:57:26.060106       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0627 08:57:30.325708       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0627 08:57:30.327356       1 utils.go:199] ID: 1 GRPC request: {}
I0627 08:57:30.327411       1 utils.go:205] ID: 1 GRPC response: {}
I0627 08:57:30.330727       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0627 08:57:30.330784       1 utils.go:199] ID: 2 GRPC request: {}
I0627 08:57:30.330797       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0627 08:57:30.330836       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0627 08:57:30.332694       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0627 08:57:30.332744       1 utils.go:199] ID: 3 GRPC request: {}
I0627 08:57:30.332786       1 utils.go:205] ID: 3 GRPC response: {}
I0627 08:57:30.333217       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0627 08:57:30.333277       1 utils.go:199] ID: 4 GRPC request: {}
I0627 08:57:30.333402       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0627 08:57:30.334179       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0627 08:57:30.334212       1 utils.go:199] ID: 5 GRPC request: {}
I0627 08:57:30.334222       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0627 08:57:30.334340       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}}}]}
I0627 08:57:32.432799       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0627 08:57:32.432848       1 utils.go:199] ID: 6 GRPC request: {}
I0627 08:57:32.432871       1 utils.go:205] ID: 6 GRPC response: {}
I0627 08:57:32.436338       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0627 08:57:32.436375       1 utils.go:199] ID: 7 GRPC request: {}
I0627 08:57:32.436388       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0627 08:57:32.436413       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0627 08:57:32.438959       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0627 08:57:32.438981       1 utils.go:199] ID: 8 GRPC request: {}
I0627 08:57:32.438995       1 utils.go:205] ID: 8 GRPC response: {}
I0627 08:57:32.439514       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0627 08:57:32.439534       1 utils.go:199] ID: 9 GRPC request: {}
I0627 08:57:32.439616       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0627 08:57:32.440397       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0627 08:57:32.440412       1 utils.go:199] ID: 10 GRPC request: {}
I0627 08:57:32.440420       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0627 08:57:32.440489       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}}}]}
I0627 08:57:32.441118       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0627 08:57:32.441144       1 utils.go:199] ID: 11 GRPC request: {}
I0627 08:57:32.441150       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0627 08:57:32.441205       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}}}]}
I0627 08:57:32.441700       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0627 08:57:32.441821       1 utils.go:199] ID: 12 GRPC request: {}
I0627 08:57:32.441841       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0627 08:57:32.442048       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}}}]}
I0627 08:57:37.452608       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0627 08:57:37.452653       1 utils.go:199] ID: 13 GRPC request: {}
I0627 08:57:37.452665       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0627 08:57:37.452724       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0627 08:57:37.457361       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0627 08:57:37.457418       1 utils.go:199] ID: 14 GRPC request: {}
I0627 08:57:37.457440       1 utils.go:205] ID: 14 GRPC response: {}
I0627 08:57:37.457982       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0627 08:57:37.458044       1 utils.go:199] ID: 15 GRPC request: {}
I0627 08:57:37.458068       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0627 08:57:37.458195       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}}}]}
I0627 08:57:39.153420       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0627 08:57:39.153462       1 utils.go:199] ID: 16 GRPC request: {}
I0627 08:57:39.153478       1 utils.go:205] ID: 16 GRPC response: {}
I0627 08:57:39.155082       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0627 08:57:39.155242       1 utils.go:199] ID: 17 GRPC request: {}
I0627 08:57:39.155307       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0627 08:57:39.155385       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0627 08:57:39.160413       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0627 08:57:39.160511       1 utils.go:199] ID: 18 GRPC request: {}
I0627 08:57:39.160615       1 utils.go:205] ID: 18 GRPC response: {}
I0627 08:57:39.161061       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0627 08:57:39.161143       1 utils.go:199] ID: 19 GRPC request: {}
I0627 08:57:39.161265       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0627 08:57:39.162367       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0627 08:57:39.162437       1 utils.go:199] ID: 20 GRPC request: {}
I0627 08:57:39.162465       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0627 08:57:39.162710       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}}}]}
I0627 08:58:39.380960       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0627 08:58:39.381076       1 utils.go:199] ID: 21 GRPC request: {}
I0627 08:58:39.381110       1 utils.go:205] ID: 21 GRPC response: {}
I0627 08:59:39.330148       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0627 08:59:39.330269       1 utils.go:199] ID: 22 GRPC request: {}
I0627 08:59:39.330289       1 utils.go:205] ID: 22 GRPC response: {}
I0627 09:00:39.328545       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0627 09:00:39.328603       1 utils.go:199] ID: 23 GRPC request: {}
I0627 09:00:39.328625       1 utils.go:205] ID: 23 GRPC response: {}
I0627 09:00:51.676646       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0627 09:00:51.676688       1 utils.go:199] ID: 24 GRPC request: {}
I0627 09:00:51.676710       1 utils.go:205] ID: 24 GRPC response: {}
I0627 09:00:51.681307       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/GetPluginInfo
I0627 09:00:51.681353       1 utils.go:199] ID: 25 GRPC request: {}
I0627 09:00:51.681363       1 identityserver-default.go:40] ID: 25 Using default GetPluginInfo
I0627 09:00:51.681420       1 utils.go:205] ID: 25 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0627 09:00:51.682830       1 utils.go:198] ID: 26 GRPC call: /csi.v1.Identity/Probe
I0627 09:00:51.682850       1 utils.go:199] ID: 26 GRPC request: {}
I0627 09:00:51.682861       1 utils.go:205] ID: 26 GRPC response: {}
I0627 09:00:51.683404       1 utils.go:198] ID: 27 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0627 09:00:51.683431       1 utils.go:199] ID: 27 GRPC request: {}
I0627 09:00:51.683518       1 utils.go:205] ID: 27 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0627 09:00:51.684187       1 utils.go:198] ID: 28 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0627 09:00:51.684230       1 utils.go:199] ID: 28 GRPC request: {}
I0627 09:00:51.684241       1 controllerserver-default.go:42] ID: 28 Using default ControllerGetCapabilities
I0627 09:00:51.684311       1 utils.go:205] ID: 28 GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}}]}
I0627 09:01:21.287948       1 utils.go:198] ID: 29 Req-ID: pvc-6f80fe01-c83e-4912-9dcc-ac554a15f509 GRPC call: /csi.v1.Controller/CreateVolume
I0627 09:01:21.288610       1 utils.go:199] ID: 29 Req-ID: pvc-6f80fe01-c83e-4912-9dcc-ac554a15f509 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-6f80fe01-c83e-4912-9dcc-ac554a15f509","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-6f80fe01-c83e-4912-9dcc-ac554a15f509","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}}]}
I0627 09:01:21.289119       1 rbd_util.go:1315] ID: 29 Req-ID: pvc-6f80fe01-c83e-4912-9dcc-ac554a15f509 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0627 09:01:21.309765       1 omap.go:80] ID: 29 Req-ID: pvc-6f80fe01-c83e-4912-9dcc-ac554a15f509 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0627 09:01:21.330397       1 omap.go:159] ID: 29 Req-ID: pvc-6f80fe01-c83e-4912-9dcc-ac554a15f509 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-6f80fe01-c83e-4912-9dcc-ac554a15f509:9a0a8d74-3df0-48b4-bb41-72f0f93d797f])
I0627 09:01:21.339156       1 omap.go:159] ID: 29 Req-ID: pvc-6f80fe01-c83e-4912-9dcc-ac554a15f509 set omap keys (pool="kube", namespace="", name="csi.volume.9a0a8d74-3df0-48b4-bb41-72f0f93d797f"): map[csi.imagename:csi-vol-9a0a8d74-3df0-48b4-bb41-72f0f93d797f csi.volname:pvc-6f80fe01-c83e-4912-9dcc-ac554a15f509 csi.volume.owner:default])
I0627 09:01:21.339175       1 rbd_journal.go:491] ID: 29 Req-ID: pvc-6f80fe01-c83e-4912-9dcc-ac554a15f509 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-9a0a8d74-3df0-48b4-bb41-72f0f93d797f) and image name (csi-vol-9a0a8d74-3df0-48b4-bb41-72f0f93d797f) for request name (pvc-6f80fe01-c83e-4912-9dcc-ac554a15f509)
I0627 09:01:21.339214       1 rbd_util.go:423] ID: 29 Req-ID: pvc-6f80fe01-c83e-4912-9dcc-ac554a15f509 rbd: create kube/csi-vol-9a0a8d74-3df0-48b4-bb41-72f0f93d797f size 5120M (features: [layering]) using mon 199.204.45.240
I0627 09:01:21.339239       1 rbd_util.go:1563] ID: 29 Req-ID: pvc-6f80fe01-c83e-4912-9dcc-ac554a15f509 setting image options on kube/csi-vol-9a0a8d74-3df0-48b4-bb41-72f0f93d797f
I0627 09:01:21.368246       1 controllerserver.go:763] ID: 29 Req-ID: pvc-6f80fe01-c83e-4912-9dcc-ac554a15f509 created image kube/csi-vol-9a0a8d74-3df0-48b4-bb41-72f0f93d797f backed for request name pvc-6f80fe01-c83e-4912-9dcc-ac554a15f509
I0627 09:01:21.395761       1 omap.go:159] ID: 29 Req-ID: pvc-6f80fe01-c83e-4912-9dcc-ac554a15f509 set omap keys (pool="kube", namespace="", name="csi.volume.9a0a8d74-3df0-48b4-bb41-72f0f93d797f"): map[csi.imageid:37ed76e890d6])
I0627 09:01:21.493545       1 utils.go:205] ID: 29 Req-ID: pvc-6f80fe01-c83e-4912-9dcc-ac554a15f509 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-9a0a8d74-3df0-48b4-bb41-72f0f93d797f","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-9a0a8d74-3df0-48b4-bb41-72f0f93d797f"}}
I0627 09:01:39.339748       1 utils.go:198] ID: 30 GRPC call: /csi.v1.Identity/Probe
I0627 09:01:39.339829       1 utils.go:199] ID: 30 GRPC request: {}
I0627 09:01:39.339854       1 utils.go:205] ID: 30 GRPC response: {}