I0616 11:40:16.552650       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0616 11:40:16.552777       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0616 11:40:16.552791       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0616 11:40:16.552805       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0616 11:40:16.552808       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0616 11:40:16.552811       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0616 11:40:16.552815       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0616 11:40:16.552818       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0616 11:40:16.552821       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0616 11:40:16.552823       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0616 11:40:16.553145       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0616 11:40:16.553220       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0616 11:40:21.335479       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0616 11:40:21.336727       1 utils.go:199] ID: 1 GRPC request: {}
I0616 11:40:21.336784       1 utils.go:205] ID: 1 GRPC response: {}
I0616 11:40:21.339295       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0616 11:40:21.339398       1 utils.go:199] ID: 2 GRPC request: {}
I0616 11:40:21.339419       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0616 11:40:21.339484       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0616 11:40:21.340595       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0616 11:40:21.340620       1 utils.go:199] ID: 3 GRPC request: {}
I0616 11:40:21.340639       1 utils.go:205] ID: 3 GRPC response: {}
I0616 11:40:21.341053       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0616 11:40:21.341223       1 utils.go:199] ID: 4 GRPC request: {}
I0616 11:40:21.341555       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0616 11:40:21.342457       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0616 11:40:21.342547       1 utils.go:199] ID: 5 GRPC request: {}
I0616 11:40:21.342558       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0616 11:40:21.342688       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}}}]}
I0616 11:40:23.435604       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0616 11:40:23.435710       1 utils.go:199] ID: 6 GRPC request: {}
I0616 11:40:23.435762       1 utils.go:205] ID: 6 GRPC response: {}
I0616 11:40:23.437766       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0616 11:40:23.437881       1 utils.go:199] ID: 7 GRPC request: {}
I0616 11:40:23.437929       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0616 11:40:23.437998       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0616 11:40:23.440654       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0616 11:40:23.440708       1 utils.go:199] ID: 8 GRPC request: {}
I0616 11:40:23.440733       1 utils.go:205] ID: 8 GRPC response: {}
I0616 11:40:23.441339       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0616 11:40:23.441410       1 utils.go:199] ID: 9 GRPC request: {}
I0616 11:40:23.441552       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0616 11:40:23.442693       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0616 11:40:23.442744       1 utils.go:199] ID: 10 GRPC request: {}
I0616 11:40:23.442767       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0616 11:40:23.442910       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}}}]}
I0616 11:40:23.444578       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0616 11:40:23.444623       1 utils.go:199] ID: 11 GRPC request: {}
I0616 11:40:23.444646       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0616 11:40:23.444735       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}}}]}
I0616 11:40:23.445497       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0616 11:40:23.445574       1 utils.go:199] ID: 12 GRPC request: {}
I0616 11:40:23.445592       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0616 11:40:23.445765       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}}}]}
I0616 11:40:25.110234       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0616 11:40:25.110276       1 utils.go:199] ID: 13 GRPC request: {}
I0616 11:40:25.110290       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0616 11:40:25.110311       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0616 11:40:25.112792       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0616 11:40:25.112808       1 utils.go:199] ID: 14 GRPC request: {}
I0616 11:40:25.112818       1 utils.go:205] ID: 14 GRPC response: {}
I0616 11:40:25.113720       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0616 11:40:25.113733       1 utils.go:199] ID: 15 GRPC request: {}
I0616 11:40:25.113739       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0616 11:40:25.113808       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}}}]}
I0616 11:40:26.674771       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0616 11:40:26.674817       1 utils.go:199] ID: 16 GRPC request: {}
I0616 11:40:26.674833       1 utils.go:205] ID: 16 GRPC response: {}
I0616 11:40:26.677276       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0616 11:40:26.677306       1 utils.go:199] ID: 17 GRPC request: {}
I0616 11:40:26.677322       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0616 11:40:26.677344       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0616 11:40:26.681123       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0616 11:40:26.681143       1 utils.go:199] ID: 18 GRPC request: {}
I0616 11:40:26.681160       1 utils.go:205] ID: 18 GRPC response: {}
I0616 11:40:26.681710       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0616 11:40:26.681731       1 utils.go:199] ID: 19 GRPC request: {}
I0616 11:40:26.681814       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0616 11:40:26.682754       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0616 11:40:26.682776       1 utils.go:199] ID: 20 GRPC request: {}
I0616 11:40:26.682796       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0616 11:40:26.682865       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}}}]}
I0616 11:41:26.854079       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0616 11:41:26.854136       1 utils.go:199] ID: 21 GRPC request: {}
I0616 11:41:26.854157       1 utils.go:205] ID: 21 GRPC response: {}
I0616 11:42:26.855240       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0616 11:42:26.855333       1 utils.go:199] ID: 22 GRPC request: {}
I0616 11:42:26.855538       1 utils.go:205] ID: 22 GRPC response: {}
I0616 11:43:26.853559       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0616 11:43:26.854270       1 utils.go:199] ID: 23 GRPC request: {}
I0616 11:43:26.854322       1 utils.go:205] ID: 23 GRPC response: {}
I0616 11:44:03.550949       1 utils.go:198] ID: 24 Req-ID: pvc-bcd6ddee-7fae-4a29-b56f-192a8f418719 GRPC call: /csi.v1.Controller/CreateVolume
I0616 11:44:03.551625       1 utils.go:199] ID: 24 Req-ID: pvc-bcd6ddee-7fae-4a29-b56f-192a8f418719 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-bcd6ddee-7fae-4a29-b56f-192a8f418719","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-bcd6ddee-7fae-4a29-b56f-192a8f418719","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}}]}
I0616 11:44:03.552080       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-bcd6ddee-7fae-4a29-b56f-192a8f418719 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0616 11:44:03.570511       1 omap.go:80] ID: 24 Req-ID: pvc-bcd6ddee-7fae-4a29-b56f-192a8f418719 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0616 11:44:03.723199       1 omap.go:159] ID: 24 Req-ID: pvc-bcd6ddee-7fae-4a29-b56f-192a8f418719 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-bcd6ddee-7fae-4a29-b56f-192a8f418719:ff06e048-48fd-4ac2-ba26-e86eeff34dc8])
I0616 11:44:03.738872       1 omap.go:159] ID: 24 Req-ID: pvc-bcd6ddee-7fae-4a29-b56f-192a8f418719 set omap keys (pool="kube", namespace="", name="csi.volume.ff06e048-48fd-4ac2-ba26-e86eeff34dc8"): map[csi.imagename:csi-vol-ff06e048-48fd-4ac2-ba26-e86eeff34dc8 csi.volname:pvc-bcd6ddee-7fae-4a29-b56f-192a8f418719 csi.volume.owner:default])
I0616 11:44:03.738910       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-bcd6ddee-7fae-4a29-b56f-192a8f418719 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-ff06e048-48fd-4ac2-ba26-e86eeff34dc8) and image name (csi-vol-ff06e048-48fd-4ac2-ba26-e86eeff34dc8) for request name (pvc-bcd6ddee-7fae-4a29-b56f-192a8f418719)
I0616 11:44:03.739011       1 rbd_util.go:423] ID: 24 Req-ID: pvc-bcd6ddee-7fae-4a29-b56f-192a8f418719 rbd: create kube/csi-vol-ff06e048-48fd-4ac2-ba26-e86eeff34dc8 size 5120M (features: [layering]) using mon 199.204.45.140
I0616 11:44:03.739075       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-bcd6ddee-7fae-4a29-b56f-192a8f418719 setting image options on kube/csi-vol-ff06e048-48fd-4ac2-ba26-e86eeff34dc8
I0616 11:44:03.775795       1 controllerserver.go:763] ID: 24 Req-ID: pvc-bcd6ddee-7fae-4a29-b56f-192a8f418719 created image kube/csi-vol-ff06e048-48fd-4ac2-ba26-e86eeff34dc8 backed for request name pvc-bcd6ddee-7fae-4a29-b56f-192a8f418719
I0616 11:44:03.810431       1 omap.go:159] ID: 24 Req-ID: pvc-bcd6ddee-7fae-4a29-b56f-192a8f418719 set omap keys (pool="kube", namespace="", name="csi.volume.ff06e048-48fd-4ac2-ba26-e86eeff34dc8"): map[csi.imageid:37ed655e55fc])
I0616 11:44:03.933652       1 utils.go:205] ID: 24 Req-ID: pvc-bcd6ddee-7fae-4a29-b56f-192a8f418719 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-ff06e048-48fd-4ac2-ba26-e86eeff34dc8","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-ff06e048-48fd-4ac2-ba26-e86eeff34dc8"}}
I0616 11:44:26.864471       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0616 11:44:26.864524       1 utils.go:199] ID: 25 GRPC request: {}
I0616 11:44:26.864555       1 utils.go:205] ID: 25 GRPC response: {}