I0516 09:22:41.419042       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0516 09:22:41.419185       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0516 09:22:41.419202       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0516 09:22:41.419207       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0516 09:22:41.419210       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0516 09:22:41.419212       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0516 09:22:41.419216       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0516 09:22:41.419218       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0516 09:22:41.419221       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0516 09:22:41.419224       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0516 09:22:41.419550       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0516 09:22:41.419566       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0516 09:22:44.276163       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0516 09:22:44.278296       1 utils.go:199] ID: 1 GRPC request: {}
I0516 09:22:44.278380       1 utils.go:205] ID: 1 GRPC response: {}
I0516 09:22:44.283293       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0516 09:22:44.283367       1 utils.go:199] ID: 2 GRPC request: {}
I0516 09:22:44.283380       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0516 09:22:44.283441       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0516 09:22:44.285084       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0516 09:22:44.285270       1 utils.go:199] ID: 3 GRPC request: {}
I0516 09:22:44.285368       1 utils.go:205] ID: 3 GRPC response: {}
I0516 09:22:44.285940       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0516 09:22:44.286067       1 utils.go:199] ID: 4 GRPC request: {}
I0516 09:22:44.286426       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0516 09:22:44.287806       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0516 09:22:44.287928       1 utils.go:199] ID: 5 GRPC request: {}
I0516 09:22:44.287946       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0516 09:22:44.288182       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}}}]}
I0516 09:22:46.745148       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0516 09:22:46.745181       1 utils.go:199] ID: 6 GRPC request: {}
I0516 09:22:46.745198       1 utils.go:205] ID: 6 GRPC response: {}
I0516 09:22:46.747270       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0516 09:22:46.747582       1 utils.go:199] ID: 7 GRPC request: {}
I0516 09:22:46.747603       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0516 09:22:46.747653       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0516 09:22:46.749821       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0516 09:22:46.749867       1 utils.go:199] ID: 8 GRPC request: {}
I0516 09:22:46.750037       1 utils.go:205] ID: 8 GRPC response: {}
I0516 09:22:46.750791       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0516 09:22:46.750823       1 utils.go:199] ID: 9 GRPC request: {}
I0516 09:22:46.750919       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0516 09:22:46.751551       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0516 09:22:46.751581       1 utils.go:199] ID: 10 GRPC request: {}
I0516 09:22:46.751589       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0516 09:22:46.751697       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}}}]}
I0516 09:22:46.752391       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0516 09:22:46.752407       1 utils.go:199] ID: 11 GRPC request: {}
I0516 09:22:46.752414       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0516 09:22:46.752459       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}}}]}
I0516 09:22:46.752828       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0516 09:22:46.752846       1 utils.go:199] ID: 12 GRPC request: {}
I0516 09:22:46.752852       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0516 09:22:46.752977       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}}}]}
I0516 09:22:47.944973       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0516 09:22:47.945040       1 utils.go:199] ID: 13 GRPC request: {}
I0516 09:22:47.945048       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0516 09:22:47.945078       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0516 09:22:47.947107       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0516 09:22:47.947142       1 utils.go:199] ID: 14 GRPC request: {}
I0516 09:22:47.947157       1 utils.go:205] ID: 14 GRPC response: {}
I0516 09:22:47.947611       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0516 09:22:47.947646       1 utils.go:199] ID: 15 GRPC request: {}
I0516 09:22:47.947655       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0516 09:22:47.947799       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}}}]}
I0516 09:22:49.397795       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0516 09:22:49.397829       1 utils.go:199] ID: 16 GRPC request: {}
I0516 09:22:49.397846       1 utils.go:205] ID: 16 GRPC response: {}
I0516 09:22:49.400377       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0516 09:22:49.400406       1 utils.go:199] ID: 17 GRPC request: {}
I0516 09:22:49.400413       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0516 09:22:49.400436       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0516 09:22:49.404985       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0516 09:22:49.405013       1 utils.go:199] ID: 18 GRPC request: {}
I0516 09:22:49.405041       1 utils.go:205] ID: 18 GRPC response: {}
I0516 09:22:49.405329       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0516 09:22:49.405343       1 utils.go:199] ID: 19 GRPC request: {}
I0516 09:22:49.405429       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0516 09:22:49.406523       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0516 09:22:49.406543       1 utils.go:199] ID: 20 GRPC request: {}
I0516 09:22:49.406560       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0516 09:22:49.406626       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}}}]}
I0516 09:23:49.631877       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0516 09:23:49.631939       1 utils.go:199] ID: 21 GRPC request: {}
I0516 09:23:49.631972       1 utils.go:205] ID: 21 GRPC response: {}
I0516 09:24:49.575414       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0516 09:24:49.575516       1 utils.go:199] ID: 22 GRPC request: {}
I0516 09:24:49.575573       1 utils.go:205] ID: 22 GRPC response: {}
I0516 09:25:49.573413       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0516 09:25:49.573487       1 utils.go:199] ID: 23 GRPC request: {}
I0516 09:25:49.573528       1 utils.go:205] ID: 23 GRPC response: {}
I0516 09:25:58.745502       1 utils.go:198] ID: 24 Req-ID: pvc-805393e0-1fc7-4b41-a6be-142f66bf9160 GRPC call: /csi.v1.Controller/CreateVolume
I0516 09:25:58.746065       1 utils.go:199] ID: 24 Req-ID: pvc-805393e0-1fc7-4b41-a6be-142f66bf9160 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-805393e0-1fc7-4b41-a6be-142f66bf9160","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-805393e0-1fc7-4b41-a6be-142f66bf9160","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}}]}
I0516 09:25:58.746405       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-805393e0-1fc7-4b41-a6be-142f66bf9160 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0516 09:25:58.764169       1 omap.go:80] ID: 24 Req-ID: pvc-805393e0-1fc7-4b41-a6be-142f66bf9160 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0516 09:25:58.777855       1 omap.go:159] ID: 24 Req-ID: pvc-805393e0-1fc7-4b41-a6be-142f66bf9160 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-805393e0-1fc7-4b41-a6be-142f66bf9160:dc368373-1d3d-4b1f-affb-55370668a5a7])
I0516 09:25:58.785389       1 omap.go:159] ID: 24 Req-ID: pvc-805393e0-1fc7-4b41-a6be-142f66bf9160 set omap keys (pool="kube", namespace="", name="csi.volume.dc368373-1d3d-4b1f-affb-55370668a5a7"): map[csi.imagename:csi-vol-dc368373-1d3d-4b1f-affb-55370668a5a7 csi.volname:pvc-805393e0-1fc7-4b41-a6be-142f66bf9160 csi.volume.owner:default])
I0516 09:25:58.785429       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-805393e0-1fc7-4b41-a6be-142f66bf9160 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-dc368373-1d3d-4b1f-affb-55370668a5a7) and image name (csi-vol-dc368373-1d3d-4b1f-affb-55370668a5a7) for request name (pvc-805393e0-1fc7-4b41-a6be-142f66bf9160)
I0516 09:25:58.785509       1 rbd_util.go:423] ID: 24 Req-ID: pvc-805393e0-1fc7-4b41-a6be-142f66bf9160 rbd: create kube/csi-vol-dc368373-1d3d-4b1f-affb-55370668a5a7 size 5120M (features: [layering]) using mon 199.204.45.115
I0516 09:25:58.785570       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-805393e0-1fc7-4b41-a6be-142f66bf9160 setting image options on kube/csi-vol-dc368373-1d3d-4b1f-affb-55370668a5a7
I0516 09:26:00.666301       1 controllerserver.go:763] ID: 24 Req-ID: pvc-805393e0-1fc7-4b41-a6be-142f66bf9160 created image kube/csi-vol-dc368373-1d3d-4b1f-affb-55370668a5a7 backed for request name pvc-805393e0-1fc7-4b41-a6be-142f66bf9160
I0516 09:26:00.692626       1 omap.go:159] ID: 24 Req-ID: pvc-805393e0-1fc7-4b41-a6be-142f66bf9160 set omap keys (pool="kube", namespace="", name="csi.volume.dc368373-1d3d-4b1f-affb-55370668a5a7"): map[csi.imageid:37d9d08113c1])
I0516 09:26:00.778008       1 utils.go:205] ID: 24 Req-ID: pvc-805393e0-1fc7-4b41-a6be-142f66bf9160 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-dc368373-1d3d-4b1f-affb-55370668a5a7","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-dc368373-1d3d-4b1f-affb-55370668a5a7"}}
I0516 09:26:49.585248       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0516 09:26:49.585323       1 utils.go:199] ID: 25 GRPC request: {}
I0516 09:26:49.585352       1 utils.go:205] ID: 25 GRPC response: {}