I0813 01:07:16.837423       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0813 01:07:16.837528       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0813 01:07:16.837541       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0813 01:07:16.837550       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0813 01:07:16.837553       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0813 01:07:16.837556       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0813 01:07:16.837559       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0813 01:07:16.837562       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0813 01:07:16.837564       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0813 01:07:16.837567       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0813 01:07:16.837925       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0813 01:07:16.837980       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0813 01:07:23.227811       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0813 01:07:23.228986       1 utils.go:199] ID: 1 GRPC request: {}
I0813 01:07:23.229039       1 utils.go:205] ID: 1 GRPC response: {}
I0813 01:07:23.231649       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0813 01:07:23.231691       1 utils.go:199] ID: 2 GRPC request: {}
I0813 01:07:23.231702       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0813 01:07:23.231736       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0813 01:07:23.234267       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0813 01:07:23.234292       1 utils.go:199] ID: 3 GRPC request: {}
I0813 01:07:23.234353       1 utils.go:205] ID: 3 GRPC response: {}
I0813 01:07:23.234755       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0813 01:07:23.234801       1 utils.go:199] ID: 4 GRPC request: {}
I0813 01:07:23.234919       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0813 01:07:23.235670       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0813 01:07:23.235716       1 utils.go:199] ID: 5 GRPC request: {}
I0813 01:07:23.235731       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0813 01:07:23.235822       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}}}]}
I0813 01:07:29.363500       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0813 01:07:29.363550       1 utils.go:199] ID: 6 GRPC request: {}
I0813 01:07:29.363577       1 utils.go:205] ID: 6 GRPC response: {}
I0813 01:07:29.367548       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0813 01:07:29.367579       1 utils.go:199] ID: 7 GRPC request: {}
I0813 01:07:29.367590       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0813 01:07:29.367620       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0813 01:07:29.369444       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0813 01:07:29.369469       1 utils.go:199] ID: 8 GRPC request: {}
I0813 01:07:29.369518       1 utils.go:205] ID: 8 GRPC response: {}
I0813 01:07:29.369947       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0813 01:07:29.369965       1 utils.go:199] ID: 9 GRPC request: {}
I0813 01:07:29.370053       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0813 01:07:29.370782       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0813 01:07:29.370799       1 utils.go:199] ID: 10 GRPC request: {}
I0813 01:07:29.370807       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0813 01:07:29.370865       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}}}]}
I0813 01:07:29.371330       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0813 01:07:29.371345       1 utils.go:199] ID: 11 GRPC request: {}
I0813 01:07:29.371350       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0813 01:07:29.371396       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}}}]}
I0813 01:07:29.371701       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0813 01:07:29.371716       1 utils.go:199] ID: 12 GRPC request: {}
I0813 01:07:29.371721       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0813 01:07:29.371768       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}}}]}
I0813 01:07:30.723123       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0813 01:07:30.723213       1 utils.go:199] ID: 13 GRPC request: {}
I0813 01:07:30.723238       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0813 01:07:30.723290       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0813 01:07:30.725713       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0813 01:07:30.725736       1 utils.go:199] ID: 14 GRPC request: {}
I0813 01:07:30.725796       1 utils.go:205] ID: 14 GRPC response: {}
I0813 01:07:30.726421       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0813 01:07:30.726490       1 utils.go:199] ID: 15 GRPC request: {}
I0813 01:07:30.726504       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0813 01:07:30.726635       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}}}]}
I0813 01:07:32.356297       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0813 01:07:32.356358       1 utils.go:199] ID: 16 GRPC request: {}
I0813 01:07:32.356375       1 utils.go:205] ID: 16 GRPC response: {}
I0813 01:07:32.358222       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0813 01:07:32.358245       1 utils.go:199] ID: 17 GRPC request: {}
I0813 01:07:32.358251       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0813 01:07:32.358270       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0813 01:07:32.359917       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0813 01:07:32.359937       1 utils.go:199] ID: 18 GRPC request: {}
I0813 01:07:32.359968       1 utils.go:205] ID: 18 GRPC response: {}
I0813 01:07:32.360139       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0813 01:07:32.360154       1 utils.go:199] ID: 19 GRPC request: {}
I0813 01:07:32.360260       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0813 01:07:32.360632       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0813 01:07:32.360678       1 utils.go:199] ID: 20 GRPC request: {}
I0813 01:07:32.360691       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0813 01:07:32.360751       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}}}]}
I0813 01:08:32.571195       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0813 01:08:32.571237       1 utils.go:199] ID: 21 GRPC request: {}
I0813 01:08:32.571251       1 utils.go:205] ID: 21 GRPC response: {}
I0813 01:09:32.513214       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0813 01:09:32.513285       1 utils.go:199] ID: 22 GRPC request: {}
I0813 01:09:32.513307       1 utils.go:205] ID: 22 GRPC response: {}
I0813 01:10:13.496022       1 utils.go:198] ID: 23 Req-ID: pvc-d9d3526c-08e7-4e94-99cc-0159b9b79117 GRPC call: /csi.v1.Controller/CreateVolume
I0813 01:10:13.496409       1 utils.go:199] ID: 23 Req-ID: pvc-d9d3526c-08e7-4e94-99cc-0159b9b79117 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-d9d3526c-08e7-4e94-99cc-0159b9b79117","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-d9d3526c-08e7-4e94-99cc-0159b9b79117","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}}]}
I0813 01:10:13.496668       1 rbd_util.go:1315] ID: 23 Req-ID: pvc-d9d3526c-08e7-4e94-99cc-0159b9b79117 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0813 01:10:13.512910       1 omap.go:80] ID: 23 Req-ID: pvc-d9d3526c-08e7-4e94-99cc-0159b9b79117 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0813 01:10:13.523614       1 omap.go:159] ID: 23 Req-ID: pvc-d9d3526c-08e7-4e94-99cc-0159b9b79117 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-d9d3526c-08e7-4e94-99cc-0159b9b79117:de262cf5-932a-4ec6-96df-1720af1083d6])
I0813 01:10:13.527968       1 omap.go:159] ID: 23 Req-ID: pvc-d9d3526c-08e7-4e94-99cc-0159b9b79117 set omap keys (pool="kube", namespace="", name="csi.volume.de262cf5-932a-4ec6-96df-1720af1083d6"): map[csi.imagename:csi-vol-de262cf5-932a-4ec6-96df-1720af1083d6 csi.volname:pvc-d9d3526c-08e7-4e94-99cc-0159b9b79117 csi.volume.owner:default])
I0813 01:10:13.528119       1 rbd_journal.go:491] ID: 23 Req-ID: pvc-d9d3526c-08e7-4e94-99cc-0159b9b79117 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-de262cf5-932a-4ec6-96df-1720af1083d6) and image name (csi-vol-de262cf5-932a-4ec6-96df-1720af1083d6) for request name (pvc-d9d3526c-08e7-4e94-99cc-0159b9b79117)
I0813 01:10:13.528233       1 rbd_util.go:423] ID: 23 Req-ID: pvc-d9d3526c-08e7-4e94-99cc-0159b9b79117 rbd: create kube/csi-vol-de262cf5-932a-4ec6-96df-1720af1083d6 size 5120M (features: [layering]) using mon 199.204.45.38
I0813 01:10:13.528295       1 rbd_util.go:1563] ID: 23 Req-ID: pvc-d9d3526c-08e7-4e94-99cc-0159b9b79117 setting image options on kube/csi-vol-de262cf5-932a-4ec6-96df-1720af1083d6
I0813 01:10:13.547080       1 controllerserver.go:763] ID: 23 Req-ID: pvc-d9d3526c-08e7-4e94-99cc-0159b9b79117 created image kube/csi-vol-de262cf5-932a-4ec6-96df-1720af1083d6 backed for request name pvc-d9d3526c-08e7-4e94-99cc-0159b9b79117
I0813 01:10:13.573552       1 omap.go:159] ID: 23 Req-ID: pvc-d9d3526c-08e7-4e94-99cc-0159b9b79117 set omap keys (pool="kube", namespace="", name="csi.volume.de262cf5-932a-4ec6-96df-1720af1083d6"): map[csi.imageid:3804ef6f9694])
I0813 01:10:13.639390       1 utils.go:205] ID: 23 Req-ID: pvc-d9d3526c-08e7-4e94-99cc-0159b9b79117 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-de262cf5-932a-4ec6-96df-1720af1083d6","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-de262cf5-932a-4ec6-96df-1720af1083d6"}}
I0813 01:10:32.512515       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0813 01:10:32.512587       1 utils.go:199] ID: 24 GRPC request: {}
I0813 01:10:32.512625       1 utils.go:205] ID: 24 GRPC response: {}