diff --git a/changelog/unreleased/issue-2389 b/changelog/unreleased/issue-2389 new file mode 100644 index 000000000..194820735 --- /dev/null +++ b/changelog/unreleased/issue-2389 @@ -0,0 +1,8 @@ +Bugfix: Fix mangled json output of backup command + +We've fixed a race condition in the json output of the backup command +that could cause multiple lines to get mixed up. We've also ensured that +the backup summary is printed last. + +https://github.com/restic/restic/issues/2389 +https://github.com/restic/restic/pull/2545 diff --git a/cmd/restic/cmd_backup.go b/cmd/restic/cmd_backup.go index 25984b623..a3a864449 100644 --- a/cmd/restic/cmd_backup.go +++ b/cmd/restic/cmd_backup.go @@ -25,7 +25,7 @@ import ( "github.com/restic/restic/internal/restic" "github.com/restic/restic/internal/textfile" "github.com/restic/restic/internal/ui" - "github.com/restic/restic/internal/ui/jsonstatus" + "github.com/restic/restic/internal/ui/json" "github.com/restic/restic/internal/ui/termstatus" ) @@ -447,7 +447,7 @@ func runBackup(opts BackupOptions, gopts GlobalOptions, term *termstatus.Termina var p ArchiveProgressReporter if gopts.JSON { - p = jsonstatus.NewBackup(term, gopts.verbosity) + p = json.NewBackup(term, gopts.verbosity) } else { p = ui.NewBackup(term, gopts.verbosity) } @@ -601,19 +601,18 @@ func runBackup(opts BackupOptions, gopts GlobalOptions, term *termstatus.Termina return errors.Fatalf("unable to save snapshot: %v", err) } - p.Finish(id) - if !gopts.JSON { - p.P("snapshot %s saved\n", id.Str()) - } - // cleanly shutdown all running goroutines t.Kill(nil) // let's see if one returned an error err = t.Wait() - if err != nil { - return err + + // Report finished execution + p.Finish(id) + if !gopts.JSON { + p.P("snapshot %s saved\n", id.Str()) } - return nil + // Return error if any + return err } diff --git a/internal/ui/jsonstatus/status.go b/internal/ui/json/backup.go similarity index 93% rename from internal/ui/jsonstatus/status.go rename to internal/ui/json/backup.go index ec1fb64be..ff7af18c4 100644 --- a/internal/ui/jsonstatus/status.go +++ b/internal/ui/json/backup.go @@ -1,6 +1,7 @@ -package jsonstatus +package json import ( + "bytes" "context" "encoding/json" "os" @@ -74,6 +75,20 @@ func NewBackup(term *termstatus.Terminal, verbosity uint) *Backup { } } +func toJSONString(status interface{}) string { + buf := new(bytes.Buffer) + json.NewEncoder(buf).Encode(status) + return buf.String() +} + +func (b *Backup) print(status interface{}) { + b.term.Print(toJSONString(status)) +} + +func (b *Backup) error(status interface{}) { + b.term.Error(toJSONString(status)) +} + // Run regularly updates the status lines. It should be called in a separate // goroutine. func (b *Backup) Run(ctx context.Context) error { @@ -162,13 +177,13 @@ func (b *Backup) update(total, processed counter, errors uint, currentFiles map[ } sort.Strings(status.CurrentFiles) - json.NewEncoder(b.StdioWrapper.Stdout()).Encode(status) + b.print(status) } // ScannerError is the error callback function for the scanner, it prints the // error in verbose mode and returns nil. func (b *Backup) ScannerError(item string, fi os.FileInfo, err error) error { - json.NewEncoder(b.StdioWrapper.Stderr()).Encode(errorUpdate{ + b.error(errorUpdate{ MessageType: "error", Error: err, During: "scan", @@ -179,7 +194,7 @@ func (b *Backup) ScannerError(item string, fi os.FileInfo, err error) error { // Error is the error callback function for the archiver, it prints the error and returns nil. func (b *Backup) Error(item string, fi os.FileInfo, err error) error { - json.NewEncoder(b.StdioWrapper.Stderr()).Encode(errorUpdate{ + b.error(errorUpdate{ MessageType: "error", Error: err, During: "archival", @@ -233,7 +248,7 @@ func (b *Backup) CompleteItem(item string, previous, current *restic.Node, s arc if current.Type == "dir" { if previous == nil { if b.v >= 3 { - json.NewEncoder(b.StdioWrapper.Stdout()).Encode(verboseUpdate{ + b.print(verboseUpdate{ MessageType: "verbose_status", Action: "new", Item: item, @@ -250,7 +265,7 @@ func (b *Backup) CompleteItem(item string, previous, current *restic.Node, s arc if previous.Equals(*current) { if b.v >= 3 { - json.NewEncoder(b.StdioWrapper.Stdout()).Encode(verboseUpdate{ + b.print(verboseUpdate{ MessageType: "verbose_status", Action: "unchanged", Item: item, @@ -261,7 +276,7 @@ func (b *Backup) CompleteItem(item string, previous, current *restic.Node, s arc b.summary.Unlock() } else { if b.v >= 3 { - json.NewEncoder(b.StdioWrapper.Stdout()).Encode(verboseUpdate{ + b.print(verboseUpdate{ MessageType: "verbose_status", Action: "modified", Item: item, @@ -284,7 +299,7 @@ func (b *Backup) CompleteItem(item string, previous, current *restic.Node, s arc if previous == nil { if b.v >= 3 { - json.NewEncoder(b.StdioWrapper.Stdout()).Encode(verboseUpdate{ + b.print(verboseUpdate{ MessageType: "verbose_status", Action: "new", Item: item, @@ -300,7 +315,7 @@ func (b *Backup) CompleteItem(item string, previous, current *restic.Node, s arc if previous.Equals(*current) { if b.v >= 3 { - json.NewEncoder(b.StdioWrapper.Stdout()).Encode(verboseUpdate{ + b.print(verboseUpdate{ MessageType: "verbose_status", Action: "unchanged", Item: item, @@ -311,7 +326,7 @@ func (b *Backup) CompleteItem(item string, previous, current *restic.Node, s arc b.summary.Unlock() } else { if b.v >= 3 { - json.NewEncoder(b.StdioWrapper.Stdout()).Encode(verboseUpdate{ + b.print(verboseUpdate{ MessageType: "verbose_status", Action: "modified", Item: item, @@ -335,7 +350,7 @@ func (b *Backup) ReportTotal(item string, s archiver.ScanStats) { if item == "" { if b.v >= 2 { - json.NewEncoder(b.StdioWrapper.Stdout()).Encode(verboseUpdate{ + b.print(verboseUpdate{ MessageType: "status", Action: "scan_finished", Duration: time.Since(b.start).Seconds(), @@ -351,7 +366,7 @@ func (b *Backup) ReportTotal(item string, s archiver.ScanStats) { // Finish prints the finishing messages. func (b *Backup) Finish(snapshotID restic.ID) { close(b.finished) - json.NewEncoder(b.StdioWrapper.Stdout()).Encode(summaryOutput{ + b.print(summaryOutput{ MessageType: "summary", FilesNew: b.summary.Files.New, FilesChanged: b.summary.Files.Changed,