DFS block cache: report index load and evict stats

Enhance cache performance monitoring for large data such as pack and
bitmap indexes. Provide details about what is loaded and evicted from
cache like total number of cache hits, time in cache before eviction.

Add a custom consumer to report loading events and eviction events when
enabled.

Signed-off-by: Alina Djamankulova <adjama@google.com>
Change-Id: I5739325db7ff7ec370e4defd8f7e46f1c3f5d2dd

2 files changed, 162 insertions, 4 deletions

diff --git a/org.eclipse.jgit/src/org/eclipse/jgit/internal/storage/dfs/DfsBlockCache.java b/org.eclipse.jgit/src/org/eclipse/jgit/internal/storage/dfs/DfsBlockCache.java
index 54c527c03c..b30d50921a 100644
--- a/org.eclipse.jgit/src/org/eclipse/jgit/internal/storage/dfs/DfsBlockCache.java
+++ b/org.eclipse.jgit/src/org/eclipse/jgit/internal/storage/dfs/DfsBlockCache.java
@@ -12,6 +12,10 @@
 package org.eclipse.jgit.internal.storage.dfs;
 
 import java.io.IOException;
+import java.time.Duration;
+import java.util.Map;
+import java.util.concurrent.ConcurrentHashMap;
+import java.util.concurrent.atomic.AtomicInteger;
 import java.util.concurrent.atomic.AtomicLong;
 import java.util.concurrent.atomic.AtomicReference;
 import java.util.concurrent.atomic.AtomicReferenceArray;
@@ -166,6 +170,12 @@ public final class DfsBlockCache {
 	/** Limits of cache hot count per pack file extension. */
 	private final int[] cacheHotLimits = new int[PackExt.values().length];
 
+	/** Consumer of loading and eviction events of indexes. */
+	private final DfsBlockCacheConfig.IndexEventConsumer indexEventConsumer;
+
+	/** Stores timestamps of the last eviction of indexes. */
+	private final Map<EvictKey, Long> indexEvictionMap = new ConcurrentHashMap<>();
+
 	@SuppressWarnings("unchecked")
 	private DfsBlockCache(DfsBlockCacheConfig cfg) {
 		tableSize = tableSize(cfg);
@@ -213,6 +223,7 @@ public final class DfsBlockCache {
 				cacheHotLimits[i] = DfsBlockCacheConfig.DEFAULT_CACHE_HOT_MAX;
 			}
 		}
+		indexEventConsumer = cfg.getIndexEventConsumer();
 	}
 
 	boolean shouldCopyThroughCache(long length) {
@@ -461,6 +472,7 @@ public final class DfsBlockCache {
 					live -= dead.size;
 					getStat(liveBytes, dead.key).addAndGet(-dead.size);
 					getStat(statEvict, dead.key).incrementAndGet();
+					reportIndexEvicted(dead);
 				} while (maxBytes < live);
 				clockHand = prev;
 			}
@@ -515,11 +527,13 @@ public final class DfsBlockCache {
 	<T> Ref<T> getOrLoadRef(
 			DfsStreamKey key, long position, RefLoader<T> loader)
 			throws IOException {
+		long start = System.nanoTime();
 		int slot = slot(key, position);
 		HashEntry e1 = table.get(slot);
 		Ref<T> ref = scanRef(e1, key, position);
 		if (ref != null) {
 			getStat(statHit, key).incrementAndGet();
+			reportIndexRequested(ref, true /* cacheHit */, start);
 			return ref;
 		}
 
@@ -532,6 +546,8 @@ public final class DfsBlockCache {
 				ref = scanRef(e2, key, position);
 				if (ref != null) {
 					getStat(statHit, key).incrementAndGet();
+					reportIndexRequested(ref, true /* cacheHit */,
+							start);
 					return ref;
 				}
 			}
@@ -556,6 +572,7 @@ public final class DfsBlockCache {
 		} finally {
 			regionLock.unlock();
 		}
+		reportIndexRequested(ref, false /* cacheHit */, start);
 		return ref;
 	}
 
@@ -682,8 +699,9 @@ public final class DfsBlockCache {
 	}
 
 	private static HashEntry clean(HashEntry top) {
-		while (top != null && top.ref.next == null)
+		while (top != null && top.ref.next == null) {
 			top = top.next;
+		}
 		if (top == null) {
 			return null;
 		}
@@ -691,6 +709,44 @@ public final class DfsBlockCache {
 		return n == top.next ? top : new HashEntry(n, top.ref);
 	}
 
+	private void reportIndexRequested(Ref<?> ref, boolean cacheHit,
+			long start) {
+		if (indexEventConsumer == null
+				|| !isIndexOrBitmapExtPos(ref.key.packExtPos)) {
+			return;
+		}
+		EvictKey evictKey = new EvictKey(ref);
+		Long prevEvictedTime = indexEvictionMap.get(evictKey);
+		long now = System.nanoTime();
+		long sinceLastEvictionNanos = prevEvictedTime == null ? 0L
+				: now - prevEvictedTime.longValue();
+		indexEventConsumer.acceptRequestedEvent(ref.key.packExtPos, cacheHit,
+				(now - start) / 1000L /* micros */, ref.size,
+				Duration.ofNanos(sinceLastEvictionNanos));
+	}
+
+	private void reportIndexEvicted(Ref<?> dead) {
+		if (indexEventConsumer == null
+				|| !indexEventConsumer.shouldReportEvictedEvent()
+				|| !isIndexOrBitmapExtPos(dead.key.packExtPos)) {
+			return;
+		}
+		EvictKey evictKey = new EvictKey(dead);
+		Long prevEvictedTime = indexEvictionMap.get(evictKey);
+		long now = System.nanoTime();
+		long sinceLastEvictionNanos = prevEvictedTime == null ? 0L
+				: now - prevEvictedTime.longValue();
+		indexEvictionMap.put(evictKey, Long.valueOf(now));
+		indexEventConsumer.acceptEvictedEvent(dead.key.packExtPos, dead.size,
+				dead.totalHitCount.get(),
+				Duration.ofNanos(sinceLastEvictionNanos));
+	}
+
+	private static boolean isIndexOrBitmapExtPos(int packExtPos) {
+		return packExtPos == PackExt.INDEX.getPosition()
+				|| packExtPos == PackExt.BITMAP_INDEX.getPosition();
+	}
+
 	private static final class HashEntry {
 		/** Next entry in the hash table's chain list. */
 		final HashEntry next;
@@ -712,6 +768,7 @@ public final class DfsBlockCache {
 		Ref next;
 
 		private volatile int hotCount;
+		private AtomicInteger totalHitCount = new AtomicInteger();
 
 		Ref(DfsStreamKey key, long position, long size, T v) {
 			this.key = key;
@@ -736,6 +793,7 @@ public final class DfsBlockCache {
 			int cap = DfsBlockCache
 					.getInstance().cacheHotLimits[key.packExtPos];
 			hotCount = Math.min(cap, hotCount + 1);
+			totalHitCount.incrementAndGet();
 		}
 
 		void markColder() {
@@ -747,6 +805,34 @@ public final class DfsBlockCache {
 		}
 	}
 
+	private static final class EvictKey {
+		private final int keyHash;
+		private final int packExtPos;
+		private final long position;
+
+		EvictKey(Ref<?> ref) {
+			keyHash = ref.key.hash;
+			packExtPos = ref.key.packExtPos;
+			position = ref.position;
+		}
+
+		@Override
+		public boolean equals(Object object) {
+			if (object instanceof EvictKey) {
+				EvictKey other = (EvictKey) object;
+				return keyHash == other.keyHash
+						&& packExtPos == other.packExtPos
+						&& position == other.position;
+			}
+			return false;
+		}
+
+		@Override
+		public int hashCode() {
+			return DfsBlockCache.getInstance().hash(keyHash, position);
+		}
+	}
+
 	@FunctionalInterface
 	interface RefLoader<T> {
 		Ref<T> load() throws IOException;
@@ -763,4 +849,4 @@ public final class DfsBlockCache {
 		 */
 		ReadableChannel get() throws IOException;
 	}
-}
+}
\ No newline at end of file
diff --git a/org.eclipse.jgit/src/org/eclipse/jgit/internal/storage/dfs/DfsBlockCacheConfig.java b/org.eclipse.jgit/src/org/eclipse/jgit/internal/storage/dfs/DfsBlockCacheConfig.java
index 2716f79a1a..69a37058bf 100644
--- a/org.eclipse.jgit/src/org/eclipse/jgit/internal/storage/dfs/DfsBlockCacheConfig.java
+++ b/org.eclipse.jgit/src/org/eclipse/jgit/internal/storage/dfs/DfsBlockCacheConfig.java
@@ -18,6 +18,7 @@ import static org.eclipse.jgit.lib.ConfigConstants.CONFIG_KEY_CONCURRENCY_LEVEL;
 import static org.eclipse.jgit.lib.ConfigConstants.CONFIG_KEY_STREAM_RATIO;
 
 import java.text.MessageFormat;
+import java.time.Duration;
 import java.util.Collections;
 import java.util.Map;
 import java.util.function.Consumer;
@@ -46,9 +47,10 @@ public class DfsBlockCacheConfig {
 	private int concurrencyLevel;
 
 	private Consumer<Long> refLock;
-
 	private Map<PackExt, Integer> cacheHotMap;
 
+	private IndexEventConsumer indexEventConsumer;
+
 	/**
 	 * Create a default configuration.
 	 */
@@ -216,6 +218,28 @@ public class DfsBlockCacheConfig {
 	}
 
 	/**
+	 * Get the consumer of cache index events.
+	 *
+	 * @return consumer of cache index events.
+	 */
+	public IndexEventConsumer getIndexEventConsumer() {
+		return indexEventConsumer;
+	}
+
+	/**
+	 * Set the consumer of cache index events.
+	 *
+	 * @param indexEventConsumer
+	 *            consumer of cache index events.
+	 * @return {@code this}
+	 */
+	public DfsBlockCacheConfig setIndexEventConsumer(
+			IndexEventConsumer indexEventConsumer) {
+		this.indexEventConsumer = indexEventConsumer;
+		return this;
+	}
+
+	/**
 	 * Update properties by setting fields from the configuration.
 	 * <p>
 	 * If a property is not defined in the configuration, then it is left
@@ -272,4 +296,52 @@ public class DfsBlockCacheConfig {
 		}
 		return this;
 	}
-}
+
+	/** Consumer of DfsBlockCache loading and eviction events for indexes. */
+	public interface IndexEventConsumer {
+		/**
+		 * Accept an event of an index requested. It could be loaded from either
+		 * cache or storage.
+		 *
+		 * @param packExtPos
+		 *            position in {@code PackExt} enum
+		 * @param cacheHit
+		 *            true if an index was already in cache. Otherwise, the
+		 *            index was loaded from storage into the cache in the
+		 *            current request,
+		 * @param loadMicros
+		 *            time to load an index from cache or storage in
+		 *            microseconds
+		 * @param bytes
+		 *            number of bytes loaded
+		 * @param lastEvictionDuration
+		 *            time since last eviction, 0 if was not evicted yet
+		 */
+		void acceptRequestedEvent(int packExtPos, boolean cacheHit,
+				long loadMicros, long bytes, Duration lastEvictionDuration);
+
+		/**
+		 * Accept an event of an index evicted from cache.
+		 *
+		 * @param packExtPos
+		 *            position in {@code PackExt} enum
+		 * @param bytes
+		 *            number of bytes evicted
+		 * @param totalCacheHitCount
+		 *            number of times an index was accessed while in cache
+		 * @param lastEvictionDuration
+		 *            time since last eviction, 0 if was not evicted yet
+		 */
+		default void acceptEvictedEvent(int packExtPos, long bytes,
+				int totalCacheHitCount, Duration lastEvictionDuration) {
+			// Off by default.
+		}
+
+		/**
+		 * @return true if reporting evicted events is enabled.
+		 */
+		default boolean shouldReportEvictedEvent() {
+			return false;
+		}
+	}
+}
\ No newline at end of file