From f0d8710611fabf5720c4062bcbdb37925fb36097 Mon Sep 17 00:00:00 2001 From: Michael Eischer Date: Thu, 2 Jan 2020 13:24:08 +0100 Subject: [PATCH 01/11] Add benchmark for checker scaling with snapshot count --- internal/checker/checker_test.go | 61 ++++++++++++++++++++++++++++++-- 1 file changed, 59 insertions(+), 2 deletions(-) diff --git a/internal/checker/checker_test.go b/internal/checker/checker_test.go index fa7d9e751..d06900d85 100644 --- a/internal/checker/checker_test.go +++ b/internal/checker/checker_test.go @@ -8,7 +8,9 @@ import ( "os" "path/filepath" "sort" + "strconv" "testing" + "time" "github.com/restic/restic/internal/archiver" "github.com/restic/restic/internal/checker" @@ -363,21 +365,66 @@ func TestCheckerModifiedData(t *testing.T) { } } -func BenchmarkChecker(t *testing.B) { +func loadBenchRepository(t *testing.B) (*checker.Checker, restic.Repository, func()) { repodir, cleanup := test.Env(t, checkerTestData) - defer cleanup() repo := repository.TestOpenLocal(t, repodir) chkr := checker.New(repo) hints, errs := chkr.LoadIndex(context.TODO()) if len(errs) > 0 { + defer cleanup() t.Fatalf("expected no errors, got %v: %v", len(errs), errs) } if len(hints) > 0 { t.Errorf("expected no hints, got %v: %v", len(hints), hints) } + return chkr, repo, cleanup +} + +func BenchmarkChecker(t *testing.B) { + chkr, _, cleanup := loadBenchRepository(t) + defer cleanup() + + t.ResetTimer() + + for i := 0; i < t.N; i++ { + test.OKs(t, checkPacks(chkr)) + test.OKs(t, checkStruct(chkr)) + test.OKs(t, checkData(chkr)) + } +} + +func benchmarkSnapshotScaling(t *testing.B, newSnapshots int) { + chkr, repo, cleanup := loadBenchRepository(t) + defer cleanup() + + snID, err := restic.FindSnapshot(repo, "51d249d2") + if err != nil { + t.Fatal(err) + } + + var sn2 restic.Snapshot + err = repo.LoadJSONUnpacked(context.TODO(), restic.SnapshotFile, snID, &sn2) + if err != nil { + t.Fatal(err) + } + + treeID := sn2.Tree + + for i := 0; i < newSnapshots; i++ { + sn, err := restic.NewSnapshot([]string{"test" + strconv.Itoa(i)}, nil, "", time.Now()) + if err != nil { + t.Fatal(err) + } + sn.Tree = treeID + + _, err = repo.SaveJSONUnpacked(context.TODO(), restic.SnapshotFile, sn) + if err != nil { + t.Fatal(err) + } + } t.ResetTimer() @@ -387,3 +434,13 @@ func BenchmarkChecker(t *testing.B) { test.OKs(t, checkData(chkr)) } } + +func BenchmarkCheckerSnapshotScaling(b *testing.B) { + counts := []int{50, 100, 200} + for _, count := range counts { + count := count + b.Run(strconv.Itoa(count), func(b *testing.B) { + benchmarkSnapshotScaling(b, count) + }) + } +} From 70f4c014ef44659e2e0727fa7a993663249d5a0d Mon Sep 17 00:00:00 2001 From: Michael Eischer Date: Sat, 6 Jul 2019 18:35:03 +0200 Subject: [PATCH 02/11] checker: Decode identical tree nodes only once Even though the checkTreeWorker skips already processed chunks, filterTrees did queue the same tree blob on every occurence. This becomes a serious performance bottleneck for larger number of snapshots that cover mostly the same directories. Therefore decode a tree blob exactly once. --- internal/checker/checker.go | 30 ++++++++++++------------------ 1 file changed, 12 insertions(+), 18 deletions(-) diff --git a/internal/checker/checker.go b/internal/checker/checker.go index 2e2e233d6..01406990e 100644 --- a/internal/checker/checker.go +++ b/internal/checker/checker.go @@ -25,7 +25,7 @@ type Checker struct { blobs restic.IDSet blobRefs struct { sync.Mutex - M map[restic.ID]uint + M map[restic.ID]bool } indexes map[restic.ID]*repository.Index @@ -44,7 +44,7 @@ func New(repo restic.Repository) *Checker { repo: repo, } - c.blobRefs.M = make(map[restic.ID]uint) + c.blobRefs.M = make(map[restic.ID]bool) return c } @@ -160,7 +160,6 @@ func (c *Checker) LoadIndex(ctx context.Context) (hints []error, errs []error) { for blob := range res.Index.Each(ctx) { c.packs.Insert(blob.PackID) c.blobs.Insert(blob.ID) - c.blobRefs.M[blob.ID] = 0 cnt++ if _, ok := packToIndex[blob.PackID]; !ok { @@ -445,20 +444,10 @@ func (c *Checker) checkTreeWorker(ctx context.Context, in <-chan treeJob, out ch return } - id := job.ID - alreadyChecked := false c.blobRefs.Lock() - if c.blobRefs.M[id] > 0 { - alreadyChecked = true - } - c.blobRefs.M[id]++ - debug.Log("tree %v refcount %d", job.ID, c.blobRefs.M[id]) + c.blobRefs.M[job.ID] = true c.blobRefs.Unlock() - if alreadyChecked { - continue - } - debug.Log("check tree %v (tree %v, err %v)", job.ID, job.Tree, job.error) var errs []error @@ -497,6 +486,7 @@ func filterTrees(ctx context.Context, backlog restic.IDs, loaderChan chan<- rest job treeJob nextTreeID restic.ID outstandingLoadTreeJobs = 0 + processedTrees = restic.NewIDSet() ) outCh = nil @@ -504,8 +494,11 @@ func filterTrees(ctx context.Context, backlog restic.IDs, loaderChan chan<- rest for { if loadCh == nil && len(backlog) > 0 { - loadCh = loaderChan nextTreeID, backlog = backlog[0], backlog[1:] + if processedTrees.Has(nextTreeID) { + continue + } + loadCh = loaderChan } if loadCh == nil && outCh == nil && outstandingLoadTreeJobs == 0 { @@ -520,6 +513,7 @@ func filterTrees(ctx context.Context, backlog restic.IDs, loaderChan chan<- rest case loadCh <- nextTreeID: outstandingLoadTreeJobs++ loadCh = nil + processedTrees.Insert(nextTreeID) case j, ok := <-inCh: if !ok { @@ -654,8 +648,8 @@ func (c *Checker) checkTree(id restic.ID, tree *restic.Tree) (errs []error) { for _, blobID := range blobs { c.blobRefs.Lock() - c.blobRefs.M[blobID]++ - debug.Log("blob %v refcount %d", blobID, c.blobRefs.M[blobID]) + c.blobRefs.M[blobID] = true + debug.Log("blob %v is referenced", blobID) c.blobRefs.Unlock() if !c.blobs.Has(blobID) { @@ -675,7 +669,7 @@ func (c *Checker) UnusedBlobs() (blobs restic.IDs) { debug.Log("checking %d blobs", len(c.blobs)) for id := range c.blobs { - if c.blobRefs.M[id] == 0 { + if !c.blobRefs.M[id] { debug.Log("blob %v not referenced", id) blobs = append(blobs, id) } From c66a0e408c2a50787073ce6eeb8067e8e43cb977 Mon Sep 17 00:00:00 2001 From: Michael Eischer Date: Sat, 6 Jul 2019 18:12:48 +0200 Subject: [PATCH 03/11] checker: Reduce cost of debug log Avoid duplicate allocation of the Subtree list. --- internal/checker/checker.go | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/internal/checker/checker.go b/internal/checker/checker.go index 01406990e..7d1a3a238 100644 --- a/internal/checker/checker.go +++ b/internal/checker/checker.go @@ -535,8 +535,9 @@ func filterTrees(ctx context.Context, backlog restic.IDs, loaderChan chan<- rest debug.Log("received job with nil tree pointer: %v (ID %v)", j.error, j.ID) err = errors.New("tree is nil and error is nil") } else { - debug.Log("subtrees for tree %v: %v", j.ID, j.Tree.Subtrees()) - for _, id := range j.Tree.Subtrees() { + subtrees := j.Tree.Subtrees() + debug.Log("subtrees for tree %v: %v", j.ID, subtrees) + for _, id := range subtrees { if id.IsNull() { // We do not need to raise this error here, it is // checked when the tree is checked. Just make sure From 35d84136395b154a69b9523ee0656a5b0da68f2b Mon Sep 17 00:00:00 2001 From: Michael Eischer Date: Sat, 13 Jul 2019 18:04:08 +0200 Subject: [PATCH 04/11] checker: Remove dead index map --- internal/checker/checker.go | 3 --- 1 file changed, 3 deletions(-) diff --git a/internal/checker/checker.go b/internal/checker/checker.go index 7d1a3a238..642dd963e 100644 --- a/internal/checker/checker.go +++ b/internal/checker/checker.go @@ -27,7 +27,6 @@ type Checker struct { sync.Mutex M map[restic.ID]bool } - indexes map[restic.ID]*repository.Index masterIndex *repository.MasterIndex @@ -40,7 +39,6 @@ func New(repo restic.Repository) *Checker { packs: restic.NewIDSet(), blobs: restic.NewIDSet(), masterIndex: repository.NewMasterIndex(), - indexes: make(map[restic.ID]*repository.Index), repo: repo, } @@ -152,7 +150,6 @@ func (c *Checker) LoadIndex(ctx context.Context) (hints []error, errs []error) { continue } - c.indexes[res.ID] = res.Index c.masterIndex.Insert(res.Index) debug.Log("process blobs") From 36c69e3ca7c01231b5d9b06a20e3f7c6726f30fb Mon Sep 17 00:00:00 2001 From: Michael Eischer Date: Sat, 13 Jul 2019 18:34:55 +0200 Subject: [PATCH 05/11] checker: Unify blobs, processed trees and referenced blobs map The blobRefs map and the processedTrees IDSet are merged to reduce the memory usage. The blobRefs map now uses separate flags to track blob usage as data or tree blob. This prevents skipping of trees whose content is identical to an already processed data blob. A third flag tracks whether a blob exists or not, which removes the need for the blobs IDSet. --- internal/checker/checker.go | 55 +++++++++++++++++++++---------------- 1 file changed, 32 insertions(+), 23 deletions(-) diff --git a/internal/checker/checker.go b/internal/checker/checker.go index 642dd963e..c8e6f3f8a 100644 --- a/internal/checker/checker.go +++ b/internal/checker/checker.go @@ -22,10 +22,10 @@ import ( // repository (e.g. missing blobs), and needs a valid Repository to work on. type Checker struct { packs restic.IDSet - blobs restic.IDSet blobRefs struct { sync.Mutex - M map[restic.ID]bool + // see flags below + M map[restic.ID]blobStatus } masterIndex *repository.MasterIndex @@ -33,16 +33,23 @@ type Checker struct { repo restic.Repository } +type blobStatus uint8 + +const ( + blobExists blobStatus = 1 << iota + blobReferenced + treeProcessed +) + // New returns a new checker which runs on repo. func New(repo restic.Repository) *Checker { c := &Checker{ packs: restic.NewIDSet(), - blobs: restic.NewIDSet(), masterIndex: repository.NewMasterIndex(), repo: repo, } - c.blobRefs.M = make(map[restic.ID]bool) + c.blobRefs.M = make(map[restic.ID]blobStatus) return c } @@ -156,7 +163,7 @@ func (c *Checker) LoadIndex(ctx context.Context) (hints []error, errs []error) { cnt := 0 for blob := range res.Index.Each(ctx) { c.packs.Insert(blob.PackID) - c.blobs.Insert(blob.ID) + c.blobRefs.M[blob.ID] = blobExists cnt++ if _, ok := packToIndex[blob.PackID]; !ok { @@ -441,10 +448,6 @@ func (c *Checker) checkTreeWorker(ctx context.Context, in <-chan treeJob, out ch return } - c.blobRefs.Lock() - c.blobRefs.M[job.ID] = true - c.blobRefs.Unlock() - debug.Log("check tree %v (tree %v, err %v)", job.ID, job.Tree, job.error) var errs []error @@ -469,7 +472,7 @@ func (c *Checker) checkTreeWorker(ctx context.Context, in <-chan treeJob, out ch } } -func filterTrees(ctx context.Context, backlog restic.IDs, loaderChan chan<- restic.ID, in <-chan treeJob, out chan<- treeJob) { +func (c *Checker) filterTrees(ctx context.Context, backlog restic.IDs, loaderChan chan<- restic.ID, in <-chan treeJob, out chan<- treeJob) { defer func() { debug.Log("closing output channels") close(loaderChan) @@ -483,7 +486,6 @@ func filterTrees(ctx context.Context, backlog restic.IDs, loaderChan chan<- rest job treeJob nextTreeID restic.ID outstandingLoadTreeJobs = 0 - processedTrees = restic.NewIDSet() ) outCh = nil @@ -492,9 +494,16 @@ func filterTrees(ctx context.Context, backlog restic.IDs, loaderChan chan<- rest for { if loadCh == nil && len(backlog) > 0 { nextTreeID, backlog = backlog[0], backlog[1:] - if processedTrees.Has(nextTreeID) { + + // use a separate flag for processed trees to ensure that check still processes trees + // even when a file references a tree blob + c.blobRefs.Lock() + blobFlags := c.blobRefs.M[nextTreeID] + c.blobRefs.Unlock() + if (blobFlags & treeProcessed) != 0 { continue } + loadCh = loaderChan } @@ -510,7 +519,9 @@ func filterTrees(ctx context.Context, backlog restic.IDs, loaderChan chan<- rest case loadCh <- nextTreeID: outstandingLoadTreeJobs++ loadCh = nil - processedTrees.Insert(nextTreeID) + c.blobRefs.Lock() + c.blobRefs.M[nextTreeID] |= treeProcessed | blobReferenced + c.blobRefs.Unlock() case j, ok := <-inCh: if !ok { @@ -591,7 +602,7 @@ func (c *Checker) Structure(ctx context.Context, errChan chan<- error) { go c.checkTreeWorker(ctx, treeJobChan2, errChan, &wg) } - filterTrees(ctx, trees, treeIDChan, treeJobChan1, treeJobChan2) + c.filterTrees(ctx, trees, treeIDChan, treeJobChan1, treeJobChan2) wg.Wait() } @@ -646,15 +657,13 @@ func (c *Checker) checkTree(id restic.ID, tree *restic.Tree) (errs []error) { for _, blobID := range blobs { c.blobRefs.Lock() - c.blobRefs.M[blobID] = true - debug.Log("blob %v is referenced", blobID) - c.blobRefs.Unlock() - - if !c.blobs.Has(blobID) { + if (c.blobRefs.M[blobID] & blobExists) == 0 { debug.Log("tree %v references blob %v which isn't contained in index", id, blobID) - errs = append(errs, Error{TreeID: id, BlobID: blobID, Err: errors.New("not found in index")}) } + c.blobRefs.M[blobID] |= blobReferenced + debug.Log("blob %v is referenced", blobID) + c.blobRefs.Unlock() } return errs @@ -665,9 +674,9 @@ func (c *Checker) UnusedBlobs() (blobs restic.IDs) { c.blobRefs.Lock() defer c.blobRefs.Unlock() - debug.Log("checking %d blobs", len(c.blobs)) - for id := range c.blobs { - if !c.blobRefs.M[id] { + debug.Log("checking %d blobs", len(c.blobRefs.M)) + for id, flags := range c.blobRefs.M { + if (flags & blobReferenced) == 0 { debug.Log("blob %v not referenced", id) blobs = append(blobs, id) } From 7a165f32a92e39228628467f3296150be7301488 Mon Sep 17 00:00:00 2001 From: Michael Eischer Date: Sat, 6 Jul 2019 20:01:48 +0200 Subject: [PATCH 06/11] checker: Traverse trees in depth-first order Backups traverse the file tree in depth-first order and saves trees on the way back up. This results in tree packs filled in a way comparable to the reverse Polish notation. In order to check tree blobs in that order, the treeFilter would have to delay the forwarding of tree nodes until all children of it are processed which would complicate the implementation. Therefore do the next similar thing and traverse the tree in depth-first order, but process trees already on the way down. The tree blob ids are added in reverse order to the backlog, which is once again reverted when removing the ids from the back of the backlog. --- internal/checker/checker.go | 8 ++++++-- 1 file changed, 6 insertions(+), 2 deletions(-) diff --git a/internal/checker/checker.go b/internal/checker/checker.go index c8e6f3f8a..577e6e8e4 100644 --- a/internal/checker/checker.go +++ b/internal/checker/checker.go @@ -493,7 +493,9 @@ func (c *Checker) filterTrees(ctx context.Context, backlog restic.IDs, loaderCha for { if loadCh == nil && len(backlog) > 0 { - nextTreeID, backlog = backlog[0], backlog[1:] + // process last added ids first, that is traverse the tree in depth-first order + ln := len(backlog) - 1 + nextTreeID, backlog = backlog[ln], backlog[:ln] // use a separate flag for processed trees to ensure that check still processes trees // even when a file references a tree blob @@ -545,7 +547,9 @@ func (c *Checker) filterTrees(ctx context.Context, backlog restic.IDs, loaderCha } else { subtrees := j.Tree.Subtrees() debug.Log("subtrees for tree %v: %v", j.ID, subtrees) - for _, id := range subtrees { + // iterate backwards over subtree to compensate backwards traversal order of nextTreeID selection + for i := len(subtrees) - 1; i >= 0; i-- { + id := subtrees[i] if id.IsNull() { // We do not need to raise this error here, it is // checked when the tree is checked. Just make sure From 0f67ae813ade9f664f24c8c055551b56a9873f99 Mon Sep 17 00:00:00 2001 From: Michael Eischer Date: Sat, 7 Mar 2020 11:25:55 +0100 Subject: [PATCH 07/11] Add changelog --- changelog/unreleased/pull-2328 | 8 ++++++++ 1 file changed, 8 insertions(+) create mode 100644 changelog/unreleased/pull-2328 diff --git a/changelog/unreleased/pull-2328 b/changelog/unreleased/pull-2328 new file mode 100644 index 000000000..79a9d2b11 --- /dev/null +++ b/changelog/unreleased/pull-2328 @@ -0,0 +1,8 @@ +Enhancement: Improve speed of check command + +We've improved the check command to traverse trees only once independent of +whether they are contained in multiple snapshots. The check command is now much +faster for repositories with a large number of snapshots. + +https://github.com/restic/restic/pull/2328 +https://github.com/restic/restic/issues/2284 From ef325ffc02960983a0417a18f318419a7c4ed3c3 Mon Sep 17 00:00:00 2001 From: Michael Eischer Date: Sat, 7 Mar 2020 14:10:34 +0100 Subject: [PATCH 08/11] checker: Cleanup error handling code This change only moves code around but does not result in any change in behavior. --- internal/checker/checker.go | 10 ++-------- 1 file changed, 2 insertions(+), 8 deletions(-) diff --git a/internal/checker/checker.go b/internal/checker/checker.go index 577e6e8e4..987eff8ca 100644 --- a/internal/checker/checker.go +++ b/internal/checker/checker.go @@ -537,13 +537,12 @@ func (c *Checker) filterTrees(ctx context.Context, backlog restic.IDs, loaderCha debug.Log("input job tree %v", j.ID) - var err error - if j.error != nil { debug.Log("received job with error: %v (tree %v, ID %v)", j.error, j.Tree, j.ID) } else if j.Tree == nil { debug.Log("received job with nil tree pointer: %v (ID %v)", j.error, j.ID) - err = errors.New("tree is nil and error is nil") + // send a new job with the new error instead of the old one + j = treeJob{ID: j.ID, error: errors.New("tree is nil and error is nil")} } else { subtrees := j.Tree.Subtrees() debug.Log("subtrees for tree %v: %v", j.ID, subtrees) @@ -561,11 +560,6 @@ func (c *Checker) filterTrees(ctx context.Context, backlog restic.IDs, loaderCha } } - if err != nil { - // send a new job with the new error instead of the old one - j = treeJob{ID: j.ID, error: err} - } - job = j outCh = out inCh = nil From 2d0c138c9bc54c6daa425d12280a052a2a9f94b6 Mon Sep 17 00:00:00 2001 From: Michael Eischer Date: Sat, 7 Mar 2020 14:12:02 +0100 Subject: [PATCH 09/11] checker: Test that check only decodes trees once The `DuplicateTree` flag is necessary to ensure that failures cannot be swallowed. The old checker implementation ignores errors from LoadTree if the corresponding tree was already checked. --- internal/checker/checker_test.go | 48 ++++++++++++++++++++++++++++++++ 1 file changed, 48 insertions(+) diff --git a/internal/checker/checker_test.go b/internal/checker/checker_test.go index d06900d85..e19982a25 100644 --- a/internal/checker/checker_test.go +++ b/internal/checker/checker_test.go @@ -9,11 +9,13 @@ import ( "path/filepath" "sort" "strconv" + "sync" "testing" "time" "github.com/restic/restic/internal/archiver" "github.com/restic/restic/internal/checker" + "github.com/restic/restic/internal/errors" "github.com/restic/restic/internal/repository" "github.com/restic/restic/internal/restic" "github.com/restic/restic/internal/test" @@ -365,6 +367,52 @@ func TestCheckerModifiedData(t *testing.T) { } } +// loadTreesOnceRepository allows each tree to be loaded only once +type loadTreesOnceRepository struct { + restic.Repository + loadedTrees restic.IDSet + mutex sync.Mutex + DuplicateTree bool +} + +func (r *loadTreesOnceRepository) LoadTree(ctx context.Context, id restic.ID) (*restic.Tree, error) { + r.mutex.Lock() + defer r.mutex.Unlock() + + if r.loadedTrees.Has(id) { + // additionally store error to ensure that it cannot be swallowed + r.DuplicateTree = true + return nil, errors.Errorf("trying to load tree with id %v twice", id) + } + r.loadedTrees.Insert(id) + return r.Repository.LoadTree(ctx, id) +} + +func TestCheckerNoDuplicateTreeDecodes(t *testing.T) { + repodir, cleanup := test.Env(t, checkerTestData) + defer cleanup() + + repo := repository.TestOpenLocal(t, repodir) + checkRepo := &loadTreesOnceRepository{ + Repository: repo, + loadedTrees: restic.NewIDSet(), + } + + chkr := checker.New(checkRepo) + hints, errs := chkr.LoadIndex(context.TODO()) + if len(errs) > 0 { + t.Fatalf("expected no errors, got %v: %v", len(errs), errs) + } + + if len(hints) > 0 { + t.Errorf("expected no hints, got %v: %v", len(hints), hints) + } + + test.OKs(t, checkPacks(chkr)) + test.OKs(t, checkStruct(chkr)) + test.Assert(t, !checkRepo.DuplicateTree, "detected duplicate tree loading") +} + func loadBenchRepository(t *testing.B) (*checker.Checker, restic.Repository, func()) { repodir, cleanup := test.Env(t, checkerTestData) From ddf0b8cd0b10577ec25e63bd83a0bbc5356d07f1 Mon Sep 17 00:00:00 2001 From: Michael Eischer Date: Sat, 18 Apr 2020 19:46:33 +0200 Subject: [PATCH 10/11] checker: Properly distinguish between data and tree blobs If a data blob and a tree blob with the same ID (= same content) exist, then the checker did not report a data or tree blob as unused when the blob of the other type was still in use. --- cmd/restic/cmd_check.go | 2 +- internal/checker/checker.go | 29 ++++++++++++++++------------- internal/checker/checker_test.go | 14 +++++++------- internal/restic/testing.go | 5 +++++ 4 files changed, 29 insertions(+), 21 deletions(-) diff --git a/cmd/restic/cmd_check.go b/cmd/restic/cmd_check.go index 35729af6d..fdd76dd3e 100644 --- a/cmd/restic/cmd_check.go +++ b/cmd/restic/cmd_check.go @@ -259,7 +259,7 @@ func runCheck(opts CheckOptions, gopts GlobalOptions, args []string) error { if opts.CheckUnused { for _, id := range chkr.UnusedBlobs() { - Verbosef("unused blob %v\n", id.Str()) + Verbosef("unused blob %v\n", id) errorsFound = true } } diff --git a/internal/checker/checker.go b/internal/checker/checker.go index 987eff8ca..95a9f6de8 100644 --- a/internal/checker/checker.go +++ b/internal/checker/checker.go @@ -25,7 +25,7 @@ type Checker struct { blobRefs struct { sync.Mutex // see flags below - M map[restic.ID]blobStatus + M map[restic.BlobHandle]blobStatus } masterIndex *repository.MasterIndex @@ -36,9 +36,8 @@ type Checker struct { type blobStatus uint8 const ( - blobExists blobStatus = 1 << iota - blobReferenced - treeProcessed + blobStatusExists blobStatus = 1 << iota + blobStatusReferenced ) // New returns a new checker which runs on repo. @@ -49,7 +48,7 @@ func New(repo restic.Repository) *Checker { repo: repo, } - c.blobRefs.M = make(map[restic.ID]blobStatus) + c.blobRefs.M = make(map[restic.BlobHandle]blobStatus) return c } @@ -163,7 +162,8 @@ func (c *Checker) LoadIndex(ctx context.Context) (hints []error, errs []error) { cnt := 0 for blob := range res.Index.Each(ctx) { c.packs.Insert(blob.PackID) - c.blobRefs.M[blob.ID] = blobExists + h := restic.BlobHandle{ID: blob.ID, Type: blob.Type} + c.blobRefs.M[h] = blobStatusExists cnt++ if _, ok := packToIndex[blob.PackID]; !ok { @@ -500,9 +500,10 @@ func (c *Checker) filterTrees(ctx context.Context, backlog restic.IDs, loaderCha // use a separate flag for processed trees to ensure that check still processes trees // even when a file references a tree blob c.blobRefs.Lock() - blobFlags := c.blobRefs.M[nextTreeID] + h := restic.BlobHandle{ID: nextTreeID, Type: restic.TreeBlob} + status := c.blobRefs.M[h] c.blobRefs.Unlock() - if (blobFlags & treeProcessed) != 0 { + if (status & blobStatusReferenced) != 0 { continue } @@ -522,7 +523,8 @@ func (c *Checker) filterTrees(ctx context.Context, backlog restic.IDs, loaderCha outstandingLoadTreeJobs++ loadCh = nil c.blobRefs.Lock() - c.blobRefs.M[nextTreeID] |= treeProcessed | blobReferenced + h := restic.BlobHandle{ID: nextTreeID, Type: restic.TreeBlob} + c.blobRefs.M[h] |= blobStatusReferenced c.blobRefs.Unlock() case j, ok := <-inCh: @@ -655,11 +657,12 @@ func (c *Checker) checkTree(id restic.ID, tree *restic.Tree) (errs []error) { for _, blobID := range blobs { c.blobRefs.Lock() - if (c.blobRefs.M[blobID] & blobExists) == 0 { + h := restic.BlobHandle{ID: blobID, Type: restic.DataBlob} + if (c.blobRefs.M[h] & blobStatusExists) == 0 { debug.Log("tree %v references blob %v which isn't contained in index", id, blobID) errs = append(errs, Error{TreeID: id, BlobID: blobID, Err: errors.New("not found in index")}) } - c.blobRefs.M[blobID] |= blobReferenced + c.blobRefs.M[h] |= blobStatusReferenced debug.Log("blob %v is referenced", blobID) c.blobRefs.Unlock() } @@ -668,13 +671,13 @@ func (c *Checker) checkTree(id restic.ID, tree *restic.Tree) (errs []error) { } // UnusedBlobs returns all blobs that have never been referenced. -func (c *Checker) UnusedBlobs() (blobs restic.IDs) { +func (c *Checker) UnusedBlobs() (blobs restic.BlobHandles) { c.blobRefs.Lock() defer c.blobRefs.Unlock() debug.Log("checking %d blobs", len(c.blobRefs.M)) for id, flags := range c.blobRefs.M { - if (flags & blobReferenced) == 0 { + if (flags & blobStatusReferenced) == 0 { debug.Log("blob %v not referenced", id) blobs = append(blobs, id) } diff --git a/internal/checker/checker_test.go b/internal/checker/checker_test.go index e19982a25..b571361ec 100644 --- a/internal/checker/checker_test.go +++ b/internal/checker/checker_test.go @@ -157,13 +157,13 @@ func TestUnreferencedBlobs(t *testing.T) { } test.OK(t, repo.Backend().Remove(context.TODO(), snapshotHandle)) - unusedBlobsBySnapshot := restic.IDs{ - restic.TestParseID("58c748bbe2929fdf30c73262bd8313fe828f8925b05d1d4a87fe109082acb849"), - restic.TestParseID("988a272ab9768182abfd1fe7d7a7b68967825f0b861d3b36156795832c772235"), - restic.TestParseID("c01952de4d91da1b1b80bc6e06eaa4ec21523f4853b69dc8231708b9b7ec62d8"), - restic.TestParseID("bec3a53d7dc737f9a9bee68b107ec9e8ad722019f649b34d474b9982c3a3fec7"), - restic.TestParseID("2a6f01e5e92d8343c4c6b78b51c5a4dc9c39d42c04e26088c7614b13d8d0559d"), - restic.TestParseID("18b51b327df9391732ba7aaf841a4885f350d8a557b2da8352c9acf8898e3f10"), + unusedBlobsBySnapshot := restic.BlobHandles{ + restic.TestParseHandle("58c748bbe2929fdf30c73262bd8313fe828f8925b05d1d4a87fe109082acb849", restic.DataBlob), + restic.TestParseHandle("988a272ab9768182abfd1fe7d7a7b68967825f0b861d3b36156795832c772235", restic.DataBlob), + restic.TestParseHandle("c01952de4d91da1b1b80bc6e06eaa4ec21523f4853b69dc8231708b9b7ec62d8", restic.TreeBlob), + restic.TestParseHandle("bec3a53d7dc737f9a9bee68b107ec9e8ad722019f649b34d474b9982c3a3fec7", restic.TreeBlob), + restic.TestParseHandle("2a6f01e5e92d8343c4c6b78b51c5a4dc9c39d42c04e26088c7614b13d8d0559d", restic.TreeBlob), + restic.TestParseHandle("18b51b327df9391732ba7aaf841a4885f350d8a557b2da8352c9acf8898e3f10", restic.DataBlob), } sort.Sort(unusedBlobsBySnapshot) diff --git a/internal/restic/testing.go b/internal/restic/testing.go index b3a42fd45..bcb3db155 100644 --- a/internal/restic/testing.go +++ b/internal/restic/testing.go @@ -200,3 +200,8 @@ func TestParseID(s string) ID { return id } + +// TestParseHandle parses s as a ID, panics if that fails and creates a BlobHandle with t. +func TestParseHandle(s string, t BlobType) BlobHandle { + return BlobHandle{ID: TestParseID(s), Type: t} +} From 9b0e718852aa13ce3681a039cfd7817bd0f08e24 Mon Sep 17 00:00:00 2001 From: Michael Eischer Date: Sat, 18 Apr 2020 21:34:59 +0200 Subject: [PATCH 11/11] checker: Test that blob types are not confused --- internal/checker/checker_test.go | 126 +++++++++++++++++++++++++++++++ 1 file changed, 126 insertions(+) diff --git a/internal/checker/checker_test.go b/internal/checker/checker_test.go index b571361ec..37133266e 100644 --- a/internal/checker/checker_test.go +++ b/internal/checker/checker_test.go @@ -413,6 +413,132 @@ func TestCheckerNoDuplicateTreeDecodes(t *testing.T) { test.Assert(t, !checkRepo.DuplicateTree, "detected duplicate tree loading") } +// delayRepository delays read of a specific handle. +type delayRepository struct { + restic.Repository + DelayTree restic.ID + UnblockChannel chan struct{} + Unblocker sync.Once +} + +func (r *delayRepository) LoadTree(ctx context.Context, id restic.ID) (*restic.Tree, error) { + if id == r.DelayTree { + <-r.UnblockChannel + } + return r.Repository.LoadTree(ctx, id) +} + +func (r *delayRepository) LookupBlobSize(id restic.ID, t restic.BlobType) (uint, bool) { + if id == r.DelayTree && t == restic.DataBlob { + r.Unblock() + } + return r.Repository.LookupBlobSize(id, t) +} + +func (r *delayRepository) Unblock() { + r.Unblocker.Do(func() { + close(r.UnblockChannel) + }) +} + +func TestCheckerBlobTypeConfusion(t *testing.T) { + ctx, cancel := context.WithTimeout(context.Background(), time.Second) + defer cancel() + + repo, cleanup := repository.TestRepository(t) + defer cleanup() + + damagedNode := &restic.Node{ + Name: "damaged", + Type: "file", + Mode: 0644, + Size: 42, + Content: restic.IDs{restic.TestParseID("0123456789abcdef0123456789abcdef0123456789abcdef0123456789abcdef")}, + } + damagedTree := &restic.Tree{ + Nodes: []*restic.Node{damagedNode}, + } + + id, err := repo.SaveTree(ctx, damagedTree) + test.OK(t, repo.Flush(ctx)) + test.OK(t, err) + + buf, err := repo.LoadBlob(ctx, restic.TreeBlob, id, nil) + test.OK(t, err) + + _, _, err = repo.SaveBlob(ctx, restic.DataBlob, buf, id, false) + test.OK(t, err) + + malNode := &restic.Node{ + Name: "aaaaa", + Type: "file", + Mode: 0644, + Size: uint64(len(buf)), + Content: restic.IDs{id}, + } + dirNode := &restic.Node{ + Name: "bbbbb", + Type: "dir", + Mode: 0755, + Subtree: &id, + } + + rootTree := &restic.Tree{ + Nodes: []*restic.Node{malNode, dirNode}, + } + + rootId, err := repo.SaveTree(ctx, rootTree) + test.OK(t, err) + + test.OK(t, repo.Flush(ctx)) + test.OK(t, repo.SaveIndex(ctx)) + + snapshot, err := restic.NewSnapshot([]string{"/damaged"}, []string{"test"}, "foo", time.Now()) + test.OK(t, err) + + snapshot.Tree = &rootId + + snapId, err := repo.SaveJSONUnpacked(ctx, restic.SnapshotFile, snapshot) + test.OK(t, err) + + t.Logf("saved snapshot %v", snapId.Str()) + + delayRepo := &delayRepository{ + Repository: repo, + DelayTree: id, + UnblockChannel: make(chan struct{}), + } + + chkr := checker.New(delayRepo) + + go func() { + <-ctx.Done() + delayRepo.Unblock() + }() + + hints, errs := chkr.LoadIndex(ctx) + if len(errs) > 0 { + t.Fatalf("expected no errors, got %v: %v", len(errs), errs) + } + + if len(hints) > 0 { + t.Errorf("expected no hints, got %v: %v", len(hints), hints) + } + + errFound := false + + for _, err := range checkStruct(chkr) { + t.Logf("struct error: %v", err) + errFound = true + } + + test.OK(t, ctx.Err()) + + if !errFound { + t.Fatal("no error found, checker is broken") + } +} + func loadBenchRepository(t *testing.B) (*checker.Checker, restic.Repository, func()) { repodir, cleanup := test.Env(t, checkerTestData)