I0726 15:56:44.214112       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0726 15:56:44.214222       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0726 15:56:44.214234       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0726 15:56:44.214238       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0726 15:56:44.214241       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0726 15:56:44.214255       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0726 15:56:44.214259       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0726 15:56:44.214262       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0726 15:56:44.214268       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0726 15:56:44.214271       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0726 15:56:44.214731       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0726 15:56:44.214803       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0726 15:56:54.287807       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0726 15:56:54.289161       1 utils.go:199] ID: 1 GRPC request: {}
I0726 15:56:54.289268       1 utils.go:205] ID: 1 GRPC response: {}
I0726 15:56:54.291420       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0726 15:56:54.291492       1 utils.go:199] ID: 2 GRPC request: {}
I0726 15:56:54.291513       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0726 15:56:54.291585       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0726 15:56:54.293254       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0726 15:56:54.293295       1 utils.go:199] ID: 3 GRPC request: {}
I0726 15:56:54.293312       1 utils.go:205] ID: 3 GRPC response: {}
I0726 15:56:54.294342       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0726 15:56:54.294401       1 utils.go:199] ID: 4 GRPC request: {}
I0726 15:56:54.294640       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0726 15:56:54.296501       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0726 15:56:54.296632       1 utils.go:199] ID: 5 GRPC request: {}
I0726 15:56:54.296661       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0726 15:56:54.296890       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}}}]}
I0726 15:56:57.465941       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0726 15:56:57.465976       1 utils.go:199] ID: 6 GRPC request: {}
I0726 15:56:57.465992       1 utils.go:205] ID: 6 GRPC response: {}
I0726 15:56:57.467882       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0726 15:56:57.467964       1 utils.go:199] ID: 7 GRPC request: {}
I0726 15:56:57.467979       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0726 15:56:57.468033       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0726 15:56:57.471075       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0726 15:56:57.471132       1 utils.go:199] ID: 8 GRPC request: {}
I0726 15:56:57.471157       1 utils.go:205] ID: 8 GRPC response: {}
I0726 15:56:57.471774       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0726 15:56:57.471892       1 utils.go:199] ID: 9 GRPC request: {}
I0726 15:56:57.472143       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0726 15:56:57.472894       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0726 15:56:57.473004       1 utils.go:199] ID: 10 GRPC request: {}
I0726 15:56:57.473087       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0726 15:56:57.473280       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}}}]}
I0726 15:56:57.473937       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0726 15:56:57.473968       1 utils.go:199] ID: 11 GRPC request: {}
I0726 15:56:57.473977       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0726 15:56:57.474064       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}}}]}
I0726 15:56:57.474530       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0726 15:56:57.474910       1 utils.go:199] ID: 12 GRPC request: {}
I0726 15:56:57.474965       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0726 15:56:57.475089       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}}}]}
I0726 15:56:59.046673       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0726 15:56:59.046710       1 utils.go:199] ID: 13 GRPC request: {}
I0726 15:56:59.046719       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0726 15:56:59.046746       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0726 15:56:59.049020       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0726 15:56:59.049095       1 utils.go:199] ID: 14 GRPC request: {}
I0726 15:56:59.049120       1 utils.go:205] ID: 14 GRPC response: {}
I0726 15:56:59.049666       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0726 15:56:59.049682       1 utils.go:199] ID: 15 GRPC request: {}
I0726 15:56:59.049689       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0726 15:56:59.049761       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}}}]}
I0726 15:57:00.769792       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0726 15:57:00.769828       1 utils.go:199] ID: 16 GRPC request: {}
I0726 15:57:00.769846       1 utils.go:205] ID: 16 GRPC response: {}
I0726 15:57:00.772965       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0726 15:57:00.772983       1 utils.go:199] ID: 17 GRPC request: {}
I0726 15:57:00.772990       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0726 15:57:00.773007       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0726 15:57:00.775820       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0726 15:57:00.775852       1 utils.go:199] ID: 18 GRPC request: {}
I0726 15:57:00.775870       1 utils.go:205] ID: 18 GRPC response: {}
I0726 15:57:00.776211       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0726 15:57:00.776238       1 utils.go:199] ID: 19 GRPC request: {}
I0726 15:57:00.776345       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0726 15:57:00.776928       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0726 15:57:00.776956       1 utils.go:199] ID: 20 GRPC request: {}
I0726 15:57:00.776966       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0726 15:57:00.777067       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}}}]}
I0726 15:58:00.993386       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0726 15:58:00.993582       1 utils.go:199] ID: 21 GRPC request: {}
I0726 15:58:00.993674       1 utils.go:205] ID: 21 GRPC response: {}
I0726 15:59:00.993431       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0726 15:59:00.993480       1 utils.go:199] ID: 22 GRPC request: {}
I0726 15:59:00.993501       1 utils.go:205] ID: 22 GRPC response: {}
I0726 16:00:00.992954       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0726 16:00:00.992991       1 utils.go:199] ID: 23 GRPC request: {}
I0726 16:00:00.993005       1 utils.go:205] ID: 23 GRPC response: {}
I0726 16:01:01.003500       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0726 16:01:01.003547       1 utils.go:199] ID: 24 GRPC request: {}
I0726 16:01:01.003568       1 utils.go:205] ID: 24 GRPC response: {}
I0726 16:02:00.993444       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0726 16:02:00.993512       1 utils.go:199] ID: 25 GRPC request: {}
I0726 16:02:00.993536       1 utils.go:205] ID: 25 GRPC response: {}
I0726 16:02:07.020449       1 utils.go:198] ID: 26 Req-ID: pvc-76fed4c6-7d58-4c12-ac1b-2e0aa4502236 GRPC call: /csi.v1.Controller/CreateVolume
I0726 16:02:07.020783       1 utils.go:199] ID: 26 Req-ID: pvc-76fed4c6-7d58-4c12-ac1b-2e0aa4502236 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-76fed4c6-7d58-4c12-ac1b-2e0aa4502236","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-76fed4c6-7d58-4c12-ac1b-2e0aa4502236","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}}]}
I0726 16:02:07.021756       1 rbd_util.go:1315] ID: 26 Req-ID: pvc-76fed4c6-7d58-4c12-ac1b-2e0aa4502236 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0726 16:02:07.043437       1 omap.go:80] ID: 26 Req-ID: pvc-76fed4c6-7d58-4c12-ac1b-2e0aa4502236 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0726 16:02:07.068878       1 omap.go:159] ID: 26 Req-ID: pvc-76fed4c6-7d58-4c12-ac1b-2e0aa4502236 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-76fed4c6-7d58-4c12-ac1b-2e0aa4502236:f6e8a2f5-5f47-4bb7-aeb0-cdd607bb8528])
I0726 16:02:07.076176       1 omap.go:159] ID: 26 Req-ID: pvc-76fed4c6-7d58-4c12-ac1b-2e0aa4502236 set omap keys (pool="kube", namespace="", name="csi.volume.f6e8a2f5-5f47-4bb7-aeb0-cdd607bb8528"): map[csi.imagename:csi-vol-f6e8a2f5-5f47-4bb7-aeb0-cdd607bb8528 csi.volname:pvc-76fed4c6-7d58-4c12-ac1b-2e0aa4502236 csi.volume.owner:default])
I0726 16:02:07.076249       1 rbd_journal.go:491] ID: 26 Req-ID: pvc-76fed4c6-7d58-4c12-ac1b-2e0aa4502236 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-f6e8a2f5-5f47-4bb7-aeb0-cdd607bb8528) and image name (csi-vol-f6e8a2f5-5f47-4bb7-aeb0-cdd607bb8528) for request name (pvc-76fed4c6-7d58-4c12-ac1b-2e0aa4502236)
I0726 16:02:07.076362       1 rbd_util.go:423] ID: 26 Req-ID: pvc-76fed4c6-7d58-4c12-ac1b-2e0aa4502236 rbd: create kube/csi-vol-f6e8a2f5-5f47-4bb7-aeb0-cdd607bb8528 size 5120M (features: [layering]) using mon 199.204.45.223
I0726 16:02:07.076457       1 rbd_util.go:1563] ID: 26 Req-ID: pvc-76fed4c6-7d58-4c12-ac1b-2e0aa4502236 setting image options on kube/csi-vol-f6e8a2f5-5f47-4bb7-aeb0-cdd607bb8528
I0726 16:02:07.115350       1 controllerserver.go:763] ID: 26 Req-ID: pvc-76fed4c6-7d58-4c12-ac1b-2e0aa4502236 created image kube/csi-vol-f6e8a2f5-5f47-4bb7-aeb0-cdd607bb8528 backed for request name pvc-76fed4c6-7d58-4c12-ac1b-2e0aa4502236
I0726 16:02:07.148665       1 omap.go:159] ID: 26 Req-ID: pvc-76fed4c6-7d58-4c12-ac1b-2e0aa4502236 set omap keys (pool="kube", namespace="", name="csi.volume.f6e8a2f5-5f47-4bb7-aeb0-cdd607bb8528"): map[csi.imageid:37f4ef0ed183])
I0726 16:02:07.236881       1 utils.go:205] ID: 26 Req-ID: pvc-76fed4c6-7d58-4c12-ac1b-2e0aa4502236 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-f6e8a2f5-5f47-4bb7-aeb0-cdd607bb8528","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-f6e8a2f5-5f47-4bb7-aeb0-cdd607bb8528"}}
I0726 16:03:01.014381       1 utils.go:198] ID: 27 GRPC call: /csi.v1.Identity/Probe
I0726 16:03:01.014415       1 utils.go:199] ID: 27 GRPC request: {}
I0726 16:03:01.014428       1 utils.go:205] ID: 27 GRPC response: {}