I0725 04:29:22.657219       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0725 04:29:22.657415       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0725 04:29:22.657456       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0725 04:29:22.657471       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0725 04:29:22.657484       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0725 04:29:22.657496       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0725 04:29:22.657508       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0725 04:29:22.657520       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0725 04:29:22.657532       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0725 04:29:22.657543       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0725 04:29:22.657845       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0725 04:29:22.657871       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0725 04:29:24.637430       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0725 04:29:24.638732       1 utils.go:199] ID: 1 GRPC request: {}
I0725 04:29:24.638825       1 utils.go:205] ID: 1 GRPC response: {}
I0725 04:29:24.640515       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0725 04:29:24.640638       1 utils.go:199] ID: 2 GRPC request: {}
I0725 04:29:24.640659       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0725 04:29:24.640814       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0725 04:29:24.642714       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0725 04:29:24.642740       1 utils.go:199] ID: 3 GRPC request: {}
I0725 04:29:24.642755       1 utils.go:205] ID: 3 GRPC response: {}
I0725 04:29:24.643269       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0725 04:29:24.643353       1 utils.go:199] ID: 4 GRPC request: {}
I0725 04:29:24.643495       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0725 04:29:24.644512       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0725 04:29:24.644633       1 utils.go:199] ID: 5 GRPC request: {}
I0725 04:29:24.644648       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0725 04:29:24.644834       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}}}]}
I0725 04:29:25.771958       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0725 04:29:25.771998       1 utils.go:199] ID: 6 GRPC request: {}
I0725 04:29:25.772023       1 utils.go:205] ID: 6 GRPC response: {}
I0725 04:29:25.776372       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0725 04:29:25.776515       1 utils.go:199] ID: 7 GRPC request: {}
I0725 04:29:25.776562       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0725 04:29:25.776632       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0725 04:29:25.778459       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0725 04:29:25.778481       1 utils.go:199] ID: 8 GRPC request: {}
I0725 04:29:25.778492       1 utils.go:205] ID: 8 GRPC response: {}
I0725 04:29:25.779257       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0725 04:29:25.779305       1 utils.go:199] ID: 9 GRPC request: {}
I0725 04:29:25.779444       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0725 04:29:25.780079       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0725 04:29:25.780104       1 utils.go:199] ID: 10 GRPC request: {}
I0725 04:29:25.780121       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0725 04:29:25.780209       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}}}]}
I0725 04:29:25.780862       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0725 04:29:25.780885       1 utils.go:199] ID: 11 GRPC request: {}
I0725 04:29:25.780895       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0725 04:29:25.781116       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}}}]}
I0725 04:29:25.781587       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0725 04:29:25.781612       1 utils.go:199] ID: 12 GRPC request: {}
I0725 04:29:25.781621       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0725 04:29:25.781820       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}}}]}
I0725 04:29:27.002481       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0725 04:29:27.002520       1 utils.go:199] ID: 13 GRPC request: {}
I0725 04:29:27.002529       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0725 04:29:27.002561       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0725 04:29:27.004743       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0725 04:29:27.004815       1 utils.go:199] ID: 14 GRPC request: {}
I0725 04:29:27.004897       1 utils.go:205] ID: 14 GRPC response: {}
I0725 04:29:27.005510       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0725 04:29:27.005578       1 utils.go:199] ID: 15 GRPC request: {}
I0725 04:29:27.005617       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0725 04:29:27.005749       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}}}]}
I0725 04:29:29.130978       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0725 04:29:29.131027       1 utils.go:199] ID: 16 GRPC request: {}
I0725 04:29:29.131047       1 utils.go:205] ID: 16 GRPC response: {}
I0725 04:29:29.140271       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0725 04:29:29.140304       1 utils.go:199] ID: 17 GRPC request: {}
I0725 04:29:29.140316       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0725 04:29:29.140347       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0725 04:29:29.148496       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0725 04:29:29.148519       1 utils.go:199] ID: 18 GRPC request: {}
I0725 04:29:29.148530       1 utils.go:205] ID: 18 GRPC response: {}
I0725 04:29:29.148821       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0725 04:29:29.148877       1 utils.go:199] ID: 19 GRPC request: {}
I0725 04:29:29.149034       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0725 04:29:29.149653       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0725 04:29:29.149675       1 utils.go:199] ID: 20 GRPC request: {}
I0725 04:29:29.149709       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0725 04:29:29.150349       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}}}]}
I0725 04:30:29.343887       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0725 04:30:29.343938       1 utils.go:199] ID: 21 GRPC request: {}
I0725 04:30:29.343954       1 utils.go:205] ID: 21 GRPC response: {}
I0725 04:31:29.295612       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0725 04:31:29.295945       1 utils.go:199] ID: 22 GRPC request: {}
I0725 04:31:29.295974       1 utils.go:205] ID: 22 GRPC response: {}
I0725 04:32:29.335190       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0725 04:32:29.335234       1 utils.go:199] ID: 23 GRPC request: {}
I0725 04:32:29.335269       1 utils.go:205] ID: 23 GRPC response: {}
I0725 04:33:29.306260       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0725 04:33:29.306300       1 utils.go:199] ID: 24 GRPC request: {}
I0725 04:33:29.306327       1 utils.go:205] ID: 24 GRPC response: {}
I0725 04:33:34.217202       1 utils.go:198] ID: 25 Req-ID: pvc-153fe022-97e7-4037-81bc-4a23ef9f70ab GRPC call: /csi.v1.Controller/CreateVolume
I0725 04:33:34.217552       1 utils.go:199] ID: 25 Req-ID: pvc-153fe022-97e7-4037-81bc-4a23ef9f70ab GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-153fe022-97e7-4037-81bc-4a23ef9f70ab","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-153fe022-97e7-4037-81bc-4a23ef9f70ab","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}}]}
I0725 04:33:34.217839       1 rbd_util.go:1315] ID: 25 Req-ID: pvc-153fe022-97e7-4037-81bc-4a23ef9f70ab setting disableInUseChecks: false image features: [layering] mounter: rbd
E0725 04:33:34.232953       1 omap.go:80] ID: 25 Req-ID: pvc-153fe022-97e7-4037-81bc-4a23ef9f70ab omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0725 04:33:34.248011       1 omap.go:159] ID: 25 Req-ID: pvc-153fe022-97e7-4037-81bc-4a23ef9f70ab set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-153fe022-97e7-4037-81bc-4a23ef9f70ab:d76a206b-fbd1-447c-befd-944c642b5ab1])
I0725 04:33:34.254151       1 omap.go:159] ID: 25 Req-ID: pvc-153fe022-97e7-4037-81bc-4a23ef9f70ab set omap keys (pool="kube", namespace="", name="csi.volume.d76a206b-fbd1-447c-befd-944c642b5ab1"): map[csi.imagename:csi-vol-d76a206b-fbd1-447c-befd-944c642b5ab1 csi.volname:pvc-153fe022-97e7-4037-81bc-4a23ef9f70ab csi.volume.owner:default])
I0725 04:33:34.254184       1 rbd_journal.go:491] ID: 25 Req-ID: pvc-153fe022-97e7-4037-81bc-4a23ef9f70ab generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-d76a206b-fbd1-447c-befd-944c642b5ab1) and image name (csi-vol-d76a206b-fbd1-447c-befd-944c642b5ab1) for request name (pvc-153fe022-97e7-4037-81bc-4a23ef9f70ab)
I0725 04:33:34.254357       1 rbd_util.go:423] ID: 25 Req-ID: pvc-153fe022-97e7-4037-81bc-4a23ef9f70ab rbd: create kube/csi-vol-d76a206b-fbd1-447c-befd-944c642b5ab1 size 5120M (features: [layering]) using mon 199.204.45.169
I0725 04:33:34.254500       1 rbd_util.go:1563] ID: 25 Req-ID: pvc-153fe022-97e7-4037-81bc-4a23ef9f70ab setting image options on kube/csi-vol-d76a206b-fbd1-447c-befd-944c642b5ab1
I0725 04:33:34.290008       1 controllerserver.go:763] ID: 25 Req-ID: pvc-153fe022-97e7-4037-81bc-4a23ef9f70ab created image kube/csi-vol-d76a206b-fbd1-447c-befd-944c642b5ab1 backed for request name pvc-153fe022-97e7-4037-81bc-4a23ef9f70ab
I0725 04:33:34.319967       1 omap.go:159] ID: 25 Req-ID: pvc-153fe022-97e7-4037-81bc-4a23ef9f70ab set omap keys (pool="kube", namespace="", name="csi.volume.d76a206b-fbd1-447c-befd-944c642b5ab1"): map[csi.imageid:37f453bbb02b])
I0725 04:33:34.405685       1 utils.go:205] ID: 25 Req-ID: pvc-153fe022-97e7-4037-81bc-4a23ef9f70ab GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-d76a206b-fbd1-447c-befd-944c642b5ab1","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-d76a206b-fbd1-447c-befd-944c642b5ab1"}}