From 68cee893f1f1ee1d4c13e8de9e5d9468915586f2 Mon Sep 17 00:00:00 2001 From: Priyansh Choudhary Date: Thu, 19 Mar 2026 03:16:32 +0530 Subject: [PATCH] Enhance logging and error handling in VolumeSnapshotContent deletion process Signed-off-by: Priyansh Choudhary --- .../csi/volumesnapshotcontent_action.go | 17 ++- .../csi/volumesnapshotcontent_action_test.go | 120 +++++++++++++++++- 2 files changed, 126 insertions(+), 11 deletions(-) diff --git a/internal/delete/actions/csi/volumesnapshotcontent_action.go b/internal/delete/actions/csi/volumesnapshotcontent_action.go index 69d604e41..a8b43d456 100644 --- a/internal/delete/actions/csi/volumesnapshotcontent_action.go +++ b/internal/delete/actions/csi/volumesnapshotcontent_action.go @@ -71,7 +71,7 @@ func (p *volumeSnapshotContentDeleteItemAction) Execute( // So skip deleting VolumeSnapshotContent not have the backup name // in its labels. if !kubeutil.HasBackupLabel(&snapCont.ObjectMeta, input.Backup.Name) { - p.log.Info( + p.log.Infof( "VolumeSnapshotContent %s was not taken by backup %s, skipping deletion", snapCont.Name, input.Backup.Name, @@ -125,6 +125,7 @@ func (p *volumeSnapshotContentDeleteItemAction) Execute( if err := p.crClient.Create(context.TODO(), &snapCont); err != nil { return errors.Wrapf(err, "fail to create VolumeSnapshotContent %s", snapCont.Name) } + p.log.Infof("Created temp VolumeSnapshotContent %s with DeletionPolicy=Delete to trigger cloud snapshot cleanup", snapCont.Name) // Read resource timeout from backup annotation, if not set, use default value. timeout, err := time.ParseDuration( @@ -149,20 +150,23 @@ func (p *volumeSnapshotContentDeleteItemAction) Execute( }, ); err != nil { // Clean up the VSC we created since it can't become ready + p.log.WithError(err).Warnf("Temp VolumeSnapshotContent %s did not become ready, cleaning up", snapCont.Name) if deleteErr := p.crClient.Delete(context.TODO(), &snapCont); deleteErr != nil && !apierrors.IsNotFound(deleteErr) { - p.log.WithError(deleteErr).Errorf("Failed to clean up VolumeSnapshotContent %s", snapCont.Name) + p.log.WithError(deleteErr).Errorf("Failed to clean up temp VolumeSnapshotContent %s", snapCont.Name) } return errors.Wrapf(err, "fail to wait VolumeSnapshotContent %s becomes ready.", snapCont.Name) } + p.log.Infof("Temp VolumeSnapshotContent %s is ready, deleting to trigger cloud snapshot removal", snapCont.Name) if err := p.crClient.Delete( context.TODO(), &snapCont, ); err != nil && !apierrors.IsNotFound(err) { - p.log.Infof("VolumeSnapshotContent %s not found", snapCont.Name) + p.log.WithError(err).Errorf("Failed to delete temp VolumeSnapshotContent %s", snapCont.Name) return err } + p.log.Infof("Successfully triggered deletion of VolumeSnapshotContent %s and its cloud snapshot", snapCont.Name) return nil } @@ -180,7 +184,7 @@ func (p *volumeSnapshotContentDeleteItemAction) tryDeleteOriginalVSC( if apierrors.IsNotFound(err) { p.log.Debugf("Original VolumeSnapshotContent %s not found in cluster, will use temp VSC flow", vscName) } else { - p.log.Debugf("Error looking up original VolumeSnapshotContent %s, will use temp VSC flow", vscName) + p.log.WithError(err).Warnf("Error looking up original VolumeSnapshotContent %s, will use temp VSC flow", vscName) } return false } @@ -192,7 +196,7 @@ func (p *volumeSnapshotContentDeleteItemAction) tryDeleteOriginalVSC( original := existing.DeepCopy() existing.Spec.DeletionPolicy = snapshotv1api.VolumeSnapshotContentDelete if err := p.crClient.Patch(ctx, existing, crclient.MergeFrom(original)); err != nil { - p.log.WithError(err).Debugf("Failed to patch DeletionPolicy on original VSC %s, will use temp VSC flow", vscName) + p.log.WithError(err).Warnf("Failed to patch DeletionPolicy on original VSC %s, will use temp VSC flow", vscName) return false } p.log.Debugf("Patched DeletionPolicy to Delete on original VolumeSnapshotContent %s", vscName) @@ -200,10 +204,11 @@ func (p *volumeSnapshotContentDeleteItemAction) tryDeleteOriginalVSC( // Delete the original VSC — the CSI driver will clean up the cloud snapshot if err := p.crClient.Delete(ctx, existing); err != nil && !apierrors.IsNotFound(err) { - p.log.WithError(err).Debugf("Failed to delete original VolumeSnapshotContent %s, will use temp VSC flow", vscName) + p.log.WithError(err).Warnf("Failed to delete original VolumeSnapshotContent %s, will use temp VSC flow", vscName) return false } + p.log.Infof("Deleted original VolumeSnapshotContent %s with DeletionPolicy=Delete, CSI driver will remove cloud snapshot", vscName) return true } diff --git a/internal/delete/actions/csi/volumesnapshotcontent_action_test.go b/internal/delete/actions/csi/volumesnapshotcontent_action_test.go index 76ebe4152..ee96018fe 100644 --- a/internal/delete/actions/csi/volumesnapshotcontent_action_test.go +++ b/internal/delete/actions/csi/volumesnapshotcontent_action_test.go @@ -39,14 +39,44 @@ import ( velerotest "github.com/vmware-tanzu/velero/pkg/test" ) +// fakeClientWithErrors wraps a real client and injects errors for specific operations. +type fakeClientWithErrors struct { + crclient.Client + getError error + patchError error + deleteError error +} + +func (c *fakeClientWithErrors) Get(ctx context.Context, key crclient.ObjectKey, obj crclient.Object, opts ...crclient.GetOption) error { + if c.getError != nil { + return c.getError + } + return c.Client.Get(ctx, key, obj, opts...) +} + +func (c *fakeClientWithErrors) Patch(ctx context.Context, obj crclient.Object, patch crclient.Patch, opts ...crclient.PatchOption) error { + if c.patchError != nil { + return c.patchError + } + return c.Client.Patch(ctx, obj, patch, opts...) +} + +func (c *fakeClientWithErrors) Delete(ctx context.Context, obj crclient.Object, opts ...crclient.DeleteOption) error { + if c.deleteError != nil { + return c.deleteError + } + return c.Client.Delete(ctx, obj, opts...) +} + func TestVSCExecute(t *testing.T) { snapshotHandleStr := "test" tests := []struct { - name string - item runtime.Unstructured - vsc *snapshotv1api.VolumeSnapshotContent - backup *velerov1api.Backup - function func( + name string + item runtime.Unstructured + vsc *snapshotv1api.VolumeSnapshotContent + backup *velerov1api.Backup + preExistingVSC *snapshotv1api.VolumeSnapshotContent + function func( ctx context.Context, vsc *snapshotv1api.VolumeSnapshotContent, client crclient.Client, @@ -96,6 +126,21 @@ func TestVSCExecute(t *testing.T) { return false, errors.Errorf("test error case") }, }, + { + name: "Original VSC exists in cluster, cleaned up directly", + vsc: builder.ForVolumeSnapshotContent("bar").ObjectMeta(builder.WithLabelsMap(map[string]string{velerov1api.BackupNameLabel: "backup"})).Status(&snapshotv1api.VolumeSnapshotContentStatus{SnapshotHandle: &snapshotHandleStr}).Result(), + backup: builder.ForBackup("velero", "backup").Result(), + expectErr: false, + preExistingVSC: &snapshotv1api.VolumeSnapshotContent{ + ObjectMeta: metav1.ObjectMeta{Name: "bar"}, + Spec: snapshotv1api.VolumeSnapshotContentSpec{ + DeletionPolicy: snapshotv1api.VolumeSnapshotContentRetain, + Driver: "disk.csi.azure.com", + Source: snapshotv1api.VolumeSnapshotContentSource{SnapshotHandle: stringPtr("snap-123")}, + VolumeSnapshotRef: corev1api.ObjectReference{Name: "vs-1", Namespace: "default"}, + }, + }, + }, { name: "Error case with CSI error, dangling VSC should be cleaned up", vsc: builder.ForVolumeSnapshotContent("bar").ObjectMeta(builder.WithLabelsMap(map[string]string{velerov1api.BackupNameLabel: "backup"})).Status(&snapshotv1api.VolumeSnapshotContentStatus{SnapshotHandle: &snapshotHandleStr}).Result(), @@ -117,6 +162,10 @@ func TestVSCExecute(t *testing.T) { logger := logrus.StandardLogger() checkVSCReadiness = test.function + if test.preExistingVSC != nil { + require.NoError(t, crClient.Create(t.Context(), test.preExistingVSC)) + } + p := volumeSnapshotContentDeleteItemAction{log: logger, crClient: crClient} if test.vsc != nil { @@ -321,6 +370,67 @@ func TestTryDeleteOriginalVSC(t *testing.T) { } }) } + + // Error injection tests for tryDeleteOriginalVSC + t.Run("Get returns non-NotFound error, returns false", func(t *testing.T) { + errClient := &fakeClientWithErrors{ + Client: velerotest.NewFakeControllerRuntimeClient(t), + getError: fmt.Errorf("connection refused"), + } + p := &volumeSnapshotContentDeleteItemAction{ + log: logrus.StandardLogger(), + crClient: errClient, + } + require.False(t, p.tryDeleteOriginalVSC(t.Context(), "some-vsc")) + }) + + t.Run("Patch fails, returns false", func(t *testing.T) { + realClient := velerotest.NewFakeControllerRuntimeClient(t) + vsc := &snapshotv1api.VolumeSnapshotContent{ + ObjectMeta: metav1.ObjectMeta{Name: "patch-fail-vsc"}, + Spec: snapshotv1api.VolumeSnapshotContentSpec{ + DeletionPolicy: snapshotv1api.VolumeSnapshotContentRetain, + Driver: "disk.csi.azure.com", + Source: snapshotv1api.VolumeSnapshotContentSource{SnapshotHandle: stringPtr("snap-789")}, + VolumeSnapshotRef: corev1api.ObjectReference{Name: "vs-3", Namespace: "default"}, + }, + } + require.NoError(t, realClient.Create(t.Context(), vsc)) + + errClient := &fakeClientWithErrors{ + Client: realClient, + patchError: fmt.Errorf("patch forbidden"), + } + p := &volumeSnapshotContentDeleteItemAction{ + log: logrus.StandardLogger(), + crClient: errClient, + } + require.False(t, p.tryDeleteOriginalVSC(t.Context(), "patch-fail-vsc")) + }) + + t.Run("Delete fails, returns false", func(t *testing.T) { + realClient := velerotest.NewFakeControllerRuntimeClient(t) + vsc := &snapshotv1api.VolumeSnapshotContent{ + ObjectMeta: metav1.ObjectMeta{Name: "delete-fail-vsc"}, + Spec: snapshotv1api.VolumeSnapshotContentSpec{ + DeletionPolicy: snapshotv1api.VolumeSnapshotContentDelete, + Driver: "disk.csi.azure.com", + Source: snapshotv1api.VolumeSnapshotContentSource{SnapshotHandle: stringPtr("snap-999")}, + VolumeSnapshotRef: corev1api.ObjectReference{Name: "vs-4", Namespace: "default"}, + }, + } + require.NoError(t, realClient.Create(t.Context(), vsc)) + + errClient := &fakeClientWithErrors{ + Client: realClient, + deleteError: fmt.Errorf("delete forbidden"), + } + p := &volumeSnapshotContentDeleteItemAction{ + log: logrus.StandardLogger(), + crClient: errClient, + } + require.False(t, p.tryDeleteOriginalVSC(t.Context(), "delete-fail-vsc")) + }) } func boolPtr(b bool) *bool {