I0507 02:05:55.697530       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0507 02:05:55.697653       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0507 02:05:55.697672       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0507 02:05:55.697677       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0507 02:05:55.697682       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0507 02:05:55.697686       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0507 02:05:55.697691       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0507 02:05:55.697696       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0507 02:05:55.697700       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0507 02:05:55.697704       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0507 02:05:55.698033       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0507 02:05:55.698038       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0507 02:05:59.053680       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0507 02:05:59.054672       1 utils.go:199] ID: 1 GRPC request: {}
I0507 02:05:59.054745       1 utils.go:205] ID: 1 GRPC response: {}
I0507 02:05:59.059268       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0507 02:05:59.059729       1 utils.go:199] ID: 2 GRPC request: {}
I0507 02:05:59.059760       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0507 02:05:59.059837       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0507 02:05:59.061349       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0507 02:05:59.061445       1 utils.go:199] ID: 3 GRPC request: {}
I0507 02:05:59.061482       1 utils.go:205] ID: 3 GRPC response: {}
I0507 02:05:59.061851       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0507 02:05:59.061930       1 utils.go:199] ID: 4 GRPC request: {}
I0507 02:05:59.062097       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0507 02:05:59.062761       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0507 02:05:59.062835       1 utils.go:199] ID: 5 GRPC request: {}
I0507 02:05:59.062863       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0507 02:05:59.062974       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}}}]}
I0507 02:06:01.025527       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0507 02:06:01.025593       1 utils.go:199] ID: 6 GRPC request: {}
I0507 02:06:01.025629       1 utils.go:205] ID: 6 GRPC response: {}
I0507 02:06:01.027598       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0507 02:06:01.027662       1 utils.go:199] ID: 7 GRPC request: {}
I0507 02:06:01.027685       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0507 02:06:01.027731       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0507 02:06:01.030676       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0507 02:06:01.030745       1 utils.go:199] ID: 8 GRPC request: {}
I0507 02:06:01.030778       1 utils.go:205] ID: 8 GRPC response: {}
I0507 02:06:01.031215       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0507 02:06:01.031277       1 utils.go:199] ID: 9 GRPC request: {}
I0507 02:06:01.031441       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0507 02:06:01.032155       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0507 02:06:01.032216       1 utils.go:199] ID: 10 GRPC request: {}
I0507 02:06:01.032236       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0507 02:06:01.032402       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}}}]}
I0507 02:06:01.033045       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0507 02:06:01.033072       1 utils.go:199] ID: 11 GRPC request: {}
I0507 02:06:01.033080       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0507 02:06:01.033269       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}}}]}
I0507 02:06:01.033728       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0507 02:06:01.033774       1 utils.go:199] ID: 12 GRPC request: {}
I0507 02:06:01.033805       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0507 02:06:01.033882       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}}}]}
I0507 02:06:02.650885       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0507 02:06:02.650920       1 utils.go:199] ID: 13 GRPC request: {}
I0507 02:06:02.650926       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0507 02:06:02.650946       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0507 02:06:02.652719       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0507 02:06:02.652736       1 utils.go:199] ID: 14 GRPC request: {}
I0507 02:06:02.652747       1 utils.go:205] ID: 14 GRPC response: {}
I0507 02:06:02.653234       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0507 02:06:02.653250       1 utils.go:199] ID: 15 GRPC request: {}
I0507 02:06:02.653256       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0507 02:06:02.653383       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}}}]}
I0507 02:06:03.860211       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0507 02:06:03.860310       1 utils.go:199] ID: 16 GRPC request: {}
I0507 02:06:03.860362       1 utils.go:205] ID: 16 GRPC response: {}
I0507 02:06:03.862869       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0507 02:06:03.862896       1 utils.go:199] ID: 17 GRPC request: {}
I0507 02:06:03.862904       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0507 02:06:03.862928       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0507 02:06:03.865099       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0507 02:06:03.865119       1 utils.go:199] ID: 18 GRPC request: {}
I0507 02:06:03.865130       1 utils.go:205] ID: 18 GRPC response: {}
I0507 02:06:03.865538       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0507 02:06:03.865563       1 utils.go:199] ID: 19 GRPC request: {}
I0507 02:06:03.865663       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0507 02:06:03.866725       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0507 02:06:03.866771       1 utils.go:199] ID: 20 GRPC request: {}
I0507 02:06:03.866785       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0507 02:06:03.866863       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}}}]}
I0507 02:07:04.121494       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0507 02:07:04.121570       1 utils.go:199] ID: 21 GRPC request: {}
I0507 02:07:04.121613       1 utils.go:205] ID: 21 GRPC response: {}
I0507 02:08:04.082039       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0507 02:08:04.082182       1 utils.go:199] ID: 22 GRPC request: {}
I0507 02:08:04.082223       1 utils.go:205] ID: 22 GRPC response: {}
I0507 02:09:04.129566       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0507 02:09:04.129635       1 utils.go:199] ID: 23 GRPC request: {}
I0507 02:09:04.129652       1 utils.go:205] ID: 23 GRPC response: {}
I0507 02:09:07.226228       1 utils.go:198] ID: 24 Req-ID: pvc-1c0a2453-07c2-4db9-a9ec-853a432859d7 GRPC call: /csi.v1.Controller/CreateVolume
I0507 02:09:07.226723       1 utils.go:199] ID: 24 Req-ID: pvc-1c0a2453-07c2-4db9-a9ec-853a432859d7 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-1c0a2453-07c2-4db9-a9ec-853a432859d7","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-1c0a2453-07c2-4db9-a9ec-853a432859d7","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}}]}
I0507 02:09:07.227086       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-1c0a2453-07c2-4db9-a9ec-853a432859d7 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0507 02:09:07.245235       1 omap.go:80] ID: 24 Req-ID: pvc-1c0a2453-07c2-4db9-a9ec-853a432859d7 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0507 02:09:07.262543       1 omap.go:159] ID: 24 Req-ID: pvc-1c0a2453-07c2-4db9-a9ec-853a432859d7 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-1c0a2453-07c2-4db9-a9ec-853a432859d7:69b69d54-1a4a-4de8-8920-41b3b88707fb])
I0507 02:09:07.268584       1 omap.go:159] ID: 24 Req-ID: pvc-1c0a2453-07c2-4db9-a9ec-853a432859d7 set omap keys (pool="kube", namespace="", name="csi.volume.69b69d54-1a4a-4de8-8920-41b3b88707fb"): map[csi.imagename:csi-vol-69b69d54-1a4a-4de8-8920-41b3b88707fb csi.volname:pvc-1c0a2453-07c2-4db9-a9ec-853a432859d7 csi.volume.owner:default])
I0507 02:09:07.268629       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-1c0a2453-07c2-4db9-a9ec-853a432859d7 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-69b69d54-1a4a-4de8-8920-41b3b88707fb) and image name (csi-vol-69b69d54-1a4a-4de8-8920-41b3b88707fb) for request name (pvc-1c0a2453-07c2-4db9-a9ec-853a432859d7)
I0507 02:09:07.268884       1 rbd_util.go:423] ID: 24 Req-ID: pvc-1c0a2453-07c2-4db9-a9ec-853a432859d7 rbd: create kube/csi-vol-69b69d54-1a4a-4de8-8920-41b3b88707fb size 5120M (features: [layering]) using mon 199.204.45.77
I0507 02:09:07.269045       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-1c0a2453-07c2-4db9-a9ec-853a432859d7 setting image options on kube/csi-vol-69b69d54-1a4a-4de8-8920-41b3b88707fb
I0507 02:09:09.005304       1 controllerserver.go:763] ID: 24 Req-ID: pvc-1c0a2453-07c2-4db9-a9ec-853a432859d7 created image kube/csi-vol-69b69d54-1a4a-4de8-8920-41b3b88707fb backed for request name pvc-1c0a2453-07c2-4db9-a9ec-853a432859d7
I0507 02:09:09.044104       1 omap.go:159] ID: 24 Req-ID: pvc-1c0a2453-07c2-4db9-a9ec-853a432859d7 set omap keys (pool="kube", namespace="", name="csi.volume.69b69d54-1a4a-4de8-8920-41b3b88707fb"): map[csi.imageid:37d9cc758898])
I0507 02:09:09.145524       1 utils.go:205] ID: 24 Req-ID: pvc-1c0a2453-07c2-4db9-a9ec-853a432859d7 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-69b69d54-1a4a-4de8-8920-41b3b88707fb","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-69b69d54-1a4a-4de8-8920-41b3b88707fb"}}
I0507 02:10:04.092538       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0507 02:10:04.092608       1 utils.go:199] ID: 25 GRPC request: {}
I0507 02:10:04.092639       1 utils.go:205] ID: 25 GRPC response: {}