Measure file timestamp resolution used in FileSnapshot

FileSnapshot.notRacyClean() assumed a worst case filesystem timestamp
resolution of 2.5 sec (FAT has a resolution of 2 sec). Instead measure
timestamp resolution to avoid unnecessary IO caused by false positives
in detecting the racy git problem caused by finite filesystem timestamp
resolution [1].

Cache the measured resolution per FileStore since timestamp resolution
depends on the respective filesystem type. If timestamp resolution
cannot be measured or fails due to an exception fallback to the worst
case FAT timestamp resolution and avoid caching this value.

Add a 10% safety margin in FileSnapshot.notRacyClean(), though running
FsTest.testFsTimestampResolution() 1000 times which is not using a
safety margin didn't fail on Mac using APFS and Java 8, 11, 12.

Measured Java file timestamp resolution: [2]

[1] https://github.com/git/git/blob/master/Documentation/technical/racy-git.txt
[2] https://docs.google.com/spreadsheets/d/1imy0y6WmRqBf0kjCxzxj2X7M50eIVfa7oaUIzEOHmjo

Bug: 546891
Change-Id: I493f3b57b6b306285ffa7d392339d253e5966ab8
Signed-off-by: Matthias Sohn <matthias.sohn@sap.com>

org.eclipse.jgit.junit/src/org/eclipse/jgit/junit/RepositoryTestCase.java

@@ -374,9 +374,7 @@ public abstract class RepositoryTestCase extends LocalDiskRepositoryTestCase {
 			while (actTime <= startTime) {
 				Thread.sleep(sleepTime);
 				sleepTime *= 2;
-				try (FileOutputStream fos = new FileOutputStream(tmp)) {
-					// Do nothing
-				}
+				FileUtils.touch(tmp.toPath());
 				actTime = fs.lastModified(tmp);
 			}
 			return actTime;

org.eclipse.jgit.test/tst/org/eclipse/jgit/util/FSTest.java

@@ -52,9 +52,16 @@ import java.io.File;
 import java.io.IOException;
 import java.nio.charset.Charset;
 import java.nio.file.Files;
+import java.nio.file.Path;
+import java.nio.file.attribute.FileTime;
 import java.nio.file.attribute.PosixFileAttributeView;
 import java.nio.file.attribute.PosixFilePermission;
+import java.time.Duration;
+import java.time.ZoneId;
+import java.time.format.DateTimeFormatter;
+import java.util.Locale;
 import java.util.Set;
+import java.util.concurrent.TimeUnit;
 
 import org.eclipse.jgit.errors.CommandFailedException;
 import org.eclipse.jgit.junit.RepositoryTestCase;
@@ -186,4 +193,34 @@ public class FSTest {
 				  new String[] { "this-command-does-not-exist" },
 				  Charset.defaultCharset().name());
 	}
+
+	@Test
+	public void testFsTimestampResolution() throws Exception {
+		DateTimeFormatter formatter = DateTimeFormatter
+				.ofPattern("uuuu-MMM-dd HH:mm:ss.nnnnnnnnn", Locale.ENGLISH)
+				.withZone(ZoneId.systemDefault());
+		Path dir = Files.createTempDirectory("probe-filesystem");
+		Duration resolution = FS.getFsTimerResolution(dir);
+		long resolutionNs = resolution.toNanos();
+		assertTrue(resolutionNs > 0);
+		for (int i = 0; i < 10; i++) {
+			Path f = null;
+			try {
+				f = dir.resolve("testTimestampResolution" + i);
+				Files.createFile(f);
+				FileUtils.touch(f);
+				FileTime t1 = Files.getLastModifiedTime(f);
+				TimeUnit.NANOSECONDS.sleep(resolutionNs);
+				FileUtils.touch(f);
+				FileTime t2 = Files.getLastModifiedTime(f);
+				assertTrue(String.format(
+						"expected t2=%s to be larger than t1=%s\nsince file timestamp resolution was measured to be %,d ns",
+						formatter.format(t2.toInstant()),
+						formatter.format(t1.toInstant()),
+						Long.valueOf(resolutionNs)), t2.compareTo(t1) > 0);
+			} finally {
+				Files.delete(f);
+			}
+		}
+	}
 }

org.eclipse.jgit/.settings/.api_filters

@@ -59,5 +59,19 @@
                 <message_argument value="fileAttributes(File)"/>
             </message_arguments>
         </filter>
+        <filter id="1142947843">
+            <message_arguments>
+                <message_argument value="5.2.3"/>
+                <message_argument value="getFsTimerResolution(Path)"/>
+            </message_arguments>
+        </filter>
+    </resource>
+    <resource path="src/org/eclipse/jgit/util/FileUtils.java" type="org.eclipse.jgit.util.FileUtils">
+        <filter id="1142947843">
+            <message_arguments>
+                <message_argument value="5.2.3"/>
+                <message_argument value="touch(Path)"/>
+            </message_arguments>
+        </filter>
     </resource>
 </component>

org.eclipse.jgit/src/org/eclipse/jgit/internal/storage/file/FileSnapshot.java

@@ -48,10 +48,12 @@ import java.io.IOException;
 import java.nio.file.attribute.BasicFileAttributes;
 import java.text.DateFormat;
 import java.text.SimpleDateFormat;
+import java.time.Duration;
 import java.util.Date;
 import java.util.Locale;
 import java.util.Objects;
 
+import org.eclipse.jgit.annotations.NonNull;
 import org.eclipse.jgit.util.FS;
 
 /**
@@ -85,7 +87,8 @@ public class FileSnapshot {
 	 * file, but only after {@link #isModified(File)} gets invoked. The returned
 	 * snapshot contains only invalid status information.
 	 */
-	public static final FileSnapshot DIRTY = new FileSnapshot(-1, -1, UNKNOWN_SIZE);
+	public static final FileSnapshot DIRTY = new FileSnapshot(-1, -1,
+			UNKNOWN_SIZE, Duration.ZERO);
 
 	/**
 	 * A FileSnapshot that is clean if the file does not exist.
@@ -94,7 +97,8 @@ public class FileSnapshot {
 	 * file to be clean. {@link #isModified(File)} will return false if the file
 	 * path does not exist.
 	 */
-	public static final FileSnapshot MISSING_FILE = new FileSnapshot(0, 0, 0) {
+	public static final FileSnapshot MISSING_FILE = new FileSnapshot(0, 0, 0,
+			Duration.ZERO) {
 		@Override
 		public boolean isModified(File path) {
 			return FS.DETECTED.exists(path);
@@ -115,6 +119,8 @@ public class FileSnapshot {
 		long read = System.currentTimeMillis();
 		long modified;
 		long size;
+		Duration fsTimerResolution = FS
+				.getFsTimerResolution(path.toPath().getParent());
 		try {
 			BasicFileAttributes fileAttributes = FS.DETECTED.fileAttributes(path);
 			modified = fileAttributes.lastModifiedTime().toMillis();
@@ -123,7 +129,7 @@ public class FileSnapshot {
 			modified = path.lastModified();
 			size = path.length();
 		}
-		return new FileSnapshot(read, modified, size);
+		return new FileSnapshot(read, modified, size, fsTimerResolution);
 	}
 
 	/**
@@ -131,6 +137,11 @@ public class FileSnapshot {
 	 * already known.
 	 * <p>
 	 * This method should be invoked before the file is accessed.
+	 * <p>
+	 * Note that this method cannot rely on measuring file timestamp resolution
+	 * to avoid racy git issues caused by finite file timestamp resolution since
+	 * it's unknown in which filesystem the file is located. Hence the worst
+	 * case fallback for timestamp resolution is used.
 	 *
 	 * @param modified
 	 *            the last modification time of the file
@@ -138,7 +149,7 @@ public class FileSnapshot {
 	 */
 	public static FileSnapshot save(long modified) {
 		final long read = System.currentTimeMillis();
-		return new FileSnapshot(read, modified, -1);
+		return new FileSnapshot(read, modified, -1, Duration.ZERO);
 	}
 
 	/** Last observed modification time of the path. */
@@ -155,11 +166,16 @@ public class FileSnapshot {
 	 * When set to {@link #UNKNOWN_SIZE} the size is not considered for modification checks. */
 	private final long size;
 
-	private FileSnapshot(long read, long modified, long size) {
+	/** measured filesystem timestamp resolution */
+	private Duration fsTimestampResolution;
+
+	private FileSnapshot(long read, long modified, long size,
+			@NonNull Duration fsTimestampResolution) {
 		this.lastRead = read;
 		this.lastModified = modified;
-		this.cannotBeRacilyClean = notRacyClean(read);
+		this.fsTimestampResolution = fsTimestampResolution;
 		this.size = size;
+		this.cannotBeRacilyClean = notRacyClean(read);
 	}
 
 	/**
@@ -279,11 +295,9 @@ public class FileSnapshot {
 	}
 
 	private boolean notRacyClean(long read) {
-		// The last modified time granularity of FAT filesystems is 2 seconds.
-		// Using 2.5 seconds here provides a reasonably high assurance that
-		// a modification was not missed.
-		//
-		return read - lastModified > 2500;
+		// add a 10% safety margin
+		long racyNanos = (fsTimestampResolution.toNanos() + 1) * 11 / 10;
+		return (read - lastModified) * 1_000_000 > racyNanos;
 	}
 
 	private boolean isModified(long currLastModified) {

org.eclipse.jgit/src/org/eclipse/jgit/util/FS.java

@@ -53,23 +53,31 @@ import java.io.InputStreamReader;
 import java.io.OutputStream;
 import java.io.PrintStream;
 import java.nio.charset.Charset;
+import java.nio.file.AccessDeniedException;
+import java.nio.file.FileStore;
 import java.nio.file.Files;
 import java.nio.file.Path;
 import java.nio.file.attribute.BasicFileAttributes;
+import java.nio.file.attribute.FileTime;
 import java.security.AccessController;
 import java.security.PrivilegedAction;
 import java.text.MessageFormat;
+import java.time.Duration;
 import java.util.Arrays;
 import java.util.HashMap;
 import java.util.Map;
 import java.util.Objects;
 import java.util.Optional;
+import java.util.UUID;
+import java.util.concurrent.ConcurrentHashMap;
 import java.util.concurrent.ExecutorService;
 import java.util.concurrent.Executors;
 import java.util.concurrent.TimeUnit;
 import java.util.concurrent.atomic.AtomicBoolean;
 import java.util.concurrent.atomic.AtomicReference;
+import java.util.stream.Collectors;
 
+import org.eclipse.jgit.annotations.NonNull;
 import org.eclipse.jgit.annotations.Nullable;
 import org.eclipse.jgit.api.errors.JGitInternalException;
 import org.eclipse.jgit.errors.CommandFailedException;
@@ -178,6 +186,83 @@ public abstract class FS {
 		}
 	}
 
+	private static final class FileStoreAttributeCache {
+		/**
+		 * The last modified time granularity of FAT filesystems is 2 seconds.
+		 */
+		private static final Duration FALLBACK_TIMESTAMP_RESOLUTION = Duration
+				.ofMillis(2000);
+
+		private static final Map<FileStore, FileStoreAttributeCache> attributeCache = new ConcurrentHashMap<>();
+
+		static Duration getFsTimestampResolution(Path file) {
+			try {
+				Path dir = Files.isDirectory(file) ? file : file.getParent();
+				if (!dir.toFile().canWrite()) {
+					// can not determine FileStore of an unborn directory or in
+					// a read-only directory
+					return FALLBACK_TIMESTAMP_RESOLUTION;
+				}
+				FileStore s = Files.getFileStore(dir);
+				FileStoreAttributeCache c = attributeCache.get(s);
+				if (c == null) {
+					c = new FileStoreAttributeCache(dir);
+					attributeCache.put(s, c);
+					if (LOG.isDebugEnabled()) {
+						LOG.debug(c.toString());
+					}
+				}
+				return c.getFsTimestampResolution();
+
+			} catch (IOException | InterruptedException e) {
+				LOG.warn(e.getMessage(), e);
+				return FALLBACK_TIMESTAMP_RESOLUTION;
+			}
+		}
+
+		private Duration fsTimestampResolution;
+
+		Duration getFsTimestampResolution() {
+			return fsTimestampResolution;
+		}
+
+		private FileStoreAttributeCache(Path dir)
+				throws IOException, InterruptedException {
+			Path probe = dir.resolve(".probe-" + UUID.randomUUID()); //$NON-NLS-1$
+			Files.createFile(probe);
+			try {
+				FileTime startTime = Files.getLastModifiedTime(probe);
+				FileTime actTime = startTime;
+				long sleepTime = 512;
+				while (actTime.compareTo(startTime) <= 0) {
+					TimeUnit.NANOSECONDS.sleep(sleepTime);
+					FileUtils.touch(probe);
+					actTime = Files.getLastModifiedTime(probe);
+					// limit sleep time to max. 100ms
+					if (sleepTime < 100_000_000L) {
+						sleepTime = sleepTime * 2;
+					}
+				}
+				fsTimestampResolution = Duration.between(startTime.toInstant(),
+						actTime.toInstant());
+			} catch (AccessDeniedException e) {
+				LOG.error(e.getLocalizedMessage(), e);
+			} finally {
+				Files.delete(probe);
+			}
+		}
+
+		@SuppressWarnings("nls")
+		@Override
+		public String toString() {
+			return "FileStoreAttributeCache[" + attributeCache.keySet()
+					.stream()
+					.map(key -> "FileStore[" + key + "]: fsTimestampResolution="
+							+ attributeCache.get(key).getFsTimestampResolution())
+					.collect(Collectors.joining(",\n")) + "]";
+		}
+	}
+
 	/** The auto-detected implementation selected for this operating system and JRE. */
 	public static final FS DETECTED = detect();
 
@@ -219,6 +304,21 @@ public abstract class FS {
 		return factory.detect(cygwinUsed);
 	}
 
+	/**
+	 * Get an estimate for the filesystem timestamp resolution from a cache of
+	 * timestamp resolution per FileStore, if not yet available it is measured
+	 * for a probe file under the given directory.
+	 *
+	 * @param dir
+	 *            the directory under which the probe file will be created to
+	 *            measure the timer resolution.
+	 * @return measured filesystem timestamp resolution
+	 * @since 5.2.3
+	 */
+	public static Duration getFsTimerResolution(@NonNull Path dir) {
+		return FileStoreAttributeCache.getFsTimestampResolution(dir);
+	}
+
 	private volatile Holder<File> userHome;
 
 	private volatile Holder<File> gitSystemConfig;

org.eclipse.jgit/src/org/eclipse/jgit/util/FileUtils.java

@@ -49,6 +49,7 @@ import static java.nio.charset.StandardCharsets.UTF_8;
 
 import java.io.File;
 import java.io.IOException;
+import java.io.OutputStream;
 import java.nio.file.AtomicMoveNotSupportedException;
 import java.nio.file.CopyOption;
 import java.nio.file.Files;
@@ -908,4 +909,18 @@ public class FileUtils {
 		}
 		return path;
 	}
+
+	/**
+	 * Touch the given file
+	 *
+	 * @param f
+	 *            the file to touch
+	 * @throws IOException
+	 * @since 5.2.3
+	 */
+	public static void touch(Path f) throws IOException {
+		try (OutputStream fos = Files.newOutputStream(f)) {
+			// touch the file
+		}
+	}
 }