I0624 05:29:50.827556       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0624 05:29:50.827669       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0624 05:29:50.827683       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0624 05:29:50.827699       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0624 05:29:50.827702       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0624 05:29:50.827705       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0624 05:29:50.827708       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0624 05:29:50.827711       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0624 05:29:50.827714       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0624 05:29:50.827718       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0624 05:29:50.827986       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0624 05:29:50.828017       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0624 05:29:55.427505       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0624 05:29:55.429659       1 utils.go:199] ID: 1 GRPC request: {}
I0624 05:29:55.429925       1 utils.go:205] ID: 1 GRPC response: {}
I0624 05:29:55.434515       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0624 05:29:55.434621       1 utils.go:199] ID: 2 GRPC request: {}
I0624 05:29:55.434660       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0624 05:29:55.434717       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0624 05:29:55.436508       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0624 05:29:55.436538       1 utils.go:199] ID: 3 GRPC request: {}
I0624 05:29:55.436557       1 utils.go:205] ID: 3 GRPC response: {}
I0624 05:29:55.437344       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0624 05:29:55.437549       1 utils.go:199] ID: 4 GRPC request: {}
I0624 05:29:55.439714       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0624 05:29:55.440934       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0624 05:29:55.441051       1 utils.go:199] ID: 5 GRPC request: {}
I0624 05:29:55.441098       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0624 05:29:55.441251       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}}}]}
I0624 05:29:57.369091       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0624 05:29:57.369169       1 utils.go:199] ID: 6 GRPC request: {}
I0624 05:29:57.369211       1 utils.go:205] ID: 6 GRPC response: {}
I0624 05:29:57.370890       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0624 05:29:57.371102       1 utils.go:199] ID: 7 GRPC request: {}
I0624 05:29:57.371147       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0624 05:29:57.371250       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0624 05:29:57.373069       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0624 05:29:57.373102       1 utils.go:199] ID: 8 GRPC request: {}
I0624 05:29:57.373119       1 utils.go:205] ID: 8 GRPC response: {}
I0624 05:29:57.373525       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0624 05:29:57.373539       1 utils.go:199] ID: 9 GRPC request: {}
I0624 05:29:57.373615       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0624 05:29:57.374060       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0624 05:29:57.374081       1 utils.go:199] ID: 10 GRPC request: {}
I0624 05:29:57.374089       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0624 05:29:57.374155       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}}}]}
I0624 05:29:57.374522       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0624 05:29:57.374537       1 utils.go:199] ID: 11 GRPC request: {}
I0624 05:29:57.374540       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0624 05:29:57.374582       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}}}]}
I0624 05:29:57.374794       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0624 05:29:57.374807       1 utils.go:199] ID: 12 GRPC request: {}
I0624 05:29:57.374811       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0624 05:29:57.374853       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}}}]}
I0624 05:29:58.981455       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0624 05:29:58.981514       1 utils.go:199] ID: 13 GRPC request: {}
I0624 05:29:58.981527       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0624 05:29:58.981572       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0624 05:29:58.984836       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0624 05:29:58.984864       1 utils.go:199] ID: 14 GRPC request: {}
I0624 05:29:58.984882       1 utils.go:205] ID: 14 GRPC response: {}
I0624 05:29:58.985405       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0624 05:29:58.985430       1 utils.go:199] ID: 15 GRPC request: {}
I0624 05:29:58.985441       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0624 05:29:58.985558       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}}}]}
I0624 05:30:00.655426       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0624 05:30:00.655463       1 utils.go:199] ID: 16 GRPC request: {}
I0624 05:30:00.655477       1 utils.go:205] ID: 16 GRPC response: {}
I0624 05:30:00.658010       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0624 05:30:00.658033       1 utils.go:199] ID: 17 GRPC request: {}
I0624 05:30:00.658040       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0624 05:30:00.658061       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0624 05:30:00.660474       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0624 05:30:00.660489       1 utils.go:199] ID: 18 GRPC request: {}
I0624 05:30:00.660500       1 utils.go:205] ID: 18 GRPC response: {}
I0624 05:30:00.664655       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0624 05:30:00.664668       1 utils.go:199] ID: 19 GRPC request: {}
I0624 05:30:00.664729       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0624 05:30:00.670667       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0624 05:30:00.670702       1 utils.go:199] ID: 20 GRPC request: {}
I0624 05:30:00.670711       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0624 05:30:00.670793       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}}}]}
I0624 05:31:00.826035       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0624 05:31:00.826071       1 utils.go:199] ID: 21 GRPC request: {}
I0624 05:31:00.826084       1 utils.go:205] ID: 21 GRPC response: {}
I0624 05:32:00.826492       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0624 05:32:00.826553       1 utils.go:199] ID: 22 GRPC request: {}
I0624 05:32:00.826579       1 utils.go:205] ID: 22 GRPC response: {}
I0624 05:33:00.825511       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0624 05:33:00.825569       1 utils.go:199] ID: 23 GRPC request: {}
I0624 05:33:00.825597       1 utils.go:205] ID: 23 GRPC response: {}
I0624 05:33:36.707482       1 utils.go:198] ID: 24 Req-ID: pvc-bfbe4fe8-1bfa-4dd7-88d4-1fb911ffe25d GRPC call: /csi.v1.Controller/CreateVolume
I0624 05:33:36.708061       1 utils.go:199] ID: 24 Req-ID: pvc-bfbe4fe8-1bfa-4dd7-88d4-1fb911ffe25d GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-bfbe4fe8-1bfa-4dd7-88d4-1fb911ffe25d","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-bfbe4fe8-1bfa-4dd7-88d4-1fb911ffe25d","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}}]}
I0624 05:33:36.708396       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-bfbe4fe8-1bfa-4dd7-88d4-1fb911ffe25d setting disableInUseChecks: false image features: [layering] mounter: rbd
E0624 05:33:36.727688       1 omap.go:80] ID: 24 Req-ID: pvc-bfbe4fe8-1bfa-4dd7-88d4-1fb911ffe25d omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0624 05:33:36.740737       1 omap.go:159] ID: 24 Req-ID: pvc-bfbe4fe8-1bfa-4dd7-88d4-1fb911ffe25d set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-bfbe4fe8-1bfa-4dd7-88d4-1fb911ffe25d:8ca64ca1-fb23-4a3b-b6f8-d5aceececccf])
I0624 05:33:36.745428       1 omap.go:159] ID: 24 Req-ID: pvc-bfbe4fe8-1bfa-4dd7-88d4-1fb911ffe25d set omap keys (pool="kube", namespace="", name="csi.volume.8ca64ca1-fb23-4a3b-b6f8-d5aceececccf"): map[csi.imagename:csi-vol-8ca64ca1-fb23-4a3b-b6f8-d5aceececccf csi.volname:pvc-bfbe4fe8-1bfa-4dd7-88d4-1fb911ffe25d csi.volume.owner:default])
I0624 05:33:36.745470       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-bfbe4fe8-1bfa-4dd7-88d4-1fb911ffe25d generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-8ca64ca1-fb23-4a3b-b6f8-d5aceececccf) and image name (csi-vol-8ca64ca1-fb23-4a3b-b6f8-d5aceececccf) for request name (pvc-bfbe4fe8-1bfa-4dd7-88d4-1fb911ffe25d)
I0624 05:33:36.745604       1 rbd_util.go:423] ID: 24 Req-ID: pvc-bfbe4fe8-1bfa-4dd7-88d4-1fb911ffe25d rbd: create kube/csi-vol-8ca64ca1-fb23-4a3b-b6f8-d5aceececccf size 5120M (features: [layering]) using mon 199.204.45.115
I0624 05:33:36.745699       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-bfbe4fe8-1bfa-4dd7-88d4-1fb911ffe25d setting image options on kube/csi-vol-8ca64ca1-fb23-4a3b-b6f8-d5aceececccf
I0624 05:33:36.769512       1 controllerserver.go:763] ID: 24 Req-ID: pvc-bfbe4fe8-1bfa-4dd7-88d4-1fb911ffe25d created image kube/csi-vol-8ca64ca1-fb23-4a3b-b6f8-d5aceececccf backed for request name pvc-bfbe4fe8-1bfa-4dd7-88d4-1fb911ffe25d
I0624 05:33:36.793777       1 omap.go:159] ID: 24 Req-ID: pvc-bfbe4fe8-1bfa-4dd7-88d4-1fb911ffe25d set omap keys (pool="kube", namespace="", name="csi.volume.8ca64ca1-fb23-4a3b-b6f8-d5aceececccf"): map[csi.imageid:37edf0c8c54])
I0624 05:33:36.864502       1 utils.go:205] ID: 24 Req-ID: pvc-bfbe4fe8-1bfa-4dd7-88d4-1fb911ffe25d GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-8ca64ca1-fb23-4a3b-b6f8-d5aceececccf","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-8ca64ca1-fb23-4a3b-b6f8-d5aceececccf"}}
I0624 05:34:00.829330       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0624 05:34:00.829406       1 utils.go:199] ID: 25 GRPC request: {}
I0624 05:34:00.829430       1 utils.go:205] ID: 25 GRPC response: {}