I0622 23:07:05.303835       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0622 23:07:05.303995       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0622 23:07:05.304011       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0622 23:07:05.304020       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0622 23:07:05.304024       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0622 23:07:05.304027       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0622 23:07:05.304032       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0622 23:07:05.304035       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0622 23:07:05.304039       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0622 23:07:05.304041       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0622 23:07:05.304390       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0622 23:07:05.304429       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0622 23:07:09.107884       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0622 23:07:09.109763       1 utils.go:199] ID: 1 GRPC request: {}
I0622 23:07:09.109830       1 utils.go:205] ID: 1 GRPC response: {}
I0622 23:07:09.116565       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0622 23:07:09.116623       1 utils.go:199] ID: 2 GRPC request: {}
I0622 23:07:09.116637       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0622 23:07:09.116695       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0622 23:07:09.119691       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0622 23:07:09.119713       1 utils.go:199] ID: 3 GRPC request: {}
I0622 23:07:09.119723       1 utils.go:205] ID: 3 GRPC response: {}
I0622 23:07:09.120143       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0622 23:07:09.120193       1 utils.go:199] ID: 4 GRPC request: {}
I0622 23:07:09.120322       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0622 23:07:09.121467       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0622 23:07:09.121613       1 utils.go:199] ID: 5 GRPC request: {}
I0622 23:07:09.121772       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0622 23:07:09.122013       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}}}]}
I0622 23:07:10.968655       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0622 23:07:10.968746       1 utils.go:199] ID: 6 GRPC request: {}
I0622 23:07:10.968800       1 utils.go:205] ID: 6 GRPC response: {}
I0622 23:07:10.971055       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0622 23:07:10.971125       1 utils.go:199] ID: 7 GRPC request: {}
I0622 23:07:10.971142       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0622 23:07:10.971206       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0622 23:07:10.978746       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0622 23:07:10.978775       1 utils.go:199] ID: 8 GRPC request: {}
I0622 23:07:10.978806       1 utils.go:205] ID: 8 GRPC response: {}
I0622 23:07:10.979329       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0622 23:07:10.979351       1 utils.go:199] ID: 9 GRPC request: {}
I0622 23:07:10.979514       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0622 23:07:10.980195       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0622 23:07:10.980217       1 utils.go:199] ID: 10 GRPC request: {}
I0622 23:07:10.980243       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0622 23:07:10.980369       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}}}]}
I0622 23:07:10.980901       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0622 23:07:10.981201       1 utils.go:199] ID: 11 GRPC request: {}
I0622 23:07:10.981220       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0622 23:07:10.981360       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}}}]}
I0622 23:07:10.981708       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0622 23:07:10.981726       1 utils.go:199] ID: 12 GRPC request: {}
I0622 23:07:10.981731       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0622 23:07:10.981811       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}}}]}
I0622 23:07:12.963398       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0622 23:07:12.963495       1 utils.go:199] ID: 13 GRPC request: {}
I0622 23:07:12.963522       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0622 23:07:12.963586       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0622 23:07:12.967051       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0622 23:07:12.967115       1 utils.go:199] ID: 14 GRPC request: {}
I0622 23:07:12.967180       1 utils.go:205] ID: 14 GRPC response: {}
I0622 23:07:12.968122       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0622 23:07:12.968190       1 utils.go:199] ID: 15 GRPC request: {}
I0622 23:07:12.968234       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0622 23:07:12.968445       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}}}]}
I0622 23:07:14.711718       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0622 23:07:14.711871       1 utils.go:199] ID: 16 GRPC request: {}
I0622 23:07:14.711953       1 utils.go:205] ID: 16 GRPC response: {}
I0622 23:07:14.717109       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0622 23:07:14.717137       1 utils.go:199] ID: 17 GRPC request: {}
I0622 23:07:14.717166       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0622 23:07:14.717198       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0622 23:07:14.721645       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0622 23:07:14.721818       1 utils.go:199] ID: 18 GRPC request: {}
I0622 23:07:14.721936       1 utils.go:205] ID: 18 GRPC response: {}
I0622 23:07:14.722962       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0622 23:07:14.722996       1 utils.go:199] ID: 19 GRPC request: {}
I0622 23:07:14.723143       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0622 23:07:14.727760       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0622 23:07:14.727788       1 utils.go:199] ID: 20 GRPC request: {}
I0622 23:07:14.727809       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0622 23:07:14.727906       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}}}]}
I0622 23:08:15.047327       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0622 23:08:15.047404       1 utils.go:199] ID: 21 GRPC request: {}
I0622 23:08:15.047433       1 utils.go:205] ID: 21 GRPC response: {}
I0622 23:09:14.988420       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0622 23:09:14.988594       1 utils.go:199] ID: 22 GRPC request: {}
I0622 23:09:14.988659       1 utils.go:205] ID: 22 GRPC response: {}
I0622 23:10:14.986191       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0622 23:10:14.986225       1 utils.go:199] ID: 23 GRPC request: {}
I0622 23:10:14.986249       1 utils.go:205] ID: 23 GRPC response: {}
I0622 23:10:54.394262       1 utils.go:198] ID: 24 Req-ID: pvc-27a89a0d-a6e3-4cc0-9d29-500ab3c6dd85 GRPC call: /csi.v1.Controller/CreateVolume
I0622 23:10:54.394718       1 utils.go:199] ID: 24 Req-ID: pvc-27a89a0d-a6e3-4cc0-9d29-500ab3c6dd85 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-27a89a0d-a6e3-4cc0-9d29-500ab3c6dd85","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-27a89a0d-a6e3-4cc0-9d29-500ab3c6dd85","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}}]}
I0622 23:10:54.395027       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-27a89a0d-a6e3-4cc0-9d29-500ab3c6dd85 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0622 23:10:54.417528       1 omap.go:80] ID: 24 Req-ID: pvc-27a89a0d-a6e3-4cc0-9d29-500ab3c6dd85 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0622 23:10:54.432748       1 omap.go:159] ID: 24 Req-ID: pvc-27a89a0d-a6e3-4cc0-9d29-500ab3c6dd85 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-27a89a0d-a6e3-4cc0-9d29-500ab3c6dd85:48202677-8897-4114-b2a0-52c8cf6d4c81])
I0622 23:10:54.439934       1 omap.go:159] ID: 24 Req-ID: pvc-27a89a0d-a6e3-4cc0-9d29-500ab3c6dd85 set omap keys (pool="kube", namespace="", name="csi.volume.48202677-8897-4114-b2a0-52c8cf6d4c81"): map[csi.imagename:csi-vol-48202677-8897-4114-b2a0-52c8cf6d4c81 csi.volname:pvc-27a89a0d-a6e3-4cc0-9d29-500ab3c6dd85 csi.volume.owner:default])
I0622 23:10:54.439975       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-27a89a0d-a6e3-4cc0-9d29-500ab3c6dd85 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-48202677-8897-4114-b2a0-52c8cf6d4c81) and image name (csi-vol-48202677-8897-4114-b2a0-52c8cf6d4c81) for request name (pvc-27a89a0d-a6e3-4cc0-9d29-500ab3c6dd85)
I0622 23:10:54.440077       1 rbd_util.go:423] ID: 24 Req-ID: pvc-27a89a0d-a6e3-4cc0-9d29-500ab3c6dd85 rbd: create kube/csi-vol-48202677-8897-4114-b2a0-52c8cf6d4c81 size 5120M (features: [layering]) using mon 199.204.45.72
I0622 23:10:54.440830       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-27a89a0d-a6e3-4cc0-9d29-500ab3c6dd85 setting image options on kube/csi-vol-48202677-8897-4114-b2a0-52c8cf6d4c81
I0622 23:10:54.470367       1 controllerserver.go:763] ID: 24 Req-ID: pvc-27a89a0d-a6e3-4cc0-9d29-500ab3c6dd85 created image kube/csi-vol-48202677-8897-4114-b2a0-52c8cf6d4c81 backed for request name pvc-27a89a0d-a6e3-4cc0-9d29-500ab3c6dd85
I0622 23:10:54.499804       1 omap.go:159] ID: 24 Req-ID: pvc-27a89a0d-a6e3-4cc0-9d29-500ab3c6dd85 set omap keys (pool="kube", namespace="", name="csi.volume.48202677-8897-4114-b2a0-52c8cf6d4c81"): map[csi.imageid:37edc6653754])
I0622 23:10:54.586081       1 utils.go:205] ID: 24 Req-ID: pvc-27a89a0d-a6e3-4cc0-9d29-500ab3c6dd85 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-48202677-8897-4114-b2a0-52c8cf6d4c81","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-48202677-8897-4114-b2a0-52c8cf6d4c81"}}
I0622 23:11:14.998887       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0622 23:11:14.998993       1 utils.go:199] ID: 25 GRPC request: {}
I0622 23:11:14.999028       1 utils.go:205] ID: 25 GRPC response: {}