diff --git a/include/xrpl/basics/TaggedCache.h b/include/xrpl/basics/TaggedCache.h index 7bb2cb552b..416d68f20d 100644 --- a/include/xrpl/basics/TaggedCache.h +++ b/include/xrpl/basics/TaggedCache.h @@ -101,6 +101,14 @@ public: int getTrackSize() const; + /** + * Longest single hold of the cache mutex by sweep() or getKeys() since + * the previous call, then reset to zero. A per-collect peak: the metrics + * gauge reads it once per collection tick. + */ + [[nodiscard]] std::chrono::nanoseconds + takeLockHoldPeak() noexcept; + float getHitRate(); @@ -375,6 +383,18 @@ private: std::atomic& allRemovals, std::scoped_lock const&); + /** + * Record one mutex hold. Keeps the maximum since the last take and warns + * when a hold reaches one second, the same bar LoadMonitor uses for a job. + * `const` because getKeys() is `const` and lockHoldPeakNs_ is `mutable`. + */ + void + noteLockHold(std::chrono::steady_clock::time_point start, std::size_t entries, char const* op) + const noexcept; + + // Peak mutex hold in nanoseconds since the last takeLockHoldPeak(). + mutable std::atomic lockHoldPeakNs_{0}; + beast::Journal journal_; clock_type& clock_; Stats stats_; diff --git a/include/xrpl/basics/TaggedCache.ipp b/include/xrpl/basics/TaggedCache.ipp index 447743a7b7..db03b67bd2 100644 --- a/include/xrpl/basics/TaggedCache.ipp +++ b/include/xrpl/basics/TaggedCache.ipp @@ -137,6 +137,53 @@ TaggedCache +inline std::chrono::nanoseconds +TaggedCache:: + takeLockHoldPeak() noexcept +{ + return std::chrono::nanoseconds{lockHoldPeakNs_.exchange(0, std::memory_order_relaxed)}; +} + +template < + class Key, + class T, + bool IsKeyCache, + class SharedWeakUnionPointer, + class SharedPointerType, + class Hash, + class KeyEqual, + class Mutex> +inline void +TaggedCache:: + noteLockHold(std::chrono::steady_clock::time_point start, std::size_t entries, char const* op) + const noexcept +{ + using namespace std::chrono; + auto const held = steady_clock::now() - start; + auto const heldNs = duration_cast(held).count(); + // fetch_max is C++26; a CAS loop is the portable maximum. + auto seen = lockHoldPeakNs_.load(std::memory_order_relaxed); + while (seen < heldNs && + !lockHoldPeakNs_.compare_exchange_weak(seen, heldNs, std::memory_order_relaxed)) + { + } + if (held >= seconds{1}) + { + JLOG(journal_.warn()) << name_ << " TaggedCache " << op << " held the lock " + << duration_cast(held).count() << "ms over " << entries + << " entries"; + } +} + template < class Key, class T, @@ -241,8 +288,10 @@ TaggedCache(cache_.size()) <= targetSize_)) { @@ -277,6 +326,7 @@ TaggedCache( std::chrono::steady_clock::now() - start) @@ -640,8 +690,10 @@ TaggedCache= cache_.size(), "xrpl::TaggedCache::getKeys(): sufficient capacity"); + auto const copyStart = std::chrono::steady_clock::now(); for (auto const& _ : cache_) v.push_back(_.first); + noteLockHold(copyStart, v.size(), "getKeys"); } return v; diff --git a/include/xrpl/shamap/FullBelowCache.h b/include/xrpl/shamap/FullBelowCache.h index 1bb67c7453..1efa4be00a 100644 --- a/include/xrpl/shamap/FullBelowCache.h +++ b/include/xrpl/shamap/FullBelowCache.h @@ -82,6 +82,16 @@ public: cache_.sweep(); } + /** + * See TaggedCache::takeLockHoldPeak(). Longest mutex hold since the last + * call, then reset. Read once per metrics collection tick. + */ + [[nodiscard]] std::chrono::nanoseconds + takeLockHoldPeak() noexcept + { + return cache_.takeLockHoldPeak(); + } + /** * Refresh the last access time of an item, if it exists. * Thread safety: diff --git a/src/tests/libxrpl/basics/TaggedCache.cpp b/src/tests/libxrpl/basics/TaggedCache.cpp index c8ccc415ad..dc9903230e 100644 --- a/src/tests/libxrpl/basics/TaggedCache.cpp +++ b/src/tests/libxrpl/basics/TaggedCache.cpp @@ -243,4 +243,36 @@ TEST(TaggedCacheTest, tagged_cache) } } +TEST(TaggedCacheTest, lock_hold_peak_records_getkeys_and_sweep_then_resets) +{ + using namespace std::chrono_literals; + beast::Journal const journal{TestSink::instance()}; + TestStopwatch clock; + clock.set(0); + + using Cache = TaggedCache; + Cache c("peak", 0, 1s, clock, journal); + + // Nothing has held the lock yet. + EXPECT_EQ(c.takeLockHoldPeak(), 0ns); + + // Enough entries that copying every key takes a measurable time. + for (LedgerIndex i = 0; i < 200'000; ++i) + c.insert(i, "v"); + + auto const keys = c.getKeys(); + ASSERT_EQ(keys.size(), 200'000u); + auto const afterGetKeys = c.takeLockHoldPeak(); + EXPECT_GT(afterGetKeys, 0ns); + // take() is destructive: the next read starts from zero. + EXPECT_EQ(c.takeLockHoldPeak(), 0ns); + + // A sweep that expires everything also holds the lock over every entry. + ++clock; + ++clock; + c.sweep(); + EXPECT_GT(c.takeLockHoldPeak(), 0ns); + EXPECT_EQ(c.getTrackSize(), 0); +} + } // namespace xrpl