Merge pull request #10005 from Lyndon-Li/fail-earlier-when-pvr-pod-is-not-ready

Issue 9973: fail earlier when PVR pod is not ready

changelogs/unreleased/10005-Lyndon-Li

@@ -0,0 +1 @@
+Fix issue #9973, fail earlier when PVR pod is not ready

pkg/controller/pod_volume_restore_controller.go

@@ -236,9 +236,9 @@ func (r *PodVolumeRestoreReconciler) Reconcile(ctx context.Context, req ctrl.Req
 			return ctrl.Result{}, nil
 		}
 
-		shouldProcess, pod, err := shouldProcess(ctx, r.client, log, pvr)
+		shouldProcess, pod, err := shouldProcess(ctx, r.client, log, pvr, r.resourceTimeout)
 		if err != nil {
-			return ctrl.Result{}, err
+			return r.errorOut(ctx, pvr, err, "Pod for this PVR is not ready", log)
 		}
 		if !shouldProcess {
 			return ctrl.Result{}, nil
@@ -565,7 +565,7 @@ func UpdatePVRStatusToFailed(ctx context.Context, c client.Client, pvr *velerov1
 	return err
 }
 
-func shouldProcess(ctx context.Context, client client.Client, log logrus.FieldLogger, pvr *velerov1api.PodVolumeRestore) (bool, *corev1api.Pod, error) {
+func shouldProcess(ctx context.Context, client client.Client, log logrus.FieldLogger, pvr *velerov1api.PodVolumeRestore, timeout time.Duration) (bool, *corev1api.Pod, error) {
 	if !isPVRNew(pvr) {
 		log.Debug("PVR is not new, skip")
 		return false, nil, nil
@@ -573,22 +573,63 @@ func shouldProcess(ctx context.Context, client client.Client, log logrus.FieldLo
 
 	// we filter the pods during the initialization of cache, if we can get a pod here, the pod must be in the same node with the controller
 	// so we don't need to compare the node anymore
-	pod := &corev1api.Pod{}
-	if err := client.Get(ctx, types.NamespacedName{Namespace: pvr.Spec.Pod.Namespace, Name: pvr.Spec.Pod.Name}, pod); err != nil {
-		if apierrors.IsNotFound(err) {
-			log.WithError(err).Debug("Pod not found on this node, skip")
-			return false, nil, nil
+	var targetPod *corev1api.Pod
+	err := wait.PollUntilContextTimeout(ctx, time.Millisecond*100, timeout, true, func(ctx context.Context) (bool, error) {
+		updated := &corev1api.Pod{}
+		if err := client.Get(ctx, types.NamespacedName{Namespace: pvr.Spec.Pod.Namespace, Name: pvr.Spec.Pod.Name}, updated); err != nil {
+			if apierrors.IsNotFound(err) {
+				return false, nil
+			}
+
+			return false, err
+		}
+
+		targetPod = updated
+
+		return true, nil
+	})
+
+	if err != nil {
+		if errors.Is(err, context.DeadlineExceeded) {
+			return false, nil, errors.Errorf("timeout to wait for pod %s/%s", pvr.Spec.Pod.Namespace, pvr.Spec.Pod.Name)
+		} else {
+			return false, nil, errors.Wrapf(err, "error waiting for pod %s/%s", pvr.Spec.Pod.Namespace, pvr.Spec.Pod.Name)
 		}
-		log.WithError(err).Error("Unable to get pod")
-		return false, nil, err
 	}
 
-	if !isInitContainerRunning(pod) {
+	if targetPod.Status.Phase == corev1api.PodFailed || targetPod.Status.Phase == corev1api.PodUnknown {
+		return false, nil, errors.Errorf("unexpected state for pod %s/%s", targetPod.Namespace, targetPod.Name)
+	}
+
+	idx := getInitContainerIndex(targetPod)
+	if idx < 0 {
+		return false, nil, errors.Errorf("no restore-wait init container in pod %s/%s", targetPod.Namespace, targetPod.Name)
+	}
+
+	if len(targetPod.Status.InitContainerStatuses) <= idx {
+		log.Debug("Pod init container statuses are not fully populated yet, skip")
+		return false, nil, nil
+	}
+
+	containerStatus := targetPod.Status.InitContainerStatuses[idx]
+
+	if containerStatus.State.Terminated != nil {
+		return false, nil, errors.Errorf("restore-wait init container has already completed in pod %s/%s", targetPod.Namespace, targetPod.Name)
+	}
+
+	if containerStatus.State.Waiting != nil {
+		reason := containerStatus.State.Waiting.Reason
+		if reason == "ImagePullBackOff" || reason == "ErrImageNeverPull" || reason == "CreateContainerConfigError" || reason == "CreateContainerError" || reason == "InvalidImageName" || reason == "ErrImagePull" {
+			return false, nil, errors.Errorf("restore-wait init container in pod %s/%s is in unrecoverable waiting state with reason %s", targetPod.Namespace, targetPod.Name, reason)
+		}
+	}
+
+	if containerStatus.State.Running == nil {
 		log.Debug("Pod is not running restore-wait init container, skip")
 		return false, nil, nil
 	}
 
-	return true, pod, nil
+	return true, targetPod, nil
 }
 
 func (r *PodVolumeRestoreReconciler) closeDataPath(ctx context.Context, pvrName string) {
@@ -770,14 +811,6 @@ func isPVRNew(pvr *velerov1api.PodVolumeRestore) bool {
 	return pvr.Status.Phase == "" || pvr.Status.Phase == velerov1api.PodVolumeRestorePhaseNew
 }
 
-func isInitContainerRunning(pod *corev1api.Pod) bool {
-	// Pod volume wait container can be anywhere in the list of init containers, but must be running.
-	i := getInitContainerIndex(pod)
-	return i >= 0 &&
-		len(pod.Status.InitContainerStatuses)-1 >= i &&
-		pod.Status.InitContainerStatuses[i].State.Running != nil
-}
-
 func getInitContainerIndex(pod *corev1api.Pod) int {
 	// Pod volume wait container can be anywhere in the list of init containers so locate it.
 	for i, initContainer := range pod.Spec.InitContainers {

pkg/controller/pod_volume_restore_controller_test.go

@@ -65,6 +65,8 @@ func TestShouldProcess(t *testing.T) {
 		obj             *velerov1api.PodVolumeRestore
 		pod             *corev1api.Pod
 		shouldProcessed bool
+		expectError     bool
+		errString       string
 	}{
 		{
 			name: "InProgress phase pvr should not be processed",
@@ -115,6 +117,8 @@ func TestShouldProcess(t *testing.T) {
 				},
 			},
 			shouldProcessed: false,
+			expectError:     true,
+			errString:       "timeout to wait for pod ns-1/pod-1",
 		},
 		{
 			name: "Empty phase pvr with pod on node not running init container should not be processed",
@@ -200,6 +204,268 @@ func TestShouldProcess(t *testing.T) {
 			},
 			shouldProcessed: true,
 		},
+		{
+			name: "pod is in failed phase should return error",
+			obj: &velerov1api.PodVolumeRestore{
+				ObjectMeta: metav1.ObjectMeta{
+					Namespace: "velero",
+					Name:      "pvr-1",
+				},
+				Spec: velerov1api.PodVolumeRestoreSpec{
+					Pod: corev1api.ObjectReference{
+						Namespace: "ns-1",
+						Name:      "pod-1",
+					},
+				},
+				Status: velerov1api.PodVolumeRestoreStatus{
+					Phase: "",
+				},
+			},
+			pod: &corev1api.Pod{
+				ObjectMeta: metav1.ObjectMeta{
+					Namespace: "ns-1",
+					Name:      "pod-1",
+				},
+				Status: corev1api.PodStatus{
+					Phase: corev1api.PodFailed,
+				},
+			},
+			shouldProcessed: false,
+			expectError:     true,
+			errString:       "unexpected state for pod",
+		},
+		{
+			name: "pod is in unknown phase should return error",
+			obj: &velerov1api.PodVolumeRestore{
+				ObjectMeta: metav1.ObjectMeta{
+					Namespace: "velero",
+					Name:      "pvr-1",
+				},
+				Spec: velerov1api.PodVolumeRestoreSpec{
+					Pod: corev1api.ObjectReference{
+						Namespace: "ns-1",
+						Name:      "pod-1",
+					},
+				},
+				Status: velerov1api.PodVolumeRestoreStatus{
+					Phase: "",
+				},
+			},
+			pod: &corev1api.Pod{
+				ObjectMeta: metav1.ObjectMeta{
+					Namespace: "ns-1",
+					Name:      "pod-1",
+				},
+				Status: corev1api.PodStatus{
+					Phase: corev1api.PodUnknown,
+				},
+			},
+			shouldProcessed: false,
+			expectError:     true,
+			errString:       "unexpected state for pod",
+		},
+		{
+			name: "pod with no init containers should return error",
+			obj: &velerov1api.PodVolumeRestore{
+				ObjectMeta: metav1.ObjectMeta{
+					Namespace: "velero",
+					Name:      "pvr-1",
+				},
+				Spec: velerov1api.PodVolumeRestoreSpec{
+					Pod: corev1api.ObjectReference{
+						Namespace: "ns-1",
+						Name:      "pod-1",
+					},
+				},
+				Status: velerov1api.PodVolumeRestoreStatus{
+					Phase: "",
+				},
+			},
+			pod: &corev1api.Pod{
+				ObjectMeta: metav1.ObjectMeta{
+					Namespace: "ns-1",
+					Name:      "pod-1",
+				},
+				Spec: corev1api.PodSpec{
+					NodeName: controllerNode,
+				},
+			},
+			shouldProcessed: false,
+			expectError:     true,
+			errString:       "no restore-wait init container",
+		},
+		{
+			name: "pod init container statuses are not fully populated yet should skip",
+			obj: &velerov1api.PodVolumeRestore{
+				ObjectMeta: metav1.ObjectMeta{
+					Namespace: "velero",
+					Name:      "pvr-1",
+				},
+				Spec: velerov1api.PodVolumeRestoreSpec{
+					Pod: corev1api.ObjectReference{
+						Namespace: "ns-1",
+						Name:      "pod-1",
+					},
+				},
+				Status: velerov1api.PodVolumeRestoreStatus{
+					Phase: "",
+				},
+			},
+			pod: &corev1api.Pod{
+				ObjectMeta: metav1.ObjectMeta{
+					Namespace: "ns-1",
+					Name:      "pod-1",
+				},
+				Spec: corev1api.PodSpec{
+					NodeName: controllerNode,
+					InitContainers: []corev1api.Container{
+						{
+							Name: restorehelper.WaitInitContainer,
+						},
+					},
+				},
+				Status: corev1api.PodStatus{
+					InitContainerStatuses: []corev1api.ContainerStatus{},
+				},
+			},
+			shouldProcessed: false,
+		},
+		{
+			name: "restore-wait init container has already completed should return error",
+			obj: &velerov1api.PodVolumeRestore{
+				ObjectMeta: metav1.ObjectMeta{
+					Namespace: "velero",
+					Name:      "pvr-1",
+				},
+				Spec: velerov1api.PodVolumeRestoreSpec{
+					Pod: corev1api.ObjectReference{
+						Namespace: "ns-1",
+						Name:      "pod-1",
+					},
+				},
+				Status: velerov1api.PodVolumeRestoreStatus{
+					Phase: "",
+				},
+			},
+			pod: &corev1api.Pod{
+				ObjectMeta: metav1.ObjectMeta{
+					Namespace: "ns-1",
+					Name:      "pod-1",
+				},
+				Spec: corev1api.PodSpec{
+					NodeName: controllerNode,
+					InitContainers: []corev1api.Container{
+						{
+							Name: restorehelper.WaitInitContainer,
+						},
+					},
+				},
+				Status: corev1api.PodStatus{
+					InitContainerStatuses: []corev1api.ContainerStatus{
+						{
+							State: corev1api.ContainerState{
+								Terminated: &corev1api.ContainerStateTerminated{
+									ExitCode: 0,
+								},
+							},
+						},
+					},
+				},
+			},
+			shouldProcessed: false,
+			expectError:     true,
+			errString:       "restore-wait init container has already completed",
+		},
+		{
+			name: "restore-wait init container is in unrecoverable waiting state should return error",
+			obj: &velerov1api.PodVolumeRestore{
+				ObjectMeta: metav1.ObjectMeta{
+					Namespace: "velero",
+					Name:      "pvr-1",
+				},
+				Spec: velerov1api.PodVolumeRestoreSpec{
+					Pod: corev1api.ObjectReference{
+						Namespace: "ns-1",
+						Name:      "pod-1",
+					},
+				},
+				Status: velerov1api.PodVolumeRestoreStatus{
+					Phase: "",
+				},
+			},
+			pod: &corev1api.Pod{
+				ObjectMeta: metav1.ObjectMeta{
+					Namespace: "ns-1",
+					Name:      "pod-1",
+				},
+				Spec: corev1api.PodSpec{
+					NodeName: controllerNode,
+					InitContainers: []corev1api.Container{
+						{
+							Name: restorehelper.WaitInitContainer,
+						},
+					},
+				},
+				Status: corev1api.PodStatus{
+					InitContainerStatuses: []corev1api.ContainerStatus{
+						{
+							State: corev1api.ContainerState{
+								Waiting: &corev1api.ContainerStateWaiting{
+									Reason: "ImagePullBackOff",
+								},
+							},
+						},
+					},
+				},
+			},
+			shouldProcessed: false,
+			expectError:     true,
+			errString:       "is in unrecoverable waiting state with reason ImagePullBackOff",
+		},
+		{
+			name: "restore-wait init container is in normal waiting state should skip",
+			obj: &velerov1api.PodVolumeRestore{
+				ObjectMeta: metav1.ObjectMeta{
+					Namespace: "velero",
+					Name:      "pvr-1",
+				},
+				Spec: velerov1api.PodVolumeRestoreSpec{
+					Pod: corev1api.ObjectReference{
+						Namespace: "ns-1",
+						Name:      "pod-1",
+					},
+				},
+				Status: velerov1api.PodVolumeRestoreStatus{
+					Phase: "",
+				},
+			},
+			pod: &corev1api.Pod{
+				ObjectMeta: metav1.ObjectMeta{
+					Namespace: "ns-1",
+					Name:      "pod-1",
+				},
+				Spec: corev1api.PodSpec{
+					NodeName: controllerNode,
+					InitContainers: []corev1api.Container{
+						{
+							Name: restorehelper.WaitInitContainer,
+						},
+					},
+				},
+				Status: corev1api.PodStatus{
+					InitContainerStatuses: []corev1api.ContainerStatus{
+						{
+							State: corev1api.ContainerState{
+								Waiting: &corev1api.ContainerStateWaiting{
+									Reason: "ContainerCreating",
+								},
+							},
+						},
+					},
+				},
+			},
+			shouldProcessed: false,
+		},
 	}
 
 	for _, ts := range tests {
@@ -221,179 +487,16 @@ func TestShouldProcess(t *testing.T) {
 				clock:  &clocks.RealClock{},
 			}
 
-			shouldProcess, _, _ := shouldProcess(ctx, c.client, c.logger, ts.obj)
+			shouldProcess, _, err := shouldProcess(ctx, c.client, c.logger, ts.obj, time.Second)
 			require.Equal(t, ts.shouldProcessed, shouldProcess)
-		})
-	}
-}
-
-func TestIsInitContainerRunning(t *testing.T) {
-	tests := []struct {
-		name     string
-		pod      *corev1api.Pod
-		expected bool
-	}{
-		{
-			name: "pod with no init containers should return false",
-			pod: &corev1api.Pod{
-				ObjectMeta: metav1.ObjectMeta{
-					Namespace: "ns-1",
-					Name:      "pod-1",
-				},
-			},
-			expected: false,
-		},
-		{
-			name: "pod with running init container that's not restore init should return false",
-			pod: &corev1api.Pod{
-				ObjectMeta: metav1.ObjectMeta{
-					Namespace: "ns-1",
-					Name:      "pod-1",
-				},
-				Spec: corev1api.PodSpec{
-					InitContainers: []corev1api.Container{
-						{
-							Name: "non-restore-init",
-						},
-					},
-				},
-				Status: corev1api.PodStatus{
-					InitContainerStatuses: []corev1api.ContainerStatus{
-						{
-							State: corev1api.ContainerState{
-								Running: &corev1api.ContainerStateRunning{StartedAt: metav1.Time{Time: time.Now()}},
-							},
-						},
-					},
-				},
-			},
-			expected: false,
-		},
-		{
-			name: "pod with running init container that's not first should still work",
-			pod: &corev1api.Pod{
-				ObjectMeta: metav1.ObjectMeta{
-					Namespace: "ns-1",
-					Name:      "pod-1",
-				},
-				Spec: corev1api.PodSpec{
-					InitContainers: []corev1api.Container{
-						{
-							Name: "non-restore-init",
-						},
-						{
-							Name: restorehelper.WaitInitContainer,
-						},
-					},
-				},
-				Status: corev1api.PodStatus{
-					InitContainerStatuses: []corev1api.ContainerStatus{
-						{
-							State: corev1api.ContainerState{
-								Running: &corev1api.ContainerStateRunning{StartedAt: metav1.Time{Time: time.Now()}},
-							},
-						},
-						{
-							State: corev1api.ContainerState{
-								Running: &corev1api.ContainerStateRunning{StartedAt: metav1.Time{Time: time.Now()}},
-							},
-						},
-					},
-				},
-			},
-			expected: true,
-		},
-		{
-			name: "pod with init container as first initContainer that's not running should return false",
-			pod: &corev1api.Pod{
-				ObjectMeta: metav1.ObjectMeta{
-					Namespace: "ns-1",
-					Name:      "pod-1",
-				},
-				Spec: corev1api.PodSpec{
-					InitContainers: []corev1api.Container{
-						{
-							Name: restorehelper.WaitInitContainer,
-						},
-						{
-							Name: "non-restore-init",
-						},
-					},
-				},
-				Status: corev1api.PodStatus{
-					InitContainerStatuses: []corev1api.ContainerStatus{
-						{
-							State: corev1api.ContainerState{},
-						},
-						{
-							State: corev1api.ContainerState{
-								Running: &corev1api.ContainerStateRunning{StartedAt: metav1.Time{Time: time.Now()}},
-							},
-						},
-					},
-				},
-			},
-			expected: false,
-		},
-		{
-			name: "pod with running init container as first initContainer should return true",
-			pod: &corev1api.Pod{
-				ObjectMeta: metav1.ObjectMeta{
-					Namespace: "ns-1",
-					Name:      "pod-1",
-				},
-				Spec: corev1api.PodSpec{
-					InitContainers: []corev1api.Container{
-						{
-							Name: restorehelper.WaitInitContainer,
-						},
-						{
-							Name: "non-restore-init",
-						},
-					},
-				},
-				Status: corev1api.PodStatus{
-					InitContainerStatuses: []corev1api.ContainerStatus{
-						{
-							State: corev1api.ContainerState{
-								Running: &corev1api.ContainerStateRunning{StartedAt: metav1.Time{Time: time.Now()}},
-							},
-						},
-						{
-							State: corev1api.ContainerState{
-								Running: &corev1api.ContainerStateRunning{StartedAt: metav1.Time{Time: time.Now()}},
-							},
-						},
-					},
-				},
-			},
-			expected: true,
-		},
-		{
-			name: "pod with init container with empty InitContainerStatuses should return 0",
-			pod: &corev1api.Pod{
-				ObjectMeta: metav1.ObjectMeta{
-					Namespace: "ns-1",
-					Name:      "pod-1",
-				},
-				Spec: corev1api.PodSpec{
-					InitContainers: []corev1api.Container{
-						{
-							Name: restorehelper.WaitInitContainer,
-						},
-					},
-				},
-				Status: corev1api.PodStatus{
-					InitContainerStatuses: []corev1api.ContainerStatus{},
-				},
-			},
-			expected: false,
-		},
-	}
-
-	for _, test := range tests {
-		t.Run(test.name, func(t *testing.T) {
-			assert.Equal(t, test.expected, isInitContainerRunning(test.pod))
+			if ts.expectError {
+				require.Error(t, err)
+				if ts.errString != "" {
+					assert.Contains(t, err.Error(), ts.errString)
+				}
+			} else {
+				require.NoError(t, err)
+			}
 		})
 	}
 }