I0428 13:55:02.690967       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0428 13:55:02.691275       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0428 13:55:02.691337       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0428 13:55:02.691362       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0428 13:55:02.691382       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0428 13:55:02.691401       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0428 13:55:02.691428       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0428 13:55:02.691458       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0428 13:55:02.691480       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0428 13:55:02.691502       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0428 13:55:02.692640       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0428 13:55:02.692711       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0428 13:55:04.602092       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0428 13:55:04.604188       1 utils.go:199] ID: 1 GRPC request: {}
I0428 13:55:04.604292       1 utils.go:205] ID: 1 GRPC response: {}
I0428 13:55:04.607760       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0428 13:55:04.607915       1 utils.go:199] ID: 2 GRPC request: {}
I0428 13:55:04.607975       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0428 13:55:04.608063       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0428 13:55:04.610444       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0428 13:55:04.610629       1 utils.go:199] ID: 3 GRPC request: {}
I0428 13:55:04.610702       1 utils.go:205] ID: 3 GRPC response: {}
I0428 13:55:04.612587       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0428 13:55:04.612717       1 utils.go:199] ID: 4 GRPC request: {}
I0428 13:55:04.612968       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0428 13:55:04.614036       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0428 13:55:04.614073       1 utils.go:199] ID: 5 GRPC request: {}
I0428 13:55:04.614086       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0428 13:55:04.614218       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}}}]}
I0428 13:55:05.885989       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0428 13:55:05.886092       1 utils.go:199] ID: 6 GRPC request: {}
I0428 13:55:05.886134       1 utils.go:205] ID: 6 GRPC response: {}
I0428 13:55:05.889474       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0428 13:55:05.889503       1 utils.go:199] ID: 7 GRPC request: {}
I0428 13:55:05.889534       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0428 13:55:05.889628       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0428 13:55:05.893596       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0428 13:55:05.893648       1 utils.go:199] ID: 8 GRPC request: {}
I0428 13:55:05.893699       1 utils.go:205] ID: 8 GRPC response: {}
I0428 13:55:05.894478       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0428 13:55:05.894630       1 utils.go:199] ID: 9 GRPC request: {}
I0428 13:55:05.894891       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0428 13:55:05.896053       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0428 13:55:05.896084       1 utils.go:199] ID: 10 GRPC request: {}
I0428 13:55:05.896116       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0428 13:55:05.896485       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}}}]}
I0428 13:55:05.897372       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0428 13:55:05.897436       1 utils.go:199] ID: 11 GRPC request: {}
I0428 13:55:05.897528       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0428 13:55:05.897687       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}}}]}
I0428 13:55:05.898246       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0428 13:55:05.898296       1 utils.go:199] ID: 12 GRPC request: {}
I0428 13:55:05.898334       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0428 13:55:05.898507       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}}}]}
I0428 13:55:07.898344       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0428 13:55:07.898402       1 utils.go:199] ID: 13 GRPC request: {}
I0428 13:55:07.898409       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0428 13:55:07.898433       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0428 13:55:07.900140       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0428 13:55:07.900265       1 utils.go:199] ID: 14 GRPC request: {}
I0428 13:55:07.900303       1 utils.go:205] ID: 14 GRPC response: {}
I0428 13:55:07.900710       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0428 13:55:07.900736       1 utils.go:199] ID: 15 GRPC request: {}
I0428 13:55:07.900746       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0428 13:55:07.900864       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}}}]}
I0428 13:55:09.376700       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0428 13:55:09.376741       1 utils.go:199] ID: 16 GRPC request: {}
I0428 13:55:09.376757       1 utils.go:205] ID: 16 GRPC response: {}
I0428 13:55:09.378918       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0428 13:55:09.378934       1 utils.go:199] ID: 17 GRPC request: {}
I0428 13:55:09.378940       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0428 13:55:09.378960       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0428 13:55:09.382902       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0428 13:55:09.382976       1 utils.go:199] ID: 18 GRPC request: {}
I0428 13:55:09.383038       1 utils.go:205] ID: 18 GRPC response: {}
I0428 13:55:09.384293       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0428 13:55:09.384359       1 utils.go:199] ID: 19 GRPC request: {}
I0428 13:55:09.384470       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0428 13:55:09.386777       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0428 13:55:09.386795       1 utils.go:199] ID: 20 GRPC request: {}
I0428 13:55:09.386801       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0428 13:55:09.386872       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}}}]}
I0428 13:56:09.648465       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0428 13:56:09.648677       1 utils.go:199] ID: 21 GRPC request: {}
I0428 13:56:09.648770       1 utils.go:205] ID: 21 GRPC response: {}
I0428 13:57:09.601922       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0428 13:57:09.602048       1 utils.go:199] ID: 22 GRPC request: {}
I0428 13:57:09.602105       1 utils.go:205] ID: 22 GRPC response: {}
I0428 13:58:09.598851       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0428 13:58:09.598955       1 utils.go:199] ID: 23 GRPC request: {}
I0428 13:58:09.599001       1 utils.go:205] ID: 23 GRPC response: {}
I0428 13:58:19.853560       1 utils.go:198] ID: 24 Req-ID: pvc-f29b5259-02d0-460d-8c84-3c58ad1da89b GRPC call: /csi.v1.Controller/CreateVolume
I0428 13:58:19.854125       1 utils.go:199] ID: 24 Req-ID: pvc-f29b5259-02d0-460d-8c84-3c58ad1da89b GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-f29b5259-02d0-460d-8c84-3c58ad1da89b","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-f29b5259-02d0-460d-8c84-3c58ad1da89b","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}}]}
I0428 13:58:19.854402       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-f29b5259-02d0-460d-8c84-3c58ad1da89b setting disableInUseChecks: false image features: [layering] mounter: rbd
E0428 13:58:19.875651       1 omap.go:80] ID: 24 Req-ID: pvc-f29b5259-02d0-460d-8c84-3c58ad1da89b omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0428 13:58:19.952280       1 omap.go:159] ID: 24 Req-ID: pvc-f29b5259-02d0-460d-8c84-3c58ad1da89b set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-f29b5259-02d0-460d-8c84-3c58ad1da89b:fd3b1931-9f38-45c1-95fa-7f068a733b96])
I0428 13:58:19.967195       1 omap.go:159] ID: 24 Req-ID: pvc-f29b5259-02d0-460d-8c84-3c58ad1da89b set omap keys (pool="kube", namespace="", name="csi.volume.fd3b1931-9f38-45c1-95fa-7f068a733b96"): map[csi.imagename:csi-vol-fd3b1931-9f38-45c1-95fa-7f068a733b96 csi.volname:pvc-f29b5259-02d0-460d-8c84-3c58ad1da89b csi.volume.owner:default])
I0428 13:58:19.967276       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-f29b5259-02d0-460d-8c84-3c58ad1da89b generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-fd3b1931-9f38-45c1-95fa-7f068a733b96) and image name (csi-vol-fd3b1931-9f38-45c1-95fa-7f068a733b96) for request name (pvc-f29b5259-02d0-460d-8c84-3c58ad1da89b)
I0428 13:58:19.967410       1 rbd_util.go:423] ID: 24 Req-ID: pvc-f29b5259-02d0-460d-8c84-3c58ad1da89b rbd: create kube/csi-vol-fd3b1931-9f38-45c1-95fa-7f068a733b96 size 5120M (features: [layering]) using mon 199.19.213.207
I0428 13:58:19.967632       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-f29b5259-02d0-460d-8c84-3c58ad1da89b setting image options on kube/csi-vol-fd3b1931-9f38-45c1-95fa-7f068a733b96
I0428 13:58:21.501841       1 controllerserver.go:763] ID: 24 Req-ID: pvc-f29b5259-02d0-460d-8c84-3c58ad1da89b created image kube/csi-vol-fd3b1931-9f38-45c1-95fa-7f068a733b96 backed for request name pvc-f29b5259-02d0-460d-8c84-3c58ad1da89b
I0428 13:58:21.540607       1 omap.go:159] ID: 24 Req-ID: pvc-f29b5259-02d0-460d-8c84-3c58ad1da89b set omap keys (pool="kube", namespace="", name="csi.volume.fd3b1931-9f38-45c1-95fa-7f068a733b96"): map[csi.imageid:37d734af421])
I0428 13:58:21.640399       1 utils.go:205] ID: 24 Req-ID: pvc-f29b5259-02d0-460d-8c84-3c58ad1da89b GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-fd3b1931-9f38-45c1-95fa-7f068a733b96","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-fd3b1931-9f38-45c1-95fa-7f068a733b96"}}
I0428 13:59:09.614478       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0428 13:59:09.614669       1 utils.go:199] ID: 25 GRPC request: {}
I0428 13:59:09.614854       1 utils.go:205] ID: 25 GRPC response: {}