I0419 16:18:36.379112       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0419 16:18:36.379258       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0419 16:18:36.379278       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0419 16:18:36.379282       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0419 16:18:36.379286       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0419 16:18:36.379289       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0419 16:18:36.379294       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0419 16:18:36.379298       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0419 16:18:36.379301       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0419 16:18:36.379304       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0419 16:18:36.379647       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0419 16:18:36.379678       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0419 16:18:38.860389       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0419 16:18:38.861635       1 utils.go:199] ID: 1 GRPC request: {}
I0419 16:18:38.861696       1 utils.go:205] ID: 1 GRPC response: {}
I0419 16:18:38.865548       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0419 16:18:38.865592       1 utils.go:199] ID: 2 GRPC request: {}
I0419 16:18:38.865607       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0419 16:18:38.865664       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0419 16:18:38.867530       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0419 16:18:38.867584       1 utils.go:199] ID: 3 GRPC request: {}
I0419 16:18:38.867605       1 utils.go:205] ID: 3 GRPC response: {}
I0419 16:18:38.868304       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0419 16:18:38.868433       1 utils.go:199] ID: 4 GRPC request: {}
I0419 16:18:38.868603       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0419 16:18:38.869557       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0419 16:18:38.869651       1 utils.go:199] ID: 5 GRPC request: {}
I0419 16:18:38.869666       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0419 16:18:38.869827       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}}}]}
I0419 16:18:40.158335       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0419 16:18:40.158384       1 utils.go:199] ID: 6 GRPC request: {}
I0419 16:18:40.158490       1 utils.go:205] ID: 6 GRPC response: {}
I0419 16:18:40.162522       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0419 16:18:40.162543       1 utils.go:199] ID: 7 GRPC request: {}
I0419 16:18:40.162656       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0419 16:18:40.162748       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0419 16:18:40.164656       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0419 16:18:40.164734       1 utils.go:199] ID: 8 GRPC request: {}
I0419 16:18:40.164765       1 utils.go:205] ID: 8 GRPC response: {}
I0419 16:18:40.165877       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0419 16:18:40.166065       1 utils.go:199] ID: 9 GRPC request: {}
I0419 16:18:40.166359       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0419 16:18:40.167563       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0419 16:18:40.167594       1 utils.go:199] ID: 10 GRPC request: {}
I0419 16:18:40.167713       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0419 16:18:40.167981       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}}}]}
I0419 16:18:40.168891       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0419 16:18:40.168927       1 utils.go:199] ID: 11 GRPC request: {}
I0419 16:18:40.168964       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0419 16:18:40.169118       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}}}]}
I0419 16:18:40.169659       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0419 16:18:40.169691       1 utils.go:199] ID: 12 GRPC request: {}
I0419 16:18:40.169827       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0419 16:18:40.170010       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}}}]}
I0419 16:18:41.426573       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0419 16:18:41.426620       1 utils.go:199] ID: 13 GRPC request: {}
I0419 16:18:41.426669       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0419 16:18:41.426700       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0419 16:18:41.430900       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0419 16:18:41.430921       1 utils.go:199] ID: 14 GRPC request: {}
I0419 16:18:41.430934       1 utils.go:205] ID: 14 GRPC response: {}
I0419 16:18:41.431643       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0419 16:18:41.431712       1 utils.go:199] ID: 15 GRPC request: {}
I0419 16:18:41.431742       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0419 16:18:41.431889       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}}}]}
I0419 16:18:41.689521       1 utils.go:198] ID: 16 Req-ID: pvc-b4c9b637-59b6-4420-93c3-fba37f71dd8e GRPC call: /csi.v1.Controller/CreateVolume
I0419 16:18:41.689882       1 utils.go:199] ID: 16 Req-ID: pvc-b4c9b637-59b6-4420-93c3-fba37f71dd8e GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-b4c9b637-59b6-4420-93c3-fba37f71dd8e","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-b4c9b637-59b6-4420-93c3-fba37f71dd8e","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}}]}
I0419 16:18:41.690183       1 rbd_util.go:1315] ID: 16 Req-ID: pvc-b4c9b637-59b6-4420-93c3-fba37f71dd8e setting disableInUseChecks: false image features: [layering] mounter: rbd
E0419 16:18:41.709065       1 omap.go:80] ID: 16 Req-ID: pvc-b4c9b637-59b6-4420-93c3-fba37f71dd8e omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0419 16:18:41.725922       1 omap.go:159] ID: 16 Req-ID: pvc-b4c9b637-59b6-4420-93c3-fba37f71dd8e set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-b4c9b637-59b6-4420-93c3-fba37f71dd8e:c3e198ac-3190-444d-987d-7d29b60efd9d])
I0419 16:18:41.732023       1 omap.go:159] ID: 16 Req-ID: pvc-b4c9b637-59b6-4420-93c3-fba37f71dd8e set omap keys (pool="kube", namespace="", name="csi.volume.c3e198ac-3190-444d-987d-7d29b60efd9d"): map[csi.imagename:csi-vol-c3e198ac-3190-444d-987d-7d29b60efd9d csi.volname:pvc-b4c9b637-59b6-4420-93c3-fba37f71dd8e csi.volume.owner:default])
I0419 16:18:41.732121       1 rbd_journal.go:491] ID: 16 Req-ID: pvc-b4c9b637-59b6-4420-93c3-fba37f71dd8e generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-c3e198ac-3190-444d-987d-7d29b60efd9d) and image name (csi-vol-c3e198ac-3190-444d-987d-7d29b60efd9d) for request name (pvc-b4c9b637-59b6-4420-93c3-fba37f71dd8e)
I0419 16:18:41.732589       1 rbd_util.go:423] ID: 16 Req-ID: pvc-b4c9b637-59b6-4420-93c3-fba37f71dd8e rbd: create kube/csi-vol-c3e198ac-3190-444d-987d-7d29b60efd9d size 5120M (features: [layering]) using mon 199.204.45.53
I0419 16:18:41.732664       1 rbd_util.go:1563] ID: 16 Req-ID: pvc-b4c9b637-59b6-4420-93c3-fba37f71dd8e setting image options on kube/csi-vol-c3e198ac-3190-444d-987d-7d29b60efd9d
I0419 16:18:43.432752       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/Probe
I0419 16:18:43.432847       1 utils.go:199] ID: 17 GRPC request: {}
I0419 16:18:43.432889       1 utils.go:205] ID: 17 GRPC response: {}
I0419 16:18:43.435920       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/GetPluginInfo
I0419 16:18:43.435977       1 utils.go:199] ID: 18 GRPC request: {}
I0419 16:18:43.435994       1 identityserver-default.go:40] ID: 18 Using default GetPluginInfo
I0419 16:18:43.436027       1 utils.go:205] ID: 18 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0419 16:18:43.439697       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/Probe
I0419 16:18:43.439768       1 utils.go:199] ID: 19 GRPC request: {}
I0419 16:18:43.439811       1 utils.go:205] ID: 19 GRPC response: {}
I0419 16:18:43.440371       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0419 16:18:43.440407       1 utils.go:199] ID: 20 GRPC request: {}
I0419 16:18:43.440607       1 utils.go:205] ID: 20 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0419 16:18:43.442516       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0419 16:18:43.442542       1 utils.go:199] ID: 21 GRPC request: {}
I0419 16:18:43.442551       1 controllerserver-default.go:42] ID: 21 Using default ControllerGetCapabilities
I0419 16:18:43.442629       1 utils.go:205] ID: 21 GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}}]}
I0419 16:18:44.212396       1 controllerserver.go:763] ID: 16 Req-ID: pvc-b4c9b637-59b6-4420-93c3-fba37f71dd8e created image kube/csi-vol-c3e198ac-3190-444d-987d-7d29b60efd9d backed for request name pvc-b4c9b637-59b6-4420-93c3-fba37f71dd8e
I0419 16:18:44.293396       1 omap.go:159] ID: 16 Req-ID: pvc-b4c9b637-59b6-4420-93c3-fba37f71dd8e set omap keys (pool="kube", namespace="", name="csi.volume.c3e198ac-3190-444d-987d-7d29b60efd9d"): map[csi.imageid:37b5610e6250])
I0419 16:18:44.382778       1 utils.go:205] ID: 16 Req-ID: pvc-b4c9b637-59b6-4420-93c3-fba37f71dd8e GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-c3e198ac-3190-444d-987d-7d29b60efd9d","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-c3e198ac-3190-444d-987d-7d29b60efd9d"}}