Files
sfdupes/progress_test.go
T
sneak ab9ca809b3
check / check (push) Waiting to run
Show the progress rate over the last 5 seconds, and where a phase waits 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; the ETA still
comes from the average. Once no item has completed for 10 seconds, the
rate gives way to "stalled" and where the phase waits, as "stalled
disk/db": disk, db, out (stdout) or cpu, or two of them. A line too
wide for the terminal loses its bar first, then its rate or those
words, so the phase, progress, elapsed time and ETA stay whole. The
content phase's last partial batch is now written under a display of
its own. The tests set the display's clock by hand.

Deviation: the stall words hold no time and name where the phase waits, not what it does.
Judgement call: trees' group phase, which works in memory, says "cpu".

Model: opus-5-5
2026-10-16 22:47:32 +00:00

990 lines
28 KiB
Go

package main
import (
"fmt"
"io"
"math"
"os"
"path/filepath"
"slices"
"strings"
"sync"
"testing"
"time"
"unicode/utf8"
)
// testRedraw is the redraw interval the tests give a display, so that
// many redraws fit in a few milliseconds.
const testRedraw = time.Millisecond
// testDeadline bounds how long a test waits for a display to draw what
// it expects.
const testDeadline = 5 * time.Second
// hashStalledOn is where the hash phase says it waits once it has
// stalled, as readRuns gives it.
const hashStalledOn = "disk/db"
// 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()
if err != nil {
t.Fatal(err)
}
regular, err := os.Create(filepath.Join(t.TempDir(), "stderr"))
if err != nil {
t.Fatal(err)
}
devNull, err := os.OpenFile(os.DevNull, os.O_WRONLY, 0)
if err != nil {
t.Fatal(err)
}
saved := os.Stderr
t.Cleanup(func() {
os.Stderr = saved
for _, f := range []*os.File{r, pipe, regular, devNull} {
_ = f.Close()
}
})
cases := map[string]*os.File{
"a pipe": pipe,
"a regular file": regular,
os.DevNull: devNull,
}
for name, f := range cases {
os.Stderr = f
if stderrIsTTY() {
t.Errorf("stderrIsTTY() = true with stderr on %s", name)
}
}
}
func TestPhaseLabel(t *testing.T) {
t.Parallel()
phases := []string{"load", "walk", "hash"}
if got := phaseLabel(phases, "walk"); got != "[2/3] walk" {
t.Errorf("phaseLabel = %q, want %q", got, "[2/3] walk")
}
}
// TestProgressLine checks the line a display shows in each state, ten
// seconds into the phase, with no draw since the first and the last
// item just completed.
func TestProgressLine(t *testing.T) {
t.Parallel()
now := time.Now()
ago := now.Add(-10 * time.Second)
cases := []struct {
p *progress
want string
}{{
p: &progress{
label: scanPhase("load"), total: -1,
waitingFor: countingRecords,
},
want: "[1/5] load: counting the records, elapsed 10s, eta unknown",
}, {
p: &progress{
label: scanPhase("hash"), unit: scanUnit, total: 100, count: 20,
},
want: "[3/5] hash: [20/100] 20%, 2 files/s, elapsed 10s, eta 40s",
}, {
p: &progress{label: scanPhase("hash"), unit: scanUnit, total: 100},
want: "[3/5] hash: [0/100] 0%, 0 files/s, elapsed 10s, eta unknown",
}, {
p: &progress{label: scanPhase("update"), unit: scanUnit, total: 0},
want: "[4/5] update: [0/0] 100%, 0 files/s, elapsed 10s, eta 0s",
}, {
p: &progress{
label: scanPhase("walk"), unit: scanUnit, total: 100,
estimate: true, count: 20,
},
want: "[2/5] walk: [20/~100] 20%, 2 files/s, elapsed 10s, eta 40s",
}, {
// Past the estimate the walk cannot tell how long it has left.
p: &progress{
label: scanPhase("walk"), unit: scanUnit, total: 100,
estimate: true, count: 120,
},
want: "[2/5] walk: [120/~100] 120%, 12 files/s, elapsed 10s, " +
"eta unknown",
}, {
// A first scan's walk has no estimate.
p: &progress{
label: scanPhase("walk"), unit: scanUnit, total: -1, count: 20,
},
want: "[2/5] walk: 20 files, 2 files/s, elapsed 10s, eta unknown",
}, {
// The rate is in what the phase counts.
p: &progress{
label: treesPhase("group"), unit: "directories", total: 100,
count: 20,
},
want: "[3/4] group: [20/100] 20%, 2 directories/s, elapsed 10s, " +
"eta 40s",
}}
for _, tc := range cases {
tc.p.start, tc.p.rateStart, tc.p.lastItem = ago, ago, now
tc.p.drawn = []drawnCount{{at: ago}}
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, and fifty into a phase with no file read for
// the last 42: it leaves out the rate, what the phase waits for, or the
// words of a stalled phase, and is cut only when what is left is still
// too wide.
func TestLineFitsRoom(t *testing.T) {
t.Parallel()
now := time.Now()
ago := now.Add(-10 * time.Second)
hash := &progress{
label: scanPhase("hash"), unit: scanUnit, total: 100, count: 20,
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,
}
started := now.Add(-50 * time.Second)
stalled := &progress{
label: scanPhase("hash"), unit: scanUnit, total: 100, count: 20,
stalledOn: hashStalledOn, start: started, rateStart: started,
lastItem: now.Add(-42 * time.Second),
drawn: []drawnCount{{at: now.Add(-rateWindow), count: 20}},
}
cases := []struct {
p *progress
room int
percent bool
want string
}{{
p: hash, room: 57, percent: true,
want: "[3/5] hash: [20/100] 20%, 2 files/s, elapsed 10s, eta 40s",
}, {
p: hash, room: 56, percent: true,
want: "[3/5] hash: [20/100] 20%, elapsed 10s, eta 40s",
}, {
p: hash, room: 45, percent: true,
want: "[3/5] hash: [20/100] 20%, elapsed 10s, eta 40",
}, {
// Before the library's bar, which shows the percent.
p: hash, room: 57, percent: false,
want: "[3/5] hash: [20/100], 2 files/s, elapsed 10s, eta 40s",
}, {
p: content, room: 40, percent: true,
want: "[5/5] content: elapsed 10s, eta unknown",
}, {
p: stalled, room: 65, percent: true,
want: "[3/5] hash: [20/100] 20%, stalled disk/db, elapsed 50s, " +
"eta 3m20s",
}, {
p: stalled, room: 64, percent: true,
want: "[3/5] hash: [20/100] 20%, elapsed 50s, eta 3m20s",
}}
for _, tc := range cases {
if got := tc.p.line(now, tc.room, tc.percent); got != tc.want {
t.Errorf("line(%d, %t) = %q, want %q",
tc.room, tc.percent, got, tc.want)
}
}
}
// TestSetTotalStartsRate checks that setTotal starts a phase's rate,
// its ETA and its time with no record read from when the total becomes
// known, not from when the phase started waiting for it: after 20
// seconds of waiting for the total, the phase has not stalled 5 seconds
// after it, and has 10 seconds after it with no record read.
func TestSetTotalStartsRate(t *testing.T) {
t.Parallel()
clock := &testClock{now: time.Now()}
waited := clock.Now().Add(-20 * time.Second)
p := &progress{
now: clock.Now, label: scanPhase("load"), unit: scanUnit, total: -1,
stalledOn: "db", start: waited, rateStart: waited,
lastItem: waited, drawn: []drawnCount{{at: waited}},
}
p.setTotal(100)
clock.Add(5 * time.Second)
want := "[1/5] load: [0/100] 0%, 0 files/s, elapsed 25s, eta unknown"
if got := p.line(clock.Now(), math.MaxInt, true); got != want {
t.Errorf("line = %q, want %q", got, want)
}
clock.Add(5 * time.Second)
want = "[1/5] load: [0/100] 0%, stalled db, 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 records are read.
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)
}
}
// awaitOutput waits until stderr holds want at least times times, and
// fails the test if it never does.
func awaitOutput(t *testing.T, stderr func() string, want string,
times int,
) {
t.Helper()
deadline := time.Now().Add(testDeadline)
for strings.Count(stderr(), want) < times {
if time.Now().After(deadline) {
t.Fatalf("stderr = %q, want %q at least %d times",
stderr(), want, times)
}
time.Sleep(testRedraw)
}
}
// TestPlainProgressPrintsAtStartAndEnd checks that when stderr is not a
// terminal a phase prints its line the moment it starts, before its
// first item, nothing for the items it completes before plainInterval
// has passed, and its line again as it ends.
//
//nolint:paralleltest // captureStderr replaces the process-wide os.Stderr
func TestPlainProgressPrintsAtStartAndEnd(t *testing.T) {
stderr := captureStderr(t)
p := newProgress(progressParams{
label: scanPhase("hash"), unit: scanUnit, total: 1000,
})
for range 1000 {
p.increment()
}
p.finish()
lines := strings.Split(strings.TrimSuffix(stderr(), "\n"), "\n")
want := "[3/5] hash: [0/1000] 0%, 0 files/s, elapsed 0s, eta unknown"
if len(lines) != 2 || lines[0] != want ||
!strings.HasPrefix(lines[1], "[3/5] hash: [1000/1000] 100%, ") {
t.Errorf("stderr lines = %q, want %q, then the line at 1000",
lines, want)
}
}
// TestPlainProgressPrintsWhileWaiting checks that a phase waiting with
// no completed items still prints a line every interval.
//
//nolint:paralleltest // captureStderr replaces the process-wide os.Stderr
func TestPlainProgressPrintsWhileWaiting(t *testing.T) {
stderr := captureStderr(t)
p := startProgress(progressParams{
label: scanPhase("load"), total: -1,
waitingFor: countingRecords,
}, 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 the phase has stalled, and where it waits, in place of the
// rate. 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,
stalledOn: hashStalledOn,
}, 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%, stalled disk/db, 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,
stalledOn: hashStalledOn,
}, 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%, stalled disk/db, 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,
stalledOn: hashStalledOn,
}, 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.
func lastFrame(out string) string {
var shown string
for frame := range strings.SplitSeq(out, "\r") {
if strings.TrimSpace(frame) != "" {
shown = frame
}
}
return shown
}
// TestTerminalRedrawsWhileWaiting checks that the terminal display of a
// phase, spinner or bar, keeps being drawn while the phase waits for its
// next item, with the elapsed time as of now, and shows every item
// completed before the wait. stderr is not a terminal here, so the
// displays take it to be fallbackWidth wide.
//
//nolint:paralleltest // captureStderr replaces the process-wide os.Stderr
func TestTerminalRedrawsWhileWaiting(t *testing.T) {
stderr := captureStderr(t)
cases := []struct {
params progressParams
want string // how the line shows a count of 50
}{
{
progressParams{label: scanPhase("walk"), unit: scanUnit, total: -1},
"50 files,",
},
{
progressParams{label: scanPhase("hash"), unit: scanUnit, total: 100},
"[50/100],",
},
}
for _, tc := range cases {
before := len(stderr())
since := func() string { return stderr()[before:] }
p := startProgress(tc.params, terminalWidth, testRedraw, time.Now)
for range 50 {
p.increment()
}
// An hour into the phase, without waiting an hour.
p.mu.Lock()
p.start = p.start.Add(-time.Hour)
p.mu.Unlock()
awaitOutput(t, since, "elapsed 1h0m0s", 1)
p.finish()
if shown := lastFrame(since()); !strings.Contains(shown, tc.want) {
t.Errorf("terminal shows %q, want %q", shown, tc.want)
}
}
}
// 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, 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,
clock.Now)
// Without counting the items one by one or waiting the hours.
clock.Add(150 * time.Minute)
p.mu.Lock()
p.count, p.lastItem = count, clock.Now()
p.mu.Unlock()
p.finish()
return stderr()[before:]
}
// TestTerminalLinesKeepETA checks the line each display shows on an
// 80-column terminal at a large scan's counts and times, and the line
// of trees' read phase at the same counts: the rate is left out, so
// that the elapsed time and the ETA stay whole.
//
//nolint:paralleltest // captureStderr replaces the process-wide os.Stderr
func TestTerminalLinesKeepETA(t *testing.T) {
stderr := captureStderr(t)
cases := []struct {
params progressParams
want string
}{{
// Past its estimate, the walk cannot tell how long it has left.
params: progressParams{
label: scanPhase("walk"), unit: scanUnit, total: 1200000,
estimate: true,
},
want: "[2/5] walk: [1234567/~1200000] 103%, elapsed 2h30m0s, " +
"eta unknown",
}, {
params: progressParams{
label: scanPhase("hash"), unit: scanUnit, total: 9876543,
},
want: "[3/5] hash: [1234567/9876543] 12%, elapsed 2h30m0s, " +
"eta 17h30m0s",
}, {
params: progressParams{
label: scanPhase("content"), unit: scanUnit, total: 9876543,
},
want: "[5/5] content: [1234567/9876543] 12%, elapsed 2h30m0s, " +
"eta 17h30m0s",
}, {
params: progressParams{
label: treesPhase("read"), unit: "records", total: 9876543,
},
want: "[2/4] read: [1234567/9876543] 12%, elapsed 2h30m0s, " +
"eta 17h30m0s",
}}
for _, tc := range cases {
out := drawLate(stderr, tc.params, 80, 1234567)
if shown := lastFrame(out); !strings.Contains(shown, tc.want) {
t.Errorf("terminal shows %q, want %q", shown, tc.want)
}
}
}
// TestTerminalStalledLines draws every phase's line on an 80-column
// terminal once the phase has stalled, its last item done 42 seconds
// before. At an ordinary scan's counts and times, 12345 of 45678 items
// done four and a half minutes in, the line shows where the phase waits
// whole, beside the phase, progress, elapsed time and ETA. At a large
// scan's, 1234567 of 9876543 two and a half hours in, those four still
// show whole, as the words give way first where they do not fit.
//
//nolint:paralleltest // captureStderr replaces the process-wide os.Stderr
func TestTerminalStalledLines(t *testing.T) {
stderr := captureStderr(t)
// drawStalled draws the display params describes as it starts and
// once more as it ends, with count of total items done elapsed into
// the phase, and returns what the terminal shows.
drawStalled := func(params progressParams, total, count int64,
elapsed time.Duration,
) string {
before := len(stderr())
clock := &testClock{now: time.Now()}
params.total = total
// No timed draws come between the two.
p := startProgress(params, func() int { return 80 }, time.Hour,
clock.Now)
clock.Add(elapsed - 42*time.Second)
p.mu.Lock()
p.count, p.lastItem = count, clock.Now()
p.mu.Unlock()
clock.Add(42 * time.Second)
p.finish()
return lastFrame(stderr()[before:])
}
phases := []progressParams{
{label: scanPhase("load"), stalledOn: "db"},
{label: scanPhase("walk"), estimate: true, stalledOn: "disk"},
{label: scanPhase("hash"), stalledOn: hashStalledOn},
{label: scanPhase("update"), stalledOn: "db"},
// The content phase's checks and reads, then its last write.
{label: scanPhase("content"), stalledOn: "disk/db"},
{label: scanPhase("content"), stalledOn: "db"},
{label: treesPhase("read"), stalledOn: "db"},
{label: treesPhase("group"), stalledOn: "cpu"},
{label: treesPhase("write"), stalledOn: "out"},
{label: reportPhase("read"), stalledOn: "db/out"},
}
for _, params := range phases {
approx := ""
if params.estimate {
approx = "~"
}
shown := drawStalled(params, 45678, 12345,
4*time.Minute+30*time.Second)
want := params.label + ": [12345/" + approx + "45678] 27%, stalled " +
params.stalledOn + ", elapsed 4m30s, eta 12m9s"
if !strings.Contains(shown, want) {
t.Errorf("terminal shows %q, want %q", shown, want)
}
shown = drawStalled(params, 9876543, 1234567, 150*time.Minute)
for _, want := range []string{
params.label + ": [1234567/" + approx + "9876543] 12%, ",
", elapsed 2h30m0s, eta 17h30m0s",
} {
if !strings.Contains(shown, want) {
t.Errorf("terminal shows %q, want %q", shown, want)
}
}
}
}
// TestTerminalLinesFitWidth draws a large scan's bar display and a small
// scan's, two and a half hours into the phase, on terminals from 120
// columns down to 40, and checks that every line stays clear of the
// terminal's last column. A line that reaches it wraps, and every
// redraw then leaves a line behind. The bar is drawn where it has room,
// as at 120 columns, and left out where it has none.
//
//nolint:paralleltest // captureStderr replaces the process-wide os.Stderr
func TestTerminalLinesFitWidth(t *testing.T) {
stderr := captureStderr(t)
for _, width := range []int{120, 100, 80, 72, 60, 50, 40} {
for _, total := range []int64{9876543, 20000} {
params := progressParams{
label: scanPhase("content"), unit: scanUnit, total: total,
}
out := drawLate(stderr, params, width, total/8)
if width == 120 && !strings.Contains(out, "% |") {
t.Errorf("no bar on a terminal %d wide: %q", width, out)
}
lines := strings.FieldsFuncSeq(out, func(r rune) bool {
return r == '\r' || r == '\n'
})
for line := range lines {
if n := utf8.RuneCountInString(line); n >= width {
t.Errorf("a line of %d columns on a terminal %d wide: %q",
n, width, line)
}
}
}
}
}
// TestTerminalNarrowedRedrawsInPlace draws a large scan's display, two
// and a half hours into the phase, on a terminal 120 columns wide, then
// makes the terminal narrower than that line and draws it again a few
// times. Nothing written after that, the erase before each redraw
// included, may reach the narrower terminal's last column: it would
// wrap, and every redraw would leave a line behind. At these widths the
// spinner stays a spinner and the bar gives way to the spinner.
//
//nolint:paralleltest // captureStderr replaces the process-wide os.Stderr
func TestTerminalNarrowedRedrawsInPlace(t *testing.T) {
stderr := captureStderr(t)
cases := []struct {
params progressParams
narrow int
}{
{
progressParams{label: scanPhase("walk"), unit: scanUnit, total: -1},
60,
},
{
progressParams{
label: scanPhase("hash"), unit: scanUnit, total: 9876543,
},
90,
},
}
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,
clock.Now)
clock.Add(150 * time.Minute)
p.mu.Lock()
p.count, p.lastItem = 1234567, clock.Now()
p.mu.Unlock()
p.draw()
width = tc.narrow
before := len(stderr())
p.draw()
p.draw()
p.finish()
lines := strings.FieldsFuncSeq(stderr()[before:], func(r rune) bool {
return r == '\r' || r == '\n'
})
for line := range lines {
if n := utf8.RuneCountInString(line); n >= width {
t.Errorf("%d columns written on a terminal made %d wide: %q",
n, width, line)
}
}
}
}
// TestProgressWarningsOnOwnLines drives the terminal displays, spinner
// and bar, through a run of warnings with no items between them, as when
// the walk meets many unreadable paths, for many redraws: every warning
// must land on a line of its own, never inside a redraw.
//
//nolint:paralleltest // captureStderr replaces the process-wide os.Stderr
func TestProgressWarningsOnOwnLines(t *testing.T) {
stderr := captureStderr(t)
cases := []progressParams{
{label: scanPhase("walk"), total: -1},
{label: scanPhase("hash"), total: 10},
}
issued := 0
for _, params := range cases {
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.
for start := time.Now(); time.Since(start) < 50*testRedraw; issued++ {
p.warnf("warning")
}
p.finish()
}
// A terminal shows each line as the text after its last carriage
// return.
shown := 0
for line := range strings.SplitSeq(stderr(), "\n") {
if !strings.Contains(line, "warning") {
continue
}
shown++
if text := line[strings.LastIndex(line, "\r")+1:]; text != "warning" {
t.Errorf("terminal shows %q, want %q", text, "warning")
}
}
if shown != issued {
t.Errorf("%d warning lines, want %d", shown, issued)
}
}
// TestProgressWriterRowsOnOwnLines drives the terminal displays,
// spinner and bar, through a run of rows written through the display's
// writer to the same terminal, as stdout is in a plain "sfdupes trees",
// each written out at once, for many redraws: the terminal must show
// every row whole, in order, on a line of its own.
//
//nolint:paralleltest // captureStderr replaces the process-wide os.Stderr
func TestProgressWriterRowsOnOwnLines(t *testing.T) {
stderr := captureStderr(t)
cases := []progressParams{
{
label: treesPhase("open"), total: -1,
waitingFor: "opening the database",
},
{label: treesPhase("write"), unit: "groups", total: 10},
}
var want []string
for _, params := range cases {
p := startProgress(params, terminalWidth, testRedraw, time.Now)
out := p.writer(os.Stderr)
// No pause between rows: one is garbled only if a redraw lands
// on its line.
for start := time.Now(); time.Since(start) < 50*testRedraw; {
row := fmt.Sprintf("row %d", len(want))
want = append(want, row)
_, err := fmt.Fprintln(out, row)
if err == nil {
err = out.Flush()
}
if err != nil {
t.Fatal(err)
}
}
p.finish()
}
// A terminal shows each line as the text after its last carriage
// return.
var shown []string
for line := range strings.SplitSeq(stderr(), "\n") {
if strings.Contains(line, "row ") {
shown = append(shown, line[strings.LastIndex(line, "\r")+1:])
}
}
if len(shown) != len(want) {
t.Fatalf("terminal shows %d rows, want %d", len(shown), len(want))
}
for i := range want {
if shown[i] != want[i] {
t.Fatalf("terminal shows %q, want %q", shown[i], want[i])
}
}
}
// TestProgressWriterStalledStdoutKeepsLines writes a row larger than a
// pipe holds through the display's writer to a pipe nobody reads yet,
// as stdout is when its reader has stopped while stderr goes to a file:
// while the write waits, the display must go on printing its line.
//
//nolint:paralleltest // captureStderr replaces the process-wide os.Stderr
func TestProgressWriterStalledStdoutKeepsLines(t *testing.T) {
stderr := captureStderr(t)
r, w, err := os.Pipe()
if err != nil {
t.Fatal(err)
}
t.Cleanup(func() {
_ = w.Close()
_ = r.Close()
})
p := startProgress(progressParams{label: treesPhase("write"), total: 1},
nil, testRedraw, time.Now)
out := p.writer(w)
written := make(chan error, 1)
go func() {
_, writeErr := fmt.Fprintln(out, strings.Repeat("x", ioBufSize))
written <- writeErr
}()
// Pass or fail, the pipe is then read so that the write ends, and
// the display ends before stderr is put back.
t.Cleanup(func() {
go func() {
_, _ = io.Copy(io.Discard, r)
}()
writeErr := <-written
if writeErr != nil {
t.Error(writeErr)
}
p.finish()
})
// The first byte read shows that the write has started; the rest
// of the row waits until the pipe is read.
_, err = r.Read(make([]byte, 1))
if err != nil {
t.Fatal(err)
}
line := "[4/4] write: "
awaitOutput(t, stderr, line, strings.Count(stderr(), line)+3)
}
// TestTerminalStoppedShortKeepsCount checks that the terminal display
// of a phase that stops before its total, as an interrupted one does,
// is left showing the count it stopped at rather than a full bar.
//
//nolint:paralleltest // captureStderr replaces the process-wide os.Stderr
func TestTerminalStoppedShortKeepsCount(t *testing.T) {
stderr := captureStderr(t)
p := startProgress(progressParams{label: scanPhase("hash"), total: 10},
terminalWidth, redrawInterval, time.Now)
p.increment()
p.increment()
p.finish()
if shown := lastFrame(stderr()); !strings.Contains(shown, "[2/10],") {
t.Errorf("terminal shows %q, want a count of 2 of 10", shown)
}
}
// TestWarningAfterLastItemKeepsBar checks that a warning printed after
// a phase's last item, as for a failed read of the last file, leaves the
// phase's full bar on the terminal below the warning.
//
//nolint:paralleltest // captureStderr replaces the process-wide os.Stderr
func TestWarningAfterLastItemKeepsBar(t *testing.T) {
stderr := captureStderr(t)
p := startProgress(progressParams{label: scanPhase("hash"), total: 2},
terminalWidth, testRedraw, time.Now)
p.increment()
p.increment()
awaitOutput(t, stderr, "[2/2],", 1)
p.warnf("warning")
p.finish()
if shown := lastFrame(stderr()); !strings.Contains(shown, "[2/2],") {
t.Errorf("terminal shows %q, want a count of 2 of 2", shown)
}
}