I0804 15:21:01.829944       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0804 15:21:01.830045       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0804 15:21:01.830061       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0804 15:21:01.830064       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0804 15:21:01.830067       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0804 15:21:01.830070       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0804 15:21:01.830074       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0804 15:21:01.830076       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0804 15:21:01.830079       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0804 15:21:01.830082       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0804 15:21:01.830715       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0804 15:21:01.830725       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0804 15:21:17.941757       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0804 15:21:17.943095       1 utils.go:199] ID: 1 GRPC request: {}
I0804 15:21:17.943175       1 utils.go:205] ID: 1 GRPC response: {}
I0804 15:21:17.947653       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0804 15:21:17.947696       1 utils.go:199] ID: 2 GRPC request: {}
I0804 15:21:17.947710       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0804 15:21:17.947784       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0804 15:21:17.949779       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0804 15:21:17.949800       1 utils.go:199] ID: 3 GRPC request: {}
I0804 15:21:17.949811       1 utils.go:205] ID: 3 GRPC response: {}
I0804 15:21:17.950391       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0804 15:21:17.950507       1 utils.go:199] ID: 4 GRPC request: {}
I0804 15:21:17.950762       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0804 15:21:17.951760       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0804 15:21:17.951810       1 utils.go:199] ID: 5 GRPC request: {}
I0804 15:21:17.951830       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0804 15:21:17.951948       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}}}]}
I0804 15:21:22.337354       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0804 15:21:22.337570       1 utils.go:199] ID: 6 GRPC request: {}
I0804 15:21:22.337721       1 utils.go:205] ID: 6 GRPC response: {}
I0804 15:21:22.340363       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0804 15:21:22.340403       1 utils.go:199] ID: 7 GRPC request: {}
I0804 15:21:22.340413       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0804 15:21:22.340445       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0804 15:21:22.341949       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0804 15:21:22.342075       1 utils.go:199] ID: 8 GRPC request: {}
I0804 15:21:22.342165       1 utils.go:205] ID: 8 GRPC response: {}
I0804 15:21:22.342776       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0804 15:21:22.342802       1 utils.go:199] ID: 9 GRPC request: {}
I0804 15:21:22.342934       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0804 15:21:22.343477       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0804 15:21:22.343500       1 utils.go:199] ID: 10 GRPC request: {}
I0804 15:21:22.343509       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0804 15:21:22.343593       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}}}]}
I0804 15:21:22.344051       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0804 15:21:22.344076       1 utils.go:199] ID: 11 GRPC request: {}
I0804 15:21:22.344086       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0804 15:21:22.344233       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}}}]}
I0804 15:21:22.344628       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0804 15:21:22.344655       1 utils.go:199] ID: 12 GRPC request: {}
I0804 15:21:22.344661       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0804 15:21:22.344723       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}}}]}
I0804 15:21:27.683624       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0804 15:21:27.683661       1 utils.go:199] ID: 13 GRPC request: {}
I0804 15:21:27.683671       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0804 15:21:27.683698       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0804 15:21:27.685768       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0804 15:21:27.685798       1 utils.go:199] ID: 14 GRPC request: {}
I0804 15:21:27.685817       1 utils.go:205] ID: 14 GRPC response: {}
I0804 15:21:27.686306       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0804 15:21:27.686351       1 utils.go:199] ID: 15 GRPC request: {}
I0804 15:21:27.686361       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0804 15:21:27.686443       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}}}]}
I0804 15:21:32.481259       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0804 15:21:32.481321       1 utils.go:199] ID: 16 GRPC request: {}
I0804 15:21:32.481345       1 utils.go:205] ID: 16 GRPC response: {}
I0804 15:21:32.483453       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0804 15:21:32.483481       1 utils.go:199] ID: 17 GRPC request: {}
I0804 15:21:32.483493       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0804 15:21:32.483523       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0804 15:21:32.485394       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0804 15:21:32.485482       1 utils.go:199] ID: 18 GRPC request: {}
I0804 15:21:32.485534       1 utils.go:205] ID: 18 GRPC response: {}
I0804 15:21:32.486076       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0804 15:21:32.486166       1 utils.go:199] ID: 19 GRPC request: {}
I0804 15:21:32.486396       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0804 15:21:32.487191       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0804 15:21:32.487251       1 utils.go:199] ID: 20 GRPC request: {}
I0804 15:21:32.487273       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0804 15:21:32.487402       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}}}]}
I0804 15:22:32.658135       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0804 15:22:32.658196       1 utils.go:199] ID: 21 GRPC request: {}
I0804 15:22:32.658219       1 utils.go:205] ID: 21 GRPC response: {}
I0804 15:23:32.663494       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0804 15:23:32.663689       1 utils.go:199] ID: 22 GRPC request: {}
I0804 15:23:32.663774       1 utils.go:205] ID: 22 GRPC response: {}
I0804 15:24:32.657285       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0804 15:24:32.657324       1 utils.go:199] ID: 23 GRPC request: {}
I0804 15:24:32.657340       1 utils.go:205] ID: 23 GRPC response: {}
I0804 15:25:20.878592       1 utils.go:198] ID: 24 Req-ID: pvc-9c4e9108-1f8f-4a8d-b6c6-854be2cc6d57 GRPC call: /csi.v1.Controller/CreateVolume
I0804 15:25:20.878986       1 utils.go:199] ID: 24 Req-ID: pvc-9c4e9108-1f8f-4a8d-b6c6-854be2cc6d57 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-9c4e9108-1f8f-4a8d-b6c6-854be2cc6d57","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-9c4e9108-1f8f-4a8d-b6c6-854be2cc6d57","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}}]}
I0804 15:25:20.879290       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-9c4e9108-1f8f-4a8d-b6c6-854be2cc6d57 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0804 15:25:20.898936       1 omap.go:80] ID: 24 Req-ID: pvc-9c4e9108-1f8f-4a8d-b6c6-854be2cc6d57 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0804 15:25:20.916597       1 omap.go:159] ID: 24 Req-ID: pvc-9c4e9108-1f8f-4a8d-b6c6-854be2cc6d57 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-9c4e9108-1f8f-4a8d-b6c6-854be2cc6d57:30d8ab60-39ff-4563-a99f-860709e703f3])
I0804 15:25:20.924173       1 omap.go:159] ID: 24 Req-ID: pvc-9c4e9108-1f8f-4a8d-b6c6-854be2cc6d57 set omap keys (pool="kube", namespace="", name="csi.volume.30d8ab60-39ff-4563-a99f-860709e703f3"): map[csi.imagename:csi-vol-30d8ab60-39ff-4563-a99f-860709e703f3 csi.volname:pvc-9c4e9108-1f8f-4a8d-b6c6-854be2cc6d57 csi.volume.owner:default])
I0804 15:25:20.924313       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-9c4e9108-1f8f-4a8d-b6c6-854be2cc6d57 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-30d8ab60-39ff-4563-a99f-860709e703f3) and image name (csi-vol-30d8ab60-39ff-4563-a99f-860709e703f3) for request name (pvc-9c4e9108-1f8f-4a8d-b6c6-854be2cc6d57)
I0804 15:25:20.924451       1 rbd_util.go:423] ID: 24 Req-ID: pvc-9c4e9108-1f8f-4a8d-b6c6-854be2cc6d57 rbd: create kube/csi-vol-30d8ab60-39ff-4563-a99f-860709e703f3 size 5120M (features: [layering]) using mon 199.19.213.60
I0804 15:25:20.924551       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-9c4e9108-1f8f-4a8d-b6c6-854be2cc6d57 setting image options on kube/csi-vol-30d8ab60-39ff-4563-a99f-860709e703f3
I0804 15:25:20.961384       1 controllerserver.go:763] ID: 24 Req-ID: pvc-9c4e9108-1f8f-4a8d-b6c6-854be2cc6d57 created image kube/csi-vol-30d8ab60-39ff-4563-a99f-860709e703f3 backed for request name pvc-9c4e9108-1f8f-4a8d-b6c6-854be2cc6d57
I0804 15:25:20.998776       1 omap.go:159] ID: 24 Req-ID: pvc-9c4e9108-1f8f-4a8d-b6c6-854be2cc6d57 set omap keys (pool="kube", namespace="", name="csi.volume.30d8ab60-39ff-4563-a99f-860709e703f3"): map[csi.imageid:37f4107c4f02])
I0804 15:25:21.092814       1 utils.go:205] ID: 24 Req-ID: pvc-9c4e9108-1f8f-4a8d-b6c6-854be2cc6d57 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-30d8ab60-39ff-4563-a99f-860709e703f3","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-30d8ab60-39ff-4563-a99f-860709e703f3"}}
I0804 15:25:32.674688       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0804 15:25:32.674750       1 utils.go:199] ID: 25 GRPC request: {}
I0804 15:25:32.674775       1 utils.go:205] ID: 25 GRPC response: {}