vaultik/internal/snapshot/upload_cancel_log_test.go

//nolint:testpackage // exercises the unexported uploadBlobIfNeeded
package snapshot

import (
	"bytes"
	"context"
	"fmt"
	"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"

// cancelOnPutStorer stands in for a backend whose upload the user
// interrupts: it cancels the operation's context mid-upload and fails
// the way the S3 backend does when its context is cancelled.
type cancelOnPutStorer struct {
	storage.Storer

	cancel context.CancelFunc
}

func (c *cancelOnPutStorer) PutWithProgress(
	ctx context.Context, _ string, _ io.Reader,
	_ int64, _ storage.ProgressCallback,
) error {
	c.cancel()

	return fmt.Errorf("upload multipart failed: %w", ctx.Err())
}

// 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)

	store := &cancelOnPutStorer{Storer: inner, cancel: cancel}

	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)
	}
}