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. Remove early return on Completed: Allow MigrationSucceeded/Failed
   phases to execute Reset logic
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 <[email protected]>

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)
 	}
 }
@@ -105,102 +107,197 @@ 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
+	portName := ovs.PodNameToPortName(vmiName, namespace, util.OvnProvider)
+
+	// ====== MIGRATION UID VALIDATION ======
+	// CRITICAL: Only use vmi.Status.MigrationState if its MigrationUID matches the current vmiMigration.UID
+	// This prevents using stale state from a previous migration (e.g., A→B data when doing B→A migration)
 	var srcNodeName, targetNodeName string
+	var migrationStateValid bool
+
 	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
+		vmiMigrationUID := vmi.Status.MigrationState.MigrationUID
+		if vmiMigrationUID == migrationUID {
+			// MigrationUID matches - this state belongs to current migration
+			migrationStateValid = true
+			srcNodeName = vmi.Status.MigrationState.SourceNode
+			targetNodeName = vmi.Status.MigrationState.TargetNode
+			klog.Infof("Migration %s (UID: %s) - VMI MigrationState is VALID (UID match), source: %s, target: %s, targetPod: %s",
+				key, migrationUID, srcNodeName, targetNodeName, vmi.Status.MigrationState.TargetPod)
+		} else {
+			// MigrationUID mismatch - this is STALE state from a PREVIOUS migration
+			// Clean up any residual migrate options from the previous migration
+			klog.Warningf("Migration %s (UID: %s) - VMI MigrationState is STALE (UID mismatch: VMI has %s), cleaning residual migrate options",
+				key, migrationUID, vmiMigrationUID)
+			if err := c.OVNNbClient.CleanLogicalSwitchPortMigrateOptions(portName); err != nil {
+				klog.Errorf("failed to clean stale migrate options for lsp %s: %v", portName, err)
+				return err
+			}
+			// Don't return here - continue processing the current migration
+			// The current migration will set new options in MigrationScheduling phase
+		}
 	} else {
-		klog.Infof("current vmiMigration %s status %s, vmi MigrationState is nil", key, vmiMigration.Status.Phase)
+		klog.V(3).Infof("Migration %s (UID: %s) - VMI MigrationState is nil, waiting for KubeVirt to populate",
+			key, migrationUID)
 	}
 
-	portName := ovs.PodNameToPortName(vmiMigration.Spec.VMIName, vmiMigration.Namespace, util.OvnProvider)
-	switch vmiMigration.Status.Phase {
+	switch phase {
 	case kubevirtv1.MigrationScheduling:
+		// During MigrationScheduling, get target node from Pod (more reliable than vmi.Status.MigrationState)
 		selector, err := metav1.LabelSelectorAsSelector(&metav1.LabelSelector{
 			MatchLabels: map[string]string{
-				kubevirtv1.MigrationJobLabel: string(vmiMigration.UID),
+				kubevirtv1.MigrationJobLabel: string(migrationUID),
 			},
 		})
 		if err != nil {
-			err = fmt.Errorf("failed to create label selector for migration job UID %s: %w", vmiMigration.UID, err)
+			err = fmt.Errorf("failed to create label selector for migration job UID %s: %w", migrationUID, err)
 			klog.Error(err)
 			return err
 		}
 
-		pods, err := c.podsLister.Pods(vmiMigration.Namespace).List(selector)
+		pods, err := c.podsLister.Pods(namespace).List(selector)
 		if err != nil {
-			err = fmt.Errorf("failed to list pods with migration job UID %s: %w", vmiMigration.UID, err)
+			err = fmt.Errorf("failed to list pods with migration job UID %s: %w", migrationUID, 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
-			}
+		if len(pods) == 0 {
+			klog.V(3).Infof("Migration %s (UID: %s) - Target pod not yet created, waiting for pod creation",
+				key, migrationUID)
+			return nil
+		}
 
-			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
-			}
+		targetPod := pods[0]
+		targetNode := targetPod.Spec.NodeName
 
-			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)
+		// Use vmi.Status.NodeName as source if MigrationState is not valid or SourceNode is empty
+		sourceNode := srcNodeName
+		if sourceNode == "" {
+			sourceNode = vmi.Status.NodeName
+			klog.V(3).Infof("Migration %s (UID: %s) - Using vmi.Status.NodeName as source: %s",
+				key, migrationUID, sourceNode)
+		}
 
-			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)
+		// Validate we have both source and target
+		if sourceNode == "" || targetNode == "" {
+			klog.Warningf("Migration %s (UID: %s) - Cannot set LSP options: source=%q, target=%q (waiting for nodes)",
+				key, migrationUID, sourceNode, targetNode)
+			return nil
+		}
+
+		// Skip if source and target are the same (shouldn't happen in normal migration)
+		if sourceNode == targetNode {
+			klog.Warningf("Migration %s (UID: %s) - Source and target are same node %s, skipping LSP setup",
+				key, migrationUID, sourceNode)
+			return nil
+		}
+
+		klog.Infof(">>> [MIGRATION LSP SET] Migration %s (UID: %s) - Setting LSP %s migrate options: %s -> %s",
+			key, migrationUID, portName, sourceNode, targetNode)
+
+		if err := c.OVNNbClient.SetLogicalSwitchPortMigrateOptions(portName, sourceNode, targetNode); err != nil {
+			err = fmt.Errorf("failed to set migrate options for lsp %s: %w", portName, err)
+			klog.Error(err)
+			return err
+		}
+
+		klog.Infof(">>> [MIGRATION LSP SET OK] Migration %s (UID: %s) - Successfully set LSP %s migrate options",
+			key, migrationUID, portName)
+
+	case kubevirtv1.MigrationSucceeded:
+		// For final phases, we need valid migration state to know source/target
+		if !migrationStateValid {
+			klog.Warningf("Migration %s (UID: %s) SUCCEEDED but VMI MigrationState is invalid/stale, cannot reset LSP options properly",
+				key, migrationUID)
+			// Try to clean up migrate options anyway using CleanLogicalSwitchPortMigrateOptions
+			if err := c.OVNNbClient.CleanLogicalSwitchPortMigrateOptions(portName); err != nil {
+				klog.Errorf("failed to clean migrate options for lsp %s: %v", portName, 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)
+		if !migrationStateValid {
+			klog.Warningf("Migration %s (UID: %s) FAILED but VMI MigrationState is invalid/stale, cannot reset LSP options properly",
+				key, migrationUID)
+			// Try to clean up migrate options anyway
+			if err := c.OVNNbClient.CleanLogicalSwitchPortMigrateOptions(portName); err != nil {
+				klog.Errorf("failed to clean migrate options for lsp %s: %v", portName, err)
+				return err
+			}
+			return nil
+		}
+
+		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
 }