I1013 11:11:56.634760       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I1013 11:11:56.634956       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I1013 11:11:56.634975       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I1013 11:11:56.634980       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I1013 11:11:56.634984       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I1013 11:11:56.634988       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I1013 11:11:56.634992       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I1013 11:11:56.634996       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I1013 11:11:56.635000       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I1013 11:11:56.635005       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I1013 11:11:56.635339       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I1013 11:11:56.635361       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I1013 11:12:00.519773       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I1013 11:12:00.521340       1 utils.go:199] ID: 1 GRPC request: {}
I1013 11:12:00.521419       1 utils.go:205] ID: 1 GRPC response: {}
I1013 11:12:00.525023       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I1013 11:12:00.525107       1 utils.go:199] ID: 2 GRPC request: {}
I1013 11:12:00.525144       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I1013 11:12:00.525212       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I1013 11:12:00.526650       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I1013 11:12:00.526670       1 utils.go:199] ID: 3 GRPC request: {}
I1013 11:12:00.526700       1 utils.go:205] ID: 3 GRPC response: {}
I1013 11:12:00.527251       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I1013 11:12:00.527314       1 utils.go:199] ID: 4 GRPC request: {}
I1013 11:12:00.527476       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I1013 11:12:00.528319       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1013 11:12:00.528391       1 utils.go:199] ID: 5 GRPC request: {}
I1013 11:12:00.528446       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I1013 11:12:00.528618       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}}}]}
I1013 11:12:02.000955       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I1013 11:12:02.000990       1 utils.go:199] ID: 6 GRPC request: {}
I1013 11:12:02.001017       1 utils.go:205] ID: 6 GRPC response: {}
I1013 11:12:02.003194       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I1013 11:12:02.003228       1 utils.go:199] ID: 7 GRPC request: {}
I1013 11:12:02.003236       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I1013 11:12:02.003260       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I1013 11:12:02.006248       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I1013 11:12:02.006273       1 utils.go:199] ID: 8 GRPC request: {}
I1013 11:12:02.006307       1 utils.go:205] ID: 8 GRPC response: {}
I1013 11:12:02.006890       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I1013 11:12:02.006910       1 utils.go:199] ID: 9 GRPC request: {}
I1013 11:12:02.007057       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I1013 11:12:02.007758       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1013 11:12:02.007778       1 utils.go:199] ID: 10 GRPC request: {}
I1013 11:12:02.007792       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I1013 11:12:02.008001       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}}}]}
I1013 11:12:02.008543       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1013 11:12:02.008573       1 utils.go:199] ID: 11 GRPC request: {}
I1013 11:12:02.008579       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I1013 11:12:02.008648       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}}}]}
I1013 11:12:02.008973       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1013 11:12:02.009026       1 utils.go:199] ID: 12 GRPC request: {}
I1013 11:12:02.009032       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I1013 11:12:02.009102       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}}}]}
I1013 11:12:03.418817       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I1013 11:12:03.419010       1 utils.go:199] ID: 13 GRPC request: {}
I1013 11:12:03.419038       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I1013 11:12:03.419098       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I1013 11:12:03.426243       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I1013 11:12:03.426280       1 utils.go:199] ID: 14 GRPC request: {}
I1013 11:12:03.426330       1 utils.go:205] ID: 14 GRPC response: {}
I1013 11:12:03.427078       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1013 11:12:03.427134       1 utils.go:199] ID: 15 GRPC request: {}
I1013 11:12:03.427145       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I1013 11:12:03.427315       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}}}]}
I1013 11:12:04.771707       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I1013 11:12:04.771739       1 utils.go:199] ID: 16 GRPC request: {}
I1013 11:12:04.771754       1 utils.go:205] ID: 16 GRPC response: {}
I1013 11:12:04.778227       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I1013 11:12:04.778264       1 utils.go:199] ID: 17 GRPC request: {}
I1013 11:12:04.778273       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I1013 11:12:04.778297       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I1013 11:12:04.780100       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I1013 11:12:04.780137       1 utils.go:199] ID: 18 GRPC request: {}
I1013 11:12:04.780152       1 utils.go:205] ID: 18 GRPC response: {}
I1013 11:12:04.780505       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I1013 11:12:04.780537       1 utils.go:199] ID: 19 GRPC request: {}
I1013 11:12:04.780631       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I1013 11:12:04.781237       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I1013 11:12:04.781259       1 utils.go:199] ID: 20 GRPC request: {}
I1013 11:12:04.781266       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I1013 11:12:04.781349       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}}}]}
I1013 11:13:04.987552       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I1013 11:13:04.987688       1 utils.go:199] ID: 21 GRPC request: {}
I1013 11:13:04.987706       1 utils.go:205] ID: 21 GRPC response: {}
I1013 11:14:04.950467       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I1013 11:14:04.950597       1 utils.go:199] ID: 22 GRPC request: {}
I1013 11:14:04.950638       1 utils.go:205] ID: 22 GRPC response: {}
I1013 11:15:04.948691       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I1013 11:15:04.948752       1 utils.go:199] ID: 23 GRPC request: {}
I1013 11:15:04.948773       1 utils.go:205] ID: 23 GRPC response: {}
I1013 11:16:04.962769       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I1013 11:16:04.962839       1 utils.go:199] ID: 24 GRPC request: {}
I1013 11:16:04.962892       1 utils.go:205] ID: 24 GRPC response: {}
I1013 11:16:25.299079       1 utils.go:198] ID: 25 Req-ID: pvc-99fefd0b-5705-4b65-9bb9-4ee458e8f054 GRPC call: /csi.v1.Controller/CreateVolume
I1013 11:16:25.300315       1 utils.go:199] ID: 25 Req-ID: pvc-99fefd0b-5705-4b65-9bb9-4ee458e8f054 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-99fefd0b-5705-4b65-9bb9-4ee458e8f054","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-99fefd0b-5705-4b65-9bb9-4ee458e8f054","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}}]}
I1013 11:16:25.301070       1 rbd_util.go:1315] ID: 25 Req-ID: pvc-99fefd0b-5705-4b65-9bb9-4ee458e8f054 setting disableInUseChecks: false image features: [layering] mounter: rbd
E1013 11:16:25.328271       1 omap.go:80] ID: 25 Req-ID: pvc-99fefd0b-5705-4b65-9bb9-4ee458e8f054 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I1013 11:16:25.349651       1 omap.go:159] ID: 25 Req-ID: pvc-99fefd0b-5705-4b65-9bb9-4ee458e8f054 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-99fefd0b-5705-4b65-9bb9-4ee458e8f054:6c878925-0d86-4259-a924-86de9e87c67f])
I1013 11:16:25.354433       1 omap.go:159] ID: 25 Req-ID: pvc-99fefd0b-5705-4b65-9bb9-4ee458e8f054 set omap keys (pool="kube", namespace="", name="csi.volume.6c878925-0d86-4259-a924-86de9e87c67f"): map[csi.imagename:csi-vol-6c878925-0d86-4259-a924-86de9e87c67f csi.volname:pvc-99fefd0b-5705-4b65-9bb9-4ee458e8f054 csi.volume.owner:default])
I1013 11:16:25.354453       1 rbd_journal.go:491] ID: 25 Req-ID: pvc-99fefd0b-5705-4b65-9bb9-4ee458e8f054 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-6c878925-0d86-4259-a924-86de9e87c67f) and image name (csi-vol-6c878925-0d86-4259-a924-86de9e87c67f) for request name (pvc-99fefd0b-5705-4b65-9bb9-4ee458e8f054)
I1013 11:16:25.354574       1 rbd_util.go:423] ID: 25 Req-ID: pvc-99fefd0b-5705-4b65-9bb9-4ee458e8f054 rbd: create kube/csi-vol-6c878925-0d86-4259-a924-86de9e87c67f size 5120M (features: [layering]) using mon 162.253.55.223
I1013 11:16:25.354755       1 rbd_util.go:1563] ID: 25 Req-ID: pvc-99fefd0b-5705-4b65-9bb9-4ee458e8f054 setting image options on kube/csi-vol-6c878925-0d86-4259-a924-86de9e87c67f
I1013 11:16:25.388128       1 controllerserver.go:763] ID: 25 Req-ID: pvc-99fefd0b-5705-4b65-9bb9-4ee458e8f054 created image kube/csi-vol-6c878925-0d86-4259-a924-86de9e87c67f backed for request name pvc-99fefd0b-5705-4b65-9bb9-4ee458e8f054
I1013 11:16:25.420085       1 omap.go:159] ID: 25 Req-ID: pvc-99fefd0b-5705-4b65-9bb9-4ee458e8f054 set omap keys (pool="kube", namespace="", name="csi.volume.6c878925-0d86-4259-a924-86de9e87c67f"): map[csi.imageid:37f49ee179a2])
I1013 11:16:25.511876       1 utils.go:205] ID: 25 Req-ID: pvc-99fefd0b-5705-4b65-9bb9-4ee458e8f054 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-6c878925-0d86-4259-a924-86de9e87c67f","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-6c878925-0d86-4259-a924-86de9e87c67f"}}
I1013 11:17:04.948645       1 utils.go:198] ID: 26 GRPC call: /csi.v1.Identity/Probe
I1013 11:17:04.948677       1 utils.go:199] ID: 26 GRPC request: {}
I1013 11:17:04.948697       1 utils.go:205] ID: 26 GRPC response: {}