I0412 20:49:24.233225       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0412 20:49:24.233336       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0412 20:49:24.233352       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0412 20:49:24.233356       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0412 20:49:24.233360       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0412 20:49:24.233363       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0412 20:49:24.233368       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0412 20:49:24.233370       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0412 20:49:24.233373       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0412 20:49:24.233377       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0412 20:49:24.233616       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0412 20:49:24.233673       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0412 20:49:26.107428       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0412 20:49:26.108701       1 utils.go:199] ID: 1 GRPC request: {}
I0412 20:49:26.108781       1 utils.go:205] ID: 1 GRPC response: {}
I0412 20:49:26.110821       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0412 20:49:26.110988       1 utils.go:199] ID: 2 GRPC request: {}
I0412 20:49:26.111032       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0412 20:49:26.111134       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0412 20:49:26.112830       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0412 20:49:26.112866       1 utils.go:199] ID: 3 GRPC request: {}
I0412 20:49:26.112899       1 utils.go:205] ID: 3 GRPC response: {}
I0412 20:49:26.113502       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0412 20:49:26.113623       1 utils.go:199] ID: 4 GRPC request: {}
I0412 20:49:26.113824       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0412 20:49:26.115203       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0412 20:49:26.115294       1 utils.go:199] ID: 5 GRPC request: {}
I0412 20:49:26.115317       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0412 20:49:26.115558       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}}}]}
I0412 20:49:28.150524       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0412 20:49:28.150557       1 utils.go:199] ID: 6 GRPC request: {}
I0412 20:49:28.150572       1 utils.go:205] ID: 6 GRPC response: {}
I0412 20:49:28.153928       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0412 20:49:28.153977       1 utils.go:199] ID: 7 GRPC request: {}
I0412 20:49:28.153989       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0412 20:49:28.154154       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0412 20:49:28.156307       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0412 20:49:28.156391       1 utils.go:199] ID: 8 GRPC request: {}
I0412 20:49:28.156440       1 utils.go:205] ID: 8 GRPC response: {}
I0412 20:49:28.157012       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0412 20:49:28.157071       1 utils.go:199] ID: 9 GRPC request: {}
I0412 20:49:28.157195       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0412 20:49:28.157887       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0412 20:49:28.157913       1 utils.go:199] ID: 10 GRPC request: {}
I0412 20:49:28.157922       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0412 20:49:28.158009       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}}}]}
I0412 20:49:28.158364       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0412 20:49:28.158409       1 utils.go:199] ID: 11 GRPC request: {}
I0412 20:49:28.158438       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0412 20:49:28.158533       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}}}]}
I0412 20:49:28.158775       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0412 20:49:28.158793       1 utils.go:199] ID: 12 GRPC request: {}
I0412 20:49:28.158799       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0412 20:49:28.158859       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}}}]}
I0412 20:49:29.447558       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0412 20:49:29.447594       1 utils.go:199] ID: 13 GRPC request: {}
I0412 20:49:29.447604       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0412 20:49:29.447626       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0412 20:49:29.450958       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0412 20:49:29.451026       1 utils.go:199] ID: 14 GRPC request: {}
I0412 20:49:29.451063       1 utils.go:205] ID: 14 GRPC response: {}
I0412 20:49:29.451456       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0412 20:49:29.451509       1 utils.go:199] ID: 15 GRPC request: {}
I0412 20:49:29.451533       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0412 20:49:29.451629       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}}}]}
I0412 20:49:30.623236       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0412 20:49:30.623320       1 utils.go:199] ID: 16 GRPC request: {}
I0412 20:49:30.623452       1 utils.go:205] ID: 16 GRPC response: {}
I0412 20:49:30.625692       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0412 20:49:30.625712       1 utils.go:199] ID: 17 GRPC request: {}
I0412 20:49:30.625720       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0412 20:49:30.625823       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0412 20:49:30.629022       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0412 20:49:30.629056       1 utils.go:199] ID: 18 GRPC request: {}
I0412 20:49:30.629074       1 utils.go:205] ID: 18 GRPC response: {}
I0412 20:49:30.631789       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0412 20:49:30.631957       1 utils.go:199] ID: 19 GRPC request: {}
I0412 20:49:30.632150       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0412 20:49:30.632894       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0412 20:49:30.632956       1 utils.go:199] ID: 20 GRPC request: {}
I0412 20:49:30.632982       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0412 20:49:30.633076       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}}}]}
I0412 20:50:30.855176       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0412 20:50:30.855328       1 utils.go:199] ID: 21 GRPC request: {}
I0412 20:50:30.855403       1 utils.go:205] ID: 21 GRPC response: {}
I0412 20:51:30.801934       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0412 20:51:30.802001       1 utils.go:199] ID: 22 GRPC request: {}
I0412 20:51:30.802050       1 utils.go:205] ID: 22 GRPC response: {}
I0412 20:52:30.853205       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0412 20:52:30.853263       1 utils.go:199] ID: 23 GRPC request: {}
I0412 20:52:30.853285       1 utils.go:205] ID: 23 GRPC response: {}
I0412 20:52:37.881757       1 utils.go:198] ID: 24 Req-ID: pvc-9089eb47-9e36-4755-a9af-bcd339cf319d GRPC call: /csi.v1.Controller/CreateVolume
I0412 20:52:37.882314       1 utils.go:199] ID: 24 Req-ID: pvc-9089eb47-9e36-4755-a9af-bcd339cf319d GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-9089eb47-9e36-4755-a9af-bcd339cf319d","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-9089eb47-9e36-4755-a9af-bcd339cf319d","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}}]}
I0412 20:52:37.882692       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-9089eb47-9e36-4755-a9af-bcd339cf319d setting disableInUseChecks: false image features: [layering] mounter: rbd
E0412 20:52:37.904074       1 omap.go:80] ID: 24 Req-ID: pvc-9089eb47-9e36-4755-a9af-bcd339cf319d omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0412 20:52:37.917451       1 omap.go:159] ID: 24 Req-ID: pvc-9089eb47-9e36-4755-a9af-bcd339cf319d set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-9089eb47-9e36-4755-a9af-bcd339cf319d:c5d8c035-c814-4277-b500-cf6c8bc6ff5b])
I0412 20:52:37.924811       1 omap.go:159] ID: 24 Req-ID: pvc-9089eb47-9e36-4755-a9af-bcd339cf319d set omap keys (pool="kube", namespace="", name="csi.volume.c5d8c035-c814-4277-b500-cf6c8bc6ff5b"): map[csi.imagename:csi-vol-c5d8c035-c814-4277-b500-cf6c8bc6ff5b csi.volname:pvc-9089eb47-9e36-4755-a9af-bcd339cf319d csi.volume.owner:default])
I0412 20:52:37.924847       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-9089eb47-9e36-4755-a9af-bcd339cf319d generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-c5d8c035-c814-4277-b500-cf6c8bc6ff5b) and image name (csi-vol-c5d8c035-c814-4277-b500-cf6c8bc6ff5b) for request name (pvc-9089eb47-9e36-4755-a9af-bcd339cf319d)
I0412 20:52:37.924915       1 rbd_util.go:423] ID: 24 Req-ID: pvc-9089eb47-9e36-4755-a9af-bcd339cf319d rbd: create kube/csi-vol-c5d8c035-c814-4277-b500-cf6c8bc6ff5b size 5120M (features: [layering]) using mon 199.204.45.25
I0412 20:52:37.924973       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-9089eb47-9e36-4755-a9af-bcd339cf319d setting image options on kube/csi-vol-c5d8c035-c814-4277-b500-cf6c8bc6ff5b
I0412 20:52:39.204963       1 controllerserver.go:763] ID: 24 Req-ID: pvc-9089eb47-9e36-4755-a9af-bcd339cf319d created image kube/csi-vol-c5d8c035-c814-4277-b500-cf6c8bc6ff5b backed for request name pvc-9089eb47-9e36-4755-a9af-bcd339cf319d
I0412 20:52:39.237945       1 omap.go:159] ID: 24 Req-ID: pvc-9089eb47-9e36-4755-a9af-bcd339cf319d set omap keys (pool="kube", namespace="", name="csi.volume.c5d8c035-c814-4277-b500-cf6c8bc6ff5b"): map[csi.imageid:37d812fac7ea])
I0412 20:52:39.336827       1 utils.go:205] ID: 24 Req-ID: pvc-9089eb47-9e36-4755-a9af-bcd339cf319d GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-c5d8c035-c814-4277-b500-cf6c8bc6ff5b","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-c5d8c035-c814-4277-b500-cf6c8bc6ff5b"}}
I0412 20:53:30.811019       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0412 20:53:30.811085       1 utils.go:199] ID: 25 GRPC request: {}
I0412 20:53:30.811105       1 utils.go:205] ID: 25 GRPC response: {}