fix: ensure kubevirt migration uses current migration state

Add MigrationUID validation to prevent stale state usage during
consecutive VM migrations (e.g., A→B→A).

Changes:
1. Add MigrationUID check: Only use vmi.Status.MigrationState if
   MigrationUID matches current vmiMigration.UID
2. Simplify MigrationScheduling: Wait for valid state instead of
   using Pod/vmi.Status.NodeName fallback
3. Add unit tests covering UID validation and migration scenarios

The root cause was that vmi.Status.MigrationState could contain stale
info from a previous migration, causing incorrect node detection and
skipping SetLogicalSwitchPortMigrateOptions.

Fixes: #6220
Signed-off-by: zbb88888 <jmdxjsjgcxy@gmail.com>

Author: zbb88888

pkg/controller/kubevirt.go

@@ -18,19 +18,21 @@ import (
 )
 
 func (c *Controller) enqueueAddVMIMigration(obj any) {
-	key := cache.MetaObjectToName(obj.(*kubevirtv1.VirtualMachineInstanceMigration)).String()
+	vmiMigration := obj.(*kubevirtv1.VirtualMachineInstanceMigration)
+	key := cache.MetaObjectToName(vmiMigration).String()
 	klog.Infof("enqueue add VMI migration %s", key)
 	c.addOrUpdateVMIMigrationQueue.Add(key)
 }
 
 func (c *Controller) enqueueUpdateVMIMigration(oldObj, newObj any) {
-	oldVmi := oldObj.(*kubevirtv1.VirtualMachineInstanceMigration)
-	newVmi := newObj.(*kubevirtv1.VirtualMachineInstanceMigration)
+	oldVmiMigration := oldObj.(*kubevirtv1.VirtualMachineInstanceMigration)
+	newVmiMigration := newObj.(*kubevirtv1.VirtualMachineInstanceMigration)
 
-	if !newVmi.DeletionTimestamp.IsZero() ||
-		oldVmi.Status.Phase != newVmi.Status.Phase {
-		key := cache.MetaObjectToName(newVmi).String()
-		klog.Infof("enqueue update VMI migration %s", key)
+	if !newVmiMigration.DeletionTimestamp.IsZero() ||
+		oldVmiMigration.Status.Phase != newVmiMigration.Status.Phase {
+		key := cache.MetaObjectToName(newVmiMigration).String()
+		klog.Infof("enqueue update VMI migration %s (phase: %s -> %s)",
+			key, oldVmiMigration.Status.Phase, newVmiMigration.Status.Phase)
 		c.addOrUpdateVMIMigrationQueue.Add(key)
 	}
 }
@@ -93,6 +95,9 @@ func (c *Controller) handleDeleteVM(key string) error {
 	return nil
 }
 
+// handleAddOrUpdateVMIMigration handles VirtualMachineInstanceMigration events.
+// KubeVirt ensures only ONE active migration per VMI at any time.
+// Process one migration at a time.
 func (c *Controller) handleAddOrUpdateVMIMigration(key string) error {
 	namespace, name, err := cache.SplitMetaNamespaceKey(key)
 	if err != nil {
@@ -105,102 +110,128 @@ func (c *Controller) handleAddOrUpdateVMIMigration(key string) error {
 		utilruntime.HandleError(fmt.Errorf("failed to get VMI migration by key %s: %w", key, err))
 		return err
 	}
+
+	migrationUID := vmiMigration.UID
+	vmiName := vmiMigration.Spec.VMIName
+	phase := vmiMigration.Status.Phase
+
+	// ====== MIGRATION LIFECYCLE MARKERS ======
+	// Log migration lifecycle events for debugging and tracking
+	switch phase {
+	case kubevirtv1.MigrationPending:
+		klog.Infof(">>> [MIGRATION START] New migration %s (UID: %s) for VMI %s/%s - Phase: %s",
+			key, migrationUID, namespace, vmiName, phase)
+	case kubevirtv1.MigrationSucceeded:
+		klog.Infof("<<< [MIGRATION END] Migration %s (UID: %s) for VMI %s/%s SUCCEEDED",
+			key, migrationUID, namespace, vmiName)
+	case kubevirtv1.MigrationFailed:
+		klog.Infof("<<< [MIGRATION END] Migration %s (UID: %s) for VMI %s/%s FAILED",
+			key, migrationUID, namespace, vmiName)
+	default:
+		klog.Infof("--- [MIGRATION PROGRESS] Migration %s (UID: %s) for VMI %s/%s - Phase: %s",
+			key, migrationUID, namespace, vmiName, phase)
+	}
+
+	// Skip if migration state is not yet initialized
 	if vmiMigration.Status.MigrationState == nil {
-		klog.V(3).Infof("VirtualMachineInstanceMigration %s migration state is nil, skipping", key)
+		klog.V(3).Infof("VirtualMachineInstanceMigration %s (UID: %s) migration state is nil, waiting for KubeVirt to initialize",
+			key, migrationUID)
 		return nil
 	}
 
+	// Skip completed migrations (already processed in final phase)
 	if vmiMigration.Status.MigrationState.Completed {
-		klog.V(3).Infof("VirtualMachineInstanceMigration %s migration state is completed, skipping", key)
+		klog.V(3).Infof("VirtualMachineInstanceMigration %s (UID: %s) migration state is already completed, skipping",
+			key, migrationUID)
 		return nil
 	}
 
-	vmi, err := c.config.KubevirtClient.VirtualMachineInstance(namespace).Get(context.TODO(), vmiMigration.Spec.VMIName, metav1.GetOptions{})
+	// Get VMI to access current migration state
+	vmi, err := c.config.KubevirtClient.VirtualMachineInstance(namespace).Get(context.TODO(), vmiName, metav1.GetOptions{})
 	if err != nil {
-		utilruntime.HandleError(fmt.Errorf("failed to get VMI by name %s: %w", vmiMigration.Spec.VMIName, err))
+		utilruntime.HandleError(fmt.Errorf("failed to get VMI by name %s: %w", vmiName, err))
 		return err
 	}
 
-	// use VirtualMachineInstance's MigrationState because VirtualMachineInstanceMigration's MigrationState is not updated until migration finished
-	var srcNodeName, targetNodeName string
-	if vmi.Status.MigrationState != nil {
-		klog.Infof("current vmiMigration %s status %s, target Node %s, source Node %s, target Pod %s, source Pod %s", key,
-			vmiMigration.Status.Phase,
-			vmi.Status.MigrationState.TargetNode,
-			vmi.Status.MigrationState.SourceNode,
-			vmi.Status.MigrationState.TargetPod,
-			vmi.Status.MigrationState.SourcePod)
-		srcNodeName = vmi.Status.MigrationState.SourceNode
-		targetNodeName = vmi.Status.MigrationState.TargetNode
-	} else {
-		klog.Infof("current vmiMigration %s status %s, vmi MigrationState is nil", key, vmiMigration.Status.Phase)
+	portName := ovs.PodNameToPortName(vmiName, namespace, util.OvnProvider)
+
+	// ====== MIGRATION UID VALIDATION ======
+	// Only use vmi.Status.MigrationState if its MigrationUID matches the current vmiMigration.UID.
+	// This prevents using stale state from a previous migration (e.g., stale A→B data when doing B→X migration).
+	// Wait for MigrationState to be fully populated before processing - there's enough time between
+	// target pod creation and actual migration start.
+	if vmi.Status.MigrationState == nil {
+		klog.V(3).Infof("Migration %s (UID: %s) - VMI MigrationState is nil, waiting for KubeVirt to populate",
+			key, migrationUID)
+		return nil
 	}
 
-	portName := ovs.PodNameToPortName(vmiMigration.Spec.VMIName, vmiMigration.Namespace, util.OvnProvider)
-	switch vmiMigration.Status.Phase {
+	vmiMigrationUID := vmi.Status.MigrationState.MigrationUID
+	if vmiMigrationUID != migrationUID {
+		// Only process the current migration; previous migrations are assumed to be already handled
+		klog.Warningf("Migration %s (UID: %s) - VMI MigrationState is STALE (contains old UID: %s), skipping",
+			key, migrationUID, vmiMigrationUID)
+		return nil
+	}
+
+	srcNodeName := vmi.Status.MigrationState.SourceNode
+	targetNodeName := vmi.Status.MigrationState.TargetNode
+	if srcNodeName == "" || targetNodeName == "" {
+		klog.V(3).Infof("Migration %s (UID: %s) - VMI MigrationState incomplete (source: %q, target: %q), waiting for KubeVirt",
+			key, migrationUID, srcNodeName, targetNodeName)
+		return nil
+	}
+
+	klog.Infof("Migration %s (UID: %s) - source: %s, target: %s", key, migrationUID, srcNodeName, targetNodeName)
+
+	switch phase {
 	case kubevirtv1.MigrationScheduling:
-		selector, err := metav1.LabelSelectorAsSelector(&metav1.LabelSelector{
-			MatchLabels: map[string]string{
-				kubevirtv1.MigrationJobLabel: string(vmiMigration.UID),
-			},
-		})
-		if err != nil {
-			err = fmt.Errorf("failed to create label selector for migration job UID %s: %w", vmiMigration.UID, err)
-			klog.Error(err)
-			return err
+		// Skip if source and target are the same (shouldn't happen in normal migration)
+		if srcNodeName == targetNodeName {
+			klog.Warningf("Migration %s (UID: %s) - Source and target are same node %s, skipping LSP setup",
+				key, migrationUID, srcNodeName)
+			return nil
 		}
 
-		pods, err := c.podsLister.Pods(vmiMigration.Namespace).List(selector)
-		if err != nil {
-			err = fmt.Errorf("failed to list pods with migration job UID %s: %w", vmiMigration.UID, err)
+		klog.Infof(">>> [MIGRATION LSP SET] Migration %s (UID: %s) - Setting LSP %s migrate options: %s -> %s",
+			key, migrationUID, portName, srcNodeName, targetNodeName)
+
+		if err := c.OVNNbClient.SetLogicalSwitchPortMigrateOptions(portName, srcNodeName, targetNodeName); err != nil {
+			err = fmt.Errorf("failed to set migrate options for lsp %s: %w", portName, err)
 			klog.Error(err)
 			return err
 		}
 
-		if len(pods) > 0 {
-			targetPod := pods[0]
-			// During MigrationScheduling phase, use vmi.Status.NodeName if SourceNode is empty
-			// because vmi.Status.MigrationState may not be fully synchronized yet
-			sourceNode := srcNodeName
-			if sourceNode == "" {
-				sourceNode = vmi.Status.NodeName
-			}
+		klog.Infof(">>> [MIGRATION LSP SET OK] Migration %s (UID: %s) - Successfully set LSP %s migrate options",
+			key, migrationUID, portName)
 
-			if sourceNode == "" || targetPod.Spec.NodeName == "" || sourceNode == targetPod.Spec.NodeName {
-				klog.Warningf("VM pod %s/%s migration setup skipped, source node: %s, target node: %s (migration job UID: %s)",
-					targetPod.Namespace, targetPod.Name, sourceNode, targetPod.Spec.NodeName, vmiMigration.UID)
-				return nil
-			}
-
-			klog.Infof("VM pod %s/%s is migrating from %s to %s (migration job UID: %s)",
-				targetPod.Namespace, targetPod.Name, sourceNode, targetPod.Spec.NodeName, vmiMigration.UID)
-
-			if err := c.OVNNbClient.SetLogicalSwitchPortMigrateOptions(portName, sourceNode, targetPod.Spec.NodeName); err != nil {
-				err = fmt.Errorf("failed to set migrate options for VM pod lsp %s: %w", portName, err)
-				klog.Error(err)
-				return err
-			}
-			klog.Infof("successfully set migrate options for lsp %s from %s to %s", portName, sourceNode, targetPod.Spec.NodeName)
-		} else {
-			klog.Warningf("target pod not yet created for migration job UID %s in phase %s, waiting for pod creation",
-				vmiMigration.UID, vmiMigration.Status.Phase)
-			return nil
-		}
 	case kubevirtv1.MigrationSucceeded:
-		klog.Infof("migrate end reset options for lsp %s from %s to %s, migrated succeed", portName, srcNodeName, targetNodeName)
+		klog.Infof("<<< [MIGRATION LSP RESET] Migration %s (UID: %s) - Resetting LSP %s to target %s (migration succeeded)",
+			key, migrationUID, portName, targetNodeName)
+
 		if err := c.OVNNbClient.ResetLogicalSwitchPortMigrateOptions(portName, srcNodeName, targetNodeName, false); err != nil {
-			err = fmt.Errorf("failed to clean migrate options for lsp %s, %w", portName, err)
+			err = fmt.Errorf("failed to reset migrate options for lsp %s: %w", portName, err)
 			klog.Error(err)
 			return err
 		}
+
+		klog.Infof("<<< [MIGRATION LSP RESET OK] Migration %s (UID: %s) - Successfully reset LSP %s",
+			key, migrationUID, portName)
+
 	case kubevirtv1.MigrationFailed:
-		klog.Infof("migrate end reset options for lsp %s from %s to %s, migrated fail", portName, srcNodeName, targetNodeName)
+		klog.Infof("<<< [MIGRATION LSP RESET] Migration %s (UID: %s) - Resetting LSP %s to source %s (migration failed)",
+			key, migrationUID, portName, srcNodeName)
+
 		if err := c.OVNNbClient.ResetLogicalSwitchPortMigrateOptions(portName, srcNodeName, targetNodeName, true); err != nil {
-			err = fmt.Errorf("failed to clean migrate options for lsp %s, %w", portName, err)
+			err = fmt.Errorf("failed to reset migrate options for lsp %s: %w", portName, err)
 			klog.Error(err)
 			return err
 		}
+
+		klog.Infof("<<< [MIGRATION LSP RESET OK] Migration %s (UID: %s) - Successfully reset LSP %s",
+			key, migrationUID, portName)
 	}
+
 	return nil
 }