I0602 23:53:12.183140       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0602 23:53:12.183269       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0602 23:53:12.183284       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0602 23:53:12.183287       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0602 23:53:12.183290       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0602 23:53:12.183293       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0602 23:53:12.183299       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0602 23:53:12.183302       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0602 23:53:12.183304       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0602 23:53:12.183307       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0602 23:53:12.183574       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0602 23:53:12.183770       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0602 23:53:20.699151       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0602 23:53:20.701281       1 utils.go:199] ID: 1 GRPC request: {}
I0602 23:53:20.701367       1 utils.go:205] ID: 1 GRPC response: {}
I0602 23:53:20.705220       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0602 23:53:20.705290       1 utils.go:199] ID: 2 GRPC request: {}
I0602 23:53:20.705314       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0602 23:53:20.705415       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0602 23:53:20.707272       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0602 23:53:20.707346       1 utils.go:199] ID: 3 GRPC request: {}
I0602 23:53:20.707392       1 utils.go:205] ID: 3 GRPC response: {}
I0602 23:53:20.707857       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0602 23:53:20.707916       1 utils.go:199] ID: 4 GRPC request: {}
I0602 23:53:20.708041       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0602 23:53:20.708910       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0602 23:53:20.709035       1 utils.go:199] ID: 5 GRPC request: {}
I0602 23:53:20.709083       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0602 23:53:20.709229       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}}}]}
I0602 23:53:22.302946       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0602 23:53:22.302975       1 utils.go:199] ID: 6 GRPC request: {}
I0602 23:53:22.303086       1 utils.go:205] ID: 6 GRPC response: {}
I0602 23:53:22.308526       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0602 23:53:22.308562       1 utils.go:199] ID: 7 GRPC request: {}
I0602 23:53:22.308656       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0602 23:53:22.308764       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0602 23:53:22.310353       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0602 23:53:22.310390       1 utils.go:199] ID: 8 GRPC request: {}
I0602 23:53:22.310408       1 utils.go:205] ID: 8 GRPC response: {}
I0602 23:53:22.310751       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0602 23:53:22.310766       1 utils.go:199] ID: 9 GRPC request: {}
I0602 23:53:22.310834       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0602 23:53:22.311367       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0602 23:53:22.311385       1 utils.go:199] ID: 10 GRPC request: {}
I0602 23:53:22.311392       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0602 23:53:22.311495       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}}}]}
I0602 23:53:22.311885       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0602 23:53:22.311901       1 utils.go:199] ID: 11 GRPC request: {}
I0602 23:53:22.311935       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0602 23:53:22.311992       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}}}]}
I0602 23:53:22.312317       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0602 23:53:22.312351       1 utils.go:199] ID: 12 GRPC request: {}
I0602 23:53:22.312366       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0602 23:53:22.312437       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}}}]}
I0602 23:53:23.561861       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0602 23:53:23.561958       1 utils.go:199] ID: 13 GRPC request: {}
I0602 23:53:23.561969       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0602 23:53:23.562385       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0602 23:53:23.566105       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0602 23:53:23.566126       1 utils.go:199] ID: 14 GRPC request: {}
I0602 23:53:23.566139       1 utils.go:205] ID: 14 GRPC response: {}
I0602 23:53:23.566742       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0602 23:53:23.566777       1 utils.go:199] ID: 15 GRPC request: {}
I0602 23:53:23.566786       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0602 23:53:23.566874       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}}}]}
I0602 23:53:24.762093       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0602 23:53:24.762135       1 utils.go:199] ID: 16 GRPC request: {}
I0602 23:53:24.762156       1 utils.go:205] ID: 16 GRPC response: {}
I0602 23:53:24.765028       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0602 23:53:24.765060       1 utils.go:199] ID: 17 GRPC request: {}
I0602 23:53:24.765067       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0602 23:53:24.765093       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0602 23:53:24.768318       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0602 23:53:24.768352       1 utils.go:199] ID: 18 GRPC request: {}
I0602 23:53:24.768368       1 utils.go:205] ID: 18 GRPC response: {}
I0602 23:53:24.768648       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0602 23:53:24.768664       1 utils.go:199] ID: 19 GRPC request: {}
I0602 23:53:24.768744       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0602 23:53:24.769203       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0602 23:53:24.769256       1 utils.go:199] ID: 20 GRPC request: {}
I0602 23:53:24.769275       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0602 23:53:24.769365       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}}}]}
I0602 23:54:24.994909       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0602 23:54:24.994955       1 utils.go:199] ID: 21 GRPC request: {}
I0602 23:54:24.994980       1 utils.go:205] ID: 21 GRPC response: {}
I0602 23:55:24.945835       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0602 23:55:24.946008       1 utils.go:199] ID: 22 GRPC request: {}
I0602 23:55:24.946062       1 utils.go:205] ID: 22 GRPC response: {}
I0602 23:56:24.944187       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0602 23:56:24.944229       1 utils.go:199] ID: 23 GRPC request: {}
I0602 23:56:24.944245       1 utils.go:205] ID: 23 GRPC response: {}
I0602 23:57:06.301909       1 utils.go:198] ID: 24 Req-ID: pvc-56c46fcf-20e3-4214-b5bc-6dd44d67ea23 GRPC call: /csi.v1.Controller/CreateVolume
I0602 23:57:06.302866       1 utils.go:199] ID: 24 Req-ID: pvc-56c46fcf-20e3-4214-b5bc-6dd44d67ea23 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-56c46fcf-20e3-4214-b5bc-6dd44d67ea23","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-56c46fcf-20e3-4214-b5bc-6dd44d67ea23","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}}]}
I0602 23:57:06.303345       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-56c46fcf-20e3-4214-b5bc-6dd44d67ea23 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0602 23:57:06.321339       1 omap.go:80] ID: 24 Req-ID: pvc-56c46fcf-20e3-4214-b5bc-6dd44d67ea23 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0602 23:57:06.338758       1 omap.go:159] ID: 24 Req-ID: pvc-56c46fcf-20e3-4214-b5bc-6dd44d67ea23 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-56c46fcf-20e3-4214-b5bc-6dd44d67ea23:0c2e6d8b-9b38-4468-a568-cb93391ee396])
I0602 23:57:06.344037       1 omap.go:159] ID: 24 Req-ID: pvc-56c46fcf-20e3-4214-b5bc-6dd44d67ea23 set omap keys (pool="kube", namespace="", name="csi.volume.0c2e6d8b-9b38-4468-a568-cb93391ee396"): map[csi.imagename:csi-vol-0c2e6d8b-9b38-4468-a568-cb93391ee396 csi.volname:pvc-56c46fcf-20e3-4214-b5bc-6dd44d67ea23 csi.volume.owner:default])
I0602 23:57:06.344165       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-56c46fcf-20e3-4214-b5bc-6dd44d67ea23 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-0c2e6d8b-9b38-4468-a568-cb93391ee396) and image name (csi-vol-0c2e6d8b-9b38-4468-a568-cb93391ee396) for request name (pvc-56c46fcf-20e3-4214-b5bc-6dd44d67ea23)
I0602 23:57:06.344270       1 rbd_util.go:423] ID: 24 Req-ID: pvc-56c46fcf-20e3-4214-b5bc-6dd44d67ea23 rbd: create kube/csi-vol-0c2e6d8b-9b38-4468-a568-cb93391ee396 size 5120M (features: [layering]) using mon 199.204.45.109
I0602 23:57:06.344352       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-56c46fcf-20e3-4214-b5bc-6dd44d67ea23 setting image options on kube/csi-vol-0c2e6d8b-9b38-4468-a568-cb93391ee396
I0602 23:57:06.378453       1 controllerserver.go:763] ID: 24 Req-ID: pvc-56c46fcf-20e3-4214-b5bc-6dd44d67ea23 created image kube/csi-vol-0c2e6d8b-9b38-4468-a568-cb93391ee396 backed for request name pvc-56c46fcf-20e3-4214-b5bc-6dd44d67ea23
I0602 23:57:06.424859       1 omap.go:159] ID: 24 Req-ID: pvc-56c46fcf-20e3-4214-b5bc-6dd44d67ea23 set omap keys (pool="kube", namespace="", name="csi.volume.0c2e6d8b-9b38-4468-a568-cb93391ee396"): map[csi.imageid:37ed212e4c4e])
I0602 23:57:06.518807       1 utils.go:205] ID: 24 Req-ID: pvc-56c46fcf-20e3-4214-b5bc-6dd44d67ea23 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-0c2e6d8b-9b38-4468-a568-cb93391ee396","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-0c2e6d8b-9b38-4468-a568-cb93391ee396"}}
I0602 23:57:24.956343       1 utils.go:198] ID: 25 GRPC call: /csi.v1.Identity/Probe
I0602 23:57:24.956445       1 utils.go:199] ID: 25 GRPC request: {}
I0602 23:57:24.956604       1 utils.go:205] ID: 25 GRPC response: {}