I0420 08:12:08.972199       1 cephcsi.go:191] Driver version: v3.11.0 and Git version: bc24b5eca87626d690a29effa9d7420cc0154a7a
I0420 08:12:08.972359       1 cephcsi.go:223] Starting driver type: rbd with name: rbd.csi.ceph.com
I0420 08:12:08.972388       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_VOLUME
I0420 08:12:08.972392       1 driver.go:95] Enabling controller service capability: CREATE_DELETE_SNAPSHOT
I0420 08:12:08.972395       1 driver.go:95] Enabling controller service capability: CLONE_VOLUME
I0420 08:12:08.972398       1 driver.go:95] Enabling controller service capability: EXPAND_VOLUME
I0420 08:12:08.972406       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_WRITER
I0420 08:12:08.972409       1 driver.go:108] Enabling volume access mode: MULTI_NODE_MULTI_WRITER
I0420 08:12:08.972411       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_SINGLE_WRITER
I0420 08:12:08.972414       1 driver.go:108] Enabling volume access mode: SINGLE_NODE_MULTI_WRITER
I0420 08:12:08.972754       1 server.go:117] Listening for connections on address: &net.UnixAddr{Name:"//csi/csi-provisioner.sock", Net:"unix"}
I0420 08:12:08.972916       1 server.go:114] listening for CSI-Addons requests on address: &net.UnixAddr{Name:"/csi/csi-addons.sock", Net:"unix"}
I0420 08:12:11.755853       1 utils.go:198] ID: 1 GRPC call: /csi.v1.Identity/Probe
I0420 08:12:11.756940       1 utils.go:199] ID: 1 GRPC request: {}
I0420 08:12:11.756977       1 utils.go:205] ID: 1 GRPC response: {}
I0420 08:12:11.760771       1 utils.go:198] ID: 2 GRPC call: /csi.v1.Identity/GetPluginInfo
I0420 08:12:11.760863       1 utils.go:199] ID: 2 GRPC request: {}
I0420 08:12:11.760880       1 identityserver-default.go:40] ID: 2 Using default GetPluginInfo
I0420 08:12:11.760931       1 utils.go:205] ID: 2 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0420 08:12:11.761943       1 utils.go:198] ID: 3 GRPC call: /csi.v1.Identity/Probe
I0420 08:12:11.761999       1 utils.go:199] ID: 3 GRPC request: {}
I0420 08:12:11.762055       1 utils.go:205] ID: 3 GRPC response: {}
I0420 08:12:11.762296       1 utils.go:198] ID: 4 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0420 08:12:11.762342       1 utils.go:199] ID: 4 GRPC request: {}
I0420 08:12:11.762448       1 utils.go:205] ID: 4 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0420 08:12:11.762951       1 utils.go:198] ID: 5 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0420 08:12:11.763005       1 utils.go:199] ID: 5 GRPC request: {}
I0420 08:12:11.763042       1 controllerserver-default.go:42] ID: 5 Using default ControllerGetCapabilities
I0420 08:12:11.763192       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}}}]}
I0420 08:12:13.845088       1 utils.go:198] ID: 6 GRPC call: /csi.v1.Identity/Probe
I0420 08:12:13.845219       1 utils.go:199] ID: 6 GRPC request: {}
I0420 08:12:13.845308       1 utils.go:205] ID: 6 GRPC response: {}
I0420 08:12:13.848414       1 utils.go:198] ID: 7 GRPC call: /csi.v1.Identity/GetPluginInfo
I0420 08:12:13.848445       1 utils.go:199] ID: 7 GRPC request: {}
I0420 08:12:13.848545       1 identityserver-default.go:40] ID: 7 Using default GetPluginInfo
I0420 08:12:13.848701       1 utils.go:205] ID: 7 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0420 08:12:13.850627       1 utils.go:198] ID: 8 GRPC call: /csi.v1.Identity/Probe
I0420 08:12:13.850723       1 utils.go:199] ID: 8 GRPC request: {}
I0420 08:12:13.850752       1 utils.go:205] ID: 8 GRPC response: {}
I0420 08:12:13.851369       1 utils.go:198] ID: 9 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0420 08:12:13.851401       1 utils.go:199] ID: 9 GRPC request: {}
I0420 08:12:13.851603       1 utils.go:205] ID: 9 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0420 08:12:13.852374       1 utils.go:198] ID: 10 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0420 08:12:13.852407       1 utils.go:199] ID: 10 GRPC request: {}
I0420 08:12:13.852424       1 controllerserver-default.go:42] ID: 10 Using default ControllerGetCapabilities
I0420 08:12:13.852576       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}}}]}
I0420 08:12:13.853141       1 utils.go:198] ID: 11 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0420 08:12:13.853166       1 utils.go:199] ID: 11 GRPC request: {}
I0420 08:12:13.853257       1 controllerserver-default.go:42] ID: 11 Using default ControllerGetCapabilities
I0420 08:12:13.853462       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}}}]}
I0420 08:12:13.853962       1 utils.go:198] ID: 12 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0420 08:12:13.853987       1 utils.go:199] ID: 12 GRPC request: {}
I0420 08:12:13.853995       1 controllerserver-default.go:42] ID: 12 Using default ControllerGetCapabilities
I0420 08:12:13.854120       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}}}]}
I0420 08:12:15.018729       1 utils.go:198] ID: 13 GRPC call: /csi.v1.Identity/GetPluginInfo
I0420 08:12:15.018775       1 utils.go:199] ID: 13 GRPC request: {}
I0420 08:12:15.018786       1 identityserver-default.go:40] ID: 13 Using default GetPluginInfo
I0420 08:12:15.018818       1 utils.go:205] ID: 13 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0420 08:12:15.020902       1 utils.go:198] ID: 14 GRPC call: /csi.v1.Identity/Probe
I0420 08:12:15.020948       1 utils.go:199] ID: 14 GRPC request: {}
I0420 08:12:15.020971       1 utils.go:205] ID: 14 GRPC response: {}
I0420 08:12:15.021370       1 utils.go:198] ID: 15 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0420 08:12:15.021397       1 utils.go:199] ID: 15 GRPC request: {}
I0420 08:12:15.021408       1 controllerserver-default.go:42] ID: 15 Using default ControllerGetCapabilities
I0420 08:12:15.021667       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}}}]}
I0420 08:12:16.347450       1 utils.go:198] ID: 16 GRPC call: /csi.v1.Identity/Probe
I0420 08:12:16.347800       1 utils.go:199] ID: 16 GRPC request: {}
I0420 08:12:16.347870       1 utils.go:205] ID: 16 GRPC response: {}
I0420 08:12:16.350678       1 utils.go:198] ID: 17 GRPC call: /csi.v1.Identity/GetPluginInfo
I0420 08:12:16.350711       1 utils.go:199] ID: 17 GRPC request: {}
I0420 08:12:16.350718       1 identityserver-default.go:40] ID: 17 Using default GetPluginInfo
I0420 08:12:16.350738       1 utils.go:205] ID: 17 GRPC response: {"name":"rbd.csi.ceph.com","vendor_version":"v3.11.0"}
I0420 08:12:16.352870       1 utils.go:198] ID: 18 GRPC call: /csi.v1.Identity/Probe
I0420 08:12:16.352891       1 utils.go:199] ID: 18 GRPC request: {}
I0420 08:12:16.352901       1 utils.go:205] ID: 18 GRPC response: {}
I0420 08:12:16.353345       1 utils.go:198] ID: 19 GRPC call: /csi.v1.Identity/GetPluginCapabilities
I0420 08:12:16.353388       1 utils.go:199] ID: 19 GRPC request: {}
I0420 08:12:16.353545       1 utils.go:205] ID: 19 GRPC response: {"capabilities":[{"Type":{"Service":{"type":1}}},{"Type":{"VolumeExpansion":{"type":1}}},{"Type":{"Service":{"type":2}}}]}
I0420 08:12:16.354302       1 utils.go:198] ID: 20 GRPC call: /csi.v1.Controller/ControllerGetCapabilities
I0420 08:12:16.354315       1 utils.go:199] ID: 20 GRPC request: {}
I0420 08:12:16.354323       1 controllerserver-default.go:42] ID: 20 Using default ControllerGetCapabilities
I0420 08:12:16.354442       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}}}]}
I0420 08:13:16.567046       1 utils.go:198] ID: 21 GRPC call: /csi.v1.Identity/Probe
I0420 08:13:16.567143       1 utils.go:199] ID: 21 GRPC request: {}
I0420 08:13:16.567200       1 utils.go:205] ID: 21 GRPC response: {}
I0420 08:14:16.521464       1 utils.go:198] ID: 22 GRPC call: /csi.v1.Identity/Probe
I0420 08:14:16.521543       1 utils.go:199] ID: 22 GRPC request: {}
I0420 08:14:16.521582       1 utils.go:205] ID: 22 GRPC response: {}
I0420 08:15:16.520083       1 utils.go:198] ID: 23 GRPC call: /csi.v1.Identity/Probe
I0420 08:15:16.520141       1 utils.go:199] ID: 23 GRPC request: {}
I0420 08:15:16.520168       1 utils.go:205] ID: 23 GRPC response: {}
I0420 08:15:19.398501       1 utils.go:198] ID: 24 Req-ID: pvc-5f8d7678-868e-4ede-ae55-f977e26fb1ad GRPC call: /csi.v1.Controller/CreateVolume
I0420 08:15:19.399220       1 utils.go:199] ID: 24 Req-ID: pvc-5f8d7678-868e-4ede-ae55-f977e26fb1ad GRPC request: {"capacity_range":{"required_bytes":5368709120},"name":"pvc-5f8d7678-868e-4ede-ae55-f977e26fb1ad","parameters":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","csi.storage.k8s.io/pv/name":"pvc-5f8d7678-868e-4ede-ae55-f977e26fb1ad","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}}]}
I0420 08:15:19.399662       1 rbd_util.go:1315] ID: 24 Req-ID: pvc-5f8d7678-868e-4ede-ae55-f977e26fb1ad setting disableInUseChecks: false image features: [layering] mounter: rbd
E0420 08:15:19.418035       1 omap.go:80] ID: 24 Req-ID: pvc-5f8d7678-868e-4ede-ae55-f977e26fb1ad omap not found (pool="kube", namespace="", name="csi.volumes.default"): rados: ret=-2, No such file or directory
I0420 08:15:19.433038       1 omap.go:159] ID: 24 Req-ID: pvc-5f8d7678-868e-4ede-ae55-f977e26fb1ad set omap keys (pool="kube", namespace="", name="csi.volumes.default"): map[csi.volume.pvc-5f8d7678-868e-4ede-ae55-f977e26fb1ad:60870347-69be-4888-95e3-c26c49c68c0a])
I0420 08:15:19.439027       1 omap.go:159] ID: 24 Req-ID: pvc-5f8d7678-868e-4ede-ae55-f977e26fb1ad set omap keys (pool="kube", namespace="", name="csi.volume.60870347-69be-4888-95e3-c26c49c68c0a"): map[csi.imagename:csi-vol-60870347-69be-4888-95e3-c26c49c68c0a csi.volname:pvc-5f8d7678-868e-4ede-ae55-f977e26fb1ad csi.volume.owner:default])
I0420 08:15:19.439082       1 rbd_journal.go:491] ID: 24 Req-ID: pvc-5f8d7678-868e-4ede-ae55-f977e26fb1ad generated Volume ID (0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-60870347-69be-4888-95e3-c26c49c68c0a) and image name (csi-vol-60870347-69be-4888-95e3-c26c49c68c0a) for request name (pvc-5f8d7678-868e-4ede-ae55-f977e26fb1ad)
I0420 08:15:19.439311       1 rbd_util.go:423] ID: 24 Req-ID: pvc-5f8d7678-868e-4ede-ae55-f977e26fb1ad rbd: create kube/csi-vol-60870347-69be-4888-95e3-c26c49c68c0a size 5120M (features: [layering]) using mon 199.19.213.151
I0420 08:15:19.439370       1 rbd_util.go:1563] ID: 24 Req-ID: pvc-5f8d7678-868e-4ede-ae55-f977e26fb1ad setting image options on kube/csi-vol-60870347-69be-4888-95e3-c26c49c68c0a
I0420 08:15:20.559507       1 controllerserver.go:763] ID: 24 Req-ID: pvc-5f8d7678-868e-4ede-ae55-f977e26fb1ad created image kube/csi-vol-60870347-69be-4888-95e3-c26c49c68c0a backed for request name pvc-5f8d7678-868e-4ede-ae55-f977e26fb1ad
I0420 08:15:20.600412       1 omap.go:159] ID: 24 Req-ID: pvc-5f8d7678-868e-4ede-ae55-f977e26fb1ad set omap keys (pool="kube", namespace="", name="csi.volume.60870347-69be-4888-95e3-c26c49c68c0a"): map[csi.imageid:37d9e560043b])
I0420 08:15:20.697676       1 utils.go:205] ID: 24 Req-ID: pvc-5f8d7678-868e-4ede-ae55-f977e26fb1ad GRPC response: {"volume":{"capacity_bytes":5368709120,"volume_context":{"clusterID":"4837cbf8-4f90-4300-b3f6-726c9b9f89b4","imageFeatures":"layering","imageName":"csi-vol-60870347-69be-4888-95e3-c26c49c68c0a","journalPool":"kube","pool":"kube"},"volume_id":"0001-0024-4837cbf8-4f90-4300-b3f6-726c9b9f89b4-0000000000000002-60870347-69be-4888-95e3-c26c49c68c0a"}}