I0412 20:51:23.490339       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0412 20:51:23.490459       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0412 20:51:23.490474       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0412 20:51:23.490479       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0412 20:51:23.490482       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0412 20:51:23.490486       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0412 20:51:23.490491       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0412 20:51:23.490495       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0412 20:51:23.490501       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0412 20:51:23.490508       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0412 20:51:23.490767       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0412 20:51:23.490791       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0412 20:51:37.393119       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0412 20:51:37.394970       1 utils.go:199] ID: 1 GRPC request: {}
I0412 20:51:37.395080       1 utils.go:205] ID: 1 GRPC response: {}
I0412 20:51:37.398094       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0412 20:51:37.398201       1 utils.go:199] ID: 2 GRPC request: {}
I0412 20:51:37.398227       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0412 20:51:37.398295       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0412 20:51:37.399946       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0412 20:51:37.399993       1 utils.go:199] ID: 3 GRPC request: {}
I0412 20:51:37.400017       1 utils.go:205] ID: 3 GRPC response: {}
I0412 20:51:37.400405       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0412 20:51:37.400492       1 utils.go:199] ID: 4 GRPC request: {}
I0412 20:51:37.400742       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0412 20:51:37.401671       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0412 20:51:37.401819       1 utils.go:199] ID: 5 GRPC request: {}
I0412 20:51:37.401841       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0412 20:51:37.402095       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}}}]}
I0412 20:51:39.608436       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0412 20:51:39.608475       1 utils.go:199] ID: 6 GRPC request: {}
I0412 20:51:39.608491       1 utils.go:205] ID: 6 GRPC response: {}
I0412 20:51:39.611340       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0412 20:51:39.611367       1 utils.go:199] ID: 7 GRPC request: {}
I0412 20:51:39.611375       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0412 20:51:39.611405       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0412 20:51:39.615305       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0412 20:51:39.615340       1 utils.go:199] ID: 8 GRPC request: {}
I0412 20:51:39.615364       1 utils.go:205] ID: 8 GRPC response: {}
I0412 20:51:39.615832       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0412 20:51:39.615869       1 utils.go:199] ID: 9 GRPC request: {}
I0412 20:51:39.616105       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0412 20:51:39.616788       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0412 20:51:39.616890       1 utils.go:199] ID: 10 GRPC request: {}
I0412 20:51:39.616936       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0412 20:51:39.617152       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}}}]}
I0412 20:51:39.617754       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0412 20:51:39.617808       1 utils.go:199] ID: 11 GRPC request: {}
I0412 20:51:39.617881       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0412 20:51:39.618102       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}}}]}
I0412 20:51:39.618562       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0412 20:51:39.618588       1 utils.go:199] ID: 12 GRPC request: {}
I0412 20:51:39.618618       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0412 20:51:39.618783       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}}}]}
I0412 20:51:42.905672       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0412 20:51:42.905737       1 utils.go:199] ID: 13 GRPC request: {}
I0412 20:51:42.905747       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0412 20:51:42.905805       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0412 20:51:42.907506       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0412 20:51:42.907593       1 utils.go:199] ID: 14 GRPC request: {}
I0412 20:51:42.907676       1 utils.go:205] ID: 14 GRPC response: {}
I0412 20:51:42.908309       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0412 20:51:42.908327       1 utils.go:199] ID: 15 GRPC request: {}
I0412 20:51:42.908334       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0412 20:51:42.908421       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}}}]}
I0412 20:51:44.901497       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0412 20:51:44.901549       1 utils.go:199] ID: 16 GRPC request: {}
I0412 20:51:44.901564       1 utils.go:205] ID: 16 GRPC response: {}
I0412 20:51:44.904515       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0412 20:51:44.904548       1 utils.go:199] ID: 17 GRPC request: {}
I0412 20:51:44.904560       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0412 20:51:44.904623       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0412 20:51:44.907838       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0412 20:51:44.907861       1 utils.go:199] ID: 18 GRPC request: {}
I0412 20:51:44.907876       1 utils.go:205] ID: 18 GRPC response: {}
I0412 20:51:44.908238       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0412 20:51:44.908256       1 utils.go:199] ID: 19 GRPC request: {}
I0412 20:51:44.908361       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0412 20:51:44.909085       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0412 20:51:44.909146       1 utils.go:199] ID: 20 GRPC request: {}
I0412 20:51:44.909158       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0412 20:51:44.909268       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}}}]}
I0412 20:52:45.107596       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0412 20:52:45.107735       1 utils.go:199] ID: 21 GRPC request: {}
I0412 20:52:45.107787       1 utils.go:205] ID: 21 GRPC response: {}
I0412 20:53:45.109573       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0412 20:53:45.109670       1 utils.go:199] ID: 22 GRPC request: {}
I0412 20:53:45.109698       1 utils.go:205] ID: 22 GRPC response: {}
I0412 20:54:43.105211       1 utils.go:198] ID: 23 Req-ID: pvc-0ca17657-0ebb-4be7-8f23-79918f5e4547 GRPC call: /csi.v1.Controller/CreateVolume
I0412 20:54:43.106069       1 utils.go:199] ID: 23 Req-ID: pvc-0ca17657-0ebb-4be7-8f23-79918f5e4547 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-0ca17657-0ebb-4be7-8f23-79918f5e4547","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-0ca17657-0ebb-4be7-8f23-79918f5e4547","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}}]}
I0412 20:54:43.107339       1 rbd_util.go:1315] ID: 23 Req-ID: pvc-0ca17657-0ebb-4be7-8f23-79918f5e4547 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0412 20:54:43.126253       1 omap.go:80] ID: 23 Req-ID: pvc-0ca17657-0ebb-4be7-8f23-79918f5e4547 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0412 20:54:43.144817       1 omap.go:159] ID: 23 Req-ID: pvc-0ca17657-0ebb-4be7-8f23-79918f5e4547 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-0ca17657-0ebb-4be7-8f23-79918f5e4547:d0f97aed-e25c-4ed5-b339-6be407bbba38])
I0412 20:54:43.153872       1 omap.go:159] ID: 23 Req-ID: pvc-0ca17657-0ebb-4be7-8f23-79918f5e4547 set omap keys (pool="kube", namespace="", name="csi.volume.d0f97aed-e25c-4ed5-b339-6be407bbba38"): map[csi.imagename:csi-vol-d0f97aed-e25c-4ed5-b339-6be407bbba38 csi.volname:pvc-0ca17657-0ebb-4be7-8f23-79918f5e4547 csi.volume.owner:default])
I0412 20:54:43.153910       1 rbd_journal.go:491] ID: 23 Req-ID: pvc-0ca17657-0ebb-4be7-8f23-79918f5e4547 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-d0f97aed-e25c-4ed5-b339-6be407bbba38) and image name (csi-vol-d0f97aed-e25c-4ed5-b339-6be407bbba38) for request name (pvc-0ca17657-0ebb-4be7-8f23-79918f5e4547)
I0412 20:54:43.154152       1 rbd_util.go:423] ID: 23 Req-ID: pvc-0ca17657-0ebb-4be7-8f23-79918f5e4547 rbd: create kube/csi-vol-d0f97aed-e25c-4ed5-b339-6be407bbba38 size 5120M (features: [layering]) using mon 199.204.45.233
I0412 20:54:43.154216       1 rbd_util.go:1563] ID: 23 Req-ID: pvc-0ca17657-0ebb-4be7-8f23-79918f5e4547 setting image options on kube/csi-vol-d0f97aed-e25c-4ed5-b339-6be407bbba38
I0412 20:54:44.716619       1 controllerserver.go:763] ID: 23 Req-ID: pvc-0ca17657-0ebb-4be7-8f23-79918f5e4547 created image kube/csi-vol-d0f97aed-e25c-4ed5-b339-6be407bbba38 backed for request name pvc-0ca17657-0ebb-4be7-8f23-79918f5e4547
I0412 20:54:44.782869       1 omap.go:159] ID: 23 Req-ID: pvc-0ca17657-0ebb-4be7-8f23-79918f5e4547 set omap keys (pool="kube", namespace="", name="csi.volume.d0f97aed-e25c-4ed5-b339-6be407bbba38"): map[csi.imageid:37d978e8991d])
I0412 20:54:44.937326       1 utils.go:205] ID: 23 Req-ID: pvc-0ca17657-0ebb-4be7-8f23-79918f5e4547 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-d0f97aed-e25c-4ed5-b339-6be407bbba38","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-d0f97aed-e25c-4ed5-b339-6be407bbba38"}}
I0412 20:54:45.107613       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0412 20:54:45.107687       1 utils.go:199] ID: 24 GRPC request: {}
I0412 20:54:45.107721       1 utils.go:205] ID: 24 GRPC response: {}