Files
vaultik/internal/snapshot/upload_cancel_log_test.go
T
sneak 3e7c12aabf
check / check (push) Successful in 9m58s
Print a failed command's error once on stderr (closes #433)
A command that failed after startup wrote the error twice on stderr:
as an ERROR log record and as the final ERROR: line. The failure
handlers now log the failure at info level, so the record appears only
under --verbose or --debug, next to the records that led up to it.

A failed blob upload is logged at info level for the same reason. A
restore that stops on a file it cannot restore no longer logs that
file's error, which the final line carries; under --skip-errors it is
still logged.

Model: opus-5-5
2026-11-11 05:55:13 +00:00

136 lines
3.4 KiB
Go

//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, at the --verbose level. 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{Verbose: true})
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.
//
//nolint:paralleltest // captureLog replaces os.Stderr
func TestFailedUploadIsLogged(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)
}
}