I0811 07:40:06.461613       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0811 07:40:06.461800       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0811 07:40:06.461836       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0811 07:40:06.461853       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0811 07:40:06.461870       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0811 07:40:06.461887       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0811 07:40:06.461906       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0811 07:40:06.461935       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0811 07:40:06.461950       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0811 07:40:06.461966       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0811 07:40:06.462279       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0811 07:40:06.462310       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0811 07:40:09.674936       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0811 07:40:09.676284       1 utils.go:199] ID: 1 GRPC request: {}
I0811 07:40:09.676368       1 utils.go:205] ID: 1 GRPC response: {}
I0811 07:40:09.680514       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0811 07:40:09.680592       1 utils.go:199] ID: 2 GRPC request: {}
I0811 07:40:09.680609       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0811 07:40:09.680654       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0811 07:40:09.682438       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0811 07:40:09.682468       1 utils.go:199] ID: 3 GRPC request: {}
I0811 07:40:09.682496       1 utils.go:205] ID: 3 GRPC response: {}
I0811 07:40:09.682810       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0811 07:40:09.682880       1 utils.go:199] ID: 4 GRPC request: {}
I0811 07:40:09.683058       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0811 07:40:09.684165       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0811 07:40:09.684295       1 utils.go:199] ID: 5 GRPC request: {}
I0811 07:40:09.684311       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0811 07:40:09.684483       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}}}]}
I0811 07:40:12.751090       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0811 07:40:12.751170       1 utils.go:199] ID: 6 GRPC request: {}
I0811 07:40:12.751187       1 utils.go:205] ID: 6 GRPC response: {}
I0811 07:40:12.754691       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0811 07:40:12.754720       1 utils.go:199] ID: 7 GRPC request: {}
I0811 07:40:12.754726       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0811 07:40:12.754745       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0811 07:40:12.756542       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0811 07:40:12.756632       1 utils.go:199] ID: 8 GRPC request: {}
I0811 07:40:12.756681       1 utils.go:205] ID: 8 GRPC response: {}
I0811 07:40:12.757250       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0811 07:40:12.757322       1 utils.go:199] ID: 9 GRPC request: {}
I0811 07:40:12.757489       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0811 07:40:12.758173       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0811 07:40:12.758217       1 utils.go:199] ID: 10 GRPC request: {}
I0811 07:40:12.758230       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0811 07:40:12.758338       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}}}]}
I0811 07:40:12.758965       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0811 07:40:12.759019       1 utils.go:199] ID: 11 GRPC request: {}
I0811 07:40:12.759048       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0811 07:40:12.759183       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}}}]}
I0811 07:40:12.759562       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0811 07:40:12.759614       1 utils.go:199] ID: 12 GRPC request: {}
I0811 07:40:12.759636       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0811 07:40:12.759736       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}}}]}
I0811 07:40:14.124364       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0811 07:40:14.124410       1 utils.go:199] ID: 13 GRPC request: {}
I0811 07:40:14.124422       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0811 07:40:14.124571       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0811 07:40:14.126861       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0811 07:40:14.126966       1 utils.go:199] ID: 14 GRPC request: {}
I0811 07:40:14.126993       1 utils.go:205] ID: 14 GRPC response: {}
I0811 07:40:14.127456       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0811 07:40:14.127483       1 utils.go:199] ID: 15 GRPC request: {}
I0811 07:40:14.127493       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0811 07:40:14.127598       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}}}]}
I0811 07:40:15.619042       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0811 07:40:15.619089       1 utils.go:199] ID: 16 GRPC request: {}
I0811 07:40:15.619109       1 utils.go:205] ID: 16 GRPC response: {}
I0811 07:40:15.622166       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0811 07:40:15.622220       1 utils.go:199] ID: 17 GRPC request: {}
I0811 07:40:15.622230       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0811 07:40:15.622254       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0811 07:40:15.633151       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0811 07:40:15.633182       1 utils.go:199] ID: 18 GRPC request: {}
I0811 07:40:15.633198       1 utils.go:205] ID: 18 GRPC response: {}
I0811 07:40:15.633881       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0811 07:40:15.633918       1 utils.go:199] ID: 19 GRPC request: {}
I0811 07:40:15.634018       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0811 07:40:15.634629       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0811 07:40:15.634650       1 utils.go:199] ID: 20 GRPC request: {}
I0811 07:40:15.634658       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0811 07:40:15.634730       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}}}]}
I0811 07:41:15.824005       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0811 07:41:15.824088       1 utils.go:199] ID: 21 GRPC request: {}
I0811 07:41:15.824112       1 utils.go:205] ID: 21 GRPC response: {}
I0811 07:42:15.827741       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0811 07:42:15.827877       1 utils.go:199] ID: 22 GRPC request: {}
I0811 07:42:15.827910       1 utils.go:205] ID: 22 GRPC response: {}
I0811 07:43:09.929557       1 utils.go:198] ID: 23 Req-ID: pvc-c3def597-d1be-41bd-aaf9-b5aeec256b88 GRPC call: /csi.v1.Controller/CreateVolume
I0811 07:43:09.930058       1 utils.go:199] ID: 23 Req-ID: pvc-c3def597-d1be-41bd-aaf9-b5aeec256b88 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-c3def597-d1be-41bd-aaf9-b5aeec256b88","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-c3def597-d1be-41bd-aaf9-b5aeec256b88","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}}]}
I0811 07:43:09.930387       1 rbd_util.go:1315] ID: 23 Req-ID: pvc-c3def597-d1be-41bd-aaf9-b5aeec256b88 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0811 07:43:09.950706       1 omap.go:80] ID: 23 Req-ID: pvc-c3def597-d1be-41bd-aaf9-b5aeec256b88 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0811 07:43:09.961061       1 omap.go:159] ID: 23 Req-ID: pvc-c3def597-d1be-41bd-aaf9-b5aeec256b88 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-c3def597-d1be-41bd-aaf9-b5aeec256b88:29f224fb-55aa-470d-83b4-fe046951b969])
I0811 07:43:09.964708       1 omap.go:159] ID: 23 Req-ID: pvc-c3def597-d1be-41bd-aaf9-b5aeec256b88 set omap keys (pool="kube", namespace="", name="csi.volume.29f224fb-55aa-470d-83b4-fe046951b969"): map[csi.imagename:csi-vol-29f224fb-55aa-470d-83b4-fe046951b969 csi.volname:pvc-c3def597-d1be-41bd-aaf9-b5aeec256b88 csi.volume.owner:default])
I0811 07:43:09.964745       1 rbd_journal.go:491] ID: 23 Req-ID: pvc-c3def597-d1be-41bd-aaf9-b5aeec256b88 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-29f224fb-55aa-470d-83b4-fe046951b969) and image name (csi-vol-29f224fb-55aa-470d-83b4-fe046951b969) for request name (pvc-c3def597-d1be-41bd-aaf9-b5aeec256b88)
I0811 07:43:09.964831       1 rbd_util.go:423] ID: 23 Req-ID: pvc-c3def597-d1be-41bd-aaf9-b5aeec256b88 rbd: create kube/csi-vol-29f224fb-55aa-470d-83b4-fe046951b969 size 5120M (features: [layering]) using mon 199.19.213.59
I0811 07:43:09.964882       1 rbd_util.go:1563] ID: 23 Req-ID: pvc-c3def597-d1be-41bd-aaf9-b5aeec256b88 setting image options on kube/csi-vol-29f224fb-55aa-470d-83b4-fe046951b969
I0811 07:43:09.986294       1 controllerserver.go:763] ID: 23 Req-ID: pvc-c3def597-d1be-41bd-aaf9-b5aeec256b88 created image kube/csi-vol-29f224fb-55aa-470d-83b4-fe046951b969 backed for request name pvc-c3def597-d1be-41bd-aaf9-b5aeec256b88
I0811 07:43:10.014611       1 omap.go:159] ID: 23 Req-ID: pvc-c3def597-d1be-41bd-aaf9-b5aeec256b88 set omap keys (pool="kube", namespace="", name="csi.volume.29f224fb-55aa-470d-83b4-fe046951b969"): map[csi.imageid:38047a1b640a])
I0811 07:43:10.087077       1 utils.go:205] ID: 23 Req-ID: pvc-c3def597-d1be-41bd-aaf9-b5aeec256b88 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-29f224fb-55aa-470d-83b4-fe046951b969","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-29f224fb-55aa-470d-83b4-fe046951b969"}}
I0811 07:43:15.823705       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0811 07:43:15.823772       1 utils.go:199] ID: 24 GRPC request: {}
I0811 07:43:15.823795       1 utils.go:205] ID: 24 GRPC response: {}