I0302 18:34:42.879855       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0302 18:34:42.879975       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0302 18:34:42.879992       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0302 18:34:42.879995       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0302 18:34:42.880001       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0302 18:34:42.880004       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0302 18:34:42.880008       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0302 18:34:42.880012       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0302 18:34:42.880015       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0302 18:34:42.880019       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0302 18:34:42.880293       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0302 18:34:42.880310       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0302 18:34:48.976170       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0302 18:34:48.977613       1 utils.go:199] ID: 1 GRPC request: {}
I0302 18:34:48.977714       1 utils.go:205] ID: 1 GRPC response: {}
I0302 18:34:48.981213       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0302 18:34:48.981252       1 utils.go:199] ID: 2 GRPC request: {}
I0302 18:34:48.981287       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0302 18:34:48.981348       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0302 18:34:48.984380       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0302 18:34:48.984401       1 utils.go:199] ID: 3 GRPC request: {}
I0302 18:34:48.984414       1 utils.go:205] ID: 3 GRPC response: {}
I0302 18:34:48.984896       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0302 18:34:48.985060       1 utils.go:199] ID: 4 GRPC request: {}
I0302 18:34:48.985271       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0302 18:34:48.986047       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0302 18:34:48.986111       1 utils.go:199] ID: 5 GRPC request: {}
I0302 18:34:48.986120       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0302 18:34:48.986233       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}}}]}
I0302 18:34:59.880867       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0302 18:34:59.880907       1 utils.go:199] ID: 6 GRPC request: {}
I0302 18:34:59.880927       1 utils.go:205] ID: 6 GRPC response: {}
I0302 18:34:59.882704       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0302 18:34:59.882907       1 utils.go:199] ID: 7 GRPC request: {}
I0302 18:34:59.882918       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0302 18:34:59.882960       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0302 18:34:59.886253       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0302 18:34:59.886280       1 utils.go:199] ID: 8 GRPC request: {}
I0302 18:34:59.886297       1 utils.go:205] ID: 8 GRPC response: {}
I0302 18:34:59.886970       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0302 18:34:59.887062       1 utils.go:199] ID: 9 GRPC request: {}
I0302 18:34:59.887271       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0302 18:34:59.888161       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0302 18:34:59.888188       1 utils.go:199] ID: 10 GRPC request: {}
I0302 18:34:59.888198       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0302 18:34:59.888393       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}}}]}
I0302 18:34:59.889202       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0302 18:34:59.889284       1 utils.go:199] ID: 11 GRPC request: {}
I0302 18:34:59.889304       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0302 18:34:59.889535       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}}}]}
I0302 18:34:59.889966       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0302 18:34:59.889988       1 utils.go:199] ID: 12 GRPC request: {}
I0302 18:34:59.889996       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0302 18:34:59.890136       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}}}]}
I0302 18:35:02.715727       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0302 18:35:02.715801       1 utils.go:199] ID: 13 GRPC request: {}
I0302 18:35:02.715822       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0302 18:35:02.715868       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0302 18:35:02.719096       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0302 18:35:02.719138       1 utils.go:199] ID: 14 GRPC request: {}
I0302 18:35:02.719168       1 utils.go:205] ID: 14 GRPC response: {}
I0302 18:35:02.719779       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0302 18:35:02.719804       1 utils.go:199] ID: 15 GRPC request: {}
I0302 18:35:02.719814       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0302 18:35:02.719910       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}}}]}
I0302 18:35:04.783650       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0302 18:35:04.783699       1 utils.go:199] ID: 16 GRPC request: {}
I0302 18:35:04.783714       1 utils.go:205] ID: 16 GRPC response: {}
I0302 18:35:04.785063       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0302 18:35:04.785083       1 utils.go:199] ID: 17 GRPC request: {}
I0302 18:35:04.785090       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0302 18:35:04.785117       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0302 18:35:04.787730       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0302 18:35:04.787860       1 utils.go:199] ID: 18 GRPC request: {}
I0302 18:35:04.787944       1 utils.go:205] ID: 18 GRPC response: {}
I0302 18:35:04.788434       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0302 18:35:04.788456       1 utils.go:199] ID: 19 GRPC request: {}
I0302 18:35:04.788563       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0302 18:35:04.789010       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0302 18:35:04.789057       1 utils.go:199] ID: 20 GRPC request: {}
I0302 18:35:04.789082       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0302 18:35:04.789210       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}}}]}
I0302 18:36:05.052833       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0302 18:36:05.052969       1 utils.go:199] ID: 21 GRPC request: {}
I0302 18:36:05.053002       1 utils.go:205] ID: 21 GRPC response: {}
I0302 18:37:05.002614       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0302 18:37:05.002675       1 utils.go:199] ID: 22 GRPC request: {}
I0302 18:37:05.002701       1 utils.go:205] ID: 22 GRPC response: {}
I0302 18:37:59.198243       1 utils.go:198] ID: 23 Req-ID: pvc-8b660cd7-82eb-4133-a31c-fdc104c2d097 GRPC call: /csi.v1.Controller/CreateVolume
I0302 18:37:59.198504       1 utils.go:199] ID: 23 Req-ID: pvc-8b660cd7-82eb-4133-a31c-fdc104c2d097 GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-8b660cd7-82eb-4133-a31c-fdc104c2d097","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-8b660cd7-82eb-4133-a31c-fdc104c2d097","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}}]}
I0302 18:37:59.198718       1 rbd_util.go:1315] ID: 23 Req-ID: pvc-8b660cd7-82eb-4133-a31c-fdc104c2d097 setting disableInUseChecks: false image features: [layering] mounter: rbd
E0302 18:37:59.217055       1 omap.go:80] ID: 23 Req-ID: pvc-8b660cd7-82eb-4133-a31c-fdc104c2d097 omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0302 18:37:59.231522       1 omap.go:159] ID: 23 Req-ID: pvc-8b660cd7-82eb-4133-a31c-fdc104c2d097 set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-8b660cd7-82eb-4133-a31c-fdc104c2d097:8d04036b-d885-4a5b-972e-508578412815])
I0302 18:37:59.239274       1 omap.go:159] ID: 23 Req-ID: pvc-8b660cd7-82eb-4133-a31c-fdc104c2d097 set omap keys (pool="kube", namespace="", name="csi.volume.8d04036b-d885-4a5b-972e-508578412815"): map[csi.imagename:csi-vol-8d04036b-d885-4a5b-972e-508578412815 csi.volname:pvc-8b660cd7-82eb-4133-a31c-fdc104c2d097 csi.volume.owner:default])
I0302 18:37:59.239301       1 rbd_journal.go:491] ID: 23 Req-ID: pvc-8b660cd7-82eb-4133-a31c-fdc104c2d097 generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-8d04036b-d885-4a5b-972e-508578412815) and image name (csi-vol-8d04036b-d885-4a5b-972e-508578412815) for request name (pvc-8b660cd7-82eb-4133-a31c-fdc104c2d097)
I0302 18:37:59.239371       1 rbd_util.go:423] ID: 23 Req-ID: pvc-8b660cd7-82eb-4133-a31c-fdc104c2d097 rbd: create kube/csi-vol-8d04036b-d885-4a5b-972e-508578412815 size 5120M (features: [layering]) using mon 199.204.45.157
I0302 18:37:59.239411       1 rbd_util.go:1563] ID: 23 Req-ID: pvc-8b660cd7-82eb-4133-a31c-fdc104c2d097 setting image options on kube/csi-vol-8d04036b-d885-4a5b-972e-508578412815
I0302 18:38:00.769706       1 controllerserver.go:763] ID: 23 Req-ID: pvc-8b660cd7-82eb-4133-a31c-fdc104c2d097 created image kube/csi-vol-8d04036b-d885-4a5b-972e-508578412815 backed for request name pvc-8b660cd7-82eb-4133-a31c-fdc104c2d097
I0302 18:38:00.802496       1 omap.go:159] ID: 23 Req-ID: pvc-8b660cd7-82eb-4133-a31c-fdc104c2d097 set omap keys (pool="kube", namespace="", name="csi.volume.8d04036b-d885-4a5b-972e-508578412815"): map[csi.imageid:37d9f813fd68])
I0302 18:38:00.895887       1 utils.go:205] ID: 23 Req-ID: pvc-8b660cd7-82eb-4133-a31c-fdc104c2d097 GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-8d04036b-d885-4a5b-972e-508578412815","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-8d04036b-d885-4a5b-972e-508578412815"}}
I0302 18:38:05.000704       1 utils.go:198] ID: 24 GRPC call: /csi.v1.Identity/Probe
I0302 18:38:05.000741       1 utils.go:199] ID: 24 GRPC request: {}
I0302 18:38:05.000757       1 utils.go:205] ID: 24 GRPC response: {}