From 473f7529e1eed779f1d5eec8a103aa185927aacc Mon Sep 17 00:00:00 2001 From: Pujitha Paladugu Date: Wed, 16 Sep 2026 05:34:20 -0700 Subject: [PATCH] Fix backup queue permanently stuck when a dequeued backup completes during the patch (#10521) * Fix backup queue permanently stuck when a dequeued backup completes during the patch Motivation: backupQueueReconciler patched a dequeued backup to ReadyToStart and only called backupTracker.AddReadyToStart on the next line. If backupReconciler picked up that patch and completed the backup (e.g. immediate FailedValidation while a BackupStorageLocation is briefly unavailable) before the queue controller reached that line, backupReconciler's Add + deferred Delete ran first, and the later AddReadyToStart re-inserted a tracker key nothing would ever delete again. backupTracker is in-memory and never reconciled against actual Backup phases, so RunningCount() stayed stuck at concurrentBackups and every later reconcile, including the periodic recheck, was refused at that gate -- the queue stopped dequeuing permanently until the deployment restarted. Approach: record the backup as ReadyToStart in the tracker before patching it, and roll that back if the patch itself fails, so the tracker entry always exists before the backup can become visible to any other reconciler. Also folds in two related fixes: the concurrency-refusal log line is now Info instead of Debug so a stuck queue is visible at the default log level, and the queue-position renumbering loop's error log (which built a logrus.Entry via log.WithError(errors.Wrapf(...)) but never called a terminal method on it, so it never actually logged anything) now emits properly. Validation: go build ./pkg/controller/..., go vet ./pkg/controller/..., and gofmt -l on both changed files are all clean. golangci-lint run ./pkg/controller/... reports no findings. go mod tidy produces a zero diff to go.mod/go.sum, matching this repo's verify-modules check. Mirrored this repo's own hack/test.sh invocation for this package (-short -vet=... -skip TestAPIs) and it passes; TestAPIs is a separate envtest suite that needs a local kubebuilder etcd binary not installed on this machine and fails identically on an unmodified checkout, so it is a pre-existing environment gap, not a regression. Added TestBackupQueueReconcilerTrackerNotLeakedWhenBackupCompletesDuringPatch, which uses a controller-runtime fake client with a Patch interceptor to simulate a racing reconciler completing the backup right after the ReadyToStart patch lands; it fails (RunningCount leaks to 1) against the pre-fix ordering and passes (RunningCount returns to 0) against the fix. Report: https://github.com/velero-io/velero/issues/10519 Signed-off-by: Pujitha Paladugu <10557236+pujitha24@users.noreply.github.com> Assisted-by: claude-sonnet-5 (via Claude Code) * Add changelog file for PR #10521 Signed-off-by: Pujitha Paladugu <10557236+pujitha24@users.noreply.github.com> * Add test covering tracker rollback when ReadyToStart patch fails Addresses review comment: verify backupTracker.RunningCount() returns to 0 when the ReadyToStart patch itself errors, covering the Delete rollback path alongside the existing race-condition regression test. Signed-off-by: Tiger Kaovilai --------- Signed-off-by: Pujitha Paladugu <10557236+pujitha24@users.noreply.github.com> Signed-off-by: Tiger Kaovilai Co-authored-by: Pujitha Paladugu <10557236+pujitha24@users.noreply.github.com> Co-authored-by: Tiger Kaovilai --- changelogs/unreleased/10521-pujitha24 | 1 + pkg/controller/backup_queue_controller.go | 11 ++- .../backup_queue_controller_test.go | 82 +++++++++++++++++++ 3 files changed, 91 insertions(+), 3 deletions(-) create mode 100644 changelogs/unreleased/10521-pujitha24 diff --git a/changelogs/unreleased/10521-pujitha24 b/changelogs/unreleased/10521-pujitha24 new file mode 100644 index 000000000..f1b7fb133 --- /dev/null +++ b/changelogs/unreleased/10521-pujitha24 @@ -0,0 +1 @@ +Fix backup queue permanently stuck when a dequeued backup completes during the patch diff --git a/pkg/controller/backup_queue_controller.go b/pkg/controller/backup_queue_controller.go index d2de26c81..e1f2d79bf 100644 --- a/pkg/controller/backup_queue_controller.go +++ b/pkg/controller/backup_queue_controller.go @@ -272,7 +272,7 @@ func (r *backupQueueReconciler) Reconcile(ctx context.Context, req ctrl.Request) } lister := r.newQueuedBackupsLister(allBackups) if r.backupTracker.RunningCount() >= r.concurrentBackups { - log.Debugf("%v concurrent backups are already running, leaving %v queued", r.concurrentBackups, backup.Name) + log.Infof("%v concurrent backups are already running, leaving %v queued", r.concurrentBackups, backup.Name) return ctrl.Result{}, nil } earlierBackups := lister.earlierThan(backup.Status.QueuePosition) @@ -294,10 +294,15 @@ func (r *backupQueueReconciler) Reconcile(ctx context.Context, req ctrl.Request) original := backup.DeepCopy() backup.Status.Phase = velerov1api.BackupPhaseReadyToStart backup.Status.QueuePosition = 0 + // Record ReadyToStart before patching: patching first would let + // backupReconciler pick up the change and complete the backup + // (Add then deferred Delete) before this call, leaking a + // tracker entry that nothing would ever clean up. + r.backupTracker.AddReadyToStart(backup.Namespace, backup.Name) if err := kube.PatchResource(original, backup, r.Client); err != nil { + r.backupTracker.Delete(backup.Namespace, backup.Name) return ctrl.Result{}, errors.Wrapf(err, "error updating Backup status to %s", backup.Status.Phase) } - r.backupTracker.AddReadyToStart(backup.Namespace, backup.Name) log.Debug("Updating queuePosition for remaining queued backups") queuedBackups := lister.orderedQueued() newQueuePos := 1 @@ -306,7 +311,7 @@ func (r *backupQueueReconciler) Reconcile(ctx context.Context, req ctrl.Request) original := queuedBackup.DeepCopy() queuedBackup.Status.QueuePosition = newQueuePos if err := kube.PatchResource(original, &queuedBackup, r.Client); err != nil { - log.WithError(errors.Wrapf(err, "error updating Backup %s queuePosition to %v", queuedBackup.Name, newQueuePos)) + log.WithError(err).Errorf("error updating Backup %s queuePosition to %v", queuedBackup.Name, newQueuePos) return ctrl.Result{}, nil } newQueuePos++ diff --git a/pkg/controller/backup_queue_controller_test.go b/pkg/controller/backup_queue_controller_test.go index 2b479ed7e..46a4a01ec 100644 --- a/pkg/controller/backup_queue_controller_test.go +++ b/pkg/controller/backup_queue_controller_test.go @@ -17,6 +17,8 @@ limitations under the License. package controller import ( + "context" + "errors" "testing" "github.com/sirupsen/logrus" @@ -27,8 +29,10 @@ import ( "k8s.io/apimachinery/pkg/runtime" "k8s.io/apimachinery/pkg/types" ctrl "sigs.k8s.io/controller-runtime" + ctrlClient "sigs.k8s.io/controller-runtime/pkg/client" //"sigs.k8s.io/controller-runtime/pkg/client/fake" + "sigs.k8s.io/controller-runtime/pkg/client/interceptor" velerov1api "github.com/vmware-tanzu/velero/pkg/apis/velero/v1" "github.com/vmware-tanzu/velero/pkg/builder" @@ -239,3 +243,81 @@ func TestBackupQueueReconciler(t *testing.T) { }) } } + +// TestBackupQueueReconcilerTrackerNotLeakedWhenBackupCompletesDuringPatch verifies the fix for +// https://github.com/velero-io/velero/issues/10519: if backupReconciler picks up the +// ReadyToStart phase change (e.g. because the backup fails validation immediately) and calls +// BackupTracker.Add/Delete before backupQueueReconciler reaches its own AddReadyToStart call, +// the queue controller must not re-insert a tracker entry nobody will ever delete. +func TestBackupQueueReconcilerTrackerNotLeakedWhenBackupCompletesDuringPatch(t *testing.T) { + scheme := runtime.NewScheme() + require.NoError(t, velerov1api.AddToScheme(scheme)) + + backup := builder.ForBackup(velerov1api.DefaultNamespace, "backup-11").Phase(velerov1api.BackupPhaseQueued).QueuePosition(1).Result() + backupTracker := NewBackupTracker() + + fakeClient := velerotest.NewFakeControllerRuntimeClientBuilder(t). + WithRuntimeObjects(backup). + WithInterceptorFuncs(interceptor.Funcs{ + Patch: func(ctx context.Context, c ctrlClient.WithWatch, obj ctrlClient.Object, patch ctrlClient.Patch, opts ...ctrlClient.PatchOption) error { + if err := c.Patch(ctx, obj, patch, opts...); err != nil { + return err + } + // Simulate backupReconciler racing ahead of this goroutine: it sees + // the ReadyToStart patch land, runs, and immediately completes the + // backup (e.g. FailedValidation), calling Add then its deferred + // Delete before backupQueueReconciler's next statement executes. + if b, ok := obj.(*velerov1api.Backup); ok && b.Status.Phase == velerov1api.BackupPhaseReadyToStart { + backupTracker.Add(b.Namespace, b.Name) + backupTracker.Delete(b.Namespace, b.Name) + } + return nil + }, + }). + Build() + + logger := logrus.New() + log := logger.WithField("controller", "backup-queue-test") + r := NewBackupQueueReconciler(fakeClient, scheme, log, 1, backupTracker) + req := ctrl.Request{NamespacedName: types.NamespacedName{Namespace: backup.Namespace, Name: backup.Name}} + _, err := r.Reconcile(t.Context(), req) + require.NoError(t, err) + + assert.Equal(t, 0, backupTracker.RunningCount(), + "tracker entry must not be leaked when a racing reconcile completes the backup before AddReadyToStart runs") +} + +// TestBackupQueueReconcilerTrackerRolledBackWhenPatchFails verifies that if the +// ReadyToStart patch itself fails, the AddReadyToStart call made just before it is +// rolled back via Delete, so a failed patch doesn't itself permanently consume a +// concurrency slot. +func TestBackupQueueReconcilerTrackerRolledBackWhenPatchFails(t *testing.T) { + scheme := runtime.NewScheme() + require.NoError(t, velerov1api.AddToScheme(scheme)) + + backup := builder.ForBackup(velerov1api.DefaultNamespace, "backup-11").Phase(velerov1api.BackupPhaseQueued).QueuePosition(1).Result() + backupTracker := NewBackupTracker() + + patchErr := errors.New("simulated patch failure") + fakeClient := velerotest.NewFakeControllerRuntimeClientBuilder(t). + WithRuntimeObjects(backup). + WithInterceptorFuncs(interceptor.Funcs{ + Patch: func(ctx context.Context, c ctrlClient.WithWatch, obj ctrlClient.Object, patch ctrlClient.Patch, opts ...ctrlClient.PatchOption) error { + if b, ok := obj.(*velerov1api.Backup); ok && b.Status.Phase == velerov1api.BackupPhaseReadyToStart { + return patchErr + } + return c.Patch(ctx, obj, patch, opts...) + }, + }). + Build() + + logger := logrus.New() + log := logger.WithField("controller", "backup-queue-test") + r := NewBackupQueueReconciler(fakeClient, scheme, log, 1, backupTracker) + req := ctrl.Request{NamespacedName: types.NamespacedName{Namespace: backup.Namespace, Name: backup.Name}} + _, err := r.Reconcile(t.Context(), req) + require.Error(t, err) + + assert.Equal(t, 0, backupTracker.RunningCount(), + "tracker entry must be rolled back when the ReadyToStart patch fails") +}