I0408 04:18:58.833542       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0408 04:18:58.833647       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0408 04:18:58.833659       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0408 04:18:58.833662       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0408 04:18:58.833668       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0408 04:18:58.833671       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0408 04:18:58.833674       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0408 04:18:58.833676       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0408 04:18:58.833679       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0408 04:18:58.833683       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0408 04:18:58.833916       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0408 04:18:58.834018       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0408 04:19:00.648444       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0408 04:19:00.649716       1 utils.go:199] ID: 1 GRPC request: {}
I0408 04:19:00.649795       1 utils.go:205] ID: 1 GRPC response: {}
I0408 04:19:00.651462       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0408 04:19:00.651525       1 utils.go:199] ID: 2 GRPC request: {}
I0408 04:19:00.651535       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0408 04:19:00.651568       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0408 04:19:00.653861       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0408 04:19:00.653932       1 utils.go:199] ID: 3 GRPC request: {}
I0408 04:19:00.653957       1 utils.go:205] ID: 3 GRPC response: {}
I0408 04:19:00.654309       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0408 04:19:00.654418       1 utils.go:199] ID: 4 GRPC request: {}
I0408 04:19:00.654603       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0408 04:19:00.655817       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0408 04:19:00.655921       1 utils.go:199] ID: 5 GRPC request: {}
I0408 04:19:00.655935       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0408 04:19:00.656058       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}}}]}
I0408 04:19:01.765689       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0408 04:19:01.765722       1 utils.go:199] ID: 6 GRPC request: {}
I0408 04:19:01.765742       1 utils.go:205] ID: 6 GRPC response: {}
I0408 04:19:01.769385       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0408 04:19:01.769450       1 utils.go:199] ID: 7 GRPC request: {}
I0408 04:19:01.769505       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0408 04:19:01.769566       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0408 04:19:01.771403       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0408 04:19:01.771485       1 utils.go:199] ID: 8 GRPC request: {}
I0408 04:19:01.771516       1 utils.go:205] ID: 8 GRPC response: {}
I0408 04:19:01.772516       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0408 04:19:01.772560       1 utils.go:199] ID: 9 GRPC request: {}
I0408 04:19:01.772652       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0408 04:19:01.774982       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0408 04:19:01.774999       1 utils.go:199] ID: 10 GRPC request: {}
I0408 04:19:01.775007       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0408 04:19:01.775082       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}}}]}
I0408 04:19:01.775537       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0408 04:19:01.775633       1 utils.go:199] ID: 11 GRPC request: {}
I0408 04:19:01.775670       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0408 04:19:01.775761       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}}}]}
I0408 04:19:01.776376       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0408 04:19:01.776403       1 utils.go:199] ID: 12 GRPC request: {}
I0408 04:19:01.776410       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0408 04:19:01.776559       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}}}]}
I0408 04:19:04.024477       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0408 04:19:04.024564       1 utils.go:199] ID: 13 GRPC request: {}
I0408 04:19:04.024640       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0408 04:19:04.024788       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0408 04:19:04.027525       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0408 04:19:04.027540       1 utils.go:199] ID: 14 GRPC request: {}
I0408 04:19:04.027605       1 utils.go:205] ID: 14 GRPC response: {}
I0408 04:19:04.028015       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0408 04:19:04.028039       1 utils.go:199] ID: 15 GRPC request: {}
I0408 04:19:04.028044       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0408 04:19:04.028204       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}}}]}
I0408 04:19:05.598478       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0408 04:19:05.598531       1 utils.go:199] ID: 16 GRPC request: {}
I0408 04:19:05.598559       1 utils.go:205] ID: 16 GRPC response: {}
I0408 04:19:05.601104       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0408 04:19:05.601139       1 utils.go:199] ID: 17 GRPC request: {}
I0408 04:19:05.601152       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0408 04:19:05.601176       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0408 04:19:05.602733       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0408 04:19:05.602756       1 utils.go:199] ID: 18 GRPC request: {}
I0408 04:19:05.602768       1 utils.go:205] ID: 18 GRPC response: {}
I0408 04:19:05.603104       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0408 04:19:05.603125       1 utils.go:199] ID: 19 GRPC request: {}
I0408 04:19:05.603204       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0408 04:19:05.603779       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0408 04:19:05.603799       1 utils.go:199] ID: 20 GRPC request: {}
I0408 04:19:05.603808       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0408 04:19:05.603902       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}}}]}
I0408 04:20:05.761936       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0408 04:20:05.762032       1 utils.go:199] ID: 21 GRPC request: {}
I0408 04:20:05.762109       1 utils.go:205] ID: 21 GRPC response: {}
I0408 04:21:05.766017       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0408 04:21:05.766074       1 utils.go:199] ID: 22 GRPC request: {}
I0408 04:21:05.766127       1 utils.go:205] ID: 22 GRPC response: {}
I0408 04:22:01.893627       1 utils.go:198] ID: 23 Req-ID: pvc-acaf7eca-5ca5-4814-b6d9-021d28c3abdc GRPC call: /csi.v1.Controller/CreateVolume
I0408 04:22:01.893920       1 utils.go:199] ID: 23 Req-ID: pvc-acaf7eca-5ca5-4814-b6d9-021d28c3abdc GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-acaf7eca-5ca5-4814-b6d9-021d28c3abdc","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-acaf7eca-5ca5-4814-b6d9-021d28c3abdc","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}}]}
I0408 04:22:01.894141       1 rbd_util.go:1315] ID: 23 Req-ID: pvc-acaf7eca-5ca5-4814-b6d9-021d28c3abdc setting disableInUseChecks: false image features: [layering] mounter: rbd
E0408 04:22:01.910152       1 omap.go:80] ID: 23 Req-ID: pvc-acaf7eca-5ca5-4814-b6d9-021d28c3abdc omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0408 04:22:01.924271       1 omap.go:159] ID: 23 Req-ID: pvc-acaf7eca-5ca5-4814-b6d9-021d28c3abdc set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-acaf7eca-5ca5-4814-b6d9-021d28c3abdc:ef6f344f-31f7-437f-8df6-3721045583c0])
I0408 04:22:01.931458       1 omap.go:159] ID: 23 Req-ID: pvc-acaf7eca-5ca5-4814-b6d9-021d28c3abdc set omap keys (pool="kube", namespace="", name="csi.volume.ef6f344f-31f7-437f-8df6-3721045583c0"): map[csi.imagename:csi-vol-ef6f344f-31f7-437f-8df6-3721045583c0 csi.volname:pvc-acaf7eca-5ca5-4814-b6d9-021d28c3abdc csi.volume.owner:default])
I0408 04:22:01.931493       1 rbd_journal.go:491] ID: 23 Req-ID: pvc-acaf7eca-5ca5-4814-b6d9-021d28c3abdc generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-ef6f344f-31f7-437f-8df6-3721045583c0) and image name (csi-vol-ef6f344f-31f7-437f-8df6-3721045583c0) for request name (pvc-acaf7eca-5ca5-4814-b6d9-021d28c3abdc)
I0408 04:22:01.931564       1 rbd_util.go:423] ID: 23 Req-ID: pvc-acaf7eca-5ca5-4814-b6d9-021d28c3abdc rbd: create kube/csi-vol-ef6f344f-31f7-437f-8df6-3721045583c0 size 5120M (features: [layering]) using mon 162.253.55.43
I0408 04:22:01.931624       1 rbd_util.go:1563] ID: 23 Req-ID: pvc-acaf7eca-5ca5-4814-b6d9-021d28c3abdc setting image options on kube/csi-vol-ef6f344f-31f7-437f-8df6-3721045583c0
I0408 04:22:03.065368       1 controllerserver.go:763] ID: 23 Req-ID: pvc-acaf7eca-5ca5-4814-b6d9-021d28c3abdc created image kube/csi-vol-ef6f344f-31f7-437f-8df6-3721045583c0 backed for request name pvc-acaf7eca-5ca5-4814-b6d9-021d28c3abdc
I0408 04:22:03.102386       1 omap.go:159] ID: 23 Req-ID: pvc-acaf7eca-5ca5-4814-b6d9-021d28c3abdc set omap keys (pool="kube", namespace="", name="csi.volume.ef6f344f-31f7-437f-8df6-3721045583c0"): map[csi.imageid:37d995ae91cf])
I0408 04:22:03.191630       1 utils.go:205] ID: 23 Req-ID: pvc-acaf7eca-5ca5-4814-b6d9-021d28c3abdc GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-ef6f344f-31f7-437f-8df6-3721045583c0","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-ef6f344f-31f7-437f-8df6-3721045583c0"}}
I0408 04:22:05.795635       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0408 04:22:05.795695       1 utils.go:199] ID: 24 GRPC request: {}
I0408 04:22:05.795716       1 utils.go:205] ID: 24 GRPC response: {}