I0406 21:06:13.453524       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0406 21:06:13.453637       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0406 21:06:13.453650       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0406 21:06:13.453653       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0406 21:06:13.453656       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0406 21:06:13.453659       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0406 21:06:13.453664       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0406 21:06:13.453668       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0406 21:06:13.453670       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0406 21:06:13.453673       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0406 21:06:13.454185       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0406 21:06:13.454221       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0406 21:06:16.748244       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0406 21:06:16.751038       1 utils.go:199] ID: 1 GRPC request: {}
I0406 21:06:16.751153       1 utils.go:205] ID: 1 GRPC response: {}
I0406 21:06:16.754549       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0406 21:06:16.754625       1 utils.go:199] ID: 2 GRPC request: {}
I0406 21:06:16.754719       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0406 21:06:16.754795       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0406 21:06:16.757148       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0406 21:06:16.757196       1 utils.go:199] ID: 3 GRPC request: {}
I0406 21:06:16.757224       1 utils.go:205] ID: 3 GRPC response: {}
I0406 21:06:16.757696       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0406 21:06:16.757794       1 utils.go:199] ID: 4 GRPC request: {}
I0406 21:06:16.757948       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0406 21:06:16.758839       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0406 21:06:16.758918       1 utils.go:199] ID: 5 GRPC request: {}
I0406 21:06:16.758948       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0406 21:06:16.759093       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}}}]}
I0406 21:06:18.608177       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0406 21:06:18.608235       1 utils.go:199] ID: 6 GRPC request: {}
I0406 21:06:18.608256       1 utils.go:205] ID: 6 GRPC response: {}
I0406 21:06:18.611782       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0406 21:06:18.611821       1 utils.go:199] ID: 7 GRPC request: {}
I0406 21:06:18.611833       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0406 21:06:18.611870       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0406 21:06:18.614126       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0406 21:06:18.614163       1 utils.go:199] ID: 8 GRPC request: {}
I0406 21:06:18.614187       1 utils.go:205] ID: 8 GRPC response: {}
I0406 21:06:18.614644       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0406 21:06:18.614667       1 utils.go:199] ID: 9 GRPC request: {}
I0406 21:06:18.614766       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0406 21:06:18.615708       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0406 21:06:18.615738       1 utils.go:199] ID: 10 GRPC request: {}
I0406 21:06:18.615748       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0406 21:06:18.615826       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}}}]}
I0406 21:06:18.616542       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0406 21:06:18.616561       1 utils.go:199] ID: 11 GRPC request: {}
I0406 21:06:18.616567       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0406 21:06:18.616639       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}}}]}
I0406 21:06:18.617080       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0406 21:06:18.617099       1 utils.go:199] ID: 12 GRPC request: {}
I0406 21:06:18.617105       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0406 21:06:18.617160       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}}}]}
I0406 21:06:19.857324       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0406 21:06:19.857383       1 utils.go:199] ID: 13 GRPC request: {}
I0406 21:06:19.857508       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0406 21:06:19.857626       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0406 21:06:19.859567       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0406 21:06:19.859594       1 utils.go:199] ID: 14 GRPC request: {}
I0406 21:06:19.859769       1 utils.go:205] ID: 14 GRPC response: {}
I0406 21:06:19.860471       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0406 21:06:19.860496       1 utils.go:199] ID: 15 GRPC request: {}
I0406 21:06:19.860507       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0406 21:06:19.860626       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}}}]}
I0406 21:06:21.297353       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0406 21:06:21.297413       1 utils.go:199] ID: 16 GRPC request: {}
I0406 21:06:21.297452       1 utils.go:205] ID: 16 GRPC response: {}
I0406 21:06:21.307413       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0406 21:06:21.307446       1 utils.go:199] ID: 17 GRPC request: {}
I0406 21:06:21.307454       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0406 21:06:21.307479       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0406 21:06:21.309426       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0406 21:06:21.309447       1 utils.go:199] ID: 18 GRPC request: {}
I0406 21:06:21.309457       1 utils.go:205] ID: 18 GRPC response: {}
I0406 21:06:21.310098       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0406 21:06:21.310117       1 utils.go:199] ID: 19 GRPC request: {}
I0406 21:06:21.310238       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0406 21:06:21.311018       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0406 21:06:21.311037       1 utils.go:199] ID: 20 GRPC request: {}
I0406 21:06:21.311045       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0406 21:06:21.311112       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}}}]}
I0406 21:07:21.525923       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0406 21:07:21.525980       1 utils.go:199] ID: 21 GRPC request: {}
I0406 21:07:21.526004       1 utils.go:205] ID: 21 GRPC response: {}
I0406 21:08:21.502942       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0406 21:08:21.502984       1 utils.go:199] ID: 22 GRPC request: {}
I0406 21:08:21.503337       1 utils.go:205] ID: 22 GRPC response: {}
I0406 21:09:21.549901       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0406 21:09:21.549957       1 utils.go:199] ID: 23 GRPC request: {}
I0406 21:09:21.549980       1 utils.go:205] ID: 23 GRPC response: {}
I0406 21:09:26.032885       1 utils.go:198] ID: 24 Req-ID: pvc-12bb57f6-da09-44a8-b568-a387330fc5ab GRPC call: /csi.v1.Controller/CreateVolume
I0406 21:09:26.033315       1 utils.go:199] ID: 24 Req-ID: pvc-12bb57f6-da09-44a8-b568-a387330fc5ab GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-12bb57f6-da09-44a8-b568-a387330fc5ab","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-12bb57f6-da09-44a8-b568-a387330fc5ab","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}}]}
I0406 21:09:26.033591       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-12bb57f6-da09-44a8-b568-a387330fc5ab setting disableInUseChecks: false image features: [layering] mounter: rbd
E0406 21:09:26.056236       1 omap.go:80] ID: 24 Req-ID: pvc-12bb57f6-da09-44a8-b568-a387330fc5ab omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0406 21:09:26.075630       1 omap.go:159] ID: 24 Req-ID: pvc-12bb57f6-da09-44a8-b568-a387330fc5ab set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-12bb57f6-da09-44a8-b568-a387330fc5ab:c871d3e9-6ca7-4baf-bd33-bcac1aa678b2])
I0406 21:09:26.085114       1 omap.go:159] ID: 24 Req-ID: pvc-12bb57f6-da09-44a8-b568-a387330fc5ab set omap keys (pool="kube", namespace="", name="csi.volume.c871d3e9-6ca7-4baf-bd33-bcac1aa678b2"): map[csi.imagename:csi-vol-c871d3e9-6ca7-4baf-bd33-bcac1aa678b2 csi.volname:pvc-12bb57f6-da09-44a8-b568-a387330fc5ab csi.volume.owner:default])
I0406 21:09:26.085150       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-12bb57f6-da09-44a8-b568-a387330fc5ab generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-c871d3e9-6ca7-4baf-bd33-bcac1aa678b2) and image name (csi-vol-c871d3e9-6ca7-4baf-bd33-bcac1aa678b2) for request name (pvc-12bb57f6-da09-44a8-b568-a387330fc5ab)
I0406 21:09:26.085239       1 rbd_util.go:423] ID: 24 Req-ID: pvc-12bb57f6-da09-44a8-b568-a387330fc5ab rbd: create kube/csi-vol-c871d3e9-6ca7-4baf-bd33-bcac1aa678b2 size 5120M (features: [layering]) using mon 199.204.45.44
I0406 21:09:26.085312       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-12bb57f6-da09-44a8-b568-a387330fc5ab setting image options on kube/csi-vol-c871d3e9-6ca7-4baf-bd33-bcac1aa678b2
I0406 21:09:27.922690       1 controllerserver.go:763] ID: 24 Req-ID: pvc-12bb57f6-da09-44a8-b568-a387330fc5ab created image kube/csi-vol-c871d3e9-6ca7-4baf-bd33-bcac1aa678b2 backed for request name pvc-12bb57f6-da09-44a8-b568-a387330fc5ab
I0406 21:09:27.952327       1 omap.go:159] ID: 24 Req-ID: pvc-12bb57f6-da09-44a8-b568-a387330fc5ab set omap keys (pool="kube", namespace="", name="csi.volume.c871d3e9-6ca7-4baf-bd33-bcac1aa678b2"): map[csi.imageid:37d959ffeb0])
I0406 21:09:28.050969       1 utils.go:205] ID: 24 Req-ID: pvc-12bb57f6-da09-44a8-b568-a387330fc5ab GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-c871d3e9-6ca7-4baf-bd33-bcac1aa678b2","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-c871d3e9-6ca7-4baf-bd33-bcac1aa678b2"}}
I0406 21:10:21.506774       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0406 21:10:21.506883       1 utils.go:199] ID: 25 GRPC request: {}
I0406 21:10:21.506912       1 utils.go:205] ID: 25 GRPC response: {}