From 573221aa4077f9a889f0dbcf17e43fbf8994d87d Mon Sep 17 00:00:00 2001 From: Alexander Weiss Date: Fri, 1 Jan 2021 09:50:47 +0100 Subject: [PATCH 1/3] Add failing test for fileRestorer --- internal/restorer/filerestorer_test.go | 27 ++++++++++++++++++++++++++ 1 file changed, 27 insertions(+) diff --git a/internal/restorer/filerestorer_test.go b/internal/restorer/filerestorer_test.go index 28bcd5e28..6ccbc2b37 100644 --- a/internal/restorer/filerestorer_test.go +++ b/internal/restorer/filerestorer_test.go @@ -8,6 +8,7 @@ import ( "testing" "github.com/restic/restic/internal/crypto" + "github.com/restic/restic/internal/errors" "github.com/restic/restic/internal/restic" rtest "github.com/restic/restic/internal/test" ) @@ -237,3 +238,29 @@ func TestFileRestorerPackSkip(t *testing.T) { }, }, files) } + +func TestErrorRestoreFiles(t *testing.T) { + tempdir, cleanup := rtest.TempDir(t) + defer cleanup() + content := []TestFile{ + { + name: "file1", + blobs: []TestBlob{ + {"data1-1", "pack1-1"}, + }, + }} + + repo := newTestRepo(content) + + loadError := errors.New("load error") + // loader always returns an error + repo.loader = func(ctx context.Context, h restic.Handle, length int, offset int64, fn func(rd io.Reader) error) error { + return loadError + } + + r := newFileRestorer(tempdir, repo.loader, repo.key, repo.Lookup) + r.files = repo.files + + err := r.restoreFiles(context.TODO()) + rtest.Assert(t, err != nil, "restoreFiles should have reported an error!") +} From 5e22ae10f18042f8aeabd6e6ed71b74833a5f3cb Mon Sep 17 00:00:00 2001 From: Alexander Weiss Date: Mon, 4 Jan 2021 19:20:04 +0100 Subject: [PATCH 2/3] Add error handling for fileRestorer --- internal/restorer/filerestorer.go | 105 ++++++++++++------------- internal/restorer/filerestorer_test.go | 2 +- internal/restorer/restorer.go | 1 + 3 files changed, 52 insertions(+), 56 deletions(-) diff --git a/internal/restorer/filerestorer.go b/internal/restorer/filerestorer.go index 92ba39e77..bdb3ff708 100644 --- a/internal/restorer/filerestorer.go +++ b/internal/restorer/filerestorer.go @@ -9,6 +9,8 @@ import ( "sort" "sync" + "golang.org/x/sync/errgroup" + "github.com/restic/restic/internal/crypto" "github.com/restic/restic/internal/debug" "github.com/restic/restic/internal/errors" @@ -23,20 +25,16 @@ import ( const ( workerCount = 8 - // fileInfo flags - fileProgress = 1 - fileError = 2 - largeFileBlobCount = 25 ) // information about regular file being restored type fileInfo struct { - lock sync.Mutex - flags int - size int64 - location string // file on local filesystem relative to restorer basedir - blobs interface{} // blobs of the file + lock sync.Mutex + inProgress bool + size int64 + location string // file on local filesystem relative to restorer basedir + blobs interface{} // blobs of the file } type fileBlobInfo struct { @@ -60,6 +58,7 @@ type fileRestorer struct { dst string files []*fileInfo + Error func(string, error) error } func newFileRestorer(dst string, @@ -73,6 +72,7 @@ func newFileRestorer(dst string, packLoader: packLoader, filesWriter: newFilesWriter(workerCount), dst: dst, + Error: restorerAbortOnAllErrors, } } @@ -142,47 +142,42 @@ func (r *fileRestorer) restoreFiles(ctx context.Context) error { } } - var wg sync.WaitGroup + wg, ctx := errgroup.WithContext(ctx) downloadCh := make(chan *packInfo) - worker := func() { - defer wg.Done() - for { - select { - case <-ctx.Done(): - return // context cancelled - case pack, ok := <-downloadCh: - if !ok { - return // channel closed - } - r.downloadPack(ctx, pack) + + worker := func() error { + for pack := range downloadCh { + if err := r.downloadPack(ctx, pack); err != nil { + return err } } + return nil } for i := 0; i < workerCount; i++ { - wg.Add(1) - go worker() + wg.Go(worker) } // the main restore loop - for _, id := range packOrder { - pack := packs[id] - select { - case <-ctx.Done(): - return ctx.Err() - case downloadCh <- pack: - debug.Log("Scheduled download pack %s", pack.id.Str()) + wg.Go(func() error { + for _, id := range packOrder { + pack := packs[id] + select { + case <-ctx.Done(): + return ctx.Err() + case downloadCh <- pack: + debug.Log("Scheduled download pack %s", pack.id.Str()) + } } - } + close(downloadCh) + return nil + }) - close(downloadCh) - wg.Wait() - - return nil + return wg.Wait() } const maxBufferSize = 4 * 1024 * 1024 -func (r *fileRestorer) downloadPack(ctx context.Context, pack *packInfo) { +func (r *fileRestorer) downloadPack(ctx context.Context, pack *packInfo) error { // calculate pack byte range and blob->[]files->[]offsets mappings start, end := int64(math.MaxInt64), int64(0) @@ -237,12 +232,11 @@ func (r *fileRestorer) downloadPack(ctx context.Context, pack *packInfo) { return blobs[sortedBlobs[i]].offset < blobs[sortedBlobs[j]].offset }) - markFileError := func(file *fileInfo, err error) { - file.lock.Lock() - defer file.lock.Unlock() - if file.flags&fileError == 0 { - file.flags |= fileError + sanitizeError := func(file *fileInfo, err error) error { + if err != nil { + err = r.Error(file.location, err) } + return err } h := restic.Handle{Type: restic.PackFile, Name: pack.id.String()} @@ -263,7 +257,9 @@ func (r *fileRestorer) downloadPack(ctx context.Context, pack *packInfo) { blobData, buf, err = r.loadBlob(bufRd, blobID, blob.length, buf) if err != nil { for file := range blob.files { - markFileError(file, err) + if errFile := sanitizeError(file, err); errFile != nil { + return errFile + } } continue } @@ -277,37 +273,36 @@ func (r *fileRestorer) downloadPack(ctx context.Context, pack *packInfo) { // - should allow concurrent writes to the file // so write the first blob while holding file lock // write other blobs after releasing the lock - file.lock.Lock() - create := file.flags&fileProgress == 0 createSize := int64(-1) - if create { - defer file.lock.Unlock() - file.flags |= fileProgress - createSize = file.size - } else { + file.lock.Lock() + if file.inProgress { file.lock.Unlock() + } else { + defer file.lock.Unlock() + file.inProgress = true + createSize = file.size } return r.filesWriter.writeToFile(r.targetPath(file.location), blobData, offset, createSize) } - err := writeToFile() + err := sanitizeError(file, writeToFile()) if err != nil { - markFileError(file, err) - break + return err } } } } - return nil }) if err != nil { for file := range pack.files { - markFileError(file, err) + if errFile := sanitizeError(file, err); errFile != nil { + return errFile + } } - return } + return nil } func (r *fileRestorer) loadBlob(rd io.Reader, blobID restic.ID, length int, buf []byte) ([]byte, []byte, error) { diff --git a/internal/restorer/filerestorer_test.go b/internal/restorer/filerestorer_test.go index 6ccbc2b37..ac8e371da 100644 --- a/internal/restorer/filerestorer_test.go +++ b/internal/restorer/filerestorer_test.go @@ -262,5 +262,5 @@ func TestErrorRestoreFiles(t *testing.T) { r.files = repo.files err := r.restoreFiles(context.TODO()) - rtest.Assert(t, err != nil, "restoreFiles should have reported an error!") + rtest.Equals(t, loadError, err) } diff --git a/internal/restorer/restorer.go b/internal/restorer/restorer.go index 292241498..75ed99f86 100644 --- a/internal/restorer/restorer.go +++ b/internal/restorer/restorer.go @@ -216,6 +216,7 @@ func (res *Restorer) RestoreTo(ctx context.Context, dst string) error { idx := restic.NewHardlinkIndex() filerestorer := newFileRestorer(dst, res.repo.Backend().Load, res.repo.Key(), res.repo.Index().Lookup) + filerestorer.Error = res.Error debug.Log("first pass for %q", dst) From 6e942693ba90f543f81f97b754dc171267c30286 Mon Sep 17 00:00:00 2001 From: Alexander Weiss Date: Tue, 5 Jan 2021 09:13:15 +0100 Subject: [PATCH 3/3] Fix #3166 --- changelog/unreleased/issue-3166 | 9 +++++++++ cmd/restic/cmd_restore.go | 22 +++++++++++++++++----- 2 files changed, 26 insertions(+), 5 deletions(-) create mode 100644 changelog/unreleased/issue-3166 diff --git a/changelog/unreleased/issue-3166 b/changelog/unreleased/issue-3166 new file mode 100644 index 000000000..b3874cf2b --- /dev/null +++ b/changelog/unreleased/issue-3166 @@ -0,0 +1,9 @@ +Bugfix: Improve error handling in restore + +Restic restore used to not print errors while downloading file contents from +the repository. restore also incorrectly exited with a zero error code even +when there were errors during the restore process. Now, a non-zero code is +returned. + +https://github.com/restic/restic/issues/3166 +https://github.com/restic/restic/pull/3207 diff --git a/cmd/restic/cmd_restore.go b/cmd/restic/cmd_restore.go index e51eee6cb..cbab2bed4 100644 --- a/cmd/restic/cmd_restore.go +++ b/cmd/restic/cmd_restore.go @@ -191,14 +191,26 @@ func runRestore(opts RestoreOptions, gopts GlobalOptions, args []string) error { Verbosef("restoring %s to %s\n", res.Snapshot(), opts.Target) err = res.RestoreTo(ctx, opts.Target) - if err == nil && opts.Verify { + if err != nil { + return err + } + + if totalErrors > 0 { + return errors.Fatalf("There were %d errors\n", totalErrors) + } + + if opts.Verify { Verbosef("verifying files in %s\n", opts.Target) var count int count, err = res.VerifyFiles(ctx, opts.Target) + if err != nil { + return err + } + if totalErrors > 0 { + return errors.Fatalf("There were %d errors\n", totalErrors) + } Verbosef("finished verifying %d files in %s\n", count, opts.Target) } - if totalErrors > 0 { - Printf("There were %d errors\n", totalErrors) - } - return err + + return nil }