Incorrect log during /CreateSnapshot

[iPraveenParihar]

Describe the bug

Observed a incorrect log statement during the /CreateSnapshot

Steps to reproduce

1. Create a snapshot of a PV
2. Observe the logs of snapshot creation

Actual results

Parent volume created: csi-vol-93d21243-5528-49cd-b6d4-287a45eaf19f
Snapshot of parent created: csi-snap-4fc3c075-3c57-46ab-868a-5119c0d5a895
Clone of snapshot created: csi-snap-4fc3c075-3c57-46ab-868a-5119c0d5a895

Now, while creating a snapshot of the clone the log writes -

rbd: snap create replicapool/csi-vol-93d21243-5528-49cd-b6d4-287a45eaf19f@csi-snap-4fc3c075-3c57-46ab-868a-5119c0d5a895

Expected behavior

It should be

rbd: snap create replicapool/csi-snap-4fc3c075-3c57-46ab-868a-5119c0d5a895@csi-snap-4fc3c075-3c57-46ab-868a-5119c0d5a895

Logs

I0926 09:37:07.356964       1 utils.go:195] ID: 1423 Req-ID: snapshot-245d1669-a65c-4aec-bbbf-9078d50db200 GRPC call: /csi.v1.Controller/CreateSnapshot
I0926 09:37:07.357247       1 utils.go:206] ID: 1423 Req-ID: snapshot-245d1669-a65c-4aec-bbbf-9078d50db200 GRPC request: {"name":"snapshot-245d1669-a65c-4aec-bbbf-9078d50db200","parameters":{"clusterID":"ee5ee003-dd5e-4f38-9b12-8dc5bceed8c5","csi.storage.k8s.io/volumesnapshot/name":"rbd-pvc-snapshot","csi.storage.k8s.io/volumesnapshot/namespace":"ceph-csi","csi.storage.k8s.io/volumesnapshotcontent/name":"snapcontent-245d1669-a65c-4aec-bbbf-9078d50db200"},"secrets":"***stripped***","source_volume_id":"0001-0024-ee5ee003-dd5e-4f38-9b12-8dc5bceed8c5-0000000000000002-93d21243-5528-49cd-b6d4-287a45eaf19f"}
I0926 09:37:07.360616       1 omap.go:88] ID: 1423 Req-ID: snapshot-245d1669-a65c-4aec-bbbf-9078d50db200 got omap values: (pool="replicapool", namespace="", name="csi.volume.93d21243-5528-49cd-b6d4-287a45eaf19f"): map[csi.imageid:1424df2f483e csi.imagename:csi-vol-93d21243-5528-49cd-b6d4-287a45eaf19f csi.volname:pvc-666df2d3-5fa9-4171-918e-4150c7c70a35 csi.volume.owner:ceph-csi]
I0926 09:37:07.380633       1 omap.go:88] ID: 1423 Req-ID: snapshot-245d1669-a65c-4aec-bbbf-9078d50db200 got omap values: (pool="replicapool", namespace="", name="csi.snaps.default"): map[]
I0926 09:37:07.398819       1 omap.go:158] ID: 1423 Req-ID: snapshot-245d1669-a65c-4aec-bbbf-9078d50db200 set omap keys (pool="replicapool", namespace="", name="csi.snaps.default"): map[csi.snap.snapshot-245d1669-a65c-4aec-bbbf-9078d50db200:4fc3c075-3c57-46ab-868a-5119c0d5a895])
I0926 09:37:07.402228       1 omap.go:158] ID: 1423 Req-ID: snapshot-245d1669-a65c-4aec-bbbf-9078d50db200 set omap keys (pool="replicapool", namespace="", name="csi.snap.4fc3c075-3c57-46ab-868a-5119c0d5a895"): map[csi.imagename:csi-snap-4fc3c075-3c57-46ab-868a-5119c0d5a895 csi.snapname:snapshot-245d1669-a65c-4aec-bbbf-9078d50db200 csi.source:csi-vol-93d21243-5528-49cd-b6d4-287a45eaf19f csi.volume.owner:ceph-csi])
I0926 09:37:07.402328       1 rbd_journal.go:413] ID: 1423 Req-ID: snapshot-245d1669-a65c-4aec-bbbf-9078d50db200 generated Volume ID (0001-0024-ee5ee003-dd5e-4f38-9b12-8dc5bceed8c5-0000000000000002-4fc3c075-3c57-46ab-868a-5119c0d5a895) and image name (csi-snap-4fc3c075-3c57-46ab-868a-5119c0d5a895) for request name (snapshot-245d1669-a65c-4aec-bbbf-9078d50db200)
I0926 09:37:07.402426       1 rbd_util.go:1414] ID: 1423 Req-ID: snapshot-245d1669-a65c-4aec-bbbf-9078d50db200 rbd: snap create replicapool/csi-vol-93d21243-5528-49cd-b6d4-287a45eaf19f@csi-snap-4fc3c075-3c57-46ab-868a-5119c0d5a895 using mon 10.98.233.61:3300
I0926 09:37:08.409209       1 rbd_util.go:1452] ID: 1423 Req-ID: snapshot-245d1669-a65c-4aec-bbbf-9078d50db200 rbd: clone replicapool/csi-vol-93d21243-5528-49cd-b6d4-287a45eaf19f@csi-snap-4fc3c075-3c57-46ab-868a-5119c0d5a895 replicapool/csi-snap-4fc3c075-3c57-46ab-868a-5119c0d5a895 (features: [deep-flatten layering]) using mon 10.98.233.61:3300
I0926 09:37:08.409250       1 rbd_util.go:1556] ID: 1423 Req-ID: snapshot-245d1669-a65c-4aec-bbbf-9078d50db200 setting image options on replicapool/csi-snap-4fc3c075-3c57-46ab-868a-5119c0d5a895
I0926 09:37:08.452798       1 rbd_util.go:1427] ID: 1423 Req-ID: snapshot-245d1669-a65c-4aec-bbbf-9078d50db200 rbd: snap rm replicapool/csi-vol-93d21243-5528-49cd-b6d4-287a45eaf19f@csi-snap-4fc3c075-3c57-46ab-868a-5119c0d5a895 using mon 10.98.233.61:3300
I0926 09:37:08.463118       1 rbd_util.go:1414] ID: 1423 Req-ID: snapshot-245d1669-a65c-4aec-bbbf-9078d50db200 rbd: snap create replicapool/csi-vol-93d21243-5528-49cd-b6d4-287a45eaf19f@csi-snap-4fc3c075-3c57-46ab-868a-5119c0d5a895 using mon 10.98.233.61:3300
I0926 09:37:09.428990       1 omap.go:158] ID: 1423 Req-ID: snapshot-245d1669-a65c-4aec-bbbf-9078d50db200 set omap keys (pool="replicapool", namespace="", name="csi.snap.4fc3c075-3c57-46ab-868a-5119c0d5a895"): map[csi.imageid:1424f798b22a])
I0926 09:37:09.454766       1 rbd_util.go:810] ID: 1423 Req-ID: snapshot-245d1669-a65c-4aec-bbbf-9078d50db200 clone depth is (1), configured softlimit (4) and hardlimit (8) for replicapool/csi-snap-4fc3c075-3c57-46ab-868a-5119c0d5a895
I0926 09:37:09.568544       1 utils.go:212] ID: 1423 Req-ID: snapshot-245d1669-a65c-4aec-bbbf-9078d50db200 GRPC response: {"snapshot":{"creation_time":{"nanos":425742132,"seconds":1695721028},"ready_to_use":true,"size_bytes":1073741824,"snapshot_id":"0001-0024-ee5ee003-dd5e-4f38-9b12-8dc5bceed8c5-0000000000000002-4fc3c075-3c57-46ab-868a-5119c0d5a895","source_volume_id":"0001-0024-ee5ee003-dd5e-4f38-9b12-8dc5bceed8c5-0000000000000002-93d21243-5528-49cd-b6d4-287a45eaf19f"}}

ceph-csi/internal/rbd/controllerserver.go

Lines 1342 to 1350 in 3bbd20a

	err = cloneRbd.createSnapshot(ctx, rbdSnap)
	if err != nil {
	// update rbd image name for logging
	rbdSnap.RbdImageName = cloneRbd.RbdImageName
	log.ErrorLog(ctx, "failed to create snapshot %s: %v", rbdSnap, err)
	return cloneRbd, err
	}

Here, rbdSnap.RbdImageName = cloneRbd.RbdImageName should be set before calling the cloneRbd.createSnapshot(ctx, rbdSnap)