Do not log an interrupted blob upload as an error (closes #434)
check / check (push) Successful in 8m55s
check / check (push) Successful in 8m55s
Ctrl-C or SIGTERM cancels the operation's context, which makes the blob upload in progress fail. The upload step logged that failure at level ERROR before the interrupted message, so a cancellation the user asked for read as a storage failure. It now logs the failure only while the context is still live; only an interrupt cancels it. Any other upload failure is still logged. Model: opus-5-5
This commit is contained in:
1 parent
0d0c76fa24
commit
e7c030f215
2 files changed
+139
No files matched your search
@@ -1861,7 +1861,11 @@ func (s *Scanner) uploadBlobIfNeeded(
|
|||||||
err = s.storage.PutWithProgress(ctx, blobPath, blobWithReader.Reader,
|
err = s.storage.PutWithProgress(ctx, blobPath, blobWithReader.Reader,
|
||||||
finishedBlob.Compressed, progressCallback)
|
finishedBlob.Compressed, progressCallback)
|
||||||
if err != nil {
|
if err != nil {
|
||||||
|
// Only an interrupt cancels ctx, and the user is told about it,
|
||||||
|
// so an upload it stopped is not logged as a storage failure.
|
||||||
|
if ctx.Err() == nil {
|
||||||
log.Error("Failed to upload blob", "hash", finishedBlob.Hash, "error", err)
|
log.Error("Failed to upload blob", "hash", finishedBlob.Hash, "error", err)
|
||||||
|
}
|
||||||
|
|
||||||
return 0, false, fmt.Errorf("uploading blob to storage: %w", err)
|
return 0, false, fmt.Errorf("uploading blob to storage: %w", err)
|
||||||
}
|
}
|
||||||
|
|||||||
@@ -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)
|
||||||
|
}
|
||||||
|
}
|
||||||
Reference in new issue
Block a user