I0218 02:57:39.865162       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0218 02:57:39.865310       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0218 02:57:39.865325       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0218 02:57:39.865329       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0218 02:57:39.865332       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0218 02:57:39.865335       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0218 02:57:39.865338       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0218 02:57:39.865341       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0218 02:57:39.865344       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0218 02:57:39.865349       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0218 02:57:39.865575       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0218 02:57:39.865605       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0218 02:57:43.559800       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0218 02:57:43.561088       1 utils.go:199] ID: 1 GRPC request: {}
I0218 02:57:43.561235       1 utils.go:205] ID: 1 GRPC response: {}
I0218 02:57:43.562887       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0218 02:57:43.562968       1 utils.go:199] ID: 2 GRPC request: {}
I0218 02:57:43.563015       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0218 02:57:43.563093       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0218 02:57:43.566821       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0218 02:57:43.566938       1 utils.go:199] ID: 3 GRPC request: {}
I0218 02:57:43.567000       1 utils.go:205] ID: 3 GRPC response: {}
I0218 02:57:43.567672       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0218 02:57:43.567797       1 utils.go:199] ID: 4 GRPC request: {}
I0218 02:57:43.568019       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0218 02:57:43.577609       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0218 02:57:43.577797       1 utils.go:199] ID: 5 GRPC request: {}
I0218 02:57:43.577892       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0218 02:57:43.578097       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}}}]}
I0218 02:57:46.315741       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0218 02:57:46.315872       1 utils.go:199] ID: 6 GRPC request: {}
I0218 02:57:46.315949       1 utils.go:205] ID: 6 GRPC response: {}
I0218 02:57:46.319926       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0218 02:57:46.319999       1 utils.go:199] ID: 7 GRPC request: {}
I0218 02:57:46.320060       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0218 02:57:46.320137       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0218 02:57:46.323473       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0218 02:57:46.323550       1 utils.go:199] ID: 8 GRPC request: {}
I0218 02:57:46.323597       1 utils.go:205] ID: 8 GRPC response: {}
I0218 02:57:46.323945       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0218 02:57:46.324082       1 utils.go:199] ID: 9 GRPC request: {}
I0218 02:57:46.324228       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0218 02:57:46.324703       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0218 02:57:46.324773       1 utils.go:199] ID: 10 GRPC request: {}
I0218 02:57:46.324837       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0218 02:57:46.324954       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}}}]}
I0218 02:57:46.325291       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0218 02:57:46.325354       1 utils.go:199] ID: 11 GRPC request: {}
I0218 02:57:46.325418       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0218 02:57:46.325516       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}}}]}
I0218 02:57:46.325780       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0218 02:57:46.325839       1 utils.go:199] ID: 12 GRPC request: {}
I0218 02:57:46.325876       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0218 02:57:46.325962       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}}}]}
I0218 02:57:50.556174       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0218 02:57:50.556235       1 utils.go:199] ID: 13 GRPC request: {}
I0218 02:57:50.556244       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0218 02:57:50.556279       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0218 02:57:50.558940       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0218 02:57:50.559002       1 utils.go:199] ID: 14 GRPC request: {}
I0218 02:57:50.559023       1 utils.go:205] ID: 14 GRPC response: {}
I0218 02:57:50.559422       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0218 02:57:50.559480       1 utils.go:199] ID: 15 GRPC request: {}
I0218 02:57:50.559489       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0218 02:57:50.559597       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}}}]}
I0218 02:57:53.369943       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0218 02:57:53.369984       1 utils.go:199] ID: 16 GRPC request: {}
I0218 02:57:53.370001       1 utils.go:205] ID: 16 GRPC response: {}
I0218 02:57:53.386840       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0218 02:57:53.386875       1 utils.go:199] ID: 17 GRPC request: {}
I0218 02:57:53.386882       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0218 02:57:53.386917       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0218 02:57:53.394112       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0218 02:57:53.394135       1 utils.go:199] ID: 18 GRPC request: {}
I0218 02:57:53.394148       1 utils.go:205] ID: 18 GRPC response: {}
I0218 02:57:53.399145       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0218 02:57:53.399173       1 utils.go:199] ID: 19 GRPC request: {}
I0218 02:57:53.399244       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0218 02:57:53.402267       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0218 02:57:53.402302       1 utils.go:199] ID: 20 GRPC request: {}
I0218 02:57:53.402308       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0218 02:57:53.402368       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}}}]}
I0218 02:58:53.790043       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0218 02:58:53.790072       1 utils.go:199] ID: 21 GRPC request: {}
I0218 02:58:53.790084       1 utils.go:205] ID: 21 GRPC response: {}
I0218 02:59:53.718021       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0218 02:59:53.718058       1 utils.go:199] ID: 22 GRPC request: {}
I0218 02:59:53.718087       1 utils.go:205] ID: 22 GRPC response: {}
I0218 03:00:53.716207       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0218 03:00:53.716292       1 utils.go:199] ID: 23 GRPC request: {}
I0218 03:00:53.716337       1 utils.go:205] ID: 23 GRPC response: {}
I0218 03:01:10.541495       1 utils.go:198] ID: 24 Req-ID: pvc-5b4fbc3e-fe8d-4224-85dc-917089ace87f GRPC call: /csi.v1.Controller/CreateVolume
I0218 03:01:10.542683       1 utils.go:199] ID: 24 Req-ID: pvc-5b4fbc3e-fe8d-4224-85dc-917089ace87f GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-5b4fbc3e-fe8d-4224-85dc-917089ace87f","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-5b4fbc3e-fe8d-4224-85dc-917089ace87f","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}}]}
I0218 03:01:10.542982       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-5b4fbc3e-fe8d-4224-85dc-917089ace87f setting disableInUseChecks: false image features: [layering] mounter: rbd
E0218 03:01:10.561147       1 omap.go:80] ID: 24 Req-ID: pvc-5b4fbc3e-fe8d-4224-85dc-917089ace87f omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0218 03:01:10.660278       1 omap.go:159] ID: 24 Req-ID: pvc-5b4fbc3e-fe8d-4224-85dc-917089ace87f set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-5b4fbc3e-fe8d-4224-85dc-917089ace87f:591cad4f-ba26-47bc-bfe9-dbaff408b77f])
I0218 03:01:10.719913       1 omap.go:159] ID: 24 Req-ID: pvc-5b4fbc3e-fe8d-4224-85dc-917089ace87f set omap keys (pool="kube", namespace="", name="csi.volume.591cad4f-ba26-47bc-bfe9-dbaff408b77f"): map[csi.imagename:csi-vol-591cad4f-ba26-47bc-bfe9-dbaff408b77f csi.volname:pvc-5b4fbc3e-fe8d-4224-85dc-917089ace87f csi.volume.owner:default])
I0218 03:01:10.719939       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-5b4fbc3e-fe8d-4224-85dc-917089ace87f generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-591cad4f-ba26-47bc-bfe9-dbaff408b77f) and image name (csi-vol-591cad4f-ba26-47bc-bfe9-dbaff408b77f) for request name (pvc-5b4fbc3e-fe8d-4224-85dc-917089ace87f)
I0218 03:01:10.719996       1 rbd_util.go:423] ID: 24 Req-ID: pvc-5b4fbc3e-fe8d-4224-85dc-917089ace87f rbd: create kube/csi-vol-591cad4f-ba26-47bc-bfe9-dbaff408b77f size 5120M (features: [layering]) using mon 199.19.213.222
I0218 03:01:10.720036       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-5b4fbc3e-fe8d-4224-85dc-917089ace87f setting image options on kube/csi-vol-591cad4f-ba26-47bc-bfe9-dbaff408b77f
I0218 03:01:12.514226       1 controllerserver.go:763] ID: 24 Req-ID: pvc-5b4fbc3e-fe8d-4224-85dc-917089ace87f created image kube/csi-vol-591cad4f-ba26-47bc-bfe9-dbaff408b77f backed for request name pvc-5b4fbc3e-fe8d-4224-85dc-917089ace87f
I0218 03:01:12.555735       1 omap.go:159] ID: 24 Req-ID: pvc-5b4fbc3e-fe8d-4224-85dc-917089ace87f set omap keys (pool="kube", namespace="", name="csi.volume.591cad4f-ba26-47bc-bfe9-dbaff408b77f"): map[csi.imageid:37d5e9770e0])
I0218 03:01:12.977516       1 utils.go:205] ID: 24 Req-ID: pvc-5b4fbc3e-fe8d-4224-85dc-917089ace87f GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-591cad4f-ba26-47bc-bfe9-dbaff408b77f","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-591cad4f-ba26-47bc-bfe9-dbaff408b77f"}}
I0218 03:01:53.738329       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0218 03:01:53.746291       1 utils.go:199] ID: 25 GRPC request: {}
I0218 03:01:53.746316       1 utils.go:205] ID: 25 GRPC response: {}