I0603 17:49:06.642425       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0603 17:49:06.642595       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0603 17:49:06.642640       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0603 17:49:06.642645       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0603 17:49:06.642648       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0603 17:49:06.642652       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0603 17:49:06.642657       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0603 17:49:06.642661       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0603 17:49:06.642664       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0603 17:49:06.642667       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0603 17:49:06.643180       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0603 17:49:06.643203       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0603 17:49:08.598448       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0603 17:49:08.600539       1 utils.go:199] ID: 1 GRPC request: {}
I0603 17:49:08.600632       1 utils.go:205] ID: 1 GRPC response: {}
I0603 17:49:08.602681       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0603 17:49:08.602757       1 utils.go:199] ID: 2 GRPC request: {}
I0603 17:49:08.602774       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0603 17:49:08.602855       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0603 17:49:08.604300       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0603 17:49:08.604349       1 utils.go:199] ID: 3 GRPC request: {}
I0603 17:49:08.604370       1 utils.go:205] ID: 3 GRPC response: {}
I0603 17:49:08.604736       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0603 17:49:08.604815       1 utils.go:199] ID: 4 GRPC request: {}
I0603 17:49:08.605014       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0603 17:49:08.606513       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0603 17:49:08.606563       1 utils.go:199] ID: 5 GRPC request: {}
I0603 17:49:08.606576       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0603 17:49:08.606671       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}}}]}
I0603 17:49:09.830790       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0603 17:49:09.830874       1 utils.go:199] ID: 6 GRPC request: {}
I0603 17:49:09.830906       1 utils.go:205] ID: 6 GRPC response: {}
I0603 17:49:09.834191       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0603 17:49:09.834223       1 utils.go:199] ID: 7 GRPC request: {}
I0603 17:49:09.834234       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0603 17:49:09.834271       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0603 17:49:09.835639       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0603 17:49:09.835667       1 utils.go:199] ID: 8 GRPC request: {}
I0603 17:49:09.835689       1 utils.go:205] ID: 8 GRPC response: {}
I0603 17:49:09.836132       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0603 17:49:09.836170       1 utils.go:199] ID: 9 GRPC request: {}
I0603 17:49:09.836284       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0603 17:49:09.836853       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0603 17:49:09.836903       1 utils.go:199] ID: 10 GRPC request: {}
I0603 17:49:09.836920       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0603 17:49:09.837128       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}}}]}
I0603 17:49:09.837659       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0603 17:49:09.837683       1 utils.go:199] ID: 11 GRPC request: {}
I0603 17:49:09.837693       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0603 17:49:09.837817       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}}}]}
I0603 17:49:09.838264       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0603 17:49:09.838288       1 utils.go:199] ID: 12 GRPC request: {}
I0603 17:49:09.838296       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0603 17:49:09.838374       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}}}]}
I0603 17:49:12.079747       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0603 17:49:12.079789       1 utils.go:199] ID: 13 GRPC request: {}
I0603 17:49:12.079884       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0603 17:49:12.079955       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0603 17:49:12.084229       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0603 17:49:12.084364       1 utils.go:199] ID: 14 GRPC request: {}
I0603 17:49:12.084444       1 utils.go:205] ID: 14 GRPC response: {}
I0603 17:49:12.085288       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0603 17:49:12.085394       1 utils.go:199] ID: 15 GRPC request: {}
I0603 17:49:12.085415       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0603 17:49:12.085806       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}}}]}
I0603 17:49:13.715352       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0603 17:49:13.715569       1 utils.go:199] ID: 16 GRPC request: {}
I0603 17:49:13.715751       1 utils.go:205] ID: 16 GRPC response: {}
I0603 17:49:13.720394       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0603 17:49:13.720426       1 utils.go:199] ID: 17 GRPC request: {}
I0603 17:49:13.720437       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0603 17:49:13.720492       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0603 17:49:13.723365       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0603 17:49:13.723429       1 utils.go:199] ID: 18 GRPC request: {}
I0603 17:49:13.723457       1 utils.go:205] ID: 18 GRPC response: {}
I0603 17:49:13.723786       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0603 17:49:13.723832       1 utils.go:199] ID: 19 GRPC request: {}
I0603 17:49:13.724042       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0603 17:49:13.724810       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0603 17:49:13.724876       1 utils.go:199] ID: 20 GRPC request: {}
I0603 17:49:13.724916       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0603 17:49:13.725094       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}}}]}
I0603 17:50:13.974199       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0603 17:50:13.974256       1 utils.go:199] ID: 21 GRPC request: {}
I0603 17:50:13.974276       1 utils.go:205] ID: 21 GRPC response: {}
I0603 17:51:13.938463       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0603 17:51:13.938620       1 utils.go:199] ID: 22 GRPC request: {}
I0603 17:51:13.938657       1 utils.go:205] ID: 22 GRPC response: {}
I0603 17:52:13.935247       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0603 17:52:13.935326       1 utils.go:199] ID: 23 GRPC request: {}
I0603 17:52:13.935355       1 utils.go:205] ID: 23 GRPC response: {}
I0603 17:53:02.308762       1 utils.go:198] ID: 24 Req-ID: pvc-997196c8-fef2-46a7-b954-c5897ce619b3 GRPC call: /csi.v1.Controller/CreateVolume
I0603 17:53:02.309286       1 utils.go:199] ID: 24 Req-ID: pvc-997196c8-fef2-46a7-b954-c5897ce619b3 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-997196c8-fef2-46a7-b954-c5897ce619b3","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-997196c8-fef2-46a7-b954-c5897ce619b3","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}}]}
I0603 17:53:02.309528       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-997196c8-fef2-46a7-b954-c5897ce619b3 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0603 17:53:02.337724       1 omap.go:80] ID: 24 Req-ID: pvc-997196c8-fef2-46a7-b954-c5897ce619b3 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0603 17:53:02.351753       1 omap.go:159] ID: 24 Req-ID: pvc-997196c8-fef2-46a7-b954-c5897ce619b3 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-997196c8-fef2-46a7-b954-c5897ce619b3:3c75afe8-7e3e-41ac-95be-3a54d4e233f1])
I0603 17:53:02.358737       1 omap.go:159] ID: 24 Req-ID: pvc-997196c8-fef2-46a7-b954-c5897ce619b3 set omap keys (pool="kube", namespace="", name="csi.volume.3c75afe8-7e3e-41ac-95be-3a54d4e233f1"): map[csi.imagename:csi-vol-3c75afe8-7e3e-41ac-95be-3a54d4e233f1 csi.volname:pvc-997196c8-fef2-46a7-b954-c5897ce619b3 csi.volume.owner:default])
I0603 17:53:02.358775       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-997196c8-fef2-46a7-b954-c5897ce619b3 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-3c75afe8-7e3e-41ac-95be-3a54d4e233f1) and image name (csi-vol-3c75afe8-7e3e-41ac-95be-3a54d4e233f1) for request name (pvc-997196c8-fef2-46a7-b954-c5897ce619b3)
I0603 17:53:02.358918       1 rbd_util.go:423] ID: 24 Req-ID: pvc-997196c8-fef2-46a7-b954-c5897ce619b3 rbd: create kube/csi-vol-3c75afe8-7e3e-41ac-95be-3a54d4e233f1 size 5120M (features: [layering]) using mon 199.204.45.65
I0603 17:53:02.359012       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-997196c8-fef2-46a7-b954-c5897ce619b3 setting image options on kube/csi-vol-3c75afe8-7e3e-41ac-95be-3a54d4e233f1
I0603 17:53:02.393414       1 controllerserver.go:763] ID: 24 Req-ID: pvc-997196c8-fef2-46a7-b954-c5897ce619b3 created image kube/csi-vol-3c75afe8-7e3e-41ac-95be-3a54d4e233f1 backed for request name pvc-997196c8-fef2-46a7-b954-c5897ce619b3
I0603 17:53:02.425608       1 omap.go:159] ID: 24 Req-ID: pvc-997196c8-fef2-46a7-b954-c5897ce619b3 set omap keys (pool="kube", namespace="", name="csi.volume.3c75afe8-7e3e-41ac-95be-3a54d4e233f1"): map[csi.imageid:37edff67126f])
I0603 17:53:02.533020       1 utils.go:205] ID: 24 Req-ID: pvc-997196c8-fef2-46a7-b954-c5897ce619b3 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-3c75afe8-7e3e-41ac-95be-3a54d4e233f1","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-3c75afe8-7e3e-41ac-95be-3a54d4e233f1"}}
I0603 17:53:13.946530       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0603 17:53:13.946794       1 utils.go:199] ID: 25 GRPC request: {}
I0603 17:53:13.946821       1 utils.go:205] ID: 25 GRPC response: {}