Compare commits
1
Commits
3f4ff92dae
...
52cafd1cd3
| Author | SHA1 | Date | |
|---|---|---|---|
|
|
52cafd1cd3 |
@@ -833,17 +833,34 @@ 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, the
|
||||
word `stalled` and what the phase is doing take the rate's place (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/45678] 27%, stalled reading, elapsed 4m30s, eta 12m9s
|
||||
```
|
||||
|
||||
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 `stalled` and what the phase
|
||||
is doing in place of the rate, which would read 0: `walk` is `listing`
|
||||
directories; `hash` and the content phase's reads are `reading` files; `update`
|
||||
is `writing` to the database; `load` and the `read` phase of `trees` 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. The `read` phase of `report` writes the report while it reads the
|
||||
records and may be waiting on either, so it says `read/write`. 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`,
|
||||
@@ -855,15 +872,18 @@ Additional requirements:
|
||||
times a second, so its elapsed time keeps moving while a phase waits for its
|
||||
next item.
|
||||
- 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 is. The phase and its place, the progress, what a stalled phase is
|
||||
doing, the elapsed time and the ETA are kept whole: a line too wide for the
|
||||
terminal leaves out its rate (or what the phase is waiting for), and a bar
|
||||
with no room beside the parts kept whole gives way to the spinner. The words a
|
||||
stalled phase shows are short, so that a line like the stalled one in the
|
||||
example above, with tens of thousands of files and times in minutes, fits on
|
||||
an 80-column terminal. Only when the parts kept whole 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.
|
||||
files, or about 90 once the phase has stalled, 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
|
||||
|
||||
@@ -29,6 +29,18 @@
|
||||
|
||||
# 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 word `stalled` and
|
||||
what the phase is doing take the rate's place, as `stalled reading`, each
|
||||
phase naming its own work where it is defined; `report`'s `read` says
|
||||
`read/write`, as it writes the report while it reads. Those words are kept
|
||||
whole with the phase, progress, elapsed time and ETA, so only the bar gives
|
||||
way before them, and they fit on an 80-column terminal in an ordinary scan
|
||||
(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
|
||||
|
||||
+104
-35
@@ -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 it has stalled, and what it is doing, in place of the rate.
|
||||
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"
|
||||
)
|
||||
|
||||
// reading is what the display of a phase that reads files or records
|
||||
// says it is doing once it has stalled; see stallTime.
|
||||
const reading = "reading"
|
||||
|
||||
// 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"; 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,41 +438,53 @@ 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 rate, which would read 0, gives way to the word
|
||||
// "stalled" and what the phase is doing, as "stalled reading".
|
||||
//
|
||||
// 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 and its place, the progress, what a stalled phase is doing,
|
||||
// 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(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
|
||||
|
||||
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)
|
||||
tail = fmt.Sprintf("elapsed %s, eta %s", elapsed, p.eta(average))
|
||||
|
||||
if now.Sub(p.lastItem) >= stallTime {
|
||||
head += "stalled " + p.doing + ", "
|
||||
extra = ""
|
||||
}
|
||||
}
|
||||
|
||||
full, kept := head+extra+", "+tail, head+tail
|
||||
full, kept := head+extra+tail, head+tail
|
||||
|
||||
switch {
|
||||
case len(full) <= room:
|
||||
@@ -437,6 +496,16 @@ func (p *progress) line(room int, percent bool) (string, bool) {
|
||||
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
|
||||
|
||||
+280
-38
@@ -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,30 +156,43 @@ 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, but
|
||||
// not what a stalled phase is doing, 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,
|
||||
}
|
||||
|
||||
started := now.Add(-50 * time.Second)
|
||||
stalled := &progress{
|
||||
label: scanPhase("hash"), unit: scanUnit, total: 100, count: 20,
|
||||
doing: reading, start: started, rateStart: started,
|
||||
lastItem: now.Add(-42 * time.Second),
|
||||
drawn: []drawnCount{{at: now.Add(-rateWindow), count: 20}},
|
||||
}
|
||||
|
||||
cases := []struct {
|
||||
p *progress
|
||||
room int
|
||||
@@ -180,10 +220,20 @@ func TestLineFitsRoom(t *testing.T) {
|
||||
p: content, room: 40, percent: true,
|
||||
want: "[5/5] content: elapsed 10s, eta unknown",
|
||||
fits: true,
|
||||
}, {
|
||||
p: stalled, room: 65, percent: true,
|
||||
want: "[3/5] hash: [20/100] 20%, stalled reading, elapsed 50s, " +
|
||||
"eta 3m20s",
|
||||
fits: true,
|
||||
}, {
|
||||
p: stalled, room: 64, percent: true,
|
||||
want: "[3/5] hash: [20/100] 20%, stalled reading, elapsed 50s, " +
|
||||
"eta 3m20",
|
||||
fits: false,
|
||||
}}
|
||||
|
||||
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 +242,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: reading, 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%, stalled reading, 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 +332,137 @@ 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 the phase has stalled, and what it is doing, 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,
|
||||
doing: reading,
|
||||
}, 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 reading, 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: reading,
|
||||
}, 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 reading, 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: reading,
|
||||
}, 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 +505,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 +527,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()
|
||||
@@ -413,6 +599,60 @@ func TestTerminalLinesKeepETA(t *testing.T) {
|
||||
}
|
||||
}
|
||||
|
||||
// TestTerminalStalledLineKeepsWords draws a stalled phase on an
|
||||
// 80-column terminal at an ordinary scan's counts and times, 12345 of
|
||||
// 45678 files read four and a half minutes in, the last 42 seconds ago,
|
||||
// and report's read phase at the same counts: the bar gives way, and
|
||||
// what the phase is doing shows whole in place of the rate, beside the
|
||||
// phase, progress, elapsed time and ETA.
|
||||
//
|
||||
//nolint:paralleltest // captureStderr replaces the process-wide os.Stderr
|
||||
func TestTerminalStalledLineKeepsWords(t *testing.T) {
|
||||
stderr := captureStderr(t)
|
||||
|
||||
cases := []struct {
|
||||
params progressParams
|
||||
want string
|
||||
}{{
|
||||
params: progressParams{
|
||||
label: scanPhase("hash"), unit: scanUnit, total: 45678,
|
||||
doing: reading,
|
||||
},
|
||||
want: "[3/5] hash: [12345/45678] 27%, stalled reading, " +
|
||||
"elapsed 4m30s, eta 12m9s",
|
||||
}, {
|
||||
params: progressParams{
|
||||
label: reportPhase("read"), total: 45678, doing: "read/write",
|
||||
},
|
||||
want: "[2/2] read: [12345/45678] 27%, stalled read/write, " +
|
||||
"elapsed 4m30s, eta 12m9s",
|
||||
}}
|
||||
|
||||
for _, tc := range cases {
|
||||
before := len(stderr())
|
||||
clock := &testClock{now: time.Now()}
|
||||
|
||||
// No timed draws: the display is drawn as it starts and as it
|
||||
// ends.
|
||||
p := startProgress(tc.params, func() int { return 80 }, time.Hour,
|
||||
clock.Now)
|
||||
|
||||
clock.Add(4*time.Minute + 30*time.Second - 42*time.Second)
|
||||
|
||||
p.mu.Lock()
|
||||
p.count, p.lastItem = 12345, clock.Now()
|
||||
p.mu.Unlock()
|
||||
|
||||
clock.Add(42 * time.Second)
|
||||
p.finish()
|
||||
|
||||
shown := lastFrame(stderr()[before:])
|
||||
if !strings.Contains(shown, tc.want) {
|
||||
t.Errorf("terminal shows %q, want %q", shown, tc.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
|
||||
@@ -479,14 +719,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 +770,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 +823,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 +886,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 +929,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 +948,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()
|
||||
|
||||
@@ -74,9 +74,11 @@ func runReport(ctx context.Context, stdout io.Writer) error {
|
||||
|
||||
defer func() { _ = db.Close() }()
|
||||
|
||||
// The read phase writes the report while it reads the records, so a
|
||||
// stall may be in either.
|
||||
prog = newProgress(progressParams{
|
||||
label: reportPhase("read"), unit: "records", total: -1,
|
||||
waitingFor: countingRecords,
|
||||
waitingFor: countingRecords, doing: "read/write",
|
||||
})
|
||||
report, err := readReport(ctx, db, dbPath, stdout, prog)
|
||||
|
||||
|
||||
+2
-2
@@ -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)
|
||||
|
||||
|
||||
@@ -446,7 +446,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: reading,
|
||||
})
|
||||
defer prog.finish()
|
||||
|
||||
@@ -497,7 +497,7 @@ func (s *scanState) walkPhase(
|
||||
|
||||
prog := newProgress(progressParams{
|
||||
label: scanPhase("walk"), unit: scanUnit, total: estimate,
|
||||
estimate: true,
|
||||
estimate: true, doing: "listing",
|
||||
})
|
||||
|
||||
var (
|
||||
@@ -689,6 +689,7 @@ func (s *scanState) readRuns(ctx context.Context, workers int,
|
||||
|
||||
prog := newProgress(progressParams{
|
||||
label: scanPhase(label), unit: scanUnit, total: int64(len(runs)),
|
||||
doing: reading,
|
||||
})
|
||||
defer prog.finish()
|
||||
|
||||
@@ -778,6 +779,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",
|
||||
})
|
||||
|
||||
defer prog.finish()
|
||||
@@ -866,7 +868,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: "searching the database", doing: "searching",
|
||||
})
|
||||
defer prog.finish()
|
||||
|
||||
|
||||
@@ -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: reading,
|
||||
})
|
||||
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",
|
||||
})
|
||||
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",
|
||||
})
|
||||
dupeTrees, reclaimable, err := writeTreeGroups(stdout, dupes, prog)
|
||||
|
||||
|
||||
+1
-1
@@ -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)
|
||||
|
||||
|
||||
Reference in New Issue
Block a user