I0205 11:24:47.563081       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0205 11:24:47.563286       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0205 11:24:47.563306       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0205 11:24:47.563310       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0205 11:24:47.563313       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0205 11:24:47.563316       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0205 11:24:47.563320       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0205 11:24:47.563324       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0205 11:24:47.563327       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0205 11:24:47.563329       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0205 11:24:47.563596       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0205 11:24:47.563615       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0205 11:24:50.497712       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0205 11:24:50.500397       1 utils.go:199] ID: 1 GRPC request: {}
I0205 11:24:50.500497       1 utils.go:205] ID: 1 GRPC response: {}
I0205 11:24:50.502519       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0205 11:24:50.502693       1 utils.go:199] ID: 2 GRPC request: {}
I0205 11:24:50.502726       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0205 11:24:50.502789       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0205 11:24:50.504132       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0205 11:24:50.504167       1 utils.go:199] ID: 3 GRPC request: {}
I0205 11:24:50.504244       1 utils.go:205] ID: 3 GRPC response: {}
I0205 11:24:50.504471       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0205 11:24:50.504534       1 utils.go:199] ID: 4 GRPC request: {}
I0205 11:24:50.504702       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0205 11:24:50.505190       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0205 11:24:50.505254       1 utils.go:199] ID: 5 GRPC request: {}
I0205 11:24:50.505271       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0205 11:24:50.505367       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}}}]}
I0205 11:24:54.915801       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0205 11:24:54.915974       1 utils.go:199] ID: 6 GRPC request: {}
I0205 11:24:54.916059       1 utils.go:205] ID: 6 GRPC response: {}
I0205 11:24:54.917617       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0205 11:24:54.917634       1 utils.go:199] ID: 7 GRPC request: {}
I0205 11:24:54.917647       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0205 11:24:54.917734       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0205 11:24:54.919071       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0205 11:24:54.919091       1 utils.go:199] ID: 8 GRPC request: {}
I0205 11:24:54.919216       1 utils.go:205] ID: 8 GRPC response: {}
I0205 11:24:54.919633       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0205 11:24:54.919648       1 utils.go:199] ID: 9 GRPC request: {}
I0205 11:24:54.919924       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0205 11:24:54.920409       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0205 11:24:54.920437       1 utils.go:199] ID: 10 GRPC request: {}
I0205 11:24:54.920516       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0205 11:24:54.920644       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}}}]}
I0205 11:24:54.921218       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0205 11:24:54.921304       1 utils.go:199] ID: 11 GRPC request: {}
I0205 11:24:54.921314       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0205 11:24:54.921439       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}}}]}
I0205 11:24:54.921961       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0205 11:24:54.921997       1 utils.go:199] ID: 12 GRPC request: {}
I0205 11:24:54.922103       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0205 11:24:54.922345       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}}}]}
I0205 11:24:57.412752       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0205 11:24:57.412802       1 utils.go:199] ID: 13 GRPC request: {}
I0205 11:24:57.412810       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0205 11:24:57.412834       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0205 11:24:57.418754       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0205 11:24:57.418784       1 utils.go:199] ID: 14 GRPC request: {}
I0205 11:24:57.418837       1 utils.go:205] ID: 14 GRPC response: {}
I0205 11:24:57.419270       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0205 11:24:57.419285       1 utils.go:199] ID: 15 GRPC request: {}
I0205 11:24:57.419295       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0205 11:24:57.419401       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}}}]}
I0205 11:25:01.223670       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0205 11:25:01.223715       1 utils.go:199] ID: 16 GRPC request: {}
I0205 11:25:01.223731       1 utils.go:205] ID: 16 GRPC response: {}
I0205 11:25:01.224927       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0205 11:25:01.224956       1 utils.go:199] ID: 17 GRPC request: {}
I0205 11:25:01.224967       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0205 11:25:01.224989       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0205 11:25:01.227395       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0205 11:25:01.227430       1 utils.go:199] ID: 18 GRPC request: {}
I0205 11:25:01.227443       1 utils.go:205] ID: 18 GRPC response: {}
I0205 11:25:01.227864       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0205 11:25:01.227910       1 utils.go:199] ID: 19 GRPC request: {}
I0205 11:25:01.227999       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0205 11:25:01.228761       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0205 11:25:01.228784       1 utils.go:199] ID: 20 GRPC request: {}
I0205 11:25:01.228798       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0205 11:25:01.228884       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}}}]}
I0205 11:26:01.468894       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0205 11:26:01.468943       1 utils.go:199] ID: 21 GRPC request: {}
I0205 11:26:01.469253       1 utils.go:205] ID: 21 GRPC response: {}
I0205 11:27:01.409739       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0205 11:27:01.409773       1 utils.go:199] ID: 22 GRPC request: {}
I0205 11:27:01.409786       1 utils.go:205] ID: 22 GRPC response: {}
I0205 11:28:01.409149       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0205 11:28:01.409196       1 utils.go:199] ID: 23 GRPC request: {}
I0205 11:28:01.409587       1 utils.go:205] ID: 23 GRPC response: {}
I0205 11:28:04.282891       1 utils.go:198] ID: 24 Req-ID: pvc-9cdb3e48-ab89-4fe5-98b3-cc7359e80aa1 GRPC call: /csi.v1.Controller/CreateVolume
I0205 11:28:04.283743       1 utils.go:199] ID: 24 Req-ID: pvc-9cdb3e48-ab89-4fe5-98b3-cc7359e80aa1 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-9cdb3e48-ab89-4fe5-98b3-cc7359e80aa1","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-9cdb3e48-ab89-4fe5-98b3-cc7359e80aa1","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}}]}
I0205 11:28:04.284201       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-9cdb3e48-ab89-4fe5-98b3-cc7359e80aa1 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0205 11:28:04.322288       1 omap.go:80] ID: 24 Req-ID: pvc-9cdb3e48-ab89-4fe5-98b3-cc7359e80aa1 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0205 11:28:04.336512       1 omap.go:159] ID: 24 Req-ID: pvc-9cdb3e48-ab89-4fe5-98b3-cc7359e80aa1 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-9cdb3e48-ab89-4fe5-98b3-cc7359e80aa1:ac38e7ab-6067-41e4-8747-8f5040e6a0d0])
I0205 11:28:04.346079       1 omap.go:159] ID: 24 Req-ID: pvc-9cdb3e48-ab89-4fe5-98b3-cc7359e80aa1 set omap keys (pool="kube", namespace="", name="csi.volume.ac38e7ab-6067-41e4-8747-8f5040e6a0d0"): map[csi.imagename:csi-vol-ac38e7ab-6067-41e4-8747-8f5040e6a0d0 csi.volname:pvc-9cdb3e48-ab89-4fe5-98b3-cc7359e80aa1 csi.volume.owner:default])
I0205 11:28:04.346113       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-9cdb3e48-ab89-4fe5-98b3-cc7359e80aa1 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-ac38e7ab-6067-41e4-8747-8f5040e6a0d0) and image name (csi-vol-ac38e7ab-6067-41e4-8747-8f5040e6a0d0) for request name (pvc-9cdb3e48-ab89-4fe5-98b3-cc7359e80aa1)
I0205 11:28:04.346190       1 rbd_util.go:423] ID: 24 Req-ID: pvc-9cdb3e48-ab89-4fe5-98b3-cc7359e80aa1 rbd: create kube/csi-vol-ac38e7ab-6067-41e4-8747-8f5040e6a0d0 size 5120M (features: [layering]) using mon 199.19.213.136
I0205 11:28:04.346249       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-9cdb3e48-ab89-4fe5-98b3-cc7359e80aa1 setting image options on kube/csi-vol-ac38e7ab-6067-41e4-8747-8f5040e6a0d0
I0205 11:28:06.682582       1 controllerserver.go:763] ID: 24 Req-ID: pvc-9cdb3e48-ab89-4fe5-98b3-cc7359e80aa1 created image kube/csi-vol-ac38e7ab-6067-41e4-8747-8f5040e6a0d0 backed for request name pvc-9cdb3e48-ab89-4fe5-98b3-cc7359e80aa1
I0205 11:28:06.716056       1 omap.go:159] ID: 24 Req-ID: pvc-9cdb3e48-ab89-4fe5-98b3-cc7359e80aa1 set omap keys (pool="kube", namespace="", name="csi.volume.ac38e7ab-6067-41e4-8747-8f5040e6a0d0"): map[csi.imageid:37d8d3146cd2])
I0205 11:28:06.805700       1 utils.go:205] ID: 24 Req-ID: pvc-9cdb3e48-ab89-4fe5-98b3-cc7359e80aa1 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-ac38e7ab-6067-41e4-8747-8f5040e6a0d0","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-ac38e7ab-6067-41e4-8747-8f5040e6a0d0"}}
I0205 11:29:01.422206       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0205 11:29:01.422239       1 utils.go:199] ID: 25 GRPC request: {}
I0205 11:29:01.422263       1 utils.go:205] ID: 25 GRPC response: {}