I0507 13:17:13.270867       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0507 13:17:13.271066       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0507 13:17:13.271090       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0507 13:17:13.271104       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0507 13:17:13.271138       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0507 13:17:13.271152       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0507 13:17:13.271167       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0507 13:17:13.271180       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0507 13:17:13.271193       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0507 13:17:13.271205       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0507 13:17:13.271687       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0507 13:17:13.271760       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0507 13:17:15.152503       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0507 13:17:15.153561       1 utils.go:199] ID: 1 GRPC request: {}
I0507 13:17:15.153678       1 utils.go:205] ID: 1 GRPC response: {}
I0507 13:17:15.155482       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0507 13:17:15.155565       1 utils.go:199] ID: 2 GRPC request: {}
I0507 13:17:15.155581       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0507 13:17:15.155713       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0507 13:17:15.157062       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0507 13:17:15.157107       1 utils.go:199] ID: 3 GRPC request: {}
I0507 13:17:15.157127       1 utils.go:205] ID: 3 GRPC response: {}
I0507 13:17:15.157523       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0507 13:17:15.157568       1 utils.go:199] ID: 4 GRPC request: {}
I0507 13:17:15.157715       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0507 13:17:15.158422       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0507 13:17:15.158485       1 utils.go:199] ID: 5 GRPC request: {}
I0507 13:17:15.158500       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0507 13:17:15.158611       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}}}]}
I0507 13:17:16.440838       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0507 13:17:16.440886       1 utils.go:199] ID: 6 GRPC request: {}
I0507 13:17:16.440910       1 utils.go:205] ID: 6 GRPC response: {}
I0507 13:17:16.446761       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0507 13:17:16.446808       1 utils.go:199] ID: 7 GRPC request: {}
I0507 13:17:16.446819       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0507 13:17:16.446857       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0507 13:17:16.450438       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0507 13:17:16.450483       1 utils.go:199] ID: 8 GRPC request: {}
I0507 13:17:16.450515       1 utils.go:205] ID: 8 GRPC response: {}
I0507 13:17:16.451622       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0507 13:17:16.452055       1 utils.go:199] ID: 9 GRPC request: {}
I0507 13:17:16.452241       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0507 13:17:16.453292       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0507 13:17:16.453323       1 utils.go:199] ID: 10 GRPC request: {}
I0507 13:17:16.453331       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0507 13:17:16.453429       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}}}]}
I0507 13:17:16.454128       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0507 13:17:16.454158       1 utils.go:199] ID: 11 GRPC request: {}
I0507 13:17:16.454166       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0507 13:17:16.454243       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}}}]}
I0507 13:17:16.454594       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0507 13:17:16.454619       1 utils.go:199] ID: 12 GRPC request: {}
I0507 13:17:16.454626       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0507 13:17:16.454697       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}}}]}
I0507 13:17:17.626951       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0507 13:17:17.626989       1 utils.go:199] ID: 13 GRPC request: {}
I0507 13:17:17.626997       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0507 13:17:17.627020       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0507 13:17:17.629260       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0507 13:17:17.629280       1 utils.go:199] ID: 14 GRPC request: {}
I0507 13:17:17.629294       1 utils.go:205] ID: 14 GRPC response: {}
I0507 13:17:17.630655       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0507 13:17:17.630673       1 utils.go:199] ID: 15 GRPC request: {}
I0507 13:17:17.630681       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0507 13:17:17.630773       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}}}]}
I0507 13:17:19.952213       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0507 13:17:19.952272       1 utils.go:199] ID: 16 GRPC request: {}
I0507 13:17:19.952296       1 utils.go:205] ID: 16 GRPC response: {}
I0507 13:17:19.955715       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0507 13:17:19.955762       1 utils.go:199] ID: 17 GRPC request: {}
I0507 13:17:19.955806       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0507 13:17:19.955844       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0507 13:17:19.957901       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0507 13:17:19.957931       1 utils.go:199] ID: 18 GRPC request: {}
I0507 13:17:19.957947       1 utils.go:205] ID: 18 GRPC response: {}
I0507 13:17:19.958393       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0507 13:17:19.958457       1 utils.go:199] ID: 19 GRPC request: {}
I0507 13:17:19.958656       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0507 13:17:19.959524       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0507 13:17:19.959572       1 utils.go:199] ID: 20 GRPC request: {}
I0507 13:17:19.959590       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0507 13:17:19.959718       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}}}]}
I0507 13:18:20.570138       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0507 13:18:20.570247       1 utils.go:199] ID: 21 GRPC request: {}
I0507 13:18:20.570360       1 utils.go:205] ID: 21 GRPC response: {}
I0507 13:19:20.572334       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0507 13:19:20.572435       1 utils.go:199] ID: 22 GRPC request: {}
I0507 13:19:20.572504       1 utils.go:205] ID: 22 GRPC response: {}
I0507 13:20:20.570774       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0507 13:20:20.570939       1 utils.go:199] ID: 23 GRPC request: {}
I0507 13:20:20.571071       1 utils.go:205] ID: 23 GRPC response: {}
I0507 13:20:21.789701       1 utils.go:198] ID: 24 Req-ID: pvc-5afa8c6c-a1f8-4d54-8997-9ab766d96bb2 GRPC call: /csi.v1.Controller/CreateVolume
I0507 13:20:21.790192       1 utils.go:199] ID: 24 Req-ID: pvc-5afa8c6c-a1f8-4d54-8997-9ab766d96bb2 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-5afa8c6c-a1f8-4d54-8997-9ab766d96bb2","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-5afa8c6c-a1f8-4d54-8997-9ab766d96bb2","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}}]}
I0507 13:20:21.790426       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-5afa8c6c-a1f8-4d54-8997-9ab766d96bb2 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0507 13:20:21.808817       1 omap.go:80] ID: 24 Req-ID: pvc-5afa8c6c-a1f8-4d54-8997-9ab766d96bb2 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0507 13:20:21.824373       1 omap.go:159] ID: 24 Req-ID: pvc-5afa8c6c-a1f8-4d54-8997-9ab766d96bb2 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-5afa8c6c-a1f8-4d54-8997-9ab766d96bb2:40ece7d0-53ca-49a2-bca8-6bf15a10e05f])
I0507 13:20:21.830511       1 omap.go:159] ID: 24 Req-ID: pvc-5afa8c6c-a1f8-4d54-8997-9ab766d96bb2 set omap keys (pool="kube", namespace="", name="csi.volume.40ece7d0-53ca-49a2-bca8-6bf15a10e05f"): map[csi.imagename:csi-vol-40ece7d0-53ca-49a2-bca8-6bf15a10e05f csi.volname:pvc-5afa8c6c-a1f8-4d54-8997-9ab766d96bb2 csi.volume.owner:default])
I0507 13:20:21.830568       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-5afa8c6c-a1f8-4d54-8997-9ab766d96bb2 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-40ece7d0-53ca-49a2-bca8-6bf15a10e05f) and image name (csi-vol-40ece7d0-53ca-49a2-bca8-6bf15a10e05f) for request name (pvc-5afa8c6c-a1f8-4d54-8997-9ab766d96bb2)
I0507 13:20:21.830654       1 rbd_util.go:423] ID: 24 Req-ID: pvc-5afa8c6c-a1f8-4d54-8997-9ab766d96bb2 rbd: create kube/csi-vol-40ece7d0-53ca-49a2-bca8-6bf15a10e05f size 5120M (features: [layering]) using mon 199.19.213.249
I0507 13:20:21.830717       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-5afa8c6c-a1f8-4d54-8997-9ab766d96bb2 setting image options on kube/csi-vol-40ece7d0-53ca-49a2-bca8-6bf15a10e05f
I0507 13:20:23.486723       1 controllerserver.go:763] ID: 24 Req-ID: pvc-5afa8c6c-a1f8-4d54-8997-9ab766d96bb2 created image kube/csi-vol-40ece7d0-53ca-49a2-bca8-6bf15a10e05f backed for request name pvc-5afa8c6c-a1f8-4d54-8997-9ab766d96bb2
I0507 13:20:23.519239       1 omap.go:159] ID: 24 Req-ID: pvc-5afa8c6c-a1f8-4d54-8997-9ab766d96bb2 set omap keys (pool="kube", namespace="", name="csi.volume.40ece7d0-53ca-49a2-bca8-6bf15a10e05f"): map[csi.imageid:37d9b7666d1a])
I0507 13:20:23.614317       1 utils.go:205] ID: 24 Req-ID: pvc-5afa8c6c-a1f8-4d54-8997-9ab766d96bb2 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-40ece7d0-53ca-49a2-bca8-6bf15a10e05f","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-40ece7d0-53ca-49a2-bca8-6bf15a10e05f"}}