I0730 19:30:56.628890       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0730 19:30:56.629046       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0730 19:30:56.629065       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0730 19:30:56.629068       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0730 19:30:56.629071       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0730 19:30:56.629075       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0730 19:30:56.629082       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0730 19:30:56.629086       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0730 19:30:56.629089       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0730 19:30:56.629092       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0730 19:30:56.629499       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0730 19:30:56.629674       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0730 19:31:03.583679       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0730 19:31:03.585081       1 utils.go:199] ID: 1 GRPC request: {}
I0730 19:31:03.585144       1 utils.go:205] ID: 1 GRPC response: {}
I0730 19:31:03.589074       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0730 19:31:03.589159       1 utils.go:199] ID: 2 GRPC request: {}
I0730 19:31:03.589202       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0730 19:31:03.589271       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0730 19:31:03.590835       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0730 19:31:03.590910       1 utils.go:199] ID: 3 GRPC request: {}
I0730 19:31:03.590942       1 utils.go:205] ID: 3 GRPC response: {}
I0730 19:31:03.591803       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0730 19:31:03.591944       1 utils.go:199] ID: 4 GRPC request: {}
I0730 19:31:03.592164       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0730 19:31:03.593874       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0730 19:31:03.594057       1 utils.go:199] ID: 5 GRPC request: {}
I0730 19:31:03.594460       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0730 19:31:03.594640       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}}}]}
I0730 19:31:06.081973       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0730 19:31:06.082031       1 utils.go:199] ID: 6 GRPC request: {}
I0730 19:31:06.082110       1 utils.go:205] ID: 6 GRPC response: {}
I0730 19:31:06.085076       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0730 19:31:06.085132       1 utils.go:199] ID: 7 GRPC request: {}
I0730 19:31:06.085144       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0730 19:31:06.085186       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0730 19:31:06.087803       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0730 19:31:06.087845       1 utils.go:199] ID: 8 GRPC request: {}
I0730 19:31:06.087863       1 utils.go:205] ID: 8 GRPC response: {}
I0730 19:31:06.088409       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0730 19:31:06.088443       1 utils.go:199] ID: 9 GRPC request: {}
I0730 19:31:06.088574       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0730 19:31:06.089204       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0730 19:31:06.089224       1 utils.go:199] ID: 10 GRPC request: {}
I0730 19:31:06.089232       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0730 19:31:06.089394       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}}}]}
I0730 19:31:06.090034       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0730 19:31:06.090115       1 utils.go:199] ID: 11 GRPC request: {}
I0730 19:31:06.090121       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0730 19:31:06.090298       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}}}]}
I0730 19:31:06.090704       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0730 19:31:06.090722       1 utils.go:199] ID: 12 GRPC request: {}
I0730 19:31:06.090727       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0730 19:31:06.090859       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}}}]}
I0730 19:31:07.797312       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0730 19:31:07.797373       1 utils.go:199] ID: 13 GRPC request: {}
I0730 19:31:07.797388       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0730 19:31:07.797417       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0730 19:31:07.800338       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0730 19:31:07.800364       1 utils.go:199] ID: 14 GRPC request: {}
I0730 19:31:07.800379       1 utils.go:205] ID: 14 GRPC response: {}
I0730 19:31:07.801010       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0730 19:31:07.801033       1 utils.go:199] ID: 15 GRPC request: {}
I0730 19:31:07.801055       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0730 19:31:07.801153       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}}}]}
I0730 19:31:09.585418       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0730 19:31:09.585472       1 utils.go:199] ID: 16 GRPC request: {}
I0730 19:31:09.585495       1 utils.go:205] ID: 16 GRPC response: {}
I0730 19:31:09.590160       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0730 19:31:09.590193       1 utils.go:199] ID: 17 GRPC request: {}
I0730 19:31:09.590201       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0730 19:31:09.590227       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0730 19:31:09.593366       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0730 19:31:09.593391       1 utils.go:199] ID: 18 GRPC request: {}
I0730 19:31:09.593402       1 utils.go:205] ID: 18 GRPC response: {}
I0730 19:31:09.593669       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0730 19:31:09.593680       1 utils.go:199] ID: 19 GRPC request: {}
I0730 19:31:09.593755       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0730 19:31:09.594466       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0730 19:31:09.594479       1 utils.go:199] ID: 20 GRPC request: {}
I0730 19:31:09.594485       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0730 19:31:09.594533       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}}}]}
I0730 19:32:09.826589       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0730 19:32:09.826647       1 utils.go:199] ID: 21 GRPC request: {}
I0730 19:32:09.826672       1 utils.go:205] ID: 21 GRPC response: {}
I0730 19:33:09.786087       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0730 19:33:09.786274       1 utils.go:199] ID: 22 GRPC request: {}
I0730 19:33:09.787024       1 utils.go:205] ID: 22 GRPC response: {}
I0730 19:34:09.786185       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0730 19:34:09.786237       1 utils.go:199] ID: 23 GRPC request: {}
I0730 19:34:09.786263       1 utils.go:205] ID: 23 GRPC response: {}
I0730 19:35:09.797577       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0730 19:35:09.797653       1 utils.go:199] ID: 24 GRPC request: {}
I0730 19:35:09.797681       1 utils.go:205] ID: 24 GRPC response: {}
I0730 19:35:21.651663       1 utils.go:198] ID: 25 Req-ID: pvc-4b4153e1-3edb-4102-a812-f68c54346183 GRPC call: /csi.v1.Controller/CreateVolume
I0730 19:35:21.652198       1 utils.go:199] ID: 25 Req-ID: pvc-4b4153e1-3edb-4102-a812-f68c54346183 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-4b4153e1-3edb-4102-a812-f68c54346183","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-4b4153e1-3edb-4102-a812-f68c54346183","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}}]}
I0730 19:35:21.652572       1 rbd_util.go:1315] ID: 25 Req-ID: pvc-4b4153e1-3edb-4102-a812-f68c54346183 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0730 19:35:21.669806       1 omap.go:80] ID: 25 Req-ID: pvc-4b4153e1-3edb-4102-a812-f68c54346183 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0730 19:35:21.701627       1 omap.go:159] ID: 25 Req-ID: pvc-4b4153e1-3edb-4102-a812-f68c54346183 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-4b4153e1-3edb-4102-a812-f68c54346183:2fb7dc40-2821-41b0-a873-2c6b2f5b5ba0])
I0730 19:35:21.714501       1 omap.go:159] ID: 25 Req-ID: pvc-4b4153e1-3edb-4102-a812-f68c54346183 set omap keys (pool="kube", namespace="", name="csi.volume.2fb7dc40-2821-41b0-a873-2c6b2f5b5ba0"): map[csi.imagename:csi-vol-2fb7dc40-2821-41b0-a873-2c6b2f5b5ba0 csi.volname:pvc-4b4153e1-3edb-4102-a812-f68c54346183 csi.volume.owner:default])
I0730 19:35:21.714676       1 rbd_journal.go:491] ID: 25 Req-ID: pvc-4b4153e1-3edb-4102-a812-f68c54346183 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-2fb7dc40-2821-41b0-a873-2c6b2f5b5ba0) and image name (csi-vol-2fb7dc40-2821-41b0-a873-2c6b2f5b5ba0) for request name (pvc-4b4153e1-3edb-4102-a812-f68c54346183)
I0730 19:35:21.714943       1 rbd_util.go:423] ID: 25 Req-ID: pvc-4b4153e1-3edb-4102-a812-f68c54346183 rbd: create kube/csi-vol-2fb7dc40-2821-41b0-a873-2c6b2f5b5ba0 size 5120M (features: [layering]) using mon 199.204.45.240
I0730 19:35:21.715118       1 rbd_util.go:1563] ID: 25 Req-ID: pvc-4b4153e1-3edb-4102-a812-f68c54346183 setting image options on kube/csi-vol-2fb7dc40-2821-41b0-a873-2c6b2f5b5ba0
I0730 19:35:21.788240       1 controllerserver.go:763] ID: 25 Req-ID: pvc-4b4153e1-3edb-4102-a812-f68c54346183 created image kube/csi-vol-2fb7dc40-2821-41b0-a873-2c6b2f5b5ba0 backed for request name pvc-4b4153e1-3edb-4102-a812-f68c54346183
I0730 19:35:21.845816       1 omap.go:159] ID: 25 Req-ID: pvc-4b4153e1-3edb-4102-a812-f68c54346183 set omap keys (pool="kube", namespace="", name="csi.volume.2fb7dc40-2821-41b0-a873-2c6b2f5b5ba0"): map[csi.imageid:37f48dbbd3d1])
I0730 19:35:22.024934       1 utils.go:205] ID: 25 Req-ID: pvc-4b4153e1-3edb-4102-a812-f68c54346183 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-2fb7dc40-2821-41b0-a873-2c6b2f5b5ba0","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-2fb7dc40-2821-41b0-a873-2c6b2f5b5ba0"}}
I0730 19:36:09.785909       1 utils.go:198] ID: 26 GRPC call: /csi.v1.Identity/Probe
I0730 19:36:09.785948       1 utils.go:199] ID: 26 GRPC request: {}
I0730 19:36:09.786557       1 utils.go:205] ID: 26 GRPC response: {}