Stop the disk size tests failing at random on ZFS (closes #150)

One ZFS commit can take a file through several sizes, and unix.Sync can
return before the blocks are counted. A test that expected the size on
disk to be settled therefore failed at random. The test that needs the
size to change now calls unix.Sync in a loop until it does, for at most
30 seconds. It then rescans until the size reads the same before and
after a rescan, and compares disk_size exactly, within the same 30
seconds. The other two tests fail only on a disk_size outside their two
reads. They call unix.Sync once first, so a wrong 512 usually fails them.

Model: opus-5-5

exclude_test.go

@@ -17,7 +17,9 @@ import (
 func TestDefaultExcludes(t *testing.T) {
 	t.Parallel()
 
-	// README "Rules for the walk": each system's list.
+	// README "Rules for the walk": the Linux and macOS lists, and none
+	// on any other system. The Windows list exists in the code only: the
+	// binary does not build for Windows, so the README leaves it out.
 	cases := map[string][]string{
 		goosLinux: {"/proc", "/sys", "/dev", "/run", "/tmp", "/var/tmp"},
 		goosDarwin: {

main_test.go

@@ -394,7 +394,7 @@ func TestRunNamesRelativeDatabase(t *testing.T) {
 }
 
 func TestRunUsesDatabaseThroughSymlinkedDirectory(t *testing.T) {
-	// README §Database: the path names the file exactly. With link a
+	// README §Settings: the path names the file exactly. With link a
 	// symlink to the directory real/sub, link/../db.sqlite names
 	// real/db.sqlite, not db.sqlite beside link. Every subcommand must
 	// use that file, relative or absolute, and its first line must name
@@ -649,7 +649,7 @@ func TestRunUsageErrors(t *testing.T) {
 }
 
 func TestRunScanRejectsWorkersBelowOne(t *testing.T) {
-	// README §scan mode: --workers below 1 is a usage error reported in
+	// README §Settings: --workers below 1 is a usage error reported in
 	// one line on stderr, before the scan opens the database.
 	for _, workers := range []string{"0", "-1"} {
 		t.Run(workers, func(t *testing.T) {
@@ -687,8 +687,8 @@ func TestRunScanRejectsWorkersBelowOne(t *testing.T) {
 func TestRunHelp(t *testing.T) {
 	t.Parallel()
 
-	// README §Subcommands: help goes to stderr, exits 0, and leaves
-	// stdout empty.
+	// README §Settings: help goes to stderr, exits 0, and leaves stdout
+	// empty.
 	cases := [][]string{{"--help"}, {"-h"}, {cmdScan, "--help"}}
 
 	for _, args := range cases {
@@ -714,8 +714,8 @@ func TestRunHelp(t *testing.T) {
 func TestRunVersion(t *testing.T) {
 	t.Parallel()
 
-	// README §Subcommands: the version is one line on stdout, with
-	// nothing on stderr, and exits 0.
+	// README §Settings: the version is one line on stdout, with nothing
+	// on stderr, and exits 0.
 	info, _ := debug.ReadBuildInfo()
 
 	for _, arg := range []string{"--version", "-v"} {
@@ -774,8 +774,8 @@ func TestBuildVersion(t *testing.T) {
 func TestRunVersionWriteFailureIsFatal(t *testing.T) {
 	t.Parallel()
 
-	// README §Error handling: a stdout write failure exits 1, reported
-	// in one line on stderr.
+	// README §Error handling: a failed write to stdout is a fatal error,
+	// exit 1, reported on stderr starting with "sfdupes:".
 	var stderr bytes.Buffer
 
 	code := run([]string{"--version"}, failingWriter{}, &stderr)
@@ -1257,7 +1257,7 @@ func assertRunsUseDatabase(t *testing.T, dir, name string) {
 }
 
 func TestRunDatabasePathUsedAsGiven(t *testing.T) {
-	// README §Database: the path names the database file exactly. In
+	// README §Settings: the path names the database file exactly. In
 	// SQLite's connection string an unescaped ? or # would end the file
 	// name and % would start an escape, and a path starting with //
 	// could be read as a host name. %25 is a valid escape, so unescaped
@@ -1302,9 +1302,8 @@ func holdScanLock(t *testing.T, path string) {
 }
 
 func TestRunSecondScanFails(t *testing.T) {
-	// README §Database: while one scan holds the lock, a second scan
-	// fails at once, naming the lock file, without opening the
-	// database.
+	// README §Database: a second scan that finds the lock held fails
+	// at once, naming the lock file, without opening the database.
 	path := testDBPath(t)
 	t.Setenv(databaseEnv, path)
 
@@ -1363,7 +1362,7 @@ func assertSecondScanFails(t *testing.T, path string) {
 }
 
 func TestRunSecondScanThroughSymlinkFails(t *testing.T) {
-	// README §Database: every path to one database names the same lock
+	// README §Database: a path through a symlink names the same lock
 	// file, so while a scan holds it through one path, a scan through
 	// another fails, naming the lock file beside the database's real
 	// path.
@@ -1468,8 +1467,8 @@ func TestRunReportsDuringScan(t *testing.T) {
 }
 
 func TestRunStdoutClosedIsFatal(t *testing.T) {
-	// README §Error handling: a stdout write failure exits 1, reported
-	// in one line on stderr.
+	// README §Error handling: a failed write to stdout is a fatal error,
+	// exit 1, reported on stderr starting with "sfdupes:".
 	for _, name := range []string{cmdReport, cmdTrees, cmdInfo} {
 		t.Run(name, func(t *testing.T) {
 			t.Setenv(databaseEnv, testDBPath(t))

scan_test.go

@@ -43,10 +43,16 @@ func writeFile(t *testing.T, dir, name string, data []byte) string {
 }
 
 // diskSizeOf returns the bytes the file at path takes on disk, from its
-// own lstat: st_blocks counts 512-byte units. ZFS counts a new file's
-// blocks only seconds after the write, and fsync does not hasten that.
-// A test therefore calls unix.Sync, which waits for it, before the scan
-// whose disk_size it compares with this.
+// own lstat: st_blocks counts 512-byte units. ZFS counts a write's
+// blocks only when it commits the write, up to seconds later, and one
+// commit can take the file through several growing sizes. So this value
+// can change at any moment. Neither fsync nor unix.Sync hastens that,
+// but a unix.Sync call often takes long enough that the blocks are
+// counted when it returns. A test that needs the value to change waits
+// for the change. A test that compares it with a scan's disk_size reads
+// it before and after the scan. The rewrite test rescans until the two
+// reads match, then compares exactly. The other two tests fail only on
+// a disk_size outside the two reads.
 func diskSizeOf(t *testing.T, path string) int64 {
 	t.Helper()
 
@@ -1082,8 +1088,9 @@ func TestScanOneFilesystemWalksNestedFileOperand(t *testing.T) {
 	}
 }
 
-// buildSmokeTree recreates the README smoke-test filesystem layout
-// with deterministic content and returns the tree root.
+// buildSmokeTree recreates the tree of the test under README
+// "Definition of done" with deterministic content and returns the tree
+// root.
 func buildSmokeTree(t *testing.T) string {
 	t.Helper()
 
@@ -1447,20 +1454,26 @@ func TestScanStoresDiskSize(t *testing.T) {
 
 	unix.Sync() // see diskSizeOf
 
-	want := diskSizeOf(t, p)
-	if want == 0 || want >= length {
+	size := diskSizeOf(t, p)
+	if size == 0 || size >= length {
 		t.Fatalf("the file takes %d bytes on disk, want more than none "+
-			"and fewer than its length %d", want, length)
+			"and fewer than its length %d", size, length)
 	}
 
 	for _, operand := range []string{filepath.Dir(p), p} {
 		db := openTestDB(t)
+
+		// ZFS may count the blocks during the scan; see diskSizeOf.
+		before := diskSizeOf(t, p)
+
 		syncTree(t, db, operand)
 
+		after := diskSizeOf(t, p)
+
 		got := recordByPath(t, dbRecords(t, db), p).diskSize
-		if got != want {
-			t.Errorf("scan of %s: disk_size = %d, want %d",
-				operand, got, want)
+		if got < before || got > after {
+			t.Errorf("scan of %s: disk_size = %d, want %d to %d",
+				operand, got, before, after)
 		}
 	}
 }
@@ -1478,7 +1491,7 @@ func TestSyncScanRewriteUpdatesDiskSize(t *testing.T) {
 
 	syncTree(t, db, dir)
 
-	before := recordByPath(t, dbRecords(t, db), p).diskSize
+	recorded := recordByPath(t, dbRecords(t, db), p).diskSize
 
 	pokeAt(t, p, 512*1024, pattern(7, 64*1024))
 
@@ -1491,22 +1504,53 @@ func TestSyncScanRewriteUpdatesDiskSize(t *testing.T) {
 		t.Fatal(err)
 	}
 
-	unix.Sync() // see diskSizeOf
+	// Wait for ZFS to count the write; see diskSizeOf.
+	deadline := time.Now().Add(30 * time.Second)
+	for diskSizeOf(t, p) == recorded {
+		if time.Now().After(deadline) {
+			t.Fatalf("the file still takes %d bytes on disk 30 seconds "+
+				"after the write into its hole", recorded)
+		}
 
-	want := diskSizeOf(t, p)
-	if want == before {
-		t.Fatalf("the file still takes %d bytes on disk after the write "+
-			"into its hole", want)
+		unix.Sync()
 	}
 
-	st := syncTree(t, db, dir)
-	if st != (scanStats{walked: 1, updated: 1}) {
-		t.Fatalf("rescan stats = %+v, want 1 updated", st)
-	}
+	// ZFS may still be counting, so the size may change during a rescan.
+	// Only a rescan with the same size on both sides of it can be compared
+	// exactly. A rescan that keeps the old size still fails, because the
+	// wait made before differ from it.
+	for {
+		before := diskSizeOf(t, p)
 
-	got := recordByPath(t, dbRecords(t, db), p).diskSize
-	if got != want {
-		t.Errorf("disk_size = %d, want %d", got, want)
+		st := syncTree(t, db, dir)
+
+		after := diskSizeOf(t, p)
+
+		if st != (scanStats{walked: 1, updated: 1}) {
+			t.Fatalf("rescan stats = %+v, want 1 updated", st)
+		}
+
+		if before == after {
+			got := recordByPath(t, dbRecords(t, db), p).diskSize
+			if got != after {
+				t.Errorf("disk_size = %d, want %d", got, after)
+			}
+
+			return
+		}
+
+		if time.Now().After(deadline) {
+			t.Fatalf("the size on disk was still changing 30 seconds after "+
+				"the write into its hole: %d, then %d", before, after)
+		}
+
+		// A later mtime makes the next rescan read the file again.
+		later = later.Add(time.Second)
+
+		err = os.Chtimes(p, later, later)
+		if err != nil {
+			t.Fatal(err)
+		}
 	}
 }
 
@@ -1532,15 +1576,21 @@ func TestSyncScanUnchangedUpdatesDiskSize(t *testing.T) {
 
 	unix.Sync() // see diskSizeOf
 
+	// ZFS may count the blocks during the rescan; see diskSizeOf.
+	before := diskSizeOf(t, p)
+
 	// A file read again would count as updated.
 	st := syncTree(t, db, dir)
+
+	after := diskSizeOf(t, p)
+
 	if st != (scanStats{walked: 1, unchanged: 1}) {
 		t.Fatalf("rescan stats = %+v, want 1 unchanged", st)
 	}
 
 	got := recordByPath(t, dbRecords(t, db), p).diskSize
-	if want := diskSizeOf(t, p); got != want {
-		t.Errorf("disk_size = %d, want %d", got, want)
+	if got < before || got > after {
+		t.Errorf("disk_size = %d, want %d to %d", got, before, after)
 	}
 }
 

trees_test.go

@@ -15,9 +15,9 @@ import (
 const treesOpenLine = "[1/4] open: opening the database, elapsed 0s, " +
 	"remain 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.
-// Each file takes one 4 KiB block on disk.
+// smokeTreeRecs mirrors the tree of the test under README "Definition
+// of done": /d/t1 and /d/t2 are identical, /d/t3 differs from them only
+// by one filename. Each file takes one 4 KiB block on disk.
 func smokeTreeRecs() []scanRec {
 	f1Head, f1Tail, f1Content := testHash("f1h"), testHash("f1t"), testHash("f1c")
 	f2Head, f2Tail, f2Content := testHash("f2h"), testHash("f2t"), testHash("f2c")