I0727 10:55:20.393592       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0727 10:55:20.393704       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0727 10:55:20.393717       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0727 10:55:20.393721       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0727 10:55:20.393725       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0727 10:55:20.393729       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0727 10:55:20.393734       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0727 10:55:20.393737       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0727 10:55:20.393741       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0727 10:55:20.393744       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0727 10:55:20.393970       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0727 10:55:20.393985       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0727 10:55:22.783111       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0727 10:55:22.784206       1 utils.go:199] ID: 1 GRPC request: {}
I0727 10:55:22.784259       1 utils.go:205] ID: 1 GRPC response: {}
I0727 10:55:22.785993       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0727 10:55:22.786033       1 utils.go:199] ID: 2 GRPC request: {}
I0727 10:55:22.786050       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0727 10:55:22.786083       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0727 10:55:22.788820       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0727 10:55:22.788855       1 utils.go:199] ID: 3 GRPC request: {}
I0727 10:55:22.788864       1 utils.go:205] ID: 3 GRPC response: {}
I0727 10:55:22.789524       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0727 10:55:22.789661       1 utils.go:199] ID: 4 GRPC request: {}
I0727 10:55:22.789951       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0727 10:55:22.790817       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0727 10:55:22.790924       1 utils.go:199] ID: 5 GRPC request: {}
I0727 10:55:22.790936       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0727 10:55:22.791075       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}}}]}
I0727 10:55:24.271504       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0727 10:55:24.271536       1 utils.go:199] ID: 6 GRPC request: {}
I0727 10:55:24.271551       1 utils.go:205] ID: 6 GRPC response: {}
I0727 10:55:24.273835       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0727 10:55:24.273850       1 utils.go:199] ID: 7 GRPC request: {}
I0727 10:55:24.273857       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0727 10:55:24.273879       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0727 10:55:24.275376       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0727 10:55:24.275412       1 utils.go:199] ID: 8 GRPC request: {}
I0727 10:55:24.275429       1 utils.go:205] ID: 8 GRPC response: {}
I0727 10:55:24.275714       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0727 10:55:24.275747       1 utils.go:199] ID: 9 GRPC request: {}
I0727 10:55:24.275859       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0727 10:55:24.276453       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0727 10:55:24.276480       1 utils.go:199] ID: 10 GRPC request: {}
I0727 10:55:24.276597       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0727 10:55:24.276708       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}}}]}
I0727 10:55:24.280109       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0727 10:55:24.280133       1 utils.go:199] ID: 11 GRPC request: {}
I0727 10:55:24.280240       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0727 10:55:24.280350       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}}}]}
I0727 10:55:24.280926       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0727 10:55:24.280949       1 utils.go:199] ID: 12 GRPC request: {}
I0727 10:55:24.280958       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0727 10:55:24.281034       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}}}]}
I0727 10:55:26.143485       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0727 10:55:26.143521       1 utils.go:199] ID: 13 GRPC request: {}
I0727 10:55:26.143666       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0727 10:55:26.143722       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0727 10:55:26.147883       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0727 10:55:26.147930       1 utils.go:199] ID: 14 GRPC request: {}
I0727 10:55:26.147999       1 utils.go:205] ID: 14 GRPC response: {}
I0727 10:55:26.148608       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0727 10:55:26.148633       1 utils.go:199] ID: 15 GRPC request: {}
I0727 10:55:26.148642       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0727 10:55:26.148727       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}}}]}
I0727 10:55:27.481610       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0727 10:55:27.481655       1 utils.go:199] ID: 16 GRPC request: {}
I0727 10:55:27.481676       1 utils.go:205] ID: 16 GRPC response: {}
I0727 10:55:27.484376       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0727 10:55:27.484447       1 utils.go:199] ID: 17 GRPC request: {}
I0727 10:55:27.484626       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0727 10:55:27.484706       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0727 10:55:27.489766       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0727 10:55:27.489786       1 utils.go:199] ID: 18 GRPC request: {}
I0727 10:55:27.489801       1 utils.go:205] ID: 18 GRPC response: {}
I0727 10:55:27.491243       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0727 10:55:27.491278       1 utils.go:199] ID: 19 GRPC request: {}
I0727 10:55:27.491387       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0727 10:55:27.493228       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0727 10:55:27.493268       1 utils.go:199] ID: 20 GRPC request: {}
I0727 10:55:27.493279       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0727 10:55:27.493375       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}}}]}
I0727 10:56:27.714027       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0727 10:56:27.714063       1 utils.go:199] ID: 21 GRPC request: {}
I0727 10:56:27.714078       1 utils.go:205] ID: 21 GRPC response: {}
I0727 10:57:27.655863       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0727 10:57:27.655991       1 utils.go:199] ID: 22 GRPC request: {}
I0727 10:57:27.656074       1 utils.go:205] ID: 22 GRPC response: {}
I0727 10:58:27.655686       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0727 10:58:27.655753       1 utils.go:199] ID: 23 GRPC request: {}
I0727 10:58:27.655783       1 utils.go:205] ID: 23 GRPC response: {}
I0727 10:59:22.509528       1 utils.go:198] ID: 24 Req-ID: pvc-f8a60ca4-e821-4cb1-a671-ee432c54199b GRPC call: /csi.v1.Controller/CreateVolume
I0727 10:59:22.510238       1 utils.go:199] ID: 24 Req-ID: pvc-f8a60ca4-e821-4cb1-a671-ee432c54199b GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-f8a60ca4-e821-4cb1-a671-ee432c54199b","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-f8a60ca4-e821-4cb1-a671-ee432c54199b","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}}]}
I0727 10:59:22.510669       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-f8a60ca4-e821-4cb1-a671-ee432c54199b setting disableInUseChecks: false image features: [layering] mounter: rbd
E0727 10:59:22.527045       1 omap.go:80] ID: 24 Req-ID: pvc-f8a60ca4-e821-4cb1-a671-ee432c54199b omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0727 10:59:22.540639       1 omap.go:159] ID: 24 Req-ID: pvc-f8a60ca4-e821-4cb1-a671-ee432c54199b set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-f8a60ca4-e821-4cb1-a671-ee432c54199b:a152fc00-d1ea-4d40-94b9-bd276aa6703a])
I0727 10:59:22.547977       1 omap.go:159] ID: 24 Req-ID: pvc-f8a60ca4-e821-4cb1-a671-ee432c54199b set omap keys (pool="kube", namespace="", name="csi.volume.a152fc00-d1ea-4d40-94b9-bd276aa6703a"): map[csi.imagename:csi-vol-a152fc00-d1ea-4d40-94b9-bd276aa6703a csi.volname:pvc-f8a60ca4-e821-4cb1-a671-ee432c54199b csi.volume.owner:default])
I0727 10:59:22.548002       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-f8a60ca4-e821-4cb1-a671-ee432c54199b generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-a152fc00-d1ea-4d40-94b9-bd276aa6703a) and image name (csi-vol-a152fc00-d1ea-4d40-94b9-bd276aa6703a) for request name (pvc-f8a60ca4-e821-4cb1-a671-ee432c54199b)
I0727 10:59:22.548140       1 rbd_util.go:423] ID: 24 Req-ID: pvc-f8a60ca4-e821-4cb1-a671-ee432c54199b rbd: create kube/csi-vol-a152fc00-d1ea-4d40-94b9-bd276aa6703a size 5120M (features: [layering]) using mon 199.19.213.21
I0727 10:59:22.548218       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-f8a60ca4-e821-4cb1-a671-ee432c54199b setting image options on kube/csi-vol-a152fc00-d1ea-4d40-94b9-bd276aa6703a
I0727 10:59:22.577936       1 controllerserver.go:763] ID: 24 Req-ID: pvc-f8a60ca4-e821-4cb1-a671-ee432c54199b created image kube/csi-vol-a152fc00-d1ea-4d40-94b9-bd276aa6703a backed for request name pvc-f8a60ca4-e821-4cb1-a671-ee432c54199b
I0727 10:59:22.607964       1 omap.go:159] ID: 24 Req-ID: pvc-f8a60ca4-e821-4cb1-a671-ee432c54199b set omap keys (pool="kube", namespace="", name="csi.volume.a152fc00-d1ea-4d40-94b9-bd276aa6703a"): map[csi.imageid:37f4e8f649ed])
I0727 10:59:22.689453       1 utils.go:205] ID: 24 Req-ID: pvc-f8a60ca4-e821-4cb1-a671-ee432c54199b GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-a152fc00-d1ea-4d40-94b9-bd276aa6703a","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-a152fc00-d1ea-4d40-94b9-bd276aa6703a"}}
I0727 10:59:27.667373       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0727 10:59:27.667443       1 utils.go:199] ID: 25 GRPC request: {}
I0727 10:59:27.667469       1 utils.go:205] ID: 25 GRPC response: {}