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) <noreply@anthropic.com>
This commit is contained in:
Pratik Mankawde
2026-07-27 18:37:00 +01:00
parent 35363c54f7
commit 216d75e2e5
9 changed files with 416 additions and 1 deletions

View File

@@ -4,6 +4,7 @@
#include <xrpl/basics/contract.h>
#include <xrpl/nodestore/NodeObject.h>
#include <xrpl/nodestore/Types.h>
#include <xrpl/nodestore/WriteStats.h>
#include <cstddef>
#include <cstdint>
@@ -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<WriteStats>
getWriteStats() const
{
return std::nullopt;
}
/**
* Open the backend.
* @param createIfMissing Create the database files if necessary.

View File

@@ -9,6 +9,7 @@
#include <xrpl/nodestore/Backend.h>
#include <xrpl/nodestore/NodeObject.h>
#include <xrpl/nodestore/Scheduler.h>
#include <xrpl/nodestore/WriteStats.h>
#include <atomic>
#include <condition_variable>
@@ -17,6 +18,7 @@
#include <map>
#include <memory>
#include <mutex>
#include <optional>
#include <string>
#include <utility>
#include <vector>
@@ -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<WriteStats>
getWriteStats() const = 0;
/**
* Store the object.
*

View File

@@ -0,0 +1,81 @@
#pragma once
#include <cstdint>
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

View File

@@ -13,6 +13,7 @@
#include <xrpl/nodestore/Database.h>
#include <xrpl/nodestore/NodeObject.h>
#include <xrpl/nodestore/Scheduler.h>
#include <xrpl/nodestore/WriteStats.h>
#include <chrono>
#include <cstdint>
@@ -89,6 +90,12 @@ public:
return backend_->getWriteLoad();
}
[[nodiscard]] std::optional<WriteStats>
getWriteStats() const override
{
return backend_->getWriteStats();
}
void
importDatabase(Database& source) override
{

View File

@@ -8,12 +8,14 @@
#include <xrpl/nodestore/DatabaseRotating.h>
#include <xrpl/nodestore/NodeObject.h>
#include <xrpl/nodestore/Scheduler.h>
#include <xrpl/nodestore/WriteStats.h>
#include <atomic>
#include <cstdint>
#include <functional>
#include <memory>
#include <mutex>
#include <optional>
#include <string>
namespace xrpl::node_store {
@@ -51,6 +53,9 @@ public:
std::int32_t
getWriteLoad() const override;
[[nodiscard]] std::optional<WriteStats>
getWriteStats() const override;
void
importDatabase(Database& source) override;

View File

@@ -12,6 +12,7 @@
#include <xrpl/nodestore/NodeObject.h>
#include <xrpl/nodestore/Scheduler.h>
#include <xrpl/nodestore/Types.h>
#include <xrpl/nodestore/WriteStats.h>
#include <atomic>
#include <chrono>
@@ -20,6 +21,7 @@
#include <functional>
#include <memory>
#include <mutex>
#include <optional>
#include <string>
#include <utility>
@@ -101,6 +103,13 @@ DatabaseRotatingImp::getWriteLoad() const
return writableBackend_->getWriteLoad();
}
std::optional<WriteStats>
DatabaseRotatingImp::getWriteStats() const
{
std::scoped_lock const lock(mutex_);
return writableBackend_->getWriteStats();
}
void
DatabaseRotatingImp::importDatabase(Database& source)
{

View File

@@ -1,6 +1,7 @@
#include <xrpl/basics/Log.h>
#include <xrpl/basics/base_uint.h>
#include <xrpl/basics/contract.h>
#include <xrpl/basics/scope.h>
#include <xrpl/beast/core/LexicalCast.h>
#include <xrpl/beast/utility/Journal.h>
#include <xrpl/beast/utility/instrumentation.h>
@@ -12,6 +13,7 @@
#include <xrpl/nodestore/NodeObject.h>
#include <xrpl/nodestore/Scheduler.h>
#include <xrpl/nodestore/Types.h>
#include <xrpl/nodestore/WriteStats.h>
#include <xrpl/nodestore/detail/DecodedBlob.h>
#include <xrpl/nodestore/detail/EncodedBlob.h>
#include <xrpl/nodestore/detail/codec.h>
@@ -64,6 +66,31 @@ public:
std::atomic<bool> deletePath;
Scheduler& scheduler;
/**
* Writers currently inside doInsert. Instantaneous depth.
*/
std::atomic<std::uint64_t> concurrentWriters{0};
/**
* Completed inserts.
*/
std::atomic<std::uint64_t> insertCount{0};
/**
* Summed insert wall time, microseconds.
*/
std::atomic<std::uint64_t> insertTotalUs{0};
/**
* Longest single insert, microseconds. Maintained as a true maximum.
*/
std::atomic<std::uint64_t> insertMaxUs{0};
/**
* Summed depth observed at each insert.
*/
std::atomic<std::uint64_t> 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<nudb::system_error>(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<int>(concurrentWriters.load(std::memory_order_relaxed));
}
[[nodiscard]] std::optional<WriteStats>
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::uint64_t>(std::chrono::duration_cast<std::chrono::microseconds>(
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)
{

View File

@@ -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,

View File

@@ -12,9 +12,11 @@
#include <array>
#include <cstddef>
#include <cstdint>
#include <exception>
#include <memory>
#include <string>
#include <thread>
#include <utility>
#include <vector>
@@ -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<std::thread> 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<std::string> const kBlockSizes = {"4096", "8192", "16384", "32768"};