diff --git a/changelog/unreleased/issue-3627 b/changelog/unreleased/issue-426 similarity index 66% rename from changelog/unreleased/issue-3627 rename to changelog/unreleased/issue-426 index edbbdbb33..9caf14ef5 100644 --- a/changelog/unreleased/issue-3627 +++ b/changelog/unreleased/issue-426 @@ -4,6 +4,11 @@ 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 +JSON output is now also supported. + +https://github.com/restic/restic/issues/426 +https://github.com/restic/restic/issues/3413 https://github.com/restic/restic/issues/3627 https://github.com/restic/restic/pull/3991 +https://github.com/restic/restic/pull/4314 https://forum.restic.net/t/progress-bar-for-restore/5210 diff --git a/cmd/restic/cmd_backup_integration_test.go b/cmd/restic/cmd_backup_integration_test.go index 3af16a2be..b81db21e6 100644 --- a/cmd/restic/cmd_backup_integration_test.go +++ b/cmd/restic/cmd_backup_integration_test.go @@ -13,34 +13,19 @@ import ( "github.com/restic/restic/internal/restic" rtest "github.com/restic/restic/internal/test" "github.com/restic/restic/internal/ui/termstatus" - "golang.org/x/sync/errgroup" ) func testRunBackupAssumeFailure(t testing.TB, dir string, target []string, opts BackupOptions, gopts GlobalOptions) error { - ctx, cancel := context.WithCancel(context.TODO()) - defer cancel() + return withTermStatus(gopts, func(ctx context.Context, term *termstatus.Terminal) error { + t.Logf("backing up %v in %v", target, dir) + if dir != "" { + cleanup := rtest.Chdir(t, dir) + defer cleanup() + } - var wg errgroup.Group - term := termstatus.New(gopts.stdout, gopts.stderr, gopts.Quiet) - wg.Go(func() error { term.Run(ctx); return nil }) - - t.Logf("backing up %v in %v", target, dir) - if dir != "" { - cleanup := rtest.Chdir(t, dir) - defer cleanup() - } - - opts.GroupBy = restic.SnapshotGroupByOptions{Host: true, Path: true} - backupErr := runBackup(ctx, opts, gopts, term, target) - - cancel() - - err := wg.Wait() - if err != nil { - t.Fatal(err) - } - - return backupErr + opts.GroupBy = restic.SnapshotGroupByOptions{Host: true, Path: true} + return runBackup(ctx, opts, gopts, term, target) + }) } func testRunBackup(t testing.TB, dir string, target []string, opts BackupOptions, gopts GlobalOptions) { diff --git a/cmd/restic/cmd_restore.go b/cmd/restic/cmd_restore.go index a0d4ce3e4..c59ac34de 100644 --- a/cmd/restic/cmd_restore.go +++ b/cmd/restic/cmd_restore.go @@ -175,16 +175,20 @@ func runRestore(ctx context.Context, opts RestoreOptions, gopts GlobalOptions, return err } - var progress *restoreui.Progress - if !gopts.Quiet && !gopts.JSON { - progress = restoreui.NewProgress(restoreui.NewProgressPrinter(term), calculateProgressInterval(!gopts.Quiet, gopts.JSON)) + msg := ui.NewMessage(term, gopts.verbosity) + var printer restoreui.ProgressPrinter + if gopts.JSON { + printer = restoreui.NewJSONProgress(term) + } else { + printer = restoreui.NewTextProgress(term) } + progress := restoreui.NewProgress(printer, calculateProgressInterval(!gopts.Quiet, gopts.JSON)) res := restorer.NewRestorer(repo, sn, opts.Sparse, progress) totalErrors := 0 res.Error = func(location string, err error) error { - Warnf("ignoring error for %s: %s\n", location, err) + msg.E("ignoring error for %s: %s\n", location, err) totalErrors++ return nil } @@ -194,12 +198,12 @@ func runRestore(ctx context.Context, opts RestoreOptions, gopts GlobalOptions, selectExcludeFilter := func(item string, dstpath string, node *restic.Node) (selectedForRestore bool, childMayBeSelected bool) { matched, err := filter.List(excludePatterns, item) if err != nil { - Warnf("error for exclude pattern: %v", err) + msg.E("error for exclude pattern: %v", err) } matchedInsensitive, err := filter.List(insensitiveExcludePatterns, strings.ToLower(item)) if err != nil { - Warnf("error for iexclude pattern: %v", err) + msg.E("error for iexclude pattern: %v", err) } // An exclude filter is basically a 'wildcard but foo', @@ -217,12 +221,12 @@ func runRestore(ctx context.Context, opts RestoreOptions, gopts GlobalOptions, selectIncludeFilter := func(item string, dstpath string, node *restic.Node) (selectedForRestore bool, childMayBeSelected bool) { matched, childMayMatch, err := filter.ListWithChild(includePatterns, item) if err != nil { - Warnf("error for include pattern: %v", err) + msg.E("error for include pattern: %v", err) } matchedInsensitive, childMayMatchInsensitive, err := filter.ListWithChild(insensitiveIncludePatterns, strings.ToLower(item)) if err != nil { - Warnf("error for iexclude pattern: %v", err) + msg.E("error for iexclude pattern: %v", err) } selectedForRestore = matched || matchedInsensitive @@ -237,23 +241,25 @@ func runRestore(ctx context.Context, opts RestoreOptions, gopts GlobalOptions, res.SelectFilter = selectIncludeFilter } - Verbosef("restoring %s to %s\n", res.Snapshot(), opts.Target) + if !gopts.JSON { + msg.P("restoring %s to %s\n", res.Snapshot(), opts.Target) + } err = res.RestoreTo(ctx, opts.Target) if err != nil { return err } - if progress != nil { - progress.Finish() - } + progress.Finish() if totalErrors > 0 { return errors.Fatalf("There were %d errors\n", totalErrors) } if opts.Verify { - Verbosef("verifying files in %s\n", opts.Target) + if !gopts.JSON { + msg.P("verifying files in %s\n", opts.Target) + } var count int t0 := time.Now() count, err = res.VerifyFiles(ctx, opts.Target) @@ -263,8 +269,11 @@ func runRestore(ctx context.Context, opts RestoreOptions, gopts GlobalOptions, if totalErrors > 0 { return errors.Fatalf("There were %d errors\n", totalErrors) } - Verbosef("finished verifying %d files in %s (took %s)\n", count, opts.Target, - time.Since(t0).Round(time.Millisecond)) + + if !gopts.JSON { + msg.P("finished verifying %d files in %s (took %s)\n", count, opts.Target, + time.Since(t0).Round(time.Millisecond)) + } } return nil diff --git a/cmd/restic/cmd_restore_integration_test.go b/cmd/restic/cmd_restore_integration_test.go index 74fddd347..2c7cbe1fb 100644 --- a/cmd/restic/cmd_restore_integration_test.go +++ b/cmd/restic/cmd_restore_integration_test.go @@ -14,6 +14,7 @@ import ( "github.com/restic/restic/internal/filter" "github.com/restic/restic/internal/restic" rtest "github.com/restic/restic/internal/test" + "github.com/restic/restic/internal/ui/termstatus" ) func testRunRestore(t testing.TB, opts GlobalOptions, dir string, snapshotID restic.ID) { @@ -26,11 +27,13 @@ func testRunRestoreExcludes(t testing.TB, gopts GlobalOptions, dir string, snaps Exclude: excludes, } - rtest.OK(t, runRestore(context.TODO(), opts, gopts, nil, []string{snapshotID.String()})) + rtest.OK(t, testRunRestoreAssumeFailure(snapshotID.String(), opts, gopts)) } func testRunRestoreAssumeFailure(snapshotID string, opts RestoreOptions, gopts GlobalOptions) error { - return runRestore(context.TODO(), opts, gopts, nil, []string{snapshotID}) + return withTermStatus(gopts, func(ctx context.Context, term *termstatus.Terminal) error { + return runRestore(ctx, opts, gopts, term, []string{snapshotID}) + }) } func testRunRestoreLatest(t testing.TB, gopts GlobalOptions, dir string, paths []string, hosts []string) { @@ -42,7 +45,7 @@ func testRunRestoreLatest(t testing.TB, gopts GlobalOptions, dir string, paths [ }, } - rtest.OK(t, runRestore(context.TODO(), opts, gopts, nil, []string{"latest"})) + rtest.OK(t, testRunRestoreAssumeFailure("latest", opts, gopts)) } func testRunRestoreIncludes(t testing.TB, gopts GlobalOptions, dir string, snapshotID restic.ID, includes []string) { @@ -51,7 +54,7 @@ func testRunRestoreIncludes(t testing.TB, gopts GlobalOptions, dir string, snaps Include: includes, } - rtest.OK(t, runRestore(context.TODO(), opts, gopts, nil, []string{snapshotID.String()})) + rtest.OK(t, testRunRestoreAssumeFailure(snapshotID.String(), opts, gopts)) } func TestRestoreFilter(t *testing.T) { diff --git a/cmd/restic/integration_helpers_test.go b/cmd/restic/integration_helpers_test.go index cdafd8c98..a0e4d49d6 100644 --- a/cmd/restic/integration_helpers_test.go +++ b/cmd/restic/integration_helpers_test.go @@ -9,6 +9,7 @@ import ( "os" "path/filepath" "runtime" + "sync" "testing" "github.com/restic/restic/internal/backend/retry" @@ -17,6 +18,7 @@ import ( "github.com/restic/restic/internal/repository" "github.com/restic/restic/internal/restic" rtest "github.com/restic/restic/internal/test" + "github.com/restic/restic/internal/ui/termstatus" ) type dirEntry struct { @@ -356,3 +358,20 @@ func withCaptureStdout(inner func() error) (*bytes.Buffer, error) { return buf, err } + +func withTermStatus(gopts GlobalOptions, callback func(ctx context.Context, term *termstatus.Terminal) error) error { + ctx, cancel := context.WithCancel(context.TODO()) + var wg sync.WaitGroup + + term := termstatus.New(gopts.stdout, gopts.stderr, gopts.Quiet) + wg.Add(1) + go func() { + defer wg.Done() + term.Run(ctx) + }() + + defer wg.Wait() + defer cancel() + + return callback(ctx, term) +} diff --git a/internal/ui/backup/json.go b/internal/ui/backup/json.go index e7c9274a4..10f0e91fa 100644 --- a/internal/ui/backup/json.go +++ b/internal/ui/backup/json.go @@ -1,8 +1,6 @@ package backup import ( - "bytes" - "encoding/json" "sort" "time" @@ -32,21 +30,12 @@ func NewJSONProgress(term *termstatus.Terminal, verbosity uint) *JSONProgress { } } -func toJSONString(status interface{}) string { - buf := new(bytes.Buffer) - err := json.NewEncoder(buf).Encode(status) - if err != nil { - panic(err) - } - return buf.String() -} - func (b *JSONProgress) print(status interface{}) { - b.term.Print(toJSONString(status)) + b.term.Print(ui.ToJSONString(status)) } func (b *JSONProgress) error(status interface{}) { - b.term.Error(toJSONString(status)) + b.term.Error(ui.ToJSONString(status)) } // Update updates the status lines. diff --git a/internal/ui/format.go b/internal/ui/format.go index 13d02f9e3..34c97703a 100644 --- a/internal/ui/format.go +++ b/internal/ui/format.go @@ -1,6 +1,8 @@ package ui import ( + "bytes" + "encoding/json" "fmt" "time" ) @@ -53,3 +55,12 @@ func FormatSeconds(sec uint64) string { } return fmt.Sprintf("%d:%02d", min, sec) } + +func ToJSONString(status interface{}) string { + buf := new(bytes.Buffer) + err := json.NewEncoder(buf).Encode(status) + if err != nil { + panic(err) + } + return buf.String() +} diff --git a/internal/ui/restore/json.go b/internal/ui/restore/json.go new file mode 100644 index 000000000..c1b95b00b --- /dev/null +++ b/internal/ui/restore/json.go @@ -0,0 +1,69 @@ +package restore + +import ( + "time" + + "github.com/restic/restic/internal/ui" +) + +type jsonPrinter struct { + terminal term +} + +func NewJSONProgress(terminal term) ProgressPrinter { + return &jsonPrinter{ + terminal: terminal, + } +} + +func (t *jsonPrinter) print(status interface{}) { + t.terminal.Print(ui.ToJSONString(status)) +} + +func (t *jsonPrinter) Update(filesFinished, filesTotal, allBytesWritten, allBytesTotal uint64, duration time.Duration) { + status := statusUpdate{ + MessageType: "status", + SecondsElapsed: uint64(duration / time.Second), + TotalFiles: filesTotal, + FilesRestored: filesFinished, + TotalBytes: allBytesTotal, + BytesRestored: allBytesWritten, + } + + if allBytesTotal > 0 { + status.PercentDone = float64(allBytesWritten) / float64(allBytesTotal) + } + + t.print(status) +} + +func (t *jsonPrinter) Finish(filesFinished, filesTotal, allBytesWritten, allBytesTotal uint64, duration time.Duration) { + status := summaryOutput{ + MessageType: "summary", + SecondsElapsed: uint64(duration / time.Second), + TotalFiles: filesTotal, + FilesRestored: filesFinished, + TotalBytes: allBytesTotal, + BytesRestored: allBytesWritten, + } + t.print(status) +} + +type statusUpdate struct { + MessageType string `json:"message_type"` // "status" + SecondsElapsed uint64 `json:"seconds_elapsed,omitempty"` + PercentDone float64 `json:"percent_done"` + TotalFiles uint64 `json:"total_files,omitempty"` + FilesRestored uint64 `json:"files_restored,omitempty"` + TotalBytes uint64 `json:"total_bytes,omitempty"` + BytesRestored uint64 `json:"bytes_restored,omitempty"` +} + +type summaryOutput struct { + MessageType string `json:"message_type"` // "summary" + SecondsElapsed uint64 `json:"seconds_elapsed,omitempty"` + TotalFiles uint64 `json:"total_files,omitempty"` + FilesRestored uint64 `json:"files_restored,omitempty"` + TotalBytes uint64 `json:"total_bytes,omitempty"` + BytesRestored uint64 `json:"bytes_restored,omitempty"` +} diff --git a/internal/ui/restore/json_test.go b/internal/ui/restore/json_test.go new file mode 100644 index 000000000..7bcabb4d7 --- /dev/null +++ b/internal/ui/restore/json_test.go @@ -0,0 +1,29 @@ +package restore + +import ( + "testing" + "time" + + "github.com/restic/restic/internal/test" +) + +func TestJSONPrintUpdate(t *testing.T) { + term := &mockTerm{} + printer := NewJSONProgress(term) + printer.Update(3, 11, 29, 47, 5*time.Second) + test.Equals(t, []string{"{\"message_type\":\"status\",\"seconds_elapsed\":5,\"percent_done\":0.6170212765957447,\"total_files\":11,\"files_restored\":3,\"total_bytes\":47,\"bytes_restored\":29}\n"}, term.output) +} + +func TestJSONPrintSummaryOnSuccess(t *testing.T) { + term := &mockTerm{} + printer := NewJSONProgress(term) + printer.Finish(11, 11, 47, 47, 5*time.Second) + test.Equals(t, []string{"{\"message_type\":\"summary\",\"seconds_elapsed\":5,\"total_files\":11,\"files_restored\":11,\"total_bytes\":47,\"bytes_restored\":47}\n"}, term.output) +} + +func TestJSONPrintSummaryOnErrors(t *testing.T) { + term := &mockTerm{} + printer := NewJSONProgress(term) + printer.Finish(3, 11, 29, 47, 5*time.Second) + test.Equals(t, []string{"{\"message_type\":\"summary\",\"seconds_elapsed\":5,\"total_files\":11,\"files_restored\":3,\"total_bytes\":47,\"bytes_restored\":29}\n"}, term.output) +} diff --git a/internal/ui/restore/progressformatter.go b/internal/ui/restore/progress.go similarity index 58% rename from internal/ui/restore/progressformatter.go rename to internal/ui/restore/progress.go index a89cc628e..f2bd5d38b 100644 --- a/internal/ui/restore/progressformatter.go +++ b/internal/ui/restore/progress.go @@ -1,11 +1,9 @@ package restore import ( - "fmt" "sync" "time" - "github.com/restic/restic/internal/ui" "github.com/restic/restic/internal/ui/progress" ) @@ -28,6 +26,11 @@ type progressInfoEntry struct { bytesTotal uint64 } +type term interface { + Print(line string) + SetStatus(lines []string) +} + type ProgressPrinter interface { Update(filesFinished, filesTotal, allBytesWritten, allBytesTotal uint64, duration time.Duration) Finish(filesFinished, filesTotal, allBytesWritten, allBytesTotal uint64, duration time.Duration) @@ -85,47 +88,3 @@ func (p *Progress) AddProgress(name string, bytesWrittenPortion uint64, bytesTot 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) -} diff --git a/internal/ui/restore/progressformatter_test.go b/internal/ui/restore/progress_test.go similarity index 80% rename from internal/ui/restore/progressformatter_test.go rename to internal/ui/restore/progress_test.go index e3dc3ace5..9e625aa20 100644 --- a/internal/ui/restore/progressformatter_test.go +++ b/internal/ui/restore/progress_test.go @@ -135,36 +135,3 @@ func TestSummaryOnErrors(t *testing.T) { 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) -} diff --git a/internal/ui/restore/text.go b/internal/ui/restore/text.go new file mode 100644 index 000000000..e6465eed0 --- /dev/null +++ b/internal/ui/restore/text.go @@ -0,0 +1,47 @@ +package restore + +import ( + "fmt" + "time" + + "github.com/restic/restic/internal/ui" +) + +type textPrinter struct { + terminal term +} + +func NewTextProgress(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) +} diff --git a/internal/ui/restore/text_test.go b/internal/ui/restore/text_test.go new file mode 100644 index 000000000..2a8c90878 --- /dev/null +++ b/internal/ui/restore/text_test.go @@ -0,0 +1,41 @@ +package restore + +import ( + "testing" + "time" + + "github.com/restic/restic/internal/test" +) + +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 := NewTextProgress(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 := NewTextProgress(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 := NewTextProgress(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) +}