From 510b545ae51abfd0800a3039d0f80dcd26b63df5 Mon Sep 17 00:00:00 2001 From: clawbot <35+clawbot@noreply.example.org> Date: Fri, 16 Oct 2026 17:23:52 +0000 Subject: [PATCH] trees: show its phases as N of M, with progress, elapsed time and ETA (closes #113) trees now runs in four phases, open, read, group and write, each under the progress display scan uses, until the summary line. open covers a wait on a busy database. read counts the records and reads them in one read-only transaction, so the two agree during a scan; group counts the directories, and write the groups. The rows reach stdout through a writer that clears the display and holds its lock while writing, so no row shares a line with the display on a shared terminal. Each rate names what its phase counts. Judgement call: opening the database is a phase of its own, so there are four phases, not the three the issue sketches. Model: opus-5-5 --- README.md | 54 +++++++++++------ TODO.md | 11 ++++ db.go | 30 ++++++++-- db_test.go | 53 ++++++++++++++++- main_test.go | 29 +++++++--- progress.go | 75 ++++++++++++++++++++---- progress_test.go | 148 +++++++++++++++++++++++++++++++++++++++++------ scan.go | 15 +++-- scan_test.go | 6 +- trees.go | 130 +++++++++++++++++++++++++++++++++-------- trees_test.go | 114 +++++++++++++++++++++++++++++++++--- 11 files changed, 566 insertions(+), 99 deletions(-) diff --git a/README.md b/README.md index 5c7459f..0db2a54 100644 --- a/README.md +++ b/README.md @@ -695,6 +695,12 @@ Processing: - Order groups by total tree size descending, tie-broken by `first` path ascending. Output must be fully deterministic for a given input. +`trees` runs in four phases, each with its own progress display on stderr (see +"Progress"): `open` opens the database; `read` counts the records, then reads +them in path order, building the hierarchy and computing the digests as it goes; +`group` groups the directories by digest and picks the maximal groups; `write` +writes the groups to stdout. + #### Trees output format TSV on stdout: a header line, then one row per duplicate tree (N-1 rows for a @@ -715,13 +721,16 @@ units. ### Progress -Use the progress-bar library for all scan progress; rendering in the style of -`pv` is the model. All progress goes to stderr. +Use the progress-bar library for all progress of `scan` and `trees`; rendering +in the style of `pv` is the model. All progress goes to stderr. -A scan must always show that it is working and not hung. Each phase gets its own -display from the moment it starts, naming the phase and its place among the five -(`[1/5] load`, `[2/5] walk`, `[3/5] hash`, `[4/5] update`, `[5/5] content`) and -showing its progress, its elapsed time and its estimated time remaining (ETA): +`scan` and `trees` must always show that they are working and not hung. Each +phase gets its own display from the moment it starts, naming the phase and its +place among the command's phases and showing its progress, its elapsed time and +its estimated time remaining (ETA). + +A scan has five phases (`[1/5] load`, `[2/5] walk`, `[3/5] hash`, +`[4/5] update`, `[5/5] content`): - `load` counts the records first, then reads them against that count. While the count runs, the display says it is counting the records. @@ -738,12 +747,23 @@ showing its progress, its elapsed time and its estimated time remaining (ETA): and ETA, start there. The files to read then get a display of their own, with their count as its total. +`trees` has four phases (`[1/4] open`, `[2/4] read`, `[3/4] group`, +`[4/4] write`, see "`trees` mode"): + +- `open` has no total. While it opens the database, waiting on a busy one + included, the display says it is opening the database. +- `read` counts the records first, then reads them against that count. While the + count runs, the display says it is counting the records. +- `group` has the directories `read` found as its total, and `write` the + duplicate-tree groups. + Each display is one line holding: - the phase and its place among the phases - 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) +- current rate (items/s), naming the items the phase counts: files, records, + directories or groups - elapsed time - estimated time remaining, or `unknown` @@ -756,13 +776,13 @@ Example shape (exact layout is flexible, content is not): Additional requirements: -- On a terminal, a phase with an exact total (every phase but `walk`, once it - has counted what it will do) is drawn as its line followed by the progress-bar - library's bar, 10 columns wide, which shows the percent in place of the line's - own. Any other phase, and a phase whose bar has no room, is drawn as the - library's spinner followed by its line. Each display is drawn again several - times a second, so its elapsed time keeps moving while a phase waits for its - next item. +- On a terminal, a phase with an exact total (every phase but `scan`'s `walk` + and `trees`' `open`, once it has counted what it will do) is drawn as its line + followed by the progress-bar library's bar, 10 columns wide, which shows the + percent in place of the line's own. Any other phase, and a phase whose bar has + no room, is drawn as the library's spinner followed by its line. Each display + is drawn again several 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 @@ -781,11 +801,11 @@ Additional requirements: goroutine counts the items, and each display draws them from a goroutine of its own. - A warning printed during a phase always lands on a line of its own, never - inside the progress display. + inside the progress display. So does every line written to stdout when stdout + is the same terminal, as in a plain `sfdupes trees`. - A phase that stops short of its total, as an interrupted one does, is left showing the count it stopped at rather than filled up. -- `report` and `trees` modes need no progress display, only their stderr - summaries. +- `report` mode needs no progress display, only its stderr summary. ### Error handling and exit codes diff --git a/TODO.md b/TODO.md index aec4797..7ad3b93 100644 --- a/TODO.md +++ b/TODO.md @@ -29,6 +29,17 @@ # Completed Steps +- `trees` shows its work on stderr in four phases, `[1/4] open`, `[2/4] read`, + `[3/4] group` and `[4/4] write`, each with the progress display `scan` uses, + from the moment it starts until the summary line: `open` says it is opening + the database, also while it waits on a busy one; `read` counts the records, + then reads them against that count; `group` counts the directories it groups, + and `write` the groups it writes. A display's rate names what its phase + counts: files, records, directories or groups. stdout and the summary line are + unchanged, and when stdout is the same terminal, none of its lines shares a + line with the display (2026-10-16, + https://git.eeqj.de/sneak/sfdupes/issues/113) + - each `scan` phase's progress display names the phase and its place among the five, as `[2/5] walk`, from the moment it starts, with its progress, elapsed time and ETA: `load` counts the records first, the walk's total is estimated diff --git a/db.go b/db.go index 596408f..fc23c6a 100644 --- a/db.go +++ b/db.go @@ -403,10 +403,32 @@ func userVersion(ctx context.Context, db *sql.DB) (int, error) { return v, nil } -// loadFileRows streams every record to fn in path order: byte order, -// which is the order of the primary key, so SQLite does not sort. -func loadFileRows(ctx context.Context, db *sql.DB, fn func(r scanRec)) error { - rows, err := db.QueryContext(ctx, +// loadFileRows gives total the number of records, then streams every +// record to fn in path order: byte order, which is the order of the +// primary key, so SQLite does not sort. The count and the records are +// read in one transaction, so they agree while a scan is committing. +func loadFileRows(ctx context.Context, db *sql.DB, total func(n int64), + fn func(r scanRec), +) error { + // Everything goes through tx: db has one connection, so a query on + // db would wait for tx forever. + tx, err := db.BeginTx(ctx, &sql.TxOptions{ReadOnly: true}) + if err != nil { + return fmt.Errorf("read records: %w", err) + } + + defer func() { _ = tx.Rollback() }() + + var n int64 + + err = tx.QueryRowContext(ctx, "SELECT COUNT(*) FROM files").Scan(&n) + if err != nil { + return fmt.Errorf("count records: %w", err) + } + + total(n) + + rows, err := tx.QueryContext(ctx, "SELECT path, size, mtime, mtime_nsec, head, tail, content "+ "FROM files ORDER BY path") if err != nil { diff --git a/db_test.go b/db_test.go index 3cc86ee..fab2369 100644 --- a/db_test.go +++ b/db_test.go @@ -284,12 +284,63 @@ func TestCloseScanDatabaseWhileReportOpen(t *testing.T) { defer func() { _ = reportDB.Close() }() - err = loadFileRows(t.Context(), reportDB, func(scanRec) {}) + err = loadFileRows(t.Context(), reportDB, func(int64) {}, + func(scanRec) {}) if err != nil { t.Fatalf("loadFileRows: %v", err) } } +// TestLoadFileRowsCountAgreesDuringScan has a scan commit records after +// loadFileRows has counted the records and before it reads them, as +// when trees runs during a scan: it must read exactly as many records +// as it counted. +func TestLoadFileRowsCountAgreesDuringScan(t *testing.T) { + t.Parallel() + + path := testDBPath(t) + + scanDB, err := openScanDatabase(t.Context(), path) + if err != nil { + t.Fatal(err) + } + + defer func() { _ = scanDB.Close() }() + + recs := smokeTreeRecs() + + err = applyChanges(t.Context(), scanDB, recs[:3], nil, nil) + if err != nil { + t.Fatal(err) + } + + reportDB, err := openReportDatabase(t.Context(), path) + if err != nil { + t.Fatal(err) + } + + defer func() { _ = reportDB.Close() }() + + var counted, read int64 + + err = loadFileRows(t.Context(), reportDB, func(n int64) { + counted = n + + err := applyChanges(t.Context(), scanDB, recs[3:], nil, nil) + if err != nil { + t.Error(err) + } + }, func(scanRec) { read++ }) + if err != nil { + t.Fatal(err) + } + + if counted != 3 || read != counted { + t.Errorf("counted %d records and read %d, want 3 and 3", + counted, read) + } +} + func TestApplyChangesRoundTrip(t *testing.T) { t.Parallel() diff --git a/main_test.go b/main_test.go index 394750b..a2c09a4 100644 --- a/main_test.go +++ b/main_test.go @@ -303,8 +303,15 @@ func TestRunMissingDatabaseIsFatal(t *testing.T) { t.Errorf("run(%s) = %d, want %d", name, code, exitFatal) } + // trees shows its open phase, as it starts and as it ends, + // before the error. + opening := "" + if name == cmdTrees { + opening = treesOpenLine + "\n" + treesOpenLine + "\n" + } + want := name + ": database " + path + " (from " + databaseEnv + - ")\n" + + ")\n" + opening + "sfdupes: " + path + ": no database (run \"sfdupes " + "scan\" first, or set " + databaseEnv + ")\n" if got := stderr(); got != want { @@ -506,7 +513,7 @@ func TestRunNamesDefaultDatabase(t *testing.T) { // nothing here may create or read one: scan gets an operand that // does not exist, which stops it before it takes the lock, and // report and trees a cancelled context, which stops them before - // they read anything. + // they read anything. trees shows its open phase after the line. t.Setenv(databaseEnv, "") // Whether scan calls the database new depends on that machine too. @@ -540,7 +547,8 @@ func TestRunNamesDefaultDatabase(t *testing.T) { run: func() error { return runTrees(cancelledContext(t), io.Discard) }, - want: "trees: database " + defaultDatabasePath + " (default)\n", + want: "trees: database " + defaultDatabasePath + " (default)\n" + + treesOpenLine + "\n" + treesOpenLine + "\n", }, } @@ -942,11 +950,16 @@ func TestRunTreesSucceeds(t *testing.T) { t.Errorf("stdout = %q, want %q", got, want) } - want = "trees: database " + path + " (from " + databaseEnv + ")\n" + - "trees: 2 records read, 1 duplicate tree groups, 1 dupe trees, " + - "300 B reclaimable\n" - if got := stderr(); got != want { - t.Errorf("stderr = %q, want %q", got, want) + // Its phases come between the two lines; see + // TestRunTreesProgressNamesEachPhase. + first := "trees: database " + path + " (from " + databaseEnv + ")\n" + last := "\ntrees: 2 records read, 1 duplicate tree groups, " + + "1 dupe trees, 300 B reclaimable\n" + + if got := stderr(); !strings.HasPrefix(got, first) || + !strings.HasSuffix(got, last) { + t.Errorf("stderr = %q, want it to start %q and end %q", + got, first, last) } assertNoSidecars(t, path) diff --git a/progress.go b/progress.go index 57623c4..bf24ac3 100644 --- a/progress.go +++ b/progress.go @@ -2,6 +2,7 @@ package main import ( "fmt" + "io" "math" "os" "slices" @@ -72,6 +73,7 @@ func phaseLabel(phases []string, phase string) string { // progressParams describe one phase's progress display as it starts. type progressParams struct { label string // the phase and its place, from phaseLabel + unit string // what the phase counts, as "files" 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 @@ -90,7 +92,8 @@ type progressParams struct { // below it. Every method must be called from the main goroutine. A nil // *progress is a valid no-display receiver: every method is a no-op, so // batched database flushes during the hash phase can reuse the update -// phase's helpers without rendering anything. +// 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 @@ -101,6 +104,7 @@ type progress struct { withBar bool // bar is the library's bar, not its spinner widest int // the widest line bar has drawn, in columns label string + unit string total int64 estimate bool waitingFor string @@ -128,8 +132,9 @@ func startProgress(params progressParams, width func() int, now := time.Now() p := &progress{ width: width, stop: make(chan struct{}), done: make(chan struct{}), - label: params.label, total: params.total, estimate: params.estimate, - waitingFor: params.waitingFor, start: now, rateStart: now, + label: params.label, unit: params.unit, total: params.total, + estimate: params.estimate, waitingFor: params.waitingFor, + start: now, rateStart: now, } // Show the zero state at once: the first item may take minutes, @@ -287,6 +292,56 @@ func (p *progress) warnf(format string, args ...any) { fmt.Fprintln(os.Stderr, msg) } +// progressWriter writes a phase's output to out, which may be the +// terminal the phase's display is drawn on, as stdout is in a plain +// "sfdupes trees". It holds what is written to it and writes that to +// out in pieces of about ioBufSize bytes, each under the display's +// lock with the display cleared first, as warnf does for a warning: no +// draw lands in the middle of a piece, and the next draw shows the +// display again, on the line below. Every write to it must end with a +// newline, as a row written with one fmt.Fprintf does, so that each +// piece ends a line. Flush writes what it holds once the last row is +// written. +type progressWriter struct { + p *progress + out io.Writer + buf []byte +} + +// writer returns a progressWriter writing to out around p's display. +func (p *progress) writer(out io.Writer) *progressWriter { + return &progressWriter{p: p, out: out} +} + +// Write holds b, and writes what it holds to out once that comes to +// ioBufSize bytes. +func (w *progressWriter) Write(b []byte) (int, error) { + w.buf = append(w.buf, b...) + if len(w.buf) < ioBufSize { + return len(b), nil + } + + return len(b), w.Flush() +} + +// Flush writes what w holds to out, with the display cleared first and +// not drawn again until it is written. +func (w *progressWriter) Flush() error { + if w.p != nil { + w.p.mu.Lock() + defer w.p.mu.Unlock() + + if w.p.bar != nil { + _ = w.p.bar.Clear() + } + } + + _, err := w.out.Write(w.buf) + w.buf = w.buf[:0] + + return err +} + // finish ends the phase's display, drawn once more as the phase ends. // A phase stopped short of its total, as an interrupted one is, shows // the count it stopped at rather than a full bar. @@ -311,9 +366,9 @@ func (p *progress) finish() { // // [3/5] hash: [1234/5000] 25%, 300 files/s, elapsed 4s, eta 13s // -// 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. +// 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. // // 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 @@ -337,7 +392,7 @@ func (p *progress) line(room int, percent bool) (string, bool) { } head = p.label + ": " + p.itemsDone(percent) + ", " - extra = fmt.Sprintf("%.0f files/s", rate) + extra = fmt.Sprintf("%.0f %s/s", rate, p.unit) tail = fmt.Sprintf("elapsed %s, eta %s", elapsed, p.eta(rate)) } @@ -355,11 +410,11 @@ func (p *progress) line(room int, percent bool) (string, bool) { // 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" when the phase has no total. -// p.mu must be held. +// percent is false, or as "1234 files", in the phase's unit, when the +// phase has no total. p.mu must be held. func (p *progress) itemsDone(percent bool) string { if p.total < 0 { - return fmt.Sprintf("%d files", p.count) + return fmt.Sprintf("%d %s", p.count, p.unit) } approx := "" diff --git a/progress_test.go b/progress_test.go index 4aa707b..0fae9da 100644 --- a/progress_test.go +++ b/progress_test.go @@ -1,6 +1,7 @@ package main import ( + "fmt" "math" "os" "path/filepath" @@ -86,30 +87,44 @@ func TestProgressLine(t *testing.T) { }, want: "[1/5] load: counting the records, elapsed 10s, eta unknown", }, { - p: &progress{label: scanPhase("hash"), total: 100, count: 20}, + 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"), total: 100}, + 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"), total: 0}, + 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"), total: 100, estimate: true, count: 20, + 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"), total: 100, estimate: true, count: 120, + 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"), total: -1, count: 20}, + 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 { @@ -129,7 +144,7 @@ func TestLineFitsRoom(t *testing.T) { ago := time.Now().Add(-10 * time.Second) hash := &progress{ - label: scanPhase("hash"), total: 100, count: 20, + label: scanPhase("hash"), unit: scanUnit, total: 100, count: 20, start: ago, rateStart: ago, } content := &progress{ @@ -183,7 +198,8 @@ func TestSetTotalStartsRate(t *testing.T) { waited := time.Now().Add(-20 * time.Second) p := &progress{ - label: scanPhase("load"), total: -1, start: waited, rateStart: waited, + label: scanPhase("load"), unit: scanUnit, total: -1, start: waited, + rateStart: waited, } p.setTotal(100) @@ -226,7 +242,9 @@ func awaitOutput(t *testing.T, stderr func() string, want string, //nolint:paralleltest // captureStderr replaces the process-wide os.Stderr func TestPlainProgressPrintsAtStartAndEnd(t *testing.T) { stderr := captureStderr(t) - p := newProgress(progressParams{label: scanPhase("hash"), total: 1000}) + p := newProgress(progressParams{ + label: scanPhase("hash"), unit: scanUnit, total: 1000, + }) for range 1000 { p.increment() @@ -289,8 +307,14 @@ func TestTerminalRedrawsWhileWaiting(t *testing.T) { params progressParams want string // how the line shows a count of 50 }{ - {progressParams{label: scanPhase("walk"), total: -1}, "50 files,"}, - {progressParams{label: scanPhase("hash"), total: 100}, "[50/100],"}, + { + progressParams{label: scanPhase("walk"), unit: scanUnit, total: -1}, + "50 files,", + }, + { + progressParams{label: scanPhase("hash"), unit: scanUnit, total: 100}, + "[50/100],", + }, } for _, tc := range cases { @@ -341,8 +365,9 @@ func drawLate(stderr func() string, params progressParams, width int, } // TestTerminalLinesKeepETA checks the line each display shows on an -// 80-column terminal at a large scan's counts and times: the rate is -// left out, so that the elapsed time and the ETA stay whole. +// 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) { @@ -354,18 +379,29 @@ func TestTerminalLinesKeepETA(t *testing.T) { }{{ // Past its estimate, the walk cannot tell how long it has left. params: progressParams{ - label: scanPhase("walk"), total: 1200000, estimate: true, + 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"), total: 9876543}, + 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"), total: 9876543}, + 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 { @@ -389,7 +425,9 @@ func TestTerminalLinesFitWidth(t *testing.T) { for _, width := range []int{120, 100, 80, 72, 60, 50, 40} { for _, total := range []int64{9876543, 20000} { - params := progressParams{label: scanPhase("content"), total: total} + params := progressParams{ + label: scanPhase("content"), unit: scanUnit, total: total, + } out := drawLate(stderr, params, width, total/8) if width == 120 && !strings.Contains(out, "% |") { @@ -426,8 +464,16 @@ func TestTerminalNarrowedRedrawsInPlace(t *testing.T) { params progressParams narrow int }{ - {progressParams{label: scanPhase("walk"), total: -1}, 60}, - {progressParams{label: scanPhase("hash"), total: 9876543}, 90}, + { + progressParams{label: scanPhase("walk"), unit: scanUnit, total: -1}, + 60, + }, + { + progressParams{ + label: scanPhase("hash"), unit: scanUnit, total: 9876543, + }, + 90, + }, } for _, tc := range cases { @@ -513,6 +559,70 @@ func TestProgressWarningsOnOwnLines(t *testing.T) { } } +// 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) + 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]) + } + } +} + // 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. diff --git a/scan.go b/scan.go index bdb22d3..101bd45 100644 --- a/scan.go +++ b/scan.go @@ -84,6 +84,10 @@ type fileMeta struct { hashed bool } +// scanUnit is what every scan phase counts, as its progress display +// names it. +const scanUnit = "files" + // scanPhase names one phase of a scan with its place among all of them, // as "[2/5] walk", for the phase's progress display. The list here is // the one place the phases are counted. @@ -441,7 +445,7 @@ func (s *scanState) loadIndex(ctx context.Context, roots []string) error { // display the scan looks hung before the walk begins. Counting them // first gives the display its total. prog := newProgress(progressParams{ - label: scanPhase("load"), total: -1, + label: scanPhase("load"), unit: scanUnit, total: -1, waitingFor: "counting the records", }) defer prog.finish() @@ -492,7 +496,8 @@ func (s *scanState) walkPhase( } prog := newProgress(progressParams{ - label: scanPhase("walk"), total: estimate, estimate: true, + label: scanPhase("walk"), unit: scanUnit, total: estimate, + estimate: true, }) var ( @@ -683,7 +688,7 @@ func (s *scanState) readRuns(ctx context.Context, workers int, defer pool.stop() prog := newProgress(progressParams{ - label: scanPhase(label), total: int64(len(runs)), + label: scanPhase(label), unit: scanUnit, total: int64(len(runs)), }) defer prog.finish() @@ -772,7 +777,7 @@ func (s *scanState) updatePhase(ctx context.Context) error { total := len(s.batch) + len(s.sentinels) + len(deletes) prog := newProgress(progressParams{ - label: scanPhase("update"), total: int64(total), + label: scanPhase("update"), unit: scanUnit, total: int64(total), }) defer prog.finish() @@ -860,7 +865,7 @@ func (s *scanState) contentCandidates( // record. The checks start there, against a count of the records // the search returns, and so do their rate and ETA. prog := newProgress(progressParams{ - label: scanPhase("content"), total: -1, + label: scanPhase("content"), unit: scanUnit, total: -1, waitingFor: "searching the database", }) defer prog.finish() diff --git a/scan_test.go b/scan_test.go index 0714e5a..1cfe8f2 100644 --- a/scan_test.go +++ b/scan_test.go @@ -1478,7 +1478,7 @@ func dbRecords(t *testing.T, db *sql.DB) []scanRec { var recs []scanRec - err := loadFileRows(t.Context(), db, func(r scanRec) { + err := loadFileRows(t.Context(), db, func(int64) {}, func(r scanRec) { recs = append(recs, r) }) if err != nil { @@ -1550,7 +1550,7 @@ func assertSmokeTreeGroups(t *testing.T, dir string, db *sql.DB) { super, dirs := dbTree(t, db) - tg := collectTreeGroups(dirs, super) + tg := collectTreeGroups(dirs, super, nil) if len(tg) != 1 { t.Fatalf("len(tree groups) = %d, want 1", len(tg)) } @@ -2092,7 +2092,7 @@ func TestTreesUnhashedNeverEqual(t *testing.T) { for name, unknown := range cases { super, dirs := treeOf(t, append(slices.Clone(shared), unknown...)) - if tg := collectTreeGroups(dirs, super); len(tg) != 0 { + if tg := collectTreeGroups(dirs, super, nil); len(tg) != 0 { t.Errorf("%s: tree groups = %d, want 0 (the files may differ)", name, len(tg)) } diff --git a/trees.go b/trees.go index 6d18564..1ff6b76 100644 --- a/trees.go +++ b/trees.go @@ -1,9 +1,9 @@ package main import ( - "bufio" "context" "crypto/sha256" + "database/sql" "fmt" "io" "os" @@ -24,6 +24,13 @@ type treeNode struct { totalSize int64 } +// treesPhase names one phase of trees with its place among all of them, +// as "[2/4] read", for the phase's progress display. The list here is +// the one place the phases are counted. +func treesPhase(name string) string { + return phaseLabel([]string{"open", "read", "group", "write"}, name) +} + // runTrees implements the trees subcommand: it reads every record from // the database in path order, reconstructs the directory hierarchy from // the record paths, computes a Merkle-style digest per directory, and @@ -31,6 +38,13 @@ type treeNode struct { // touches the scanned filesystem; its only I/O is the database, stdout, // and stderr. It names the database on stderr before it opens it. Any // database problem, including a missing database, is fatal. +// +// The work runs in four phases, each under a progress display of its +// own on stderr: open (open the database), read (count the records, +// then read them into the hierarchy), group (group the directories by +// digest) and write (write the groups to stdout). Each display ends +// before the next phase starts, and before an error is returned to be +// printed. func runTrees(ctx context.Context, stdout io.Writer) error { dbPath, source, err := databasePath() if err != nil { @@ -40,34 +54,99 @@ func runTrees(ctx context.Context, stdout io.Writer) error { fmt.Fprintf(os.Stderr, "trees: database %s (%s)\n", escapePath(dbPath), source) + // Opening can wait on a busy database for as long as the busy + // timeout. + prog := newProgress(progressParams{ + label: treesPhase("open"), total: -1, + waitingFor: "opening the database", + }) db, err := openReportDatabase(ctx, dbPath) + + prog.finish() + if err != nil { return err } defer func() { _ = db.Close() }() - records := 0 - tree := newTreeBuilder() - - err = loadFileRows(ctx, db, func(r scanRec) { - records++ - - tree.add(r) + prog = newProgress(progressParams{ + label: treesPhase("read"), unit: "records", total: -1, + waitingFor: "counting the records", }) + records, super, allDirs, err := readTree(ctx, db, prog) + + prog.finish() + if err != nil { return fmt.Errorf("database %s: %w", dbPath, err) } + prog = newProgress(progressParams{ + label: treesPhase("group"), unit: "directories", + total: int64(len(allDirs)), + }) + dupes := collectTreeGroups(allDirs, super, prog) + + prog.finish() + + prog = newProgress(progressParams{ + label: treesPhase("write"), unit: "groups", total: int64(len(dupes)), + }) + dupeTrees, reclaimable, err := writeTreeGroups(stdout, dupes, prog) + + prog.finish() + + if err != nil { + return err + } + + fmt.Fprintf(os.Stderr, + "trees: %d records read, %d duplicate tree groups, %d dupe trees, "+ + "%s reclaimable\n", + records, len(dupes), dupeTrees, humanBytes(reclaimable)) + + return nil +} + +// readTree gives prog the number of records in db as its total, then +// reads every record in path order into the directory hierarchy, +// counting each on prog. It returns the number of records read, the +// super-root and every directory. +func readTree(ctx context.Context, db *sql.DB, + prog *progress, +) (int, *treeNode, []*treeNode, error) { + records := 0 + tree := newTreeBuilder() + + err := loadFileRows(ctx, db, prog.setTotal, func(r scanRec) { + records++ + + prog.increment() + tree.add(r) + }) + if err != nil { + return 0, nil, nil, err + } + super, allDirs := tree.finish() - dupes := collectTreeGroups(allDirs, super) + return records, super, allDirs, nil +} - out := bufio.NewWriterSize(stdout, ioBufSize) +// writeTreeGroups writes dupes to stdout as TSV, a header line and then +// a row for every member of each group but its first, counting each +// group on prog once its rows are written. stdout may be the terminal +// prog is drawn on, so the lines go through prog's writer. It returns +// the number of rows (dupe trees) and the bytes they could reclaim. +func writeTreeGroups(stdout io.Writer, dupes [][]*treeNode, + prog *progress, +) (int, int64, error) { + out := prog.writer(stdout) - _, err = fmt.Fprintln(out, "first\tdupe\tfiles\tsize") + _, err := fmt.Fprintln(out, "first\tdupe\tfiles\tsize") if err != nil { - return fmt.Errorf("write stdout: %w", err) + return 0, 0, fmt.Errorf("write stdout: %w", err) } dupeTrees := 0 @@ -81,25 +160,22 @@ func runTrees(ctx context.Context, stdout io.Writer) error { escapePath(first.path), escapePath(n.path), first.fileCount, first.totalSize) if err != nil { - return fmt.Errorf("write stdout: %w", err) + return 0, 0, fmt.Errorf("write stdout: %w", err) } dupeTrees++ reclaimable += first.totalSize } + + prog.increment() } err = out.Flush() if err != nil { - return fmt.Errorf("write stdout: %w", err) + return 0, 0, fmt.Errorf("write stdout: %w", err) } - fmt.Fprintf(os.Stderr, - "trees: %d records read, %d duplicate tree groups, %d dupe trees, "+ - "%s reclaimable\n", - records, len(dupes), dupeTrees, humanBytes(reclaimable)) - - return nil + return dupeTrees, reclaimable, nil } // treeBuilder reconstructs the directory hierarchy from records added @@ -221,14 +297,18 @@ func fileEntry(name string, r scanRec) string { "\x00" + r.head + "\x00" + r.tail + "\x00" + content } -// collectTreeGroups groups directories by digest and returns every -// maximal group with two or more members, each group's members sorted -// by path, groups ordered by tree size descending then by first path -// ascending. -func collectTreeGroups(allDirs []*treeNode, super *treeNode) [][]*treeNode { +// collectTreeGroups groups directories by digest, counting each one on +// prog as it is grouped, and returns every maximal group with two or +// more members, each group's members sorted by path, groups ordered by +// tree size descending then by first path ascending. +func collectTreeGroups(allDirs []*treeNode, super *treeNode, + prog *progress, +) [][]*treeNode { groups := make(map[[sha256.Size]byte][]*treeNode) for _, d := range allDirs { groups[d.digest] = append(groups[d.digest], d) + + prog.increment() } var dupes [][]*treeNode diff --git a/trees_test.go b/trees_test.go index 969c438..5257149 100644 --- a/trees_test.go +++ b/trees_test.go @@ -3,8 +3,11 @@ package main import ( "bytes" "database/sql" + "os" "slices" + "strings" "testing" + "time" ) // Signature hashes shared by the smoke-test records. @@ -17,6 +20,11 @@ const ( f2Content = "f2c" ) +// treesOpenLine is the plain line of trees' open phase when it opens +// the database at once; it prints it as the phase starts and as it ends. +const treesOpenLine = "[1/4] open: opening the database, elapsed 0s, " + + "eta unknown" + // smokeTreeRecs mirrors the README smoke-test tree layout: /d/t1 and // /d/t2 are identical, /d/t3 differs from them only by one filename. func smokeTreeRecs() []scanRec { @@ -38,7 +46,7 @@ func dbTree(t *testing.T, db *sql.DB) (*treeNode, []*treeNode) { tree := newTreeBuilder() - err := loadFileRows(t.Context(), db, tree.add) + err := loadFileRows(t.Context(), db, func(int64) {}, tree.add) if err != nil { t.Fatal(err) } @@ -170,7 +178,7 @@ func TestTreeNamesSortingBeforeSlash(t *testing.T) { t.Fatalf("directory paths = %q, want %q", got, want) } - groups := collectTreeGroups(dirs, super) + groups := collectTreeGroups(dirs, super, nil) gotGroups := groupPaths(groups) wantGroups := [][]string{{"/a", "/c"}} @@ -203,6 +211,98 @@ func TestRunTreesEscapesPaths(t *testing.T) { } } +// TestRunTreesProgressNamesEachPhase runs trees on the smoke-test +// records with stderr not a terminal, and checks every line it prints +// there. After the line naming the database, each phase prints a line +// naming it with its place among the four as it starts and another as +// it ends. read counts the 6 records before it reads them, group counts +// the 8 directories, and write the 1 group. The summary comes last, and +// stdout holds the report alone. +func TestRunTreesProgressNamesEachPhase(t *testing.T) { + path := seedDatabase(t, smokeTreeRecs()) + t.Setenv(databaseEnv, path) + + stderr := captureStderr(t) + + var stdout bytes.Buffer + + code := run([]string{cmdTrees}, &stdout, os.Stderr) + if code != exitOK { + t.Fatalf("run(trees) = %d, want %d; stderr: %s", + code, exitOK, stderr()) + } + + report := "first\tdupe\tfiles\tsize\n/d/t1\t/d/t2\t2\t3100\n" + if got := stdout.String(); got != report { + t.Errorf("stdout = %q, want %q", got, report) + } + + // How each line starts; the rate at the end of a phase varies. + want := []string{ + "trees: database " + path + " (from " + databaseEnv + ")", + treesOpenLine, + treesOpenLine, + "[2/4] read: counting the records, elapsed 0s, eta unknown", + "[2/4] read: [6/6] 100%, ", + "[3/4] group: [0/8] 0%, 0 directories/s, elapsed 0s, eta unknown", + "[3/4] group: [8/8] 100%, ", + "[4/4] write: [0/1] 0%, 0 groups/s, elapsed 0s, eta unknown", + "[4/4] write: [1/1] 100%, ", + "trees: 6 records read, 1 duplicate tree groups, 1 dupe trees, ", + } + + lines := strings.Split(strings.TrimSuffix(stderr(), "\n"), "\n") + if len(lines) != len(want) { + t.Fatalf("stderr lines = %q, want %d lines starting %q", + lines, len(want), want) + } + + for i := range want { + if !strings.HasPrefix(lines[i], want[i]) { + t.Errorf("stderr line %d = %q, want it to start %q", + i+1, lines[i], want[i]) + } + } +} + +// TestWriteTreeGroupsOnTerminal writes the smoke-test report to the +// terminal its write phase's display is drawn on, as a plain "sfdupes +// trees" does: the terminal must show the header and the row whole, +// each on a line of its own. +// +//nolint:paralleltest // captureStderr replaces the process-wide os.Stderr +func TestWriteTreeGroupsOnTerminal(t *testing.T) { + stderr := captureStderr(t) + super, dirs := treeOf(t, smokeTreeRecs()) + dupes := collectTreeGroups(dirs, super, nil) + + // 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) + + _, _, err := writeTreeGroups(os.Stderr, dupes, p) + + p.finish() + + if err != nil { + t.Fatal(err) + } + + // A terminal shows each line as the text after its last carriage + // return. + var shown []string + + for line := range strings.SplitSeq(stderr(), "\n") { + shown = append(shown, line[strings.LastIndex(line, "\r")+1:]) + } + + want := []string{"first\tdupe\tfiles\tsize", "/d/t1\t/d/t2\t2\t3100"} + if len(shown) < len(want) || !slices.Equal(shown[:len(want)], want) { + t.Errorf("terminal shows lines %q, want %q first", shown, want) + } +} + func TestTreeDigests(t *testing.T) { t.Parallel() @@ -254,7 +354,7 @@ func TestCollectTreeGroupsMaximal(t *testing.T) { super, dirs := treeOf(t, smokeTreeRecs()) - groups := collectTreeGroups(dirs, super) + groups := collectTreeGroups(dirs, super, nil) want := [][]string{{"/d/t1", "/d/t2"}} if got := groupPaths(groups); !slices.EqualFunc(got, want, @@ -278,14 +378,14 @@ func TestCollectTreeGroupsDeterministic(t *testing.T) { super, dirs := treeOf(t, recs) - forward := groupPaths(collectTreeGroups(dirs, super)) + forward := groupPaths(collectTreeGroups(dirs, super, nil)) reversed := slices.Clone(recs) slices.Reverse(reversed) superR, dirsR := treeOf(t, reversed) - backward := groupPaths(collectTreeGroups(dirsR, superR)) + backward := groupPaths(collectTreeGroups(dirsR, superR, nil)) if !slices.EqualFunc(forward, backward, slices.Equal) { t.Fatalf("output depends on record order: %v vs %v", forward, backward) @@ -304,7 +404,7 @@ func TestCollectTreeGroupsSiblings(t *testing.T) { super, dirs := treeOf(t, recs) - got := groupPaths(collectTreeGroups(dirs, super)) + got := groupPaths(collectTreeGroups(dirs, super, nil)) want := [][]string{{"/p/x1", "/p/x2"}} if !slices.EqualFunc(got, want, slices.Equal) { @@ -326,7 +426,7 @@ func TestCollectTreeGroupsDifferingParents(t *testing.T) { super, dirs := treeOf(t, recs) - got := groupPaths(collectTreeGroups(dirs, super)) + got := groupPaths(collectTreeGroups(dirs, super, nil)) want := [][]string{{"/p/a/x", "/q/b/x"}} if !slices.EqualFunc(got, want, slices.Equal) {