I0624 18:02:21.685179       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0624 18:02:21.685520       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0624 18:02:21.685602       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0624 18:02:21.685655       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0624 18:02:21.685710       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0624 18:02:21.685769       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0624 18:02:21.685815       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0624 18:02:21.685873       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0624 18:02:21.685918       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0624 18:02:21.685975       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0624 18:02:21.686365       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0624 18:02:21.686551       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0624 18:02:25.482137       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0624 18:02:25.484367       1 utils.go:199] ID: 1 GRPC request: {}
I0624 18:02:25.484487       1 utils.go:205] ID: 1 GRPC response: {}
I0624 18:02:25.488496       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0624 18:02:25.488572       1 utils.go:199] ID: 2 GRPC request: {}
I0624 18:02:25.488589       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0624 18:02:25.489405       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0624 18:02:25.493449       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0624 18:02:25.493485       1 utils.go:199] ID: 3 GRPC request: {}
I0624 18:02:25.493706       1 utils.go:205] ID: 3 GRPC response: {}
I0624 18:02:25.494164       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0624 18:02:25.494326       1 utils.go:199] ID: 4 GRPC request: {}
I0624 18:02:25.494548       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0624 18:02:25.496863       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0624 18:02:25.497066       1 utils.go:199] ID: 5 GRPC request: {}
I0624 18:02:25.497082       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0624 18:02:25.497290       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}}}]}
I0624 18:02:27.493357       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0624 18:02:27.493406       1 utils.go:199] ID: 6 GRPC request: {}
I0624 18:02:27.493438       1 utils.go:205] ID: 6 GRPC response: {}
I0624 18:02:27.497603       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0624 18:02:27.497628       1 utils.go:199] ID: 7 GRPC request: {}
I0624 18:02:27.497637       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0624 18:02:27.497674       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0624 18:02:27.499411       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0624 18:02:27.499447       1 utils.go:199] ID: 8 GRPC request: {}
I0624 18:02:27.499463       1 utils.go:205] ID: 8 GRPC response: {}
I0624 18:02:27.499846       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0624 18:02:27.499885       1 utils.go:199] ID: 9 GRPC request: {}
I0624 18:02:27.500030       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0624 18:02:27.500601       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0624 18:02:27.500628       1 utils.go:199] ID: 10 GRPC request: {}
I0624 18:02:27.500656       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0624 18:02:27.500828       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}}}]}
I0624 18:02:27.501408       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0624 18:02:27.501430       1 utils.go:199] ID: 11 GRPC request: {}
I0624 18:02:27.501437       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0624 18:02:27.501606       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}}}]}
I0624 18:02:27.502030       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0624 18:02:27.502057       1 utils.go:199] ID: 12 GRPC request: {}
I0624 18:02:27.502108       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0624 18:02:27.502224       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}}}]}
I0624 18:02:31.256379       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0624 18:02:31.256465       1 utils.go:199] ID: 13 GRPC request: {}
I0624 18:02:31.256599       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0624 18:02:31.256667       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0624 18:02:31.259867       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0624 18:02:31.259919       1 utils.go:199] ID: 14 GRPC request: {}
I0624 18:02:31.259935       1 utils.go:205] ID: 14 GRPC response: {}
I0624 18:02:31.260397       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0624 18:02:31.260491       1 utils.go:199] ID: 15 GRPC request: {}
I0624 18:02:31.260508       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0624 18:02:31.260615       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}}}]}
I0624 18:02:34.604502       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0624 18:02:34.604545       1 utils.go:199] ID: 16 GRPC request: {}
I0624 18:02:34.604567       1 utils.go:205] ID: 16 GRPC response: {}
I0624 18:02:34.611482       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0624 18:02:34.611516       1 utils.go:199] ID: 17 GRPC request: {}
I0624 18:02:34.611524       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0624 18:02:34.611566       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0624 18:02:34.613588       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0624 18:02:34.613631       1 utils.go:199] ID: 18 GRPC request: {}
I0624 18:02:34.613652       1 utils.go:205] ID: 18 GRPC response: {}
I0624 18:02:34.614302       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0624 18:02:34.614345       1 utils.go:199] ID: 19 GRPC request: {}
I0624 18:02:34.614425       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0624 18:02:34.614968       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0624 18:02:34.615003       1 utils.go:199] ID: 20 GRPC request: {}
I0624 18:02:34.615012       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0624 18:02:34.615117       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}}}]}
I0624 18:03:34.811754       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0624 18:03:34.811811       1 utils.go:199] ID: 21 GRPC request: {}
I0624 18:03:34.811834       1 utils.go:205] ID: 21 GRPC response: {}
I0624 18:04:34.764803       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0624 18:04:34.764858       1 utils.go:199] ID: 22 GRPC request: {}
I0624 18:04:34.764907       1 utils.go:205] ID: 22 GRPC response: {}
I0624 18:05:34.762683       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0624 18:05:34.762743       1 utils.go:199] ID: 23 GRPC request: {}
I0624 18:05:34.762765       1 utils.go:205] ID: 23 GRPC response: {}
I0624 18:06:09.605178       1 utils.go:198] ID: 24 Req-ID: pvc-15a43ac6-0dd5-4037-9cb2-0c3555ca4f9f GRPC call: /csi.v1.Controller/CreateVolume
I0624 18:06:09.605644       1 utils.go:199] ID: 24 Req-ID: pvc-15a43ac6-0dd5-4037-9cb2-0c3555ca4f9f GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-15a43ac6-0dd5-4037-9cb2-0c3555ca4f9f","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-15a43ac6-0dd5-4037-9cb2-0c3555ca4f9f","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}}]}
I0624 18:06:09.606290       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-15a43ac6-0dd5-4037-9cb2-0c3555ca4f9f setting disableInUseChecks: false image features: [layering] mounter: rbd
E0624 18:06:09.624016       1 omap.go:80] ID: 24 Req-ID: pvc-15a43ac6-0dd5-4037-9cb2-0c3555ca4f9f omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0624 18:06:09.636082       1 omap.go:159] ID: 24 Req-ID: pvc-15a43ac6-0dd5-4037-9cb2-0c3555ca4f9f set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-15a43ac6-0dd5-4037-9cb2-0c3555ca4f9f:6a78e032-6d07-4827-b3e1-92a121e02e20])
I0624 18:06:09.641097       1 omap.go:159] ID: 24 Req-ID: pvc-15a43ac6-0dd5-4037-9cb2-0c3555ca4f9f set omap keys (pool="kube", namespace="", name="csi.volume.6a78e032-6d07-4827-b3e1-92a121e02e20"): map[csi.imagename:csi-vol-6a78e032-6d07-4827-b3e1-92a121e02e20 csi.volname:pvc-15a43ac6-0dd5-4037-9cb2-0c3555ca4f9f csi.volume.owner:default])
I0624 18:06:09.641117       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-15a43ac6-0dd5-4037-9cb2-0c3555ca4f9f generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-6a78e032-6d07-4827-b3e1-92a121e02e20) and image name (csi-vol-6a78e032-6d07-4827-b3e1-92a121e02e20) for request name (pvc-15a43ac6-0dd5-4037-9cb2-0c3555ca4f9f)
I0624 18:06:09.641221       1 rbd_util.go:423] ID: 24 Req-ID: pvc-15a43ac6-0dd5-4037-9cb2-0c3555ca4f9f rbd: create kube/csi-vol-6a78e032-6d07-4827-b3e1-92a121e02e20 size 5120M (features: [layering]) using mon 199.19.213.246
I0624 18:06:09.641287       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-15a43ac6-0dd5-4037-9cb2-0c3555ca4f9f setting image options on kube/csi-vol-6a78e032-6d07-4827-b3e1-92a121e02e20
I0624 18:06:09.669409       1 controllerserver.go:763] ID: 24 Req-ID: pvc-15a43ac6-0dd5-4037-9cb2-0c3555ca4f9f created image kube/csi-vol-6a78e032-6d07-4827-b3e1-92a121e02e20 backed for request name pvc-15a43ac6-0dd5-4037-9cb2-0c3555ca4f9f
I0624 18:06:09.702584       1 omap.go:159] ID: 24 Req-ID: pvc-15a43ac6-0dd5-4037-9cb2-0c3555ca4f9f set omap keys (pool="kube", namespace="", name="csi.volume.6a78e032-6d07-4827-b3e1-92a121e02e20"): map[csi.imageid:37ed40b284f7])
I0624 18:06:09.785776       1 utils.go:205] ID: 24 Req-ID: pvc-15a43ac6-0dd5-4037-9cb2-0c3555ca4f9f GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-6a78e032-6d07-4827-b3e1-92a121e02e20","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-6a78e032-6d07-4827-b3e1-92a121e02e20"}}
I0624 18:06:34.775943       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0624 18:06:34.776038       1 utils.go:199] ID: 25 GRPC request: {}
I0624 18:06:34.776056       1 utils.go:205] ID: 25 GRPC response: {}