I0618 01:03:20.082931       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0618 01:03:20.083202       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0618 01:03:20.083228       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0618 01:03:20.083242       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0618 01:03:20.083258       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0618 01:03:20.083274       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0618 01:03:20.083293       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0618 01:03:20.083308       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0618 01:03:20.083327       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0618 01:03:20.083342       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0618 01:03:20.083688       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0618 01:03:20.083793       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0618 01:03:23.585104       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0618 01:03:23.586462       1 utils.go:199] ID: 1 GRPC request: {}
I0618 01:03:23.586522       1 utils.go:205] ID: 1 GRPC response: {}
I0618 01:03:23.589953       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0618 01:03:23.590356       1 utils.go:199] ID: 2 GRPC request: {}
I0618 01:03:23.590394       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0618 01:03:23.590459       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0618 01:03:23.592168       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0618 01:03:23.592202       1 utils.go:199] ID: 3 GRPC request: {}
I0618 01:03:23.592330       1 utils.go:205] ID: 3 GRPC response: {}
I0618 01:03:23.593093       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0618 01:03:23.593374       1 utils.go:199] ID: 4 GRPC request: {}
I0618 01:03:23.593660       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0618 01:03:23.594928       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0618 01:03:23.594986       1 utils.go:199] ID: 5 GRPC request: {}
I0618 01:03:23.594999       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0618 01:03:23.595125       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}}}]}
I0618 01:03:25.371109       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0618 01:03:25.371204       1 utils.go:199] ID: 6 GRPC request: {}
I0618 01:03:25.371278       1 utils.go:205] ID: 6 GRPC response: {}
I0618 01:03:25.374090       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0618 01:03:25.374263       1 utils.go:199] ID: 7 GRPC request: {}
I0618 01:03:25.374330       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0618 01:03:25.374408       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0618 01:03:25.378222       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0618 01:03:25.378335       1 utils.go:199] ID: 8 GRPC request: {}
I0618 01:03:25.378403       1 utils.go:205] ID: 8 GRPC response: {}
I0618 01:03:25.379064       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0618 01:03:25.379100       1 utils.go:199] ID: 9 GRPC request: {}
I0618 01:03:25.379329       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0618 01:03:25.379949       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0618 01:03:25.379972       1 utils.go:199] ID: 10 GRPC request: {}
I0618 01:03:25.379979       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0618 01:03:25.380128       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}}}]}
I0618 01:03:25.380585       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0618 01:03:25.380629       1 utils.go:199] ID: 11 GRPC request: {}
I0618 01:03:25.380638       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0618 01:03:25.380744       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}}}]}
I0618 01:03:25.381090       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0618 01:03:25.381107       1 utils.go:199] ID: 12 GRPC request: {}
I0618 01:03:25.381112       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0618 01:03:25.381158       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}}}]}
I0618 01:03:26.980871       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0618 01:03:26.980914       1 utils.go:199] ID: 13 GRPC request: {}
I0618 01:03:26.980931       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0618 01:03:26.980961       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0618 01:03:26.985305       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0618 01:03:26.985326       1 utils.go:199] ID: 14 GRPC request: {}
I0618 01:03:26.985360       1 utils.go:205] ID: 14 GRPC response: {}
I0618 01:03:26.985803       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0618 01:03:26.985821       1 utils.go:199] ID: 15 GRPC request: {}
I0618 01:03:26.985828       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0618 01:03:26.985919       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}}}]}
I0618 01:03:28.703216       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0618 01:03:28.703290       1 utils.go:199] ID: 16 GRPC request: {}
I0618 01:03:28.703343       1 utils.go:205] ID: 16 GRPC response: {}
I0618 01:03:28.705998       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0618 01:03:28.706274       1 utils.go:199] ID: 17 GRPC request: {}
I0618 01:03:28.706315       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0618 01:03:28.706356       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0618 01:03:28.710418       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0618 01:03:28.710460       1 utils.go:199] ID: 18 GRPC request: {}
I0618 01:03:28.710482       1 utils.go:205] ID: 18 GRPC response: {}
I0618 01:03:28.710853       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0618 01:03:28.710898       1 utils.go:199] ID: 19 GRPC request: {}
I0618 01:03:28.710998       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0618 01:03:28.711590       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0618 01:03:28.711617       1 utils.go:199] ID: 20 GRPC request: {}
I0618 01:03:28.711627       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0618 01:03:28.711724       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}}}]}
I0618 01:04:28.938867       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0618 01:04:28.938923       1 utils.go:199] ID: 21 GRPC request: {}
I0618 01:04:28.938947       1 utils.go:205] ID: 21 GRPC response: {}
I0618 01:05:28.884828       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0618 01:05:28.884893       1 utils.go:199] ID: 22 GRPC request: {}
I0618 01:05:28.884912       1 utils.go:205] ID: 22 GRPC response: {}
I0618 01:06:28.919932       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0618 01:06:28.920012       1 utils.go:199] ID: 23 GRPC request: {}
I0618 01:06:28.920045       1 utils.go:205] ID: 23 GRPC response: {}
I0618 01:07:09.664112       1 utils.go:198] ID: 24 Req-ID: pvc-89e116e2-5a4b-44d0-a08e-592a24e6b119 GRPC call: /csi.v1.Controller/CreateVolume
I0618 01:07:09.664337       1 utils.go:199] ID: 24 Req-ID: pvc-89e116e2-5a4b-44d0-a08e-592a24e6b119 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-89e116e2-5a4b-44d0-a08e-592a24e6b119","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-89e116e2-5a4b-44d0-a08e-592a24e6b119","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}}]}
I0618 01:07:09.664552       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-89e116e2-5a4b-44d0-a08e-592a24e6b119 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0618 01:07:09.686148       1 omap.go:80] ID: 24 Req-ID: pvc-89e116e2-5a4b-44d0-a08e-592a24e6b119 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0618 01:07:09.702598       1 omap.go:159] ID: 24 Req-ID: pvc-89e116e2-5a4b-44d0-a08e-592a24e6b119 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-89e116e2-5a4b-44d0-a08e-592a24e6b119:e46ad694-3c45-43c6-9df6-f663c92fd8be])
I0618 01:07:09.710118       1 omap.go:159] ID: 24 Req-ID: pvc-89e116e2-5a4b-44d0-a08e-592a24e6b119 set omap keys (pool="kube", namespace="", name="csi.volume.e46ad694-3c45-43c6-9df6-f663c92fd8be"): map[csi.imagename:csi-vol-e46ad694-3c45-43c6-9df6-f663c92fd8be csi.volname:pvc-89e116e2-5a4b-44d0-a08e-592a24e6b119 csi.volume.owner:default])
I0618 01:07:09.710161       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-89e116e2-5a4b-44d0-a08e-592a24e6b119 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-e46ad694-3c45-43c6-9df6-f663c92fd8be) and image name (csi-vol-e46ad694-3c45-43c6-9df6-f663c92fd8be) for request name (pvc-89e116e2-5a4b-44d0-a08e-592a24e6b119)
I0618 01:07:09.710258       1 rbd_util.go:423] ID: 24 Req-ID: pvc-89e116e2-5a4b-44d0-a08e-592a24e6b119 rbd: create kube/csi-vol-e46ad694-3c45-43c6-9df6-f663c92fd8be size 5120M (features: [layering]) using mon 199.19.213.128
I0618 01:07:09.710391       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-89e116e2-5a4b-44d0-a08e-592a24e6b119 setting image options on kube/csi-vol-e46ad694-3c45-43c6-9df6-f663c92fd8be
I0618 01:07:09.740387       1 controllerserver.go:763] ID: 24 Req-ID: pvc-89e116e2-5a4b-44d0-a08e-592a24e6b119 created image kube/csi-vol-e46ad694-3c45-43c6-9df6-f663c92fd8be backed for request name pvc-89e116e2-5a4b-44d0-a08e-592a24e6b119
I0618 01:07:09.768106       1 omap.go:159] ID: 24 Req-ID: pvc-89e116e2-5a4b-44d0-a08e-592a24e6b119 set omap keys (pool="kube", namespace="", name="csi.volume.e46ad694-3c45-43c6-9df6-f663c92fd8be"): map[csi.imageid:37ed961c00bc])
I0618 01:07:09.867179       1 utils.go:205] ID: 24 Req-ID: pvc-89e116e2-5a4b-44d0-a08e-592a24e6b119 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-e46ad694-3c45-43c6-9df6-f663c92fd8be","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-e46ad694-3c45-43c6-9df6-f663c92fd8be"}}
I0618 01:07:28.894564       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0618 01:07:28.894636       1 utils.go:199] ID: 25 GRPC request: {}
I0618 01:07:28.894661       1 utils.go:205] ID: 25 GRPC response: {}