1 Commits
Author SHA1 Message Date
sneak 52cafd1cd3 Show the progress rate over the last 5 seconds, and what a phase is doing after 10 seconds with no item done (closes #125)
check / check (push) Canceled after 0s
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 what the phase is doing, as "stalled
reading", kept whole with the phase, progress, elapsed time and ETA, so
only the bar gives way before them. report's read phase says
"read/write", as it writes the report while it reads. The tests set the
display's clock by hand.

Deviation: the stall words hold no time; with one, no words naming the
work fit beside the rest at 80 columns.
Judgement call: trees' group phase says "grouping".

Model: opus-5-5
2026-10-16 21:40:05 +00:00
7 changed files with 143 additions and 180 deletions
+23 -26
View File
@@ -799,8 +799,7 @@ A scan has five phases (`[1/5] load`, `[2/5] walk`, `[3/5] hash`,
`head`, and `tail`, without fetching the records. It then says it is searching `head`, and `tail`, without fetching the records. It then says it is searching
the database until SQLite returns the first record; the checks, and their rate the database until SQLite returns the first record; the checks, and their rate
and ETA, start there. The files to read then get a display of their own, with and ETA, start there. The files to read then get a display of their own, with
their count as its total, and so does the writing of the last of their records their count as its total.
to the database, with the count of those records as its total.
`trees` has four phases (`[1/4] open`, `[2/4] read`, `[3/4] group`, `trees` has four phases (`[1/4] open`, `[2/4] read`, `[3/4] group`,
`[4/4] write`, see "`trees` mode"): `[4/4] write`, see "`trees` mode"):
@@ -838,7 +837,7 @@ Each display is one line holding:
or, when stderr is not a terminal, since the line before, so it falls to 0 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 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 rather than as a steady rate. Once no item has completed for 10 seconds, the
word `stalled` and where the phase waits take the rate's place (see below). word `stalled` and what the phase is doing take the rate's place (see below).
- elapsed time - elapsed time
- estimated time remaining, or `unknown`. It comes from the phase's average rate - 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. since it started counting, so that it does not swing with each burst.
@@ -848,20 +847,18 @@ Example shape (exact layout is flexible, content is not):
``` ```
[3/5] hash: [12345/98765] 12% |████ | 92 files/s elapsed 2:32 eta 17:54 [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 [2/5] walk: [1234567/~1200000] 103%, 5120 files/s, elapsed 4m1s, eta unknown
[3/5] hash: [12345/45678] 27%, stalled disk/db, elapsed 4m30s, eta 12m9s [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 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 where the disk is slow or the database is busy, the line says `stalled` and what the phase
phase waits in place of the rate, which would read 0: `disk` for files, `db` for is doing in place of the rate, which would read 0: `walk` is `listing`
the database, `out` for stdout, and two of them, as `disk/db`, for a phase that directories; `hash` and the content phase's reads are `reading` files; `update`
may wait on either. `walk` says `disk`. `hash` and the content phase's reads say is `writing` to the database; `load` and the `read` phase of `trees` are
`disk/db`, as they read files and write their records to the database between `reading` the database; the content phase's checks are `searching` the database;
them, and so do the content phase's checks, which `lstat` each record's file as `trees`' `group` is `grouping` directories, and its `write` is `writing` the
the database search returns it. `load`, `update`, the content phase's last write report. The `read` phase of `report` writes the report while it reads the
and the `read` phase of `trees` say `db`. `trees`' `write` says `out`, and its records and may be waiting on either, so it says `read/write`. A phase still
`group`, which works in memory, says `cpu`. The `read` phase of `report` writes
the report while it reads the records, so it says `db/out`. A phase still
waiting for its total already says what it waits for, and says nothing more. waiting for its total already says what it waits for, and says nothing more.
Additional requirements: Additional requirements:
@@ -875,18 +872,18 @@ Additional requirements:
times a second, so its elapsed time keeps moving while a phase waits for its times a second, so its elapsed time keeps moving while a phase waits for its
next item. next item.
- On a terminal no line reaches the terminal's last column, however narrow the - On a terminal no line reaches the terminal's last column, however narrow the
terminal is. A line too wide for the terminal first loses its bar, which gives terminal is. The phase and its place, the progress, what a stalled phase is
way to the spinner, then its rate, the words of a stalled phase, or what the doing, the elapsed time and the ETA are kept whole: a line too wide for the
phase is waiting for. The phase and its place, the progress, the elapsed time terminal leaves out its rate (or what the phase is waiting for), and a bar
and the ETA are kept whole. On an 80-column terminal, a stalled line at counts with no room beside the parts kept whole gives way to the spinner. The words a
and times like those of the stalled line in the example above keeps its words stalled phase shows are short, so that a line like the stalled one in the
whole in every phase; where the words and the ETA do not both fit, as at example above, with tens of thousands of files and times in minutes, fits on
millions of files and times in hours, the words give way. Only when those four an 80-column terminal. Only when the parts kept whole are too wide, as on a
alone are too wide, as on a terminal narrower than about 70 columns hours into terminal narrower than about 70 columns hours into a scan of millions of
a scan of millions of files, is the line cut short at the terminal's edge, so files, or about 90 once the phase has stalled, is the line cut short at the
the end of the ETA is lost first. A terminal made narrower while a phase runs terminal's edge, so the end of the ETA is lost first. A terminal made narrower
gets the same: the next draw erases the line within the new width and fits the while a phase runs gets the same: the next draw erases the line within the new
line to it, and the display goes on redrawing in place. 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 - 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 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 runs (whether or not an item has completed, and never more often), and once
+6 -8
View File
@@ -34,14 +34,12 @@
to 0 while nothing completes, and a burst after a wait no longer reads as a 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 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 average. Once no item has completed for 10 seconds, the word `stalled` and
where the phase waits take the rate's place, as `stalled disk/db`: `disk`, what the phase is doing take the rate's place, as `stalled reading`, each
`db`, `out` for stdout or `cpu`, or two of them for a phase that may wait on phase naming its own work where it is defined; `report`'s `read` says
either, each phase giving its word where it is defined. A line too wide for `read/write`, as it writes the report while it reads. Those words are kept
the terminal loses its bar first, then its rate or those words, so the phase, whole with the phase, progress, elapsed time and ETA, so only the bar gives
progress, elapsed time and ETA stay whole; on an 80-column terminal the words way before them, and they fit on an 80-column terminal in an ordinary scan
fit beside them in an ordinary scan. The content phase's last partial batch is (2026-10-16, https://git.eeqj.de/sneak/sfdupes/issues/125)
now written under a display of its own (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 - 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 a name, a tab and the value: its path and where it came from, the sizes of the
+30 -23
View File
@@ -28,7 +28,7 @@ const redrawInterval = 100 * time.Millisecond
const rateWindow = 5 * time.Second const rateWindow = 5 * time.Second
// stallTime is how long a phase goes with no item completed before its // stallTime is how long a phase goes with no item completed before its
// line says it has stalled, and where it waits, in place of the rate. // line says it has stalled, and what it is doing, in place of the rate.
const stallTime = 10 * time.Second const stallTime = 10 * time.Second
// spinnerType selects the progressbar library's spinner style. // spinnerType selects the progressbar library's spinner style.
@@ -68,6 +68,10 @@ const (
openingDatabase = "opening the database" 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. // stderrIsTTY reports whether stderr is attached to a terminal.
func stderrIsTTY() bool { func stderrIsTTY() bool {
return term.IsTerminal(int(os.Stderr.Fd())) return term.IsTerminal(int(os.Stderr.Fd()))
@@ -98,7 +102,7 @@ type progressParams struct {
total int64 // the items the phase will complete; -1 when not known total int64 // the items the phase will complete; -1 when not known
estimate bool // total is an estimate, which the count may pass estimate bool // total is an estimate, which the count may pass
waitingFor string // what the phase waits for until setTotal is called waitingFor string // what the phase waits for until setTotal is called
stalledOn string // where the phase waits, as "disk/db"; see stallTime doing string // what the phase is doing, as "reading"; see stallTime
} }
// drawnCount is the count of items completed as of one draw, and when // drawnCount is the count of items completed as of one draw, and when
@@ -138,7 +142,7 @@ type progress struct {
total int64 total int64
estimate bool estimate bool
waitingFor string waitingFor string
stalledOn string doing string
count int64 count int64
start time.Time // when the phase started, for the elapsed time start time.Time // when the phase started, for the elapsed time
rateStart time.Time // when the count started, for the ETA rateStart time.Time // when the count started, for the ETA
@@ -172,7 +176,7 @@ func startProgress(params progressParams, width func() int,
stop: make(chan struct{}), done: make(chan struct{}), stop: make(chan struct{}), done: make(chan struct{}),
label: params.label, unit: params.unit, total: params.total, label: params.label, unit: params.unit, total: params.total,
estimate: params.estimate, waitingFor: params.waitingFor, estimate: params.estimate, waitingFor: params.waitingFor,
stalledOn: params.stalledOn, start: start, rateStart: start, doing: params.doing, start: start, rateStart: start,
lastItem: start, drawn: []drawnCount{{at: start}}, lastItem: start, drawn: []drawnCount{{at: start}},
} }
@@ -215,27 +219,26 @@ func (p *progress) draw() {
} }
if p.width == nil { if p.width == nil {
fmt.Fprintln(os.Stderr, p.line(now, math.MaxInt, true)) text, _ := p.line(now, math.MaxInt, true)
fmt.Fprintln(os.Stderr, text)
return return
} }
width := p.width() width := p.width()
// A phase with an exact total gets the library's bar when its whole // A phase with an exact total gets the library's bar when its line,
// line, without the percent the bar shows, fits beside the bar: the // without the percent the bar shows, fits whole beside the bar. A
// bar gives way before any part of the line. A total of 0 leaves the // total of 0 leaves the bar nothing to fill.
// bar nothing to fill.
text, withBar := "", false text, withBar := "", false
if p.total > 0 && !p.estimate { if p.total > 0 && !p.estimate {
text = p.line(now, math.MaxInt, false) text, withBar = p.line(now, width-barMargin, false)
withBar = len(text) <= width-barMargin
} }
margin := barMargin margin := barMargin
if !withBar { if !withBar {
margin = spinnerMargin margin = spinnerMargin
text = p.line(now, width-margin, true) text, _ = p.line(now, width-margin, true)
} }
// The library makes a bar or a spinner, and before each draw erases // The library makes a bar or a spinner, and before each draw erases
@@ -446,14 +449,17 @@ func (p *progress) finish() {
// rate is that since the first draw in drawn, and the ETA comes from // 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 // 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 // stallTime, the rate, which would read 0, gives way to the word
// "stalled" and where the phase waits, as "stalled disk/db". // "stalled" and what the phase is doing, as "stalled reading".
// //
// The phase and its place, the progress, the elapsed time and the ETA // The phase and its place, the progress, what a stalled phase is doing,
// are kept whole. A line wider than room leaves out the rate, the words // the elapsed time and the ETA are kept whole. A line wider than room
// of a stalled phase, or what the phase waits for; only if it is still // leaves out the rate, or what the phase waits for; only if it is still
// wider is it cut at room. Every part is ASCII, so its length is its // wider is it cut at room, and line reports that it does not fit. Every
// width in columns. p.mu must be held. // part is ASCII, so its length is its width in columns. p.mu must be
func (p *progress) line(now time.Time, room int, percent bool) string { // held.
func (p *progress) line(now time.Time, room int,
percent bool,
) (string, bool) {
elapsed := now.Sub(p.start).Round(time.Second) elapsed := now.Sub(p.start).Round(time.Second)
// head and tail hold the parts kept whole; extra, between them, is // head and tail hold the parts kept whole; extra, between them, is
@@ -473,7 +479,8 @@ func (p *progress) line(now time.Time, room int, percent bool) string {
tail = fmt.Sprintf("elapsed %s, eta %s", elapsed, p.eta(average)) tail = fmt.Sprintf("elapsed %s, eta %s", elapsed, p.eta(average))
if now.Sub(p.lastItem) >= stallTime { if now.Sub(p.lastItem) >= stallTime {
extra = "stalled " + p.stalledOn + ", " head += "stalled " + p.doing + ", "
extra = ""
} }
} }
@@ -481,12 +488,12 @@ func (p *progress) line(now time.Time, room int, percent bool) string {
switch { switch {
case len(full) <= room: case len(full) <= room:
return full return full, true
case len(kept) <= room: case len(kept) <= room:
return kept return kept, true
} }
return kept[:max(room, 0)] return kept[:max(room, 0)], false
} }
// perSecond returns count items over d as items a second, or 0 when no // perSecond returns count items over d as items a second, or 0 when no
+71 -97
View File
@@ -22,10 +22,6 @@ const testRedraw = time.Millisecond
// it expects. // it expects.
const testDeadline = 5 * time.Second 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 // testClock is a clock a test moves by hand, for a display that reads
// it from its own goroutine too. // it from its own goroutine too.
type testClock struct { type testClock struct {
@@ -163,7 +159,7 @@ func TestProgressLine(t *testing.T) {
tc.p.start, tc.p.rateStart, tc.p.lastItem = ago, ago, now tc.p.start, tc.p.rateStart, tc.p.lastItem = ago, ago, now
tc.p.drawn = []drawnCount{{at: ago}} tc.p.drawn = []drawnCount{{at: ago}}
if got := tc.p.line(now, 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) t.Errorf("line = %q, want %q", got, tc.want)
} }
} }
@@ -171,9 +167,9 @@ func TestProgressLine(t *testing.T) {
// TestLineFitsRoom checks how a line is fitted to the room it has, ten // 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 // 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 // the last 42: it leaves out the rate, or what the phase waits for, but
// words of a stalled phase, and is cut only when what is left is still // not what a stalled phase is doing, and is cut only when what is left
// too wide. // is still too wide.
func TestLineFitsRoom(t *testing.T) { func TestLineFitsRoom(t *testing.T) {
t.Parallel() t.Parallel()
@@ -192,7 +188,7 @@ func TestLineFitsRoom(t *testing.T) {
started := now.Add(-50 * time.Second) started := now.Add(-50 * time.Second)
stalled := &progress{ stalled := &progress{
label: scanPhase("hash"), unit: scanUnit, total: 100, count: 20, label: scanPhase("hash"), unit: scanUnit, total: 100, count: 20,
stalledOn: hashStalledOn, start: started, rateStart: started, doing: reading, start: started, rateStart: started,
lastItem: now.Add(-42 * time.Second), lastItem: now.Add(-42 * time.Second),
drawn: []drawnCount{{at: now.Add(-rateWindow), count: 20}}, drawn: []drawnCount{{at: now.Add(-rateWindow), count: 20}},
} }
@@ -202,44 +198,52 @@ func TestLineFitsRoom(t *testing.T) {
room int room int
percent bool percent bool
want string want string
fits bool
}{{ }{{
p: hash, room: 57, percent: true, p: hash, room: 57, percent: true,
want: "[3/5] hash: [20/100] 20%, 2 files/s, elapsed 10s, eta 40s", want: "[3/5] hash: [20/100] 20%, 2 files/s, elapsed 10s, eta 40s",
fits: true,
}, { }, {
p: hash, room: 56, percent: true, p: hash, room: 56, percent: true,
want: "[3/5] hash: [20/100] 20%, elapsed 10s, eta 40s", want: "[3/5] hash: [20/100] 20%, elapsed 10s, eta 40s",
fits: true,
}, { }, {
p: hash, room: 45, percent: true, p: hash, room: 45, percent: true,
want: "[3/5] hash: [20/100] 20%, elapsed 10s, eta 40", want: "[3/5] hash: [20/100] 20%, elapsed 10s, eta 40",
fits: false,
}, { }, {
// Before the library's bar, which shows the percent. // Before the library's bar, which shows the percent.
p: hash, room: 57, percent: false, p: hash, room: 57, percent: false,
want: "[3/5] hash: [20/100], 2 files/s, elapsed 10s, eta 40s", want: "[3/5] hash: [20/100], 2 files/s, elapsed 10s, eta 40s",
fits: true,
}, { }, {
p: content, room: 40, percent: true, p: content, room: 40, percent: true,
want: "[5/5] content: elapsed 10s, eta unknown", want: "[5/5] content: elapsed 10s, eta unknown",
fits: true,
}, { }, {
p: stalled, room: 65, percent: true, p: stalled, room: 65, percent: true,
want: "[3/5] hash: [20/100] 20%, stalled disk/db, elapsed 50s, " + want: "[3/5] hash: [20/100] 20%, stalled reading, elapsed 50s, " +
"eta 3m20s", "eta 3m20s",
fits: true,
}, { }, {
p: stalled, room: 64, percent: true, p: stalled, room: 64, percent: true,
want: "[3/5] hash: [20/100] 20%, elapsed 50s, eta 3m20s", want: "[3/5] hash: [20/100] 20%, stalled reading, elapsed 50s, " +
"eta 3m20",
fits: false,
}} }}
for _, tc := range cases { for _, tc := range cases {
if got := tc.p.line(now, tc.room, tc.percent); got != tc.want { got, fits := tc.p.line(now, tc.room, tc.percent)
t.Errorf("line(%d, %t) = %q, want %q", if got != tc.want || fits != tc.fits {
tc.room, tc.percent, got, tc.want) t.Errorf("line(%d, %t) = %q, %t, want %q, %t",
tc.room, tc.percent, got, fits, tc.want, tc.fits)
} }
} }
} }
// TestSetTotalStartsRate checks that setTotal starts a phase's rate, // TestSetTotalStartsRate checks that setTotal starts a phase's rate,
// its ETA and its time with no record read from when the total becomes // 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 // known, not from when the phase started waiting for it.
// 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) { func TestSetTotalStartsRate(t *testing.T) {
t.Parallel() t.Parallel()
@@ -247,33 +251,28 @@ func TestSetTotalStartsRate(t *testing.T) {
waited := clock.Now().Add(-20 * time.Second) waited := clock.Now().Add(-20 * time.Second)
p := &progress{ p := &progress{
now: clock.Now, label: scanPhase("load"), unit: scanUnit, total: -1, now: clock.Now, label: scanPhase("load"), unit: scanUnit, total: -1,
stalledOn: "db", start: waited, rateStart: waited, doing: reading, start: waited, rateStart: waited,
lastItem: waited, drawn: []drawnCount{{at: waited}}, lastItem: waited, drawn: []drawnCount{{at: waited}},
} }
p.setTotal(100) p.setTotal(100)
clock.Add(5 * time.Second) // Ten seconds after the total came, no record has been read yet.
clock.Add(10 * time.Second)
want := "[1/5] load: [0/100] 0%, 0 files/s, elapsed 25s, eta unknown" want := "[1/5] load: [0/100] 0%, stalled reading, elapsed 30s, " +
if got := p.line(clock.Now(), math.MaxInt, true); got != want { "eta unknown"
if got, _ := p.line(clock.Now(), math.MaxInt, true); got != want {
t.Errorf("line = %q, want %q", got, want) t.Errorf("line = %q, want %q", got, want)
} }
clock.Add(5 * time.Second) // Then 20 are.
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 { for range 20 {
p.increment() p.increment()
} }
want = "[1/5] load: [20/100] 20%, 2 files/s, elapsed 30s, eta 40s" 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 { if got, _ := p.line(clock.Now(), math.MaxInt, true); got != want {
t.Errorf("line = %q, want %q", got, want) t.Errorf("line = %q, want %q", got, want)
} }
} }
@@ -344,8 +343,8 @@ func TestPlainProgressPrintsWhileWaiting(t *testing.T) {
// coming, as when one large file is being read or a disk is slow, goes // 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 // 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 // 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 // line says the phase has stalled, and what it is doing, in place of
// rate. The test moves the display's clock by hand. // the rate. The test moves the display's clock by hand.
// //
//nolint:paralleltest // captureStderr replaces the process-wide os.Stderr //nolint:paralleltest // captureStderr replaces the process-wide os.Stderr
func TestPlainProgressStalledProducer(t *testing.T) { func TestPlainProgressStalledProducer(t *testing.T) {
@@ -353,7 +352,7 @@ func TestPlainProgressStalledProducer(t *testing.T) {
clock := &testClock{now: time.Now()} clock := &testClock{now: time.Now()}
p := startProgress(progressParams{ p := startProgress(progressParams{
label: scanPhase("hash"), unit: scanUnit, total: 100, label: scanPhase("hash"), unit: scanUnit, total: 100,
stalledOn: hashStalledOn, doing: reading,
}, nil, testRedraw, clock.Now) }, nil, testRedraw, clock.Now)
// Pass or fail, the display ends before stderr is put back. // Pass or fail, the display ends before stderr is put back.
@@ -374,7 +373,7 @@ func TestPlainProgressStalledProducer(t *testing.T) {
clock.Add(4 * time.Second) clock.Add(4 * time.Second)
awaitOutput(t, stderr, awaitOutput(t, stderr,
"[3/5] hash: [20/100] 20%, stalled disk/db, elapsed 10s, eta 40s\n", "[3/5] hash: [20/100] 20%, stalled reading, elapsed 10s, eta 40s\n",
3) 3)
} }
@@ -392,7 +391,7 @@ func TestPlainProgressRateAfterStall(t *testing.T) {
// No timed draws: the test draws. // No timed draws: the test draws.
p := startProgress(progressParams{ p := startProgress(progressParams{
label: scanPhase("hash"), unit: scanUnit, total: 1000, label: scanPhase("hash"), unit: scanUnit, total: 1000,
stalledOn: hashStalledOn, doing: reading,
}, nil, time.Hour, clock.Now) }, nil, time.Hour, clock.Now)
late := plainInterval + time.Millisecond late := plainInterval + time.Millisecond
@@ -412,7 +411,7 @@ func TestPlainProgressRateAfterStall(t *testing.T) {
want := []string{ 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 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, elapsed 5s, eta unknown",
"[3/5] hash: [0/1000] 0%, stalled disk/db, elapsed 10s, 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", "[3/5] hash: [100/1000] 10%, 20 files/s, elapsed 15s, eta 2m15s",
} }
@@ -437,7 +436,7 @@ func TestProgressRateAfterStallRedrawn(t *testing.T) {
// No timed draws: the test draws. // No timed draws: the test draws.
p := startProgress(progressParams{ p := startProgress(progressParams{
label: scanPhase("hash"), unit: scanUnit, total: 1000, label: scanPhase("hash"), unit: scanUnit, total: 1000,
stalledOn: hashStalledOn, doing: reading,
}, nil, time.Hour, clock.Now) }, nil, time.Hour, clock.Now)
// redraw draws the display every redrawInterval for d. // redraw draws the display every redrawInterval for d.
@@ -600,81 +599,56 @@ func TestTerminalLinesKeepETA(t *testing.T) {
} }
} }
// TestTerminalStalledLines draws every phase's line on an 80-column // TestTerminalStalledLineKeepsWords draws a stalled phase on an
// terminal once the phase has stalled, its last item done 42 seconds // 80-column terminal at an ordinary scan's counts and times, 12345 of
// before. At an ordinary scan's counts and times, 12345 of 45678 items // 45678 files read four and a half minutes in, the last 42 seconds ago,
// done four and a half minutes in, the line shows where the phase waits // and report's read phase at the same counts: the bar gives way, and
// whole, beside the phase, progress, elapsed time and ETA. At a large // what the phase is doing shows whole in place of the rate, beside the
// scan's, 1234567 of 9876543 two and a half hours in, those four still // phase, progress, elapsed time and ETA.
// show whole, as the words give way first where they do not fit.
// //
//nolint:paralleltest // captureStderr replaces the process-wide os.Stderr //nolint:paralleltest // captureStderr replaces the process-wide os.Stderr
func TestTerminalStalledLines(t *testing.T) { func TestTerminalStalledLineKeepsWords(t *testing.T) {
stderr := captureStderr(t) stderr := captureStderr(t)
// drawStalled draws the display params describes as it starts and cases := []struct {
// once more as it ends, with count of total items done elapsed into params progressParams
// the phase, and returns what the terminal shows. want string
drawStalled := func(params progressParams, total, count int64, }{{
elapsed time.Duration, params: progressParams{
) string { 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()) before := len(stderr())
clock := &testClock{now: time.Now()} clock := &testClock{now: time.Now()}
params.total = total
// No timed draws come between the two. // No timed draws: the display is drawn as it starts and as it
p := startProgress(params, func() int { return 80 }, time.Hour, // ends.
p := startProgress(tc.params, func() int { return 80 }, time.Hour,
clock.Now) clock.Now)
clock.Add(elapsed - 42*time.Second) clock.Add(4*time.Minute + 30*time.Second - 42*time.Second)
p.mu.Lock() p.mu.Lock()
p.count, p.lastItem = count, clock.Now() p.count, p.lastItem = 12345, clock.Now()
p.mu.Unlock() p.mu.Unlock()
clock.Add(42 * time.Second) clock.Add(42 * time.Second)
p.finish() p.finish()
return lastFrame(stderr()[before:]) shown := lastFrame(stderr()[before:])
} if !strings.Contains(shown, tc.want) {
t.Errorf("terminal shows %q, want %q", shown, tc.want)
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)
}
} }
} }
} }
@@ -721,7 +695,7 @@ func TestTerminalLinesFitWidth(t *testing.T) {
// times. Nothing written after that, the erase before each redraw // times. Nothing written after that, the erase before each redraw
// included, may reach the narrower terminal's last column: it would // included, may reach the narrower terminal's last column: it would
// wrap, and every redraw would leave a line behind. At these widths the // 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. // spinner stays a spinner and the bar stays a bar.
// //
//nolint:paralleltest // captureStderr replaces the process-wide os.Stderr //nolint:paralleltest // captureStderr replaces the process-wide os.Stderr
func TestTerminalNarrowedRedrawsInPlace(t *testing.T) { func TestTerminalNarrowedRedrawsInPlace(t *testing.T) {
+3 -3
View File
@@ -74,11 +74,11 @@ func runReport(ctx context.Context, stdout io.Writer) error {
defer func() { _ = db.Close() }() defer func() { _ = db.Close() }()
// The read phase writes the report to stdout while it reads the // The read phase writes the report while it reads the records, so a
// records, so it may wait on either. // stall may be in either.
prog = newProgress(progressParams{ prog = newProgress(progressParams{
label: reportPhase("read"), unit: "records", total: -1, label: reportPhase("read"), unit: "records", total: -1,
waitingFor: countingRecords, stalledOn: "db/out", waitingFor: countingRecords, doing: "read/write",
}) })
report, err := readReport(ctx, db, dbPath, stdout, prog) report, err := readReport(ctx, db, dbPath, stdout, prog)
+7 -18
View File
@@ -446,7 +446,7 @@ func (s *scanState) loadIndex(ctx context.Context, roots []string) error {
// first gives the display its total. // first gives the display its total.
prog := newProgress(progressParams{ prog := newProgress(progressParams{
label: scanPhase("load"), unit: scanUnit, total: -1, label: scanPhase("load"), unit: scanUnit, total: -1,
waitingFor: countingRecords, stalledOn: "db", waitingFor: countingRecords, doing: reading,
}) })
defer prog.finish() defer prog.finish()
@@ -497,7 +497,7 @@ func (s *scanState) walkPhase(
prog := newProgress(progressParams{ prog := newProgress(progressParams{
label: scanPhase("walk"), unit: scanUnit, total: estimate, label: scanPhase("walk"), unit: scanUnit, total: estimate,
estimate: true, stalledOn: "disk", estimate: true, doing: "listing",
}) })
var ( var (
@@ -687,11 +687,9 @@ func (s *scanState) readRuns(ctx context.Context, workers int,
pool := startHashPool(ctx, runs, workers, hash) pool := startHashPool(ctx, runs, workers, hash)
defer pool.stop() defer pool.stop()
// Between results the phase may wait on a file being read or on a
// batch of records being written.
prog := newProgress(progressParams{ prog := newProgress(progressParams{
label: scanPhase(label), unit: scanUnit, total: int64(len(runs)), label: scanPhase(label), unit: scanUnit, total: int64(len(runs)),
stalledOn: "disk/db", doing: reading,
}) })
defer prog.finish() defer prog.finish()
@@ -781,7 +779,7 @@ func (s *scanState) updatePhase(ctx context.Context) error {
total := len(s.batch) + len(s.sentinels) + len(deletes) total := len(s.batch) + len(s.sentinels) + len(deletes)
prog := newProgress(progressParams{ prog := newProgress(progressParams{
label: scanPhase("update"), unit: scanUnit, total: int64(total), label: scanPhase("update"), unit: scanUnit, total: int64(total),
stalledOn: "db", doing: "writing",
}) })
defer prog.finish() defer prog.finish()
@@ -844,15 +842,7 @@ func (s *scanState) contentPhase(ctx context.Context, workers int) error {
return err return err
} }
// The last partial batch is written under a display of its own, as return applyChanges(ctx, s.db, s.batch, nil, nil)
// the update phase writes the hash phase's.
prog := newProgress(progressParams{
label: scanPhase("content"), unit: scanUnit,
total: int64(len(s.batch)), stalledOn: "db",
})
defer prog.finish()
return applyChanges(ctx, s.db, s.batch, nil, prog)
} }
// contentCandidates returns the files the content phase reads, and // contentCandidates returns the files the content phase reads, and
@@ -875,11 +865,10 @@ func (s *scanState) contentCandidates(
// without a display the scan looks hung before the reads begin. // without a display the scan looks hung before the reads begin.
// The display says it is searching until SQLite returns the first // The display says it is searching until SQLite returns the first
// record. The checks start there, against a count of the records // record. The checks start there, against a count of the records
// the search returns, and so do their rate and ETA. Between records // the search returns, and so do their rate and ETA.
// they may wait on a file's lstat or on the search.
prog := newProgress(progressParams{ prog := newProgress(progressParams{
label: scanPhase("content"), unit: scanUnit, total: -1, label: scanPhase("content"), unit: scanUnit, total: -1,
waitingFor: "searching the database", stalledOn: "disk/db", waitingFor: "searching the database", doing: "searching",
}) })
defer prog.finish() defer prog.finish()
+3 -5
View File
@@ -72,7 +72,7 @@ func runTrees(ctx context.Context, stdout io.Writer) error {
prog = newProgress(progressParams{ prog = newProgress(progressParams{
label: treesPhase("read"), unit: "records", total: -1, label: treesPhase("read"), unit: "records", total: -1,
waitingFor: countingRecords, stalledOn: "db", waitingFor: countingRecords, doing: reading,
}) })
records, super, allDirs, err := readTree(ctx, db, prog) records, super, allDirs, err := readTree(ctx, db, prog)
@@ -82,11 +82,9 @@ func runTrees(ctx context.Context, stdout io.Writer) error {
return fmt.Errorf("database %s: %w", dbPath, err) return fmt.Errorf("database %s: %w", dbPath, err)
} }
// Grouping works in memory, so it waits on nothing but the
// processor.
prog = newProgress(progressParams{ prog = newProgress(progressParams{
label: treesPhase("group"), unit: "directories", label: treesPhase("group"), unit: "directories",
total: int64(len(allDirs)), stalledOn: "cpu", total: int64(len(allDirs)), doing: "grouping",
}) })
dupes := collectTreeGroups(allDirs, super, prog) dupes := collectTreeGroups(allDirs, super, prog)
@@ -94,7 +92,7 @@ func runTrees(ctx context.Context, stdout io.Writer) error {
prog = newProgress(progressParams{ prog = newProgress(progressParams{
label: treesPhase("write"), unit: "groups", total: int64(len(dupes)), label: treesPhase("write"), unit: "groups", total: int64(len(dupes)),
stalledOn: "out", doing: "writing",
}) })
dupeTrees, reclaimable, err := writeTreeGroups(stdout, dupes, prog) dupeTrees, reclaimable, err := writeTreeGroups(stdout, dupes, prog)