I0313 09:53:15.890053       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0313 09:53:15.890159       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0313 09:53:15.890171       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0313 09:53:15.890174       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0313 09:53:15.890176       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0313 09:53:15.890180       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0313 09:53:15.890184       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0313 09:53:15.890187       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0313 09:53:15.890190       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0313 09:53:15.890193       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0313 09:53:15.890416       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0313 09:53:15.890517       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0313 09:53:20.021808       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0313 09:53:20.023237       1 utils.go:199] ID: 1 GRPC request: {}
I0313 09:53:20.023299       1 utils.go:205] ID: 1 GRPC response: {}
I0313 09:53:20.025752       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0313 09:53:20.025854       1 utils.go:199] ID: 2 GRPC request: {}
I0313 09:53:20.025891       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0313 09:53:20.025996       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0313 09:53:20.028023       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0313 09:53:20.028047       1 utils.go:199] ID: 3 GRPC request: {}
I0313 09:53:20.028061       1 utils.go:205] ID: 3 GRPC response: {}
I0313 09:53:20.028513       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0313 09:53:20.028577       1 utils.go:199] ID: 4 GRPC request: {}
I0313 09:53:20.028722       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0313 09:53:20.029434       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0313 09:53:20.029471       1 utils.go:199] ID: 5 GRPC request: {}
I0313 09:53:20.029484       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0313 09:53:20.029579       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}}}]}
I0313 09:53:21.254983       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0313 09:53:21.255017       1 utils.go:199] ID: 6 GRPC request: {}
I0313 09:53:21.255030       1 utils.go:205] ID: 6 GRPC response: {}
I0313 09:53:21.260512       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0313 09:53:21.260543       1 utils.go:199] ID: 7 GRPC request: {}
I0313 09:53:21.260551       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0313 09:53:21.260575       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0313 09:53:21.262686       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0313 09:53:21.262715       1 utils.go:199] ID: 8 GRPC request: {}
I0313 09:53:21.262741       1 utils.go:205] ID: 8 GRPC response: {}
I0313 09:53:21.263544       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0313 09:53:21.263576       1 utils.go:199] ID: 9 GRPC request: {}
I0313 09:53:21.263717       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0313 09:53:21.264242       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0313 09:53:21.264265       1 utils.go:199] ID: 10 GRPC request: {}
I0313 09:53:21.264273       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0313 09:53:21.264420       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}}}]}
I0313 09:53:21.264981       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0313 09:53:21.264996       1 utils.go:199] ID: 11 GRPC request: {}
I0313 09:53:21.265001       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0313 09:53:21.265065       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}}}]}
I0313 09:53:21.265338       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0313 09:53:21.265362       1 utils.go:199] ID: 12 GRPC request: {}
I0313 09:53:21.265383       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0313 09:53:21.265456       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}}}]}
I0313 09:53:22.434893       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0313 09:53:22.434938       1 utils.go:199] ID: 13 GRPC request: {}
I0313 09:53:22.434949       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0313 09:53:22.434980       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0313 09:53:22.437751       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0313 09:53:22.437782       1 utils.go:199] ID: 14 GRPC request: {}
I0313 09:53:22.437801       1 utils.go:205] ID: 14 GRPC response: {}
I0313 09:53:22.438499       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0313 09:53:22.438529       1 utils.go:199] ID: 15 GRPC request: {}
I0313 09:53:22.438542       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0313 09:53:22.438711       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}}}]}
I0313 09:53:32.162358       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0313 09:53:32.162451       1 utils.go:199] ID: 16 GRPC request: {}
I0313 09:53:32.162469       1 utils.go:205] ID: 16 GRPC response: {}
I0313 09:53:32.164742       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0313 09:53:32.164786       1 utils.go:199] ID: 17 GRPC request: {}
I0313 09:53:32.164797       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0313 09:53:32.164831       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0313 09:53:32.166598       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0313 09:53:32.166619       1 utils.go:199] ID: 18 GRPC request: {}
I0313 09:53:32.166632       1 utils.go:205] ID: 18 GRPC response: {}
I0313 09:53:32.167025       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0313 09:53:32.167052       1 utils.go:199] ID: 19 GRPC request: {}
I0313 09:53:32.167140       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0313 09:53:32.167658       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0313 09:53:32.167677       1 utils.go:199] ID: 20 GRPC request: {}
I0313 09:53:32.167685       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0313 09:53:32.167761       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}}}]}
I0313 09:54:32.465218       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0313 09:54:32.465253       1 utils.go:199] ID: 21 GRPC request: {}
I0313 09:54:32.465266       1 utils.go:205] ID: 21 GRPC response: {}
I0313 09:55:32.409514       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0313 09:55:32.409570       1 utils.go:199] ID: 22 GRPC request: {}
I0313 09:55:32.410164       1 utils.go:205] ID: 22 GRPC response: {}
I0313 09:56:25.567031       1 utils.go:198] ID: 23 Req-ID: pvc-023bbdc2-9fc0-43ff-b0da-49ff0fa911c7 GRPC call: /csi.v1.Controller/CreateVolume
I0313 09:56:25.567300       1 utils.go:199] ID: 23 Req-ID: pvc-023bbdc2-9fc0-43ff-b0da-49ff0fa911c7 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-023bbdc2-9fc0-43ff-b0da-49ff0fa911c7","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-023bbdc2-9fc0-43ff-b0da-49ff0fa911c7","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}}]}
I0313 09:56:25.567516       1 rbd_util.go:1315] ID: 23 Req-ID: pvc-023bbdc2-9fc0-43ff-b0da-49ff0fa911c7 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0313 09:56:25.584851       1 omap.go:80] ID: 23 Req-ID: pvc-023bbdc2-9fc0-43ff-b0da-49ff0fa911c7 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0313 09:56:25.597814       1 omap.go:159] ID: 23 Req-ID: pvc-023bbdc2-9fc0-43ff-b0da-49ff0fa911c7 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-023bbdc2-9fc0-43ff-b0da-49ff0fa911c7:baf0eecb-4c95-4179-a49f-538e93297a59])
I0313 09:56:25.608605       1 omap.go:159] ID: 23 Req-ID: pvc-023bbdc2-9fc0-43ff-b0da-49ff0fa911c7 set omap keys (pool="kube", namespace="", name="csi.volume.baf0eecb-4c95-4179-a49f-538e93297a59"): map[csi.imagename:csi-vol-baf0eecb-4c95-4179-a49f-538e93297a59 csi.volname:pvc-023bbdc2-9fc0-43ff-b0da-49ff0fa911c7 csi.volume.owner:default])
I0313 09:56:25.608695       1 rbd_journal.go:491] ID: 23 Req-ID: pvc-023bbdc2-9fc0-43ff-b0da-49ff0fa911c7 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-baf0eecb-4c95-4179-a49f-538e93297a59) and image name (csi-vol-baf0eecb-4c95-4179-a49f-538e93297a59) for request name (pvc-023bbdc2-9fc0-43ff-b0da-49ff0fa911c7)
I0313 09:56:25.608794       1 rbd_util.go:423] ID: 23 Req-ID: pvc-023bbdc2-9fc0-43ff-b0da-49ff0fa911c7 rbd: create kube/csi-vol-baf0eecb-4c95-4179-a49f-538e93297a59 size 5120M (features: [layering]) using mon 199.19.213.195
I0313 09:56:25.608851       1 rbd_util.go:1563] ID: 23 Req-ID: pvc-023bbdc2-9fc0-43ff-b0da-49ff0fa911c7 setting image options on kube/csi-vol-baf0eecb-4c95-4179-a49f-538e93297a59
I0313 09:56:27.523301       1 controllerserver.go:763] ID: 23 Req-ID: pvc-023bbdc2-9fc0-43ff-b0da-49ff0fa911c7 created image kube/csi-vol-baf0eecb-4c95-4179-a49f-538e93297a59 backed for request name pvc-023bbdc2-9fc0-43ff-b0da-49ff0fa911c7
I0313 09:56:27.563392       1 omap.go:159] ID: 23 Req-ID: pvc-023bbdc2-9fc0-43ff-b0da-49ff0fa911c7 set omap keys (pool="kube", namespace="", name="csi.volume.baf0eecb-4c95-4179-a49f-538e93297a59"): map[csi.imageid:37d9ffba8da9])
I0313 09:56:27.655228       1 utils.go:205] ID: 23 Req-ID: pvc-023bbdc2-9fc0-43ff-b0da-49ff0fa911c7 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-baf0eecb-4c95-4179-a49f-538e93297a59","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-baf0eecb-4c95-4179-a49f-538e93297a59"}}
I0313 09:56:32.463163       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0313 09:56:32.463215       1 utils.go:199] ID: 24 GRPC request: {}
I0313 09:56:32.463242       1 utils.go:205] ID: 24 GRPC response: {}