Merge pull request stellar#4274 from SirTyson/bucketlistdb-better-met…

…rics

Seperate metrics for bloom miss loads

Reviewed-by: marta-lokhova

docs/metrics.md

@@ -38,7 +38,7 @@ bucketlistDB.bulk.loads                   | meter     | number of entries Bucket
 bucketlistDB.bulk.inflationWinners        | timer     | time to load inflation winners
 bucketlistDB.bulk.poolshareTrustlines     | timer     | time to load poolshare trustlines by accountID and assetID
 bucketlistDB.bulk.prefetch                | timer     | time to prefetch
-bucketlistDB.point.<X>                    | timer     | time to load single entry of type <X>
+bucketlistDB.point.<X>                    | timer     | time to load single entry of type <X> (if no bloom miss occurred)
 herder.pending[-soroban]-txs.age0         | counter   | number of gen0 pending transactions
 herder.pending[-soroban]-txs.age1         | counter   | number of gen1 pending transactions
 herder.pending[-soroban]-txs.age2         | counter   | number of gen2 pending transactions

src/bucket/BucketListSnapshot.cpp

@@ -125,22 +125,28 @@ SearchableBucketListSnapshot::getLedgerEntry(LedgerKey const& k)
 
     if (threadIsMain())
     {
-        auto timer = mSnapshotManager.getPointLoadTimer(k.type()).TimeScope();
-        return getLedgerEntryInternal(k);
+        mSnapshotManager.startPointLoadTimer();
+        auto [result, bloomMiss] = getLedgerEntryInternal(k);
+        mSnapshotManager.endPointLoadTimer(k.type(), bloomMiss);
+        return result;
     }
     else
     {
-        return getLedgerEntryInternal(k);
+        auto [result, bloomMiss] = getLedgerEntryInternal(k);
+        return result;
     }
 }
 
-std::shared_ptr<LedgerEntry>
+std::pair<std::shared_ptr<LedgerEntry>, bool>
 SearchableBucketListSnapshot::getLedgerEntryInternal(LedgerKey const& k)
 {
     std::shared_ptr<LedgerEntry> result{};
+    auto sawBloomMiss = false;
 
     auto f = [&](BucketSnapshot const& b) {
-        auto be = b.getBucketEntry(k);
+        auto [be, bloomMiss] = b.getBucketEntry(k);
+        sawBloomMiss = sawBloomMiss || bloomMiss;
+
         if (be.has_value())
         {
             result =
@@ -156,7 +162,7 @@ SearchableBucketListSnapshot::getLedgerEntryInternal(LedgerKey const& k)
     };
 
     loopAllBuckets(f);
-    return result;
+    return {result, sawBloomMiss};
 }
 
 std::vector<LedgerEntry>

src/bucket/BucketListSnapshot.h

@@ -68,7 +68,10 @@ class SearchableBucketListSnapshot : public NonMovableOrCopyable
     std::vector<LedgerEntry>
     loadKeysInternal(std::set<LedgerKey, LedgerEntryIdCmp> const& inKeys);
 
-    std::shared_ptr<LedgerEntry> getLedgerEntryInternal(LedgerKey const& k);
+    // Loads bucket entry for LedgerKey k. Returns <LedgerEntry, bloomMiss>,
+    // where bloomMiss is true if a bloom miss occurred during the load.
+    std::pair<std::shared_ptr<LedgerEntry>, bool>
+    getLedgerEntryInternal(LedgerKey const& k);
 
     SearchableBucketListSnapshot(BucketSnapshotManager const& snapshotManager);
 

src/bucket/BucketManagerImpl.cpp

@@ -126,8 +126,7 @@ BucketManagerImpl::initialize()
         if (mApp.getConfig().isUsingBucketListDB())
         {
             mSnapshotManager = std::make_unique<BucketSnapshotManager>(
-                mApp.getMetrics(),
-                std::make_unique<BucketListSnapshot>(*mBucketList, 0));
+                mApp, std::make_unique<BucketListSnapshot>(*mBucketList, 0));
         }
     }
 }

src/bucket/BucketSnapshot.cpp

@@ -31,14 +31,14 @@ BucketSnapshot::isEmpty() const
     return mBucket->isEmpty();
 }
 
-std::optional<BucketEntry>
+std::pair<std::optional<BucketEntry>, bool>
 BucketSnapshot::getEntryAtOffset(LedgerKey const& k, std::streamoff pos,
                                  size_t pageSize) const
 {
     ZoneScoped;
     if (isEmpty())
     {
-        return std::nullopt;
+        return {std::nullopt, false};
     }
 
     auto& stream = getStream();
@@ -49,26 +49,26 @@ BucketSnapshot::getEntryAtOffset(LedgerKey const& k, std::streamoff pos,
     {
         if (stream.readOne(be))
         {
-            return std::make_optional(be);
+            return {std::make_optional(be), false};
         }
     }
     else if (stream.readPage(be, k, pageSize))
     {
-        return std::make_optional(be);
+        return {std::make_optional(be), false};
     }
 
     // Mark entry miss for metrics
     mBucket->getIndex().markBloomMiss();
-    return std::nullopt;
+    return {std::nullopt, true};
 }
 
-std::optional<BucketEntry>
+std::pair<std::optional<BucketEntry>, bool>
 BucketSnapshot::getBucketEntry(LedgerKey const& k) const
 {
     ZoneScoped;
     if (isEmpty())
     {
-        return std::nullopt;
+        return {std::nullopt, false};
     }
 
     auto pos = mBucket->getIndex().lookup(k);
@@ -78,7 +78,7 @@ BucketSnapshot::getBucketEntry(LedgerKey const& k) const
                                 mBucket->getIndex().getPageSize());
     }
 
-    return std::nullopt;
+    return {std::nullopt, false};
 }
 
 // When searching for an entry, BucketList calls this function on every bucket.
@@ -105,8 +105,8 @@ BucketSnapshot::loadKeys(std::set<LedgerKey, LedgerEntryIdCmp>& keys,
         indexIter = newIndexIter;
         if (offOp)
         {
-            auto entryOp = getEntryAtOffset(*currKeyIt, *offOp,
-                                            mBucket->getIndex().getPageSize());
+            auto [entryOp, bloomMiss] = getEntryAtOffset(
+                *currKeyIt, *offOp, mBucket->getIndex().getPageSize());
             if (entryOp)
             {
                 if (entryOp->type() != DEADENTRY)

src/bucket/BucketSnapshot.h

@@ -33,10 +33,12 @@ class BucketSnapshot : public NonMovable
     XDRInputFileStream& getStream() const;
 
     // Loads the bucket entry for LedgerKey k. Starts at file offset pos and
-    // reads until key is found or the end of the page.
-    std::optional<BucketEntry> getEntryAtOffset(LedgerKey const& k,
-                                                std::streamoff pos,
-                                                size_t pageSize) const;
+    // reads until key is found or the end of the page. Returns <BucketEntry,
+    // bloomMiss>, where bloomMiss is true if a bloomMiss occurred during the
+    // load.
+    std::pair<std::optional<BucketEntry>, bool>
+    getEntryAtOffset(LedgerKey const& k, std::streamoff pos,
+                     size_t pageSize) const;
 
     BucketSnapshot(std::shared_ptr<Bucket const> const b);
 
@@ -48,8 +50,10 @@ class BucketSnapshot : public NonMovable
     bool isEmpty() const;
     std::shared_ptr<Bucket const> getRawBucket() const;
 
-    // Loads bucket entry for LedgerKey k.
-    std::optional<BucketEntry> getBucketEntry(LedgerKey const& k) const;
+    // Loads bucket entry for LedgerKey k. Returns <BucketEntry, bloomMiss>,
+    // where bloomMiss is true if a bloomMiss occurred during the load.
+    std::pair<std::optional<BucketEntry>, bool>
+    getBucketEntry(LedgerKey const& k) const;
 
     // Loads LedgerEntry's for given keys. When a key is found, the
     // entry is added to result and the key is removed from keys.

src/bucket/BucketSnapshotManager.cpp

@@ -13,16 +13,15 @@ namespace stellar
 {
 
 BucketSnapshotManager::BucketSnapshotManager(
-    medida::MetricsRegistry& metrics,
-    std::unique_ptr<BucketListSnapshot const>&& snapshot)
-    : mMetrics(metrics)
+    Application& app, std::unique_ptr<BucketListSnapshot const>&& snapshot)
+    : mApp(app)
     , mCurrentSnapshot(std::move(snapshot))
-    , mBulkLoadMeter(
-          mMetrics.NewMeter({"bucketlistDB", "query", "loads"}, "query"))
-    , mBloomMisses(
-          mMetrics.NewMeter({"bucketlistDB", "bloom", "misses"}, "bloom"))
-    , mBloomLookups(
-          mMetrics.NewMeter({"bucketlistDB", "bloom", "lookups"}, "bloom"))
+    , mBulkLoadMeter(app.getMetrics().NewMeter(
+          {"bucketlistDB", "query", "loads"}, "query"))
+    , mBloomMisses(app.getMetrics().NewMeter(
+          {"bucketlistDB", "bloom", "misses"}, "bloom"))
+    , mBloomLookups(app.getMetrics().NewMeter(
+          {"bucketlistDB", "bloom", "lookups"}, "bloom"))
 {
     releaseAssert(threadIsMain());
 }
@@ -51,31 +50,14 @@ BucketSnapshotManager::recordBulkLoadMetrics(std::string const& label,
     auto iter = mBulkTimers.find(label);
     if (iter == mBulkTimers.end())
     {
-        auto& metric = mMetrics.NewTimer({"bucketlistDB", "bulk", label});
+        auto& metric =
+            mApp.getMetrics().NewTimer({"bucketlistDB", "bulk", label});
         iter = mBulkTimers.emplace(label, metric).first;
     }
 
     return iter->second;
 }
 
-medida::Timer&
-BucketSnapshotManager::getPointLoadTimer(LedgerEntryType t) const
-{
-    // For now, only keep metrics for the main thread. We can decide on what
-    // metrics make sense when more background services are added later.
-    releaseAssert(threadIsMain());
-
-    auto iter = mPointTimers.find(t);
-    if (iter == mPointTimers.end())
-    {
-        auto const& label = xdr::xdr_traits<LedgerEntryType>::enum_name(t);
-        auto& metric = mMetrics.NewTimer({"bucketlistDB", "point", label});
-        iter = mPointTimers.emplace(t, metric).first;
-    }
-
-    return iter->second;
-}
-
 void
 BucketSnapshotManager::maybeUpdateSnapshot(
     std::unique_ptr<BucketListSnapshot const>& snapshot) const
@@ -102,4 +84,39 @@ BucketSnapshotManager::updateCurrentSnapshot(
                                            mCurrentSnapshot->getLedgerSeq());
     mCurrentSnapshot.swap(newSnapshot);
 }
+
+void
+BucketSnapshotManager::startPointLoadTimer() const
+{
+    releaseAssert(threadIsMain());
+    releaseAssert(!mTimerStart);
+    mTimerStart = mApp.getClock().now();
+}
+
+void
+BucketSnapshotManager::endPointLoadTimer(LedgerEntryType t,
+                                         bool bloomMiss) const
+{
+    releaseAssert(threadIsMain());
+    releaseAssert(mTimerStart);
+    auto duration = mApp.getClock().now() - *mTimerStart;
+    mTimerStart.reset();
+
+    // We expect about 0.1% of lookups to encounter a bloom miss. To avoid noise
+    // in disk performance metrics, we only track metrics for entries that did
+    // not encounter a bloom miss.
+    if (!bloomMiss)
+    {
+        auto iter = mPointTimers.find(t);
+        if (iter == mPointTimers.end())
+        {
+            auto const& label = xdr::xdr_traits<LedgerEntryType>::enum_name(t);
+            auto& metric =
+                mApp.getMetrics().NewTimer({"bucketlistDB", "point", label});
+            iter = mPointTimers.emplace(t, metric).first;
+        }
+
+        iter->second.Update(duration);
+    }
+}
 }

src/bucket/BucketSnapshotManager.h

@@ -32,7 +32,7 @@ class BucketListSnapshot;
 class BucketSnapshotManager : NonMovableOrCopyable
 {
   private:
-    medida::MetricsRegistry& mMetrics;
+    Application& mApp;
 
     // Snapshot that is maintained and periodically updated by BucketManager on
     // the main thread. When background threads need to generate or refresh a
@@ -49,6 +49,8 @@ class BucketSnapshotManager : NonMovableOrCopyable
     medida::Meter& mBloomMisses;
     medida::Meter& mBloomLookups;
 
+    mutable std::optional<VirtualClock::time_point> mTimerStart;
+
     // Called by main thread to update mCurrentSnapshot whenever the BucketList
     // is updated
     void updateCurrentSnapshot(
@@ -65,7 +67,7 @@ class BucketSnapshotManager : NonMovableOrCopyable
                                                bool restartMerges);
 
   public:
-    BucketSnapshotManager(medida::MetricsRegistry& metrics,
+    BucketSnapshotManager(Application& app,
                           std::unique_ptr<BucketListSnapshot const>&& snapshot);
 
     std::unique_ptr<SearchableBucketListSnapshot>
@@ -76,9 +78,10 @@ class BucketSnapshotManager : NonMovableOrCopyable
     void maybeUpdateSnapshot(
         std::unique_ptr<BucketListSnapshot const>& snapshot) const;
 
+    // All metric recording functions must only be called by the main thread
+    void startPointLoadTimer() const;
+    void endPointLoadTimer(LedgerEntryType t, bool bloomMiss) const;
     medida::Timer& recordBulkLoadMetrics(std::string const& label,
                                          size_t numEntries) const;
-
-    medida::Timer& getPointLoadTimer(LedgerEntryType t) const;
 };
 }