I0525 17:55:47.823744       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0525 17:55:47.823875       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0525 17:55:47.823888       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0525 17:55:47.823891       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0525 17:55:47.823896       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0525 17:55:47.823898       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0525 17:55:47.823902       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0525 17:55:47.823905       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0525 17:55:47.823908       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0525 17:55:47.823911       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0525 17:55:47.824226       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0525 17:55:47.824325       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0525 17:55:50.897102       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0525 17:55:50.898702       1 utils.go:199] ID: 1 GRPC request: {}
I0525 17:55:50.898766       1 utils.go:205] ID: 1 GRPC response: {}
I0525 17:55:50.904832       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0525 17:55:50.904938       1 utils.go:199] ID: 2 GRPC request: {}
I0525 17:55:50.904953       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0525 17:55:50.905003       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0525 17:55:50.907833       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0525 17:55:50.907864       1 utils.go:199] ID: 3 GRPC request: {}
I0525 17:55:50.907877       1 utils.go:205] ID: 3 GRPC response: {}
I0525 17:55:50.908733       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0525 17:55:50.908836       1 utils.go:199] ID: 4 GRPC request: {}
I0525 17:55:50.909152       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0525 17:55:50.910101       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0525 17:55:50.910166       1 utils.go:199] ID: 5 GRPC request: {}
I0525 17:55:50.910179       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0525 17:55:50.910369       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 17:55:52.525642       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0525 17:55:52.525683       1 utils.go:199] ID: 6 GRPC request: {}
I0525 17:55:52.525856       1 utils.go:205] ID: 6 GRPC response: {}
I0525 17:55:52.529120       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0525 17:55:52.529158       1 utils.go:199] ID: 7 GRPC request: {}
I0525 17:55:52.529166       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0525 17:55:52.529191       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0525 17:55:52.531156       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0525 17:55:52.531176       1 utils.go:199] ID: 8 GRPC request: {}
I0525 17:55:52.531191       1 utils.go:205] ID: 8 GRPC response: {}
I0525 17:55:52.531624       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0525 17:55:52.531642       1 utils.go:199] ID: 9 GRPC request: {}
I0525 17:55:52.531730       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0525 17:55:52.532341       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0525 17:55:52.532364       1 utils.go:199] ID: 10 GRPC request: {}
I0525 17:55:52.532387       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0525 17:55:52.532493       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 17:55:52.533045       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0525 17:55:52.533092       1 utils.go:199] ID: 11 GRPC request: {}
I0525 17:55:52.533105       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0525 17:55:52.533188       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 17:55:52.533556       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0525 17:55:52.533578       1 utils.go:199] ID: 12 GRPC request: {}
I0525 17:55:52.533584       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0525 17:55:52.533716       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 17:55:54.658337       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0525 17:55:54.658400       1 utils.go:199] ID: 13 GRPC request: {}
I0525 17:55:54.658412       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0525 17:55:54.658444       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0525 17:55:54.662108       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0525 17:55:54.662142       1 utils.go:199] ID: 14 GRPC request: {}
I0525 17:55:54.662161       1 utils.go:205] ID: 14 GRPC response: {}
I0525 17:55:54.662771       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0525 17:55:54.662797       1 utils.go:199] ID: 15 GRPC request: {}
I0525 17:55:54.662806       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0525 17:55:54.663078       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 17:55:55.916743       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0525 17:55:55.916817       1 utils.go:199] ID: 16 GRPC request: {}
I0525 17:55:55.916843       1 utils.go:205] ID: 16 GRPC response: {}
I0525 17:55:55.922342       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0525 17:55:55.922383       1 utils.go:199] ID: 17 GRPC request: {}
I0525 17:55:55.922392       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0525 17:55:55.922419       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0525 17:55:55.925470       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0525 17:55:55.925501       1 utils.go:199] ID: 18 GRPC request: {}
I0525 17:55:55.925520       1 utils.go:205] ID: 18 GRPC response: {}
I0525 17:55:55.925985       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0525 17:55:55.926012       1 utils.go:199] ID: 19 GRPC request: {}
I0525 17:55:55.926102       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0525 17:55:55.927057       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0525 17:55:55.927100       1 utils.go:199] ID: 20 GRPC request: {}
I0525 17:55:55.927145       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0525 17:55:55.927448       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 17:56:56.111939       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0525 17:56:56.111983       1 utils.go:199] ID: 21 GRPC request: {}
I0525 17:56:56.112001       1 utils.go:205] ID: 21 GRPC response: {}
I0525 17:57:56.116345       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0525 17:57:56.116415       1 utils.go:199] ID: 22 GRPC request: {}
I0525 17:57:56.116449       1 utils.go:205] ID: 22 GRPC response: {}
I0525 17:58:56.111782       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0525 17:58:56.111826       1 utils.go:199] ID: 23 GRPC request: {}
I0525 17:58:56.111843       1 utils.go:205] ID: 23 GRPC response: {}
I0525 17:59:36.994212       1 utils.go:198] ID: 24 Req-ID: pvc-de9ac5f5-836f-4e53-ba12-1ec9a64ab65f GRPC call: /csi.v1.Controller/CreateVolume
I0525 17:59:36.994593       1 utils.go:199] ID: 24 Req-ID: pvc-de9ac5f5-836f-4e53-ba12-1ec9a64ab65f GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-de9ac5f5-836f-4e53-ba12-1ec9a64ab65f","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-de9ac5f5-836f-4e53-ba12-1ec9a64ab65f","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 17:59:36.994864       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-de9ac5f5-836f-4e53-ba12-1ec9a64ab65f setting disableInUseChecks: false image features: [layering] mounter: rbd
E0525 17:59:37.016001       1 omap.go:80] ID: 24 Req-ID: pvc-de9ac5f5-836f-4e53-ba12-1ec9a64ab65f omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0525 17:59:37.030718       1 omap.go:159] ID: 24 Req-ID: pvc-de9ac5f5-836f-4e53-ba12-1ec9a64ab65f set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-de9ac5f5-836f-4e53-ba12-1ec9a64ab65f:1c5ecc9f-dfbd-40fd-9bef-e841e8f804eb])
I0525 17:59:37.038685       1 omap.go:159] ID: 24 Req-ID: pvc-de9ac5f5-836f-4e53-ba12-1ec9a64ab65f set omap keys (pool="kube", namespace="", name="csi.volume.1c5ecc9f-dfbd-40fd-9bef-e841e8f804eb"): map[csi.imagename:csi-vol-1c5ecc9f-dfbd-40fd-9bef-e841e8f804eb csi.volname:pvc-de9ac5f5-836f-4e53-ba12-1ec9a64ab65f csi.volume.owner:default])
I0525 17:59:37.038768       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-de9ac5f5-836f-4e53-ba12-1ec9a64ab65f generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-1c5ecc9f-dfbd-40fd-9bef-e841e8f804eb) and image name (csi-vol-1c5ecc9f-dfbd-40fd-9bef-e841e8f804eb) for request name (pvc-de9ac5f5-836f-4e53-ba12-1ec9a64ab65f)
I0525 17:59:37.038958       1 rbd_util.go:423] ID: 24 Req-ID: pvc-de9ac5f5-836f-4e53-ba12-1ec9a64ab65f rbd: create kube/csi-vol-1c5ecc9f-dfbd-40fd-9bef-e841e8f804eb size 5120M (features: [layering]) using mon 199.204.45.162
I0525 17:59:37.039086       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-de9ac5f5-836f-4e53-ba12-1ec9a64ab65f setting image options on kube/csi-vol-1c5ecc9f-dfbd-40fd-9bef-e841e8f804eb
I0525 17:59:37.072287       1 controllerserver.go:763] ID: 24 Req-ID: pvc-de9ac5f5-836f-4e53-ba12-1ec9a64ab65f created image kube/csi-vol-1c5ecc9f-dfbd-40fd-9bef-e841e8f804eb backed for request name pvc-de9ac5f5-836f-4e53-ba12-1ec9a64ab65f
I0525 17:59:37.102918       1 omap.go:159] ID: 24 Req-ID: pvc-de9ac5f5-836f-4e53-ba12-1ec9a64ab65f set omap keys (pool="kube", namespace="", name="csi.volume.1c5ecc9f-dfbd-40fd-9bef-e841e8f804eb"): map[csi.imageid:37ed911188d5])
I0525 17:59:37.184023       1 utils.go:205] ID: 24 Req-ID: pvc-de9ac5f5-836f-4e53-ba12-1ec9a64ab65f GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-1c5ecc9f-dfbd-40fd-9bef-e841e8f804eb","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-1c5ecc9f-dfbd-40fd-9bef-e841e8f804eb"}}
I0525 17:59:56.122158       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0525 17:59:56.122211       1 utils.go:199] ID: 25 GRPC request: {}
I0525 17:59:56.122232       1 utils.go:205] ID: 25 GRPC response: {}