Name each prefix once in restore, verify and purge errors (closes #327)

A missing blob during restore, a failed shallow verify and an invalid
purge duration each printed their prefix twice. FetchBlob now returns
the storage error as is, since restore and deep verify name the blob
themselves; purge returns the duration parser's error unchanged; and a
failed shallow verify wraps "problems found in storage" instead of
"verification failed", which the command already prints. Deep verify
words a storage error other than not found as a blob it could not
check, and its log line no longer says S3.

Already fixed for #314: the
deep verify size message naming S3 and other errors called missing;
tests now check both.
Not tested: the log line.

Model: opus-5-5

README.md

@@ -360,16 +360,20 @@ snapshot from the local index and strips the snapshot's metadata from
 the backup destination store. Blobs are NOT touched — deleting blobs
 requires reading every remaining remote manifest (the destination store
 may hold snapshots this host doesn't know about), which is what
-`vaultik prune` does. On success the command prints the exact `vaultik
+`vaultik prune` does. The command prints the `vaultik prune` invocation
-prune` invocation to run as a follow-up. An ID that names no snapshot in
+to run as a follow-up only when it removed the snapshot's metadata from
-the local index or on the destination store is an error; with
+the destination store, and never under `--json`. An ID that names no
-`--local-only`, the snapshot must be in the local index. Local row
+snapshot in the local index or on the destination store is an error;
+with `--local-only`, the snapshot must be in the local index. Local row
 cleanup (files, chunks, blobs the snapshot was the last referrer for)
-runs automatically. If the destination store is unreachable, the local-DB
+runs automatically. If removing the snapshot's metadata from the
-removal still completes and a warning is emitted; run `vaultik snapshot
+destination store fails (for example because the store is unreachable),
-remove <snapshot-id>` again once the store is reachable to remove the
+the local-DB removal still completes and a warning is emitted; run
-snapshot's metadata from it (`vaultik prune` does not). To wipe everything
+`vaultik snapshot remove <snapshot-id>` again once the store is reachable
-on the destination in one go, use `vaultik remote nuke --force`.
+to remove the snapshot's metadata from it (`vaultik prune` does not). For
+a snapshot that is only on the destination store, that failure is an
+error. To wipe everything on the destination in one go, use `vaultik
+remote nuke --force`.
 * `--local-only`: Skip remote cleanup; only touch the local index
 * `--dry-run`: Show what would be deleted without deleting
 * `--force`: Skip confirmation prompt

internal/cli/snapshot.go

@@ -270,8 +270,9 @@ By default, this removes the snapshot from the local index database and
 strips the snapshot's metadata from the backup destination store. Blobs
 are NOT touched: deleting them requires reading every remaining remote
 manifest (the destination store may hold snapshots this host doesn't
-know about), which is what 'vaultik prune' does. On success the command
+know about), which is what 'vaultik prune' does. The command prints the
-prints the exact 'vaultik prune' invocation to run as a follow-up.
+'vaultik prune' invocation to run as a follow-up only when it removed the
+snapshot's metadata from the destination store, and never under --json.
 
 An ID that names no snapshot in the local index or on the destination
 store is an error.
@@ -280,10 +281,12 @@ Use --local-only to skip the remote half (e.g. when you want to forget a
 snapshot locally without touching the destination store); the snapshot
 must then be in the local index.
 
-If the remote is unreachable, the local-database removal still completes
+If removing the snapshot's metadata from the destination store fails (for
-and a warning is emitted; run 'vaultik snapshot remove <snapshot-id>' again
+example because the remote is unreachable), the local-database removal
-once the destination store is reachable to remove the snapshot's metadata
+still completes and a warning is emitted; run 'vaultik snapshot remove
-from it ('vaultik prune' does not).
+<snapshot-id>' again once the destination store is reachable to remove
+the snapshot's metadata from it ('vaultik prune' does not). For a
+snapshot that is only on the destination store, that failure is an error.
 
 To wipe the entire destination store and start over, use 'vaultik remote
 nuke --force' — it is the single supported entry point for that.`,

internal/vaultik/blob_fetch.go

@@ -104,7 +104,8 @@ func (v *Vaultik) FetchAndDecryptBlob(
 
 // FetchBlob downloads a blob and returns a reader for the encrypted data.
 // The reader is closed as soon as ctx is cancelled, which ends a read
-// blocked inside it.
+// blocked inside it. A storage error is returned as is: restore and deep
+// verify name the blob in their own errors.
 func (v *Vaultik) FetchBlob(
 	ctx context.Context, blobHash string,
 ) (io.ReadCloser, error) {
@@ -119,7 +120,7 @@ func (v *Vaultik) FetchBlob(
 
 	rc, err := v.Storage.Get(ctx, blobPath)
 	if err != nil {
-		return nil, fmt.Errorf("downloading blob %s: %w", shortHash(blobHash), err)
+		return nil, err
 	}
 
 	return newCloseOnCancelReader(ctx, rc), nil

internal/vaultik/deep_verify_test.go

@@ -6,6 +6,7 @@ import (
 	"crypto/rand"
 	"io"
 	"os"
+	"path"
 	"path/filepath"
 	"testing"
 
@@ -142,7 +143,8 @@ func TestDeepVerifyJSONCountsBlobs(t *testing.T) {
 
 // TestDeepVerifyJSONCountsWrongSizeBlob checks that under --deep --json a
 // blob of the wrong size is counted in mismatched and fails the run, and
-// that the check goes on past it to count a missing blob after it.
+// that the check goes on past it to count a missing blob after it. The
+// store is on disk, so the message must not call it S3.
 func TestDeepVerifyJSONCountsWrongSizeBlob(t *testing.T) {
 	log.Initialize(log.Config{})
 	t.Parallel()
@@ -168,11 +170,14 @@ func TestDeepVerifyJSONCountsWrongSizeBlob(t *testing.T) {
 	require.Equal(t, 1, got.Mismatched)
 	require.Equal(t, 1, got.Missing)
 	require.Zero(t, got.Verified)
+	require.Contains(t, got.ErrorMessage, "with the wrong size")
+	require.NotContains(t, got.ErrorMessage, "S3")
 }
 
 // TestDeepVerifyStopsOnBlobThatCannotBeChecked checks that a blob that is
 // present in storage but cannot be checked is not counted as missing:
-// deep verify stops and fails with the storage error.
+// deep verify stops and fails, saying it could not check the blob, with
+// the storage error.
 func TestDeepVerifyStopsOnBlobThatCannotBeChecked(t *testing.T) {
 	log.Initialize(log.Config{})
 	t.Parallel()
@@ -187,6 +192,8 @@ func TestDeepVerifyStopsOnBlobThatCannotBeChecked(t *testing.T) {
 	require.Error(t, err)
 	require.Equal(t, "failed", got.Status)
 	require.Zero(t, got.Missing)
+	require.Contains(t, got.ErrorMessage,
+		"could not check blob "+path.Base(keys[0]))
 	require.Contains(t, got.ErrorMessage, errStatDenied.Error())
 }
 

internal/vaultik/purge_per_name_test.go

@@ -281,7 +281,8 @@ func TestPurgeOlderThan_TooLargeDeletesNothing(t *testing.T) {
 		OlderThan: "1000y",
 		Force:     true,
 	})
-	require.Error(t, err)
+	require.EqualError(t, err,
+		`invalid duration: "1000y" is longer than about 292 years`)
 
 	err = v.PurgeSnapshotsWithOptions(&vaultik.SnapshotPurgeOptions{
 		OlderThan: "292y",

internal/vaultik/remove_snapshot_test.go

@@ -17,6 +17,7 @@ import (
 	"sneak.berlin/go/vaultik/internal/log"
 	"sneak.berlin/go/vaultik/internal/snapshot"
 	"sneak.berlin/go/vaultik/internal/storage"
+	"sneak.berlin/go/vaultik/internal/storage/faultstore"
 	"sneak.berlin/go/vaultik/internal/types"
 	"sneak.berlin/go/vaultik/internal/vaultik"
 )
@@ -431,6 +432,40 @@ func TestRemoveSnapshot_NotInLocalIndex(t *testing.T) {
 	assert.Contains(t, out, "Removed snapshot metadata from remote storage")
 }
 
+// TestRemoveSnapshot_NotInLocalIndexDeleteFails checks that removing a
+// snapshot only the destination store holds fails when its metadata
+// cannot be deleted there, under --force and under --json: nothing was
+// removed, so the command must not succeed.
+func TestRemoveSnapshot_NotInLocalIndexDeleteFails(t *testing.T) {
+	log.Initialize(log.Config{})
+	t.Parallel()
+
+	for name, opts := range map[string]vaultik.RemoveOptions{
+		"force": {Force: true},
+		"json":  {JSON: true},
+	} {
+		t.Run(name, func(t *testing.T) {
+			t.Parallel()
+
+			store := newTestStorer()
+			addManifest(t, store, "snapshot-001", nil)
+
+			faulty := faultstore.New(store)
+			faulty.OnDelete = func(string) bool { return true }
+
+			tv := vaultik.NewForTesting(faulty)
+			tv.Repositories = newLocalIndex(t)
+
+			result, err := tv.RemoveSnapshot("snapshot-001", &opts)
+
+			require.ErrorIs(t, err, faultstore.ErrInjectedDelete)
+			assert.False(t, result.RemoteRemoved)
+			assert.True(t, store.hasKey(remoteKeyPath("snapshot-001")))
+			assert.Empty(t, tv.Stdout.String())
+		})
+	}
+}
+
 func TestRemoveAllSnapshots_RequiresForce(t *testing.T) {
 	log.Initialize(log.Config{})
 	t.Parallel()

internal/vaultik/restore_skip_errors_test.go

@@ -231,7 +231,8 @@ func (f trailingByteFile) Close() error {
 }
 
 // TestRestoreMissingBlobAbortsWithoutSkipErrors checks that a deleted blob
-// still ends the restore with an error when SkipErrors is not set.
+// still ends the restore with an error when SkipErrors is not set, and
+// that the error names the blob once.
 func TestRestoreMissingBlobAbortsWithoutSkipErrors(t *testing.T) {
 	log.Initialize(log.Config{})
 	t.Parallel()
@@ -247,6 +248,8 @@ func TestRestoreMissingBlobAbortsWithoutSkipErrors(t *testing.T) {
 	})
 
 	require.ErrorIs(t, err, storage.ErrNotFound)
+	assert.Equal(t, 1, strings.Count(err.Error(), "downloading blob"),
+		err.Error())
 }
 
 // TestRestoreChunkInNoBlobAbortsWithoutSkipErrors checks that a chunk held

internal/vaultik/shallow_verify_test.go

@@ -27,7 +27,7 @@ import (
 // then grows one stored blob so its size no longer matches the manifest.
 // Shallow verify must then fail, count the grown blob as a size mismatch,
 // and drop it from the verified count rather than continuing to report it
-// as checked.
+// as checked, and its error must not repeat the cli layer's prefix.
 func TestShallowVerifyDetectsWrongBlobSize(t *testing.T) {
 	log.Initialize(log.Config{})
 	t.Parallel()
@@ -96,6 +96,12 @@ func TestShallowVerifyDetectsWrongBlobSize(t *testing.T) {
 	require.Equal(t, 1, bad.Mismatched)
 	require.Equal(t, healthy.BlobCount-1, bad.Verified,
 		"the wrong-sized blob must not be counted as verified")
+
+	// The cli layer prints this error after its own "Verification failed:".
+	err = newVerifier(io.Discard).VerifySnapshotWithOptions(
+		snapshotID, &vaultik.VerifyOptions{})
+	require.EqualError(t, err,
+		"problems found in storage: 1 blobs have the wrong size")
 }
 
 // TestShallowVerifyDetectsMissingDatabase backs up a real snapshot,

internal/vaultik/snapshot.go

@@ -23,6 +23,7 @@ var (
 	errSnapshotNotInConfig  = errors.New("snapshot not found in config")
 	errNoSnapshotsInConfig  = errors.New("no snapshots configured")
 	errSnapshotVerifyFailed = errors.New("verification failed")
+	errProblemsInStorage    = errors.New("problems found in storage")
 	errRemoveAllNeedsForce  = errors.New("--all requires --force")
 	errSnapshotNotFound     = errors.New("snapshot not found")
 	errSnapshotRemoveFailed = errors.New("snapshot(s) could not be removed")
@@ -612,7 +613,7 @@ func selectSnapshotsToPurge(
 	case opts.OlderThan != "":
 		duration, err := parseDuration(opts.OlderThan)
 		if err != nil {
-			return nil, fmt.Errorf("invalid duration: %w", err)
+			return nil, err
 		}
 
 		cutoff := time.Now().UTC().Add(-duration)
@@ -941,8 +942,10 @@ func (v *Vaultik) formatVerifyResult(
 		v.printVerifySummary(result, failure)
 	}
 
+	// Not errSnapshotVerifyFailed: the cli layer prints this after its own
+	// "Verification failed:".
 	if failure != "" {
-		return fmt.Errorf("%w: %s", errSnapshotVerifyFailed, failure)
+		return fmt.Errorf("%w: %s", errProblemsInStorage, failure)
 	}
 
 	return nil
@@ -1228,9 +1231,11 @@ const snapshotRemoveCommandHint = "vaultik snapshot remove"
 // destination store. Blobs are NOT touched: removing a snapshot's
 // blobs requires reading every remaining remote manifest (the remote
 // may hold snapshots this host doesn't know about), which is what
-// `vaultik prune` is for — the command prints the prune invocation to
+// `vaultik prune` is for — when metadata was removed from the
-// run as a follow-up. When the remote is unreachable the command still
+// destination store, the text output names the prune invocation to run
-// completes the local-DB removal and warns.
+// as a follow-up. When removing the metadata fails, a snapshot in the
+// local index is still removed from it, with a warning; a snapshot
+// only on the destination store is an error.
 func (v *Vaultik) RemoveSnapshot(
 	snapshotID string, opts *RemoveOptions,
 ) (*RemoveResult, error) {
@@ -1265,8 +1270,10 @@ func (v *Vaultik) RemoveSnapshot(
 		}
 	}
 
-	if !opts.LocalOnly {
+	result.RemoteRemoved, err = v.removeSnapshotRemote(
-		result.RemoteRemoved = v.removeSnapshotRemote(snapshotID, opts)
+		snapshotID, inLocalIndex, opts)
+	if err != nil {
+		return result, err
 	}
 
 	if v.SnapshotManager != nil {
@@ -1391,19 +1398,33 @@ func (v *Vaultik) confirmRemoveSnapshot(snapshotID string, opts *RemoveOptions)
 }
 
 // removeSnapshotRemote strips the snapshot's metadata from the
-// destination store, warning and proceeding on failure: the local-DB
+// destination store. It returns true only when the delete finished
-// removal has already happened, so the user is told the remote half
+// without an error and removed at least one object; under LocalOnly it
-// didn't finish and to run `vaultik snapshot remove` for the snapshot
+// does nothing. When the snapshot is only on the destination store, a
-// again once the destination store is reachable (`vaultik prune` never
+// failure is returned as an error, because that removal is all the
-// removes snapshot metadata). Returns true when the remote removal
+// command does. When the snapshot was in the local index, its removal
-// succeeded and deleted something.
+// there has already happened, so a failure is only a warning telling the
-func (v *Vaultik) removeSnapshotRemote(snapshotID string, opts *RemoveOptions) bool {
+// user to run `vaultik snapshot remove` for the snapshot again once the
+// destination store is reachable (`vaultik prune` never removes snapshot
+// metadata).
+func (v *Vaultik) removeSnapshotRemote(
+	snapshotID string, inLocalIndex bool, opts *RemoveOptions,
+) (bool, error) {
+	if opts.LocalOnly {
+		return false, nil
+	}
+
 	log.Info("Removing snapshot metadata from remote storage",
 		"snapshot_id", snapshotID)
 
 	remoteKey := snapshot.RemoteSnapshotKey(snapshotID)
 
 	deleted, err := v.deleteRemoteSnapshotByKey(remoteKey)
+	if err != nil && !inLocalIndex {
+		return false, fmt.Errorf(
+			"removing snapshot metadata from destination store: %w", err)
+	}
+
 	if err != nil {
 		log.Warn("Could not remove snapshot metadata from remote storage; "+
 			"run '"+snapshotRemoveCommandHint+"' with the snapshot's ID "+
@@ -1418,10 +1439,10 @@ func (v *Vaultik) removeSnapshotRemote(snapshotID string, opts *RemoveOptions) b
 				err, snapshotRemoveCommandHint, snapshotID)
 		}
 
-		return false
+		return false, nil
 	}
 
-	return deleted > 0
+	return deleted > 0, nil
 }
 
 // RemoveAllSnapshots removes every snapshot known to the local

internal/vaultik/verify.go

@@ -680,7 +680,7 @@ func (v *Vaultik) verifyManifestAgainstDatabase(
 func (v *Vaultik) verifyBlobExistenceFromDB(
 	blobs []snapshot.BlobInfo, result *VerifyResult,
 ) error {
-	log.Info("Verifying blob existence in S3", "blob_count", len(blobs))
+	log.Info("Verifying blob existence in storage", "blob_count", len(blobs))
 
 	for i, blob := range blobs {
 		// The hash is read from the snapshot database, which is not
@@ -700,7 +700,7 @@ func (v *Vaultik) verifyBlobExistenceFromDB(
 			result.Missing++
 			result.MissingSize += blob.CompressedSize
 		case err != nil:
-			return fmt.Errorf("checking blob %s in storage: %w",
+			return fmt.Errorf("could not check blob %s in storage: %w",
 				blob.Hash, err)
 		case stat.Size != blob.CompressedSize:
 			log.Warn("Blob has the wrong size in storage",