From b536dbdb9b7099511362abe825cfd50b942ccf7c Mon Sep 17 00:00:00 2001 From: Alina Djamankulova Date: Wed, 29 Dec 2021 15:07:27 -0800 Subject: [PATCH] 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 Change-Id: I5739325db7ff7ec370e4defd8f7e46f1c3f5d2dd --- .../storage/dfs/DfsBlockCacheTest.java | 117 ++++++++++++++++++ .../internal/storage/dfs/DfsBlockCache.java | 90 +++++++++++++- .../storage/dfs/DfsBlockCacheConfig.java | 76 +++++++++++- 3 files changed, 279 insertions(+), 4 deletions(-) diff --git a/org.eclipse.jgit.test/tst/org/eclipse/jgit/internal/storage/dfs/DfsBlockCacheTest.java b/org.eclipse.jgit.test/tst/org/eclipse/jgit/internal/storage/dfs/DfsBlockCacheTest.java index 070d666ee..bacd3ba0a 100644 --- a/org.eclipse.jgit.test/tst/org/eclipse/jgit/internal/storage/dfs/DfsBlockCacheTest.java +++ b/org.eclipse.jgit.test/tst/org/eclipse/jgit/internal/storage/dfs/DfsBlockCacheTest.java @@ -15,16 +15,19 @@ import static org.junit.Assert.assertEquals; import static org.junit.Assert.assertTrue; +import java.time.Duration; import java.util.Arrays; import java.util.Collections; import java.util.HashMap; import java.util.List; import java.util.Map; +import java.util.concurrent.atomic.AtomicInteger; import java.util.stream.LongStream; import java.util.concurrent.Callable; import java.util.concurrent.ExecutorService; import java.util.concurrent.Executors; +import org.eclipse.jgit.internal.storage.dfs.DfsBlockCacheConfig.IndexEventConsumer; import org.eclipse.jgit.internal.storage.pack.PackExt; import org.eclipse.jgit.junit.TestRepository; import org.eclipse.jgit.junit.TestRng; @@ -152,6 +155,120 @@ public void hasCacheHotMap() throws Exception { assertEquals(0, cache.getEvictions()[PackExt.INDEX.getPosition()]); } + @SuppressWarnings("resource") + @Test + public void hasIndexEventConsumerOnlyLoaded() throws Exception { + AtomicInteger loaded = new AtomicInteger(); + IndexEventConsumer indexEventConsumer = new IndexEventConsumer() { + @Override + public void acceptRequestedEvent(int packExtPos, boolean cacheHit, + long loadMicros, long bytes, + Duration lastEvictionDuration) { + assertEquals(PackExt.INDEX.getPosition(), packExtPos); + assertTrue(cacheHit); + assertTrue(lastEvictionDuration.isZero()); + loaded.incrementAndGet(); + } + }; + + DfsBlockCache.reconfigure(new DfsBlockCacheConfig().setBlockSize(512) + .setBlockLimit(512 * 4) + .setIndexEventConsumer(indexEventConsumer)); + cache = DfsBlockCache.getInstance(); + + DfsRepositoryDescription repo = new DfsRepositoryDescription("test"); + InMemoryRepository r1 = new InMemoryRepository(repo); + byte[] content = rng.nextBytes(424242); + ObjectId id; + try (ObjectInserter ins = r1.newObjectInserter()) { + id = ins.insert(OBJ_BLOB, content); + ins.flush(); + } + + try (ObjectReader rdr = r1.newObjectReader()) { + byte[] actual = rdr.open(id, OBJ_BLOB).getBytes(); + assertTrue(Arrays.equals(content, actual)); + } + // All cache entries are hot and cache is at capacity. + assertTrue(LongStream.of(cache.getHitCount()).sum() > 0); + assertEquals(99, cache.getFillPercentage()); + + InMemoryRepository r2 = new InMemoryRepository(repo); + content = rng.nextBytes(424242); + try (ObjectInserter ins = r2.newObjectInserter()) { + ins.insert(OBJ_BLOB, content); + ins.flush(); + } + assertTrue(cache.getEvictions()[PackExt.PACK.getPosition()] > 0); + assertEquals(1, cache.getEvictions()[PackExt.INDEX.getPosition()]); + assertEquals(1, loaded.get()); + } + + @SuppressWarnings("resource") + @Test + public void hasIndexEventConsumerLoadedAndEvicted() throws Exception { + AtomicInteger loaded = new AtomicInteger(); + AtomicInteger evicted = new AtomicInteger(); + IndexEventConsumer indexEventConsumer = new IndexEventConsumer() { + @Override + public void acceptRequestedEvent(int packExtPos, boolean cacheHit, + long loadMicros, long bytes, + Duration lastEvictionDuration) { + assertEquals(PackExt.INDEX.getPosition(), packExtPos); + assertTrue(cacheHit); + assertTrue(lastEvictionDuration.isZero()); + loaded.incrementAndGet(); + } + + @Override + public void acceptEvictedEvent(int packExtPos, long bytes, + int totalCacheHitCount, Duration lastEvictionDuration) { + assertEquals(PackExt.INDEX.getPosition(), packExtPos); + assertTrue(totalCacheHitCount > 0); + assertTrue(lastEvictionDuration.isZero()); + evicted.incrementAndGet(); + } + + @Override + public boolean shouldReportEvictedEvent() { + return true; + } + }; + + DfsBlockCache.reconfigure(new DfsBlockCacheConfig().setBlockSize(512) + .setBlockLimit(512 * 4) + .setIndexEventConsumer(indexEventConsumer)); + cache = DfsBlockCache.getInstance(); + + DfsRepositoryDescription repo = new DfsRepositoryDescription("test"); + InMemoryRepository r1 = new InMemoryRepository(repo); + byte[] content = rng.nextBytes(424242); + ObjectId id; + try (ObjectInserter ins = r1.newObjectInserter()) { + id = ins.insert(OBJ_BLOB, content); + ins.flush(); + } + + try (ObjectReader rdr = r1.newObjectReader()) { + byte[] actual = rdr.open(id, OBJ_BLOB).getBytes(); + assertTrue(Arrays.equals(content, actual)); + } + // All cache entries are hot and cache is at capacity. + assertTrue(LongStream.of(cache.getHitCount()).sum() > 0); + assertEquals(99, cache.getFillPercentage()); + + InMemoryRepository r2 = new InMemoryRepository(repo); + content = rng.nextBytes(424242); + try (ObjectInserter ins = r2.newObjectInserter()) { + ins.insert(OBJ_BLOB, content); + ins.flush(); + } + assertTrue(cache.getEvictions()[PackExt.PACK.getPosition()] > 0); + assertEquals(1, cache.getEvictions()[PackExt.INDEX.getPosition()]); + assertEquals(1, loaded.get()); + assertEquals(1, evicted.get()); + } + @SuppressWarnings("resource") @Test public void noConcurrencySerializedReads_oneRepo() throws Exception { 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 54c527c03..b30d50921 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 static DfsBlockCache getInstance() { /** 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 indexEvictionMap = new ConcurrentHashMap<>(); + @SuppressWarnings("unchecked") private DfsBlockCache(DfsBlockCacheConfig cfg) { tableSize = tableSize(cfg); @@ -213,6 +223,7 @@ private DfsBlockCache(DfsBlockCacheConfig cfg) { cacheHotLimits[i] = DfsBlockCacheConfig.DEFAULT_CACHE_HOT_MAX; } } + indexEventConsumer = cfg.getIndexEventConsumer(); } boolean shouldCopyThroughCache(long length) { @@ -461,6 +472,7 @@ private void reserveSpace(long reserve, DfsStreamKey key) { 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 @@ void put(DfsBlock v) { Ref getOrLoadRef( DfsStreamKey key, long position, RefLoader loader) throws IOException { + long start = System.nanoTime(); int slot = slot(key, position); HashEntry e1 = table.get(slot); Ref ref = scanRef(e1, key, position); if (ref != null) { getStat(statHit, key).incrementAndGet(); + reportIndexRequested(ref, true /* cacheHit */, start); return ref; } @@ -532,6 +546,8 @@ Ref getOrLoadRef( ref = scanRef(e2, key, position); if (ref != null) { getStat(statHit, key).incrementAndGet(); + reportIndexRequested(ref, true /* cacheHit */, + start); return ref; } } @@ -556,6 +572,7 @@ Ref getOrLoadRef( } finally { regionLock.unlock(); } + reportIndexRequested(ref, false /* cacheHit */, start); return ref; } @@ -682,8 +699,9 @@ private static long[] getStatVals(AtomicReference stat) { } 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 @@ private static HashEntry clean(HashEntry top) { 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 @@ static final class Ref { 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 @@ void markHotter() { int cap = DfsBlockCache .getInstance().cacheHotLimits[key.packExtPos]; hotCount = Math.min(cap, hotCount + 1); + totalHitCount.incrementAndGet(); } void markColder() { @@ -747,6 +805,34 @@ boolean isHot() { } } + 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 { Ref load() throws IOException; @@ -763,4 +849,4 @@ interface ReadableChannelSupplier { */ 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 2716f79a1..69a37058b 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_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 refLock; - private Map cacheHotMap; + private IndexEventConsumer indexEventConsumer; + /** * Create a default configuration. */ @@ -215,6 +217,28 @@ public DfsBlockCacheConfig setCacheHotMap( return this; } + /** + * 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. *

@@ -272,4 +296,52 @@ public DfsBlockCacheConfig fromConfig(Config rc) { } 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