I0427 21:00:57.631649       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0427 21:00:57.631823       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0427 21:00:57.631947       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0427 21:00:57.631955       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0427 21:00:57.631958       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0427 21:00:57.631961       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0427 21:00:57.631965       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0427 21:00:57.631968       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0427 21:00:57.631970       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0427 21:00:57.631978       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0427 21:00:57.632281       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0427 21:00:57.632368       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0427 21:01:00.304201       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0427 21:01:00.305550       1 utils.go:199] ID: 1 GRPC request: {}
I0427 21:01:00.305620       1 utils.go:205] ID: 1 GRPC response: {}
I0427 21:01:00.307507       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0427 21:01:00.307802       1 utils.go:199] ID: 2 GRPC request: {}
I0427 21:01:00.307841       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0427 21:01:00.308053       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0427 21:01:00.310338       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0427 21:01:00.310392       1 utils.go:199] ID: 3 GRPC request: {}
I0427 21:01:00.310450       1 utils.go:205] ID: 3 GRPC response: {}
I0427 21:01:00.311379       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0427 21:01:00.311425       1 utils.go:199] ID: 4 GRPC request: {}
I0427 21:01:00.311654       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0427 21:01:00.312596       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0427 21:01:00.312642       1 utils.go:199] ID: 5 GRPC request: {}
I0427 21:01:00.312656       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0427 21:01:00.312810       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}}}]}
I0427 21:01:03.136304       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0427 21:01:03.136341       1 utils.go:199] ID: 6 GRPC request: {}
I0427 21:01:03.136362       1 utils.go:205] ID: 6 GRPC response: {}
I0427 21:01:03.139716       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0427 21:01:03.139750       1 utils.go:199] ID: 7 GRPC request: {}
I0427 21:01:03.139758       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0427 21:01:03.139781       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0427 21:01:03.142103       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0427 21:01:03.142190       1 utils.go:199] ID: 8 GRPC request: {}
I0427 21:01:03.142221       1 utils.go:205] ID: 8 GRPC response: {}
I0427 21:01:03.142887       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0427 21:01:03.142955       1 utils.go:199] ID: 9 GRPC request: {}
I0427 21:01:03.143089       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0427 21:01:03.143966       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0427 21:01:03.143990       1 utils.go:199] ID: 10 GRPC request: {}
I0427 21:01:03.143998       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0427 21:01:03.144087       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}}}]}
I0427 21:01:03.144721       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0427 21:01:03.144738       1 utils.go:199] ID: 11 GRPC request: {}
I0427 21:01:03.144743       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0427 21:01:03.144794       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}}}]}
I0427 21:01:03.145148       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0427 21:01:03.145200       1 utils.go:199] ID: 12 GRPC request: {}
I0427 21:01:03.145215       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0427 21:01:03.145319       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}}}]}
I0427 21:01:04.486504       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0427 21:01:04.487730       1 utils.go:199] ID: 13 GRPC request: {}
I0427 21:01:04.487738       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0427 21:01:04.487758       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0427 21:01:04.490129       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0427 21:01:04.490248       1 utils.go:199] ID: 14 GRPC request: {}
I0427 21:01:04.490268       1 utils.go:205] ID: 14 GRPC response: {}
I0427 21:01:04.490772       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0427 21:01:04.490790       1 utils.go:199] ID: 15 GRPC request: {}
I0427 21:01:04.490798       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0427 21:01:04.490883       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}}}]}
I0427 21:01:05.762765       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0427 21:01:05.762828       1 utils.go:199] ID: 16 GRPC request: {}
I0427 21:01:05.762848       1 utils.go:205] ID: 16 GRPC response: {}
I0427 21:01:05.765571       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0427 21:01:05.765595       1 utils.go:199] ID: 17 GRPC request: {}
I0427 21:01:05.765604       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0427 21:01:05.765632       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0427 21:01:05.769108       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0427 21:01:05.769123       1 utils.go:199] ID: 18 GRPC request: {}
I0427 21:01:05.769132       1 utils.go:205] ID: 18 GRPC response: {}
I0427 21:01:05.769528       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0427 21:01:05.769545       1 utils.go:199] ID: 19 GRPC request: {}
I0427 21:01:05.769622       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0427 21:01:05.770209       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0427 21:01:05.770343       1 utils.go:199] ID: 20 GRPC request: {}
I0427 21:01:05.770406       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0427 21:01:05.770558       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}}}]}
I0427 21:02:05.925597       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0427 21:02:05.925664       1 utils.go:199] ID: 21 GRPC request: {}
I0427 21:02:05.925687       1 utils.go:205] ID: 21 GRPC response: {}
I0427 21:03:05.926263       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0427 21:03:05.926321       1 utils.go:199] ID: 22 GRPC request: {}
I0427 21:03:05.926341       1 utils.go:205] ID: 22 GRPC response: {}
I0427 21:04:05.925381       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0427 21:04:05.925485       1 utils.go:199] ID: 23 GRPC request: {}
I0427 21:04:05.925531       1 utils.go:205] ID: 23 GRPC response: {}
I0427 21:04:07.225732       1 utils.go:198] ID: 24 Req-ID: pvc-592faddc-cc3c-4af2-b684-1c453e1e0adf GRPC call: /csi.v1.Controller/CreateVolume
I0427 21:04:07.226571       1 utils.go:199] ID: 24 Req-ID: pvc-592faddc-cc3c-4af2-b684-1c453e1e0adf GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-592faddc-cc3c-4af2-b684-1c453e1e0adf","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-592faddc-cc3c-4af2-b684-1c453e1e0adf","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}}]}
I0427 21:04:07.227646       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-592faddc-cc3c-4af2-b684-1c453e1e0adf setting disableInUseChecks: false image features: [layering] mounter: rbd
E0427 21:04:07.245211       1 omap.go:80] ID: 24 Req-ID: pvc-592faddc-cc3c-4af2-b684-1c453e1e0adf omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0427 21:04:07.258452       1 omap.go:159] ID: 24 Req-ID: pvc-592faddc-cc3c-4af2-b684-1c453e1e0adf set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-592faddc-cc3c-4af2-b684-1c453e1e0adf:6908942e-8f77-479e-8315-1b3426f270f9])
I0427 21:04:07.263934       1 omap.go:159] ID: 24 Req-ID: pvc-592faddc-cc3c-4af2-b684-1c453e1e0adf set omap keys (pool="kube", namespace="", name="csi.volume.6908942e-8f77-479e-8315-1b3426f270f9"): map[csi.imagename:csi-vol-6908942e-8f77-479e-8315-1b3426f270f9 csi.volname:pvc-592faddc-cc3c-4af2-b684-1c453e1e0adf csi.volume.owner:default])
I0427 21:04:07.263980       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-592faddc-cc3c-4af2-b684-1c453e1e0adf generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-6908942e-8f77-479e-8315-1b3426f270f9) and image name (csi-vol-6908942e-8f77-479e-8315-1b3426f270f9) for request name (pvc-592faddc-cc3c-4af2-b684-1c453e1e0adf)
I0427 21:04:07.264126       1 rbd_util.go:423] ID: 24 Req-ID: pvc-592faddc-cc3c-4af2-b684-1c453e1e0adf rbd: create kube/csi-vol-6908942e-8f77-479e-8315-1b3426f270f9 size 5120M (features: [layering]) using mon 199.204.45.89
I0427 21:04:07.264270       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-592faddc-cc3c-4af2-b684-1c453e1e0adf setting image options on kube/csi-vol-6908942e-8f77-479e-8315-1b3426f270f9
I0427 21:04:08.750106       1 controllerserver.go:763] ID: 24 Req-ID: pvc-592faddc-cc3c-4af2-b684-1c453e1e0adf created image kube/csi-vol-6908942e-8f77-479e-8315-1b3426f270f9 backed for request name pvc-592faddc-cc3c-4af2-b684-1c453e1e0adf
I0427 21:04:08.875675       1 omap.go:159] ID: 24 Req-ID: pvc-592faddc-cc3c-4af2-b684-1c453e1e0adf set omap keys (pool="kube", namespace="", name="csi.volume.6908942e-8f77-479e-8315-1b3426f270f9"): map[csi.imageid:37d9e61749b6])
I0427 21:04:08.955968       1 utils.go:205] ID: 24 Req-ID: pvc-592faddc-cc3c-4af2-b684-1c453e1e0adf GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-6908942e-8f77-479e-8315-1b3426f270f9","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-6908942e-8f77-479e-8315-1b3426f270f9"}}
I0427 21:05:05.941178       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0427 21:05:05.941262       1 utils.go:199] ID: 25 GRPC request: {}
I0427 21:05:05.941374       1 utils.go:205] ID: 25 GRPC response: {}