I0813 08:04:27.696674       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0813 08:04:27.696794       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0813 08:04:27.696811       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0813 08:04:27.696815       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0813 08:04:27.696819       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0813 08:04:27.696822       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0813 08:04:27.696826       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0813 08:04:27.696828       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0813 08:04:27.696831       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0813 08:04:27.696834       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0813 08:04:27.697121       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0813 08:04:27.697142       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0813 08:04:29.940636       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0813 08:04:29.942903       1 utils.go:199] ID: 1 GRPC request: {}
I0813 08:04:29.943025       1 utils.go:205] ID: 1 GRPC response: {}
I0813 08:04:29.945457       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0813 08:04:29.945545       1 utils.go:199] ID: 2 GRPC request: {}
I0813 08:04:29.945596       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0813 08:04:29.945755       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0813 08:04:29.949485       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0813 08:04:29.949517       1 utils.go:199] ID: 3 GRPC request: {}
I0813 08:04:29.949532       1 utils.go:205] ID: 3 GRPC response: {}
I0813 08:04:29.949910       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0813 08:04:29.949963       1 utils.go:199] ID: 4 GRPC request: {}
I0813 08:04:29.950389       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0813 08:04:29.951770       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0813 08:04:29.951826       1 utils.go:199] ID: 5 GRPC request: {}
I0813 08:04:29.951837       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0813 08:04:29.951972       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}}}]}
I0813 08:04:31.331210       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0813 08:04:31.331265       1 utils.go:199] ID: 6 GRPC request: {}
I0813 08:04:31.331294       1 utils.go:205] ID: 6 GRPC response: {}
I0813 08:04:31.333432       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0813 08:04:31.333474       1 utils.go:199] ID: 7 GRPC request: {}
I0813 08:04:31.333483       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0813 08:04:31.333510       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0813 08:04:31.335793       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0813 08:04:31.335821       1 utils.go:199] ID: 8 GRPC request: {}
I0813 08:04:31.335908       1 utils.go:205] ID: 8 GRPC response: {}
I0813 08:04:31.336441       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0813 08:04:31.336461       1 utils.go:199] ID: 9 GRPC request: {}
I0813 08:04:31.336633       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0813 08:04:31.337452       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0813 08:04:31.337483       1 utils.go:199] ID: 10 GRPC request: {}
I0813 08:04:31.337563       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0813 08:04:31.337742       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}}}]}
I0813 08:04:31.338284       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0813 08:04:31.338304       1 utils.go:199] ID: 11 GRPC request: {}
I0813 08:04:31.338310       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0813 08:04:31.338364       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}}}]}
I0813 08:04:31.338728       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0813 08:04:31.338748       1 utils.go:199] ID: 12 GRPC request: {}
I0813 08:04:31.338754       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0813 08:04:31.338817       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}}}]}
I0813 08:04:32.687384       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0813 08:04:32.687417       1 utils.go:199] ID: 13 GRPC request: {}
I0813 08:04:32.687422       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0813 08:04:32.687444       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0813 08:04:32.692837       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0813 08:04:32.692875       1 utils.go:199] ID: 14 GRPC request: {}
I0813 08:04:32.692897       1 utils.go:205] ID: 14 GRPC response: {}
I0813 08:04:32.693548       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0813 08:04:32.693588       1 utils.go:199] ID: 15 GRPC request: {}
I0813 08:04:32.693596       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0813 08:04:32.693682       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}}}]}
I0813 08:04:34.084905       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0813 08:04:34.084937       1 utils.go:199] ID: 16 GRPC request: {}
I0813 08:04:34.084950       1 utils.go:205] ID: 16 GRPC response: {}
I0813 08:04:34.087136       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0813 08:04:34.087155       1 utils.go:199] ID: 17 GRPC request: {}
I0813 08:04:34.087161       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0813 08:04:34.087179       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0813 08:04:34.089372       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0813 08:04:34.089386       1 utils.go:199] ID: 18 GRPC request: {}
I0813 08:04:34.089394       1 utils.go:205] ID: 18 GRPC response: {}
I0813 08:04:34.089645       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0813 08:04:34.089663       1 utils.go:199] ID: 19 GRPC request: {}
I0813 08:04:34.089724       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0813 08:04:34.090091       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0813 08:04:34.090111       1 utils.go:199] ID: 20 GRPC request: {}
I0813 08:04:34.090117       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0813 08:04:34.090163       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}}}]}
I0813 08:05:34.290409       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0813 08:05:34.290471       1 utils.go:199] ID: 21 GRPC request: {}
I0813 08:05:34.290507       1 utils.go:205] ID: 21 GRPC response: {}
I0813 08:06:34.287487       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0813 08:06:34.288075       1 utils.go:199] ID: 22 GRPC request: {}
I0813 08:06:34.288172       1 utils.go:205] ID: 22 GRPC response: {}
I0813 08:07:34.286419       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0813 08:07:34.286515       1 utils.go:199] ID: 23 GRPC request: {}
I0813 08:07:34.286541       1 utils.go:205] ID: 23 GRPC response: {}
I0813 08:07:48.567612       1 utils.go:198] ID: 24 Req-ID: pvc-8ecfb5cb-8b55-4831-b902-107acb2b3b17 GRPC call: /csi.v1.Controller/CreateVolume
I0813 08:07:48.568012       1 utils.go:199] ID: 24 Req-ID: pvc-8ecfb5cb-8b55-4831-b902-107acb2b3b17 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-8ecfb5cb-8b55-4831-b902-107acb2b3b17","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-8ecfb5cb-8b55-4831-b902-107acb2b3b17","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}}]}
I0813 08:07:48.568275       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-8ecfb5cb-8b55-4831-b902-107acb2b3b17 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0813 08:07:48.600438       1 omap.go:80] ID: 24 Req-ID: pvc-8ecfb5cb-8b55-4831-b902-107acb2b3b17 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0813 08:07:48.610309       1 omap.go:159] ID: 24 Req-ID: pvc-8ecfb5cb-8b55-4831-b902-107acb2b3b17 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-8ecfb5cb-8b55-4831-b902-107acb2b3b17:4d5a56e6-caa9-4b70-9244-8e18b5b1b0e0])
I0813 08:07:48.615863       1 omap.go:159] ID: 24 Req-ID: pvc-8ecfb5cb-8b55-4831-b902-107acb2b3b17 set omap keys (pool="kube", namespace="", name="csi.volume.4d5a56e6-caa9-4b70-9244-8e18b5b1b0e0"): map[csi.imagename:csi-vol-4d5a56e6-caa9-4b70-9244-8e18b5b1b0e0 csi.volname:pvc-8ecfb5cb-8b55-4831-b902-107acb2b3b17 csi.volume.owner:default])
I0813 08:07:48.615926       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-8ecfb5cb-8b55-4831-b902-107acb2b3b17 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-4d5a56e6-caa9-4b70-9244-8e18b5b1b0e0) and image name (csi-vol-4d5a56e6-caa9-4b70-9244-8e18b5b1b0e0) for request name (pvc-8ecfb5cb-8b55-4831-b902-107acb2b3b17)
I0813 08:07:48.616029       1 rbd_util.go:423] ID: 24 Req-ID: pvc-8ecfb5cb-8b55-4831-b902-107acb2b3b17 rbd: create kube/csi-vol-4d5a56e6-caa9-4b70-9244-8e18b5b1b0e0 size 5120M (features: [layering]) using mon 199.19.213.217
I0813 08:07:48.616118       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-8ecfb5cb-8b55-4831-b902-107acb2b3b17 setting image options on kube/csi-vol-4d5a56e6-caa9-4b70-9244-8e18b5b1b0e0
I0813 08:07:48.648267       1 controllerserver.go:763] ID: 24 Req-ID: pvc-8ecfb5cb-8b55-4831-b902-107acb2b3b17 created image kube/csi-vol-4d5a56e6-caa9-4b70-9244-8e18b5b1b0e0 backed for request name pvc-8ecfb5cb-8b55-4831-b902-107acb2b3b17
I0813 08:07:48.674852       1 omap.go:159] ID: 24 Req-ID: pvc-8ecfb5cb-8b55-4831-b902-107acb2b3b17 set omap keys (pool="kube", namespace="", name="csi.volume.4d5a56e6-caa9-4b70-9244-8e18b5b1b0e0"): map[csi.imageid:3804ae8444b4])
I0813 08:07:48.750836       1 utils.go:205] ID: 24 Req-ID: pvc-8ecfb5cb-8b55-4831-b902-107acb2b3b17 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-4d5a56e6-caa9-4b70-9244-8e18b5b1b0e0","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-4d5a56e6-caa9-4b70-9244-8e18b5b1b0e0"}}
I0813 08:08:34.308180       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0813 08:08:34.308238       1 utils.go:199] ID: 25 GRPC request: {}
I0813 08:08:34.308307       1 utils.go:205] ID: 25 GRPC response: {}