I0420 04:52:13.158562       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0420 04:52:13.158768       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0420 04:52:13.158786       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0420 04:52:13.158793       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0420 04:52:13.158796       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0420 04:52:13.158799       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0420 04:52:13.158804       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0420 04:52:13.158807       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0420 04:52:13.158810       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0420 04:52:13.158812       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0420 04:52:13.159456       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0420 04:52:13.159466       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0420 04:52:15.076808       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0420 04:52:15.078622       1 utils.go:199] ID: 1 GRPC request: {}
I0420 04:52:15.078676       1 utils.go:205] ID: 1 GRPC response: {}
I0420 04:52:15.081209       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0420 04:52:15.081348       1 utils.go:199] ID: 2 GRPC request: {}
I0420 04:52:15.081370       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0420 04:52:15.081428       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0420 04:52:15.083840       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0420 04:52:15.083887       1 utils.go:199] ID: 3 GRPC request: {}
I0420 04:52:15.083915       1 utils.go:205] ID: 3 GRPC response: {}
I0420 04:52:15.084596       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0420 04:52:15.084671       1 utils.go:199] ID: 4 GRPC request: {}
I0420 04:52:15.084849       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0420 04:52:15.086263       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0420 04:52:15.086440       1 utils.go:199] ID: 5 GRPC request: {}
I0420 04:52:15.086484       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0420 04:52:15.086652       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}}}]}
I0420 04:52:17.352895       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0420 04:52:17.352951       1 utils.go:199] ID: 6 GRPC request: {}
I0420 04:52:17.352970       1 utils.go:205] ID: 6 GRPC response: {}
I0420 04:52:17.357302       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0420 04:52:17.357473       1 utils.go:199] ID: 7 GRPC request: {}
I0420 04:52:17.357493       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0420 04:52:17.357553       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0420 04:52:17.359769       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0420 04:52:17.359997       1 utils.go:199] ID: 8 GRPC request: {}
I0420 04:52:17.360088       1 utils.go:205] ID: 8 GRPC response: {}
I0420 04:52:17.360933       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0420 04:52:17.360993       1 utils.go:199] ID: 9 GRPC request: {}
I0420 04:52:17.361130       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0420 04:52:17.361928       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0420 04:52:17.361994       1 utils.go:199] ID: 10 GRPC request: {}
I0420 04:52:17.362013       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0420 04:52:17.362194       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}}}]}
I0420 04:52:17.363063       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0420 04:52:17.363140       1 utils.go:199] ID: 11 GRPC request: {}
I0420 04:52:17.363225       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0420 04:52:17.363357       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}}}]}
I0420 04:52:17.363875       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0420 04:52:17.363953       1 utils.go:199] ID: 12 GRPC request: {}
I0420 04:52:17.363988       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0420 04:52:17.364107       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}}}]}
I0420 04:52:18.855399       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0420 04:52:18.855623       1 utils.go:199] ID: 13 GRPC request: {}
I0420 04:52:18.855743       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0420 04:52:18.855922       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0420 04:52:18.858451       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0420 04:52:18.858485       1 utils.go:199] ID: 14 GRPC request: {}
I0420 04:52:18.858671       1 utils.go:205] ID: 14 GRPC response: {}
I0420 04:52:18.860207       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0420 04:52:18.860236       1 utils.go:199] ID: 15 GRPC request: {}
I0420 04:52:18.860247       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0420 04:52:18.860433       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}}}]}
I0420 04:52:20.061205       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0420 04:52:20.061255       1 utils.go:199] ID: 16 GRPC request: {}
I0420 04:52:20.061274       1 utils.go:205] ID: 16 GRPC response: {}
I0420 04:52:20.063745       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0420 04:52:20.063766       1 utils.go:199] ID: 17 GRPC request: {}
I0420 04:52:20.063774       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0420 04:52:20.063799       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0420 04:52:20.066717       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0420 04:52:20.066775       1 utils.go:199] ID: 18 GRPC request: {}
I0420 04:52:20.066933       1 utils.go:205] ID: 18 GRPC response: {}
I0420 04:52:20.067483       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0420 04:52:20.067782       1 utils.go:199] ID: 19 GRPC request: {}
I0420 04:52:20.068053       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0420 04:52:20.069257       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0420 04:52:20.069323       1 utils.go:199] ID: 20 GRPC request: {}
I0420 04:52:20.069342       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0420 04:52:20.069478       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}}}]}
I0420 04:53:20.270513       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0420 04:53:20.270600       1 utils.go:199] ID: 21 GRPC request: {}
I0420 04:53:20.270661       1 utils.go:205] ID: 21 GRPC response: {}
I0420 04:54:20.271106       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0420 04:54:20.271318       1 utils.go:199] ID: 22 GRPC request: {}
I0420 04:54:20.271451       1 utils.go:205] ID: 22 GRPC response: {}
I0420 04:55:20.269100       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0420 04:55:20.269191       1 utils.go:199] ID: 23 GRPC request: {}
I0420 04:55:20.269238       1 utils.go:205] ID: 23 GRPC response: {}
I0420 04:55:29.599057       1 utils.go:198] ID: 24 Req-ID: pvc-08a9aec4-9e03-4a6f-9957-c4c043e80033 GRPC call: /csi.v1.Controller/CreateVolume
I0420 04:55:29.599502       1 utils.go:199] ID: 24 Req-ID: pvc-08a9aec4-9e03-4a6f-9957-c4c043e80033 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-08a9aec4-9e03-4a6f-9957-c4c043e80033","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-08a9aec4-9e03-4a6f-9957-c4c043e80033","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}}]}
I0420 04:55:29.599793       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-08a9aec4-9e03-4a6f-9957-c4c043e80033 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0420 04:55:29.616118       1 omap.go:80] ID: 24 Req-ID: pvc-08a9aec4-9e03-4a6f-9957-c4c043e80033 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0420 04:55:29.631387       1 omap.go:159] ID: 24 Req-ID: pvc-08a9aec4-9e03-4a6f-9957-c4c043e80033 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-08a9aec4-9e03-4a6f-9957-c4c043e80033:a1095354-c546-4d83-9e00-66f6b1a63b55])
I0420 04:55:29.638115       1 omap.go:159] ID: 24 Req-ID: pvc-08a9aec4-9e03-4a6f-9957-c4c043e80033 set omap keys (pool="kube", namespace="", name="csi.volume.a1095354-c546-4d83-9e00-66f6b1a63b55"): map[csi.imagename:csi-vol-a1095354-c546-4d83-9e00-66f6b1a63b55 csi.volname:pvc-08a9aec4-9e03-4a6f-9957-c4c043e80033 csi.volume.owner:default])
I0420 04:55:29.638149       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-08a9aec4-9e03-4a6f-9957-c4c043e80033 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-a1095354-c546-4d83-9e00-66f6b1a63b55) and image name (csi-vol-a1095354-c546-4d83-9e00-66f6b1a63b55) for request name (pvc-08a9aec4-9e03-4a6f-9957-c4c043e80033)
I0420 04:55:29.638214       1 rbd_util.go:423] ID: 24 Req-ID: pvc-08a9aec4-9e03-4a6f-9957-c4c043e80033 rbd: create kube/csi-vol-a1095354-c546-4d83-9e00-66f6b1a63b55 size 5120M (features: [layering]) using mon 199.204.45.25
I0420 04:55:29.638775       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-08a9aec4-9e03-4a6f-9957-c4c043e80033 setting image options on kube/csi-vol-a1095354-c546-4d83-9e00-66f6b1a63b55
I0420 04:55:30.748288       1 controllerserver.go:763] ID: 24 Req-ID: pvc-08a9aec4-9e03-4a6f-9957-c4c043e80033 created image kube/csi-vol-a1095354-c546-4d83-9e00-66f6b1a63b55 backed for request name pvc-08a9aec4-9e03-4a6f-9957-c4c043e80033
I0420 04:55:30.777811       1 omap.go:159] ID: 24 Req-ID: pvc-08a9aec4-9e03-4a6f-9957-c4c043e80033 set omap keys (pool="kube", namespace="", name="csi.volume.a1095354-c546-4d83-9e00-66f6b1a63b55"): map[csi.imageid:37d9fc6e6788])
I0420 04:55:30.878795       1 utils.go:205] ID: 24 Req-ID: pvc-08a9aec4-9e03-4a6f-9957-c4c043e80033 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-a1095354-c546-4d83-9e00-66f6b1a63b55","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-a1095354-c546-4d83-9e00-66f6b1a63b55"}}
I0420 04:56:20.279969       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0420 04:56:20.280042       1 utils.go:199] ID: 25 GRPC request: {}
I0420 04:56:20.280075       1 utils.go:205] ID: 25 GRPC response: {}