Merge pull request #3199 from MichaelEischer/non-interactive-counter

Don't print progress on non-interactive terminals

changelog/unreleased/issue-2706

@@ -0,0 +1,16 @@
+Enhancement: Configurable progress reports for non-interactive terminals
+
+The `backup`, `check` and `prune` commands never printed any progress
+reports on non-interactive terminals. This behavior is now configurable
+using the `RESTIC_PROGRESS_FPS` environment variable. Use for example a
+value of `1` for an update per second or `0.01666` for an update per minute.
+
+The `backup` command now also prints the current progress when restic
+receives a `SIGUSR1` signal.
+
+Setting the `RESTIC_PROGRESS_FPS` environment variable or sending a `SIGUSR1`
+signal prints a status report even when `--quiet` was specified.
+
+https://github.com/restic/restic/issues/2706
+https://github.com/restic/restic/issues/3194
+https://github.com/restic/restic/pull/3199

cmd/restic/cmd_backup.go

@@ -11,7 +11,6 @@ import (
 	"path"
 	"path/filepath"
 	"runtime"
-	"strconv"
 	"strings"
 	"time"
 
@@ -545,15 +544,7 @@ func runBackup(opts BackupOptions, gopts GlobalOptions, term *termstatus.Termina
 	}()
 	gopts.stdout, gopts.stderr = p.Stdout(), p.Stderr()
 
-	if s, ok := os.LookupEnv("RESTIC_PROGRESS_FPS"); ok {
+	p.SetMinUpdatePause(calculateProgressInterval())
-		fps, err := strconv.Atoi(s)
-		if err == nil && fps >= 1 {
-			if fps > 60 {
-				fps = 60
-			}
-			p.SetMinUpdatePause(time.Second / time.Duration(fps))
-		}
-	}
 
 	t.Go(func() error { return p.Run(t.Context(gopts.ctx)) })
 

cmd/restic/progress.go

@@ -9,24 +9,29 @@ import (
 	"github.com/restic/restic/internal/ui/progress"
 )
 
+// calculateProgressInterval returns the interval configured via RESTIC_PROGRESS_FPS
+// or if unset returns an interval for 60fps on interactive terminals and 0 (=disabled)
+// for non-interactive terminals
+func calculateProgressInterval() time.Duration {
+	interval := time.Second / 60
+	fps, err := strconv.ParseFloat(os.Getenv("RESTIC_PROGRESS_FPS"), 64)
+	if err == nil && fps > 0 {
+		if fps > 60 {
+			fps = 60
+		}
+		interval = time.Duration(float64(time.Second) / fps)
+	} else if !stdoutIsTerminal() {
+		interval = 0
+	}
+	return interval
+}
+
 // newProgressMax returns a progress.Counter that prints to stdout.
 func newProgressMax(show bool, max uint64, description string) *progress.Counter {
 	if !show {
 		return nil
 	}
-
+	interval := calculateProgressInterval()
-	interval := time.Second / 60
-	if !stdoutIsTerminal() {
-		interval = time.Second
-	} else {
-		fps, err := strconv.ParseInt(os.Getenv("RESTIC_PROGRESS_FPS"), 10, 64)
-		if err == nil && fps >= 1 {
-			if fps > 60 {
-				fps = 60
-			}
-			interval = time.Second / time.Duration(fps)
-		}
-	}
 
 	return progress.New(interval, func(v uint64, d time.Duration, final bool) {
 		status := fmt.Sprintf("[%s] %s  %d / %d %s",

doc/manual_rest.rst

@@ -133,18 +133,21 @@ command:
           --tls-client-cert file       path to a file containing PEM encoded TLS client certificate and private key
       -v, --verbose n                  be verbose (specify multiple times or a level using --verbose=n, max level/times is 3)
 
-Subcommand that support showing progress information such as ``backup``,
+Subcommands 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
+reporting is disabled by default to not fill your logs. For interactive
-logs. Use ``backup`` with the quiet flag ``-q`` or ``--quiet`` to skip
+and non-interactive consoles the environment variable ``RESTIC_PROGRESS_FPS``
-the initial scan of the source directory, this may shorten the backup
+can be used to control the frequency of progress reporting. Use for example
-time needed for large directories.
+``0.016666`` to only update the progress once per minute.
 
-Additionally on Unix systems if ``restic`` receives a SIGUSR1 signal the
+Additionally, on Unix systems if ``restic`` receives a SIGUSR1 signal the
 current progress will be written to the standard output so you can check up
 on the status at will.
 
+Setting the `RESTIC_PROGRESS_FPS` environment variable or sending a `SIGUSR1`
+signal prints a status report even when `--quiet` was specified.
+
 Manage tags
 -----------
 

internal/ui/backup.go

@@ -10,6 +10,7 @@ import (
 
 	"github.com/restic/restic/internal/archiver"
 	"github.com/restic/restic/internal/restic"
+	"github.com/restic/restic/internal/ui/signals"
 	"github.com/restic/restic/internal/ui/termstatus"
 )
 
@@ -31,7 +32,6 @@ type Backup struct {
 	MinUpdatePause time.Duration
 
 	term  *termstatus.Terminal
-	v     uint
 	start time.Time
 
 	totalBytes uint64
@@ -40,7 +40,6 @@ type Backup struct {
 	processedCh chan counter
 	errCh       chan struct{}
 	workerCh    chan fileWorkerMessage
-	finished    chan struct{}
 	closed      chan struct{}
 
 	summary struct {
@@ -61,7 +60,6 @@ func NewBackup(term *termstatus.Terminal, verbosity uint) *Backup {
 		Message:      NewMessage(term, verbosity),
 		StdioWrapper: NewStdioWrapper(term),
 		term:         term,
-		v:            verbosity,
 		start:        time.Now(),
 
 		// limit to 60fps by default
@@ -71,7 +69,6 @@ func NewBackup(term *termstatus.Terminal, verbosity uint) *Backup {
 		processedCh: make(chan counter),
 		errCh:       make(chan struct{}),
 		workerCh:    make(chan fileWorkerMessage),
-		finished:    make(chan struct{}),
 		closed:      make(chan struct{}),
 	}
 }
@@ -89,18 +86,22 @@ func (b *Backup) Run(ctx context.Context) error {
 	)
 
 	t := time.NewTicker(time.Second)
+	signalsCh := signals.GetProgressChannel()
 	defer t.Stop()
 	defer close(b.closed)
 	// Reset status when finished
-	defer b.term.SetStatus([]string{""})
+	defer func() {
+		if b.term.CanUpdateStatus() {
+			b.term.SetStatus([]string{""})
+		}
+	}()
 
 	for {
+		forceUpdate := false
+
 		select {
 		case <-ctx.Done():
 			return nil
-		case <-b.finished:
-			started = false
-			b.term.SetStatus([]string{""})
 		case t, ok := <-b.totalCh:
 			if ok {
 				total = t
@@ -134,10 +135,12 @@ func (b *Backup) Run(ctx context.Context) error {
 				todo := float64(total.Bytes - processed.Bytes)
 				secondsRemaining = uint64(secs / float64(processed.Bytes) * todo)
 			}
+		case <-signalsCh:
+			forceUpdate = true
 		}
 
 		// limit update frequency
-		if time.Since(lastUpdate) < b.MinUpdatePause {
+		if !forceUpdate && (time.Since(lastUpdate) < b.MinUpdatePause || b.MinUpdatePause == 0) {
 			continue
 		}
 		lastUpdate = time.Now()
@@ -374,10 +377,8 @@ func (b *Backup) ReportTotal(item string, s archiver.ScanStats) {
 
 // Finish prints the finishing messages.
 func (b *Backup) Finish(snapshotID restic.ID) {
-	select {
+	// wait for the status update goroutine to shut down
-	case b.finished <- struct{}{}:
+	<-b.closed
-	case <-b.closed:
-	}
 
 	b.P("\n")
 	b.P("Files:       %5d new, %5d changed, %5d unmodified\n", b.summary.Files.New, b.summary.Files.Changed, b.summary.Files.Unchanged)

internal/ui/progress/counter.go

@@ -1,11 +1,11 @@
 package progress
 
 import (
-	"os"
 	"sync"
 	"time"
 
 	"github.com/restic/restic/internal/debug"
+	"github.com/restic/restic/internal/ui/signals"
 )
 
 // A Func is a callback for a Counter.
@@ -31,17 +31,14 @@ type Counter struct {
 
 // New starts a new Counter.
 func New(interval time.Duration, report Func) *Counter {
-	signals.Once.Do(func() {
-		signals.ch = make(chan os.Signal, 1)
-		setupSignals()
-	})
-
 	c := &Counter{
 		report:  report,
 		start:   time.Now(),
 		stopped: make(chan struct{}),
 		stop:    make(chan struct{}),
-		tick:    time.NewTicker(interval),
+	}
+	if interval > 0 {
+		c.tick = time.NewTicker(interval)
 	}
 
 	go c.run()
@@ -64,7 +61,9 @@ func (c *Counter) Done() {
 	if c == nil {
 		return
 	}
+	if c.tick != nil {
 		c.tick.Stop()
+	}
 	close(c.stop)
 	<-c.stopped    // Wait for last progress report.
 	*c = Counter{} // Prevent reuse.
@@ -85,12 +84,17 @@ func (c *Counter) run() {
 		c.report(c.get(), time.Since(c.start), true)
 	}()
 
+	var tick <-chan time.Time
+	if c.tick != nil {
+		tick = c.tick.C
+	}
+	signalsCh := signals.GetProgressChannel()
 	for {
 		var now time.Time
 
 		select {
-		case now = <-c.tick.C:
+		case now = <-tick:
-		case sig := <-signals.ch:
+		case sig := <-signalsCh:
 			debug.Log("Signal received: %v\n", sig)
 			now = time.Now()
 		case <-c.stop:
@@ -100,10 +104,3 @@ func (c *Counter) run() {
 		c.report(c.get(), now.Sub(c.start), false)
 	}
 }
-
-// XXX The fact that signals is a single global variable means that only one
-// Counter receives each incoming signal.
-var signals struct {
-	ch chan os.Signal
-	sync.Once
-}

internal/ui/progress/counter_test.go

@@ -53,3 +53,22 @@ func TestCounterNil(t *testing.T) {
 	c.Add(1)
 	c.Done()
 }
+
+func TestCounterNoTick(t *testing.T) {
+	finalSeen := false
+	otherSeen := false
+
+	report := func(value uint64, d time.Duration, final bool) {
+		if final {
+			finalSeen = true
+		} else {
+			otherSeen = true
+		}
+	}
+	c := progress.New(0, report)
+	time.Sleep(time.Millisecond)
+	c.Done()
+
+	test.Assert(t, finalSeen, "final call did not happen")
+	test.Assert(t, !otherSeen, "unexpected status update")
+}

internal/ui/signals/signals.go

@@ -0,0 +1,24 @@
+package signals
+
+import (
+	"os"
+	"sync"
+)
+
+// GetProgressChannel returns a channel with which a single listener
+// receives each incoming signal.
+func GetProgressChannel() <-chan os.Signal {
+	signals.Once.Do(func() {
+		signals.ch = make(chan os.Signal, 1)
+		setupSignals()
+	})
+
+	return signals.ch
+}
+
+// XXX The fact that signals is a single global variable means that only one
+// listener receives each incoming signal.
+var signals struct {
+	ch chan os.Signal
+	sync.Once
+}

internal/ui/signals/signals_bsd.go

@@ -1,6 +1,6 @@
 // +build darwin dragonfly freebsd netbsd openbsd
 
-package progress
+package signals
 
 import (
 	"os/signal"

internal/ui/signals/signals_sysv.go

@@ -1,6 +1,6 @@
 // +build aix linux solaris
 
-package progress
+package signals
 
 import (
 	"os/signal"

internal/ui/signals/signals_windows.go

@@ -1,3 +1,3 @@
-package progress
+package signals
 
 func setupSignals() {}

internal/ui/termstatus/status.go

@@ -78,6 +78,11 @@ func New(wr io.Writer, errWriter io.Writer, disableStatus bool) *Terminal {
 	return t
 }
 
+// CanUpdateStatus return whether the status output is updated in place.
+func (t *Terminal) CanUpdateStatus() bool {
+	return t.canUpdateStatus
+}
+
 // Run updates the screen. It should be run in a separate goroutine. When
 // ctx is cancelled, the status lines are cleanly removed.
 func (t *Terminal) Run(ctx context.Context) {
@@ -203,8 +208,15 @@ func (t *Terminal) runWithoutStatus(ctx context.Context) {
 				fmt.Fprintf(os.Stderr, "flush failed: %v\n", err)
 			}
 
-		case <-t.status:
+		case stat := <-t.status:
-			// discard status lines
+			for _, line := range stat.lines {
+				// ensure that each line ends with newline
+				withNewline := strings.TrimRight(line, "\n") + "\n"
+				fmt.Fprint(t.wr, withNewline)
+			}
+			if err := t.wr.Flush(); err != nil {
+				fmt.Fprintf(os.Stderr, "flush failed: %v\n", err)
+			}
 		}
 	}
 }
@@ -302,17 +314,24 @@ func (t *Terminal) SetStatus(lines []string) {
 		return
 	}
 
-	width, _, err := terminal.GetSize(int(t.fd))
+	// only truncate interactive status output
+	var width int
+	if t.canUpdateStatus {
+		var err error
+		width, _, err = terminal.GetSize(int(t.fd))
 		if err != nil || width <= 0 {
 			// use 80 columns by default
 			width = 80
 		}
+	}
 
 	// make sure that all lines have a line break and are not too long
 	for i, line := range lines {
 		line = strings.TrimRight(line, "\n")
-		line = truncate(line, width-2) + "\n"
+		if width > 0 {
-		lines[i] = line
+			line = truncate(line, width-2)
+		}
+		lines[i] = line + "\n"
 	}
 
 	// make sure the last line does not have a line break