From 0ba5538b7faba51474c7fd4c5512f795e05a787c Mon Sep 17 00:00:00 2001 From: Luke Shumaker Date: Sun, 11 Dec 2022 22:29:05 -0700 Subject: rebuildnodes: Improve logging --- .../btrfsinspect/rebuildnodes/orphans.go | 43 ++++++++++++++++++++-- .../btrfsinspect/rebuildnodes/rebuild.go | 14 ++++++- lib/containers/set.go | 13 +++++++ 3 files changed, 66 insertions(+), 4 deletions(-) diff --git a/lib/btrfsprogs/btrfsinspect/rebuildnodes/orphans.go b/lib/btrfsprogs/btrfsinspect/rebuildnodes/orphans.go index 70bd128..55cf95b 100644 --- a/lib/btrfsprogs/btrfsinspect/rebuildnodes/orphans.go +++ b/lib/btrfsprogs/btrfsinspect/rebuildnodes/orphans.go @@ -5,12 +5,17 @@ package rebuildnodes import ( + "context" + + "github.com/datawire/dlib/dlog" + "git.lukeshu.com/btrfs-progs-ng/lib/btrfs/btrfsprim" "git.lukeshu.com/btrfs-progs-ng/lib/btrfs/btrfstree" "git.lukeshu.com/btrfs-progs-ng/lib/btrfs/btrfsvol" "git.lukeshu.com/btrfs-progs-ng/lib/btrfsprogs/btrfsinspect/rebuildnodes/graph" "git.lukeshu.com/btrfs-progs-ng/lib/containers" "git.lukeshu.com/btrfs-progs-ng/lib/diskio" + "git.lukeshu.com/btrfs-progs-ng/lib/maps" ) func listRoots(graph graph.Graph, leaf btrfsvol.LogicalAddr) containers.Set[btrfsvol.LogicalAddr] { @@ -49,12 +54,13 @@ func (a keyAndTree) Cmp(b keyAndTree) int { return containers.NativeCmp(a.TreeID, b.TreeID) } -func indexOrphans(fs diskio.File[btrfsvol.LogicalAddr], sb btrfstree.Superblock, graph graph.Graph) ( +func indexOrphans(ctx context.Context, fs diskio.File[btrfsvol.LogicalAddr], sb btrfstree.Superblock, graph graph.Graph) ( orphans containers.Set[btrfsvol.LogicalAddr], leaf2orphans map[btrfsvol.LogicalAddr]containers.Set[btrfsvol.LogicalAddr], key2leaf *containers.SortedMap[keyAndTree, btrfsvol.LogicalAddr], err error, ) { + dlog.Info(ctx, "... counting orphans") orphans = make(containers.Set[btrfsvol.LogicalAddr]) for node := range graph.Nodes { if len(graph.EdgesTo[node]) == 0 { @@ -64,7 +70,22 @@ func indexOrphans(fs diskio.File[btrfsvol.LogicalAddr], sb btrfstree.Superblock, leaf2orphans = make(map[btrfsvol.LogicalAddr]containers.Set[btrfsvol.LogicalAddr]) visited := make(containers.Set[btrfsvol.LogicalAddr]) - for orphan := range orphans { + + lastPct, lastVisited, lastLeafs := -1, 0, 0 + total := len(orphans) + done := 0 + progress := func() { + pct := int(100 * float64(done) / float64(total)) + if pct != lastPct || (len(visited) != lastVisited && len(visited)%500 == 0) || len(leaf2orphans) != lastLeafs || done == total { + dlog.Infof(ctx, "... crawling orphans %v%% (%v/%v); visited %d nodes, found %d leaf nodes", + pct, done, total, len(visited), len(leaf2orphans)) + lastPct = pct + lastVisited = len(visited) + lastLeafs = len(leaf2orphans) + } + } + progress() + for _, orphan := range maps.SortedKeys(orphans) { walk(graph, orphan, func(node btrfsvol.LogicalAddr) bool { if visited.Has(node) { return false @@ -75,12 +96,26 @@ func indexOrphans(fs diskio.File[btrfsvol.LogicalAddr], sb btrfstree.Superblock, leaf2orphans[node] = roots } } + progress() return true }) + done++ + progress() } key2leaf = new(containers.SortedMap[keyAndTree, btrfsvol.LogicalAddr]) - for laddr := range leaf2orphans { + total = len(leaf2orphans) + done = 0 + progress = func() { + pct := int(100 * float64(done) / float64(total)) + if pct != lastPct || done == total { + dlog.Infof(ctx, "... reading leafs %v%% (%v/%v)", + pct, done, total) + lastPct = pct + } + } + progress() + for _, laddr := range maps.SortedKeys(leaf2orphans) { nodeRef, err := btrfstree.ReadNode[btrfsvol.LogicalAddr](fs, sb, laddr, btrfstree.NodeExpectations{ LAddr: containers.Optional[btrfsvol.LogicalAddr]{OK: true, Val: laddr}, Level: containers.Optional[uint8]{OK: true, Val: 0}, @@ -98,6 +133,8 @@ func indexOrphans(fs diskio.File[btrfsvol.LogicalAddr], sb btrfstree.Superblock, key2leaf.Store(k, laddr) } } + done++ + progress() } return orphans, leaf2orphans, key2leaf, nil } diff --git a/lib/btrfsprogs/btrfsinspect/rebuildnodes/rebuild.go b/lib/btrfsprogs/btrfsinspect/rebuildnodes/rebuild.go index be2834b..5dc4fa6 100644 --- a/lib/btrfsprogs/btrfsinspect/rebuildnodes/rebuild.go +++ b/lib/btrfsprogs/btrfsinspect/rebuildnodes/rebuild.go @@ -65,7 +65,7 @@ func RebuildNodes(ctx context.Context, fs *btrfs.FS, nodeScanResults btrfsinspec } dlog.Info(ctx, "Indexing orphans...") - orphans, leaf2orphans, key2leaf, err := indexOrphans(fs, *sb, *scanData.nodeGraph) + orphans, leaf2orphans, key2leaf, err := indexOrphans(ctx, fs, *sb, *scanData.nodeGraph) if err != nil { return nil, err } @@ -93,6 +93,8 @@ func RebuildNodes(ctx context.Context, fs *btrfs.FS, nodeScanResults btrfsinspec } func (o *Rebuilder) rebuild(ctx context.Context) error { + passNum := 0 + dlog.Infof(ctx, "... pass %d: scanning for implied items", passNum) o.pendingAugments = make(map[btrfsprim.ObjID][]map[btrfsvol.LogicalAddr]int) btrfsutil.WalkAllTrees(ctx, o.inner, btrfsutil.WalkAllTreesHandler{ Err: func(*btrfsutil.WalkError) {}, @@ -105,8 +107,10 @@ func (o *Rebuilder) rebuild(ctx context.Context) error { }) for len(o.pendingAugments) > 0 { // Apply the augments, keeping track of what keys are added to what tree. + dlog.Infof(ctx, "... pass %d: augmenting trees to add implied items", passNum) newKeys := make(map[btrfsprim.ObjID][]btrfsprim.Key) for _, treeID := range maps.SortedKeys(o.pendingAugments) { + dlog.Infof(ctx, "... ... augmenting tree %v:", treeID) treeAugments := o.resolveTreeAugments(ctx, o.pendingAugments[treeID]) for _, nodeAddr := range maps.SortedKeys(treeAugments) { added, err := o.inner.Augment(treeID, nodeAddr) @@ -126,7 +130,9 @@ func (o *Rebuilder) rebuild(ctx context.Context) error { } // Clear the list of pending augments. o.pendingAugments = make(map[btrfsprim.ObjID][]map[btrfsvol.LogicalAddr]int) + passNum++ // Call handleItem() for each of the added keys. + dlog.Infof(ctx, "... pass %d: scanning for implied items", passNum) for _, treeID := range maps.SortedKeys(newKeys) { for _, key := range newKeys[treeID] { item, err := o.inner.TreeLookup(treeID, key) @@ -247,6 +253,11 @@ func (o *Rebuilder) resolveTreeAugments(ctx context.Context, listsWithDistances accept(item) } } + + for i, list := range lists { + dlog.Infof(ctx, "... ... ... %d: %v: %v", i, list.Intersection(ret).TakeOne(), maps.SortedKeys(list)) + } + return ret } @@ -287,6 +298,7 @@ func (o *Rebuilder) wantAugment(ctx context.Context, treeID btrfsprim.ObjID, cho } } if len(choicesWithDist) > 0 { + dlog.Infof(ctx, "augment(tree=%v): %v", treeID, maps.SortedKeys(choicesWithDist)) o.pendingAugments[treeID] = append(o.pendingAugments[treeID], choicesWithDist) } } diff --git a/lib/containers/set.go b/lib/containers/set.go index d3f8ca7..67ba7ac 100644 --- a/lib/containers/set.go +++ b/lib/containers/set.go @@ -150,3 +150,16 @@ func (small Set[T]) HasAny(big Set[T]) bool { } return false } + +func (small Set[T]) Intersection(big Set[T]) Set[T] { + if len(big) < len(small) { + small, big = big, small + } + ret := make(Set[T]) + for v := range small { + if _, ok := big[v]; ok { + ret.Insert(v) + } + } + return ret +} -- cgit v1.2.3-2-g168b