I0615 19:07:52.661664       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0615 19:07:52.661882       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0615 19:07:52.661908       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0615 19:07:52.661916       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0615 19:07:52.661921       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0615 19:07:52.661926       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0615 19:07:52.661934       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0615 19:07:52.661938       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0615 19:07:52.661942       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0615 19:07:52.661947       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0615 19:07:52.662544       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0615 19:07:52.662556       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0615 19:07:55.641870       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0615 19:07:55.644715       1 utils.go:199] ID: 1 GRPC request: {}
I0615 19:07:55.644872       1 utils.go:205] ID: 1 GRPC response: {}
I0615 19:07:55.654497       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0615 19:07:55.654608       1 utils.go:199] ID: 2 GRPC request: {}
I0615 19:07:55.654626       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0615 19:07:55.654684       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0615 19:07:55.657914       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0615 19:07:55.657969       1 utils.go:199] ID: 3 GRPC request: {}
I0615 19:07:55.658006       1 utils.go:205] ID: 3 GRPC response: {}
I0615 19:07:55.658850       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0615 19:07:55.659049       1 utils.go:199] ID: 4 GRPC request: {}
I0615 19:07:55.659309       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0615 19:07:55.660243       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0615 19:07:55.660323       1 utils.go:199] ID: 5 GRPC request: {}
I0615 19:07:55.660338       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0615 19:07:55.660551       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}}}]}
I0615 19:07:57.401827       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0615 19:07:57.401915       1 utils.go:199] ID: 6 GRPC request: {}
I0615 19:07:57.401958       1 utils.go:205] ID: 6 GRPC response: {}
I0615 19:07:57.406881       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0615 19:07:57.406947       1 utils.go:199] ID: 7 GRPC request: {}
I0615 19:07:57.407041       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0615 19:07:57.407276       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0615 19:07:57.409552       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0615 19:07:57.409584       1 utils.go:199] ID: 8 GRPC request: {}
I0615 19:07:57.409660       1 utils.go:205] ID: 8 GRPC response: {}
I0615 19:07:57.410252       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0615 19:07:57.410273       1 utils.go:199] ID: 9 GRPC request: {}
I0615 19:07:57.410434       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0615 19:07:57.411180       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0615 19:07:57.411201       1 utils.go:199] ID: 10 GRPC request: {}
I0615 19:07:57.411212       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0615 19:07:57.411363       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}}}]}
I0615 19:07:57.412050       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0615 19:07:57.412070       1 utils.go:199] ID: 11 GRPC request: {}
I0615 19:07:57.412075       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0615 19:07:57.412166       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}}}]}
I0615 19:07:57.412566       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0615 19:07:57.412585       1 utils.go:199] ID: 12 GRPC request: {}
I0615 19:07:57.412591       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0615 19:07:57.412679       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}}}]}
I0615 19:08:02.905489       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0615 19:08:02.905571       1 utils.go:199] ID: 13 GRPC request: {}
I0615 19:08:02.905591       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0615 19:08:02.905644       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0615 19:08:02.910933       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0615 19:08:02.911028       1 utils.go:199] ID: 14 GRPC request: {}
I0615 19:08:02.911059       1 utils.go:205] ID: 14 GRPC response: {}
I0615 19:08:02.912300       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0615 19:08:02.912350       1 utils.go:199] ID: 15 GRPC request: {}
I0615 19:08:02.912365       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0615 19:08:02.912472       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}}}]}
I0615 19:08:04.702080       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0615 19:08:04.702159       1 utils.go:199] ID: 16 GRPC request: {}
I0615 19:08:04.702206       1 utils.go:205] ID: 16 GRPC response: {}
I0615 19:08:04.704746       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0615 19:08:04.704825       1 utils.go:199] ID: 17 GRPC request: {}
I0615 19:08:04.704868       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0615 19:08:04.704929       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0615 19:08:04.708342       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0615 19:08:04.708359       1 utils.go:199] ID: 18 GRPC request: {}
I0615 19:08:04.708403       1 utils.go:205] ID: 18 GRPC response: {}
I0615 19:08:04.708772       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0615 19:08:04.708827       1 utils.go:199] ID: 19 GRPC request: {}
I0615 19:08:04.708960       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0615 19:08:04.709902       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0615 19:08:04.709927       1 utils.go:199] ID: 20 GRPC request: {}
I0615 19:08:04.709971       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0615 19:08:04.710094       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}}}]}
I0615 19:09:04.950322       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0615 19:09:04.950380       1 utils.go:199] ID: 21 GRPC request: {}
I0615 19:09:04.950409       1 utils.go:205] ID: 21 GRPC response: {}
I0615 19:10:04.911111       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0615 19:10:04.911338       1 utils.go:199] ID: 22 GRPC request: {}
I0615 19:10:04.911522       1 utils.go:205] ID: 22 GRPC response: {}
I0615 19:11:04.963067       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0615 19:11:04.963224       1 utils.go:199] ID: 23 GRPC request: {}
I0615 19:11:04.963348       1 utils.go:205] ID: 23 GRPC response: {}
I0615 19:11:58.235988       1 utils.go:198] ID: 24 Req-ID: pvc-e9add14a-b3f9-4050-93be-d2dc0b0ae736 GRPC call: /csi.v1.Controller/CreateVolume
I0615 19:11:58.236847       1 utils.go:199] ID: 24 Req-ID: pvc-e9add14a-b3f9-4050-93be-d2dc0b0ae736 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-e9add14a-b3f9-4050-93be-d2dc0b0ae736","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-e9add14a-b3f9-4050-93be-d2dc0b0ae736","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}}]}
I0615 19:11:58.237325       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-e9add14a-b3f9-4050-93be-d2dc0b0ae736 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0615 19:11:58.258848       1 omap.go:80] ID: 24 Req-ID: pvc-e9add14a-b3f9-4050-93be-d2dc0b0ae736 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0615 19:11:58.275861       1 omap.go:159] ID: 24 Req-ID: pvc-e9add14a-b3f9-4050-93be-d2dc0b0ae736 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-e9add14a-b3f9-4050-93be-d2dc0b0ae736:d6904ddb-2267-45b6-b09f-5821a5aaa2a8])
I0615 19:11:58.283119       1 omap.go:159] ID: 24 Req-ID: pvc-e9add14a-b3f9-4050-93be-d2dc0b0ae736 set omap keys (pool="kube", namespace="", name="csi.volume.d6904ddb-2267-45b6-b09f-5821a5aaa2a8"): map[csi.imagename:csi-vol-d6904ddb-2267-45b6-b09f-5821a5aaa2a8 csi.volname:pvc-e9add14a-b3f9-4050-93be-d2dc0b0ae736 csi.volume.owner:default])
I0615 19:11:58.283166       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-e9add14a-b3f9-4050-93be-d2dc0b0ae736 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-d6904ddb-2267-45b6-b09f-5821a5aaa2a8) and image name (csi-vol-d6904ddb-2267-45b6-b09f-5821a5aaa2a8) for request name (pvc-e9add14a-b3f9-4050-93be-d2dc0b0ae736)
I0615 19:11:58.283401       1 rbd_util.go:423] ID: 24 Req-ID: pvc-e9add14a-b3f9-4050-93be-d2dc0b0ae736 rbd: create kube/csi-vol-d6904ddb-2267-45b6-b09f-5821a5aaa2a8 size 5120M (features: [layering]) using mon 199.19.213.128
I0615 19:11:58.283533       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-e9add14a-b3f9-4050-93be-d2dc0b0ae736 setting image options on kube/csi-vol-d6904ddb-2267-45b6-b09f-5821a5aaa2a8
I0615 19:11:58.319400       1 controllerserver.go:763] ID: 24 Req-ID: pvc-e9add14a-b3f9-4050-93be-d2dc0b0ae736 created image kube/csi-vol-d6904ddb-2267-45b6-b09f-5821a5aaa2a8 backed for request name pvc-e9add14a-b3f9-4050-93be-d2dc0b0ae736
I0615 19:11:58.354961       1 omap.go:159] ID: 24 Req-ID: pvc-e9add14a-b3f9-4050-93be-d2dc0b0ae736 set omap keys (pool="kube", namespace="", name="csi.volume.d6904ddb-2267-45b6-b09f-5821a5aaa2a8"): map[csi.imageid:37edd32ec5b1])
I0615 19:11:58.458815       1 utils.go:205] ID: 24 Req-ID: pvc-e9add14a-b3f9-4050-93be-d2dc0b0ae736 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-d6904ddb-2267-45b6-b09f-5821a5aaa2a8","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-d6904ddb-2267-45b6-b09f-5821a5aaa2a8"}}
I0615 19:12:04.920999       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0615 19:12:04.921084       1 utils.go:199] ID: 25 GRPC request: {}
I0615 19:12:04.921135       1 utils.go:205] ID: 25 GRPC response: {}