restore: Add progress bar

Co-authored-by: Mark Herrmann <mark.herrmann@mailbox.org>
This commit is contained in:
Mark Herrmann 2022-10-28 17:44:34 +02:00 committed by Michael Eischer
parent 024d01d85b
commit f875a8843d
10 changed files with 399 additions and 21 deletions

View File

@ -0,0 +1,9 @@
Enhancement: Show progress bar during restore
The `restore` command now shows a progress report while restoring files.
Example: [0:42] 5.76% 23 files 12.98 MiB, total 3456 files 23.54 GiB
https://github.com/restic/restic/issues/3627
https://github.com/restic/restic/pull/3991
https://forum.restic.net/t/progress-bar-for-restore/5210

View File

@ -3,6 +3,7 @@ package main
import (
"context"
"strings"
"sync"
"time"
"github.com/restic/restic/internal/debug"
@ -10,6 +11,9 @@ import (
"github.com/restic/restic/internal/filter"
"github.com/restic/restic/internal/restic"
"github.com/restic/restic/internal/restorer"
"github.com/restic/restic/internal/ui"
restoreui "github.com/restic/restic/internal/ui/restore"
"github.com/restic/restic/internal/ui/termstatus"
"github.com/spf13/cobra"
)
@ -31,7 +35,31 @@ Exit status is 0 if the command was successful, and non-zero if there was any er
`,
DisableAutoGenTag: true,
RunE: func(cmd *cobra.Command, args []string) error {
return runRestore(cmd.Context(), restoreOptions, globalOptions, args)
ctx := cmd.Context()
var wg sync.WaitGroup
cancelCtx, cancel := context.WithCancel(ctx)
defer func() {
// shutdown termstatus
cancel()
wg.Wait()
}()
term := termstatus.New(globalOptions.stdout, globalOptions.stderr, globalOptions.Quiet)
wg.Add(1)
go func() {
defer wg.Done()
term.Run(cancelCtx)
}()
// allow usage of warnf / verbosef
prevStdout, prevStderr := globalOptions.stdout, globalOptions.stderr
defer func() {
globalOptions.stdout, globalOptions.stderr = prevStdout, prevStderr
}()
stdioWrapper := ui.NewStdioWrapper(term)
globalOptions.stdout, globalOptions.stderr = stdioWrapper.Stdout(), stdioWrapper.Stderr()
return runRestore(ctx, restoreOptions, globalOptions, term, args)
},
}
@ -64,7 +92,9 @@ func init() {
flags.BoolVar(&restoreOptions.Verify, "verify", false, "verify restored files content")
}
func runRestore(ctx context.Context, opts RestoreOptions, gopts GlobalOptions, args []string) error {
func runRestore(ctx context.Context, opts RestoreOptions, gopts GlobalOptions,
term *termstatus.Terminal, args []string) error {
hasExcludes := len(opts.Exclude) > 0 || len(opts.InsensitiveExclude) > 0
hasIncludes := len(opts.Include) > 0 || len(opts.InsensitiveInclude) > 0
@ -145,7 +175,12 @@ func runRestore(ctx context.Context, opts RestoreOptions, gopts GlobalOptions, a
return err
}
res := restorer.NewRestorer(ctx, repo, sn, opts.Sparse)
var progress *restoreui.Progress
if !globalOptions.Quiet && !globalOptions.JSON {
progress = restoreui.NewProgress(restoreui.NewProgressPrinter(term), calculateProgressInterval(!gopts.Quiet, gopts.JSON))
}
res := restorer.NewRestorer(ctx, repo, sn, opts.Sparse, progress)
totalErrors := 0
res.Error = func(location string, err error) error {
@ -209,6 +244,10 @@ func runRestore(ctx context.Context, opts RestoreOptions, gopts GlobalOptions, a
return err
}
if progress != nil {
progress.Finish()
}
if totalErrors > 0 {
return errors.Fatalf("There were %d errors\n", totalErrors)
}

View File

@ -112,7 +112,7 @@ func testRunRestoreLatest(t testing.TB, gopts GlobalOptions, dir string, paths [
},
}
rtest.OK(t, runRestore(context.TODO(), opts, gopts, []string{"latest"}))
rtest.OK(t, runRestore(context.TODO(), opts, gopts, nil, []string{"latest"}))
}
func testRunRestoreExcludes(t testing.TB, gopts GlobalOptions, dir string, snapshotID restic.ID, excludes []string) {
@ -121,7 +121,7 @@ func testRunRestoreExcludes(t testing.TB, gopts GlobalOptions, dir string, snaps
Exclude: excludes,
}
rtest.OK(t, runRestore(context.TODO(), opts, gopts, []string{snapshotID.String()}))
rtest.OK(t, runRestore(context.TODO(), opts, gopts, nil, []string{snapshotID.String()}))
}
func testRunRestoreIncludes(t testing.TB, gopts GlobalOptions, dir string, snapshotID restic.ID, includes []string) {
@ -130,11 +130,11 @@ func testRunRestoreIncludes(t testing.TB, gopts GlobalOptions, dir string, snaps
Include: includes,
}
rtest.OK(t, runRestore(context.TODO(), opts, gopts, []string{snapshotID.String()}))
rtest.OK(t, runRestore(context.TODO(), opts, gopts, nil, []string{snapshotID.String()}))
}
func testRunRestoreAssumeFailure(t testing.TB, snapshotID string, opts RestoreOptions, gopts GlobalOptions) error {
err := runRestore(context.TODO(), opts, gopts, []string{snapshotID})
err := runRestore(context.TODO(), opts, gopts, nil, []string{snapshotID})
return err
}

View File

@ -12,6 +12,7 @@ import (
"github.com/restic/restic/internal/errors"
"github.com/restic/restic/internal/repository"
"github.com/restic/restic/internal/restic"
"github.com/restic/restic/internal/ui/restore"
)
// TODO if a blob is corrupt, there may be good blob copies in other packs
@ -54,6 +55,7 @@ type fileRestorer struct {
filesWriter *filesWriter
zeroChunk restic.ID
sparse bool
progress *restore.Progress
dst string
files []*fileInfo
@ -65,7 +67,8 @@ func newFileRestorer(dst string,
key *crypto.Key,
idx func(restic.BlobHandle) []restic.PackedBlob,
connections uint,
sparse bool) *fileRestorer {
sparse bool,
progress *restore.Progress) *fileRestorer {
// as packs are streamed the concurrency is limited by IO
workerCount := int(connections)
@ -77,6 +80,7 @@ func newFileRestorer(dst string,
filesWriter: newFilesWriter(workerCount),
zeroChunk: repository.ZeroChunk(),
sparse: sparse,
progress: progress,
workerCount: workerCount,
dst: dst,
Error: restorerAbortOnAllErrors,
@ -268,7 +272,13 @@ func (r *fileRestorer) downloadPack(ctx context.Context, pack *packInfo) error {
file.inProgress = true
createSize = file.size
}
return r.filesWriter.writeToFile(r.targetPath(file.location), blobData, offset, createSize, file.sparse)
writeErr := r.filesWriter.writeToFile(r.targetPath(file.location), blobData, offset, createSize, file.sparse)
if r.progress != nil {
r.progress.AddProgress(file.location, uint64(len(blobData)), uint64(file.size))
}
return writeErr
}
err := sanitizeError(file, writeToFile())
if err != nil {

View File

@ -150,7 +150,7 @@ func newTestRepo(content []TestFile) *TestRepo {
func restoreAndVerify(t *testing.T, tempdir string, content []TestFile, files map[string]bool, sparse bool) {
repo := newTestRepo(content)
r := newFileRestorer(tempdir, repo.loader, repo.key, repo.Lookup, 2, sparse)
r := newFileRestorer(tempdir, repo.loader, repo.key, repo.Lookup, 2, sparse, nil)
if files == nil {
r.files = repo.files
@ -265,7 +265,7 @@ func TestErrorRestoreFiles(t *testing.T) {
return loadError
}
r := newFileRestorer(tempdir, repo.loader, repo.key, repo.Lookup, 2, false)
r := newFileRestorer(tempdir, repo.loader, repo.key, repo.Lookup, 2, false, nil)
r.files = repo.files
err := r.restoreFiles(context.TODO())
@ -304,7 +304,7 @@ func testPartialDownloadError(t *testing.T, part int) {
return loader(ctx, h, length, offset, fn)
}
r := newFileRestorer(tempdir, repo.loader, repo.key, repo.Lookup, 2, false)
r := newFileRestorer(tempdir, repo.loader, repo.key, repo.Lookup, 2, false, nil)
r.files = repo.files
r.Error = func(s string, e error) error {
// ignore errors as in the `restore` command

View File

@ -10,6 +10,7 @@ import (
"github.com/restic/restic/internal/errors"
"github.com/restic/restic/internal/fs"
"github.com/restic/restic/internal/restic"
restoreui "github.com/restic/restic/internal/ui/restore"
"golang.org/x/sync/errgroup"
)
@ -20,6 +21,8 @@ type Restorer struct {
sn *restic.Snapshot
sparse bool
progress *restoreui.Progress
Error func(location string, err error) error
SelectFilter func(item string, dstpath string, node *restic.Node) (selectedForRestore bool, childMayBeSelected bool)
}
@ -27,12 +30,14 @@ type Restorer struct {
var restorerAbortOnAllErrors = func(location string, err error) error { return err }
// NewRestorer creates a restorer preloaded with the content from the snapshot id.
func NewRestorer(ctx context.Context, repo restic.Repository, sn *restic.Snapshot, sparse bool) *Restorer {
func NewRestorer(ctx context.Context, repo restic.Repository, sn *restic.Snapshot, sparse bool,
progress *restoreui.Progress) *Restorer {
r := &Restorer{
repo: repo,
sparse: sparse,
Error: restorerAbortOnAllErrors,
SelectFilter: func(string, string, *restic.Node) (bool, bool) { return true, true },
progress: progress,
sn: sn,
}
@ -186,6 +191,11 @@ func (res *Restorer) restoreHardlinkAt(node *restic.Node, target, path, location
if err != nil {
return errors.WithStack(err)
}
if res.progress != nil {
res.progress.AddProgress(location, 0, 0)
}
// TODO investigate if hardlinks have separate metadata on any supported system
return res.restoreNodeMetadataTo(node, path, location)
}
@ -200,6 +210,10 @@ func (res *Restorer) restoreEmptyFileAt(node *restic.Node, target, location stri
return err
}
if res.progress != nil {
res.progress.AddProgress(location, 0, 0)
}
return res.restoreNodeMetadataTo(node, target, location)
}
@ -215,7 +229,8 @@ func (res *Restorer) RestoreTo(ctx context.Context, dst string) error {
}
idx := NewHardlinkIndex()
filerestorer := newFileRestorer(dst, res.repo.Backend().Load, res.repo.Key(), res.repo.Index().Lookup, res.repo.Connections(), res.sparse)
filerestorer := newFileRestorer(dst, res.repo.Backend().Load, res.repo.Key(), res.repo.Index().Lookup,
res.repo.Connections(), res.sparse, res.progress)
filerestorer.Error = res.Error
debug.Log("first pass for %q", dst)
@ -242,6 +257,10 @@ func (res *Restorer) RestoreTo(ctx context.Context, dst string) error {
return nil
}
if res.progress != nil {
res.progress.AddFile(node.Size)
}
if node.Size == 0 {
return nil // deal with empty files later
}

View File

@ -325,7 +325,7 @@ func TestRestorer(t *testing.T) {
sn, id := saveSnapshot(t, repo, test.Snapshot)
t.Logf("snapshot saved as %v", id.Str())
res := NewRestorer(context.TODO(), repo, sn, false)
res := NewRestorer(context.TODO(), repo, sn, false, nil)
tempdir := rtest.TempDir(t)
// make sure we're creating a new subdir of the tempdir
@ -442,7 +442,7 @@ func TestRestorerRelative(t *testing.T) {
sn, id := saveSnapshot(t, repo, test.Snapshot)
t.Logf("snapshot saved as %v", id.Str())
res := NewRestorer(context.TODO(), repo, sn, false)
res := NewRestorer(context.TODO(), repo, sn, false, nil)
tempdir := rtest.TempDir(t)
cleanup := rtest.Chdir(t, tempdir)
@ -671,7 +671,7 @@ func TestRestorerTraverseTree(t *testing.T) {
repo := repository.TestRepository(t)
sn, _ := saveSnapshot(t, repo, test.Snapshot)
res := NewRestorer(context.TODO(), repo, sn, false)
res := NewRestorer(context.TODO(), repo, sn, false, nil)
res.SelectFilter = test.Select
@ -747,7 +747,7 @@ func TestRestorerConsistentTimestampsAndPermissions(t *testing.T) {
},
})
res := NewRestorer(context.TODO(), repo, sn, false)
res := NewRestorer(context.TODO(), repo, sn, false, nil)
res.SelectFilter = func(item string, dstpath string, node *restic.Node) (selectedForRestore bool, childMayBeSelected bool) {
switch filepath.ToSlash(item) {
@ -802,7 +802,7 @@ func TestVerifyCancel(t *testing.T) {
repo := repository.TestRepository(t)
sn, _ := saveSnapshot(t, repo, snapshot)
res := NewRestorer(context.TODO(), repo, sn, false)
res := NewRestorer(context.TODO(), repo, sn, false, nil)
tempdir := rtest.TempDir(t)
ctx, cancel := context.WithCancel(context.Background())
@ -844,7 +844,7 @@ func TestRestorerSparseFiles(t *testing.T) {
archiver.SnapshotOptions{})
rtest.OK(t, err)
res := NewRestorer(context.TODO(), repo, sn, true)
res := NewRestorer(context.TODO(), repo, sn, true, nil)
tempdir := rtest.TempDir(t)
ctx, cancel := context.WithCancel(context.Background())

View File

@ -29,7 +29,7 @@ func TestRestorerRestoreEmptyHardlinkedFileds(t *testing.T) {
},
})
res := NewRestorer(context.TODO(), repo, sn, false)
res := NewRestorer(context.TODO(), repo, sn, false, nil)
res.SelectFilter = func(item string, dstpath string, node *restic.Node) (selectedForRestore bool, childMayBeSelected bool) {
return true, true

View File

@ -0,0 +1,131 @@
package restore
import (
"fmt"
"sync"
"time"
"github.com/restic/restic/internal/ui"
"github.com/restic/restic/internal/ui/progress"
)
type Progress struct {
updater progress.Updater
m sync.Mutex
progressInfoMap map[string]progressInfoEntry
filesFinished uint64
filesTotal uint64
allBytesWritten uint64
allBytesTotal uint64
started time.Time
printer ProgressPrinter
}
type progressInfoEntry struct {
bytesWritten uint64
bytesTotal uint64
}
type ProgressPrinter interface {
Update(filesFinished, filesTotal, allBytesWritten, allBytesTotal uint64, duration time.Duration)
Finish(filesFinished, filesTotal, allBytesWritten, allBytesTotal uint64, duration time.Duration)
}
func NewProgress(printer ProgressPrinter, interval time.Duration) *Progress {
p := &Progress{
progressInfoMap: make(map[string]progressInfoEntry),
started: time.Now(),
printer: printer,
}
p.updater = *progress.NewUpdater(interval, p.update)
return p
}
func (p *Progress) update(runtime time.Duration, final bool) {
p.m.Lock()
defer p.m.Unlock()
if !final {
p.printer.Update(p.filesFinished, p.filesTotal, p.allBytesWritten, p.allBytesTotal, runtime)
} else {
p.printer.Finish(p.filesFinished, p.filesTotal, p.allBytesWritten, p.allBytesTotal, runtime)
}
}
// AddFile starts tracking a new file with the given size
func (p *Progress) AddFile(size uint64) {
p.m.Lock()
defer p.m.Unlock()
p.filesTotal++
p.allBytesTotal += size
}
// AddProgress accumulates the number of bytes written for a file
func (p *Progress) AddProgress(name string, bytesWrittenPortion uint64, bytesTotal uint64) {
p.m.Lock()
defer p.m.Unlock()
entry, exists := p.progressInfoMap[name]
if !exists {
entry.bytesTotal = bytesTotal
}
entry.bytesWritten += bytesWrittenPortion
p.progressInfoMap[name] = entry
p.allBytesWritten += bytesWrittenPortion
if entry.bytesWritten == entry.bytesTotal {
delete(p.progressInfoMap, name)
p.filesFinished++
}
}
func (p *Progress) Finish() {
p.updater.Done()
}
type term interface {
Print(line string)
SetStatus(lines []string)
}
type textPrinter struct {
terminal term
}
func NewProgressPrinter(terminal term) ProgressPrinter {
return &textPrinter{
terminal: terminal,
}
}
func (t *textPrinter) Update(filesFinished, filesTotal, allBytesWritten, allBytesTotal uint64, duration time.Duration) {
timeLeft := ui.FormatDuration(duration)
formattedAllBytesWritten := ui.FormatBytes(allBytesWritten)
formattedAllBytesTotal := ui.FormatBytes(allBytesTotal)
allPercent := ui.FormatPercent(allBytesWritten, allBytesTotal)
progress := fmt.Sprintf("[%s] %s %v files %s, total %v files %v",
timeLeft, allPercent, filesFinished, formattedAllBytesWritten, filesTotal, formattedAllBytesTotal)
t.terminal.SetStatus([]string{progress})
}
func (t *textPrinter) Finish(filesFinished, filesTotal, allBytesWritten, allBytesTotal uint64, duration time.Duration) {
t.terminal.SetStatus([]string{})
timeLeft := ui.FormatDuration(duration)
formattedAllBytesTotal := ui.FormatBytes(allBytesTotal)
var summary string
if filesFinished == filesTotal && allBytesWritten == allBytesTotal {
summary = fmt.Sprintf("Summary: Restored %d Files (%s) in %s", filesTotal, formattedAllBytesTotal, timeLeft)
} else {
formattedAllBytesWritten := ui.FormatBytes(allBytesWritten)
summary = fmt.Sprintf("Summary: Restored %d / %d Files (%s / %s) in %s",
filesFinished, filesTotal, formattedAllBytesWritten, formattedAllBytesTotal, timeLeft)
}
t.terminal.Print(summary)
}

View File

@ -0,0 +1,170 @@
package restore
import (
"testing"
"time"
"github.com/restic/restic/internal/test"
)
type printerTraceEntry struct {
filesFinished, filesTotal, allBytesWritten, allBytesTotal uint64
duration time.Duration
isFinished bool
}
type printerTrace []printerTraceEntry
type mockPrinter struct {
trace printerTrace
}
const mockFinishDuration = 42 * time.Second
func (p *mockPrinter) Update(filesFinished, filesTotal, allBytesWritten, allBytesTotal uint64, duration time.Duration) {
p.trace = append(p.trace, printerTraceEntry{filesFinished, filesTotal, allBytesWritten, allBytesTotal, duration, false})
}
func (p *mockPrinter) Finish(filesFinished, filesTotal, allBytesWritten, allBytesTotal uint64, duration time.Duration) {
p.trace = append(p.trace, printerTraceEntry{filesFinished, filesTotal, allBytesWritten, allBytesTotal, mockFinishDuration, true})
}
func testProgress(fn func(progress *Progress) bool) printerTrace {
printer := &mockPrinter{}
progress := NewProgress(printer, 0)
final := fn(progress)
progress.update(0, final)
trace := append(printerTrace{}, printer.trace...)
// cleanup to avoid goroutine leak, but copy trace first
progress.Finish()
return trace
}
func TestNew(t *testing.T) {
result := testProgress(func(progress *Progress) bool {
return false
})
test.Equals(t, printerTrace{
printerTraceEntry{0, 0, 0, 0, 0, false},
}, result)
}
func TestAddFile(t *testing.T) {
fileSize := uint64(100)
result := testProgress(func(progress *Progress) bool {
progress.AddFile(fileSize)
return false
})
test.Equals(t, printerTrace{
printerTraceEntry{0, 1, 0, fileSize, 0, false},
}, result)
}
func TestFirstProgressOnAFile(t *testing.T) {
expectedBytesWritten := uint64(5)
expectedBytesTotal := uint64(100)
result := testProgress(func(progress *Progress) bool {
progress.AddFile(expectedBytesTotal)
progress.AddProgress("test", expectedBytesWritten, expectedBytesTotal)
return false
})
test.Equals(t, printerTrace{
printerTraceEntry{0, 1, expectedBytesWritten, expectedBytesTotal, 0, false},
}, result)
}
func TestLastProgressOnAFile(t *testing.T) {
fileSize := uint64(100)
result := testProgress(func(progress *Progress) bool {
progress.AddFile(fileSize)
progress.AddProgress("test", 30, fileSize)
progress.AddProgress("test", 35, fileSize)
progress.AddProgress("test", 35, fileSize)
return false
})
test.Equals(t, printerTrace{
printerTraceEntry{1, 1, fileSize, fileSize, 0, false},
}, result)
}
func TestLastProgressOnLastFile(t *testing.T) {
fileSize := uint64(100)
result := testProgress(func(progress *Progress) bool {
progress.AddFile(fileSize)
progress.AddFile(50)
progress.AddProgress("test1", 50, 50)
progress.AddProgress("test2", 50, fileSize)
progress.AddProgress("test2", 50, fileSize)
return false
})
test.Equals(t, printerTrace{
printerTraceEntry{2, 2, 50 + fileSize, 50 + fileSize, 0, false},
}, result)
}
func TestSummaryOnSuccess(t *testing.T) {
fileSize := uint64(100)
result := testProgress(func(progress *Progress) bool {
progress.AddFile(fileSize)
progress.AddFile(50)
progress.AddProgress("test1", 50, 50)
progress.AddProgress("test2", fileSize, fileSize)
return true
})
test.Equals(t, printerTrace{
printerTraceEntry{2, 2, 50 + fileSize, 50 + fileSize, mockFinishDuration, true},
}, result)
}
func TestSummaryOnErrors(t *testing.T) {
fileSize := uint64(100)
result := testProgress(func(progress *Progress) bool {
progress.AddFile(fileSize)
progress.AddFile(50)
progress.AddProgress("test1", 50, 50)
progress.AddProgress("test2", fileSize/2, fileSize)
return true
})
test.Equals(t, printerTrace{
printerTraceEntry{1, 2, 50 + fileSize/2, 50 + fileSize, mockFinishDuration, true},
}, result)
}
type mockTerm struct {
output []string
}
func (m *mockTerm) Print(line string) {
m.output = append(m.output, line)
}
func (m *mockTerm) SetStatus(lines []string) {
m.output = append([]string{}, lines...)
}
func TestPrintUpdate(t *testing.T) {
term := &mockTerm{}
printer := NewProgressPrinter(term)
printer.Update(3, 11, 29, 47, 5*time.Second)
test.Equals(t, []string{"[0:05] 61.70% 3 files 29 B, total 11 files 47 B"}, term.output)
}
func TestPrintSummaryOnSuccess(t *testing.T) {
term := &mockTerm{}
printer := NewProgressPrinter(term)
printer.Finish(11, 11, 47, 47, 5*time.Second)
test.Equals(t, []string{"Summary: Restored 11 Files (47 B) in 0:05"}, term.output)
}
func TestPrintSummaryOnErrors(t *testing.T) {
term := &mockTerm{}
printer := NewProgressPrinter(term)
printer.Finish(3, 11, 29, 47, 5*time.Second)
test.Equals(t, []string{"Summary: Restored 3 / 11 Files (29 B / 47 B) in 0:05"}, term.output)
}