I0203 13:01:17.826931       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0203 13:01:17.827053       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0203 13:01:17.827226       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0203 13:01:17.827281       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0203 13:01:17.827290       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0203 13:01:17.827295       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0203 13:01:17.827320       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0203 13:01:17.827356       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0203 13:01:17.827365       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0203 13:01:17.827429       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0203 13:01:17.827879       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0203 13:01:17.827891       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0203 13:01:22.107643       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0203 13:01:22.109351       1 utils.go:199] ID: 1 GRPC request: {}
I0203 13:01:22.109622       1 utils.go:205] ID: 1 GRPC response: {}
I0203 13:01:22.116483       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0203 13:01:22.116585       1 utils.go:199] ID: 2 GRPC request: {}
I0203 13:01:22.116619       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0203 13:01:22.116687       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0203 13:01:22.122252       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0203 13:01:22.122304       1 utils.go:199] ID: 3 GRPC request: {}
I0203 13:01:22.122328       1 utils.go:205] ID: 3 GRPC response: {}
I0203 13:01:22.122987       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0203 13:01:22.123088       1 utils.go:199] ID: 4 GRPC request: {}
I0203 13:01:22.123468       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0203 13:01:22.126276       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0203 13:01:22.126350       1 utils.go:199] ID: 5 GRPC request: {}
I0203 13:01:22.126373       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0203 13:01:22.126500       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}}}]}
I0203 13:01:23.981188       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0203 13:01:23.981347       1 utils.go:199] ID: 6 GRPC request: {}
I0203 13:01:23.981849       1 utils.go:205] ID: 6 GRPC response: {}
I0203 13:01:23.987322       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0203 13:01:23.987407       1 utils.go:199] ID: 7 GRPC request: {}
I0203 13:01:23.987467       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0203 13:01:23.987559       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0203 13:01:23.988995       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0203 13:01:23.989014       1 utils.go:199] ID: 8 GRPC request: {}
I0203 13:01:23.989024       1 utils.go:205] ID: 8 GRPC response: {}
I0203 13:01:23.989360       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0203 13:01:23.989802       1 utils.go:199] ID: 9 GRPC request: {}
I0203 13:01:23.990027       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0203 13:01:23.990541       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0203 13:01:23.990553       1 utils.go:199] ID: 10 GRPC request: {}
I0203 13:01:23.990558       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0203 13:01:23.990704       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}}}]}
I0203 13:01:23.991109       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0203 13:01:23.991183       1 utils.go:199] ID: 11 GRPC request: {}
I0203 13:01:23.991239       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0203 13:01:23.991344       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}}}]}
I0203 13:01:23.991646       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0203 13:01:23.991717       1 utils.go:199] ID: 12 GRPC request: {}
I0203 13:01:23.991782       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0203 13:01:23.991889       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}}}]}
I0203 13:01:25.774538       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0203 13:01:25.774595       1 utils.go:199] ID: 13 GRPC request: {}
I0203 13:01:25.774609       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0203 13:01:25.774634       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0203 13:01:25.776224       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0203 13:01:25.776262       1 utils.go:199] ID: 14 GRPC request: {}
I0203 13:01:25.776368       1 utils.go:205] ID: 14 GRPC response: {}
I0203 13:01:25.776728       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0203 13:01:25.776753       1 utils.go:199] ID: 15 GRPC request: {}
I0203 13:01:25.776768       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0203 13:01:25.776870       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}}}]}
I0203 13:01:27.574628       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0203 13:01:27.574700       1 utils.go:199] ID: 16 GRPC request: {}
I0203 13:01:27.574727       1 utils.go:205] ID: 16 GRPC response: {}
I0203 13:01:27.578916       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0203 13:01:27.578953       1 utils.go:199] ID: 17 GRPC request: {}
I0203 13:01:27.578970       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0203 13:01:27.579010       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0203 13:01:27.580400       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0203 13:01:27.580450       1 utils.go:199] ID: 18 GRPC request: {}
I0203 13:01:27.580473       1 utils.go:205] ID: 18 GRPC response: {}
I0203 13:01:27.580781       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0203 13:01:27.580828       1 utils.go:199] ID: 19 GRPC request: {}
I0203 13:01:27.580920       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0203 13:01:27.581500       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0203 13:01:27.581834       1 utils.go:199] ID: 20 GRPC request: {}
I0203 13:01:27.582066       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0203 13:01:27.582276       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}}}]}
I0203 13:02:27.818690       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0203 13:02:27.818783       1 utils.go:199] ID: 21 GRPC request: {}
I0203 13:02:27.818805       1 utils.go:205] ID: 21 GRPC response: {}
I0203 13:03:27.758773       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0203 13:03:27.758818       1 utils.go:199] ID: 22 GRPC request: {}
I0203 13:03:27.758836       1 utils.go:205] ID: 22 GRPC response: {}
I0203 13:04:19.540193       1 utils.go:198] ID: 23 Req-ID: pvc-5941846d-8c3a-4df5-a194-78208182fcb4 GRPC call: /csi.v1.Controller/CreateVolume
I0203 13:04:19.543106       1 utils.go:199] ID: 23 Req-ID: pvc-5941846d-8c3a-4df5-a194-78208182fcb4 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-5941846d-8c3a-4df5-a194-78208182fcb4","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-5941846d-8c3a-4df5-a194-78208182fcb4","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}}]}
I0203 13:04:19.543384       1 rbd_util.go:1315] ID: 23 Req-ID: pvc-5941846d-8c3a-4df5-a194-78208182fcb4 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0203 13:04:19.571047       1 omap.go:80] ID: 23 Req-ID: pvc-5941846d-8c3a-4df5-a194-78208182fcb4 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0203 13:04:19.584180       1 omap.go:159] ID: 23 Req-ID: pvc-5941846d-8c3a-4df5-a194-78208182fcb4 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-5941846d-8c3a-4df5-a194-78208182fcb4:5b9ad18f-2ded-4bf2-a10e-5d4bb58b09a1])
I0203 13:04:19.590388       1 omap.go:159] ID: 23 Req-ID: pvc-5941846d-8c3a-4df5-a194-78208182fcb4 set omap keys (pool="kube", namespace="", name="csi.volume.5b9ad18f-2ded-4bf2-a10e-5d4bb58b09a1"): map[csi.imagename:csi-vol-5b9ad18f-2ded-4bf2-a10e-5d4bb58b09a1 csi.volname:pvc-5941846d-8c3a-4df5-a194-78208182fcb4 csi.volume.owner:default])
I0203 13:04:19.590448       1 rbd_journal.go:491] ID: 23 Req-ID: pvc-5941846d-8c3a-4df5-a194-78208182fcb4 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-5b9ad18f-2ded-4bf2-a10e-5d4bb58b09a1) and image name (csi-vol-5b9ad18f-2ded-4bf2-a10e-5d4bb58b09a1) for request name (pvc-5941846d-8c3a-4df5-a194-78208182fcb4)
I0203 13:04:19.590588       1 rbd_util.go:423] ID: 23 Req-ID: pvc-5941846d-8c3a-4df5-a194-78208182fcb4 rbd: create kube/csi-vol-5b9ad18f-2ded-4bf2-a10e-5d4bb58b09a1 size 5120M (features: [layering]) using mon 199.19.213.199
I0203 13:04:19.590664       1 rbd_util.go:1563] ID: 23 Req-ID: pvc-5941846d-8c3a-4df5-a194-78208182fcb4 setting image options on kube/csi-vol-5b9ad18f-2ded-4bf2-a10e-5d4bb58b09a1
I0203 13:04:21.099074       1 controllerserver.go:763] ID: 23 Req-ID: pvc-5941846d-8c3a-4df5-a194-78208182fcb4 created image kube/csi-vol-5b9ad18f-2ded-4bf2-a10e-5d4bb58b09a1 backed for request name pvc-5941846d-8c3a-4df5-a194-78208182fcb4
I0203 13:04:21.134790       1 omap.go:159] ID: 23 Req-ID: pvc-5941846d-8c3a-4df5-a194-78208182fcb4 set omap keys (pool="kube", namespace="", name="csi.volume.5b9ad18f-2ded-4bf2-a10e-5d4bb58b09a1"): map[csi.imageid:37d948bcc5cf])
I0203 13:04:21.231995       1 utils.go:205] ID: 23 Req-ID: pvc-5941846d-8c3a-4df5-a194-78208182fcb4 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-5b9ad18f-2ded-4bf2-a10e-5d4bb58b09a1","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-5b9ad18f-2ded-4bf2-a10e-5d4bb58b09a1"}}
I0203 13:04:27.822577       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0203 13:04:27.823643       1 utils.go:199] ID: 24 GRPC request: {}
I0203 13:04:27.823666       1 utils.go:205] ID: 24 GRPC response: {}