I0525 00:47:49.432278       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0525 00:47:49.432413       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0525 00:47:49.432425       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0525 00:47:49.432430       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0525 00:47:49.432434       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0525 00:47:49.432440       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0525 00:47:49.432453       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0525 00:47:49.432459       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0525 00:47:49.432467       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0525 00:47:49.432471       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0525 00:47:49.432805       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0525 00:47:49.432819       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0525 00:47:51.486178       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0525 00:47:51.487582       1 utils.go:199] ID: 1 GRPC request: {}
I0525 00:47:51.487647       1 utils.go:205] ID: 1 GRPC response: {}
I0525 00:47:51.489680       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0525 00:47:51.489728       1 utils.go:199] ID: 2 GRPC request: {}
I0525 00:47:51.489744       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0525 00:47:51.489786       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0525 00:47:51.491402       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0525 00:47:51.491444       1 utils.go:199] ID: 3 GRPC request: {}
I0525 00:47:51.491462       1 utils.go:205] ID: 3 GRPC response: {}
I0525 00:47:51.491731       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0525 00:47:51.491795       1 utils.go:199] ID: 4 GRPC request: {}
I0525 00:47:51.491929       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0525 00:47:51.492424       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0525 00:47:51.492458       1 utils.go:199] ID: 5 GRPC request: {}
I0525 00:47:51.492468       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0525 00:47:51.492543       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}}}]}
I0525 00:47:52.688192       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0525 00:47:52.688280       1 utils.go:199] ID: 6 GRPC request: {}
I0525 00:47:52.688300       1 utils.go:205] ID: 6 GRPC response: {}
I0525 00:47:52.691175       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0525 00:47:52.691242       1 utils.go:199] ID: 7 GRPC request: {}
I0525 00:47:52.691312       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0525 00:47:52.691365       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0525 00:47:52.694599       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0525 00:47:52.694646       1 utils.go:199] ID: 8 GRPC request: {}
I0525 00:47:52.694665       1 utils.go:205] ID: 8 GRPC response: {}
I0525 00:47:52.695815       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0525 00:47:52.695855       1 utils.go:199] ID: 9 GRPC request: {}
I0525 00:47:52.696131       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0525 00:47:52.696805       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0525 00:47:52.696843       1 utils.go:199] ID: 10 GRPC request: {}
I0525 00:47:52.696852       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0525 00:47:52.696941       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}}}]}
I0525 00:47:52.697694       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0525 00:47:52.697726       1 utils.go:199] ID: 11 GRPC request: {}
I0525 00:47:52.697734       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0525 00:47:52.697862       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}}}]}
I0525 00:47:52.698143       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0525 00:47:52.698172       1 utils.go:199] ID: 12 GRPC request: {}
I0525 00:47:52.698180       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0525 00:47:52.698742       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}}}]}
I0525 00:47:54.548715       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0525 00:47:54.548789       1 utils.go:199] ID: 13 GRPC request: {}
I0525 00:47:54.548809       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0525 00:47:54.548864       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0525 00:47:54.552380       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0525 00:47:54.552403       1 utils.go:199] ID: 14 GRPC request: {}
I0525 00:47:54.552419       1 utils.go:205] ID: 14 GRPC response: {}
I0525 00:47:54.553211       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0525 00:47:54.553258       1 utils.go:199] ID: 15 GRPC request: {}
I0525 00:47:54.553272       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0525 00:47:54.553363       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}}}]}
I0525 00:47:57.458284       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0525 00:47:57.458340       1 utils.go:199] ID: 16 GRPC request: {}
I0525 00:47:57.458363       1 utils.go:205] ID: 16 GRPC response: {}
I0525 00:47:57.461321       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0525 00:47:57.461347       1 utils.go:199] ID: 17 GRPC request: {}
I0525 00:47:57.461355       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0525 00:47:57.461378       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0525 00:47:57.466919       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0525 00:47:57.466954       1 utils.go:199] ID: 18 GRPC request: {}
I0525 00:47:57.466981       1 utils.go:205] ID: 18 GRPC response: {}
I0525 00:47:57.467428       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0525 00:47:57.467444       1 utils.go:199] ID: 19 GRPC request: {}
I0525 00:47:57.467576       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0525 00:47:57.468239       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0525 00:47:57.468264       1 utils.go:199] ID: 20 GRPC request: {}
I0525 00:47:57.468272       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0525 00:47:57.468350       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}}}]}
I0525 00:48:57.621431       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0525 00:48:57.621470       1 utils.go:199] ID: 21 GRPC request: {}
I0525 00:48:57.621490       1 utils.go:205] ID: 21 GRPC response: {}
I0525 00:49:57.622330       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0525 00:49:57.622644       1 utils.go:199] ID: 22 GRPC request: {}
I0525 00:49:57.622754       1 utils.go:205] ID: 22 GRPC response: {}
I0525 00:50:57.677274       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0525 00:50:57.677342       1 utils.go:199] ID: 23 GRPC request: {}
I0525 00:50:57.677372       1 utils.go:205] ID: 23 GRPC response: {}
I0525 00:51:33.569254       1 utils.go:198] ID: 24 Req-ID: pvc-7b13db09-da85-4657-821c-e773e76caf1f GRPC call: /csi.v1.Controller/CreateVolume
I0525 00:51:33.569599       1 utils.go:199] ID: 24 Req-ID: pvc-7b13db09-da85-4657-821c-e773e76caf1f GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-7b13db09-da85-4657-821c-e773e76caf1f","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-7b13db09-da85-4657-821c-e773e76caf1f","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}}]}
I0525 00:51:33.569879       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-7b13db09-da85-4657-821c-e773e76caf1f setting disableInUseChecks: false image features: [layering] mounter: rbd
E0525 00:51:33.588945       1 omap.go:80] ID: 24 Req-ID: pvc-7b13db09-da85-4657-821c-e773e76caf1f omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0525 00:51:33.602411       1 omap.go:159] ID: 24 Req-ID: pvc-7b13db09-da85-4657-821c-e773e76caf1f set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-7b13db09-da85-4657-821c-e773e76caf1f:84211dc5-b87f-4300-a3bb-5f112daa7e23])
I0525 00:51:33.608501       1 omap.go:159] ID: 24 Req-ID: pvc-7b13db09-da85-4657-821c-e773e76caf1f set omap keys (pool="kube", namespace="", name="csi.volume.84211dc5-b87f-4300-a3bb-5f112daa7e23"): map[csi.imagename:csi-vol-84211dc5-b87f-4300-a3bb-5f112daa7e23 csi.volname:pvc-7b13db09-da85-4657-821c-e773e76caf1f csi.volume.owner:default])
I0525 00:51:33.608537       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-7b13db09-da85-4657-821c-e773e76caf1f generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-84211dc5-b87f-4300-a3bb-5f112daa7e23) and image name (csi-vol-84211dc5-b87f-4300-a3bb-5f112daa7e23) for request name (pvc-7b13db09-da85-4657-821c-e773e76caf1f)
I0525 00:51:33.608688       1 rbd_util.go:423] ID: 24 Req-ID: pvc-7b13db09-da85-4657-821c-e773e76caf1f rbd: create kube/csi-vol-84211dc5-b87f-4300-a3bb-5f112daa7e23 size 5120M (features: [layering]) using mon 199.204.45.78
I0525 00:51:33.608763       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-7b13db09-da85-4657-821c-e773e76caf1f setting image options on kube/csi-vol-84211dc5-b87f-4300-a3bb-5f112daa7e23
I0525 00:51:33.642190       1 controllerserver.go:763] ID: 24 Req-ID: pvc-7b13db09-da85-4657-821c-e773e76caf1f created image kube/csi-vol-84211dc5-b87f-4300-a3bb-5f112daa7e23 backed for request name pvc-7b13db09-da85-4657-821c-e773e76caf1f
I0525 00:51:33.679049       1 omap.go:159] ID: 24 Req-ID: pvc-7b13db09-da85-4657-821c-e773e76caf1f set omap keys (pool="kube", namespace="", name="csi.volume.84211dc5-b87f-4300-a3bb-5f112daa7e23"): map[csi.imageid:37edf916b1d3])
I0525 00:51:33.772006       1 utils.go:205] ID: 24 Req-ID: pvc-7b13db09-da85-4657-821c-e773e76caf1f GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-84211dc5-b87f-4300-a3bb-5f112daa7e23","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-84211dc5-b87f-4300-a3bb-5f112daa7e23"}}
I0525 00:51:57.633457       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0525 00:51:57.633494       1 utils.go:199] ID: 25 GRPC request: {}
I0525 00:51:57.633517       1 utils.go:205] ID: 25 GRPC response: {}