restore: print processed files at maximum verbosity

This commit is contained in:
Michael Eischer 2024-05-31 20:38:51 +02:00
parent 2a7d257036
commit c47bf33884
10 changed files with 228 additions and 64 deletions

View file

@ -133,9 +133,9 @@ func runRestore(ctx context.Context, opts RestoreOptions, gopts GlobalOptions,
msg := ui.NewMessage(term, gopts.verbosity)
var printer restoreui.ProgressPrinter
if gopts.JSON {
printer = restoreui.NewJSONProgress(term)
printer = restoreui.NewJSONProgress(term, gopts.verbosity)
} else {
printer = restoreui.NewTextProgress(term)
printer = restoreui.NewTextProgress(term, gopts.verbosity)
}
progress := restoreui.NewProgress(printer, calculateProgressInterval(!gopts.Quiet, gopts.JSON))

View file

@ -215,7 +215,7 @@ func (r *fileRestorer) restoreEmptyFileAt(location string) error {
return err
}
r.progress.AddProgress(location, 0, 0)
r.progress.AddProgress(location, false, true, 0, 0)
return nil
}
@ -337,7 +337,7 @@ func (r *fileRestorer) downloadBlobs(ctx context.Context, packID restic.ID,
createSize = file.size
}
writeErr := r.filesWriter.writeToFile(r.targetPath(file.location), blobData, offset, createSize, file.sparse)
r.progress.AddProgress(file.location, uint64(len(blobData)), uint64(file.size))
r.progress.AddProgress(file.location, false, file.state == nil, uint64(len(blobData)), uint64(file.size))
return writeErr
}
err := r.sanitizeError(file, writeToFile())

View file

@ -231,7 +231,7 @@ func (res *Restorer) restoreNodeTo(ctx context.Context, node *restic.Node, targe
return err
}
res.opts.Progress.AddProgress(location, 0, 0)
res.opts.Progress.AddProgress(location, false, true, 0, 0)
return res.restoreNodeMetadataTo(node, target, location)
}
@ -253,8 +253,7 @@ func (res *Restorer) restoreHardlinkAt(node *restic.Node, target, path, location
return errors.WithStack(err)
}
res.opts.Progress.AddProgress(location, 0, 0)
res.opts.Progress.AddProgress(location, false, true, 0, 0)
// TODO investigate if hardlinks have separate metadata on any supported system
return res.restoreNodeMetadataTo(node, path, location)
}
@ -324,9 +323,9 @@ func (res *Restorer) RestoreTo(ctx context.Context, dst string) error {
idx.Add(node.Inode, node.DeviceID, location)
}
buf, err = res.withOverwriteCheck(node, target, false, buf, func(updateMetadataOnly bool, matches *fileState) error {
buf, err = res.withOverwriteCheck(node, target, location, false, buf, func(updateMetadataOnly bool, matches *fileState) error {
if updateMetadataOnly {
res.opts.Progress.AddSkippedFile(node.Size)
res.opts.Progress.AddSkippedFile(location, node.Size)
} else {
res.opts.Progress.AddFile(node.Size)
filerestorer.addFile(location, node.Content, int64(node.Size), matches)
@ -353,14 +352,14 @@ func (res *Restorer) RestoreTo(ctx context.Context, dst string) error {
visitNode: func(node *restic.Node, target, location string) error {
debug.Log("second pass, visitNode: restore node %q", location)
if node.Type != "file" {
_, err := res.withOverwriteCheck(node, target, false, nil, func(_ bool, _ *fileState) error {
_, err := res.withOverwriteCheck(node, target, location, false, nil, func(_ bool, _ *fileState) error {
return res.restoreNodeTo(ctx, node, target, location)
})
return err
}
if idx.Has(node.Inode, node.DeviceID) && idx.Value(node.Inode, node.DeviceID) != location {
_, err := res.withOverwriteCheck(node, target, true, nil, func(_ bool, _ *fileState) error {
_, err := res.withOverwriteCheck(node, target, location, true, nil, func(_ bool, _ *fileState) error {
return res.restoreHardlinkAt(node, filerestorer.targetPath(idx.Value(node.Inode, node.DeviceID)), target, location)
})
return err
@ -375,7 +374,7 @@ func (res *Restorer) RestoreTo(ctx context.Context, dst string) error {
leaveDir: func(node *restic.Node, target, location string) error {
err := res.restoreNodeMetadataTo(node, target, location)
if err == nil {
res.opts.Progress.AddProgress(location, 0, 0)
res.opts.Progress.AddProgress(location, false, true, 0, 0)
}
return err
},
@ -392,7 +391,7 @@ func (res *Restorer) hasRestoredFile(location string) (metadataOnly bool, ok boo
return metadataOnly, ok
}
func (res *Restorer) withOverwriteCheck(node *restic.Node, target string, isHardlink bool, buf []byte, cb func(updateMetadataOnly bool, matches *fileState) error) ([]byte, error) {
func (res *Restorer) withOverwriteCheck(node *restic.Node, target, location string, isHardlink bool, buf []byte, cb func(updateMetadataOnly bool, matches *fileState) error) ([]byte, error) {
overwrite, err := shouldOverwrite(res.opts.Overwrite, node, target)
if err != nil {
return buf, err
@ -401,7 +400,7 @@ func (res *Restorer) withOverwriteCheck(node *restic.Node, target string, isHard
if isHardlink {
size = 0
}
res.opts.Progress.AddSkippedFile(size)
res.opts.Progress.AddSkippedFile(location, size)
return buf, nil
}

View file

@ -76,6 +76,8 @@ type printerMock struct {
func (p *printerMock) Update(_ restoreui.State, _ time.Duration) {
}
func (p *printerMock) CompleteItem(action restoreui.ItemAction, item string, size uint64) {
}
func (p *printerMock) Finish(s restoreui.State, _ time.Duration) {
p.s = s
}

View file

@ -7,12 +7,14 @@ import (
)
type jsonPrinter struct {
terminal term
terminal term
verbosity uint
}
func NewJSONProgress(terminal term) ProgressPrinter {
func NewJSONProgress(terminal term, verbosity uint) ProgressPrinter {
return &jsonPrinter{
terminal: terminal,
terminal: terminal,
verbosity: verbosity,
}
}
@ -39,6 +41,34 @@ func (t *jsonPrinter) Update(p State, duration time.Duration) {
t.print(status)
}
func (t *jsonPrinter) CompleteItem(messageType ItemAction, item string, size uint64) {
if t.verbosity < 3 {
return
}
var action string
switch messageType {
case ActionDirRestored:
action = "restored"
case ActionFileRestored:
action = "restored"
case ActionFileUpdated:
action = "updated"
case ActionFileUnchanged:
action = "unchanged"
default:
panic("unknown message type")
}
status := verboseUpdate{
MessageType: "verbose_status",
Action: action,
Item: item,
Size: size,
}
t.print(status)
}
func (t *jsonPrinter) Finish(p State, duration time.Duration) {
status := summaryOutput{
MessageType: "summary",
@ -65,6 +95,13 @@ type statusUpdate struct {
BytesSkipped uint64 `json:"bytes_skipped,omitempty"`
}
type verboseUpdate struct {
MessageType string `json:"message_type"` // "verbose_status"
Action string `json:"action"`
Item string `json:"item"`
Size uint64 `json:"size"`
}
type summaryOutput struct {
MessageType string `json:"message_type"` // "summary"
SecondsElapsed uint64 `json:"seconds_elapsed,omitempty"`

View file

@ -7,37 +7,55 @@ import (
"github.com/restic/restic/internal/test"
)
func TestJSONPrintUpdate(t *testing.T) {
func createJSONProgress() (*mockTerm, ProgressPrinter) {
term := &mockTerm{}
printer := NewJSONProgress(term)
printer := NewJSONProgress(term, 3)
return term, printer
}
func TestJSONPrintUpdate(t *testing.T) {
term, printer := createJSONProgress()
printer.Update(State{3, 11, 0, 29, 47, 0}, 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 TestJSONPrintUpdateWithSkipped(t *testing.T) {
term := &mockTerm{}
printer := NewJSONProgress(term)
term, printer := createJSONProgress()
printer.Update(State{3, 11, 2, 29, 47, 59}, 5*time.Second)
test.Equals(t, []string{"{\"message_type\":\"status\",\"seconds_elapsed\":5,\"percent_done\":0.6170212765957447,\"total_files\":11,\"files_restored\":3,\"files_skipped\":2,\"total_bytes\":47,\"bytes_restored\":29,\"bytes_skipped\":59}\n"}, term.output)
}
func TestJSONPrintSummaryOnSuccess(t *testing.T) {
term := &mockTerm{}
printer := NewJSONProgress(term)
term, printer := createJSONProgress()
printer.Finish(State{11, 11, 0, 47, 47, 0}, 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)
term, printer := createJSONProgress()
printer.Finish(State{3, 11, 0, 29, 47, 0}, 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)
}
func TestJSONPrintSummaryOnSuccessWithSkipped(t *testing.T) {
term := &mockTerm{}
printer := NewJSONProgress(term)
term, printer := createJSONProgress()
printer.Finish(State{11, 11, 2, 47, 47, 59}, 5*time.Second)
test.Equals(t, []string{"{\"message_type\":\"summary\",\"seconds_elapsed\":5,\"total_files\":11,\"files_restored\":11,\"files_skipped\":2,\"total_bytes\":47,\"bytes_restored\":47,\"bytes_skipped\":59}\n"}, term.output)
}
func TestJSONPrintCompleteItem(t *testing.T) {
for _, data := range []struct {
action ItemAction
size uint64
expected string
}{
{ActionDirRestored, 0, "{\"message_type\":\"verbose_status\",\"action\":\"restored\",\"item\":\"test\",\"size\":0}\n"},
{ActionFileRestored, 123, "{\"message_type\":\"verbose_status\",\"action\":\"restored\",\"item\":\"test\",\"size\":123}\n"},
{ActionFileUpdated, 123, "{\"message_type\":\"verbose_status\",\"action\":\"updated\",\"item\":\"test\",\"size\":123}\n"},
{ActionFileUnchanged, 123, "{\"message_type\":\"verbose_status\",\"action\":\"unchanged\",\"item\":\"test\",\"size\":123}\n"},
} {
term, printer := createJSONProgress()
printer.CompleteItem(data.action, "test", data.size)
test.Equals(t, []string{data.expected}, term.output)
}
}

View file

@ -39,9 +39,20 @@ type term interface {
type ProgressPrinter interface {
Update(progress State, duration time.Duration)
CompleteItem(action ItemAction, item string, size uint64)
Finish(progress State, duration time.Duration)
}
type ItemAction string
// Constants for the different CompleteItem actions.
const (
ActionDirRestored ItemAction = "dir restored"
ActionFileRestored ItemAction = "file restored"
ActionFileUpdated ItemAction = "file updated"
ActionFileUnchanged ItemAction = "file unchanged"
)
func NewProgress(printer ProgressPrinter, interval time.Duration) *Progress {
p := &Progress{
progressInfoMap: make(map[string]progressInfoEntry),
@ -77,7 +88,7 @@ func (p *Progress) AddFile(size uint64) {
}
// AddProgress accumulates the number of bytes written for a file
func (p *Progress) AddProgress(name string, bytesWrittenPortion uint64, bytesTotal uint64) {
func (p *Progress) AddProgress(name string, isDir bool, isNew bool, bytesWrittenPortion uint64, bytesTotal uint64) {
if p == nil {
return
}
@ -96,10 +107,18 @@ func (p *Progress) AddProgress(name string, bytesWrittenPortion uint64, bytesTot
if entry.bytesWritten == entry.bytesTotal {
delete(p.progressInfoMap, name)
p.s.FilesFinished++
action := ActionFileUpdated
if isDir {
action = ActionDirRestored
} else if isNew {
action = ActionFileRestored
}
p.printer.CompleteItem(action, name, bytesTotal)
}
}
func (p *Progress) AddSkippedFile(size uint64) {
func (p *Progress) AddSkippedFile(name string, size uint64) {
if p == nil {
return
}
@ -109,6 +128,8 @@ func (p *Progress) AddSkippedFile(size uint64) {
p.s.FilesSkipped++
p.s.AllBytesSkipped += size
p.printer.CompleteItem(ActionFileUnchanged, name, size)
}
func (p *Progress) Finish() {

View file

@ -16,8 +16,16 @@ type printerTraceEntry struct {
type printerTrace []printerTraceEntry
type itemTraceEntry struct {
action ItemAction
item string
size uint64
}
type itemTrace []itemTraceEntry
type mockPrinter struct {
trace printerTrace
items itemTrace
}
const mockFinishDuration = 42 * time.Second
@ -25,95 +33,109 @@ const mockFinishDuration = 42 * time.Second
func (p *mockPrinter) Update(progress State, duration time.Duration) {
p.trace = append(p.trace, printerTraceEntry{progress, duration, false})
}
func (p *mockPrinter) CompleteItem(action ItemAction, item string, size uint64) {
p.items = append(p.items, itemTraceEntry{action, item, size})
}
func (p *mockPrinter) Finish(progress State, _ time.Duration) {
p.trace = append(p.trace, printerTraceEntry{progress, mockFinishDuration, true})
}
func testProgress(fn func(progress *Progress) bool) printerTrace {
func testProgress(fn func(progress *Progress) bool) (printerTrace, itemTrace) {
printer := &mockPrinter{}
progress := NewProgress(printer, 0)
final := fn(progress)
progress.update(0, final)
trace := append(printerTrace{}, printer.trace...)
items := append(itemTrace{}, printer.items...)
// cleanup to avoid goroutine leak, but copy trace first
progress.Finish()
return trace
return trace, items
}
func TestNew(t *testing.T) {
result := testProgress(func(progress *Progress) bool {
result, items := testProgress(func(progress *Progress) bool {
return false
})
test.Equals(t, printerTrace{
printerTraceEntry{State{0, 0, 0, 0, 0, 0}, 0, false},
}, result)
test.Equals(t, itemTrace{}, items)
}
func TestAddFile(t *testing.T) {
fileSize := uint64(100)
result := testProgress(func(progress *Progress) bool {
result, items := testProgress(func(progress *Progress) bool {
progress.AddFile(fileSize)
return false
})
test.Equals(t, printerTrace{
printerTraceEntry{State{0, 1, 0, 0, fileSize, 0}, 0, false},
}, result)
test.Equals(t, itemTrace{}, items)
}
func TestFirstProgressOnAFile(t *testing.T) {
expectedBytesWritten := uint64(5)
expectedBytesTotal := uint64(100)
result := testProgress(func(progress *Progress) bool {
result, items := testProgress(func(progress *Progress) bool {
progress.AddFile(expectedBytesTotal)
progress.AddProgress("test", expectedBytesWritten, expectedBytesTotal)
progress.AddProgress("test", false, false, expectedBytesWritten, expectedBytesTotal)
return false
})
test.Equals(t, printerTrace{
printerTraceEntry{State{0, 1, 0, expectedBytesWritten, expectedBytesTotal, 0}, 0, false},
}, result)
test.Equals(t, itemTrace{}, items)
}
func TestLastProgressOnAFile(t *testing.T) {
fileSize := uint64(100)
result := testProgress(func(progress *Progress) bool {
result, items := testProgress(func(progress *Progress) bool {
progress.AddFile(fileSize)
progress.AddProgress("test", 30, fileSize)
progress.AddProgress("test", 35, fileSize)
progress.AddProgress("test", 35, fileSize)
progress.AddProgress("test", false, false, 30, fileSize)
progress.AddProgress("test", false, false, 35, fileSize)
progress.AddProgress("test", false, false, 35, fileSize)
return false
})
test.Equals(t, printerTrace{
printerTraceEntry{State{1, 1, 0, fileSize, fileSize, 0}, 0, false},
}, result)
test.Equals(t, itemTrace{
itemTraceEntry{action: ActionFileUpdated, item: "test", size: fileSize},
}, items)
}
func TestLastProgressOnLastFile(t *testing.T) {
fileSize := uint64(100)
result := testProgress(func(progress *Progress) bool {
result, items := 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)
progress.AddProgress("test1", false, false, 50, 50)
progress.AddProgress("test2", false, false, 50, fileSize)
progress.AddProgress("test2", false, false, 50, fileSize)
return false
})
test.Equals(t, printerTrace{
printerTraceEntry{State{2, 2, 0, 50 + fileSize, 50 + fileSize, 0}, 0, false},
}, result)
test.Equals(t, itemTrace{
itemTraceEntry{action: ActionFileUpdated, item: "test1", size: 50},
itemTraceEntry{action: ActionFileUpdated, item: "test2", size: fileSize},
}, items)
}
func TestSummaryOnSuccess(t *testing.T) {
fileSize := uint64(100)
result := testProgress(func(progress *Progress) bool {
result, _ := testProgress(func(progress *Progress) bool {
progress.AddFile(fileSize)
progress.AddFile(50)
progress.AddProgress("test1", 50, 50)
progress.AddProgress("test2", fileSize, fileSize)
progress.AddProgress("test1", false, false, 50, 50)
progress.AddProgress("test2", false, false, fileSize, fileSize)
return true
})
test.Equals(t, printerTrace{
@ -124,11 +146,11 @@ func TestSummaryOnSuccess(t *testing.T) {
func TestSummaryOnErrors(t *testing.T) {
fileSize := uint64(100)
result := testProgress(func(progress *Progress) bool {
result, _ := testProgress(func(progress *Progress) bool {
progress.AddFile(fileSize)
progress.AddFile(50)
progress.AddProgress("test1", 50, 50)
progress.AddProgress("test2", fileSize/2, fileSize)
progress.AddProgress("test1", false, false, 50, 50)
progress.AddProgress("test2", false, false, fileSize/2, fileSize)
return true
})
test.Equals(t, printerTrace{
@ -139,11 +161,30 @@ func TestSummaryOnErrors(t *testing.T) {
func TestSkipFile(t *testing.T) {
fileSize := uint64(100)
result := testProgress(func(progress *Progress) bool {
progress.AddSkippedFile(fileSize)
result, items := testProgress(func(progress *Progress) bool {
progress.AddSkippedFile("test", fileSize)
return true
})
test.Equals(t, printerTrace{
printerTraceEntry{State{0, 0, 1, 0, 0, fileSize}, mockFinishDuration, true},
}, result)
test.Equals(t, itemTrace{
itemTraceEntry{ActionFileUnchanged, "test", fileSize},
}, items)
}
func TestProgressTypes(t *testing.T) {
fileSize := uint64(100)
_, items := testProgress(func(progress *Progress) bool {
progress.AddFile(fileSize)
progress.AddFile(0)
progress.AddProgress("dir", true, false, fileSize, fileSize)
progress.AddProgress("new", false, true, 0, 0)
return true
})
test.Equals(t, itemTrace{
itemTraceEntry{ActionDirRestored, "dir", fileSize},
itemTraceEntry{ActionFileRestored, "new", 0},
}, items)
}

View file

@ -8,12 +8,14 @@ import (
)
type textPrinter struct {
terminal term
terminal term
verbosity uint
}
func NewTextProgress(terminal term) ProgressPrinter {
func NewTextProgress(terminal term, verbosity uint) ProgressPrinter {
return &textPrinter{
terminal: terminal,
terminal: terminal,
verbosity: verbosity,
}
}
@ -31,6 +33,32 @@ func (t *textPrinter) Update(p State, duration time.Duration) {
t.terminal.SetStatus([]string{progress})
}
func (t *textPrinter) CompleteItem(messageType ItemAction, item string, size uint64) {
if t.verbosity < 3 {
return
}
var action string
switch messageType {
case ActionDirRestored:
action = "restored"
case ActionFileRestored:
action = "restored"
case ActionFileUpdated:
action = "updated"
case ActionFileUnchanged:
action = "unchanged"
default:
panic("unknown message type")
}
if messageType == ActionDirRestored {
t.terminal.Print(fmt.Sprintf("restored %v", item))
} else {
t.terminal.Print(fmt.Sprintf("%-9v %v with size %v", action, item, ui.FormatBytes(size)))
}
}
func (t *textPrinter) Finish(p State, duration time.Duration) {
t.terminal.SetStatus([]string{})

View file

@ -19,37 +19,55 @@ func (m *mockTerm) SetStatus(lines []string) {
m.output = append([]string{}, lines...)
}
func TestPrintUpdate(t *testing.T) {
func createTextProgress() (*mockTerm, ProgressPrinter) {
term := &mockTerm{}
printer := NewTextProgress(term)
printer := NewTextProgress(term, 3)
return term, printer
}
func TestPrintUpdate(t *testing.T) {
term, printer := createTextProgress()
printer.Update(State{3, 11, 0, 29, 47, 0}, 5*time.Second)
test.Equals(t, []string{"[0:05] 61.70% 3 files/dirs 29 B, total 11 files/dirs 47 B"}, term.output)
}
func TestPrintUpdateWithSkipped(t *testing.T) {
term := &mockTerm{}
printer := NewTextProgress(term)
term, printer := createTextProgress()
printer.Update(State{3, 11, 2, 29, 47, 59}, 5*time.Second)
test.Equals(t, []string{"[0:05] 61.70% 3 files/dirs 29 B, total 11 files/dirs 47 B, skipped 2 files/dirs 59 B"}, term.output)
}
func TestPrintSummaryOnSuccess(t *testing.T) {
term := &mockTerm{}
printer := NewTextProgress(term)
term, printer := createTextProgress()
printer.Finish(State{11, 11, 0, 47, 47, 0}, 5*time.Second)
test.Equals(t, []string{"Summary: Restored 11 files/dirs (47 B) in 0:05"}, term.output)
}
func TestPrintSummaryOnErrors(t *testing.T) {
term := &mockTerm{}
printer := NewTextProgress(term)
term, printer := createTextProgress()
printer.Finish(State{3, 11, 0, 29, 47, 0}, 5*time.Second)
test.Equals(t, []string{"Summary: Restored 3 / 11 files/dirs (29 B / 47 B) in 0:05"}, term.output)
}
func TestPrintSummaryOnSuccessWithSkipped(t *testing.T) {
term := &mockTerm{}
printer := NewTextProgress(term)
term, printer := createTextProgress()
printer.Finish(State{11, 11, 2, 47, 47, 59}, 5*time.Second)
test.Equals(t, []string{"Summary: Restored 11 files/dirs (47 B) in 0:05, skipped 2 files/dirs 59 B"}, term.output)
}
func TestPrintCompleteItem(t *testing.T) {
for _, data := range []struct {
action ItemAction
size uint64
expected string
}{
{ActionDirRestored, 0, "restored test"},
{ActionFileRestored, 123, "restored test with size 123 B"},
{ActionFileUpdated, 123, "updated test with size 123 B"},
{ActionFileUnchanged, 123, "unchanged test with size 123 B"},
} {
term, printer := createTextProgress()
printer.CompleteItem(data.action, "test", data.size)
test.Equals(t, []string{data.expected}, term.output)
}
}