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

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
+// own lstat: st_blocks counts 512-byte units. ZFS counts a write's
-// blocks only seconds after the write, and fsync does not hasten that.
+// blocks only when it commits the write, up to seconds later, and one
-// A test therefore calls unix.Sync, which waits for it, before the scan
+// commit can take the file through several growing sizes. So this value
-// whose disk_size it compares with this.
+// 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()
 
@@ -1448,20 +1454,26 @@ func TestScanStoresDiskSize(t *testing.T) {
 
 	unix.Sync() // see diskSizeOf
 
-	want := diskSizeOf(t, p)
+	size := diskSizeOf(t, p)
-	if want == 0 || want >= length {
+	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 {
+		if got < before || got > after {
-			t.Errorf("scan of %s: disk_size = %d, want %d",
+			t.Errorf("scan of %s: disk_size = %d, want %d to %d",
-				operand, got, want)
+				operand, got, before, after)
 		}
 	}
 }
@@ -1479,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))
 
@@ -1492,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)
-	want := diskSizeOf(t, p)
+	for diskSizeOf(t, p) == recorded {
-	if want == before {
+		if time.Now().After(deadline) {
-		t.Fatalf("the file still takes %d bytes on disk after the write "+
+			t.Fatalf("the file still takes %d bytes on disk 30 seconds "+
-			"into its hole", want)
+				"after the write into its hole", recorded)
 		}
 
+		unix.Sync()
+	}
+
+	// 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)
+
 		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 != want {
+			if got != after {
-		t.Errorf("disk_size = %d, want %d", got, want)
+				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)
+		}
 	}
 }
 
@@ -1533,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 {
+	if got < before || got > after {
-		t.Errorf("disk_size = %d, want %d", got, want)
+		t.Errorf("disk_size = %d, want %d to %d", got, before, after)
 	}
 }