Show the progress rate over the last 5 seconds, and what a phase is doing after 10 seconds with no item done (closes #125)

The rate was the phase's average, so a burst after a long wait read as
over 1,000 files a second. It now covers the items completed over the
last 5 seconds, or since the line before off a terminal, and falls to 0
while nothing completes; the ETA still comes from the average. Once no
item has completed for 10 seconds, the line says so and what the phase
is doing, a phrase each phase gives where it is defined. A narrow
terminal leaves that out after the rate, keeping the phase, progress,
elapsed time and ETA whole. The tests set the display's clock by hand.

Judgement call: the line reads "no files finished", in the phase's unit.
Judgement call: trees' group phase says "grouping directories".

Model: opus-5-5

README.md

@@ -833,17 +833,33 @@ Each display is one line holding:
 - a `[m/n] x%` display (items processed / total items, percent); before a phase
   has a total, the items processed, or what the phase is waiting for
 - current rate (items/s), naming the items the phase counts: files, records,
-  directories or groups
+  directories or groups. It covers the items completed over the last 5 seconds,
+  or, when stderr is not a terminal, since the line before, so it falls to 0
+  while nothing completes, and a burst of items after a wait shows as a burst
+  rather than as a steady rate.
+- once no item has completed for 10 seconds, how long that has been and what the
+  phase is doing (see below)
 - elapsed time
-- estimated time remaining, or `unknown`
+- estimated time remaining, or `unknown`. It comes from the phase's average rate
+  since it started counting, so that it does not swing with each burst.
 
 Example shape (exact layout is flexible, content is not):
 
 ```
 [3/5] hash: [12345/98765] 12% |████      | 92 files/s elapsed 2:32 eta 17:54
 [2/5] walk: [1234567/~1200000] 103%, 5120 files/s, elapsed 4m1s, eta unknown
+[3/5] hash: [12345/98765] 12%, 0 files/s, no files finished for 42s, reading files, elapsed 4m1s, eta 28m7s
 ```
 
+When no item has completed for 10 seconds, as while one large file is read, a
+disk is slow or the database is busy, the line says so and what the phase is
+doing: `walk` is listing directories; `hash` and the content phase's reads are
+reading files; `update` is writing to the database; `load` and the `read` phases
+of `trees` and `report` are reading the database; the content phase's checks are
+searching the database; `trees`' `group` is grouping directories, and its
+`write` is writing the report. A phase still waiting for its total already says
+what it waits for, and says nothing more.
+
 Additional requirements:
 
 - On a terminal, a phase with an exact total (every phase but `scan`'s `walk`,
@@ -857,13 +873,14 @@ Additional requirements:
 - On a terminal no line reaches the terminal's last column, however narrow the
   terminal is. The phase and its place, the progress, the elapsed time and the
   ETA are kept whole: a line too wide for the terminal leaves out its rate first
-  (or what the phase is waiting for), and a bar with no room beside those four
-  gives way to the spinner. Only when those four alone are too wide, as on a
-  terminal narrower than about 70 columns hours into a scan of millions of
-  files, is the line cut short at the terminal's edge, so the end of the ETA is
-  lost first. A terminal made narrower while a phase runs gets the same: the
-  next draw erases the line within the new width and fits the line to it, and
-  the display goes on redrawing in place.
+  (or what the phase is waiting for), then what it says of 10 seconds with no
+  item completed, and a bar with no room beside those four gives way to the
+  spinner. Only when those four alone are too wide, as on a terminal narrower
+  than about 70 columns hours into a scan of millions of files, is the line cut
+  short at the terminal's edge, so the end of the ETA is lost first. A terminal
+  made narrower while a phase runs gets the same: the next draw erases the line
+  within the new width and fits the line to it, and the display goes on
+  redrawing in place.
 - When stderr is not a terminal (a pipe, a file, `/dev/null`), do not emit ANSI
   redraws: print the line the moment each phase starts, every 5 seconds while it
   runs (whether or not an item has completed, and never more often), and once

TODO.md

@@ -29,6 +29,16 @@
 
 # Completed Steps
 
+- the rate a progress display shows covers the items completed over the last 5
+  seconds, or since the line before when stderr is not a terminal, so it falls
+  to 0 while nothing completes, and a burst after a wait no longer reads as a
+  steady rate of over 1,000 files a second; the ETA still comes from the phase's
+  average. Once no item has completed for 10 seconds, the line says how long and
+  what the phase is doing, as `no files finished for 42s, reading files`, each
+  phase naming its own work where it is defined. A line too wide for the
+  terminal leaves that out after the rate, keeping the phase, progress, elapsed
+  time and ETA whole (2026-10-16, https://git.eeqj.de/sneak/sfdupes/issues/125)
+
 - new subcommand `info` prints the database's details on stdout, one per line as
   a name, a tab and the value: its path and where it came from, the sizes of the
   database file and of its `-wal` file when there is one, when the database file

progress.go

@@ -22,6 +22,15 @@ const plainInterval = 5 * time.Second
 // a TTY.
 const redrawInterval = 100 * time.Millisecond
 
+// rateWindow is the time the rate a display shows covers: the items
+// completed over the last rateWindow, which is the time since the line
+// before when stderr is not a TTY.
+const rateWindow = 5 * time.Second
+
+// stallTime is how long a phase goes with no item completed before its
+// line says so, and what the phase is doing.
+const stallTime = 10 * time.Second
+
 // spinnerType selects the progressbar library's spinner style.
 const spinnerType = 14
 
@@ -59,6 +68,10 @@ const (
 	openingDatabase = "opening the database"
 )
 
+// readingDatabase is what the display of a phase that reads the records
+// says it is doing once no record has been read for stallTime.
+const readingDatabase = "reading the database"
+
 // stderrIsTTY reports whether stderr is attached to a terminal.
 func stderrIsTTY() bool {
 	return term.IsTerminal(int(os.Stderr.Fd()))
@@ -89,6 +102,14 @@ type progressParams struct {
 	total      int64  // the items the phase will complete; -1 when not known
 	estimate   bool   // total is an estimate, which the count may pass
 	waitingFor string // what the phase waits for until setTotal is called
+	doing      string // what the phase is doing, as "reading files"; see stallTime
+}
+
+// drawnCount is the count of items completed as of one draw, and when
+// that draw was.
+type drawnCount struct {
+	at    time.Time
+	count int64
 }
 
 // progress renders one phase's progress on stderr. On a TTY the
@@ -107,9 +128,10 @@ type progressParams struct {
 // phase's helpers without rendering anything, and its writer writes
 // with no display to clear.
 type progress struct {
-	width func() int    // reads the terminal's width; nil when not a TTY
-	stop  chan struct{} // closed by finish to end the draws
-	done  chan struct{} // closed once the draws have ended
+	now   func() time.Time // reads the time
+	width func() int       // reads the terminal's width; nil when not a TTY
+	stop  chan struct{}    // closed by finish to end the draws
+	done  chan struct{}    // closed once the draws have ended
 
 	mu         sync.Mutex
 	bar        *progressbar.ProgressBar // what the library draws; nil until then
@@ -120,33 +142,42 @@ type progress struct {
 	total      int64
 	estimate   bool
 	waitingFor string
+	doing      string
 	count      int64
 	start      time.Time // when the phase started, for the elapsed time
-	rateStart  time.Time // when the count started, for the rate
+	rateStart  time.Time // when the count started, for the ETA
+	lastItem   time.Time // when the last item was completed, or the count started
+	// drawn holds the count at each draw over the last rateWindow, oldest
+	// first; the rate counts from the first. It keeps the draw before the
+	// latest even when that is older, as the line before is when lines
+	// are plainInterval apart and a tick comes late.
+	drawn []drawnCount
 }
 
 // newProgress starts the display of one phase on stderr.
 func newProgress(params progressParams) *progress {
 	if stderrIsTTY() {
-		return startProgress(params, terminalWidth, redrawInterval)
+		return startProgress(params, terminalWidth, redrawInterval, time.Now)
 	}
 
-	return startProgress(params, nil, plainInterval)
+	return startProgress(params, nil, plainInterval, time.Now)
 }
 
 // startProgress shows the phase params describes at once, and again
 // every interval until finish: with the progressbar library on a
 // terminal, whose width each draw reads by calling width, or as a plain
-// line when width is nil.
+// line when width is nil. The display reads the time by calling now.
 func startProgress(params progressParams, width func() int,
-	interval time.Duration,
+	interval time.Duration, now func() time.Time,
 ) *progress {
-	now := time.Now()
+	start := now()
 	p := &progress{
-		width: width, stop: make(chan struct{}), done: make(chan struct{}),
+		now: now, width: width,
+		stop: make(chan struct{}), done: make(chan struct{}),
 		label: params.label, unit: params.unit, total: params.total,
 		estimate: params.estimate, waitingFor: params.waitingFor,
-		start: now, rateStart: now,
+		doing: params.doing, start: start, rateStart: start,
+		lastItem: start, drawn: []drawnCount{{at: start}},
 	}
 
 	// Show the zero state at once: the first item may take minutes,
@@ -173,13 +204,22 @@ func startProgress(params progressParams, width func() int,
 }
 
 // draw shows the phase's progress: on a TTY in place of the line
-// before, and otherwise as a plain line.
+// before, and otherwise as a plain line. It first adds the count to
+// drawn, then drops from drawn the draws older than rateWindow, except
+// the one before this draw.
 func (p *progress) draw() {
 	p.mu.Lock()
 	defer p.mu.Unlock()
 
+	now := p.now()
+
+	p.drawn = append(p.drawn, drawnCount{at: now, count: p.count})
+	for len(p.drawn) > 2 && now.Sub(p.drawn[0].at) > rateWindow {
+		p.drawn = p.drawn[1:]
+	}
+
 	if p.width == nil {
-		text, _ := p.line(math.MaxInt, true)
+		text, _ := p.line(now, math.MaxInt, true)
 		fmt.Fprintln(os.Stderr, text)
 
 		return
@@ -192,13 +232,13 @@ func (p *progress) draw() {
 	// total of 0 leaves the bar nothing to fill.
 	text, withBar := "", false
 	if p.total > 0 && !p.estimate {
-		text, withBar = p.line(width-barMargin, false)
+		text, withBar = p.line(now, width-barMargin, false)
 	}
 
 	margin := barMargin
 	if !withBar {
 		margin = spinnerMargin
-		text, _ = p.line(width-margin, true)
+		text, _ = p.line(now, width-margin, true)
 	}
 
 	// The library makes a bar or a spinner, and before each draw erases
@@ -255,18 +295,22 @@ func (p *progress) newBar(withBar bool, width int) {
 }
 
 // setTotal gives a phase that started without a total its total, once
-// it is known. The rate, and so the ETA, count from then on: the time
-// spent waiting for the total says nothing about how fast items go.
+// it is known. The rate, the ETA and the time with no item completed
+// count from then on: the time spent waiting for the total says nothing
+// about how fast items go.
 func (p *progress) setTotal(total int64) {
 	if p == nil {
 		return
 	}
 
+	now := p.now()
+
 	p.mu.Lock()
 	defer p.mu.Unlock()
 
 	p.total = total
-	p.rateStart = time.Now()
+	p.rateStart, p.lastItem = now, now
+	p.drawn = []drawnCount{{at: now, count: p.count}}
 }
 
 // increment records one completed item, which the display shows at its
@@ -276,10 +320,13 @@ func (p *progress) increment() {
 		return
 	}
 
+	now := p.now()
+
 	p.mu.Lock()
 	defer p.mu.Unlock()
 
 	p.count++
+	p.lastItem = now
 }
 
 // warnf prints a one-line warning to stderr without corrupting the
@@ -391,52 +438,77 @@ func (p *progress) finish() {
 	}
 }
 
-// line formats the phase's progress in at most room columns, as
+// line formats the phase's progress as of now in at most room columns,
+// as
 //
 //	[3/5] hash: [1234/5000] 25%, 300 files/s, elapsed 4s, eta 13s
 //
 // where "files" is the phase's unit, without the percent when percent
 // is false, as before the library's bar, which shows its own. A phase
-// with no total shows the items done instead, or what it waits for.
+// with no total shows the items done instead, or what it waits for. The
+// rate is that since the first draw in drawn, and the ETA comes from
+// the rate since the count started. Once no item has been completed for
+// stallTime, the line says so before the elapsed time, and what the
+// phase is doing, as "no files finished for 42s, reading files".
 //
 // The phase and its place, the progress, the elapsed time and the ETA
 // are kept whole. A line wider than room leaves out the rate, or what
-// the phase waits for; only if it is still wider is it cut at room, and
-// line reports that it does not fit. Every part is ASCII, so its length
-// is its width in columns. p.mu must be held.
-func (p *progress) line(room int, percent bool) (string, bool) {
-	elapsed := time.Since(p.start).Round(time.Second)
+// the phase waits for, then what it says of a stall; only if it is
+// still wider is it cut at room, and line reports that it does not fit.
+// Every part is ASCII, so its length is its width in columns. p.mu must
+// be held.
+func (p *progress) line(now time.Time, room int,
+	percent bool,
+) (string, bool) {
+	elapsed := now.Sub(p.start).Round(time.Second)
 
-	// head and tail hold the parts kept whole; extra, between them, is
-	// the part left out.
-	var head, extra, tail string
+	// head and tail hold the parts kept whole. extra, after head, is the
+	// part left out first, and stall, before tail, the part left out
+	// next.
+	var head, extra, stall, tail string
 
 	if p.total < 0 && p.waitingFor != "" {
-		head, extra = p.label+": ", p.waitingFor
+		head, extra = p.label+": ", p.waitingFor+", "
 		tail = fmt.Sprintf("elapsed %s, eta unknown", elapsed)
 	} else {
-		rate := 0.0
-		if s := time.Since(p.rateStart).Seconds(); s > 0 {
-			rate = float64(p.count) / s
-		}
+		since := p.drawn[0]
+		rate := perSecond(p.count-since.count, now.Sub(since.at))
+		average := perSecond(p.count, now.Sub(p.rateStart))
 
 		head = p.label + ": " + p.itemsDone(percent) + ", "
-		extra = fmt.Sprintf("%.0f %s/s", rate, p.unit)
-		tail = fmt.Sprintf("elapsed %s, eta %s", elapsed, p.eta(rate))
+		extra = fmt.Sprintf("%.0f %s/s, ", rate, p.unit)
+
+		if idle := now.Sub(p.lastItem); idle >= stallTime {
+			stall = fmt.Sprintf("no %s finished for %s, %s, ",
+				p.unit, idle.Round(time.Second), p.doing)
+		}
+
+		tail = fmt.Sprintf("elapsed %s, eta %s", elapsed, p.eta(average))
 	}
 
-	full, kept := head+extra+", "+tail, head+tail
-
-	switch {
-	case len(full) <= room:
-		return full, true
-	case len(kept) <= room:
-		return kept, true
+	for _, text := range []string{
+		head + extra + stall + tail, head + stall + tail, head + tail,
+	} {
+		if len(text) <= room {
+			return text, true
+		}
 	}
 
+	kept := head + tail
+
 	return kept[:max(room, 0)], false
 }
 
+// perSecond returns count items over d as items a second, or 0 when no
+// time has passed.
+func perSecond(count int64, d time.Duration) float64 {
+	if d <= 0 {
+		return 0
+	}
+
+	return float64(count) / d.Seconds()
+}
+
 // itemsDone formats the items done, as "[1234/5000] 25%", with "~"
 // before a total that is an estimate and without the percent when
 // percent is false, or as "1234 files", in the phase's unit, when the

progress_test.go

@@ -6,7 +6,9 @@ import (
 	"math"
 	"os"
 	"path/filepath"
+	"slices"
 	"strings"
+	"sync"
 	"testing"
 	"time"
 	"unicode/utf8"
@@ -20,6 +22,29 @@ const testRedraw = time.Millisecond
 // it expects.
 const testDeadline = 5 * time.Second
 
+// testClock is a clock a test moves by hand, for a display that reads
+// it from its own goroutine too.
+type testClock struct {
+	mu  sync.Mutex
+	now time.Time
+}
+
+// Now returns the clock's time.
+func (c *testClock) Now() time.Time {
+	c.mu.Lock()
+	defer c.mu.Unlock()
+
+	return c.now
+}
+
+// Add moves the clock on by d.
+func (c *testClock) Add(d time.Duration) {
+	c.mu.Lock()
+	defer c.mu.Unlock()
+
+	c.now = c.now.Add(d)
+}
+
 //nolint:paralleltest // replaces the process-wide os.Stderr
 func TestStderrIsTTYFalseForNonTerminals(t *testing.T) {
 	r, pipe, err := os.Pipe()
@@ -72,11 +97,13 @@ func TestPhaseLabel(t *testing.T) {
 }
 
 // TestProgressLine checks the line a display shows in each state, ten
-// seconds into the phase.
+// seconds into the phase, with no draw since the first and the last
+// item just completed.
 func TestProgressLine(t *testing.T) {
 	t.Parallel()
 
-	ago := time.Now().Add(-10 * time.Second)
+	now := time.Now()
+	ago := now.Add(-10 * time.Second)
 
 	cases := []struct {
 		p    *progress
@@ -129,28 +156,41 @@ func TestProgressLine(t *testing.T) {
 	}}
 
 	for _, tc := range cases {
-		tc.p.start, tc.p.rateStart = ago, ago
+		tc.p.start, tc.p.rateStart, tc.p.lastItem = ago, ago, now
+		tc.p.drawn = []drawnCount{{at: ago}}
 
-		if got, _ := tc.p.line(math.MaxInt, true); got != tc.want {
+		if got, _ := tc.p.line(now, math.MaxInt, true); got != tc.want {
 			t.Errorf("line = %q, want %q", got, tc.want)
 		}
 	}
 }
 
 // TestLineFitsRoom checks how a line is fitted to the room it has, ten
-// seconds into the phase: it leaves out the rate, or what the phase
-// waits for, and is cut only when what is left is still too wide.
+// seconds into the phase, and fifty into a phase with no file read for
+// the last 42: it leaves out the rate, or what the phase waits for,
+// then what it says of the stall, and is cut only when what is left is
+// still too wide.
 func TestLineFitsRoom(t *testing.T) {
 	t.Parallel()
 
-	ago := time.Now().Add(-10 * time.Second)
+	now := time.Now()
+	ago := now.Add(-10 * time.Second)
 	hash := &progress{
 		label: scanPhase("hash"), unit: scanUnit, total: 100, count: 20,
-		start: ago, rateStart: ago,
+		start: ago, rateStart: ago, lastItem: now,
+		drawn: []drawnCount{{at: ago}},
 	}
 	content := &progress{
 		label: scanPhase("content"), total: -1,
-		waitingFor: "searching the database", start: ago, rateStart: ago,
+		waitingFor: searchingDatabase, start: ago, rateStart: ago,
+	}
+
+	started := now.Add(-50 * time.Second)
+	stalled := &progress{
+		label: scanPhase("hash"), unit: scanUnit, total: 100, count: 20,
+		doing: readingFiles, start: started, rateStart: started,
+		lastItem: now.Add(-42 * time.Second),
+		drawn:    []drawnCount{{at: now.Add(-rateWindow), count: 20}},
 	}
 
 	cases := []struct {
@@ -180,10 +220,24 @@ func TestLineFitsRoom(t *testing.T) {
 		p: content, room: 40, percent: true,
 		want: "[5/5] content: elapsed 10s, eta unknown",
 		fits: true,
+	}, {
+		p: stalled, room: 101, percent: true,
+		want: "[3/5] hash: [20/100] 20%, 0 files/s, no files finished for " +
+			"42s, reading files, elapsed 50s, eta 3m20s",
+		fits: true,
+	}, {
+		p: stalled, room: 100, percent: true,
+		want: "[3/5] hash: [20/100] 20%, no files finished for 42s, " +
+			"reading files, elapsed 50s, eta 3m20s",
+		fits: true,
+	}, {
+		p: stalled, room: 89, percent: true,
+		want: "[3/5] hash: [20/100] 20%, elapsed 50s, eta 3m20s",
+		fits: true,
 	}}
 
 	for _, tc := range cases {
-		got, fits := tc.p.line(tc.room, tc.percent)
+		got, fits := tc.p.line(now, tc.room, tc.percent)
 		if got != tc.want || fits != tc.fits {
 			t.Errorf("line(%d, %t) = %q, %t, want %q, %t",
 				tc.room, tc.percent, got, fits, tc.want, tc.fits)
@@ -192,27 +246,37 @@ func TestLineFitsRoom(t *testing.T) {
 }
 
 // TestSetTotalStartsRate checks that setTotal starts a phase's rate,
-// and so its ETA, from when the total becomes known, not from when the
-// phase started waiting for it.
+// its ETA and its time with no record read from when the total becomes
+// known, not from when the phase started waiting for it.
 func TestSetTotalStartsRate(t *testing.T) {
 	t.Parallel()
 
-	waited := time.Now().Add(-20 * time.Second)
+	clock := &testClock{now: time.Now()}
+	waited := clock.Now().Add(-20 * time.Second)
 	p := &progress{
-		label: scanPhase("load"), unit: scanUnit, total: -1, start: waited,
-		rateStart: waited,
+		now: clock.Now, label: scanPhase("load"), unit: scanUnit, total: -1,
+		doing: readingDatabase, start: waited, rateStart: waited,
+		lastItem: waited, drawn: []drawnCount{{at: waited}},
 	}
 
 	p.setTotal(100)
 
-	// Ten seconds after the total came, without waiting ten seconds,
-	// 20 records are read.
-	p.start = p.start.Add(-10 * time.Second)
-	p.rateStart = p.rateStart.Add(-10 * time.Second)
-	p.count = 20
+	// Ten seconds after the total came, no record has been read yet.
+	clock.Add(10 * time.Second)
 
-	want := "[1/5] load: [20/100] 20%, 2 files/s, elapsed 30s, eta 40s"
-	if got, _ := p.line(math.MaxInt, true); got != want {
+	want := "[1/5] load: [0/100] 0%, 0 files/s, no files finished for 10s, " +
+		"reading the database, elapsed 30s, eta unknown"
+	if got, _ := p.line(clock.Now(), math.MaxInt, true); got != want {
+		t.Errorf("line = %q, want %q", got, want)
+	}
+
+	// Then 20 are.
+	for range 20 {
+		p.increment()
+	}
+
+	want = "[1/5] load: [20/100] 20%, 2 files/s, elapsed 30s, eta 40s"
+	if got, _ := p.line(clock.Now(), math.MaxInt, true); got != want {
 		t.Errorf("line = %q, want %q", got, want)
 	}
 }
@@ -272,13 +336,138 @@ func TestPlainProgressPrintsWhileWaiting(t *testing.T) {
 	p := startProgress(progressParams{
 		label: scanPhase("load"), total: -1,
 		waitingFor: countingRecords,
-	}, nil, testRedraw)
+	}, nil, testRedraw, time.Now)
 
 	awaitOutput(t, stderr,
 		"[1/5] load: counting the records, elapsed 0s, eta unknown\n", 3)
 	p.finish()
 }
 
+// TestPlainProgressStalledProducer checks that a phase whose files stop
+// coming, as when one large file is being read or a disk is slow, goes
+// on printing its line every interval: the rate falls to 0 once no file
+// has been read for rateWindow, and once none has for stallTime the
+// line says so, and what the phase is doing. The test moves the
+// display's clock by hand.
+//
+//nolint:paralleltest // captureStderr replaces the process-wide os.Stderr
+func TestPlainProgressStalledProducer(t *testing.T) {
+	stderr := captureStderr(t)
+	clock := &testClock{now: time.Now()}
+	p := startProgress(progressParams{
+		label: scanPhase("hash"), unit: scanUnit, total: 100,
+		doing: readingFiles,
+	}, nil, testRedraw, clock.Now)
+
+	// Pass or fail, the display ends before stderr is put back.
+	t.Cleanup(p.finish)
+
+	// 20 files read as the phase starts, then none.
+	for range 20 {
+		p.increment()
+	}
+
+	clock.Add(5 * time.Second)
+	awaitOutput(t, stderr,
+		"[3/5] hash: [20/100] 20%, 4 files/s, elapsed 5s, eta 20s\n", 3)
+
+	clock.Add(time.Second)
+	awaitOutput(t, stderr,
+		"[3/5] hash: [20/100] 20%, 0 files/s, elapsed 6s, eta 24s\n", 3)
+
+	clock.Add(4 * time.Second)
+	awaitOutput(t, stderr,
+		"[3/5] hash: [20/100] 20%, 0 files/s, no files finished for 10s, "+
+			"reading files, elapsed 10s, eta 40s\n", 3)
+}
+
+// TestPlainProgressRateAfterStall draws a phase's plain line by hand, a
+// little over plainInterval after the line before, as a late tick
+// does, through a stall and a burst of files after it: the rate covers
+// the files read since the line before, while the ETA comes from the
+// phase's average.
+//
+//nolint:paralleltest // captureStderr replaces the process-wide os.Stderr
+func TestPlainProgressRateAfterStall(t *testing.T) {
+	stderr := captureStderr(t)
+	clock := &testClock{now: time.Now()}
+
+	// No timed draws: the test draws.
+	p := startProgress(progressParams{
+		label: scanPhase("hash"), unit: scanUnit, total: 1000,
+		doing: readingFiles,
+	}, nil, time.Hour, clock.Now)
+
+	late := plainInterval + time.Millisecond
+
+	clock.Add(late)
+	p.draw()
+	clock.Add(late)
+	p.draw()
+
+	for range 100 {
+		p.increment()
+	}
+
+	clock.Add(late)
+	p.finish()
+
+	want := []string{
+		"[3/5] hash: [0/1000] 0%, 0 files/s, elapsed 0s, eta unknown",
+		"[3/5] hash: [0/1000] 0%, 0 files/s, elapsed 5s, eta unknown",
+		"[3/5] hash: [0/1000] 0%, 0 files/s, no files finished for 10s, " +
+			"reading files, elapsed 10s, eta unknown",
+		"[3/5] hash: [100/1000] 10%, 20 files/s, elapsed 15s, eta 2m15s",
+	}
+
+	lines := strings.Split(strings.TrimSuffix(stderr(), "\n"), "\n")
+	if !slices.Equal(lines, want) {
+		t.Errorf("stderr lines = %q, want %q", lines, want)
+	}
+}
+
+// TestProgressRateAfterStallRedrawn draws a phase by hand every
+// redrawInterval, as a terminal does, through a stall of stallTime and
+// a burst of files after it: the rate covers the files read over the
+// last rateWindow, and falls to 0 once the burst is older than that,
+// while the ETA comes from the phase's average. Plain lines show each
+// draw.
+//
+//nolint:paralleltest // captureStderr replaces the process-wide os.Stderr
+func TestProgressRateAfterStallRedrawn(t *testing.T) {
+	stderr := captureStderr(t)
+	clock := &testClock{now: time.Now()}
+
+	// No timed draws: the test draws.
+	p := startProgress(progressParams{
+		label: scanPhase("hash"), unit: scanUnit, total: 1000,
+		doing: readingFiles,
+	}, nil, time.Hour, clock.Now)
+
+	// redraw draws the display every redrawInterval for d.
+	redraw := func(d time.Duration) {
+		for range d / redrawInterval {
+			clock.Add(redrawInterval)
+			p.draw()
+		}
+	}
+
+	redraw(stallTime)
+
+	for range 50 {
+		p.increment()
+	}
+
+	redraw(rateWindow + redrawInterval)
+	p.finish()
+
+	want := "[3/5] hash: [50/1000] 5%, 10 files/s, elapsed 15s, eta 4m45s\n" +
+		"[3/5] hash: [50/1000] 5%, 0 files/s, elapsed 15s, eta 4m47s\n"
+	if !strings.Contains(stderr(), want) {
+		t.Errorf("stderr = %q, want the lines %q", stderr(), want)
+	}
+}
+
 // lastFrame returns what a terminal shows of the frames a display drew:
 // the last one. The library starts each frame with a carriage return
 // and erases the previous one with spaces first.
@@ -321,7 +510,7 @@ func TestTerminalRedrawsWhileWaiting(t *testing.T) {
 	for _, tc := range cases {
 		before := len(stderr())
 		since := func() string { return stderr()[before:] }
-		p := startProgress(tc.params, terminalWidth, testRedraw)
+		p := startProgress(tc.params, terminalWidth, testRedraw, time.Now)
 
 		for range 50 {
 			p.increment()
@@ -343,21 +532,23 @@ func TestTerminalRedrawsWhileWaiting(t *testing.T) {
 
 // drawLate draws the display params describes on a terminal width
 // columns wide as it starts and once more as it ends, with count items
-// done two and a half hours into the phase, and returns what it wrote
-// to stderr.
+// done two and a half hours into the phase, the last just now, and
+// returns what it wrote to stderr.
 func drawLate(stderr func() string, params progressParams, width int,
 	count int64,
 ) string {
 	before := len(stderr())
+	clock := &testClock{now: time.Now()}
 
 	// No timed draws come between the two.
-	p := startProgress(params, func() int { return width }, time.Hour)
+	p := startProgress(params, func() int { return width }, time.Hour,
+		clock.Now)
 
 	// Without counting the items one by one or waiting the hours.
+	clock.Add(150 * time.Minute)
+
 	p.mu.Lock()
-	p.count = count
-	p.start = p.start.Add(-150 * time.Minute)
-	p.rateStart = p.start
+	p.count, p.lastItem = count, clock.Now()
 	p.mu.Unlock()
 
 	p.finish()
@@ -479,14 +670,16 @@ func TestTerminalNarrowedRedrawsInPlace(t *testing.T) {
 
 	for _, tc := range cases {
 		width := 120
+		clock := &testClock{now: time.Now()}
 
 		// No timed draws: the test draws.
-		p := startProgress(tc.params, func() int { return width }, time.Hour)
+		p := startProgress(tc.params, func() int { return width }, time.Hour,
+			clock.Now)
+
+		clock.Add(150 * time.Minute)
 
 		p.mu.Lock()
-		p.count = 1234567
-		p.start = p.start.Add(-150 * time.Minute)
-		p.rateStart = p.start
+		p.count, p.lastItem = 1234567, clock.Now()
 		p.mu.Unlock()
 
 		p.draw()
@@ -528,7 +721,7 @@ func TestProgressWarningsOnOwnLines(t *testing.T) {
 	issued := 0
 
 	for _, params := range cases {
-		p := startProgress(params, terminalWidth, testRedraw)
+		p := startProgress(params, terminalWidth, testRedraw, time.Now)
 
 		// No pause between warnings: one written straight to stderr is
 		// garbled only if a redraw lands while it is being written.
@@ -581,7 +774,7 @@ func TestProgressWriterRowsOnOwnLines(t *testing.T) {
 	var want []string
 
 	for _, params := range cases {
-		p := startProgress(params, terminalWidth, testRedraw)
+		p := startProgress(params, terminalWidth, testRedraw, time.Now)
 		out := p.writer(os.Stderr)
 
 		// No pause between rows: one is garbled only if a redraw lands
@@ -644,7 +837,7 @@ func TestProgressWriterStalledStdoutKeepsLines(t *testing.T) {
 	})
 
 	p := startProgress(progressParams{label: treesPhase("write"), total: 1},
-		nil, testRedraw)
+		nil, testRedraw, time.Now)
 	out := p.writer(w)
 	written := make(chan error, 1)
 
@@ -687,7 +880,7 @@ func TestProgressWriterStalledStdoutKeepsLines(t *testing.T) {
 func TestTerminalStoppedShortKeepsCount(t *testing.T) {
 	stderr := captureStderr(t)
 	p := startProgress(progressParams{label: scanPhase("hash"), total: 10},
-		terminalWidth, redrawInterval)
+		terminalWidth, redrawInterval, time.Now)
 
 	p.increment()
 	p.increment()
@@ -706,7 +899,7 @@ func TestTerminalStoppedShortKeepsCount(t *testing.T) {
 func TestWarningAfterLastItemKeepsBar(t *testing.T) {
 	stderr := captureStderr(t)
 	p := startProgress(progressParams{label: scanPhase("hash"), total: 2},
-		terminalWidth, testRedraw)
+		terminalWidth, testRedraw, time.Now)
 
 	p.increment()
 	p.increment()

report.go

@@ -76,7 +76,7 @@ func runReport(ctx context.Context, stdout io.Writer) error {
 
 	prog = newProgress(progressParams{
 		label: reportPhase("read"), unit: "records", total: -1,
-		waitingFor: countingRecords,
+		waitingFor: countingRecords, doing: readingDatabase,
 	})
 	report, err := readReport(ctx, db, dbPath, stdout, prog)
 

report_test.go

@@ -156,7 +156,7 @@ func TestReportStdoutFailsWhileReading(t *testing.T) {
 	}
 
 	// Counts the records read, and draws nothing.
-	prog := &progress{}
+	prog := &progress{now: time.Now}
 
 	_, err = readReport(t.Context(), db, "", failingWriter{}, prog)
 	if !errors.Is(err, errWriteFailed) ||
@@ -250,7 +250,7 @@ func TestReadReportOnTerminal(t *testing.T) {
 	p := startProgress(progressParams{
 		label: reportPhase("read"), unit: "records", total: -1,
 		waitingFor: countingRecords,
-	}, terminalWidth, time.Hour)
+	}, terminalWidth, time.Hour, time.Now)
 
 	_, err = readReport(t.Context(), db, "", os.Stderr, p)
 

scan.go

@@ -88,6 +88,15 @@ type fileMeta struct {
 // names it.
 const scanUnit = "files"
 
+// readingFiles is what the display of a phase that reads files says it
+// is doing once no file has been read for stallTime.
+const readingFiles = "reading files"
+
+// searchingDatabase is what the display of the content phase's checks
+// says it waits for until the search returns its first record, and what
+// it says it is doing once no record has been checked for stallTime.
+const searchingDatabase = "searching the database"
+
 // scanPhase names one phase of a scan with its place among all of them,
 // as "[2/5] walk", for the phase's progress display. The list here is
 // the one place the phases are counted.
@@ -446,7 +455,7 @@ func (s *scanState) loadIndex(ctx context.Context, roots []string) error {
 	// first gives the display its total.
 	prog := newProgress(progressParams{
 		label: scanPhase("load"), unit: scanUnit, total: -1,
-		waitingFor: countingRecords,
+		waitingFor: countingRecords, doing: readingDatabase,
 	})
 	defer prog.finish()
 
@@ -497,7 +506,7 @@ func (s *scanState) walkPhase(
 
 	prog := newProgress(progressParams{
 		label: scanPhase("walk"), unit: scanUnit, total: estimate,
-		estimate: true,
+		estimate: true, doing: "listing directories",
 	})
 
 	var (
@@ -689,6 +698,7 @@ func (s *scanState) readRuns(ctx context.Context, workers int,
 
 	prog := newProgress(progressParams{
 		label: scanPhase(label), unit: scanUnit, total: int64(len(runs)),
+		doing: readingFiles,
 	})
 	defer prog.finish()
 
@@ -778,6 +788,7 @@ func (s *scanState) updatePhase(ctx context.Context) error {
 	total := len(s.batch) + len(s.sentinels) + len(deletes)
 	prog := newProgress(progressParams{
 		label: scanPhase("update"), unit: scanUnit, total: int64(total),
+		doing: "writing to the database",
 	})
 
 	defer prog.finish()
@@ -866,7 +877,7 @@ func (s *scanState) contentCandidates(
 	// the search returns, and so do their rate and ETA.
 	prog := newProgress(progressParams{
 		label: scanPhase("content"), unit: scanUnit, total: -1,
-		waitingFor: "searching the database",
+		waitingFor: searchingDatabase, doing: searchingDatabase,
 	})
 	defer prog.finish()
 

trees.go

@@ -72,7 +72,7 @@ func runTrees(ctx context.Context, stdout io.Writer) error {
 
 	prog = newProgress(progressParams{
 		label: treesPhase("read"), unit: "records", total: -1,
-		waitingFor: countingRecords,
+		waitingFor: countingRecords, doing: readingDatabase,
 	})
 	records, super, allDirs, err := readTree(ctx, db, prog)
 
@@ -84,7 +84,7 @@ func runTrees(ctx context.Context, stdout io.Writer) error {
 
 	prog = newProgress(progressParams{
 		label: treesPhase("group"), unit: "directories",
-		total: int64(len(allDirs)),
+		total: int64(len(allDirs)), doing: "grouping directories",
 	})
 	dupes := collectTreeGroups(allDirs, super, prog)
 
@@ -92,6 +92,7 @@ func runTrees(ctx context.Context, stdout io.Writer) error {
 
 	prog = newProgress(progressParams{
 		label: treesPhase("write"), unit: "groups", total: int64(len(dupes)),
+		doing: "writing the report",
 	})
 	dupeTrees, reclaimable, err := writeTreeGroups(stdout, dupes, prog)
 

trees_test.go

@@ -279,7 +279,7 @@ func TestWriteTreeGroupsOnTerminal(t *testing.T) {
 	// No timed draws: the display is drawn as it starts and as it ends.
 	p := startProgress(progressParams{
 		label: treesPhase("write"), unit: "groups", total: int64(len(dupes)),
-	}, terminalWidth, time.Hour)
+	}, terminalWidth, time.Hour, time.Now)
 
 	_, _, err := writeTreeGroups(os.Stderr, dupes, p)