FileSnapshot: fix bug with timestamp thresholding

Increase the safety factor to 2.5x for extra safety if max of measured
timestamp resolution and measured minimal racy threshold is < 100ms, use
1.25 otherwise since for large filesystem resolution values the
influence of finite resolution of the system clock should be negligible.

Before, not yet using the newly introduced minRacyThreshold measurement,
the threshold was 1.1x FS resolution, and we could issue the
following sequence of events,

  start
  create-file
  read-file (currentTime)
  end

which had the following timestamps:

  create-file 1564589081998
  start 1564589082002
  read 1564589082003
  end 1564589082004

In this case, the difference between create-file and read is 5ms,
which exceeded the 4ms FS resolution, even though the events together
took just 2ms of runtime.

Reproduce with:
  bazel test --runs_per_test=100 \
    //org.eclipse.jgit.test:org_eclipse_jgit_internal_storage_file_FileSnapshotTest

The file system timestamp resolution is 4ms in this case.

This code assumes that the kernel and the JVM use the same clock that
is synchronized with the file system clock. This seems plausible,
given the resolution of System.currentTimeMillis() and the latency for
a gettimeofday system call (typically ~1us), but it would be good to
justify this with specifications.

Also cover a source of flakiness: if the test runs under extreme load,
then we could have

  start
  create-file
  <long delay>
  read
  end

which would register as an unmodified file. Avoid this by skipping the
test if end-start is too big.

[msohn]:
- downported from master to stable-5.1
- skip test if resolution is below 10ms
- adjust safety factor to 1.25 for resolutions above 100ms

Change-Id: I87d2cf035e01c44b7ba8364c410a860aa8e312ef
Signed-off-by: Han-Wen Nienhuys <hanwen@google.com>
Signed-off-by: Matthias Sohn <matthias.sohn@sap.com>

1 files changed, 28 insertions, 8 deletions

diff --git a/org.eclipse.jgit.test/tst/org/eclipse/jgit/internal/storage/file/FileSnapshotTest.java b/org.eclipse.jgit.test/tst/org/eclipse/jgit/internal/storage/file/FileSnapshotTest.java
index 40af9e2a00..6fa35d64b0 100644
--- a/org.eclipse.jgit.test/tst/org/eclipse/jgit/internal/storage/file/FileSnapshotTest.java
+++ b/org.eclipse.jgit.test/tst/org/eclipse/jgit/internal/storage/file/FileSnapshotTest.java
@@ -47,6 +47,7 @@ import static org.eclipse.jgit.junit.JGitTestUtil.write;
 import static org.junit.Assert.assertEquals;
 import static org.junit.Assert.assertFalse;
 import static org.junit.Assert.assertTrue;
+import static org.junit.Assert.fail;
 
 import java.io.File;
 import java.io.IOException;
@@ -150,14 +151,33 @@ public class FileSnapshotTest {
 	 */
 	@Test
 	public void testNewFileNoWait() throws Exception {
-		// if filesystem timestamp resolution is high the snapshot won't be
-		// racily clean
-		Assume.assumeTrue(
-				fsAttrCache.getFsTimestampResolution()
-						.compareTo(Duration.ofMillis(10)) > 0);
-		Path f1 = createFile("newfile");
-		FileSnapshot save = FileSnapshot.save(f1.toFile());
-		assertTrue(save.isModified(f1.toFile()));
+		// if filesystem timestamp resolution is smaller than time needed to
+		// create a file and FileSnapshot the snapshot won't be racily clean
+		Assume.assumeTrue(fsAttrCache.getFsTimestampResolution()
+				.compareTo(Duration.ofMillis(10)) > 0);
+		for (int i = 0; i < 50; i++) {
+			Instant start = Instant.now();
+			Path f1 = createFile("newfile");
+			FileSnapshot save = FileSnapshot.save(f1.toFile());
+			Duration res = FS.getFileStoreAttributes(f1)
+					.getFsTimestampResolution();
+			Instant end = Instant.now();
+			if (Duration.between(start, end)
+					.compareTo(res.multipliedBy(2)) > 0) {
+				// This test is racy: under load, there may be a delay between createFile() and
+				// FileSnapshot.save(). This can stretch the time between the read TS and FS
+				// creation TS to the point that it exceeds the FS granularity, and we
+				// conclude it cannot be racily clean, and therefore must be really clean.
+				//
+				// This should be relatively uncommon.
+				continue;
+			}
+			// The file wasn't really modified, but it looks just like a "maybe racily clean"
+			// file.
+			assertTrue(save.isModified(f1.toFile()));
+			return;
+		}
+		fail("too much load for this test");
 	}
 
 	/**