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

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/restore.go

@@ -12,7 +12,6 @@ import (
 	"path/filepath"
 	"slices"
 	"strings"
-	"syscall"
 	"time"
 
 	"filippo.io/age"
@@ -220,7 +219,9 @@ func (v *Vaultik) finishRestore(
 	)
 
 	if os.Geteuid() != 0 {
-		v.warnIfOwnershipNotPreserved(files, opts.TargetDir)
+		v.UI.Warningf("Restore did not preserve file ownership: chown(2) " +
+			"requires root. Re-run as root (e.g. with sudo) if you need " +
+			"original UID/GID preserved.")
 	}
 
 	if result.FilesFailed > 0 {
@@ -246,43 +247,6 @@ func (v *Vaultik) finishRestore(
 	return unmatchedErr
 }
 
-// warnIfOwnershipNotPreserved warns once if some entry restored under
-// targetDir has another owner or group on disk than the snapshot
-// records. It is meant for a restore by a normal user, which changes no
-// owner or group: a new entry is owned by that user, and its group is
-// that user's, or the group of the directory it is created in on macOS
-// and in a setgid directory on Linux. An entry that is not on disk, or
-// whose filesystem reports no owner, is skipped.
-func (v *Vaultik) warnIfOwnershipNotPreserved(
-	files []*database.File, targetDir string,
-) {
-	for _, file := range files {
-		targetPath, err := containedRestorePath(
-			v.Fs, targetDir, file.Path.String())
-		if err != nil {
-			continue
-		}
-
-		info, err := lstatIfPossible(v.Fs, targetPath)
-		if err != nil {
-			continue
-		}
-
-		owner, ok := info.Sys().(*syscall.Stat_t)
-		if !ok {
-			continue
-		}
-
-		if owner.Uid != file.UID || owner.Gid != file.GID {
-			v.UI.Warningf("Restore did not preserve file ownership: chown(2) " +
-				"requires root. Re-run as root (e.g. with sudo) if you need " +
-				"original UID/GID preserved.")
-
-			return
-		}
-	}
-}
-
 // reportUnmatchedPaths warns, by name, about each requested path that
 // matched nothing in the snapshot, and returns an error counting them,
 // or nil when there are none.
@@ -1001,9 +965,8 @@ type restoreSession struct {
 	// root can chown a file to an arbitrary UID/GID — non-root chown
 	// always fails with EPERM. Attempting it anyway produces N
 	// guaranteed-failed syscalls + N noisy debug lines, so we skip
-	// the call entirely as non-root; warnIfOwnershipNotPreserved warns
-	// once at the end of the restore if that left any owner or group
-	// other than recorded.
+	// the call entirely as non-root and emit one warning at the end
+	// of the restore explaining that ownership was not preserved.
 	runningAsRoot bool
 	// directories holds every restored directory, for
 	// applyDirectoryMetadata to finish after the restore loop.

internal/vaultik/restore_ownership_warning_test.go

@@ -1,114 +0,0 @@
-package vaultik //nolint:testpackage // calls the unexported ownership check
-
-import (
-	"bytes"
-	"context"
-	"os"
-	"strings"
-	"syscall"
-	"testing"
-
-	"github.com/spf13/afero"
-	"github.com/stretchr/testify/assert"
-	"github.com/stretchr/testify/require"
-	"sneak.berlin/go/vaultik/internal/database"
-	"sneak.berlin/go/vaultik/internal/log"
-	"sneak.berlin/go/vaultik/internal/ui"
-)
-
-// These tests cover https://git.eeqj.de/sneak/vaultik/issues/316: a
-// restore by a normal user warns that ownership was not preserved only
-// when some restored entry has another owner or group on disk than the
-// snapshot records.
-
-const ownershipWarning = "did not preserve file ownership"
-
-// TestOwnershipWarningSilentWhenEntriesMatch checks that a restore whose
-// entries all end up with their recorded owner and group prints no
-// warning.
-func TestOwnershipWarningSilentWhenEntriesMatch(t *testing.T) {
-	log.Initialize(log.Config{})
-	t.Parallel()
-
-	targetDir := t.TempDir()
-	owner := ownerOf(t, targetDir)
-
-	out := restoreAsNormalUser(t, targetDir, []*database.File{
-		{Path: "/a", Mode: plainFileMode, UID: owner.Uid, GID: owner.Gid},
-		{Path: "/b", Mode: plainFileMode, UID: owner.Uid, GID: owner.Gid},
-	})
-
-	assert.Empty(t, out)
-}
-
-// TestOwnershipWarningWhenDirectoryGivesItsGroup checks that the warning
-// is printed, once, when entries recorded with the restoring user's
-// owner and group take another group from the setgid directory they are
-// restored into, as every new entry takes its directory's group on
-// macOS.
-func TestOwnershipWarningWhenDirectoryGivesItsGroup(t *testing.T) {
-	log.Initialize(log.Config{})
-	t.Parallel()
-
-	if os.Geteuid() != 0 {
-		t.Skip("giving a directory to another group needs root")
-	}
-
-	targetDir := t.TempDir()
-	user := ownerOf(t, targetDir)
-
-	require.NoError(t, os.Chown(targetDir, -1, int(otherOwnerID)))
-	require.NoError(t, os.Chmod(targetDir, os.ModeSetgid|writableTestMode))
-
-	out := restoreAsNormalUser(t, targetDir, []*database.File{
-		{Path: "/a", Mode: plainFileMode, UID: user.Uid, GID: user.Gid},
-		{Path: "/b", Mode: plainFileMode, UID: user.Uid, GID: user.Gid},
-	})
-
-	assert.Equal(t, 1, strings.Count(out, ownershipWarning), out)
-}
-
-// ownerOf returns the owner and group path has on disk.
-func ownerOf(t *testing.T, path string) *syscall.Stat_t {
-	t.Helper()
-
-	info, err := os.Lstat(path)
-	require.NoError(t, err)
-
-	owner, ok := info.Sys().(*syscall.Stat_t)
-	require.True(t, ok)
-
-	return owner
-}
-
-// restoreAsNormalUser restores rows, all empty regular files, into
-// targetDir without changing any owner or group, as restore does for a
-// normal user, and returns what warnIfOwnershipNotPreserved prints.
-func restoreAsNormalUser(
-	t *testing.T, targetDir string, rows []*database.File,
-) string {
-	t.Helper()
-
-	ctx := context.Background()
-	rows, repos := makeFiles(ctx, t, rows)
-
-	var out bytes.Buffer
-
-	v := newContainmentVaultik(ctx, afero.NewOsFs())
-	v.UI = ui.NewWithColor(&out, false)
-
-	session := &restoreSession{
-		v:      v,
-		ctx:    ctx,
-		repos:  repos,
-		opts:   &RestoreOptions{TargetDir: targetDir},
-		result: &RestoreResult{},
-	}
-	for _, row := range rows {
-		require.NoError(t, session.restoreFile(row))
-	}
-
-	v.warnIfOwnershipNotPreserved(rows, targetDir)
-
-	return out.String()
-}

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

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",