I0417 18:48:30.924851       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0417 18:48:30.924980       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0417 18:48:30.924991       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0417 18:48:30.924995       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0417 18:48:30.924997       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0417 18:48:30.925000       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0417 18:48:30.925003       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0417 18:48:30.925006       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0417 18:48:30.925009       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0417 18:48:30.925011       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0417 18:48:30.925324       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0417 18:48:30.925348       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0417 18:48:32.738008       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0417 18:48:32.744283       1 utils.go:199] ID: 1 GRPC request: {}
I0417 18:48:32.744390       1 utils.go:205] ID: 1 GRPC response: {}
I0417 18:48:32.748092       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0417 18:48:32.748187       1 utils.go:199] ID: 2 GRPC request: {}
I0417 18:48:32.748206       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0417 18:48:32.748254       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0417 18:48:32.750105       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0417 18:48:32.750131       1 utils.go:199] ID: 3 GRPC request: {}
I0417 18:48:32.750146       1 utils.go:205] ID: 3 GRPC response: {}
I0417 18:48:32.750485       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0417 18:48:32.750581       1 utils.go:199] ID: 4 GRPC request: {}
I0417 18:48:32.750866       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0417 18:48:32.751830       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0417 18:48:32.751997       1 utils.go:199] ID: 5 GRPC request: {}
I0417 18:48:32.752011       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0417 18:48:32.752182       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}}}]}
I0417 18:48:42.516797       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0417 18:48:42.516827       1 utils.go:199] ID: 6 GRPC request: {}
I0417 18:48:42.516844       1 utils.go:205] ID: 6 GRPC response: {}
I0417 18:48:42.522000       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0417 18:48:42.522034       1 utils.go:199] ID: 7 GRPC request: {}
I0417 18:48:42.522040       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0417 18:48:42.522059       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0417 18:48:42.524245       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0417 18:48:42.524271       1 utils.go:199] ID: 8 GRPC request: {}
I0417 18:48:42.524284       1 utils.go:205] ID: 8 GRPC response: {}
I0417 18:48:42.524611       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0417 18:48:42.524625       1 utils.go:199] ID: 9 GRPC request: {}
I0417 18:48:42.524687       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0417 18:48:42.525178       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0417 18:48:42.525193       1 utils.go:199] ID: 10 GRPC request: {}
I0417 18:48:42.525200       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0417 18:48:42.525298       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}}}]}
I0417 18:48:42.525704       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0417 18:48:42.525715       1 utils.go:199] ID: 11 GRPC request: {}
I0417 18:48:42.525719       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0417 18:48:42.525776       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}}}]}
I0417 18:48:42.526102       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0417 18:48:42.526116       1 utils.go:199] ID: 12 GRPC request: {}
I0417 18:48:42.526119       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0417 18:48:42.526159       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}}}]}
I0417 18:48:46.969948       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0417 18:48:46.970005       1 utils.go:199] ID: 13 GRPC request: {}
I0417 18:48:46.970020       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0417 18:48:46.970060       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0417 18:48:46.974769       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0417 18:48:46.974796       1 utils.go:199] ID: 14 GRPC request: {}
I0417 18:48:46.974851       1 utils.go:205] ID: 14 GRPC response: {}
I0417 18:48:46.975325       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0417 18:48:46.975349       1 utils.go:199] ID: 15 GRPC request: {}
I0417 18:48:46.975358       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0417 18:48:46.975446       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}}}]}
I0417 18:48:50.667921       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0417 18:48:50.667969       1 utils.go:199] ID: 16 GRPC request: {}
I0417 18:48:50.668009       1 utils.go:205] ID: 16 GRPC response: {}
I0417 18:48:50.669673       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0417 18:48:50.669727       1 utils.go:199] ID: 17 GRPC request: {}
I0417 18:48:50.669738       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0417 18:48:50.669773       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0417 18:48:50.671931       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0417 18:48:50.672001       1 utils.go:199] ID: 18 GRPC request: {}
I0417 18:48:50.672018       1 utils.go:205] ID: 18 GRPC response: {}
I0417 18:48:50.672456       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0417 18:48:50.672477       1 utils.go:199] ID: 19 GRPC request: {}
I0417 18:48:50.672573       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0417 18:48:50.673036       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0417 18:48:50.673105       1 utils.go:199] ID: 20 GRPC request: {}
I0417 18:48:50.673116       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0417 18:48:50.673181       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}}}]}
I0417 18:49:50.919439       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0417 18:49:50.919566       1 utils.go:199] ID: 21 GRPC request: {}
I0417 18:49:50.919602       1 utils.go:205] ID: 21 GRPC response: {}
I0417 18:50:50.864655       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0417 18:50:50.865066       1 utils.go:199] ID: 22 GRPC request: {}
I0417 18:50:50.865170       1 utils.go:205] ID: 22 GRPC response: {}
I0417 18:51:41.355914       1 utils.go:198] ID: 23 Req-ID: pvc-66c8c8ca-cd80-4afb-ad12-6519e0f8af58 GRPC call: /csi.v1.Controller/CreateVolume
I0417 18:51:41.356520       1 utils.go:199] ID: 23 Req-ID: pvc-66c8c8ca-cd80-4afb-ad12-6519e0f8af58 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-66c8c8ca-cd80-4afb-ad12-6519e0f8af58","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-66c8c8ca-cd80-4afb-ad12-6519e0f8af58","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}}]}
I0417 18:51:41.356925       1 rbd_util.go:1315] ID: 23 Req-ID: pvc-66c8c8ca-cd80-4afb-ad12-6519e0f8af58 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0417 18:51:41.376848       1 omap.go:80] ID: 23 Req-ID: pvc-66c8c8ca-cd80-4afb-ad12-6519e0f8af58 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0417 18:51:41.394038       1 omap.go:159] ID: 23 Req-ID: pvc-66c8c8ca-cd80-4afb-ad12-6519e0f8af58 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-66c8c8ca-cd80-4afb-ad12-6519e0f8af58:c8b92a38-fc10-426b-9e1d-447e391741c6])
I0417 18:51:41.400839       1 omap.go:159] ID: 23 Req-ID: pvc-66c8c8ca-cd80-4afb-ad12-6519e0f8af58 set omap keys (pool="kube", namespace="", name="csi.volume.c8b92a38-fc10-426b-9e1d-447e391741c6"): map[csi.imagename:csi-vol-c8b92a38-fc10-426b-9e1d-447e391741c6 csi.volname:pvc-66c8c8ca-cd80-4afb-ad12-6519e0f8af58 csi.volume.owner:default])
I0417 18:51:41.400943       1 rbd_journal.go:491] ID: 23 Req-ID: pvc-66c8c8ca-cd80-4afb-ad12-6519e0f8af58 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-c8b92a38-fc10-426b-9e1d-447e391741c6) and image name (csi-vol-c8b92a38-fc10-426b-9e1d-447e391741c6) for request name (pvc-66c8c8ca-cd80-4afb-ad12-6519e0f8af58)
I0417 18:51:41.401368       1 rbd_util.go:423] ID: 23 Req-ID: pvc-66c8c8ca-cd80-4afb-ad12-6519e0f8af58 rbd: create kube/csi-vol-c8b92a38-fc10-426b-9e1d-447e391741c6 size 5120M (features: [layering]) using mon 199.19.213.222
I0417 18:51:41.401458       1 rbd_util.go:1563] ID: 23 Req-ID: pvc-66c8c8ca-cd80-4afb-ad12-6519e0f8af58 setting image options on kube/csi-vol-c8b92a38-fc10-426b-9e1d-447e391741c6
I0417 18:51:43.002475       1 controllerserver.go:763] ID: 23 Req-ID: pvc-66c8c8ca-cd80-4afb-ad12-6519e0f8af58 created image kube/csi-vol-c8b92a38-fc10-426b-9e1d-447e391741c6 backed for request name pvc-66c8c8ca-cd80-4afb-ad12-6519e0f8af58
I0417 18:51:43.039055       1 omap.go:159] ID: 23 Req-ID: pvc-66c8c8ca-cd80-4afb-ad12-6519e0f8af58 set omap keys (pool="kube", namespace="", name="csi.volume.c8b92a38-fc10-426b-9e1d-447e391741c6"): map[csi.imageid:37d93fdb231f])
I0417 18:51:43.151488       1 utils.go:205] ID: 23 Req-ID: pvc-66c8c8ca-cd80-4afb-ad12-6519e0f8af58 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-c8b92a38-fc10-426b-9e1d-447e391741c6","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-c8b92a38-fc10-426b-9e1d-447e391741c6"}}
I0417 18:51:50.863525       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0417 18:51:50.863581       1 utils.go:199] ID: 24 GRPC request: {}
I0417 18:51:50.863609       1 utils.go:205] ID: 24 GRPC response: {}