I0330 17:57:11.339263       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0330 17:57:11.339373       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0330 17:57:11.339385       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0330 17:57:11.339388       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0330 17:57:11.339391       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0330 17:57:11.339394       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0330 17:57:11.339398       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0330 17:57:11.339422       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0330 17:57:11.339426       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0330 17:57:11.339429       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0330 17:57:11.339692       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0330 17:57:11.339732       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0330 17:57:13.237157       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0330 17:57:13.238889       1 utils.go:199] ID: 1 GRPC request: {}
I0330 17:57:13.238955       1 utils.go:205] ID: 1 GRPC response: {}
I0330 17:57:13.242344       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0330 17:57:13.242393       1 utils.go:199] ID: 2 GRPC request: {}
I0330 17:57:13.242407       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0330 17:57:13.242521       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0330 17:57:13.244077       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0330 17:57:13.244097       1 utils.go:199] ID: 3 GRPC request: {}
I0330 17:57:13.244107       1 utils.go:205] ID: 3 GRPC response: {}
I0330 17:57:13.244686       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0330 17:57:13.244727       1 utils.go:199] ID: 4 GRPC request: {}
I0330 17:57:13.244914       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0330 17:57:13.245787       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0330 17:57:13.245928       1 utils.go:199] ID: 5 GRPC request: {}
I0330 17:57:13.245960       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0330 17:57:13.246172       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}}}]}
I0330 17:57:17.233947       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0330 17:57:17.233983       1 utils.go:199] ID: 6 GRPC request: {}
I0330 17:57:17.234002       1 utils.go:205] ID: 6 GRPC response: {}
I0330 17:57:17.237299       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0330 17:57:17.237370       1 utils.go:199] ID: 7 GRPC request: {}
I0330 17:57:17.237396       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0330 17:57:17.237451       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0330 17:57:17.239279       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0330 17:57:17.239303       1 utils.go:199] ID: 8 GRPC request: {}
I0330 17:57:17.239369       1 utils.go:205] ID: 8 GRPC response: {}
I0330 17:57:17.239850       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0330 17:57:17.239873       1 utils.go:199] ID: 9 GRPC request: {}
I0330 17:57:17.239993       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0330 17:57:17.240603       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0330 17:57:17.240622       1 utils.go:199] ID: 10 GRPC request: {}
I0330 17:57:17.240666       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0330 17:57:17.240761       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}}}]}
I0330 17:57:17.241157       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0330 17:57:17.241171       1 utils.go:199] ID: 11 GRPC request: {}
I0330 17:57:17.241181       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0330 17:57:17.241320       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}}}]}
I0330 17:57:17.241628       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0330 17:57:17.241676       1 utils.go:199] ID: 12 GRPC request: {}
I0330 17:57:17.241686       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0330 17:57:17.241790       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}}}]}
I0330 17:57:18.876881       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0330 17:57:18.876924       1 utils.go:199] ID: 13 GRPC request: {}
I0330 17:57:18.877271       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0330 17:57:18.877387       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0330 17:57:18.882255       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0330 17:57:18.882299       1 utils.go:199] ID: 14 GRPC request: {}
I0330 17:57:18.882316       1 utils.go:205] ID: 14 GRPC response: {}
I0330 17:57:18.882708       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0330 17:57:18.882739       1 utils.go:199] ID: 15 GRPC request: {}
I0330 17:57:18.882760       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0330 17:57:18.883007       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}}}]}
I0330 17:57:20.980001       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0330 17:57:20.980034       1 utils.go:199] ID: 16 GRPC request: {}
I0330 17:57:20.980046       1 utils.go:205] ID: 16 GRPC response: {}
I0330 17:57:20.983632       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0330 17:57:20.983646       1 utils.go:199] ID: 17 GRPC request: {}
I0330 17:57:20.983652       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0330 17:57:20.983669       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0330 17:57:20.985867       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0330 17:57:20.985914       1 utils.go:199] ID: 18 GRPC request: {}
I0330 17:57:20.985931       1 utils.go:205] ID: 18 GRPC response: {}
I0330 17:57:20.986546       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0330 17:57:20.986575       1 utils.go:199] ID: 19 GRPC request: {}
I0330 17:57:20.986741       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0330 17:57:20.987485       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0330 17:57:20.987540       1 utils.go:199] ID: 20 GRPC request: {}
I0330 17:57:20.987553       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0330 17:57:20.987674       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}}}]}
I0330 17:58:21.160966       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0330 17:58:21.161049       1 utils.go:199] ID: 21 GRPC request: {}
I0330 17:58:21.161073       1 utils.go:205] ID: 21 GRPC response: {}
I0330 17:59:21.138574       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0330 17:59:21.138659       1 utils.go:199] ID: 22 GRPC request: {}
I0330 17:59:21.138683       1 utils.go:205] ID: 22 GRPC response: {}
I0330 18:00:21.137441       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0330 18:00:21.137497       1 utils.go:199] ID: 23 GRPC request: {}
I0330 18:00:21.137519       1 utils.go:205] ID: 23 GRPC response: {}
I0330 18:00:24.273000       1 utils.go:198] ID: 24 Req-ID: pvc-dc4d32af-f9f1-43a4-98c2-d330b055feae GRPC call: /csi.v1.Controller/CreateVolume
I0330 18:00:24.273247       1 utils.go:199] ID: 24 Req-ID: pvc-dc4d32af-f9f1-43a4-98c2-d330b055feae GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-dc4d32af-f9f1-43a4-98c2-d330b055feae","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-dc4d32af-f9f1-43a4-98c2-d330b055feae","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}}]}
I0330 18:00:24.273458       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-dc4d32af-f9f1-43a4-98c2-d330b055feae setting disableInUseChecks: false image features: [layering] mounter: rbd
E0330 18:00:24.292515       1 omap.go:80] ID: 24 Req-ID: pvc-dc4d32af-f9f1-43a4-98c2-d330b055feae omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0330 18:00:24.305784       1 omap.go:159] ID: 24 Req-ID: pvc-dc4d32af-f9f1-43a4-98c2-d330b055feae set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-dc4d32af-f9f1-43a4-98c2-d330b055feae:7419d3b4-44fc-497d-9ce1-64dee3cf6a58])
I0330 18:00:24.310447       1 omap.go:159] ID: 24 Req-ID: pvc-dc4d32af-f9f1-43a4-98c2-d330b055feae set omap keys (pool="kube", namespace="", name="csi.volume.7419d3b4-44fc-497d-9ce1-64dee3cf6a58"): map[csi.imagename:csi-vol-7419d3b4-44fc-497d-9ce1-64dee3cf6a58 csi.volname:pvc-dc4d32af-f9f1-43a4-98c2-d330b055feae csi.volume.owner:default])
I0330 18:00:24.310473       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-dc4d32af-f9f1-43a4-98c2-d330b055feae generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-7419d3b4-44fc-497d-9ce1-64dee3cf6a58) and image name (csi-vol-7419d3b4-44fc-497d-9ce1-64dee3cf6a58) for request name (pvc-dc4d32af-f9f1-43a4-98c2-d330b055feae)
I0330 18:00:24.310558       1 rbd_util.go:423] ID: 24 Req-ID: pvc-dc4d32af-f9f1-43a4-98c2-d330b055feae rbd: create kube/csi-vol-7419d3b4-44fc-497d-9ce1-64dee3cf6a58 size 5120M (features: [layering]) using mon 199.19.213.145
I0330 18:00:24.310630       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-dc4d32af-f9f1-43a4-98c2-d330b055feae setting image options on kube/csi-vol-7419d3b4-44fc-497d-9ce1-64dee3cf6a58
I0330 18:00:25.837455       1 controllerserver.go:763] ID: 24 Req-ID: pvc-dc4d32af-f9f1-43a4-98c2-d330b055feae created image kube/csi-vol-7419d3b4-44fc-497d-9ce1-64dee3cf6a58 backed for request name pvc-dc4d32af-f9f1-43a4-98c2-d330b055feae
I0330 18:00:25.867764       1 omap.go:159] ID: 24 Req-ID: pvc-dc4d32af-f9f1-43a4-98c2-d330b055feae set omap keys (pool="kube", namespace="", name="csi.volume.7419d3b4-44fc-497d-9ce1-64dee3cf6a58"): map[csi.imageid:37d98a8420b2])
I0330 18:00:25.945793       1 utils.go:205] ID: 24 Req-ID: pvc-dc4d32af-f9f1-43a4-98c2-d330b055feae GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-7419d3b4-44fc-497d-9ce1-64dee3cf6a58","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-7419d3b4-44fc-497d-9ce1-64dee3cf6a58"}}