I0725 10:41:50.190717       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0725 10:41:50.190848       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0725 10:41:50.190861       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0725 10:41:50.190869       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0725 10:41:50.190872       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0725 10:41:50.190875       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0725 10:41:50.190879       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0725 10:41:50.190882       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0725 10:41:50.190885       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0725 10:41:50.190888       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0725 10:41:50.191150       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0725 10:41:50.191184       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0725 10:41:53.157500       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0725 10:41:53.159785       1 utils.go:199] ID: 1 GRPC request: {}
I0725 10:41:53.159874       1 utils.go:205] ID: 1 GRPC response: {}
I0725 10:41:53.166435       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0725 10:41:53.166632       1 utils.go:199] ID: 2 GRPC request: {}
I0725 10:41:53.166692       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0725 10:41:53.166774       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0725 10:41:53.168957       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0725 10:41:53.169040       1 utils.go:199] ID: 3 GRPC request: {}
I0725 10:41:53.170118       1 utils.go:205] ID: 3 GRPC response: {}
I0725 10:41:53.172114       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0725 10:41:53.172166       1 utils.go:199] ID: 4 GRPC request: {}
I0725 10:41:53.172314       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0725 10:41:53.173271       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0725 10:41:53.173446       1 utils.go:199] ID: 5 GRPC request: {}
I0725 10:41:53.173493       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0725 10:41:53.173781       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}}}]}
I0725 10:41:56.862691       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0725 10:41:56.862726       1 utils.go:199] ID: 6 GRPC request: {}
I0725 10:41:56.862740       1 utils.go:205] ID: 6 GRPC response: {}
I0725 10:41:56.864195       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0725 10:41:56.864216       1 utils.go:199] ID: 7 GRPC request: {}
I0725 10:41:56.864223       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0725 10:41:56.864244       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0725 10:41:56.866061       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0725 10:41:56.866087       1 utils.go:199] ID: 8 GRPC request: {}
I0725 10:41:56.866102       1 utils.go:205] ID: 8 GRPC response: {}
I0725 10:41:56.867026       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0725 10:41:56.867165       1 utils.go:199] ID: 9 GRPC request: {}
I0725 10:41:56.867319       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0725 10:41:56.868567       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0725 10:41:56.868589       1 utils.go:199] ID: 10 GRPC request: {}
I0725 10:41:56.868597       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0725 10:41:56.868751       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}}}]}
I0725 10:41:56.869419       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0725 10:41:56.869527       1 utils.go:199] ID: 11 GRPC request: {}
I0725 10:41:56.869544       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0725 10:41:56.869664       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}}}]}
I0725 10:41:56.870060       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0725 10:41:56.870193       1 utils.go:199] ID: 12 GRPC request: {}
I0725 10:41:56.870223       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0725 10:41:56.870350       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}}}]}
I0725 10:41:58.095302       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0725 10:41:58.095687       1 utils.go:199] ID: 13 GRPC request: {}
I0725 10:41:58.095701       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0725 10:41:58.095722       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0725 10:41:58.100778       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0725 10:41:58.100875       1 utils.go:199] ID: 14 GRPC request: {}
I0725 10:41:58.100925       1 utils.go:205] ID: 14 GRPC response: {}
I0725 10:41:58.101464       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0725 10:41:58.101486       1 utils.go:199] ID: 15 GRPC request: {}
I0725 10:41:58.101494       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0725 10:41:58.101580       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}}}]}
I0725 10:41:59.235493       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0725 10:41:59.235551       1 utils.go:199] ID: 16 GRPC request: {}
I0725 10:41:59.235625       1 utils.go:205] ID: 16 GRPC response: {}
I0725 10:41:59.237738       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0725 10:41:59.237775       1 utils.go:199] ID: 17 GRPC request: {}
I0725 10:41:59.237784       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0725 10:41:59.237855       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0725 10:41:59.239578       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0725 10:41:59.239613       1 utils.go:199] ID: 18 GRPC request: {}
I0725 10:41:59.239664       1 utils.go:205] ID: 18 GRPC response: {}
I0725 10:41:59.240149       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0725 10:41:59.240201       1 utils.go:199] ID: 19 GRPC request: {}
I0725 10:41:59.240333       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0725 10:41:59.240973       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0725 10:41:59.241021       1 utils.go:199] ID: 20 GRPC request: {}
I0725 10:41:59.241037       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0725 10:41:59.241310       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}}}]}
I0725 10:42:59.448749       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0725 10:42:59.448798       1 utils.go:199] ID: 21 GRPC request: {}
I0725 10:42:59.448819       1 utils.go:205] ID: 21 GRPC response: {}
I0725 10:43:59.402151       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0725 10:43:59.403015       1 utils.go:199] ID: 22 GRPC request: {}
I0725 10:43:59.403100       1 utils.go:205] ID: 22 GRPC response: {}
I0725 10:44:59.444824       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0725 10:44:59.444887       1 utils.go:199] ID: 23 GRPC request: {}
I0725 10:44:59.444917       1 utils.go:205] ID: 23 GRPC response: {}
I0725 10:45:59.415100       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0725 10:45:59.415421       1 utils.go:199] ID: 24 GRPC request: {}
I0725 10:45:59.415465       1 utils.go:205] ID: 24 GRPC response: {}
I0725 10:46:49.782394       1 utils.go:198] ID: 25 Req-ID: pvc-e1933cbb-4c98-49e6-938b-dbbde73ab219 GRPC call: /csi.v1.Controller/CreateVolume
I0725 10:46:49.782800       1 utils.go:199] ID: 25 Req-ID: pvc-e1933cbb-4c98-49e6-938b-dbbde73ab219 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-e1933cbb-4c98-49e6-938b-dbbde73ab219","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-e1933cbb-4c98-49e6-938b-dbbde73ab219","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}}]}
I0725 10:46:49.783124       1 rbd_util.go:1315] ID: 25 Req-ID: pvc-e1933cbb-4c98-49e6-938b-dbbde73ab219 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0725 10:46:49.799592       1 omap.go:80] ID: 25 Req-ID: pvc-e1933cbb-4c98-49e6-938b-dbbde73ab219 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0725 10:46:49.815197       1 omap.go:159] ID: 25 Req-ID: pvc-e1933cbb-4c98-49e6-938b-dbbde73ab219 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-e1933cbb-4c98-49e6-938b-dbbde73ab219:13c226de-5478-46e1-8ff9-1c75dc45a882])
I0725 10:46:49.830597       1 omap.go:159] ID: 25 Req-ID: pvc-e1933cbb-4c98-49e6-938b-dbbde73ab219 set omap keys (pool="kube", namespace="", name="csi.volume.13c226de-5478-46e1-8ff9-1c75dc45a882"): map[csi.imagename:csi-vol-13c226de-5478-46e1-8ff9-1c75dc45a882 csi.volname:pvc-e1933cbb-4c98-49e6-938b-dbbde73ab219 csi.volume.owner:default])
I0725 10:46:49.830791       1 rbd_journal.go:491] ID: 25 Req-ID: pvc-e1933cbb-4c98-49e6-938b-dbbde73ab219 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-13c226de-5478-46e1-8ff9-1c75dc45a882) and image name (csi-vol-13c226de-5478-46e1-8ff9-1c75dc45a882) for request name (pvc-e1933cbb-4c98-49e6-938b-dbbde73ab219)
I0725 10:46:49.831039       1 rbd_util.go:423] ID: 25 Req-ID: pvc-e1933cbb-4c98-49e6-938b-dbbde73ab219 rbd: create kube/csi-vol-13c226de-5478-46e1-8ff9-1c75dc45a882 size 5120M (features: [layering]) using mon 199.204.45.169
I0725 10:46:49.831203       1 rbd_util.go:1563] ID: 25 Req-ID: pvc-e1933cbb-4c98-49e6-938b-dbbde73ab219 setting image options on kube/csi-vol-13c226de-5478-46e1-8ff9-1c75dc45a882
I0725 10:46:49.866860       1 controllerserver.go:763] ID: 25 Req-ID: pvc-e1933cbb-4c98-49e6-938b-dbbde73ab219 created image kube/csi-vol-13c226de-5478-46e1-8ff9-1c75dc45a882 backed for request name pvc-e1933cbb-4c98-49e6-938b-dbbde73ab219
I0725 10:46:49.899880       1 omap.go:159] ID: 25 Req-ID: pvc-e1933cbb-4c98-49e6-938b-dbbde73ab219 set omap keys (pool="kube", namespace="", name="csi.volume.13c226de-5478-46e1-8ff9-1c75dc45a882"): map[csi.imageid:37f4440f745f])
I0725 10:46:49.987317       1 utils.go:205] ID: 25 Req-ID: pvc-e1933cbb-4c98-49e6-938b-dbbde73ab219 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-13c226de-5478-46e1-8ff9-1c75dc45a882","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-13c226de-5478-46e1-8ff9-1c75dc45a882"}}
I0725 10:46:59.456364       1 utils.go:198] ID: 26 GRPC call: /csi.v1.Identity/Probe
I0725 10:46:59.456435       1 utils.go:199] ID: 26 GRPC request: {}
I0725 10:46:59.456458       1 utils.go:205] ID: 26 GRPC response: {}