Merge pull request #4144 from SirTyson/eviction-metrics

Add eviction cycle metrics

Reviewed-by: marta-lokhova

docs/metrics.md

@@ -157,6 +157,8 @@ scp.timing.self-to-others-externalize-lag | timer     | delay between local node
 scp.value.invalid                         | meter     | SCP value is invalid
 scp.value.valid                           | meter     | SCP value is valid
 scp.slot.values-referenced                | histogram | number of values referenced per consensus round
+state-archival.eviction.age               | counter   | the average of the delta between an entry's liveUntilLedger and the ledger when it is evicted
 state-archival.eviction.bytes-scanned     | counter   | number of bytes that eviction scan has read
 state-archival.eviction.entries-evicted   | counter   | number of entries that have been evicted
 state-archival.eviction.incomplete-scan   | counter   | number of buckets that were too large to be fully scanned for eviction
+state-archival.eviction.period            | counter   | number of ledgers to complete an eviction scan

src/bucket/Bucket.cpp

@@ -841,7 +841,8 @@ Bucket::scanForEviction(AbstractLedgerTxn& ltx, EvictionIterator& iter,
                         uint64_t& bytesToScan, uint32_t& maxEntriesToEvict,
                         uint32_t ledgerSeq,
                         medida::Counter& entriesEvictedCounter,
-                        medida::Counter& bytesScannedForEvictionCounter)
+                        medida::Counter& bytesScannedForEvictionCounter,
+                        std::optional<EvictionMetrics>& metrics)
 {
     ZoneScoped;
     if (isEmpty())
@@ -876,6 +877,7 @@ Bucket::scanForEviction(AbstractLedgerTxn& ltx, EvictionIterator& iter,
                 auto initialStreamPos = stream.pos();
 
                 auto ttlKey = getTTLKey(le);
+                uint32_t liveUntilLedger = 0;
                 auto shouldEvict = [&] {
                     auto entryLtxe = ltx.loadWithoutRecord(LedgerEntryKey(le));
                     auto ttlLtxe = ltx.loadWithoutRecord(ttlKey);
@@ -888,13 +890,21 @@ Bucket::scanForEviction(AbstractLedgerTxn& ltx, EvictionIterator& iter,
                     }
 
                     releaseAssert(ttlLtxe);
-
+                    liveUntilLedger =
+                        ttlLtxe.current().data.ttl().liveUntilLedgerSeq;
                     return !isLive(ttlLtxe.current(), ledgerSeq);
                 };
 
                 if (shouldEvict())
                 {
                     ZoneNamedN(evict, "evict entry", true);
+                    if (metrics.has_value())
+                    {
+                        ++metrics->numEntriesEvicted;
+                        metrics->evictedEntriesAgeSum +=
+                            ledgerSeq - liveUntilLedger;
+                    }
+
                     ltx.erase(ttlKey);
                     ltx.erase(LedgerEntryKey(le));
                     entriesEvictedCounter.inc();

src/bucket/Bucket.h

@@ -38,6 +38,7 @@ namespace stellar
 class AbstractLedgerTxn;
 class Application;
 class BucketManager;
+struct EvictionMetrics;
 
 class Bucket : public std::enable_shared_from_this<Bucket>,
                public NonMovableOrCopyable
@@ -145,7 +146,8 @@ class Bucket : public std::enable_shared_from_this<Bucket>,
                          uint64_t& bytesToScan, uint32_t& maxEntriesToEvict,
                          uint32_t ledgerSeq,
                          medida::Counter& entriesEvictedCounter,
-                         medida::Counter& bytesScannedForEvictionCounter);
+                         medida::Counter& bytesScannedForEvictionCounter,
+                         std::optional<EvictionMetrics>& metrics);
 
 #ifdef BUILD_TESTS
     // "Applies" the bucket to the database. For each entry in the bucket,

src/bucket/BucketList.cpp

@@ -829,9 +829,7 @@ BucketList::addBatch(Application& app, uint32_t currLedger,
 void
 BucketList::scanForEviction(Application& app, AbstractLedgerTxn& ltx,
                             uint32_t ledgerSeq,
-                            medida::Counter& entriesEvictedCounter,
-                            medida::Counter& bytesScannedForEvictionCounter,
-                            medida::Counter& incompleteBucketScanCounter)
+                            BucketListEvictionCounters& counters)
 {
     auto getBucketFromIter = [&levels = mLevels](EvictionIterator const& iter) {
         auto& level = levels.at(iter.bucketListLevel);
@@ -894,7 +892,8 @@ BucketList::scanForEviction(Application& app, AbstractLedgerTxn& ltx,
         auto b = getBucketFromIter(evictionIter);
         while (!b->scanForEviction(
             ltx, evictionIter, scanSize, maxEntriesToEvict, ledgerSeq,
-            entriesEvictedCounter, bytesScannedForEvictionCounter))
+            counters.entriesEvicted, counters.bytesScannedForEviction,
+            mEvictionMetrics))
         {
             // If we reached eof in curr bucket, start scanning snap.
             // Last level has no snap so cycle back to the initial level.
@@ -916,6 +915,26 @@ BucketList::scanForEviction(Application& app, AbstractLedgerTxn& ltx,
                 if (evictionIter.bucketListLevel == kNumLevels)
                 {
                     evictionIter.bucketListLevel = firstScanLevel;
+
+                    // If eviction metrics are not null, we have accounted for a
+                    // complete cycle and should log the metrics
+                    if (mEvictionMetrics)
+                    {
+                        counters.evictionCyclePeriod.set_count(
+                            ledgerSeq -
+                            mEvictionMetrics->evictionCycleStartLedger);
+
+                        auto averageAge =
+                            mEvictionMetrics->numEntriesEvicted == 0
+                                ? 0
+                                : mEvictionMetrics->evictedEntriesAgeSum /
+                                      mEvictionMetrics->numEntriesEvicted;
+                        counters.averageEvictedEntryAge.set_count(averageAge);
+                    }
+
+                    // Reset metrics at beginning of new eviction cycle
+                    mEvictionMetrics = std::make_optional<EvictionMetrics>();
+                    mEvictionMetrics->evictionCycleStartLedger = ledgerSeq;
                 }
             }
 
@@ -936,7 +955,7 @@ BucketList::scanForEviction(Application& app, AbstractLedgerTxn& ltx,
             {
                 CLOG_WARNING(
                     Bucket, "Bucket too large for current eviction scan size.");
-                incompleteBucketScanCounter.inc();
+                counters.incompleteBucketScan.inc();
             }
         }
 

src/bucket/BucketList.h

@@ -352,6 +352,7 @@ class AbstractLedgerTxn;
 class Application;
 class Bucket;
 class Config;
+struct BucketListEvictionCounters;
 struct InflationWinner;
 
 namespace testutil
@@ -402,10 +403,24 @@ class BucketListDepth
     friend class testutil::BucketListDepthModifier;
 };
 
+struct EvictionMetrics
+{
+    // Evicted entry "age" is the delta between its liveUntilLedger and the
+    // ledger when the entry is actually evicted
+    uint64_t evictedEntriesAgeSum{};
+    uint64_t numEntriesEvicted{};
+    uint32_t evictionCycleStartLedger{};
+};
+
 class BucketList
 {
     std::vector<BucketLevel> mLevels;
 
+    // To avoid noisy data, only count metrics that encompass a complete
+    // eviction cycle. If a node joins the network mid cycle, metrics will be
+    // nullopt and be initialized at the start of the next cycle.
+    std::optional<EvictionMetrics> mEvictionMetrics;
+
     // Loops through all buckets, starting with curr at level 0, then snap at
     // level 0, etc. Calls f on each bucket. Exits early if function
     // returns true
@@ -526,8 +541,6 @@ class BucketList
 
     void scanForEviction(Application& app, AbstractLedgerTxn& ltx,
                          uint32_t ledgerSeq,
-                         medida::Counter& entriesEvictedCounter,
-                         medida::Counter& bytesScannedForEvictionCounter,
-                         medida::Counter& incompleteBucketScanCounter);
+                         BucketListEvictionCounters& counters);
 };
 }

src/bucket/BucketManager.h

@@ -78,6 +78,17 @@ struct MergeCounters
     bool operator==(MergeCounters const& other) const;
 };
 
+struct BucketListEvictionCounters
+{
+    medida::Counter& entriesEvicted;
+    medida::Counter& bytesScannedForEviction;
+    medida::Counter& incompleteBucketScan;
+    medida::Counter& evictionCyclePeriod;
+    medida::Counter& averageEvictedEntryAge;
+
+    BucketListEvictionCounters(Application& app);
+};
+
 /**
  * BucketManager is responsible for maintaining a collection of Buckets of
  * ledger entries (each sorted, de-duplicated and identified by hash) and,

src/bucket/BucketManagerImpl.cpp

@@ -104,6 +104,20 @@ BucketManagerImpl::getTmpDirManager()
     return *mTmpDirManager;
 }
 
+BucketListEvictionCounters::BucketListEvictionCounters(Application& app)
+    : entriesEvicted(app.getMetrics().NewCounter(
+          {"state-archival", "eviction", "entries-evicted"}))
+    , bytesScannedForEviction(app.getMetrics().NewCounter(
+          {"state-archival", "eviction", "bytes-scanned"}))
+    , incompleteBucketScan(app.getMetrics().NewCounter(
+          {"state-archival", "eviction", "incomplete-scan"}))
+    , evictionCyclePeriod(
+          app.getMetrics().NewCounter({"state-archival", "eviction", "period"}))
+    , averageEvictedEntryAge(
+          app.getMetrics().NewCounter({"state-archival", "eviction", "age"}))
+{
+}
+
 BucketManagerImpl::BucketManagerImpl(Application& app)
     : mApp(app)
     , mBucketList(nullptr)
@@ -122,14 +136,9 @@ BucketManagerImpl::BucketManagerImpl(Application& app)
           {"bucketlistDB", "bloom", "misses"}, "bloom"))
     , mBucketListDBBloomLookups(app.getMetrics().NewMeter(
           {"bucketlistDB", "bloom", "lookups"}, "bloom"))
-    , mEntriesEvicted(app.getMetrics().NewCounter(
-          {"state-archival", "eviction", "entries-evicted"}))
-    , mBytesScannedForEviction(app.getMetrics().NewCounter(
-          {"state-archival", "eviction", "bytes-scanned"}))
-    , mIncompleteBucketScans(app.getMetrics().NewCounter(
-          {"state-archival", "eviction", "incomplete-scan"}))
     , mBucketListSizeCounter(
           app.getMetrics().NewCounter({"bucketlist", "size", "bytes"}))
+    , mBucketListEvictionCounters(app)
     // Minimal DB is stored in the buckets dir, so delete it only when
     // mode does not use minimal DB
     , mDeleteEntireBucketDirInDtor(
@@ -857,7 +866,7 @@ BucketManagerImpl::getBucketHashesInBucketDirForTesting() const
 medida::Counter&
 BucketManagerImpl::getEntriesEvictedCounter() const
 {
-    return mEntriesEvicted;
+    return mBucketListEvictionCounters.entriesEvicted;
 }
 #endif
 
@@ -904,9 +913,8 @@ BucketManagerImpl::scanForEviction(AbstractLedgerTxn& ltx, uint32_t ledgerSeq)
     if (protocolVersionStartsFrom(ltx.getHeader().ledgerVersion,
                                   SOROBAN_PROTOCOL_VERSION))
     {
-        mBucketList->scanForEviction(mApp, ltx, ledgerSeq, mEntriesEvicted,
-                                     mBytesScannedForEviction,
-                                     mIncompleteBucketScans);
+        mBucketList->scanForEviction(mApp, ltx, ledgerSeq,
+                                     mBucketListEvictionCounters);
     }
 }
 

src/bucket/BucketManagerImpl.h

@@ -50,10 +50,8 @@ class BucketManagerImpl : public BucketManager
     medida::Meter& mBucketListDBBulkLoadMeter;
     medida::Meter& mBucketListDBBloomMisses;
     medida::Meter& mBucketListDBBloomLookups;
-    medida::Counter& mEntriesEvicted;
-    medida::Counter& mBytesScannedForEviction;
-    medida::Counter& mIncompleteBucketScans;
     medida::Counter& mBucketListSizeCounter;
+    BucketListEvictionCounters mBucketListEvictionCounters;
     mutable UnorderedMap<LedgerEntryType, medida::Timer&>
         mBucketListDBPointTimers{};
     mutable UnorderedMap<std::string, medida::Timer&> mBucketListDBBulkTimers{};