Report an unreadable blob without its bytes, once (closes #424)

A blob that is not a valid age stream made restore print age's error, which quotes the blob's raw bytes, once for every file that needed it. The error now says the blob is not a valid age stream and names its hash, without quoting any bytes. Under --skip-errors a blob that failed is reported once, with the number of files it affected, and is not downloaded again for each file.

Model: opus-5-5

internal/blobgen/negative_test.go

@@ -2,8 +2,10 @@ package blobgen_test
 
 import (
 	"bytes"
+	"errors"
 	"fmt"
 	"testing"
+	"testing/iotest"
 
 	"filippo.io/age"
 	"github.com/stretchr/testify/assert"
@@ -120,6 +122,38 @@ func TestNewReaderTrailingAndGarbage(t *testing.T) {
 	})
 }
 
+// TestNewReaderGarbageErrorQuotesNoBytes checks that lines of text in
+// place of a blob fail with ErrNotAgeStream, and that the error carries
+// none of their bytes. The lines end in a newline because age's own error
+// quotes the data's first line only when it reads a whole line.
+func TestNewReaderGarbageErrorQuotesNoBytes(t *testing.T) {
+	t.Parallel()
+
+	id, _ := makeIdentity(t)
+	garbage := bytes.Repeat([]byte("garbage-bytes-\n"), 100)
+
+	_, err := blobgen.NewReader(bytes.NewReader(garbage), id)
+
+	require.ErrorIs(t, err, blobgen.ErrNotAgeStream)
+	assert.NotContains(t, err.Error(), "garbage-bytes-")
+}
+
+// errConnectionReset stands for a storage read that fails.
+var errConnectionReset = errors.New("connection reset")
+
+// TestNewReaderReadFailure checks that a failed read of the age header is
+// returned as that read error, not as ErrNotAgeStream.
+func TestNewReaderReadFailure(t *testing.T) {
+	t.Parallel()
+
+	id, _ := makeIdentity(t)
+
+	_, err := blobgen.NewReader(iotest.ErrReader(errConnectionReset), id)
+
+	require.ErrorIs(t, err, errConnectionReset)
+	assert.NotErrorIs(t, err, blobgen.ErrNotAgeStream)
+}
+
 // TestNewWriterInvalidLevel covers the rejected end of issue case 9: an
 // out-of-range compression level errors and writes nothing to the destination.
 func TestNewWriterInvalidLevel(t *testing.T) {

internal/blobgen/reader.go

@@ -11,6 +11,11 @@ import (
 	"github.com/klauspost/compress/zstd"
 )
 
+// ErrNotAgeStream is returned by NewReader when the data cannot be opened
+// as an age stream, for example because its header is malformed. It
+// replaces age's own error, which can quote the data's first bytes.
+var ErrNotAgeStream = errors.New("not a valid age stream")
+
 // Reader wraps decompression and decryption with SHA256 verification
 type Reader struct {
 	reader       io.Reader
@@ -24,11 +29,25 @@ type Reader struct {
 // NewReader creates a new Reader that decrypts, decompresses, and verifies
 // data. Every supplied identity is offered to age.Decrypt, so a blob
 // encrypted to any one of them can be read.
+//
+// A failure to read r is returned as that error, and a blob encrypted to
+// none of the identities as age.NoIdentityMatchError. Any other failure
+// to open the age stream is ErrNotAgeStream.
 func NewReader(r io.Reader, identities ...age.Identity) (*Reader, error) {
-	// Create decryption reader
+	src := &readErrorRecorder{reader: r}
-	decReader, err := age.Decrypt(r, identities...)
+
+	decReader, err := age.Decrypt(src, identities...)
 	if err != nil {
-		return nil, fmt.Errorf("creating decryption reader: %w", err)
+		var noMatch *age.NoIdentityMatchError
+
+		switch {
+		case src.err != nil:
+			return nil, fmt.Errorf("reading age header: %w", src.err)
+		case errors.As(err, &noMatch):
+			return nil, fmt.Errorf("creating decryption reader: %w", err)
+		default:
+			return nil, ErrNotAgeStream
+		}
 	}
 
 	// Create decompression reader
@@ -52,6 +71,23 @@ func NewReader(r io.Reader, identities ...age.Identity) (*Reader, error) {
 	}, nil
 }
 
+// readErrorRecorder passes reads through to reader and keeps the first
+// error other than io.EOF, so NewReader can tell a failed read from bad
+// data.
+type readErrorRecorder struct {
+	reader io.Reader
+	err    error
+}
+
+func (r *readErrorRecorder) Read(p []byte) (int, error) {
+	n, err := r.reader.Read(p)
+	if err != nil && !errors.Is(err, io.EOF) && r.err == nil {
+		r.err = err
+	}
+
+	return n, err
+}
+
 // Read implements io.Reader
 func (r *Reader) Read(p []byte) (int, error) {
 	n, err := r.teeReader.Read(p)

internal/vaultik/restore.go

@@ -106,7 +106,12 @@ type RestoreResult struct {
 	BytesDownloaded int64
 	Duration        time.Duration
 	FilesFailed     int
-	FailedFiles     []string // Paths of files that failed to restore
+	FailedFiles     []string // Paths of files that failed to restore for their own reason
+	// Blobs that could not be downloaded, and the paths of the files
+	// skipped because they need one of them. Those files are counted in
+	// FilesFailed but not listed in the summary.
+	BlobsFailed            int
+	FilesNeedingFailedBlob []string
 	// Verification results (only populated if Verify option is set)
 	FilesVerified     int
 	BytesVerified     int64
@@ -231,6 +236,11 @@ func (v *Vaultik) finishRestore(
 	if result.FilesFailed > 0 {
 		v.UI.Warningf("%d file(s) failed to restore:", result.FilesFailed)
 
+		if result.BlobsFailed > 0 {
+			v.UI.Detailf("%d of them need a blob that could not be read (%d blob(s) in all).",
+				len(result.FilesNeedingFailedBlob), result.BlobsFailed)
+		}
+
 		for _, path := range result.FailedFiles {
 			v.UI.Detailf("%s", v.UI.Path(path))
 		}
@@ -499,8 +509,8 @@ func (v *Vaultik) runRestoreLoop(
 // Returns false when nothing is pending download (the caller stops).
 //
 // A blob that cannot be downloaded is reported through
-// handleRestoreFileError for every pending file that references it, so
+// handleRestoreBlobError, so it aborts the restore unless --skip-errors
-// it aborts the restore unless --skip-errors is set.
+// is set.
 func (s *restoreSession) downloadNextBlobSet(
 	plan *restorePlan, filesByID map[types.FileID]*database.File,
 ) (bool, error) {
@@ -533,12 +543,11 @@ func (s *restoreSession) downloadNextBlobSet(
 				return false, err
 			}
 
-			for _, fileID := range plan.filesReferencingBlob(hash) {
+			blobErr := s.v.handleRestoreBlobError(
-				fileErr := s.v.handleRestoreFileError(
+				plan, s.opts, s.result, filesByID,
-					plan, s.opts, s.result, filesByID[fileID], fileID, err)
+				plan.filesReferencingBlob(hash), err)
-				if fileErr != nil {
+			if blobErr != nil {
-					return false, fileErr
+				return false, blobErr
-				}
 			}
 
 			// next is among the failed files, so the rest of its blob set
@@ -653,6 +662,41 @@ func (v *Vaultik) handleRestoreFileError(
 	return nil
 }
 
+// handleRestoreBlobError records a blob that could not be downloaded.
+// fileIDs are the pending files that need it, never empty. Without
+// --skip-errors the first of them fails the restore. With it, the blob is
+// reported once, and its files are counted as failed and dropped from
+// the plan without being reported one by one.
+func (v *Vaultik) handleRestoreBlobError(
+	plan *restorePlan, opts *RestoreOptions, result *RestoreResult,
+	filesByID map[types.FileID]*database.File, fileIDs []types.FileID,
+	err error,
+) error {
+	if !opts.SkipErrors {
+		return v.handleRestoreFileError(
+			plan, opts, result, filesByID[fileIDs[0]], fileIDs[0], err)
+	}
+
+	log.Error("Failed to restore files", "files", len(fileIDs), "error", err)
+	v.UI.Errorf("Failed to restore %d file(s): %v. Skipping them (--skip-errors).",
+		len(fileIDs), err)
+
+	result.BlobsFailed++
+
+	for _, fileID := range fileIDs {
+		path := filesByID[fileID].Path.String()
+
+		log.Debug("Skipped file that needs a failed blob", "path", path)
+
+		result.FilesFailed++
+		result.FilesNeedingFailedBlob = append(result.FilesNeedingFailedBlob, path)
+
+		plan.finishFile(fileID)
+	}
+
+	return nil
+}
+
 // printRestoreProgress emits a periodic restore-phase status line via
 // the UI writer, mirroring scanner.printProcessingProgress so the two
 // long-running commands have the same on-screen rhythm.
@@ -724,8 +768,8 @@ func (v *Vaultik) handleRestoreVerification(
 ) error {
 	// A file that failed to restore was not written and is already
 	// reported as such, so it is not verified.
-	failedToRestore := make(map[string]bool, len(result.FailedFiles))
+	failedToRestore := make(map[string]bool, result.FilesFailed)
-	for _, path := range result.FailedFiles {
+	for _, path := range slices.Concat(result.FailedFiles, result.FilesNeedingFailedBlob) {
 		failedToRestore[path] = true
 	}
 

internal/vaultik/restore_skip_errors_test.go

@@ -51,27 +51,72 @@ func TestRestoreSkipErrorsSkipsFilesOfMissingBlob(t *testing.T) {
 	t.Parallel()
 
 	ctx := context.Background()
-	assertRestoreSkipsLostFiles(ctx, t, backupThenDeleteOneBlob(ctx, t))
+	backup := backupThenDeleteOneBlob(ctx, t)
+	out := assertRestoreSkipsLostFiles(ctx, t, backup)
+
+	assertLostFilesCountedNotListed(t, backup, out)
+}
+
+// TestRestoreSkipErrorsReportsUnreadableBlobOnce restores with SkipErrors
+// after one blob of a two-blob snapshot was overwritten with other bytes
+// of the same size. The blob must be reported once, by its hash, as not a
+// valid age stream, without quoting its bytes, and its files must be
+// counted, not listed.
+func TestRestoreSkipErrorsReportsUnreadableBlobOnce(t *testing.T) {
+	log.Initialize(log.Config{})
+	t.Parallel()
+
+	ctx := context.Background()
+	backup, lostBlob := backupThenOverwriteOneBlob(ctx, t)
+	out := assertRestoreSkipsLostFiles(ctx, t, backup)
+
+	assert.Equal(t, 1, strings.Count(out, "not a valid age stream"), out)
+	assert.Contains(t, out, lostBlob[:16])
+	assert.NotContains(t, out, overwriteBlobPattern)
+	assertLostFilesCountedNotListed(t, backup, out)
 }
 
 // TestRestoreSkipErrorsSkipsFilesWithChunkInNoBlob restores with
 // SkipErrors a snapshot whose metadata lists chunks that no blob holds, as
-// earlier backup defects left behind.
+// earlier backup defects left behind. Each such file fails for its own
+// reason, so each is listed.
 func TestRestoreSkipErrorsSkipsFilesWithChunkInNoBlob(t *testing.T) {
 	log.Initialize(log.Config{})
 	t.Parallel()
 
 	ctx := context.Background()
-	assertRestoreSkipsLostFiles(ctx, t, backupThenDropOneBlobFromMetadata(ctx, t))
+	backup := backupThenDropOneBlobFromMetadata(ctx, t)
+	out := assertRestoreSkipsLostFiles(ctx, t, backup)
+
+	for path := range backup.lost {
+		assert.Containsf(t, out, path, "%s must be reported", path)
+	}
 }
 
-// assertRestoreSkipsLostFiles restores backup with SkipErrors. Every file
+// assertLostFilesCountedNotListed checks that the restore output out
-// stored in the lost blob must be reported as failed and left absent,
+// counts the files of the lost blob and names none of them.
-// every other file must be restored intact, and Restore must still return
+func assertLostFilesCountedNotListed(
-// an error.
+	t *testing.T, backup *missingBlobBackup, out string,
+) {
+	t.Helper()
+
+	assert.Contains(t, out, fmt.Sprintf(
+		"%d of them need a blob that could not be read (1 blob(s) in all)",
+		len(backup.lost)))
+
+	for path := range backup.lost {
+		assert.NotContainsf(t, out, path,
+			"%s needs the lost blob and must be counted, not listed", path)
+	}
+}
+
+// assertRestoreSkipsLostFiles restores backup with SkipErrors and returns
+// what it printed. Every file stored in the lost blob must be left
+// absent, every other file must be restored intact, and Restore must
+// still return an error.
 func assertRestoreSkipsLostFiles(
 	ctx context.Context, t *testing.T, backup *missingBlobBackup,
-) {
+) string {
 	t.Helper()
 
 	var out bytes.Buffer
@@ -93,8 +138,6 @@ func assertRestoreSkipsLostFiles(
 		restored := filepath.Join(backup.restoreDir, path)
 
 		if backup.lost[path] {
-			assert.Containsf(t, out.String(), path,
-				"%s needs the lost blob and must be reported", path)
 			assert.NoFileExists(t, restored)
 
 			continue
@@ -104,6 +147,8 @@ func assertRestoreSkipsLostFiles(
 		require.NoErrorf(t, err, "%s does not need the lost blob", path)
 		assert.Equalf(t, content, got, "%s restored with wrong content", path)
 	}
+
+	return out.String()
 }
 
 // TestRestoreSkipErrorsVerifyChecksOnlyRestoredFiles restores with
@@ -144,9 +189,9 @@ func TestRestoreSkipErrorsVerifyChecksOnlyRestoredFiles(t *testing.T) {
 // TestRestoreSkipErrorsVerifyReportsFailuresApart restores with
 // SkipErrors and Verify after one blob of a two-blob snapshot was
 // deleted, while one file that does restore is written one byte too long.
-// The restore warning must list only the files of the deleted blob, the
+// The restore warning must count the files of the deleted blob without
-// verification summary only the long file, each path once, and Restore
+// listing them, the verification summary must list only the long file,
-// must return an error.
+// once, and Restore must return an error.
 func TestRestoreSkipErrorsVerifyReportsFailuresApart(t *testing.T) {
 	log.Initialize(log.Config{})
 	t.Parallel()
@@ -186,9 +231,9 @@ func TestRestoreSkipErrorsVerifyReportsFailuresApart(t *testing.T) {
 		"Verification failed: 1 files did not match")
 	require.Truef(t, found, "no verification summary in:\n%s", out.String())
 
+	assertLostFilesCountedNotListed(t, backup, warning)
+
 	for path := range backup.lost {
-		assert.Equalf(t, 1, strings.Count(warning, path),
-			"%s must be listed once as failed to restore", path)
 		assert.NotContainsf(t, summary, path,
 			"%s was not restored and must not fail verification", path)
 	}
@@ -292,6 +337,35 @@ func backupThenDeleteOneBlob(
 	return backup
 }
 
+// overwriteBlobPattern repeats, each time followed by a newline, through
+// the bytes that backupThenOverwriteOneBlob writes over a blob. age's own
+// error quotes the data's first line only when it reads a whole line.
+const overwriteBlobPattern = "overwritten-blob-bytes-"
+
+// backupThenOverwriteOneBlob backs up missingBlobFileCount single-chunk
+// files, then overwrites the blob holding the first of them with as many
+// bytes of overwriteBlobPattern lines. It also returns that blob's hash.
+func backupThenOverwriteOneBlob(
+	ctx context.Context, t *testing.T,
+) (*missingBlobBackup, string) {
+	t.Helper()
+
+	backup, db, lostBlob := backupSingleChunkFiles(ctx, t)
+	require.NoError(t, db.Close())
+
+	key := fmt.Sprintf("blobs/%s/%s/%s", lostBlob[:2], lostBlob[2:4], lostBlob)
+
+	info, err := backup.storer.Stat(ctx, key)
+	require.NoError(t, err)
+
+	line := overwriteBlobPattern + "\n"
+	pattern := bytes.Repeat([]byte(line), int(info.Size)/len(line)+1)
+	require.NoError(t, backup.storer.Put(
+		ctx, key, bytes.NewReader(pattern[:info.Size])))
+
+	return backup, lostBlob
+}
+
 // backupThenDropOneBlobFromMetadata backs up missingBlobFileCount
 // single-chunk files, then removes the blob holding the first of them from
 // the snapshot and exports the snapshot metadata again. The exported