I0227 14:49:40.218062       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0227 14:49:40.218225       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0227 14:49:40.218252       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0227 14:49:40.218277       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0227 14:49:40.218295       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0227 14:49:40.218309       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0227 14:49:40.218352       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0227 14:49:40.218462       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0227 14:49:40.218485       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0227 14:49:40.218498       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0227 14:49:40.218741       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0227 14:49:40.218793       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0227 14:49:42.406785       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0227 14:49:42.409908       1 utils.go:199] ID: 1 GRPC request: {}
I0227 14:49:42.410019       1 utils.go:205] ID: 1 GRPC response: {}
I0227 14:49:42.414445       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0227 14:49:42.414581       1 utils.go:199] ID: 2 GRPC request: {}
I0227 14:49:42.414618       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0227 14:49:42.414713       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0227 14:49:42.416247       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0227 14:49:42.416354       1 utils.go:199] ID: 3 GRPC request: {}
I0227 14:49:42.416395       1 utils.go:205] ID: 3 GRPC response: {}
I0227 14:49:42.416810       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0227 14:49:42.416961       1 utils.go:199] ID: 4 GRPC request: {}
I0227 14:49:42.417243       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0227 14:49:42.418084       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0227 14:49:42.418180       1 utils.go:199] ID: 5 GRPC request: {}
I0227 14:49:42.418211       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0227 14:49:42.418352       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}}}]}
I0227 14:49:45.903303       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0227 14:49:45.903347       1 utils.go:199] ID: 6 GRPC request: {}
I0227 14:49:45.903360       1 utils.go:205] ID: 6 GRPC response: {}
I0227 14:49:45.906084       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0227 14:49:45.906121       1 utils.go:199] ID: 7 GRPC request: {}
I0227 14:49:45.906130       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0227 14:49:45.906153       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0227 14:49:45.909853       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0227 14:49:45.909870       1 utils.go:199] ID: 8 GRPC request: {}
I0227 14:49:45.909878       1 utils.go:205] ID: 8 GRPC response: {}
I0227 14:49:45.910474       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0227 14:49:45.910490       1 utils.go:199] ID: 9 GRPC request: {}
I0227 14:49:45.910553       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0227 14:49:45.914481       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0227 14:49:45.914511       1 utils.go:199] ID: 10 GRPC request: {}
I0227 14:49:45.914518       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0227 14:49:45.914614       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}}}]}
I0227 14:49:45.915085       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0227 14:49:45.915138       1 utils.go:199] ID: 11 GRPC request: {}
I0227 14:49:45.915162       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0227 14:49:45.915256       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}}}]}
I0227 14:49:45.915677       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0227 14:49:45.915701       1 utils.go:199] ID: 12 GRPC request: {}
I0227 14:49:45.915706       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0227 14:49:45.915752       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}}}]}
I0227 14:49:52.093113       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/Probe
I0227 14:49:52.093163       1 utils.go:199] ID: 13 GRPC request: {}
I0227 14:49:52.093179       1 utils.go:205] ID: 13 GRPC response: {}
I0227 14:49:52.094864       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/GetPluginInfo
I0227 14:49:52.094884       1 utils.go:199] ID: 14 GRPC request: {}
I0227 14:49:52.094891       1 identityserver-default.go:40] ID: 14 Using default GetPluginInfo
I0227 14:49:52.094914       1 utils.go:205] ID: 14 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0227 14:49:52.098164       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Identity/Probe
I0227 14:49:52.098198       1 utils.go:199] ID: 15 GRPC request: {}
I0227 14:49:52.098217       1 utils.go:205] ID: 15 GRPC response: {}
I0227 14:49:52.098575       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0227 14:49:52.098621       1 utils.go:199] ID: 16 GRPC request: {}
I0227 14:49:52.098849       1 utils.go:205] ID: 16 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0227 14:49:52.099689       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0227 14:49:52.099712       1 utils.go:199] ID: 17 GRPC request: {}
I0227 14:49:52.099720       1 controllerserver-default.go:42] ID: 17 Using default ControllerGetCapabilities
I0227 14:49:52.100545       1 utils.go:205] ID: 17 GRPC response: {"capabilities":[{"Type":{"Rpc":{"type":1}}},{"Type":{"Rpc":{"type":5}}},{"Type":{"Rpc":{"type":7}}},{"Type":{"Rpc":{"type":9}}}]}
I0227 14:50:08.971555       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/GetPluginInfo
I0227 14:50:08.971587       1 utils.go:199] ID: 18 GRPC request: {}
I0227 14:50:08.971594       1 identityserver-default.go:40] ID: 18 Using default GetPluginInfo
I0227 14:50:08.971627       1 utils.go:205] ID: 18 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0227 14:50:08.974116       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/Probe
I0227 14:50:08.974148       1 utils.go:199] ID: 19 GRPC request: {}
I0227 14:50:08.974163       1 utils.go:205] ID: 19 GRPC response: {}
I0227 14:50:08.974682       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0227 14:50:08.974701       1 utils.go:199] ID: 20 GRPC request: {}
I0227 14:50:08.974723       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0227 14:50:08.974820       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}}}]}
I0227 14:50:52.644303       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0227 14:50:52.644624       1 utils.go:199] ID: 21 GRPC request: {}
I0227 14:50:52.644735       1 utils.go:205] ID: 21 GRPC response: {}
I0227 14:51:52.609371       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0227 14:51:52.609474       1 utils.go:199] ID: 22 GRPC request: {}
I0227 14:51:52.609501       1 utils.go:205] ID: 22 GRPC response: {}
I0227 14:52:44.647837       1 utils.go:198] ID: 23 Req-ID: pvc-47addc7d-5448-458c-9c5d-f7c7bb503c2a GRPC call: /csi.v1.Controller/CreateVolume
I0227 14:52:44.648274       1 utils.go:199] ID: 23 Req-ID: pvc-47addc7d-5448-458c-9c5d-f7c7bb503c2a GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-47addc7d-5448-458c-9c5d-f7c7bb503c2a","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-47addc7d-5448-458c-9c5d-f7c7bb503c2a","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}}]}
I0227 14:52:44.648966       1 rbd_util.go:1315] ID: 23 Req-ID: pvc-47addc7d-5448-458c-9c5d-f7c7bb503c2a setting disableInUseChecks: false image features: [layering] mounter: rbd
E0227 14:52:44.670529       1 omap.go:80] ID: 23 Req-ID: pvc-47addc7d-5448-458c-9c5d-f7c7bb503c2a omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0227 14:52:44.688408       1 omap.go:159] ID: 23 Req-ID: pvc-47addc7d-5448-458c-9c5d-f7c7bb503c2a set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-47addc7d-5448-458c-9c5d-f7c7bb503c2a:b9e87cee-23d1-42b3-b230-ac3f2f199547])
I0227 14:52:44.696500       1 omap.go:159] ID: 23 Req-ID: pvc-47addc7d-5448-458c-9c5d-f7c7bb503c2a set omap keys (pool="kube", namespace="", name="csi.volume.b9e87cee-23d1-42b3-b230-ac3f2f199547"): map[csi.imagename:csi-vol-b9e87cee-23d1-42b3-b230-ac3f2f199547 csi.volname:pvc-47addc7d-5448-458c-9c5d-f7c7bb503c2a csi.volume.owner:default])
I0227 14:52:44.696593       1 rbd_journal.go:491] ID: 23 Req-ID: pvc-47addc7d-5448-458c-9c5d-f7c7bb503c2a generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-b9e87cee-23d1-42b3-b230-ac3f2f199547) and image name (csi-vol-b9e87cee-23d1-42b3-b230-ac3f2f199547) for request name (pvc-47addc7d-5448-458c-9c5d-f7c7bb503c2a)
I0227 14:52:44.696701       1 rbd_util.go:423] ID: 23 Req-ID: pvc-47addc7d-5448-458c-9c5d-f7c7bb503c2a rbd: create kube/csi-vol-b9e87cee-23d1-42b3-b230-ac3f2f199547 size 5120M (features: [layering]) using mon 199.204.45.225
I0227 14:52:44.696833       1 rbd_util.go:1563] ID: 23 Req-ID: pvc-47addc7d-5448-458c-9c5d-f7c7bb503c2a setting image options on kube/csi-vol-b9e87cee-23d1-42b3-b230-ac3f2f199547
I0227 14:52:46.804110       1 controllerserver.go:763] ID: 23 Req-ID: pvc-47addc7d-5448-458c-9c5d-f7c7bb503c2a created image kube/csi-vol-b9e87cee-23d1-42b3-b230-ac3f2f199547 backed for request name pvc-47addc7d-5448-458c-9c5d-f7c7bb503c2a
I0227 14:52:46.853861       1 omap.go:159] ID: 23 Req-ID: pvc-47addc7d-5448-458c-9c5d-f7c7bb503c2a set omap keys (pool="kube", namespace="", name="csi.volume.b9e87cee-23d1-42b3-b230-ac3f2f199547"): map[csi.imageid:37d84f4d1a19])
I0227 14:52:46.949138       1 utils.go:205] ID: 23 Req-ID: pvc-47addc7d-5448-458c-9c5d-f7c7bb503c2a GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-b9e87cee-23d1-42b3-b230-ac3f2f199547","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-b9e87cee-23d1-42b3-b230-ac3f2f199547"}}
I0227 14:52:52.608345       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0227 14:52:52.608419       1 utils.go:199] ID: 24 GRPC request: {}
I0227 14:52:52.608583       1 utils.go:205] ID: 24 GRPC response: {}