I0225 17:06:28.270763       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0225 17:06:28.270869       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0225 17:06:28.270882       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0225 17:06:28.270885       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0225 17:06:28.270888       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0225 17:06:28.270890       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0225 17:06:28.270894       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0225 17:06:28.270896       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0225 17:06:28.270899       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0225 17:06:28.270901       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0225 17:06:28.271159       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0225 17:06:28.271161       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0225 17:06:40.035198       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0225 17:06:40.036767       1 utils.go:199] ID: 1 GRPC request: {}
I0225 17:06:40.036839       1 utils.go:205] ID: 1 GRPC response: {}
I0225 17:06:40.039261       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0225 17:06:40.039340       1 utils.go:199] ID: 2 GRPC request: {}
I0225 17:06:40.039360       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0225 17:06:40.039418       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0225 17:06:40.040886       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0225 17:06:40.041013       1 utils.go:199] ID: 3 GRPC request: {}
I0225 17:06:40.041033       1 utils.go:205] ID: 3 GRPC response: {}
I0225 17:06:40.041418       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0225 17:06:40.041472       1 utils.go:199] ID: 4 GRPC request: {}
I0225 17:06:40.041634       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0225 17:06:40.042295       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0225 17:06:40.042383       1 utils.go:199] ID: 5 GRPC request: {}
I0225 17:06:40.042398       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0225 17:06:40.042507       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}}}]}
I0225 17:06:44.150739       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0225 17:06:44.150775       1 utils.go:199] ID: 6 GRPC request: {}
I0225 17:06:44.150791       1 utils.go:205] ID: 6 GRPC response: {}
I0225 17:06:44.152999       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0225 17:06:44.153044       1 utils.go:199] ID: 7 GRPC request: {}
I0225 17:06:44.153097       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0225 17:06:44.153153       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0225 17:06:44.155910       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0225 17:06:44.155942       1 utils.go:199] ID: 8 GRPC request: {}
I0225 17:06:44.155959       1 utils.go:205] ID: 8 GRPC response: {}
I0225 17:06:44.156491       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0225 17:06:44.156538       1 utils.go:199] ID: 9 GRPC request: {}
I0225 17:06:44.156672       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0225 17:06:44.157274       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0225 17:06:44.157302       1 utils.go:199] ID: 10 GRPC request: {}
I0225 17:06:44.157310       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0225 17:06:44.157403       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}}}]}
I0225 17:06:44.157890       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0225 17:06:44.157908       1 utils.go:199] ID: 11 GRPC request: {}
I0225 17:06:44.157927       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0225 17:06:44.158075       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}}}]}
I0225 17:06:44.158401       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0225 17:06:44.158433       1 utils.go:199] ID: 12 GRPC request: {}
I0225 17:06:44.158451       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0225 17:06:44.158571       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}}}]}
I0225 17:06:46.595435       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0225 17:06:46.595473       1 utils.go:199] ID: 13 GRPC request: {}
I0225 17:06:46.595482       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0225 17:06:46.595534       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0225 17:06:46.598767       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0225 17:06:46.598818       1 utils.go:199] ID: 14 GRPC request: {}
I0225 17:06:46.598835       1 utils.go:205] ID: 14 GRPC response: {}
I0225 17:06:46.599571       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0225 17:06:46.599599       1 utils.go:199] ID: 15 GRPC request: {}
I0225 17:06:46.599623       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0225 17:06:46.599734       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}}}]}
I0225 17:06:48.648306       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0225 17:06:48.648338       1 utils.go:199] ID: 16 GRPC request: {}
I0225 17:06:48.648379       1 utils.go:205] ID: 16 GRPC response: {}
I0225 17:06:48.653011       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0225 17:06:48.653054       1 utils.go:199] ID: 17 GRPC request: {}
I0225 17:06:48.653062       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0225 17:06:48.653089       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0225 17:06:48.655290       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0225 17:06:48.655309       1 utils.go:199] ID: 18 GRPC request: {}
I0225 17:06:48.655321       1 utils.go:205] ID: 18 GRPC response: {}
I0225 17:06:48.655724       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0225 17:06:48.655740       1 utils.go:199] ID: 19 GRPC request: {}
I0225 17:06:48.655805       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0225 17:06:48.656490       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0225 17:06:48.656517       1 utils.go:199] ID: 20 GRPC request: {}
I0225 17:06:48.656526       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0225 17:06:48.656598       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}}}]}
I0225 17:07:48.829387       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0225 17:07:48.829428       1 utils.go:199] ID: 21 GRPC request: {}
I0225 17:07:48.829444       1 utils.go:205] ID: 21 GRPC response: {}
I0225 17:08:48.829364       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0225 17:08:48.829407       1 utils.go:199] ID: 22 GRPC request: {}
I0225 17:08:48.829423       1 utils.go:205] ID: 22 GRPC response: {}
I0225 17:09:37.080191       1 utils.go:198] ID: 23 Req-ID: pvc-2e17b37c-6fb9-4b51-bf27-2c386e7119f6 GRPC call: /csi.v1.Controller/CreateVolume
I0225 17:09:37.080668       1 utils.go:199] ID: 23 Req-ID: pvc-2e17b37c-6fb9-4b51-bf27-2c386e7119f6 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-2e17b37c-6fb9-4b51-bf27-2c386e7119f6","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-2e17b37c-6fb9-4b51-bf27-2c386e7119f6","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}}]}
I0225 17:09:37.081018       1 rbd_util.go:1315] ID: 23 Req-ID: pvc-2e17b37c-6fb9-4b51-bf27-2c386e7119f6 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0225 17:09:37.098802       1 omap.go:80] ID: 23 Req-ID: pvc-2e17b37c-6fb9-4b51-bf27-2c386e7119f6 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0225 17:09:37.110835       1 omap.go:159] ID: 23 Req-ID: pvc-2e17b37c-6fb9-4b51-bf27-2c386e7119f6 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-2e17b37c-6fb9-4b51-bf27-2c386e7119f6:3606b470-d61c-471b-8647-be768f7fbf0d])
I0225 17:09:37.119163       1 omap.go:159] ID: 23 Req-ID: pvc-2e17b37c-6fb9-4b51-bf27-2c386e7119f6 set omap keys (pool="kube", namespace="", name="csi.volume.3606b470-d61c-471b-8647-be768f7fbf0d"): map[csi.imagename:csi-vol-3606b470-d61c-471b-8647-be768f7fbf0d csi.volname:pvc-2e17b37c-6fb9-4b51-bf27-2c386e7119f6 csi.volume.owner:default])
I0225 17:09:37.119211       1 rbd_journal.go:491] ID: 23 Req-ID: pvc-2e17b37c-6fb9-4b51-bf27-2c386e7119f6 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-3606b470-d61c-471b-8647-be768f7fbf0d) and image name (csi-vol-3606b470-d61c-471b-8647-be768f7fbf0d) for request name (pvc-2e17b37c-6fb9-4b51-bf27-2c386e7119f6)
I0225 17:09:37.119436       1 rbd_util.go:423] ID: 23 Req-ID: pvc-2e17b37c-6fb9-4b51-bf27-2c386e7119f6 rbd: create kube/csi-vol-3606b470-d61c-471b-8647-be768f7fbf0d size 5120M (features: [layering]) using mon 199.19.213.234
I0225 17:09:37.119519       1 rbd_util.go:1563] ID: 23 Req-ID: pvc-2e17b37c-6fb9-4b51-bf27-2c386e7119f6 setting image options on kube/csi-vol-3606b470-d61c-471b-8647-be768f7fbf0d
I0225 17:09:38.372735       1 controllerserver.go:763] ID: 23 Req-ID: pvc-2e17b37c-6fb9-4b51-bf27-2c386e7119f6 created image kube/csi-vol-3606b470-d61c-471b-8647-be768f7fbf0d backed for request name pvc-2e17b37c-6fb9-4b51-bf27-2c386e7119f6
I0225 17:09:38.418209       1 omap.go:159] ID: 23 Req-ID: pvc-2e17b37c-6fb9-4b51-bf27-2c386e7119f6 set omap keys (pool="kube", namespace="", name="csi.volume.3606b470-d61c-471b-8647-be768f7fbf0d"): map[csi.imageid:37d96f05c8f7])
I0225 17:09:38.519620       1 utils.go:205] ID: 23 Req-ID: pvc-2e17b37c-6fb9-4b51-bf27-2c386e7119f6 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-3606b470-d61c-471b-8647-be768f7fbf0d","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-3606b470-d61c-471b-8647-be768f7fbf0d"}}
I0225 17:09:48.828856       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0225 17:09:48.828924       1 utils.go:199] ID: 24 GRPC request: {}
I0225 17:09:48.828950       1 utils.go:205] ID: 24 GRPC response: {}