I0204 05:23:58.864179       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0204 05:23:58.864348       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0204 05:23:58.864448       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0204 05:23:58.864517       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0204 05:23:58.864557       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0204 05:23:58.864580       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0204 05:23:58.864605       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0204 05:23:58.864656       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0204 05:23:58.864680       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0204 05:23:58.864693       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0204 05:23:58.865000       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0204 05:23:58.865089       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0204 05:24:02.464610       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0204 05:24:02.465913       1 utils.go:199] ID: 1 GRPC request: {}
I0204 05:24:02.466103       1 utils.go:205] ID: 1 GRPC response: {}
I0204 05:24:02.467874       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0204 05:24:02.468055       1 utils.go:199] ID: 2 GRPC request: {}
I0204 05:24:02.468144       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0204 05:24:02.468297       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0204 05:24:02.469824       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0204 05:24:02.469881       1 utils.go:199] ID: 3 GRPC request: {}
I0204 05:24:02.469912       1 utils.go:205] ID: 3 GRPC response: {}
I0204 05:24:02.470548       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0204 05:24:02.470642       1 utils.go:199] ID: 4 GRPC request: {}
I0204 05:24:02.470860       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0204 05:24:02.472412       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0204 05:24:02.472498       1 utils.go:199] ID: 5 GRPC request: {}
I0204 05:24:02.472548       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0204 05:24:02.472718       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}}}]}
I0204 05:24:04.536470       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0204 05:24:04.536501       1 utils.go:199] ID: 6 GRPC request: {}
I0204 05:24:04.536516       1 utils.go:205] ID: 6 GRPC response: {}
I0204 05:24:04.539187       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0204 05:24:04.539204       1 utils.go:199] ID: 7 GRPC request: {}
I0204 05:24:04.539210       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0204 05:24:04.539232       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0204 05:24:04.543074       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0204 05:24:04.543088       1 utils.go:199] ID: 8 GRPC request: {}
I0204 05:24:04.543097       1 utils.go:205] ID: 8 GRPC response: {}
I0204 05:24:04.544994       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0204 05:24:04.545008       1 utils.go:199] ID: 9 GRPC request: {}
I0204 05:24:04.545071       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0204 05:24:04.545606       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0204 05:24:04.545617       1 utils.go:199] ID: 10 GRPC request: {}
I0204 05:24:04.545623       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0204 05:24:04.545707       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}}}]}
I0204 05:24:04.545992       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0204 05:24:04.546001       1 utils.go:199] ID: 11 GRPC request: {}
I0204 05:24:04.546005       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0204 05:24:04.546047       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}}}]}
I0204 05:24:04.546241       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0204 05:24:04.546250       1 utils.go:199] ID: 12 GRPC request: {}
I0204 05:24:04.546254       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0204 05:24:04.546294       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}}}]}
I0204 05:24:08.785224       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0204 05:24:08.785328       1 utils.go:199] ID: 13 GRPC request: {}
I0204 05:24:08.785391       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0204 05:24:08.785486       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0204 05:24:08.787291       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0204 05:24:08.787345       1 utils.go:199] ID: 14 GRPC request: {}
I0204 05:24:08.787369       1 utils.go:205] ID: 14 GRPC response: {}
I0204 05:24:08.787623       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0204 05:24:08.787673       1 utils.go:199] ID: 15 GRPC request: {}
I0204 05:24:08.787729       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0204 05:24:08.787857       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}}}]}
I0204 05:24:15.174215       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0204 05:24:15.174364       1 utils.go:199] ID: 16 GRPC request: {}
I0204 05:24:15.174379       1 utils.go:205] ID: 16 GRPC response: {}
I0204 05:24:15.203708       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0204 05:24:15.203743       1 utils.go:199] ID: 17 GRPC request: {}
I0204 05:24:15.203749       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0204 05:24:15.203773       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0204 05:24:15.208551       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0204 05:24:15.208565       1 utils.go:199] ID: 18 GRPC request: {}
I0204 05:24:15.208575       1 utils.go:205] ID: 18 GRPC response: {}
I0204 05:24:15.208803       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0204 05:24:15.208813       1 utils.go:199] ID: 19 GRPC request: {}
I0204 05:24:15.208907       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0204 05:24:15.212261       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0204 05:24:15.212283       1 utils.go:199] ID: 20 GRPC request: {}
I0204 05:24:15.212289       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0204 05:24:15.212359       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}}}]}
I0204 05:25:15.449421       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0204 05:25:15.449498       1 utils.go:199] ID: 21 GRPC request: {}
I0204 05:25:15.449787       1 utils.go:205] ID: 21 GRPC response: {}
I0204 05:26:15.453559       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0204 05:26:15.453744       1 utils.go:199] ID: 22 GRPC request: {}
I0204 05:26:15.453825       1 utils.go:205] ID: 22 GRPC response: {}
I0204 05:27:08.669523       1 utils.go:198] ID: 23 Req-ID: pvc-572d3f3e-e3f7-4462-8c55-3f7269de3f86 GRPC call: /csi.v1.Controller/CreateVolume
I0204 05:27:08.669899       1 utils.go:199] ID: 23 Req-ID: pvc-572d3f3e-e3f7-4462-8c55-3f7269de3f86 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-572d3f3e-e3f7-4462-8c55-3f7269de3f86","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-572d3f3e-e3f7-4462-8c55-3f7269de3f86","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}}]}
I0204 05:27:08.670178       1 rbd_util.go:1315] ID: 23 Req-ID: pvc-572d3f3e-e3f7-4462-8c55-3f7269de3f86 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0204 05:27:08.685227       1 omap.go:80] ID: 23 Req-ID: pvc-572d3f3e-e3f7-4462-8c55-3f7269de3f86 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0204 05:27:08.706285       1 omap.go:159] ID: 23 Req-ID: pvc-572d3f3e-e3f7-4462-8c55-3f7269de3f86 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-572d3f3e-e3f7-4462-8c55-3f7269de3f86:855829f2-c7c6-41bc-9c6e-4dcb51f5ebe2])
I0204 05:27:08.715327       1 omap.go:159] ID: 23 Req-ID: pvc-572d3f3e-e3f7-4462-8c55-3f7269de3f86 set omap keys (pool="kube", namespace="", name="csi.volume.855829f2-c7c6-41bc-9c6e-4dcb51f5ebe2"): map[csi.imagename:csi-vol-855829f2-c7c6-41bc-9c6e-4dcb51f5ebe2 csi.volname:pvc-572d3f3e-e3f7-4462-8c55-3f7269de3f86 csi.volume.owner:default])
I0204 05:27:08.715357       1 rbd_journal.go:491] ID: 23 Req-ID: pvc-572d3f3e-e3f7-4462-8c55-3f7269de3f86 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-855829f2-c7c6-41bc-9c6e-4dcb51f5ebe2) and image name (csi-vol-855829f2-c7c6-41bc-9c6e-4dcb51f5ebe2) for request name (pvc-572d3f3e-e3f7-4462-8c55-3f7269de3f86)
I0204 05:27:08.715435       1 rbd_util.go:423] ID: 23 Req-ID: pvc-572d3f3e-e3f7-4462-8c55-3f7269de3f86 rbd: create kube/csi-vol-855829f2-c7c6-41bc-9c6e-4dcb51f5ebe2 size 5120M (features: [layering]) using mon 199.204.45.238
I0204 05:27:08.715490       1 rbd_util.go:1563] ID: 23 Req-ID: pvc-572d3f3e-e3f7-4462-8c55-3f7269de3f86 setting image options on kube/csi-vol-855829f2-c7c6-41bc-9c6e-4dcb51f5ebe2
I0204 05:27:10.844901       1 controllerserver.go:763] ID: 23 Req-ID: pvc-572d3f3e-e3f7-4462-8c55-3f7269de3f86 created image kube/csi-vol-855829f2-c7c6-41bc-9c6e-4dcb51f5ebe2 backed for request name pvc-572d3f3e-e3f7-4462-8c55-3f7269de3f86
I0204 05:27:10.886472       1 omap.go:159] ID: 23 Req-ID: pvc-572d3f3e-e3f7-4462-8c55-3f7269de3f86 set omap keys (pool="kube", namespace="", name="csi.volume.855829f2-c7c6-41bc-9c6e-4dcb51f5ebe2"): map[csi.imageid:37d769feee7c])
I0204 05:27:10.986486       1 utils.go:205] ID: 23 Req-ID: pvc-572d3f3e-e3f7-4462-8c55-3f7269de3f86 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-855829f2-c7c6-41bc-9c6e-4dcb51f5ebe2","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-855829f2-c7c6-41bc-9c6e-4dcb51f5ebe2"}}
I0204 05:27:15.448665       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0204 05:27:15.448805       1 utils.go:199] ID: 24 GRPC request: {}
I0204 05:27:15.448934       1 utils.go:205] ID: 24 GRPC response: {}