I0415 19:38:53.602719       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0415 19:38:53.602963       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0415 19:38:53.602988       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0415 19:38:53.603008       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0415 19:38:53.603019       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0415 19:38:53.603023       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0415 19:38:53.603027       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0415 19:38:53.603030       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0415 19:38:53.603033       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0415 19:38:53.603037       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0415 19:38:53.603649       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0415 19:38:53.603667       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0415 19:38:56.671570       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0415 19:38:56.673139       1 utils.go:199] ID: 1 GRPC request: {}
I0415 19:38:56.673246       1 utils.go:205] ID: 1 GRPC response: {}
I0415 19:38:56.678162       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0415 19:38:56.678267       1 utils.go:199] ID: 2 GRPC request: {}
I0415 19:38:56.678810       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0415 19:38:56.678932       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0415 19:38:56.680774       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0415 19:38:56.680835       1 utils.go:199] ID: 3 GRPC request: {}
I0415 19:38:56.680864       1 utils.go:205] ID: 3 GRPC response: {}
I0415 19:38:56.681460       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0415 19:38:56.681527       1 utils.go:199] ID: 4 GRPC request: {}
I0415 19:38:56.681730       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0415 19:38:56.682745       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0415 19:38:56.682827       1 utils.go:199] ID: 5 GRPC request: {}
I0415 19:38:56.682842       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0415 19:38:56.682991       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}}}]}
I0415 19:38:58.879977       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0415 19:38:58.880056       1 utils.go:199] ID: 6 GRPC request: {}
I0415 19:38:58.880151       1 utils.go:205] ID: 6 GRPC response: {}
I0415 19:38:58.882497       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0415 19:38:58.882559       1 utils.go:199] ID: 7 GRPC request: {}
I0415 19:38:58.882579       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0415 19:38:58.882629       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0415 19:38:58.884651       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0415 19:38:58.884676       1 utils.go:199] ID: 8 GRPC request: {}
I0415 19:38:58.884695       1 utils.go:205] ID: 8 GRPC response: {}
I0415 19:38:58.885826       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0415 19:38:58.885856       1 utils.go:199] ID: 9 GRPC request: {}
I0415 19:38:58.885989       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0415 19:38:58.886870       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0415 19:38:58.886929       1 utils.go:199] ID: 10 GRPC request: {}
I0415 19:38:58.886938       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0415 19:38:58.887042       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}}}]}
I0415 19:38:58.887654       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0415 19:38:58.887679       1 utils.go:199] ID: 11 GRPC request: {}
I0415 19:38:58.887690       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0415 19:38:58.887789       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}}}]}
I0415 19:38:58.888244       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0415 19:38:58.888283       1 utils.go:199] ID: 12 GRPC request: {}
I0415 19:38:58.888293       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0415 19:38:58.888393       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}}}]}
I0415 19:39:00.098424       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0415 19:39:00.098493       1 utils.go:199] ID: 13 GRPC request: {}
I0415 19:39:00.098508       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0415 19:39:00.098595       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0415 19:39:00.102346       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0415 19:39:00.102379       1 utils.go:199] ID: 14 GRPC request: {}
I0415 19:39:00.102407       1 utils.go:205] ID: 14 GRPC response: {}
I0415 19:39:00.102905       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0415 19:39:00.102934       1 utils.go:199] ID: 15 GRPC request: {}
I0415 19:39:00.102952       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0415 19:39:00.103059       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}}}]}
I0415 19:39:01.341832       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0415 19:39:01.341871       1 utils.go:199] ID: 16 GRPC request: {}
I0415 19:39:01.341903       1 utils.go:205] ID: 16 GRPC response: {}
I0415 19:39:01.344940       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0415 19:39:01.344985       1 utils.go:199] ID: 17 GRPC request: {}
I0415 19:39:01.344993       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0415 19:39:01.345025       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0415 19:39:01.350029       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0415 19:39:01.350074       1 utils.go:199] ID: 18 GRPC request: {}
I0415 19:39:01.350095       1 utils.go:205] ID: 18 GRPC response: {}
I0415 19:39:01.350385       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0415 19:39:01.350413       1 utils.go:199] ID: 19 GRPC request: {}
I0415 19:39:01.350541       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0415 19:39:01.353200       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0415 19:39:01.353255       1 utils.go:199] ID: 20 GRPC request: {}
I0415 19:39:01.353269       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0415 19:39:01.353421       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}}}]}
I0415 19:40:01.565010       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0415 19:40:01.565578       1 utils.go:199] ID: 21 GRPC request: {}
I0415 19:40:01.565664       1 utils.go:205] ID: 21 GRPC response: {}
I0415 19:41:01.530658       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0415 19:41:01.530796       1 utils.go:199] ID: 22 GRPC request: {}
I0415 19:41:01.531038       1 utils.go:205] ID: 22 GRPC response: {}
I0415 19:42:01.525967       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0415 19:42:01.526021       1 utils.go:199] ID: 23 GRPC request: {}
I0415 19:42:01.526054       1 utils.go:205] ID: 23 GRPC response: {}
I0415 19:42:11.179523       1 utils.go:198] ID: 24 Req-ID: pvc-7e0bd85d-9b59-471e-a1e5-d422e2ee5e8c GRPC call: /csi.v1.Controller/CreateVolume
I0415 19:42:11.180053       1 utils.go:199] ID: 24 Req-ID: pvc-7e0bd85d-9b59-471e-a1e5-d422e2ee5e8c GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-7e0bd85d-9b59-471e-a1e5-d422e2ee5e8c","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-7e0bd85d-9b59-471e-a1e5-d422e2ee5e8c","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}}]}
I0415 19:42:11.180486       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-7e0bd85d-9b59-471e-a1e5-d422e2ee5e8c setting disableInUseChecks: false image features: [layering] mounter: rbd
E0415 19:42:11.199362       1 omap.go:80] ID: 24 Req-ID: pvc-7e0bd85d-9b59-471e-a1e5-d422e2ee5e8c omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0415 19:42:11.216442       1 omap.go:159] ID: 24 Req-ID: pvc-7e0bd85d-9b59-471e-a1e5-d422e2ee5e8c set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-7e0bd85d-9b59-471e-a1e5-d422e2ee5e8c:1583784a-fa08-4238-b8c8-df671b6b7678])
I0415 19:42:11.223797       1 omap.go:159] ID: 24 Req-ID: pvc-7e0bd85d-9b59-471e-a1e5-d422e2ee5e8c set omap keys (pool="kube", namespace="", name="csi.volume.1583784a-fa08-4238-b8c8-df671b6b7678"): map[csi.imagename:csi-vol-1583784a-fa08-4238-b8c8-df671b6b7678 csi.volname:pvc-7e0bd85d-9b59-471e-a1e5-d422e2ee5e8c csi.volume.owner:default])
I0415 19:42:11.223835       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-7e0bd85d-9b59-471e-a1e5-d422e2ee5e8c generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-1583784a-fa08-4238-b8c8-df671b6b7678) and image name (csi-vol-1583784a-fa08-4238-b8c8-df671b6b7678) for request name (pvc-7e0bd85d-9b59-471e-a1e5-d422e2ee5e8c)
I0415 19:42:11.223946       1 rbd_util.go:423] ID: 24 Req-ID: pvc-7e0bd85d-9b59-471e-a1e5-d422e2ee5e8c rbd: create kube/csi-vol-1583784a-fa08-4238-b8c8-df671b6b7678 size 5120M (features: [layering]) using mon 199.204.45.238
I0415 19:42:11.224029       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-7e0bd85d-9b59-471e-a1e5-d422e2ee5e8c setting image options on kube/csi-vol-1583784a-fa08-4238-b8c8-df671b6b7678
I0415 19:42:13.269922       1 controllerserver.go:763] ID: 24 Req-ID: pvc-7e0bd85d-9b59-471e-a1e5-d422e2ee5e8c created image kube/csi-vol-1583784a-fa08-4238-b8c8-df671b6b7678 backed for request name pvc-7e0bd85d-9b59-471e-a1e5-d422e2ee5e8c
I0415 19:42:13.308620       1 omap.go:159] ID: 24 Req-ID: pvc-7e0bd85d-9b59-471e-a1e5-d422e2ee5e8c set omap keys (pool="kube", namespace="", name="csi.volume.1583784a-fa08-4238-b8c8-df671b6b7678"): map[csi.imageid:37d9c7529756])
I0415 19:42:13.403105       1 utils.go:205] ID: 24 Req-ID: pvc-7e0bd85d-9b59-471e-a1e5-d422e2ee5e8c GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-1583784a-fa08-4238-b8c8-df671b6b7678","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-1583784a-fa08-4238-b8c8-df671b6b7678"}}
I0415 19:43:01.536858       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0415 19:43:01.536957       1 utils.go:199] ID: 25 GRPC request: {}
I0415 19:43:01.537018       1 utils.go:205] ID: 25 GRPC response: {}