From 216d75e2e59a13bce100dc56961712ad7cf8be76 Mon Sep 17 00:00:00 2001 From: Pratik Mankawde <3397372+pratikmankawde@users.noreply.github.com> Date: Mon, 27 Jul 2026 18:37:00 +0100 Subject: [PATCH] feat(nodestore): measure the NuDB write queue NuDB serializes every insert behind one global mutex held for the whole call, so a caller cannot see how long it waited. Record instead the writer depth joined at and the wall time spent; with mean depth L and mean insert time W, Little's Law gives service time W/L and queueing W - W/L. That distinguishes a serialized write path from a saturated disk: measured on a dev box the device sat 89 percent idle while throughput stayed flat at 42k inserts per second. The accounting runs from a ScopeExit guard because the insert can allocate and therefore throw; leaking the depth would strand the gauge above zero for the life of the process. getWriteLoad also stops returning a hardcoded zero. It now reports writer depth, which is bounded by the writing-thread count and so stays far below the kMaxWriteLoadAcquire cutoff that gates history acquisition, where returning bytes or microseconds would have silently suppressed it. Co-Authored-By: Claude Opus 5 (1M context) --- include/xrpl/nodestore/Backend.h | 13 ++ include/xrpl/nodestore/Database.h | 11 ++ include/xrpl/nodestore/WriteStats.h | 81 ++++++++ .../xrpl/nodestore/detail/DatabaseNodeImp.h | 7 + .../nodestore/detail/DatabaseRotatingImp.h | 5 + src/libxrpl/nodestore/DatabaseRotatingImp.cpp | 9 + src/libxrpl/nodestore/backend/NuDBFactory.cpp | 88 ++++++++- src/tests/libxrpl/nodestore/Backend.cpp | 24 +++ src/tests/libxrpl/nodestore/NuDBFactory.cpp | 179 ++++++++++++++++++ 9 files changed, 416 insertions(+), 1 deletion(-) create mode 100644 include/xrpl/nodestore/WriteStats.h diff --git a/include/xrpl/nodestore/Backend.h b/include/xrpl/nodestore/Backend.h index 85d076bcfb..efc88b3c40 100644 --- a/include/xrpl/nodestore/Backend.h +++ b/include/xrpl/nodestore/Backend.h @@ -4,6 +4,7 @@ #include #include #include +#include #include #include @@ -53,6 +54,18 @@ public: return std::nullopt; } + /** + * Get write-path statistics for backends that support it. + * + * Returns std::nullopt for backends that do not measure their writes. + * @see WriteStats for how to derive queuing time from the result. + */ + [[nodiscard]] virtual std::optional + getWriteStats() const + { + return std::nullopt; + } + /** * Open the backend. * @param createIfMissing Create the database files if necessary. diff --git a/include/xrpl/nodestore/Database.h b/include/xrpl/nodestore/Database.h index acdedf1043..d88296e6b2 100644 --- a/include/xrpl/nodestore/Database.h +++ b/include/xrpl/nodestore/Database.h @@ -9,6 +9,7 @@ #include #include #include +#include #include #include @@ -17,6 +18,7 @@ #include #include #include +#include #include #include #include @@ -84,6 +86,15 @@ public: virtual std::int32_t getWriteLoad() const = 0; + /** + * Get backend write-path statistics, if the backend measures them. + * + * @return The statistics, or std::nullopt when the backend does not + * measure its writes. + */ + [[nodiscard]] virtual std::optional + getWriteStats() const = 0; + /** * Store the object. * diff --git a/include/xrpl/nodestore/WriteStats.h b/include/xrpl/nodestore/WriteStats.h new file mode 100644 index 0000000000..08d4529960 --- /dev/null +++ b/include/xrpl/nodestore/WriteStats.h @@ -0,0 +1,81 @@ +#pragma once + +#include + +namespace xrpl::node_store { + +/** + * A snapshot of a backend's write-path behaviour. + * + * A backend that serializes its writes behind an internal lock cannot + * report lock wait time directly, because the lock is private to it. This + * type reports what an outside caller can measure - how many writers were + * in flight and how long each write took - from which the queuing time + * follows. + * + * With mean depth L, mean insert time W and arrival rate lambda, Little's + * Law gives service time S = W / L and queuing time W - S. When S times + * lambda approaches 1.0 the backend is consuming a whole core-equivalent + * inside its critical section, which is the signature of a serialized + * write path. + * + * caller ---+ + * caller ---+--> [ backend lock ] --> disk + * caller ---+ + * | + * concurrentWriters = queue length here + * insertTotalUs / insertCount = time in the whole system (W) + * depthSum / insertCount = mean depth (L) + * + * @note All fields except @ref concurrentWriters are cumulative for the + * life of the backend, so a reader must difference successive + * samples to get a rate. @ref concurrentWriters is instantaneous. + * @note Sampled without a lock, so fields may be a few operations out of + * step with each other. They are diagnostics, not accounting. + * + * Example - mean insert time and mean depth: + * @code + * if (auto const s = backend->getWriteStats(); s && s->insertCount) + * { + * double const meanUs = double(s->insertTotalUs) / s->insertCount; + * double const meanDepth = double(s->depthSum) / s->insertCount; + * double const serviceUs = meanUs / meanDepth; // Little's Law + * } + * @endcode + * + * Example - edge case, an idle backend: + * @code + * // insertCount is 0, so every derived mean is undefined. Guard on it + * // rather than publishing a division by zero. + * @endcode + */ +struct WriteStats +{ + /** + * Writers inside the backend store call right now. + */ + std::uint64_t concurrentWriters = 0; + + /** + * Total completed inserts. + */ + std::uint64_t insertCount = 0; + + /** + * Summed wall time of all inserts, in microseconds. + */ + std::uint64_t insertTotalUs = 0; + + /** + * Longest single insert seen, in microseconds. A true maximum. + */ + std::uint64_t insertMaxUs = 0; + + /** + * Summed writer depth observed at each insert. Divided by + * @ref insertCount this gives mean depth. + */ + std::uint64_t depthSum = 0; +}; + +} // namespace xrpl::node_store diff --git a/include/xrpl/nodestore/detail/DatabaseNodeImp.h b/include/xrpl/nodestore/detail/DatabaseNodeImp.h index 33a2e27939..d2aff66467 100644 --- a/include/xrpl/nodestore/detail/DatabaseNodeImp.h +++ b/include/xrpl/nodestore/detail/DatabaseNodeImp.h @@ -13,6 +13,7 @@ #include #include #include +#include #include #include @@ -89,6 +90,12 @@ public: return backend_->getWriteLoad(); } + [[nodiscard]] std::optional + getWriteStats() const override + { + return backend_->getWriteStats(); + } + void importDatabase(Database& source) override { diff --git a/include/xrpl/nodestore/detail/DatabaseRotatingImp.h b/include/xrpl/nodestore/detail/DatabaseRotatingImp.h index 9b566195ef..22ee4f367c 100644 --- a/include/xrpl/nodestore/detail/DatabaseRotatingImp.h +++ b/include/xrpl/nodestore/detail/DatabaseRotatingImp.h @@ -8,12 +8,14 @@ #include #include #include +#include #include #include #include #include #include +#include #include namespace xrpl::node_store { @@ -51,6 +53,9 @@ public: std::int32_t getWriteLoad() const override; + [[nodiscard]] std::optional + getWriteStats() const override; + void importDatabase(Database& source) override; diff --git a/src/libxrpl/nodestore/DatabaseRotatingImp.cpp b/src/libxrpl/nodestore/DatabaseRotatingImp.cpp index f4373fa49d..3c1554faac 100644 --- a/src/libxrpl/nodestore/DatabaseRotatingImp.cpp +++ b/src/libxrpl/nodestore/DatabaseRotatingImp.cpp @@ -12,6 +12,7 @@ #include #include #include +#include #include #include @@ -20,6 +21,7 @@ #include #include #include +#include #include #include @@ -101,6 +103,13 @@ DatabaseRotatingImp::getWriteLoad() const return writableBackend_->getWriteLoad(); } +std::optional +DatabaseRotatingImp::getWriteStats() const +{ + std::scoped_lock const lock(mutex_); + return writableBackend_->getWriteStats(); +} + void DatabaseRotatingImp::importDatabase(Database& source) { diff --git a/src/libxrpl/nodestore/backend/NuDBFactory.cpp b/src/libxrpl/nodestore/backend/NuDBFactory.cpp index bbf37f3edf..4f19283c8e 100644 --- a/src/libxrpl/nodestore/backend/NuDBFactory.cpp +++ b/src/libxrpl/nodestore/backend/NuDBFactory.cpp @@ -1,6 +1,7 @@ #include #include #include +#include #include #include #include @@ -12,6 +13,7 @@ #include #include #include +#include #include #include #include @@ -64,6 +66,31 @@ public: std::atomic deletePath; Scheduler& scheduler; + /** + * Writers currently inside doInsert. Instantaneous depth. + */ + std::atomic concurrentWriters{0}; + + /** + * Completed inserts. + */ + std::atomic insertCount{0}; + + /** + * Summed insert wall time, microseconds. + */ + std::atomic insertTotalUs{0}; + + /** + * Longest single insert, microseconds. Maintained as a true maximum. + */ + std::atomic insertMaxUs{0}; + + /** + * Summed depth observed at each insert. + */ + std::atomic depthSum{0}; + NuDBBackend( size_t keyBytes, Section const& keyValues, @@ -239,7 +266,20 @@ public: nudb::error_code ec; nudb::detail::buffer bf; auto const result = nodeobjectCompress(e.getData(), e.getSize(), bf); + + // NuDB takes one global mutex for the whole insert, so the wait is + // invisible from here. Record the depth we joined at and the wall + // time we spent; the split follows from Little's Law. + auto const depth = concurrentWriters.fetch_add(1, std::memory_order_relaxed) + 1; + auto const begin = std::chrono::steady_clock::now(); + + // A scope guard rather than straight-line code, because the insert + // can allocate and so can throw. Leaking the depth would strand the + // gauge above zero for the life of the process. + ScopeExit const account([this, depth, begin] { recordInsert(depth, begin); }); + db.insert(e.getKey(), result.first, result.second, ec); + if (ec && ec != nudb::error::key_exists) Throw(ec); } @@ -314,7 +354,22 @@ public: int getWriteLoad() override { - return 0; + // Writers in flight. Bounded by the number of writing threads, so + // it stays far below LedgerMaster's kMaxWriteLoadAcquire of 8192 + // and cannot suppress history acquisition. + return static_cast(concurrentWriters.load(std::memory_order_relaxed)); + } + + [[nodiscard]] std::optional + getWriteStats() const override + { + WriteStats stats; + stats.concurrentWriters = concurrentWriters.load(std::memory_order_relaxed); + stats.insertCount = insertCount.load(std::memory_order_relaxed); + stats.insertTotalUs = insertTotalUs.load(std::memory_order_relaxed); + stats.insertMaxUs = insertMaxUs.load(std::memory_order_relaxed); + stats.depthSum = depthSum.load(std::memory_order_relaxed); + return stats; } void @@ -349,6 +404,37 @@ public: } private: + /** + * Fold one finished insert into the write-path counters. + * + * Always runs, including on the throwing path, so the depth gauge + * returns to its true value even when the insert fails. + * + * @param depth Writer depth this insert joined at, at least 1. + * @param begin When the insert started. + */ + void + recordInsert(std::uint64_t depth, std::chrono::steady_clock::time_point begin) noexcept + { + auto const elapsedUs = + static_cast(std::chrono::duration_cast( + std::chrono::steady_clock::now() - begin) + .count()); + + concurrentWriters.fetch_sub(1, std::memory_order_relaxed); + insertCount.fetch_add(1, std::memory_order_relaxed); + insertTotalUs.fetch_add(elapsedUs, std::memory_order_relaxed); + depthSum.fetch_add(depth, std::memory_order_relaxed); + + // std::atomic has no fetch_max, so raise the maximum with a CAS + // loop. Mirrors the clamp loop in OTelCollector.cpp. + auto current = insertMaxUs.load(std::memory_order_relaxed); + while (elapsedUs > current && + !insertMaxUs.compare_exchange_weak(current, elapsedUs, std::memory_order_relaxed)) + { + } + } + static std::size_t parseBlockSize(std::string const& name, Section const& keyValues, beast::Journal journal) { diff --git a/src/tests/libxrpl/nodestore/Backend.cpp b/src/tests/libxrpl/nodestore/Backend.cpp index eb78851429..a05ae2521d 100644 --- a/src/tests/libxrpl/nodestore/Backend.cpp +++ b/src/tests/libxrpl/nodestore/Backend.cpp @@ -173,6 +173,30 @@ TEST_P(BackendTypeTest, concurrent_store_and_fetch) } } +// Write-path statistics are optional per backend. Only NuDB measures them; +// every other backend inherits the base-class default. Reporting absence +// rather than zeros is what lets a reader tell "not measured" apart from +// "measured, and idle". +TEST_P(BackendTypeTest, write_stats_reported_only_when_measured) +{ + auto backend = makeOpenBackend(); + auto const stats = backend->getWriteStats(); + + if (GetParam() == "nudb") + { + ASSERT_TRUE(stats.has_value()); + // Freshly opened and not yet written to. + EXPECT_EQ(stats->insertCount, 0u); + EXPECT_EQ(stats->concurrentWriters, 0u); + } + else + { + EXPECT_FALSE(stats.has_value()); + } + + backend->close(); +} + INSTANTIATE_TEST_SUITE_P( BackendTypes, BackendTypeTest, diff --git a/src/tests/libxrpl/nodestore/NuDBFactory.cpp b/src/tests/libxrpl/nodestore/NuDBFactory.cpp index c126984630..e88356ed11 100644 --- a/src/tests/libxrpl/nodestore/NuDBFactory.cpp +++ b/src/tests/libxrpl/nodestore/NuDBFactory.cpp @@ -12,9 +12,11 @@ #include #include +#include #include #include #include +#include #include #include @@ -259,6 +261,183 @@ TEST(NuDBFactory, configuration_parsing) } } +// Write-path measurement. NuDB holds one global mutex for the whole insert, +// so these counters plus Little's Law are the only way to separate queuing +// from service time from outside the library. + +TEST(NuDBFactory, write_stats_accumulate_per_insert) +{ + beast::TempDir const tempDir; + auto const params = makeSection(tempDir.path()); + DummyScheduler scheduler; + beast::Journal const journal(TestSink::instance()); + + auto backend = Manager::instance().makeBackend(params, megabytes(4), scheduler, journal); + ASSERT_TRUE(backend); + backend->open(); + + // Before any write the stats exist but are all zero, and no writer is + // in flight. + auto const initial = backend->getWriteStats(); + ASSERT_TRUE(initial.has_value()); + EXPECT_EQ(initial->insertCount, 0u); + EXPECT_EQ(initial->insertTotalUs, 0u); + EXPECT_EQ(initial->insertMaxUs, 0u); + EXPECT_EQ(initial->depthSum, 0u); + EXPECT_EQ(initial->concurrentWriters, 0u); + + // Exactly 10 inserts must be counted as 10, and depthSum must be 10 + // because a single-threaded caller is always the only writer, so the + // depth recorded at each insert is exactly 1. + constexpr std::uint64_t kFirstBatch = 10; + auto const batch = createPredictableBatch(kFirstBatch, 12345); + storeBatch(*backend, batch); + + auto const after = backend->getWriteStats(); + ASSERT_TRUE(after.has_value()); + EXPECT_EQ(after->insertCount, kFirstBatch); + EXPECT_EQ(after->depthSum, kFirstBatch); + EXPECT_GT(after->insertTotalUs, 0u); + EXPECT_GT(after->insertMaxUs, 0u); + // The largest single insert cannot exceed the sum of all of them. + EXPECT_LE(after->insertMaxUs, after->insertTotalUs); + // A maximum is never below the mean. This fails if the field were + // holding the minimum, or the first or last sample, instead of the + // running maximum. + EXPECT_GE(after->insertMaxUs * after->insertCount, after->insertTotalUs); + // No writer remains in flight once the calls have returned. + EXPECT_EQ(after->concurrentWriters, 0u); + + // The counters are cumulative across calls, not per call: a second, + // differently sized batch must add exactly its own size to both + // totals. This is what the mean-depth denominator relies on. + constexpr std::uint64_t kSecondBatch = 7; + auto const more = createPredictableBatch(kSecondBatch, 999); + storeBatch(*backend, more); + + auto const cumulative = backend->getWriteStats(); + ASSERT_TRUE(cumulative.has_value()); + EXPECT_EQ(cumulative->insertCount, kFirstBatch + kSecondBatch); + EXPECT_EQ(cumulative->depthSum, kFirstBatch + kSecondBatch); + EXPECT_EQ(cumulative->concurrentWriters, 0u); + // A running maximum never decreases. + EXPECT_GE(cumulative->insertMaxUs, after->insertMaxUs); + // Nor does a running total. + EXPECT_GE(cumulative->insertTotalUs, after->insertTotalUs); + + backend->close(); +} + +// Negative path: NuDB reports key_exists for a duplicate key and doInsert +// deliberately does not treat that as an error. The accounting must still +// run, and in particular the depth must come back down. +TEST(NuDBFactory, write_stats_count_duplicate_key_inserts) +{ + beast::TempDir const tempDir; + auto const params = makeSection(tempDir.path()); + DummyScheduler scheduler; + beast::Journal const journal(TestSink::instance()); + + auto backend = Manager::instance().makeBackend(params, megabytes(4), scheduler, journal); + ASSERT_TRUE(backend); + backend->open(); + + constexpr std::uint64_t kBatchSize = 8; + auto const batch = createPredictableBatch(kBatchSize, 4242); + storeBatch(*backend, batch); + + auto const first = backend->getWriteStats(); + ASSERT_TRUE(first.has_value()); + ASSERT_EQ(first->insertCount, kBatchSize); + + // Re-storing the identical batch writes nothing new, but each call is + // still an insert attempt that entered and left the backend. + storeBatch(*backend, batch); + + auto const second = backend->getWriteStats(); + ASSERT_TRUE(second.has_value()); + EXPECT_EQ(second->insertCount, kBatchSize * 2); + EXPECT_EQ(second->depthSum, kBatchSize * 2); + // The depth returned to zero, so the early-return error path did not + // leak a writer. + EXPECT_EQ(second->concurrentWriters, 0u); + + backend->close(); +} + +TEST(NuDBFactory, write_stats_observe_concurrent_writers) +{ + beast::TempDir const tempDir; + auto const params = makeSection(tempDir.path()); + DummyScheduler scheduler; + beast::Journal const journal(TestSink::instance()); + + auto backend = Manager::instance().makeBackend(params, megabytes(4), scheduler, journal); + ASSERT_TRUE(backend); + backend->open(); + + // Four threads insert distinct objects concurrently. The exact peak + // depth is racy, but two invariants are not: every insert is counted, + // and depthSum is at least insertCount because depth is >= 1 per + // insert. + constexpr std::uint64_t kThreads = 4; + constexpr std::uint64_t kPerThread = 50; + + std::vector threads; + threads.reserve(kThreads); + for (auto t = 0uz; t < kThreads; ++t) + { + threads.emplace_back([&backend, t] { + auto const batch = createPredictableBatch(kPerThread, 1000 + t); + for (auto const& obj : batch) + backend->store(obj); + }); + } + for (auto& th : threads) + th.join(); + + auto const stats = backend->getWriteStats(); + ASSERT_TRUE(stats.has_value()); + EXPECT_EQ(stats->insertCount, kThreads * kPerThread); + EXPECT_GE(stats->depthSum, stats->insertCount); + EXPECT_EQ(stats->concurrentWriters, 0u); + EXPECT_GT(stats->insertMaxUs, 0u); + // Depth cannot exceed the number of threads that could be inside the + // insert at once, so the mean depth is bounded by kThreads. + EXPECT_LE(stats->depthSum, stats->insertCount * kThreads); + + backend->close(); +} + +TEST(NuDBFactory, write_load_reports_writer_depth) +{ + beast::TempDir const tempDir; + auto const params = makeSection(tempDir.path()); + DummyScheduler scheduler; + beast::Journal const journal(TestSink::instance()); + + auto backend = Manager::instance().makeBackend(params, megabytes(4), scheduler, journal); + ASSERT_TRUE(backend); + backend->open(); + + // Idle: no writer in flight, so the load is exactly 0. + EXPECT_EQ(backend->getWriteLoad(), 0); + + // After writes complete the depth returns to 0 rather than staying + // elevated, because this is an instantaneous gauge and not a counter. + auto const batch = createPredictableBatch(5, 777); + storeBatch(*backend, batch); + EXPECT_EQ(backend->getWriteLoad(), 0); + + // The value must stay far below the history-acquisition cutoff that + // LedgerMaster applies (kMaxWriteLoadAcquire), or history acquisition + // would silently stop. Depth is bounded by the writing threads. + constexpr int kMaxWriteLoadAcquire = 8192; + EXPECT_LT(backend->getWriteLoad(), kMaxWriteLoadAcquire); + + backend->close(); +} + TEST(NuDBFactory, data_persistence) { std::vector const kBlockSizes = {"4096", "8192", "16384", "32768"};