I0509 16:59:18.829072       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0509 16:59:18.829180       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0509 16:59:18.829193       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0509 16:59:18.829196       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0509 16:59:18.829201       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0509 16:59:18.829227       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0509 16:59:18.829231       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0509 16:59:18.829234       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0509 16:59:18.829236       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0509 16:59:18.829239       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0509 16:59:18.829526       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0509 16:59:18.829555       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0509 16:59:24.527527       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0509 16:59:24.529018       1 utils.go:199] ID: 1 GRPC request: {}
I0509 16:59:24.529078       1 utils.go:205] ID: 1 GRPC response: {}
I0509 16:59:24.531228       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0509 16:59:24.531407       1 utils.go:199] ID: 2 GRPC request: {}
I0509 16:59:24.531456       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0509 16:59:24.531583       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0509 16:59:24.533383       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0509 16:59:24.533411       1 utils.go:199] ID: 3 GRPC request: {}
I0509 16:59:24.533430       1 utils.go:205] ID: 3 GRPC response: {}
I0509 16:59:24.534305       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0509 16:59:24.534387       1 utils.go:199] ID: 4 GRPC request: {}
I0509 16:59:24.534626       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0509 16:59:24.535921       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0509 16:59:24.535990       1 utils.go:199] ID: 5 GRPC request: {}
I0509 16:59:24.536006       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0509 16:59:24.536175       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}}}]}
I0509 16:59:37.228122       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0509 16:59:37.228160       1 utils.go:199] ID: 6 GRPC request: {}
I0509 16:59:37.228177       1 utils.go:205] ID: 6 GRPC response: {}
I0509 16:59:37.230813       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0509 16:59:37.230834       1 utils.go:199] ID: 7 GRPC request: {}
I0509 16:59:37.230841       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0509 16:59:37.230869       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0509 16:59:37.231799       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0509 16:59:37.231816       1 utils.go:199] ID: 8 GRPC request: {}
I0509 16:59:37.231833       1 utils.go:205] ID: 8 GRPC response: {}
I0509 16:59:37.232214       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0509 16:59:37.232253       1 utils.go:199] ID: 9 GRPC request: {}
I0509 16:59:37.232355       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0509 16:59:37.232871       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0509 16:59:37.232895       1 utils.go:199] ID: 10 GRPC request: {}
I0509 16:59:37.232906       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0509 16:59:37.232969       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}}}]}
I0509 16:59:37.233320       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0509 16:59:37.233338       1 utils.go:199] ID: 11 GRPC request: {}
I0509 16:59:37.233346       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0509 16:59:37.233426       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}}}]}
I0509 16:59:37.233725       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0509 16:59:37.233748       1 utils.go:199] ID: 12 GRPC request: {}
I0509 16:59:37.233755       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0509 16:59:37.233933       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}}}]}
I0509 16:59:38.719553       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0509 16:59:38.719600       1 utils.go:199] ID: 13 GRPC request: {}
I0509 16:59:38.719612       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0509 16:59:38.719646       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0509 16:59:38.725373       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0509 16:59:38.725409       1 utils.go:199] ID: 14 GRPC request: {}
I0509 16:59:38.725424       1 utils.go:205] ID: 14 GRPC response: {}
I0509 16:59:38.725941       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0509 16:59:38.725974       1 utils.go:199] ID: 15 GRPC request: {}
I0509 16:59:38.725983       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0509 16:59:38.726060       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}}}]}
I0509 16:59:40.372689       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0509 16:59:40.372759       1 utils.go:199] ID: 16 GRPC request: {}
I0509 16:59:40.372776       1 utils.go:205] ID: 16 GRPC response: {}
I0509 16:59:40.375945       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0509 16:59:40.375984       1 utils.go:199] ID: 17 GRPC request: {}
I0509 16:59:40.375998       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0509 16:59:40.376050       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0509 16:59:40.377678       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0509 16:59:40.377700       1 utils.go:199] ID: 18 GRPC request: {}
I0509 16:59:40.377714       1 utils.go:205] ID: 18 GRPC response: {}
I0509 16:59:40.378083       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0509 16:59:40.378101       1 utils.go:199] ID: 19 GRPC request: {}
I0509 16:59:40.378191       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0509 16:59:40.378743       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0509 16:59:40.378786       1 utils.go:199] ID: 20 GRPC request: {}
I0509 16:59:40.378794       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0509 16:59:40.378927       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}}}]}
I0509 17:00:40.610116       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0509 17:00:40.610164       1 utils.go:199] ID: 21 GRPC request: {}
I0509 17:00:40.610180       1 utils.go:205] ID: 21 GRPC response: {}
I0509 17:01:40.580753       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0509 17:01:40.580811       1 utils.go:199] ID: 22 GRPC request: {}
I0509 17:01:40.580836       1 utils.go:205] ID: 22 GRPC response: {}
I0509 17:02:40.579157       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0509 17:02:40.579205       1 utils.go:199] ID: 23 GRPC request: {}
I0509 17:02:40.579227       1 utils.go:205] ID: 23 GRPC response: {}
I0509 17:02:45.020664       1 utils.go:198] ID: 24 Req-ID: pvc-736b9c54-f253-46f2-9ba0-0f91e4bb10d2 GRPC call: /csi.v1.Controller/CreateVolume
I0509 17:02:45.021093       1 utils.go:199] ID: 24 Req-ID: pvc-736b9c54-f253-46f2-9ba0-0f91e4bb10d2 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-736b9c54-f253-46f2-9ba0-0f91e4bb10d2","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-736b9c54-f253-46f2-9ba0-0f91e4bb10d2","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}}]}
I0509 17:02:45.021376       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-736b9c54-f253-46f2-9ba0-0f91e4bb10d2 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0509 17:02:45.040053       1 omap.go:80] ID: 24 Req-ID: pvc-736b9c54-f253-46f2-9ba0-0f91e4bb10d2 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0509 17:02:45.118710       1 omap.go:159] ID: 24 Req-ID: pvc-736b9c54-f253-46f2-9ba0-0f91e4bb10d2 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-736b9c54-f253-46f2-9ba0-0f91e4bb10d2:3ba78819-b4e4-40f6-9e89-c82d0bd86595])
I0509 17:02:45.125889       1 omap.go:159] ID: 24 Req-ID: pvc-736b9c54-f253-46f2-9ba0-0f91e4bb10d2 set omap keys (pool="kube", namespace="", name="csi.volume.3ba78819-b4e4-40f6-9e89-c82d0bd86595"): map[csi.imagename:csi-vol-3ba78819-b4e4-40f6-9e89-c82d0bd86595 csi.volname:pvc-736b9c54-f253-46f2-9ba0-0f91e4bb10d2 csi.volume.owner:default])
I0509 17:02:45.125915       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-736b9c54-f253-46f2-9ba0-0f91e4bb10d2 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-3ba78819-b4e4-40f6-9e89-c82d0bd86595) and image name (csi-vol-3ba78819-b4e4-40f6-9e89-c82d0bd86595) for request name (pvc-736b9c54-f253-46f2-9ba0-0f91e4bb10d2)
I0509 17:02:45.125991       1 rbd_util.go:423] ID: 24 Req-ID: pvc-736b9c54-f253-46f2-9ba0-0f91e4bb10d2 rbd: create kube/csi-vol-3ba78819-b4e4-40f6-9e89-c82d0bd86595 size 5120M (features: [layering]) using mon 199.204.45.205
I0509 17:02:45.126026       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-736b9c54-f253-46f2-9ba0-0f91e4bb10d2 setting image options on kube/csi-vol-3ba78819-b4e4-40f6-9e89-c82d0bd86595
I0509 17:02:46.710717       1 controllerserver.go:763] ID: 24 Req-ID: pvc-736b9c54-f253-46f2-9ba0-0f91e4bb10d2 created image kube/csi-vol-3ba78819-b4e4-40f6-9e89-c82d0bd86595 backed for request name pvc-736b9c54-f253-46f2-9ba0-0f91e4bb10d2
I0509 17:02:46.760415       1 omap.go:159] ID: 24 Req-ID: pvc-736b9c54-f253-46f2-9ba0-0f91e4bb10d2 set omap keys (pool="kube", namespace="", name="csi.volume.3ba78819-b4e4-40f6-9e89-c82d0bd86595"): map[csi.imageid:37d7a70c04df])
I0509 17:02:46.860909       1 utils.go:205] ID: 24 Req-ID: pvc-736b9c54-f253-46f2-9ba0-0f91e4bb10d2 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-3ba78819-b4e4-40f6-9e89-c82d0bd86595","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-3ba78819-b4e4-40f6-9e89-c82d0bd86595"}}
I0509 17:03:40.590105       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0509 17:03:40.590240       1 utils.go:199] ID: 25 GRPC request: {}
I0509 17:03:40.590281       1 utils.go:205] ID: 25 GRPC response: {}