I0715 11:20:54.889559       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0715 11:20:54.889820       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0715 11:20:54.889841       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0715 11:20:54.889867       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0715 11:20:54.889878       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0715 11:20:54.889882       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0715 11:20:54.889888       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0715 11:20:54.889896       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0715 11:20:54.889900       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0715 11:20:54.889906       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0715 11:20:54.890726       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0715 11:20:54.890922       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0715 11:20:57.577216       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0715 11:20:57.581266       1 utils.go:199] ID: 1 GRPC request: {}
I0715 11:20:57.582079       1 utils.go:205] ID: 1 GRPC response: {}
I0715 11:20:57.587301       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0715 11:20:57.587439       1 utils.go:199] ID: 2 GRPC request: {}
I0715 11:20:57.587463       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0715 11:20:57.587555       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0715 11:20:57.589984       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0715 11:20:57.590051       1 utils.go:199] ID: 3 GRPC request: {}
I0715 11:20:57.590088       1 utils.go:205] ID: 3 GRPC response: {}
I0715 11:20:57.591326       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0715 11:20:57.591431       1 utils.go:199] ID: 4 GRPC request: {}
I0715 11:20:57.591642       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0715 11:20:57.593355       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0715 11:20:57.593493       1 utils.go:199] ID: 5 GRPC request: {}
I0715 11:20:57.593528       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0715 11:20:57.593700       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}}}]}
I0715 11:20:59.431193       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0715 11:20:59.431250       1 utils.go:199] ID: 6 GRPC request: {}
I0715 11:20:59.431299       1 utils.go:205] ID: 6 GRPC response: {}
I0715 11:20:59.434427       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0715 11:20:59.434450       1 utils.go:199] ID: 7 GRPC request: {}
I0715 11:20:59.434482       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0715 11:20:59.434518       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0715 11:20:59.438789       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0715 11:20:59.438855       1 utils.go:199] ID: 8 GRPC request: {}
I0715 11:20:59.438880       1 utils.go:205] ID: 8 GRPC response: {}
I0715 11:20:59.439370       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0715 11:20:59.439441       1 utils.go:199] ID: 9 GRPC request: {}
I0715 11:20:59.439655       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0715 11:20:59.440393       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0715 11:20:59.440438       1 utils.go:199] ID: 10 GRPC request: {}
I0715 11:20:59.440448       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0715 11:20:59.440579       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}}}]}
I0715 11:20:59.441323       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0715 11:20:59.441344       1 utils.go:199] ID: 11 GRPC request: {}
I0715 11:20:59.441351       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0715 11:20:59.441433       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}}}]}
I0715 11:20:59.441897       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0715 11:20:59.441982       1 utils.go:199] ID: 12 GRPC request: {}
I0715 11:20:59.442010       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0715 11:20:59.442134       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}}}]}
I0715 11:21:00.938113       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0715 11:21:00.938173       1 utils.go:199] ID: 13 GRPC request: {}
I0715 11:21:00.938189       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0715 11:21:00.938230       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0715 11:21:00.943185       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0715 11:21:00.943243       1 utils.go:199] ID: 14 GRPC request: {}
I0715 11:21:00.943264       1 utils.go:205] ID: 14 GRPC response: {}
I0715 11:21:00.943925       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0715 11:21:00.943965       1 utils.go:199] ID: 15 GRPC request: {}
I0715 11:21:00.944013       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0715 11:21:00.944197       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}}}]}
I0715 11:21:02.467028       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0715 11:21:02.467126       1 utils.go:199] ID: 16 GRPC request: {}
I0715 11:21:02.467184       1 utils.go:205] ID: 16 GRPC response: {}
I0715 11:21:02.469939       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0715 11:21:02.469993       1 utils.go:199] ID: 17 GRPC request: {}
I0715 11:21:02.470002       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0715 11:21:02.470031       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0715 11:21:02.472660       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0715 11:21:02.472684       1 utils.go:199] ID: 18 GRPC request: {}
I0715 11:21:02.472696       1 utils.go:205] ID: 18 GRPC response: {}
I0715 11:21:02.473204       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0715 11:21:02.473225       1 utils.go:199] ID: 19 GRPC request: {}
I0715 11:21:02.473334       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0715 11:21:02.474396       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0715 11:21:02.474424       1 utils.go:199] ID: 20 GRPC request: {}
I0715 11:21:02.474433       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0715 11:21:02.474539       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}}}]}
I0715 11:22:02.724988       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0715 11:22:02.725049       1 utils.go:199] ID: 21 GRPC request: {}
I0715 11:22:02.725076       1 utils.go:205] ID: 21 GRPC response: {}
I0715 11:23:02.685500       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0715 11:23:02.685620       1 utils.go:199] ID: 22 GRPC request: {}
I0715 11:23:02.685652       1 utils.go:205] ID: 22 GRPC response: {}
I0715 11:24:02.683637       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0715 11:24:02.683945       1 utils.go:199] ID: 23 GRPC request: {}
I0715 11:24:02.684038       1 utils.go:205] ID: 23 GRPC response: {}
I0715 11:25:02.694401       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0715 11:25:02.695097       1 utils.go:199] ID: 24 GRPC request: {}
I0715 11:25:02.695146       1 utils.go:205] ID: 24 GRPC response: {}
I0715 11:25:24.047852       1 utils.go:198] ID: 25 Req-ID: pvc-511617c3-f47c-4f8e-bfcc-cf727dee61a8 GRPC call: /csi.v1.Controller/CreateVolume
I0715 11:25:24.049032       1 utils.go:199] ID: 25 Req-ID: pvc-511617c3-f47c-4f8e-bfcc-cf727dee61a8 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-511617c3-f47c-4f8e-bfcc-cf727dee61a8","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-511617c3-f47c-4f8e-bfcc-cf727dee61a8","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}}]}
I0715 11:25:24.050620       1 rbd_util.go:1315] ID: 25 Req-ID: pvc-511617c3-f47c-4f8e-bfcc-cf727dee61a8 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0715 11:25:24.073982       1 omap.go:80] ID: 25 Req-ID: pvc-511617c3-f47c-4f8e-bfcc-cf727dee61a8 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0715 11:25:24.089593       1 omap.go:159] ID: 25 Req-ID: pvc-511617c3-f47c-4f8e-bfcc-cf727dee61a8 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-511617c3-f47c-4f8e-bfcc-cf727dee61a8:1efa8cec-d852-43a2-8d4d-95e59636fcaf])
I0715 11:25:24.099287       1 omap.go:159] ID: 25 Req-ID: pvc-511617c3-f47c-4f8e-bfcc-cf727dee61a8 set omap keys (pool="kube", namespace="", name="csi.volume.1efa8cec-d852-43a2-8d4d-95e59636fcaf"): map[csi.imagename:csi-vol-1efa8cec-d852-43a2-8d4d-95e59636fcaf csi.volname:pvc-511617c3-f47c-4f8e-bfcc-cf727dee61a8 csi.volume.owner:default])
I0715 11:25:24.099321       1 rbd_journal.go:491] ID: 25 Req-ID: pvc-511617c3-f47c-4f8e-bfcc-cf727dee61a8 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-1efa8cec-d852-43a2-8d4d-95e59636fcaf) and image name (csi-vol-1efa8cec-d852-43a2-8d4d-95e59636fcaf) for request name (pvc-511617c3-f47c-4f8e-bfcc-cf727dee61a8)
I0715 11:25:24.099540       1 rbd_util.go:423] ID: 25 Req-ID: pvc-511617c3-f47c-4f8e-bfcc-cf727dee61a8 rbd: create kube/csi-vol-1efa8cec-d852-43a2-8d4d-95e59636fcaf size 5120M (features: [layering]) using mon 199.204.45.210
I0715 11:25:24.099602       1 rbd_util.go:1563] ID: 25 Req-ID: pvc-511617c3-f47c-4f8e-bfcc-cf727dee61a8 setting image options on kube/csi-vol-1efa8cec-d852-43a2-8d4d-95e59636fcaf
I0715 11:25:24.134167       1 controllerserver.go:763] ID: 25 Req-ID: pvc-511617c3-f47c-4f8e-bfcc-cf727dee61a8 created image kube/csi-vol-1efa8cec-d852-43a2-8d4d-95e59636fcaf backed for request name pvc-511617c3-f47c-4f8e-bfcc-cf727dee61a8
I0715 11:25:24.169247       1 omap.go:159] ID: 25 Req-ID: pvc-511617c3-f47c-4f8e-bfcc-cf727dee61a8 set omap keys (pool="kube", namespace="", name="csi.volume.1efa8cec-d852-43a2-8d4d-95e59636fcaf"): map[csi.imageid:37f4e82f96c9])
I0715 11:25:24.264822       1 utils.go:205] ID: 25 Req-ID: pvc-511617c3-f47c-4f8e-bfcc-cf727dee61a8 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-1efa8cec-d852-43a2-8d4d-95e59636fcaf","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-1efa8cec-d852-43a2-8d4d-95e59636fcaf"}}
I0715 11:26:02.736027       1 utils.go:198] ID: 26 GRPC call: /csi.v1.Identity/Probe
I0715 11:26:02.736080       1 utils.go:199] ID: 26 GRPC request: {}
I0715 11:26:02.736102       1 utils.go:205] ID: 26 GRPC response: {}