Fix backup-finalizer: do not set backup phase to Completed before PutBackupMetadata succeeds (#9646)

* Fix backup-finalizer: do not set backup phase to Completed before PutBackupMetadata succeeds

Previously, the backup finalizer controller set backup.Status.Phase to
Completed/PartiallyFailed in-memory BEFORE calling PutBackupMetadata and
PutBackupContents. When these uploads failed (e.g., due to object lock
or immutability), the deferred patch function still wrote the terminal
phase to the Kubernetes API server, preventing the controller from
retrying the upload on the next reconcile.

This fix moves the phase assignment to AFTER both uploads succeed. A
DeepCopy of the backup is used to encode the JSON with the final phase
for object storage, while the in-memory backup object retains the
Finalizing phase until uploads complete.

Caveats:
- CompletionTimestamp is now captured before upload but only committed to
  the API server after upload succeeds. On retry after a transient
  failure, a new timestamp is generated, so the completion time reflects
  when the upload finally succeeded rather than when finalization
  processing completed.
- Metrics (RegisterBackupSuccess/RegisterBackupPartialFailure) are now
  recorded after uploads succeed, so they accurately reflect only fully
  persisted backups.
- The metadata uploaded to object storage contains the final phase and
  completion timestamp via DeepCopy, so storage state is correct even
  before the API server is patched.

Fixes #9645

Generated with [Claude Code](https://claude.ai/code)
via [Happy](https://happy.engineering)

Co-Authored-By: Claude <noreply@anthropic.com>
Co-Authored-By: Happy <yesreply@happy.engineering>
Signed-off-by: Tiger Kaovilai <tkaovila@redhat.com>

* Add changelog for #9646

Generated with [Claude Code](https://claude.ai/code)
via [Happy](https://happy.engineering)

Co-Authored-By: Claude <noreply@anthropic.com>
Co-Authored-By: Happy <yesreply@happy.engineering>
Signed-off-by: Tiger Kaovilai <tkaovila@redhat.com>

* Fix testifylint: use require.Error instead of assert.Error

Generated with [Claude Code](https://claude.ai/code)
via [Happy](https://happy.engineering)

Co-Authored-By: Claude <noreply@anthropic.com>
Co-Authored-By: Happy <yesreply@happy.engineering>
Signed-off-by: Tiger Kaovilai <tkaovila@redhat.com>

* Address review feedback on backup-finalizer fix

- Add default guard for unhandled phase values in finalPhase switch
- Add retry with DefaultBackoff for PutBackupMetadata per reviewer request
- Replace brittle framework.BackupItemActionResolverV2{} mock with mock.Anything
- Add FinalizingPartiallyFailed test case for PutBackupContents failure

Generated with [Claude Code](https://claude.ai/code)
via [Happy](https://happy.engineering)

Co-Authored-By: Claude <noreply@anthropic.com>
Co-Authored-By: Happy <yesreply@happy.engineering>
Signed-off-by: Tiger Kaovilai <tkaovila@redhat.com>

* Use bounded, object-storage-tuned backoff for backup-finalizer uploads

retry.DefaultBackoff is tuned for API server optimistic-concurrency
conflicts (4 steps, ~1.25s total) and gives up far too quickly for
object storage calls, which can see longer transient outages or
throttling (review feedback from blackpiglet). Replace it with a
dedicated, bounded backoff (1s base, 2x factor, 5 steps, ~31s total)
applied to both PutBackupMetadata and PutBackupContents.

Being bounded (rather than retrying forever) means a persistent
failure, e.g. an object-lock/immutability policy denying every write,
surfaces as an error within a bounded time instead of hanging the
reconcile indefinitely; controller-runtime requeues on error, so
retries continue across reconciles (review feedback from priyansh17).

Signed-off-by: Tiger Kaovilai <tkaovila@redhat.com>

* Fix PutBackupMetadata retry to re-read backupJSON each attempt

backupJSON is a bytes.Buffer, so passing it directly to
PutBackupMetadata drains it on the first read attempt. A retry after
a transient failure would then upload empty content instead of the
backup metadata. Wrap it in bytes.NewReader(backupJSON.Bytes()) inside
the retry closure so every attempt gets a fresh reader.

Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
Signed-off-by: Tiger Kaovilai <tkaovila@redhat.com>

---------

Signed-off-by: Tiger Kaovilai <tkaovila@redhat.com>
Co-authored-by: Claude <noreply@anthropic.com>
Co-authored-by: Happy <yesreply@happy.engineering>

changelogs/unreleased/9646-kaovilai

@@ -0,0 +1 @@
+Fix backup-finalizer: do not set backup phase to Completed before PutBackupMetadata succeeds

pkg/controller/backup_finalizer_controller.go

@@ -26,6 +26,8 @@ import (
 	"github.com/sirupsen/logrus"
 	apierrors "k8s.io/apimachinery/pkg/api/errors"
 	metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
+	"k8s.io/apimachinery/pkg/util/wait"
+	"k8s.io/client-go/util/retry"
 	clocks "k8s.io/utils/clock"
 	ctrl "sigs.k8s.io/controller-runtime"
 	kbclient "sigs.k8s.io/controller-runtime/pkg/client"
@@ -43,6 +45,18 @@ import (
 	"github.com/vmware-tanzu/velero/pkg/util/encode"
 )
 
+// objectStorageBackoff retries object storage writes (PutBackupMetadata,
+// PutBackupContents). Bounded (Steps) so a persistent failure surfaces as an
+// error within a bounded time rather than retrying forever; see the retry
+// call sites below for rationale. Var (not const) so tests can shrink it for
+// speed, matching pkg/repository/maintenance's waitCompletionBackOff pattern.
+var objectStorageBackoff = wait.Backoff{
+	Duration: time.Second,
+	Factor:   2.0,
+	Steps:    5,
+	Jitter:   0.1,
+}
+
 // backupFinalizerReconciler reconciles a Backup object
 type backupFinalizerReconciler struct {
 	client            kbclient.Client
@@ -203,37 +217,74 @@ func (r *backupFinalizerReconciler) Reconcile(ctx context.Context, req ctrl.Requ
 		}
 	}
 	backupScheduleName := backupRequest.GetLabels()[velerov1api.ScheduleNameLabel]
+
+	// Determine the final phase and completion timestamp, but do NOT set them
+	// on the in-memory backup object yet. We first need to upload metadata and
+	// contents to object storage. If the upload fails, the deferred patch must
+	// NOT write a terminal phase to the API server so the controller can retry.
+	var finalPhase velerov1api.BackupPhase
 	switch backup.Status.Phase {
 	case velerov1api.BackupPhaseFinalizing:
-		backup.Status.Phase = velerov1api.BackupPhaseCompleted
+		finalPhase = velerov1api.BackupPhaseCompleted
+	case velerov1api.BackupPhaseFinalizingPartiallyFailed:
+		finalPhase = velerov1api.BackupPhasePartiallyFailed
+	default:
+		return ctrl.Result{}, nil
+	}
+
+	completionTimestamp := &metav1.Time{Time: r.clock.Now()}
+	csiVolumeSnapshotsCompleted := updateCSIVolumeSnapshotsCompleted(operations)
+
+	// Encode backup JSON with the final phase for object storage, so that the
+	// metadata in storage reflects the completed state.
+	backupForUpload := backup.DeepCopy()
+	backupForUpload.Status.Phase = finalPhase
+	backupForUpload.Status.CompletionTimestamp = completionTimestamp
+	backupForUpload.Status.CSIVolumeSnapshotsCompleted = csiVolumeSnapshotsCompleted
+
+	backupJSON := new(bytes.Buffer)
+	if err := encode.To(backupForUpload, "json", backupJSON); err != nil {
+		return ctrl.Result{}, errors.Wrap(err, "error encoding backup json")
+	}
+	// retry.DefaultBackoff is tuned for API server optimistic-concurrency
+	// conflicts (4 steps, ~1.25s total) and gives up far too quickly for
+	// object storage calls, which can see longer transient outages or
+	// throttling. objectStorageBackoff (above) grows more slowly and gives
+	// up after a bounded time instead of retrying forever, so a persistent
+	// failure (e.g. an object-lock/immutability policy) surfaces as an error
+	// promptly; controller-runtime requeues the Reconcile on error, so
+	// retries continue across reconciles rather than blocking a worker
+	// goroutine indefinitely on a call that will never succeed.
+	if err := retry.OnError(objectStorageBackoff, func(err error) bool { return err != nil },
+		func() error { return backupStore.PutBackupMetadata(backup.Name, bytes.NewReader(backupJSON.Bytes())) },
+	); err != nil {
+		return ctrl.Result{}, errors.Wrap(err, "error uploading backup json")
+	}
+	if len(operations) > 0 {
+		if err := retry.OnError(objectStorageBackoff, func(err error) bool { return err != nil },
+			func() error { return backupStore.PutBackupContents(backup.Name, outBackupFile) },
+		); err != nil {
+			return ctrl.Result{}, errors.Wrap(err, "error uploading backup final contents")
+		}
+	}
+
+	// Uploads succeeded — now safe to set the final phase on the in-memory
+	// backup object so the deferred patch writes it to the API server.
+	backup.Status.Phase = finalPhase
+	backup.Status.CompletionTimestamp = completionTimestamp
+	backup.Status.CSIVolumeSnapshotsCompleted = csiVolumeSnapshotsCompleted
+
+	switch finalPhase {
+	case velerov1api.BackupPhaseCompleted:
 		r.metrics.RegisterBackupSuccess(backupScheduleName)
 		r.metrics.RegisterBackupLastStatus(backupScheduleName, metrics.BackupLastStatusSucc)
-	case velerov1api.BackupPhaseFinalizingPartiallyFailed:
-		backup.Status.Phase = velerov1api.BackupPhasePartiallyFailed
+	case velerov1api.BackupPhasePartiallyFailed:
 		r.metrics.RegisterBackupPartialFailure(backupScheduleName)
 		r.metrics.RegisterBackupLastStatus(backupScheduleName, metrics.BackupLastStatusFailure)
 	}
 
-	backup.Status.CompletionTimestamp = &metav1.Time{Time: r.clock.Now()}
-	backup.Status.CSIVolumeSnapshotsCompleted = updateCSIVolumeSnapshotsCompleted(operations)
-
 	recordBackupMetrics(log, backup, outBackupFile, r.metrics, true)
 
-	// update backup metadata in object store
-	backupJSON := new(bytes.Buffer)
-	if err := encode.To(backup, "json", backupJSON); err != nil {
-		return ctrl.Result{}, errors.Wrap(err, "error encoding backup json")
-	}
-	err = backupStore.PutBackupMetadata(backup.Name, backupJSON)
-	if err != nil {
-		return ctrl.Result{}, errors.Wrap(err, "error uploading backup json")
-	}
-	if len(operations) > 0 {
-		err = backupStore.PutBackupContents(backup.Name, outBackupFile)
-		if err != nil {
-			return ctrl.Result{}, errors.Wrap(err, "error uploading backup final contents")
-		}
-	}
 	return ctrl.Result{}, nil
 }
 

pkg/controller/backup_finalizer_controller_test.go

@@ -18,6 +18,7 @@ package controller
 
 import (
 	"bytes"
+	"fmt"
 	"io"
 	"testing"
 	"time"
@@ -29,6 +30,7 @@ import (
 	metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
 	"k8s.io/apimachinery/pkg/runtime"
 	"k8s.io/apimachinery/pkg/types"
+	"k8s.io/apimachinery/pkg/util/wait"
 	testclocks "k8s.io/utils/clock/testing"
 	ctrl "sigs.k8s.io/controller-runtime"
 	kbclient "sigs.k8s.io/controller-runtime/pkg/client"
@@ -39,8 +41,9 @@ import (
 	"github.com/vmware-tanzu/velero/pkg/itemoperation"
 	"github.com/vmware-tanzu/velero/pkg/kuberesource"
 	"github.com/vmware-tanzu/velero/pkg/metrics"
+	persistencemocks "github.com/vmware-tanzu/velero/pkg/persistence/mocks"
 	"github.com/vmware-tanzu/velero/pkg/plugin/clientmgmt"
-	"github.com/vmware-tanzu/velero/pkg/plugin/framework"
+	pluginmocks "github.com/vmware-tanzu/velero/pkg/plugin/mocks"
 	"github.com/vmware-tanzu/velero/pkg/plugin/velero"
 	velerotest "github.com/vmware-tanzu/velero/pkg/test"
 )
@@ -225,7 +228,7 @@ func TestBackupFinalizerReconcile(t *testing.T) {
 			backupStore.On("GetBackupVolumeInfos", mock.Anything).Return(nil, nil)
 			backupStore.On("PutBackupVolumeInfos", mock.Anything, mock.Anything).Return(nil)
 			pluginManager.On("GetBackupItemActionsV2").Return(nil, nil)
-			backupper.On("FinalizeBackup", mock.Anything, mock.Anything, mock.Anything, mock.Anything, framework.BackupItemActionResolverV2{}, mock.Anything, mock.Anything).Return(nil)
+			backupper.On("FinalizeBackup", mock.Anything, mock.Anything, mock.Anything, mock.Anything, mock.Anything, mock.Anything, mock.Anything).Return(nil)
 			_, err := reconciler.Reconcile(t.Context(), ctrl.Request{NamespacedName: types.NamespacedName{Namespace: test.backup.Namespace, Name: test.backup.Name}})
 			gotErr := err != nil
 			assert.Equal(t, test.expectError, gotErr)
@@ -242,3 +245,177 @@ func TestBackupFinalizerReconcile(t *testing.T) {
 		})
 	}
 }
+
+func TestBackupFinalizerReconcile_PutBackupMetadataFail(t *testing.T) {
+	origBackoff := objectStorageBackoff
+	objectStorageBackoff = wait.Backoff{Duration: time.Millisecond, Steps: 2}
+	t.Cleanup(func() { objectStorageBackoff = origBackoff })
+
+	tests := []struct {
+		name         string
+		initialPhase velerov1api.BackupPhase
+	}{
+		{
+			name:         "Finalizing backup stays Finalizing when PutBackupMetadata fails",
+			initialPhase: velerov1api.BackupPhaseFinalizing,
+		},
+		{
+			name:         "FinalizingPartiallyFailed backup stays FinalizingPartiallyFailed when PutBackupMetadata fails",
+			initialPhase: velerov1api.BackupPhaseFinalizingPartiallyFailed,
+		},
+	}
+
+	for _, test := range tests {
+		t.Run(test.name, func(t *testing.T) {
+			fakeClock := testclocks.NewFakeClock(time.Now())
+			defaultBackupLocation := builder.ForBackupStorageLocation(velerov1api.DefaultNamespace, "default").Result()
+
+			backup := builder.ForBackup(velerov1api.DefaultNamespace, "backup-meta-fail").
+				StorageLocation("default").
+				ObjectMeta(builder.WithUID("foo")).
+				StartTimestamp(fakeClock.Now()).
+				Phase(test.initialPhase).Result()
+
+			fakeClient := velerotest.NewFakeControllerRuntimeClient(t, backup, defaultBackupLocation)
+			fakeGlobalClient := velerotest.NewFakeControllerRuntimeClient(t, backup, defaultBackupLocation)
+
+			// Use local mocks to avoid interference with other tests
+			localPluginManager := &pluginmocks.Manager{}
+			localBackupStore := &persistencemocks.BackupStore{}
+
+			backupper := new(fakeBackupper)
+			reconciler := NewBackupFinalizerReconciler(
+				fakeClient,
+				fakeGlobalClient,
+				fakeClock,
+				backupper,
+				func(logrus.FieldLogger) clientmgmt.Manager { return localPluginManager },
+				NewBackupTracker(),
+				NewFakeSingleObjectBackupStoreGetter(localBackupStore),
+				logrus.StandardLogger(),
+				metrics.NewServerMetrics(),
+				10*time.Minute,
+			)
+
+			localPluginManager.On("CleanupClients").Return(nil)
+			localBackupStore.On("GetBackupItemOperations", backup.Name).Return(nil, nil)
+			// PutBackupMetadata fails — retry exhausts after DefaultBackoff (5 retries)
+			localBackupStore.On("PutBackupMetadata", mock.Anything, mock.Anything).Return(fmt.Errorf("object lock prevented upload"))
+			localBackupStore.On("GetBackupVolumeInfos", mock.Anything).Return(nil, nil)
+			localBackupStore.On("PutBackupVolumeInfos", mock.Anything, mock.Anything).Return(nil)
+
+			_, err := reconciler.Reconcile(t.Context(), ctrl.Request{NamespacedName: types.NamespacedName{Namespace: backup.Namespace, Name: backup.Name}})
+			require.Error(t, err, "reconcile should return error when PutBackupMetadata fails")
+
+			backupAfter := velerov1api.Backup{}
+			err = fakeClient.Get(t.Context(), types.NamespacedName{
+				Namespace: backup.Namespace,
+				Name:      backup.Name,
+			}, &backupAfter)
+			require.NoError(t, err)
+			assert.Equal(t, test.initialPhase, backupAfter.Status.Phase,
+				"backup phase should remain %s when PutBackupMetadata fails", test.initialPhase)
+			assert.Nil(t, backupAfter.Status.CompletionTimestamp,
+				"CompletionTimestamp should not be set when PutBackupMetadata fails")
+		})
+	}
+}
+
+func TestBackupFinalizerReconcile_PutBackupContentsFail(t *testing.T) {
+	origBackoff := objectStorageBackoff
+	objectStorageBackoff = wait.Backoff{Duration: time.Millisecond, Steps: 2}
+	t.Cleanup(func() { objectStorageBackoff = origBackoff })
+
+	tests := []struct {
+		name         string
+		initialPhase velerov1api.BackupPhase
+	}{
+		{
+			name:         "Finalizing backup stays Finalizing when PutBackupContents fails",
+			initialPhase: velerov1api.BackupPhaseFinalizing,
+		},
+		{
+			name:         "FinalizingPartiallyFailed backup stays FinalizingPartiallyFailed when PutBackupContents fails",
+			initialPhase: velerov1api.BackupPhaseFinalizingPartiallyFailed,
+		},
+	}
+
+	for _, test := range tests {
+		t.Run(test.name, func(t *testing.T) {
+			fakeClock := testclocks.NewFakeClock(time.Now())
+			metav1Now := metav1.NewTime(fakeClock.Now())
+			defaultBackupLocation := builder.ForBackupStorageLocation(velerov1api.DefaultNamespace, "default").Result()
+
+			backup := builder.ForBackup(velerov1api.DefaultNamespace, "backup-contents-fail").
+				StorageLocation("default").
+				ObjectMeta(builder.WithUID("foo")).
+				StartTimestamp(fakeClock.Now()).
+				Phase(test.initialPhase).Result()
+
+			fakeClient := velerotest.NewFakeControllerRuntimeClient(t, backup, defaultBackupLocation)
+			fakeGlobalClient := velerotest.NewFakeControllerRuntimeClient(t, backup, defaultBackupLocation)
+
+			localPluginManager := &pluginmocks.Manager{}
+			localBackupStore := &persistencemocks.BackupStore{}
+
+			backupper := new(fakeBackupper)
+			reconciler := NewBackupFinalizerReconciler(
+				fakeClient,
+				fakeGlobalClient,
+				fakeClock,
+				backupper,
+				func(logrus.FieldLogger) clientmgmt.Manager { return localPluginManager },
+				NewBackupTracker(),
+				NewFakeSingleObjectBackupStoreGetter(localBackupStore),
+				logrus.StandardLogger(),
+				metrics.NewServerMetrics(),
+				10*time.Minute,
+			)
+
+			operations := []*itemoperation.BackupOperation{
+				{
+					Spec: itemoperation.BackupOperationSpec{
+						BackupName:       "backup-contents-fail",
+						BackupUID:        "foo",
+						BackupItemAction: "foo",
+						ResourceIdentifier: velero.ResourceIdentifier{
+							GroupResource: kuberesource.Pods,
+							Namespace:     "ns-1",
+							Name:          "pod-1",
+						},
+						OperationID: "operation-1",
+					},
+					Status: itemoperation.OperationStatus{
+						Phase:   itemoperation.OperationPhaseCompleted,
+						Created: &metav1Now,
+					},
+				},
+			}
+
+			localPluginManager.On("CleanupClients").Return(nil)
+			localPluginManager.On("GetBackupItemActionsV2").Return(nil, nil)
+			localBackupStore.On("GetBackupItemOperations", backup.Name).Return(operations, nil)
+			localBackupStore.On("GetBackupContents", mock.Anything).Return(io.NopCloser(bytes.NewReader([]byte("hello world"))), nil)
+			localBackupStore.On("PutBackupMetadata", mock.Anything, mock.Anything).Return(nil)
+			// PutBackupContents fails
+			localBackupStore.On("PutBackupContents", mock.Anything, mock.Anything).Return(fmt.Errorf("object lock prevented upload"))
+			localBackupStore.On("GetBackupVolumeInfos", mock.Anything).Return(nil, nil)
+			localBackupStore.On("PutBackupVolumeInfos", mock.Anything, mock.Anything).Return(nil)
+			backupper.On("FinalizeBackup", mock.Anything, mock.Anything, mock.Anything, mock.Anything, mock.Anything, mock.Anything, mock.Anything).Return(nil)
+
+			_, err := reconciler.Reconcile(t.Context(), ctrl.Request{NamespacedName: types.NamespacedName{Namespace: backup.Namespace, Name: backup.Name}})
+			require.Error(t, err, "reconcile should return error when PutBackupContents fails")
+
+			backupAfter := velerov1api.Backup{}
+			err = fakeClient.Get(t.Context(), types.NamespacedName{
+				Namespace: backup.Namespace,
+				Name:      backup.Name,
+			}, &backupAfter)
+			require.NoError(t, err)
+			assert.Equal(t, test.initialPhase, backupAfter.Status.Phase,
+				"backup phase should remain %s when PutBackupContents fails", test.initialPhase)
+			assert.Nil(t, backupAfter.Status.CompletionTimestamp,
+				"CompletionTimestamp should not be set when PutBackupContents fails")
+		})
+	}
+}