I0418 22:19:34.438761       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0418 22:19:34.438953       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0418 22:19:34.438984       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0418 22:19:34.438995       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0418 22:19:34.439001       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0418 22:19:34.439005       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0418 22:19:34.439017       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0418 22:19:34.439023       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0418 22:19:34.439032       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0418 22:19:34.439038       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0418 22:19:34.439566       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0418 22:19:34.439619       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0418 22:19:38.077327       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0418 22:19:38.080070       1 utils.go:199] ID: 1 GRPC request: {}
I0418 22:19:38.080185       1 utils.go:205] ID: 1 GRPC response: {}
I0418 22:19:38.082198       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0418 22:19:38.082390       1 utils.go:199] ID: 2 GRPC request: {}
I0418 22:19:38.082423       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0418 22:19:38.082581       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0418 22:19:38.084003       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0418 22:19:38.084041       1 utils.go:199] ID: 3 GRPC request: {}
I0418 22:19:38.084067       1 utils.go:205] ID: 3 GRPC response: {}
I0418 22:19:38.084855       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0418 22:19:38.085108       1 utils.go:199] ID: 4 GRPC request: {}
I0418 22:19:38.085500       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0418 22:19:38.086893       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0418 22:19:38.087010       1 utils.go:199] ID: 5 GRPC request: {}
I0418 22:19:38.087031       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0418 22:19:38.087250       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}}}]}
I0418 22:19:53.956116       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0418 22:19:53.956160       1 utils.go:199] ID: 6 GRPC request: {}
I0418 22:19:53.956175       1 utils.go:205] ID: 6 GRPC response: {}
I0418 22:19:53.959580       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0418 22:19:53.959609       1 utils.go:199] ID: 7 GRPC request: {}
I0418 22:19:53.959615       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0418 22:19:53.959645       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0418 22:19:53.963438       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0418 22:19:53.963638       1 utils.go:199] ID: 8 GRPC request: {}
I0418 22:19:53.963744       1 utils.go:205] ID: 8 GRPC response: {}
I0418 22:19:53.964978       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0418 22:19:53.965001       1 utils.go:199] ID: 9 GRPC request: {}
I0418 22:19:53.965092       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0418 22:19:53.965787       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0418 22:19:53.965806       1 utils.go:199] ID: 10 GRPC request: {}
I0418 22:19:53.965814       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0418 22:19:53.965874       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}}}]}
I0418 22:19:53.966815       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0418 22:19:53.966870       1 utils.go:199] ID: 11 GRPC request: {}
I0418 22:19:53.966889       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0418 22:19:53.967040       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}}}]}
I0418 22:19:53.967537       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0418 22:19:53.967559       1 utils.go:199] ID: 12 GRPC request: {}
I0418 22:19:53.967565       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0418 22:19:53.967677       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}}}]}
I0418 22:19:55.501597       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0418 22:19:55.501688       1 utils.go:199] ID: 13 GRPC request: {}
I0418 22:19:55.501707       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0418 22:19:55.501751       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0418 22:19:55.503510       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0418 22:19:55.503544       1 utils.go:199] ID: 14 GRPC request: {}
I0418 22:19:55.503578       1 utils.go:205] ID: 14 GRPC response: {}
I0418 22:19:55.504120       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0418 22:19:55.504149       1 utils.go:199] ID: 15 GRPC request: {}
I0418 22:19:55.504161       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0418 22:19:55.504321       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}}}]}
I0418 22:19:57.065343       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0418 22:19:57.065381       1 utils.go:199] ID: 16 GRPC request: {}
I0418 22:19:57.065411       1 utils.go:205] ID: 16 GRPC response: {}
I0418 22:19:57.069425       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0418 22:19:57.069448       1 utils.go:199] ID: 17 GRPC request: {}
I0418 22:19:57.069461       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0418 22:19:57.069530       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0418 22:19:57.071586       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0418 22:19:57.071692       1 utils.go:199] ID: 18 GRPC request: {}
I0418 22:19:57.071735       1 utils.go:205] ID: 18 GRPC response: {}
I0418 22:19:57.072244       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0418 22:19:57.072312       1 utils.go:199] ID: 19 GRPC request: {}
I0418 22:19:57.072464       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0418 22:19:57.073211       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0418 22:19:57.073313       1 utils.go:199] ID: 20 GRPC request: {}
I0418 22:19:57.073461       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0418 22:19:57.073690       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}}}]}
I0418 22:20:57.249962       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0418 22:20:57.250063       1 utils.go:199] ID: 21 GRPC request: {}
I0418 22:20:57.250106       1 utils.go:205] ID: 21 GRPC response: {}
I0418 22:21:57.253062       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0418 22:21:57.253200       1 utils.go:199] ID: 22 GRPC request: {}
I0418 22:21:57.253288       1 utils.go:205] ID: 22 GRPC response: {}
I0418 22:22:55.081343       1 utils.go:198] ID: 23 Req-ID: pvc-10558174-0107-4179-aa3e-b9ff444dc3c7 GRPC call: /csi.v1.Controller/CreateVolume
I0418 22:22:55.082113       1 utils.go:199] ID: 23 Req-ID: pvc-10558174-0107-4179-aa3e-b9ff444dc3c7 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-10558174-0107-4179-aa3e-b9ff444dc3c7","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-10558174-0107-4179-aa3e-b9ff444dc3c7","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}}]}
I0418 22:22:55.082525       1 rbd_util.go:1315] ID: 23 Req-ID: pvc-10558174-0107-4179-aa3e-b9ff444dc3c7 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0418 22:22:55.102900       1 omap.go:80] ID: 23 Req-ID: pvc-10558174-0107-4179-aa3e-b9ff444dc3c7 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0418 22:22:55.118948       1 omap.go:159] ID: 23 Req-ID: pvc-10558174-0107-4179-aa3e-b9ff444dc3c7 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-10558174-0107-4179-aa3e-b9ff444dc3c7:22a823a4-9c36-4591-af33-d9c2adcf1981])
I0418 22:22:55.126448       1 omap.go:159] ID: 23 Req-ID: pvc-10558174-0107-4179-aa3e-b9ff444dc3c7 set omap keys (pool="kube", namespace="", name="csi.volume.22a823a4-9c36-4591-af33-d9c2adcf1981"): map[csi.imagename:csi-vol-22a823a4-9c36-4591-af33-d9c2adcf1981 csi.volname:pvc-10558174-0107-4179-aa3e-b9ff444dc3c7 csi.volume.owner:default])
I0418 22:22:55.126530       1 rbd_journal.go:491] ID: 23 Req-ID: pvc-10558174-0107-4179-aa3e-b9ff444dc3c7 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-22a823a4-9c36-4591-af33-d9c2adcf1981) and image name (csi-vol-22a823a4-9c36-4591-af33-d9c2adcf1981) for request name (pvc-10558174-0107-4179-aa3e-b9ff444dc3c7)
I0418 22:22:55.126668       1 rbd_util.go:423] ID: 23 Req-ID: pvc-10558174-0107-4179-aa3e-b9ff444dc3c7 rbd: create kube/csi-vol-22a823a4-9c36-4591-af33-d9c2adcf1981 size 5120M (features: [layering]) using mon 199.204.45.35
I0418 22:22:55.126731       1 rbd_util.go:1563] ID: 23 Req-ID: pvc-10558174-0107-4179-aa3e-b9ff444dc3c7 setting image options on kube/csi-vol-22a823a4-9c36-4591-af33-d9c2adcf1981
I0418 22:22:56.900987       1 controllerserver.go:763] ID: 23 Req-ID: pvc-10558174-0107-4179-aa3e-b9ff444dc3c7 created image kube/csi-vol-22a823a4-9c36-4591-af33-d9c2adcf1981 backed for request name pvc-10558174-0107-4179-aa3e-b9ff444dc3c7
I0418 22:22:56.936316       1 omap.go:159] ID: 23 Req-ID: pvc-10558174-0107-4179-aa3e-b9ff444dc3c7 set omap keys (pool="kube", namespace="", name="csi.volume.22a823a4-9c36-4591-af33-d9c2adcf1981"): map[csi.imageid:37d963205827])
I0418 22:22:57.043268       1 utils.go:205] ID: 23 Req-ID: pvc-10558174-0107-4179-aa3e-b9ff444dc3c7 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-22a823a4-9c36-4591-af33-d9c2adcf1981","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-22a823a4-9c36-4591-af33-d9c2adcf1981"}}
I0418 22:22:57.249977       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0418 22:22:57.250328       1 utils.go:199] ID: 24 GRPC request: {}
I0418 22:22:57.250521       1 utils.go:205] ID: 24 GRPC response: {}