Do not log an upload stopped by Ctrl-C as an error (closes #434)

Pressing Ctrl-C or sending SIGTERM during a backup logged the interrupted blob upload as an ERROR before the interrupted message. The upload step now skips that record when the backup's context has been cancelled, whatever error the storage returned. An upload that fails for any other reason is still logged.

Model: opus-5-5

internal/snapshot/upload_cancel_log_test.go

@@ -0,0 +1,135 @@
+//nolint:testpackage // exercises the unexported uploadBlobIfNeeded
+package snapshot
+
+import (
+	"bytes"
+	"context"
+	"io"
+	"os"
+	"path/filepath"
+	"strings"
+	"testing"
+	"time"
+
+	"sneak.berlin/go/vaultik/internal/blob"
+	"sneak.berlin/go/vaultik/internal/log"
+	"sneak.berlin/go/vaultik/internal/storage"
+	"sneak.berlin/go/vaultik/internal/storage/faultstore"
+	"sneak.berlin/go/vaultik/internal/ui"
+)
+
+const uploadFailedLogMessage = "Failed to upload blob"
+
+// uploadTestBlob uploads a small blob through store.
+func uploadTestBlob(ctx context.Context, store storage.Storer) error {
+	data := []byte("blob data")
+	s := &Scanner{storage: store, ui: ui.NewWithColor(io.Discard, false)}
+
+	_, _, err := s.uploadBlobIfNeeded(ctx, "blobs/test", &blob.WithReader{
+		FinishedBlob: &blob.FinishedBlob{
+			Hash:       "test",
+			Compressed: int64(len(data)),
+		},
+		Reader: bytes.NewReader(data),
+	}, time.Now(), &ScanResult{})
+
+	return err
+}
+
+// captureLog runs fn and returns what the logger wrote to stderr
+// meanwhile. The logger writes to the os.Stderr it finds when it is
+// initialized, so os.Stderr is pointed at a file first. Not
+// parallel-safe: os.Stderr and the logger are process-global.
+func captureLog(t *testing.T, fn func()) string {
+	t.Helper()
+
+	stderrPath := filepath.Join(t.TempDir(), "stderr")
+
+	stderrFile, err := os.Create(stderrPath) //nolint:gosec // G304: test temp path
+	if err != nil {
+		t.Fatalf("creating stderr file: %v", err)
+	}
+
+	previous := os.Stderr
+	os.Stderr = stderrFile
+
+	log.Initialize(log.Config{})
+
+	fn()
+
+	os.Stderr = previous
+
+	log.Initialize(log.Config{})
+
+	_ = stderrFile.Close()
+
+	captured, err := os.ReadFile(stderrPath) //nolint:gosec // G304: test temp path
+	if err != nil {
+		t.Fatalf("reading stderr file: %v", err)
+	}
+
+	return string(captured)
+}
+
+// An upload stopped by Ctrl-C or SIGTERM is not logged as an error; the
+// interrupted message is all the user sees. See
+// https://git.eeqj.de/sneak/vaultik/issues/434.
+//
+//nolint:paralleltest // captureLog replaces os.Stderr
+func TestInterruptedUploadIsNotLoggedAsError(t *testing.T) {
+	inner, err := storage.NewFileStorer(t.TempDir())
+	if err != nil {
+		t.Fatal(err)
+	}
+
+	ctx, cancel := context.WithCancel(context.Background())
+	t.Cleanup(cancel)
+
+	// The user interrupts mid-upload. The injected error does not wrap
+	// context.Canceled, so only ctx shows why the upload failed.
+	store := faultstore.New(inner)
+	store.OnPut = func(string) faultstore.PutAction {
+		cancel()
+
+		return faultstore.PutFail
+	}
+
+	var uploadErr error
+
+	stderr := captureLog(t, func() { uploadErr = uploadTestBlob(ctx, store) })
+
+	if uploadErr == nil {
+		t.Fatal("expected the upload to fail")
+	}
+
+	if strings.Contains(stderr, uploadFailedLogMessage) {
+		t.Errorf("interrupted upload logged as a failure: %q", stderr)
+	}
+}
+
+// An upload that fails for any other reason is still logged as an error.
+//
+//nolint:paralleltest // captureLog replaces os.Stderr
+func TestFailedUploadIsLoggedAsError(t *testing.T) {
+	inner, err := storage.NewFileStorer(t.TempDir())
+	if err != nil {
+		t.Fatal(err)
+	}
+
+	store := faultstore.New(inner)
+	store.OnPut = func(string) faultstore.PutAction { return faultstore.PutFail }
+
+	var uploadErr error
+
+	stderr := captureLog(t, func() {
+		uploadErr = uploadTestBlob(context.Background(), store)
+	})
+
+	if uploadErr == nil {
+		t.Fatal("expected the upload to fail")
+	}
+
+	if !strings.Contains(stderr, uploadFailedLogMessage) {
+		t.Errorf("failed upload not logged: %q", stderr)
+	}
+}