I0505 11:25:16.385052       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0505 11:25:16.385314       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0505 11:25:16.385333       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0505 11:25:16.385338       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0505 11:25:16.385342       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0505 11:25:16.385347       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0505 11:25:16.385353       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0505 11:25:16.385358       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0505 11:25:16.385362       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0505 11:25:16.385366       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0505 11:25:16.386071       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0505 11:25:16.386107       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0505 11:25:37.440618       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0505 11:25:37.443273       1 utils.go:199] ID: 1 GRPC request: {}
I0505 11:25:37.443373       1 utils.go:205] ID: 1 GRPC response: {}
I0505 11:25:37.445975       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0505 11:25:37.446081       1 utils.go:199] ID: 2 GRPC request: {}
I0505 11:25:37.446113       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0505 11:25:37.446234       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0505 11:25:37.448619       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0505 11:25:37.448664       1 utils.go:199] ID: 3 GRPC request: {}
I0505 11:25:37.448682       1 utils.go:205] ID: 3 GRPC response: {}
I0505 11:25:37.449133       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0505 11:25:37.449178       1 utils.go:199] ID: 4 GRPC request: {}
I0505 11:25:37.449398       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0505 11:25:37.450721       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0505 11:25:37.450784       1 utils.go:199] ID: 5 GRPC request: {}
I0505 11:25:37.450798       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0505 11:25:37.450975       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}}}]}
I0505 11:25:42.822674       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0505 11:25:42.822719       1 utils.go:199] ID: 6 GRPC request: {}
I0505 11:25:42.822739       1 utils.go:205] ID: 6 GRPC response: {}
I0505 11:25:42.827516       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0505 11:25:42.827561       1 utils.go:199] ID: 7 GRPC request: {}
I0505 11:25:42.827573       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0505 11:25:42.827604       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0505 11:25:42.830203       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0505 11:25:42.830222       1 utils.go:199] ID: 8 GRPC request: {}
I0505 11:25:42.830238       1 utils.go:205] ID: 8 GRPC response: {}
I0505 11:25:42.830785       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0505 11:25:42.830812       1 utils.go:199] ID: 9 GRPC request: {}
I0505 11:25:42.831406       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0505 11:25:42.832065       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0505 11:25:42.832087       1 utils.go:199] ID: 10 GRPC request: {}
I0505 11:25:42.832095       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0505 11:25:42.832212       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}}}]}
I0505 11:25:42.832682       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0505 11:25:42.832699       1 utils.go:199] ID: 11 GRPC request: {}
I0505 11:25:42.832704       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0505 11:25:42.832787       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}}}]}
I0505 11:25:42.833169       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0505 11:25:42.833187       1 utils.go:199] ID: 12 GRPC request: {}
I0505 11:25:42.833193       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0505 11:25:42.833352       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}}}]}
I0505 11:25:47.743906       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0505 11:25:47.743949       1 utils.go:199] ID: 13 GRPC request: {}
I0505 11:25:47.743956       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0505 11:25:47.743986       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0505 11:25:47.746015       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0505 11:25:47.746034       1 utils.go:199] ID: 14 GRPC request: {}
I0505 11:25:47.746062       1 utils.go:205] ID: 14 GRPC response: {}
I0505 11:25:47.746432       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0505 11:25:47.746445       1 utils.go:199] ID: 15 GRPC request: {}
I0505 11:25:47.746450       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0505 11:25:47.746524       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}}}]}
I0505 11:25:50.956067       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0505 11:25:50.956165       1 utils.go:199] ID: 16 GRPC request: {}
I0505 11:25:50.956217       1 utils.go:205] ID: 16 GRPC response: {}
I0505 11:25:50.960463       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0505 11:25:50.960489       1 utils.go:199] ID: 17 GRPC request: {}
I0505 11:25:50.960505       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0505 11:25:50.960533       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0505 11:25:50.964628       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0505 11:25:50.964648       1 utils.go:199] ID: 18 GRPC request: {}
I0505 11:25:50.964661       1 utils.go:205] ID: 18 GRPC response: {}
I0505 11:25:50.965603       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0505 11:25:50.965645       1 utils.go:199] ID: 19 GRPC request: {}
I0505 11:25:50.965791       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0505 11:25:50.966655       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0505 11:25:50.966680       1 utils.go:199] ID: 20 GRPC request: {}
I0505 11:25:50.966689       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0505 11:25:50.966847       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}}}]}
I0505 11:26:51.225173       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0505 11:26:51.225399       1 utils.go:199] ID: 21 GRPC request: {}
I0505 11:26:51.225566       1 utils.go:205] ID: 21 GRPC response: {}
I0505 11:27:51.181999       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0505 11:27:51.182137       1 utils.go:199] ID: 22 GRPC request: {}
I0505 11:27:51.183417       1 utils.go:205] ID: 22 GRPC response: {}
I0505 11:28:51.211416       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0505 11:28:51.211513       1 utils.go:199] ID: 23 GRPC request: {}
I0505 11:28:51.211749       1 utils.go:205] ID: 23 GRPC response: {}
I0505 11:28:56.029827       1 utils.go:198] ID: 24 Req-ID: pvc-49f8912a-0fab-47a9-b899-18c719994c13 GRPC call: /csi.v1.Controller/CreateVolume
I0505 11:28:56.030435       1 utils.go:199] ID: 24 Req-ID: pvc-49f8912a-0fab-47a9-b899-18c719994c13 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-49f8912a-0fab-47a9-b899-18c719994c13","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-49f8912a-0fab-47a9-b899-18c719994c13","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}}]}
I0505 11:28:56.030849       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-49f8912a-0fab-47a9-b899-18c719994c13 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0505 11:28:56.052002       1 omap.go:80] ID: 24 Req-ID: pvc-49f8912a-0fab-47a9-b899-18c719994c13 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0505 11:28:56.069691       1 omap.go:159] ID: 24 Req-ID: pvc-49f8912a-0fab-47a9-b899-18c719994c13 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-49f8912a-0fab-47a9-b899-18c719994c13:aa1cd7f9-e69d-4e2b-88ae-10b79cad3840])
I0505 11:28:56.076670       1 omap.go:159] ID: 24 Req-ID: pvc-49f8912a-0fab-47a9-b899-18c719994c13 set omap keys (pool="kube", namespace="", name="csi.volume.aa1cd7f9-e69d-4e2b-88ae-10b79cad3840"): map[csi.imagename:csi-vol-aa1cd7f9-e69d-4e2b-88ae-10b79cad3840 csi.volname:pvc-49f8912a-0fab-47a9-b899-18c719994c13 csi.volume.owner:default])
I0505 11:28:56.076728       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-49f8912a-0fab-47a9-b899-18c719994c13 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-aa1cd7f9-e69d-4e2b-88ae-10b79cad3840) and image name (csi-vol-aa1cd7f9-e69d-4e2b-88ae-10b79cad3840) for request name (pvc-49f8912a-0fab-47a9-b899-18c719994c13)
I0505 11:28:56.076841       1 rbd_util.go:423] ID: 24 Req-ID: pvc-49f8912a-0fab-47a9-b899-18c719994c13 rbd: create kube/csi-vol-aa1cd7f9-e69d-4e2b-88ae-10b79cad3840 size 5120M (features: [layering]) using mon 199.19.213.121
I0505 11:28:56.076908       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-49f8912a-0fab-47a9-b899-18c719994c13 setting image options on kube/csi-vol-aa1cd7f9-e69d-4e2b-88ae-10b79cad3840
I0505 11:28:58.052625       1 controllerserver.go:763] ID: 24 Req-ID: pvc-49f8912a-0fab-47a9-b899-18c719994c13 created image kube/csi-vol-aa1cd7f9-e69d-4e2b-88ae-10b79cad3840 backed for request name pvc-49f8912a-0fab-47a9-b899-18c719994c13
I0505 11:28:58.086883       1 omap.go:159] ID: 24 Req-ID: pvc-49f8912a-0fab-47a9-b899-18c719994c13 set omap keys (pool="kube", namespace="", name="csi.volume.aa1cd7f9-e69d-4e2b-88ae-10b79cad3840"): map[csi.imageid:37d7e9027f4b])
I0505 11:28:58.187136       1 utils.go:205] ID: 24 Req-ID: pvc-49f8912a-0fab-47a9-b899-18c719994c13 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-aa1cd7f9-e69d-4e2b-88ae-10b79cad3840","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-aa1cd7f9-e69d-4e2b-88ae-10b79cad3840"}}
I0505 11:29:51.190603       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0505 11:29:51.190691       1 utils.go:199] ID: 25 GRPC request: {}
I0505 11:29:51.190740       1 utils.go:205] ID: 25 GRPC response: {}