I0725 13:43:52.489901       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0725 13:43:52.490024       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0725 13:43:52.490042       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0725 13:43:52.490047       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0725 13:43:52.490052       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0725 13:43:52.490056       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0725 13:43:52.490060       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0725 13:43:52.490063       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0725 13:43:52.490067       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0725 13:43:52.490071       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0725 13:43:52.490393       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0725 13:43:52.490418       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0725 13:43:54.648439       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0725 13:43:54.649849       1 utils.go:199] ID: 1 GRPC request: {}
I0725 13:43:54.649982       1 utils.go:205] ID: 1 GRPC response: {}
I0725 13:43:54.654737       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0725 13:43:54.654807       1 utils.go:199] ID: 2 GRPC request: {}
I0725 13:43:54.654829       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0725 13:43:54.654989       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0725 13:43:54.656761       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0725 13:43:54.656824       1 utils.go:199] ID: 3 GRPC request: {}
I0725 13:43:54.656846       1 utils.go:205] ID: 3 GRPC response: {}
I0725 13:43:54.657260       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0725 13:43:54.657363       1 utils.go:199] ID: 4 GRPC request: {}
I0725 13:43:54.657568       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0725 13:43:54.658420       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0725 13:43:54.658495       1 utils.go:199] ID: 5 GRPC request: {}
I0725 13:43:54.658507       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0725 13:43:54.658651       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 13:43:57.837571       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0725 13:43:57.837702       1 utils.go:199] ID: 6 GRPC request: {}
I0725 13:43:57.837794       1 utils.go:205] ID: 6 GRPC response: {}
I0725 13:43:57.841076       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0725 13:43:57.841912       1 utils.go:199] ID: 7 GRPC request: {}
I0725 13:43:57.841936       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0725 13:43:57.841973       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0725 13:43:57.845998       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0725 13:43:57.846032       1 utils.go:199] ID: 8 GRPC request: {}
I0725 13:43:57.846078       1 utils.go:205] ID: 8 GRPC response: {}
I0725 13:43:57.846779       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0725 13:43:57.846800       1 utils.go:199] ID: 9 GRPC request: {}
I0725 13:43:57.846889       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0725 13:43:57.847365       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0725 13:43:57.847383       1 utils.go:199] ID: 10 GRPC request: {}
I0725 13:43:57.847391       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0725 13:43:57.847474       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 13:43:57.847840       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0725 13:43:57.847856       1 utils.go:199] ID: 11 GRPC request: {}
I0725 13:43:57.847862       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0725 13:43:57.847951       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 13:43:57.848299       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0725 13:43:57.848375       1 utils.go:199] ID: 12 GRPC request: {}
I0725 13:43:57.848404       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0725 13:43:57.848559       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 13:44:00.021605       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0725 13:44:00.021651       1 utils.go:199] ID: 13 GRPC request: {}
I0725 13:44:00.021665       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0725 13:44:00.021699       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0725 13:44:00.025693       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0725 13:44:00.025717       1 utils.go:199] ID: 14 GRPC request: {}
I0725 13:44:00.025732       1 utils.go:205] ID: 14 GRPC response: {}
I0725 13:44:00.026391       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0725 13:44:00.026416       1 utils.go:199] ID: 15 GRPC request: {}
I0725 13:44:00.026426       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0725 13:44:00.026526       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 13:44:01.237685       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0725 13:44:01.237751       1 utils.go:199] ID: 16 GRPC request: {}
I0725 13:44:01.237779       1 utils.go:205] ID: 16 GRPC response: {}
I0725 13:44:01.239339       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0725 13:44:01.239490       1 utils.go:199] ID: 17 GRPC request: {}
I0725 13:44:01.239506       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0725 13:44:01.239589       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0725 13:44:01.241679       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0725 13:44:01.241812       1 utils.go:199] ID: 18 GRPC request: {}
I0725 13:44:01.241899       1 utils.go:205] ID: 18 GRPC response: {}
I0725 13:44:01.242276       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0725 13:44:01.242356       1 utils.go:199] ID: 19 GRPC request: {}
I0725 13:44:01.242456       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0725 13:44:01.243120       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0725 13:44:01.243304       1 utils.go:199] ID: 20 GRPC request: {}
I0725 13:44:01.243410       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0725 13:44:01.243739       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 13:45:01.417094       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0725 13:45:01.417253       1 utils.go:199] ID: 21 GRPC request: {}
I0725 13:45:01.417309       1 utils.go:205] ID: 21 GRPC response: {}
I0725 13:46:01.418080       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0725 13:46:01.418140       1 utils.go:199] ID: 22 GRPC request: {}
I0725 13:46:01.418164       1 utils.go:205] ID: 22 GRPC response: {}
I0725 13:47:01.416859       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0725 13:47:01.417057       1 utils.go:199] ID: 23 GRPC request: {}
I0725 13:47:01.417127       1 utils.go:205] ID: 23 GRPC response: {}
I0725 13:48:01.428035       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0725 13:48:01.428295       1 utils.go:199] ID: 24 GRPC request: {}
I0725 13:48:01.428352       1 utils.go:205] ID: 24 GRPC response: {}
I0725 13:48:57.558756       1 utils.go:198] ID: 25 Req-ID: pvc-135ab7fd-1b17-41c5-8711-57a9f5f47efb GRPC call: /csi.v1.Controller/CreateVolume
I0725 13:48:57.559330       1 utils.go:199] ID: 25 Req-ID: pvc-135ab7fd-1b17-41c5-8711-57a9f5f47efb GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-135ab7fd-1b17-41c5-8711-57a9f5f47efb","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-135ab7fd-1b17-41c5-8711-57a9f5f47efb","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 13:48:57.559714       1 rbd_util.go:1315] ID: 25 Req-ID: pvc-135ab7fd-1b17-41c5-8711-57a9f5f47efb setting disableInUseChecks: false image features: [layering] mounter: rbd
E0725 13:48:57.578255       1 omap.go:80] ID: 25 Req-ID: pvc-135ab7fd-1b17-41c5-8711-57a9f5f47efb omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0725 13:48:57.599280       1 omap.go:159] ID: 25 Req-ID: pvc-135ab7fd-1b17-41c5-8711-57a9f5f47efb set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-135ab7fd-1b17-41c5-8711-57a9f5f47efb:a902ff47-abca-452d-b9c9-056d9b1eb5dd])
I0725 13:48:57.608604       1 omap.go:159] ID: 25 Req-ID: pvc-135ab7fd-1b17-41c5-8711-57a9f5f47efb set omap keys (pool="kube", namespace="", name="csi.volume.a902ff47-abca-452d-b9c9-056d9b1eb5dd"): map[csi.imagename:csi-vol-a902ff47-abca-452d-b9c9-056d9b1eb5dd csi.volname:pvc-135ab7fd-1b17-41c5-8711-57a9f5f47efb csi.volume.owner:default])
I0725 13:48:57.608689       1 rbd_journal.go:491] ID: 25 Req-ID: pvc-135ab7fd-1b17-41c5-8711-57a9f5f47efb generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-a902ff47-abca-452d-b9c9-056d9b1eb5dd) and image name (csi-vol-a902ff47-abca-452d-b9c9-056d9b1eb5dd) for request name (pvc-135ab7fd-1b17-41c5-8711-57a9f5f47efb)
I0725 13:48:57.608859       1 rbd_util.go:423] ID: 25 Req-ID: pvc-135ab7fd-1b17-41c5-8711-57a9f5f47efb rbd: create kube/csi-vol-a902ff47-abca-452d-b9c9-056d9b1eb5dd size 5120M (features: [layering]) using mon 199.204.45.95
I0725 13:48:57.608917       1 rbd_util.go:1563] ID: 25 Req-ID: pvc-135ab7fd-1b17-41c5-8711-57a9f5f47efb setting image options on kube/csi-vol-a902ff47-abca-452d-b9c9-056d9b1eb5dd
I0725 13:48:57.642993       1 controllerserver.go:763] ID: 25 Req-ID: pvc-135ab7fd-1b17-41c5-8711-57a9f5f47efb created image kube/csi-vol-a902ff47-abca-452d-b9c9-056d9b1eb5dd backed for request name pvc-135ab7fd-1b17-41c5-8711-57a9f5f47efb
I0725 13:48:57.680546       1 omap.go:159] ID: 25 Req-ID: pvc-135ab7fd-1b17-41c5-8711-57a9f5f47efb set omap keys (pool="kube", namespace="", name="csi.volume.a902ff47-abca-452d-b9c9-056d9b1eb5dd"): map[csi.imageid:37f44dd698b6])
I0725 13:48:57.781084       1 utils.go:205] ID: 25 Req-ID: pvc-135ab7fd-1b17-41c5-8711-57a9f5f47efb GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-a902ff47-abca-452d-b9c9-056d9b1eb5dd","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-a902ff47-abca-452d-b9c9-056d9b1eb5dd"}}
I0725 13:49:01.473513       1 utils.go:198] ID: 26 GRPC call: /csi.v1.Identity/Probe
I0725 13:49:01.473580       1 utils.go:199] ID: 26 GRPC request: {}
I0725 13:49:01.473618       1 utils.go:205] ID: 26 GRPC response: {}