I0521 08:58:05.135321       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0521 08:58:05.135489       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0521 08:58:05.135508       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0521 08:58:05.135513       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0521 08:58:05.135517       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0521 08:58:05.135521       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0521 08:58:05.135527       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0521 08:58:05.135532       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0521 08:58:05.135536       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0521 08:58:05.135540       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0521 08:58:05.135933       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0521 08:58:05.136027       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0521 08:58:07.241429       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0521 08:58:07.243695       1 utils.go:199] ID: 1 GRPC request: {}
I0521 08:58:07.243873       1 utils.go:205] ID: 1 GRPC response: {}
I0521 08:58:07.247264       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0521 08:58:07.247386       1 utils.go:199] ID: 2 GRPC request: {}
I0521 08:58:07.247444       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0521 08:58:07.247541       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0521 08:58:07.252572       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0521 08:58:07.252643       1 utils.go:199] ID: 3 GRPC request: {}
I0521 08:58:07.252674       1 utils.go:205] ID: 3 GRPC response: {}
I0521 08:58:07.253315       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0521 08:58:07.253412       1 utils.go:199] ID: 4 GRPC request: {}
I0521 08:58:07.253619       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0521 08:58:07.255157       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0521 08:58:07.255429       1 utils.go:199] ID: 5 GRPC request: {}
I0521 08:58:07.255454       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0521 08:58:07.255813       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}}}]}
I0521 08:58:08.838241       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0521 08:58:08.838286       1 utils.go:199] ID: 6 GRPC request: {}
I0521 08:58:08.838315       1 utils.go:205] ID: 6 GRPC response: {}
I0521 08:58:08.840622       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0521 08:58:08.840691       1 utils.go:199] ID: 7 GRPC request: {}
I0521 08:58:08.840702       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0521 08:58:08.840779       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0521 08:58:08.844680       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0521 08:58:08.844755       1 utils.go:199] ID: 8 GRPC request: {}
I0521 08:58:08.844779       1 utils.go:205] ID: 8 GRPC response: {}
I0521 08:58:08.845401       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0521 08:58:08.845620       1 utils.go:199] ID: 9 GRPC request: {}
I0521 08:58:08.845820       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0521 08:58:08.847153       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0521 08:58:08.847185       1 utils.go:199] ID: 10 GRPC request: {}
I0521 08:58:08.847196       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0521 08:58:08.847295       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}}}]}
I0521 08:58:08.848417       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0521 08:58:08.848438       1 utils.go:199] ID: 11 GRPC request: {}
I0521 08:58:08.848446       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0521 08:58:08.848526       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}}}]}
I0521 08:58:08.849017       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0521 08:58:08.849036       1 utils.go:199] ID: 12 GRPC request: {}
I0521 08:58:08.849041       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0521 08:58:08.849122       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}}}]}
I0521 08:58:10.573007       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0521 08:58:10.573065       1 utils.go:199] ID: 13 GRPC request: {}
I0521 08:58:10.573077       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0521 08:58:10.573175       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0521 08:58:10.577330       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0521 08:58:10.577366       1 utils.go:199] ID: 14 GRPC request: {}
I0521 08:58:10.577383       1 utils.go:205] ID: 14 GRPC response: {}
I0521 08:58:10.578288       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0521 08:58:10.578365       1 utils.go:199] ID: 15 GRPC request: {}
I0521 08:58:10.578386       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0521 08:58:10.578617       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}}}]}
I0521 08:58:12.082876       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0521 08:58:12.082919       1 utils.go:199] ID: 16 GRPC request: {}
I0521 08:58:12.082952       1 utils.go:205] ID: 16 GRPC response: {}
I0521 08:58:12.088823       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0521 08:58:12.088910       1 utils.go:199] ID: 17 GRPC request: {}
I0521 08:58:12.088932       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0521 08:58:12.089050       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0521 08:58:12.092160       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0521 08:58:12.092222       1 utils.go:199] ID: 18 GRPC request: {}
I0521 08:58:12.092285       1 utils.go:205] ID: 18 GRPC response: {}
I0521 08:58:12.093017       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0521 08:58:12.093044       1 utils.go:199] ID: 19 GRPC request: {}
I0521 08:58:12.093357       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0521 08:58:12.094367       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0521 08:58:12.094392       1 utils.go:199] ID: 20 GRPC request: {}
I0521 08:58:12.094418       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0521 08:58:12.094528       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}}}]}
I0521 08:59:12.326442       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0521 08:59:12.326528       1 utils.go:199] ID: 21 GRPC request: {}
I0521 08:59:12.326603       1 utils.go:205] ID: 21 GRPC response: {}
I0521 09:00:12.292098       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0521 09:00:12.292332       1 utils.go:199] ID: 22 GRPC request: {}
I0521 09:00:12.292399       1 utils.go:205] ID: 22 GRPC response: {}
I0521 09:01:12.289010       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0521 09:01:12.289076       1 utils.go:199] ID: 23 GRPC request: {}
I0521 09:01:12.289111       1 utils.go:205] ID: 23 GRPC response: {}
I0521 09:02:01.081488       1 utils.go:198] ID: 24 Req-ID: pvc-5858950c-6757-48f2-9fe6-d70d58c9ace2 GRPC call: /csi.v1.Controller/CreateVolume
I0521 09:02:01.081841       1 utils.go:199] ID: 24 Req-ID: pvc-5858950c-6757-48f2-9fe6-d70d58c9ace2 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-5858950c-6757-48f2-9fe6-d70d58c9ace2","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-5858950c-6757-48f2-9fe6-d70d58c9ace2","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}}]}
I0521 09:02:01.082138       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-5858950c-6757-48f2-9fe6-d70d58c9ace2 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0521 09:02:01.103919       1 omap.go:80] ID: 24 Req-ID: pvc-5858950c-6757-48f2-9fe6-d70d58c9ace2 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0521 09:02:01.119279       1 omap.go:159] ID: 24 Req-ID: pvc-5858950c-6757-48f2-9fe6-d70d58c9ace2 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-5858950c-6757-48f2-9fe6-d70d58c9ace2:1ef595e4-aca8-44d9-9fc0-8ec1fbbe57ca])
I0521 09:02:01.126279       1 omap.go:159] ID: 24 Req-ID: pvc-5858950c-6757-48f2-9fe6-d70d58c9ace2 set omap keys (pool="kube", namespace="", name="csi.volume.1ef595e4-aca8-44d9-9fc0-8ec1fbbe57ca"): map[csi.imagename:csi-vol-1ef595e4-aca8-44d9-9fc0-8ec1fbbe57ca csi.volname:pvc-5858950c-6757-48f2-9fe6-d70d58c9ace2 csi.volume.owner:default])
I0521 09:02:01.126319       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-5858950c-6757-48f2-9fe6-d70d58c9ace2 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-1ef595e4-aca8-44d9-9fc0-8ec1fbbe57ca) and image name (csi-vol-1ef595e4-aca8-44d9-9fc0-8ec1fbbe57ca) for request name (pvc-5858950c-6757-48f2-9fe6-d70d58c9ace2)
I0521 09:02:01.126481       1 rbd_util.go:423] ID: 24 Req-ID: pvc-5858950c-6757-48f2-9fe6-d70d58c9ace2 rbd: create kube/csi-vol-1ef595e4-aca8-44d9-9fc0-8ec1fbbe57ca size 5120M (features: [layering]) using mon 199.19.213.95
I0521 09:02:01.126575       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-5858950c-6757-48f2-9fe6-d70d58c9ace2 setting image options on kube/csi-vol-1ef595e4-aca8-44d9-9fc0-8ec1fbbe57ca
I0521 09:02:01.165579       1 controllerserver.go:763] ID: 24 Req-ID: pvc-5858950c-6757-48f2-9fe6-d70d58c9ace2 created image kube/csi-vol-1ef595e4-aca8-44d9-9fc0-8ec1fbbe57ca backed for request name pvc-5858950c-6757-48f2-9fe6-d70d58c9ace2
I0521 09:02:01.202263       1 omap.go:159] ID: 24 Req-ID: pvc-5858950c-6757-48f2-9fe6-d70d58c9ace2 set omap keys (pool="kube", namespace="", name="csi.volume.1ef595e4-aca8-44d9-9fc0-8ec1fbbe57ca"): map[csi.imageid:37ed3a05458e])
I0521 09:02:01.346925       1 utils.go:205] ID: 24 Req-ID: pvc-5858950c-6757-48f2-9fe6-d70d58c9ace2 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-1ef595e4-aca8-44d9-9fc0-8ec1fbbe57ca","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-1ef595e4-aca8-44d9-9fc0-8ec1fbbe57ca"}}
I0521 09:02:12.302731       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0521 09:02:12.302797       1 utils.go:199] ID: 25 GRPC request: {}
I0521 09:02:12.302816       1 utils.go:205] ID: 25 GRPC response: {}