I0528 00:48:12.300192       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0528 00:48:12.300312       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0528 00:48:12.300327       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0528 00:48:12.300332       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0528 00:48:12.300336       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0528 00:48:12.300340       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0528 00:48:12.300344       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0528 00:48:12.300347       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0528 00:48:12.300350       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0528 00:48:12.300354       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0528 00:48:12.300612       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0528 00:48:12.300656       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0528 00:48:15.504662       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0528 00:48:15.506112       1 utils.go:199] ID: 1 GRPC request: {}
I0528 00:48:15.506171       1 utils.go:205] ID: 1 GRPC response: {}
I0528 00:48:15.508278       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0528 00:48:15.508388       1 utils.go:199] ID: 2 GRPC request: {}
I0528 00:48:15.508406       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0528 00:48:15.508469       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0528 00:48:15.509975       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0528 00:48:15.510005       1 utils.go:199] ID: 3 GRPC request: {}
I0528 00:48:15.510017       1 utils.go:205] ID: 3 GRPC response: {}
I0528 00:48:15.510644       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0528 00:48:15.510725       1 utils.go:199] ID: 4 GRPC request: {}
I0528 00:48:15.510963       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0528 00:48:15.511735       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0528 00:48:15.511889       1 utils.go:199] ID: 5 GRPC request: {}
I0528 00:48:15.511905       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0528 00:48:15.512115       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}}}]}
I0528 00:48:16.854619       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0528 00:48:16.854686       1 utils.go:199] ID: 6 GRPC request: {}
I0528 00:48:16.854719       1 utils.go:205] ID: 6 GRPC response: {}
I0528 00:48:16.857509       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0528 00:48:16.857673       1 utils.go:199] ID: 7 GRPC request: {}
I0528 00:48:16.857690       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0528 00:48:16.857797       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0528 00:48:16.859659       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0528 00:48:16.859685       1 utils.go:199] ID: 8 GRPC request: {}
I0528 00:48:16.859820       1 utils.go:205] ID: 8 GRPC response: {}
I0528 00:48:16.860321       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0528 00:48:16.860381       1 utils.go:199] ID: 9 GRPC request: {}
I0528 00:48:16.860485       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0528 00:48:16.861106       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0528 00:48:16.861165       1 utils.go:199] ID: 10 GRPC request: {}
I0528 00:48:16.861182       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0528 00:48:16.861310       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}}}]}
I0528 00:48:16.861810       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0528 00:48:16.861857       1 utils.go:199] ID: 11 GRPC request: {}
I0528 00:48:16.861880       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0528 00:48:16.861968       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}}}]}
I0528 00:48:16.862352       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0528 00:48:16.862378       1 utils.go:199] ID: 12 GRPC request: {}
I0528 00:48:16.862409       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0528 00:48:16.862747       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}}}]}
I0528 00:48:22.584835       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0528 00:48:22.584930       1 utils.go:199] ID: 13 GRPC request: {}
I0528 00:48:22.584953       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0528 00:48:22.584988       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0528 00:48:22.590084       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0528 00:48:22.590162       1 utils.go:199] ID: 14 GRPC request: {}
I0528 00:48:22.590192       1 utils.go:205] ID: 14 GRPC response: {}
I0528 00:48:22.590966       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0528 00:48:22.591008       1 utils.go:199] ID: 15 GRPC request: {}
I0528 00:48:22.591024       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0528 00:48:22.591117       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}}}]}
I0528 00:48:25.219399       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0528 00:48:25.219441       1 utils.go:199] ID: 16 GRPC request: {}
I0528 00:48:25.219463       1 utils.go:205] ID: 16 GRPC response: {}
I0528 00:48:25.225812       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0528 00:48:25.225851       1 utils.go:199] ID: 17 GRPC request: {}
I0528 00:48:25.225869       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0528 00:48:25.225907       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0528 00:48:25.227845       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0528 00:48:25.227859       1 utils.go:199] ID: 18 GRPC request: {}
I0528 00:48:25.227873       1 utils.go:205] ID: 18 GRPC response: {}
I0528 00:48:25.228179       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0528 00:48:25.228217       1 utils.go:199] ID: 19 GRPC request: {}
I0528 00:48:25.228354       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0528 00:48:25.228942       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0528 00:48:25.228960       1 utils.go:199] ID: 20 GRPC request: {}
I0528 00:48:25.228968       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0528 00:48:25.229046       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}}}]}
I0528 00:49:25.466624       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0528 00:49:25.466653       1 utils.go:199] ID: 21 GRPC request: {}
I0528 00:49:25.466665       1 utils.go:205] ID: 21 GRPC response: {}
I0528 00:50:25.415546       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0528 00:50:25.415608       1 utils.go:199] ID: 22 GRPC request: {}
I0528 00:50:25.415631       1 utils.go:205] ID: 22 GRPC response: {}
I0528 00:51:25.467811       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0528 00:51:25.467863       1 utils.go:199] ID: 23 GRPC request: {}
I0528 00:51:25.467885       1 utils.go:205] ID: 23 GRPC response: {}
I0528 00:52:00.294193       1 utils.go:198] ID: 24 Req-ID: pvc-8ad0d4ba-796a-40b8-8d72-abac12f5f681 GRPC call: /csi.v1.Controller/CreateVolume
I0528 00:52:00.294464       1 utils.go:199] ID: 24 Req-ID: pvc-8ad0d4ba-796a-40b8-8d72-abac12f5f681 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-8ad0d4ba-796a-40b8-8d72-abac12f5f681","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-8ad0d4ba-796a-40b8-8d72-abac12f5f681","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}}]}
I0528 00:52:00.294672       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-8ad0d4ba-796a-40b8-8d72-abac12f5f681 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0528 00:52:00.310088       1 omap.go:80] ID: 24 Req-ID: pvc-8ad0d4ba-796a-40b8-8d72-abac12f5f681 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0528 00:52:00.322923       1 omap.go:159] ID: 24 Req-ID: pvc-8ad0d4ba-796a-40b8-8d72-abac12f5f681 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-8ad0d4ba-796a-40b8-8d72-abac12f5f681:2829fe67-2088-48fe-a4ad-9feef62eac59])
I0528 00:52:00.329619       1 omap.go:159] ID: 24 Req-ID: pvc-8ad0d4ba-796a-40b8-8d72-abac12f5f681 set omap keys (pool="kube", namespace="", name="csi.volume.2829fe67-2088-48fe-a4ad-9feef62eac59"): map[csi.imagename:csi-vol-2829fe67-2088-48fe-a4ad-9feef62eac59 csi.volname:pvc-8ad0d4ba-796a-40b8-8d72-abac12f5f681 csi.volume.owner:default])
I0528 00:52:00.329658       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-8ad0d4ba-796a-40b8-8d72-abac12f5f681 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-2829fe67-2088-48fe-a4ad-9feef62eac59) and image name (csi-vol-2829fe67-2088-48fe-a4ad-9feef62eac59) for request name (pvc-8ad0d4ba-796a-40b8-8d72-abac12f5f681)
I0528 00:52:00.329735       1 rbd_util.go:423] ID: 24 Req-ID: pvc-8ad0d4ba-796a-40b8-8d72-abac12f5f681 rbd: create kube/csi-vol-2829fe67-2088-48fe-a4ad-9feef62eac59 size 5120M (features: [layering]) using mon 199.204.45.246
I0528 00:52:00.329801       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-8ad0d4ba-796a-40b8-8d72-abac12f5f681 setting image options on kube/csi-vol-2829fe67-2088-48fe-a4ad-9feef62eac59
I0528 00:52:00.357040       1 controllerserver.go:763] ID: 24 Req-ID: pvc-8ad0d4ba-796a-40b8-8d72-abac12f5f681 created image kube/csi-vol-2829fe67-2088-48fe-a4ad-9feef62eac59 backed for request name pvc-8ad0d4ba-796a-40b8-8d72-abac12f5f681
I0528 00:52:00.380674       1 omap.go:159] ID: 24 Req-ID: pvc-8ad0d4ba-796a-40b8-8d72-abac12f5f681 set omap keys (pool="kube", namespace="", name="csi.volume.2829fe67-2088-48fe-a4ad-9feef62eac59"): map[csi.imageid:37edad4a7fae])
I0528 00:52:00.462736       1 utils.go:205] ID: 24 Req-ID: pvc-8ad0d4ba-796a-40b8-8d72-abac12f5f681 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-2829fe67-2088-48fe-a4ad-9feef62eac59","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-2829fe67-2088-48fe-a4ad-9feef62eac59"}}
I0528 00:52:25.426088       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0528 00:52:25.426156       1 utils.go:199] ID: 25 GRPC request: {}
I0528 00:52:25.426181       1 utils.go:205] ID: 25 GRPC response: {}
I0528 00:53:25.437923       1 utils.go:198] ID: 26 GRPC call: /csi.v1.Identity/Probe
I0528 00:53:25.437975       1 utils.go:199] ID: 26 GRPC request: {}
I0528 00:53:25.437997       1 utils.go:205] ID: 26 GRPC response: {}
I0528 00:54:25.436751       1 utils.go:198] ID: 27 GRPC call: /csi.v1.Identity/Probe
I0528 00:54:25.436792       1 utils.go:199] ID: 27 GRPC request: {}
I0528 00:54:25.436808       1 utils.go:205] ID: 27 GRPC response: {}