Merge pull request #585 from trbs/progress_without_terminal

show progress every second when run non interactively

doc/Manual.md

@@ -89,6 +89,14 @@ them, e.g. for the `backup` command:
           -f, --force    Force re-reading the target. Overrides the "parent" flag
           -e, --exclude= Exclude a pattern (can be specified multiple times)
 
+Subcommand that support showing progress information such as `backup`, `check` and `prune` will do so unless
+the quiet flag `-q` or `--quiet` is set. When running from a non-interactive console progress reporting will
+be limited to once every 10 seconds to not fill your logs.
+
+Additionally on Unix systems if `restic` receives a SIGUSR signal the current progress will written to the
+standard output so you can check up on the status at will.
+
+
 # Initialize a repository
 
 First, we need to create a "repository". This is the place where your backups

src/cmds/restic/cmd_backup.go

@@ -112,12 +112,12 @@ func (cmd CmdBackup) newScanProgress() *restic.Progress {
 		return nil
 	}
 
-	p := restic.NewProgress(time.Second)
+	p := restic.NewProgress()
 	p.OnUpdate = func(s restic.Stat, d time.Duration, ticker bool) {
-		fmt.Printf("%s[%s] %d directories, %d files, %s\r", ClearLine(), formatDuration(d), s.Dirs, s.Files, formatBytes(s.Bytes))
+		PrintProgress("[%s] %d directories, %d files, %s", formatDuration(d), s.Dirs, s.Files, formatBytes(s.Bytes))
 	}
 	p.OnDone = func(s restic.Stat, d time.Duration, ticker bool) {
-		fmt.Printf("%sscanned %d directories, %d files in %s\n", ClearLine(), s.Dirs, s.Files, formatDuration(d))
+		PrintProgress("scanned %d directories, %d files in %s\n", s.Dirs, s.Files, formatDuration(d))
 	}
 
 	return p
@@ -128,7 +128,7 @@ func (cmd CmdBackup) newArchiveProgress(todo restic.Stat) *restic.Progress {
 		return nil
 	}
 
-	archiveProgress := restic.NewProgress(time.Second)
+	archiveProgress := restic.NewProgress()
 
 	var bps, eta uint64
 	itemsTodo := todo.Files + todo.Dirs
@@ -167,7 +167,7 @@ func (cmd CmdBackup) newArchiveProgress(todo restic.Stat) *restic.Progress {
 			}
 		}
 
-		fmt.Printf("%s%s%s\r", ClearLine(), status1, status2)
+		PrintProgress("%s%s", status1, status2)
 	}
 
 	archiveProgress.OnDone = func(s restic.Stat, d time.Duration, ticker bool) {
@@ -182,7 +182,7 @@ func (cmd CmdBackup) newArchiveStdinProgress() *restic.Progress {
 		return nil
 	}
 
-	archiveProgress := restic.NewProgress(time.Second)
+	archiveProgress := restic.NewProgress()
 
 	var bps uint64
 
@@ -208,7 +208,7 @@ func (cmd CmdBackup) newArchiveStdinProgress() *restic.Progress {
 			}
 		}
 
-		fmt.Printf("%s%s\r", ClearLine(), status1)
+		PrintProgress("%s%s", status1)
 	}
 
 	archiveProgress.OnDone = func(s restic.Stat, d time.Duration, ticker bool) {

src/cmds/restic/cmd_check.go

@@ -38,7 +38,7 @@ func (cmd CmdCheck) newReadProgress(todo restic.Stat) *restic.Progress {
 		return nil
 	}
 
-	readProgress := restic.NewProgress(time.Second)
+	readProgress := restic.NewProgress()
 
 	readProgress.OnUpdate = func(s restic.Stat, d time.Duration, ticker bool) {
 		status := fmt.Sprintf("[%s] %s  %d / %d items",
@@ -54,7 +54,7 @@ func (cmd CmdCheck) newReadProgress(todo restic.Stat) *restic.Progress {
 			}
 		}
 
-		fmt.Printf("%s%s\r", ClearLine(), status)
+		PrintProgress("%s", status)
 	}
 
 	readProgress.OnDone = func(s restic.Stat, d time.Duration, ticker bool) {

src/cmds/restic/cmd_prune.go

@@ -39,7 +39,7 @@ func newProgressMax(show bool, max uint64, description string) *restic.Progress
 		return nil
 	}
 
-	p := restic.NewProgress(time.Second)
+	p := restic.NewProgress()
 
 	p.OnUpdate = func(s restic.Stat, d time.Duration, ticker bool) {
 		status := fmt.Sprintf("[%s] %s  %d / %d %s",
@@ -55,7 +55,7 @@ func newProgressMax(show bool, max uint64, description string) *restic.Progress
 			}
 		}
 
-		fmt.Printf("%s%s\r", ClearLine(), status)
+		PrintProgress("%s", status)
 	}
 
 	p.OnDone = func(s restic.Stat, d time.Duration, ticker bool) {

src/cmds/restic/global.go

@@ -24,6 +24,7 @@ import (
 
 var version = "compiled manually"
 var compiledAt = "unknown time"
+var isTerminal = terminal.IsTerminal(int(os.Stdout.Fd()))
 
 // GlobalOptions holds all those options that can be set for every command.
 type GlobalOptions struct {
@@ -60,11 +61,11 @@ func checkErrno(err error) error {
 // restoreTerminal installs a cleanup handler that restores the previous
 // terminal state on exit.
 func restoreTerminal() {
-	fd := int(os.Stdout.Fd())
-	if !terminal.IsTerminal(fd) {
+	if !isTerminal {
 		return
 	}
 
+	fd := int(os.Stdout.Fd())
 	state, err := terminal.GetState(fd)
 	if err != nil {
 		fmt.Fprintf(os.Stderr, "unable to get terminal state: %v\n", err)
@@ -116,17 +117,38 @@ func (o GlobalOptions) Verbosef(format string, args ...interface{}) {
 }
 
 // ShowProgress returns true iff the progress status should be written, i.e.
-// the quiet flag is not set and the output is a terminal.
+// the quiet flag is not set.
 func (o GlobalOptions) ShowProgress() bool {
 	if o.Quiet {
 		return false
 	}
 
-	if !terminal.IsTerminal(int(os.Stdout.Fd())) {
-		return false
+	return true
+}
+
+// PrintProgress wraps fmt.Printf to handle the difference in writing progress
+// information to terminals and non-terminal stdout
+func PrintProgress(format string, args ...interface{}) {
+	var (
+		message         string
+		carriageControl string
+	)
+	message = fmt.Sprintf(format, args...)
+
+	if !(strings.HasSuffix(message, "\r") || strings.HasSuffix(message, "\n")) {
+		if isTerminal {
+			carriageControl = "\r"
+		} else {
+			carriageControl = "\n"
+		}
+		message = fmt.Sprintf("%s%s", message, carriageControl)
 	}
 
-	return true
+	if isTerminal {
+		message = fmt.Sprintf("%s%s", ClearLine(), message)
+	}
+
+	fmt.Print(message)
 }
 
 // Warnf writes the message to the configured stderr stream.
@@ -183,7 +205,7 @@ func (o GlobalOptions) ReadPassword(prompt string) string {
 		err      error
 	)
 
-	if terminal.IsTerminal(int(os.Stdin.Fd())) {
+	if isTerminal {
 		password, err = readPasswordTerminal(os.Stdin, os.Stderr, prompt)
 	} else {
 		password, err = readPassword(os.Stdin)

src/restic/progress.go

@@ -2,12 +2,17 @@ package restic
 
 import (
 	"fmt"
+	"golang.org/x/crypto/ssh/terminal"
+	"os"
 	"sync"
 	"time"
 )
 
 const minTickerTime = time.Second / 60
 
+var isTerminal = terminal.IsTerminal(int(os.Stdout.Fd()))
+var forceUpdateProgress = make(chan bool)
+
 type Progress struct {
 	OnStart  func()
 	OnUpdate ProgressFunc
@@ -42,7 +47,14 @@ type ProgressFunc func(s Stat, runtime time.Duration, ticker bool)
 // called when new data arrives or at least every d interval. The function
 // OnDone is called when Done() is called. Both functions are called
 // synchronously and can use shared state.
-func NewProgress(d time.Duration) *Progress {
+func NewProgress() *Progress {
+	var d time.Duration
+	if !isTerminal {
+		// TODO: make the duration for non-terminal progress (user) configurable
+		d = time.Duration(10) * time.Second
+	} else {
+		d = time.Second
+	}
 	return &Progress{d: d}
 }
 
@@ -96,7 +108,7 @@ func (p *Progress) Report(s Stat) {
 	p.cur.Add(s)
 	cur := p.cur
 	needUpdate := false
-	if time.Since(p.lastUpdate) > minTickerTime {
+	if isTerminal && time.Since(p.lastUpdate) > minTickerTime {
 		p.lastUpdate = time.Now()
 		needUpdate = true
 	}
@@ -123,13 +135,19 @@ func (p *Progress) reporter() {
 		return
 	}
 
+	updateProgress := func() {
+		p.curM.Lock()
+		cur := p.cur
+		p.curM.Unlock()
+		p.updateProgress(cur, true)
+	}
+
 	for {
 		select {
 		case <-p.c.C:
-			p.curM.Lock()
-			cur := p.cur
-			p.curM.Unlock()
-			p.updateProgress(cur, true)
+			updateProgress()
+		case <-forceUpdateProgress:
+			updateProgress()
 		case <-p.cancel:
 			p.c.Stop()
 			return

src/restic/progress_unix.go

@@ -0,0 +1,22 @@
+// +build !windows
+
+package restic
+
+import (
+	"os"
+	"os/signal"
+	"syscall"
+
+	"restic/debug"
+)
+
+func init() {
+	c := make(chan os.Signal)
+	signal.Notify(c, syscall.SIGUSR1)
+	go func() {
+		for s := range c {
+			debug.Log("progress.handleSIGUSR1", "Signal received: %v\n", s)
+			forceUpdateProgress <- true
+		}
+	}()
+}