feat: Metrics for requested ledger age (#2947)

Adding metrics to be able to analyse requested ledger age distribution.

---------

Co-authored-by: Claude Sonnet 4.5 <noreply@anthropic.com>
This commit is contained in:
Sergey Kuznetsov
2026-02-20 18:01:15 +00:00
committed by GitHub
parent 6ba58f42f0
commit 2d6f82c27f
9 changed files with 224 additions and 14 deletions

2
.gitignore vendored
View File

@@ -10,3 +10,5 @@
.sanitizer-report
CMakeUserPresets.json
config.json
CLAUDE.md
.claude/**

View File

@@ -21,18 +21,24 @@
#include "rpc/JS.hpp"
#include "rpc/WorkQueue.hpp"
#include "util/JsonUtils.hpp"
#include "util/prometheus/Label.hpp"
#include "util/prometheus/Prometheus.hpp"
#include <boost/json/object.hpp>
#include <boost/json/value.hpp>
#include <boost/json/value_to.hpp>
#include <fmt/format.h>
#include <xrpl/protocol/jss.h>
#include <chrono>
#include <cstdint>
#include <functional>
#include <mutex>
#include <optional>
#include <string>
#include <utility>
#include <vector>
namespace rpc {
@@ -138,6 +144,21 @@ Counters::Counters(Reportable const& wq)
"Total number of internal errors"
)
)
, ledgerAgeLedgersHistogram_(
PrometheusService::histogramInt(
"rpc_requested_ledger_age_histogram",
Labels{},
{0, 10, 100, 1'000, 10'000, 100'000, 1'000'000, 10'000'000, 100'000'000},
"Age of requested ledgers in ledger count"
)
)
, ledgerHashRequestsCounter_(
PrometheusService::counterInt(
"rpc_ledger_hash_requests_total_number",
Labels{},
"Total number of successful requests containing ledger_hash field"
)
)
, workQueue_(std::cref(wq))
, startupTime_{std::chrono::system_clock::now()}
{
@@ -217,6 +238,35 @@ Counters::onInternalError()
++internalErrorCounter_.get();
}
void
Counters::recordLedgerRequest(
boost::json::object const& params,
std::uint32_t currentLedgerSequence
)
{
if (params.contains(JS(ledger_hash))) {
++ledgerHashRequestsCounter_.get();
return;
}
if (not params.contains(JS(ledger_index))) {
ledgerAgeLedgersHistogram_.get().observe(0);
return;
}
auto const& indexValue = params.at("ledger_index");
if (auto const parsed = util::getLedgerIndex(indexValue); parsed.has_value()) {
if (*parsed <= currentLedgerSequence) {
auto const ageLedgers = static_cast<std::int64_t>(currentLedgerSequence - *parsed);
ledgerAgeLedgersHistogram_.get().observe(ageLedgers);
}
} else if (indexValue.is_string()) {
auto const indexStr = boost::json::value_to<std::string>(indexValue);
if (indexStr == "validated") {
ledgerAgeLedgersHistogram_.get().observe(0);
}
}
}
std::chrono::seconds
Counters::uptime() const
{

View File

@@ -21,11 +21,13 @@
#include "rpc/WorkQueue.hpp"
#include "util/prometheus/Counter.hpp"
#include "util/prometheus/Histogram.hpp"
#include <boost/json.hpp>
#include <boost/json/object.hpp>
#include <chrono>
#include <cstdint>
#include <functional>
#include <mutex>
#include <string>
@@ -66,6 +68,9 @@ class Counters {
CounterType unknownCommandCounter_;
CounterType internalErrorCounter_;
std::reference_wrapper<util::prometheus::HistogramInt> ledgerAgeLedgersHistogram_;
CounterType ledgerHashRequestsCounter_;
std::reference_wrapper<Reportable const> workQueue_;
std::chrono::time_point<std::chrono::system_clock> startupTime_;
@@ -150,6 +155,15 @@ public:
void
onInternalError();
/**
* @brief Records ledger request metrics based on the ledger parameter in the request.
*
* @param params The request parameters containing ledger information
* @param currentLedgerSequence The current ledger sequence number
*/
void
recordLedgerRequest(boost::json::object const& params, std::uint32_t currentLedgerSequence);
/** @return Uptime of this instance in seconds. */
std::chrono::seconds
uptime() const;

View File

@@ -27,7 +27,6 @@
#include "rpc/common/HandlerProvider.hpp"
#include "rpc/common/Types.hpp"
#include "rpc/common/impl/ForwardingProxy.hpp"
#include "util/OverloadSet.hpp"
#include "util/ResponseExpirationCache.hpp"
#include "util/log/Logger.hpp"
#include "web/Context.hpp"
@@ -41,6 +40,7 @@
#include <xrpl/protocol/ErrorCodes.h>
#include <chrono>
#include <cstdint>
#include <exception>
#include <functional>
#include <memory>
@@ -228,16 +228,37 @@ public:
}
/**
* @brief Notify the system that specified method was executed.
* @brief Notify the system that specified method was executed and record ledger metrics.
*
* @param method
* @param context The web context containing method, params, and ledger information
* @param duration The time it took to execute the method specified in microseconds
* @param isForwarded Whether the request was forwarded to rippled or not
*/
void
notifyComplete(std::string const& method, std::chrono::microseconds const& duration)
notifyComplete(
web::Context const& context,
std::chrono::microseconds const& duration,
bool isForwarded
)
{
if (validHandler(method))
counters_.get().rpcComplete(method, duration);
if (validHandler(context.method)) {
counters_.get().rpcComplete(context.method, duration);
if (not isForwarded) {
counters_.get().recordLedgerRequest(context.params, context.range.maxSequence);
}
}
}
/**
* @brief Record ledger request metrics.
*
* @param params The request parameters containing ledger information
* @param currentLedgerSequence The current ledger sequence
*/
void
recordLedgerMetrics(boost::json::object const& params, std::uint32_t currentLedgerSequence)
{
counters_.get().recordLedgerRequest(params, currentLedgerSequence);
}
/**

View File

@@ -229,14 +229,14 @@ private:
LOG(perfLog_.debug()) << context->tag() << "Encountered error: " << responseStr;
LOG(log_.debug()) << context->tag() << "Encountered error: " << responseStr;
} else {
// This can still technically be an error. Clio counts forwarded requests as
// successful.
rpcEngine_->notifyComplete(context->method, us);
auto& json = result.response.value();
auto const isForwarded = json.contains("forwarded") &&
json.at("forwarded").is_bool() && json.at("forwarded").as_bool();
// This can still technically be an error. Clio counts forwarded requests
// as successful.
rpcEngine_->notifyComplete(*context, us, isForwarded);
if (isForwarded)
json.erase("forwarded");

View File

@@ -287,14 +287,14 @@ private:
LOG(perfLog_.debug()) << context->tag() << "Encountered error: " << responseStr;
LOG(log_.debug()) << context->tag() << "Encountered error: " << responseStr;
} else {
// This can still technically be an error. Clio counts forwarded requests as
// successful.
rpcEngine_->notifyComplete(context->method, us);
auto& json = result.response.value();
auto const isForwarded = json.contains("forwarded") &&
json.at("forwarded").is_bool() && json.at("forwarded").as_bool();
// This can still technically be an error. Clio counts forwarded requests
// as successful.
rpcEngine_->notifyComplete(*context, us, isForwarded);
if (isForwarded)
json.erase("forwarded");

View File

@@ -25,9 +25,11 @@
#include <boost/asio.hpp>
#include <boost/asio/io_context.hpp>
#include <boost/asio/spawn.hpp>
#include <boost/json/object.hpp>
#include <gtest/gtest.h>
#include <chrono>
#include <cstdint>
#include <functional>
#include <string>
@@ -49,6 +51,17 @@ struct MockAsyncRPCEngine {
}
MOCK_METHOD(void, notifyComplete, (std::string const&, std::chrono::microseconds const&), ());
void
notifyComplete(
web::Context const& ctx,
std::chrono::microseconds const& duration,
bool isForwarded
)
{
notifyComplete(ctx.method, duration);
if (not isForwarded)
recordLedgerMetrics(ctx.params, ctx.range.maxSequence);
}
MOCK_METHOD(void, notifyFailed, (std::string const&), ());
MOCK_METHOD(void, notifyErrored, (std::string const&), ());
MOCK_METHOD(void, notifyForwarded, (std::string const&), ());
@@ -58,6 +71,7 @@ struct MockAsyncRPCEngine {
MOCK_METHOD(void, notifyTooBusy, (), ());
MOCK_METHOD(void, notifyUnknownCommand, (), ());
MOCK_METHOD(void, notifyInternalError, (), ());
MOCK_METHOD(void, recordLedgerMetrics, (boost::json::object const&, std::uint32_t), ());
MOCK_METHOD(rpc::Result, buildResponse, (web::Context const&), ());
};
@@ -69,6 +83,17 @@ struct MockRPCEngine {
()
);
MOCK_METHOD(void, notifyComplete, (std::string const&, std::chrono::microseconds const&), ());
void
notifyComplete(
web::Context const& ctx,
std::chrono::microseconds const& duration,
bool isForwarded
)
{
notifyComplete(ctx.method, duration);
if (not isForwarded)
recordLedgerMetrics(ctx.params, ctx.range.maxSequence);
}
MOCK_METHOD(void, notifyErrored, (std::string const&), ());
MOCK_METHOD(void, notifyForwarded, (std::string const&), ());
MOCK_METHOD(void, notifyFailedToForward, (std::string const&), ());
@@ -77,5 +102,6 @@ struct MockRPCEngine {
MOCK_METHOD(void, notifyTooBusy, (), ());
MOCK_METHOD(void, notifyUnknownCommand, (), ());
MOCK_METHOD(void, notifyInternalError, (), ());
MOCK_METHOD(void, recordLedgerMetrics, (boost::json::object const&, std::uint32_t), ());
MOCK_METHOD(rpc::Result, buildResponse, (web::Context const&), ());
};

View File

@@ -22,6 +22,7 @@
#include "rpc/WorkQueue.hpp"
#include "util/MockPrometheus.hpp"
#include "util/prometheus/Counter.hpp"
#include "util/prometheus/Histogram.hpp"
#include <boost/json/object.hpp>
#include <boost/json/value_to.hpp>
@@ -30,6 +31,7 @@
#include <xrpl/protocol/jss.h>
#include <chrono>
#include <cstdint>
#include <string>
using namespace rpc;
@@ -272,3 +274,93 @@ TEST_F(RPCCountersMockPrometheusTests, onInternalError)
EXPECT_CALL(internalErrorMock, add(1));
counters.onInternalError();
}
struct RPCCountersMockPrometheusRecotdLedgerRequestTest : RPCCountersMockPrometheusTests {
testing::StrictMock<util::prometheus::MockHistogramImpl<int64_t>>& ageLedgersHistogramMock =
makeMock<util::prometheus::HistogramInt>("rpc_requested_ledger_age_histogram", "");
};
TEST_F(RPCCountersMockPrometheusRecotdLedgerRequestTest, currentLedger)
{
// "current" is not tracked in the histogram (it's not a historical ledger lookup)
// No mock expectations needed
boost::json::object params;
params["ledger_index"] = "current";
counters.recordLedgerRequest(params, 1000);
}
TEST_F(RPCCountersMockPrometheusRecotdLedgerRequestTest, validateLedger)
{
EXPECT_CALL(ageLedgersHistogramMock, observe(0));
boost::json::object params;
params["ledger_index"] = "validated";
counters.recordLedgerRequest(params, 1000);
}
TEST_F(RPCCountersMockPrometheusRecotdLedgerRequestTest, validatedDefaultLedger)
{
EXPECT_CALL(ageLedgersHistogramMock, observe(0));
boost::json::object params;
counters.recordLedgerRequest(params, 1000);
}
TEST_F(RPCCountersMockPrometheusRecotdLedgerRequestTest, specificLedger)
{
auto& ageLedgersHistogramMock =
makeMock<util::prometheus::HistogramInt>("rpc_requested_ledger_age_histogram", "");
EXPECT_CALL(ageLedgersHistogramMock, observe(100)); // age is 1000 - 900 = 100
boost::json::object params;
params["ledger_index"] = 900;
counters.recordLedgerRequest(params, 1000);
}
TEST_F(RPCCountersMockPrometheusRecotdLedgerRequestTest, stringNumberLedger)
{
EXPECT_CALL(ageLedgersHistogramMock, observe(50)); // 1000 - 950 = 50 ledgers
boost::json::object params;
params["ledger_index"] = "950";
counters.recordLedgerRequest(params, 1000);
}
TEST_F(RPCCountersMockPrometheusRecotdLedgerRequestTest, zeroAgeLedger)
{
auto& ageLedgersHistogramMock =
makeMock<util::prometheus::HistogramInt>("rpc_requested_ledger_age_histogram", "");
EXPECT_CALL(ageLedgersHistogramMock, observe(0)); // 1000 - 1000 = 0 ledgers
boost::json::object params;
params["ledger_index"] = 1000; // Same as current
counters.recordLedgerRequest(params, 1000);
}
TEST_F(RPCCountersMockPrometheusRecotdLedgerRequestTest, ledgerHashRequest)
{
auto& ledgerHashCounterMock = makeMock<CounterInt>("rpc_ledger_hash_requests_total_number", "");
EXPECT_CALL(ledgerHashCounterMock, add(1));
boost::json::object params;
params["ledger_hash"] = "ABCDEF0123456789ABCDEF0123456789ABCDEF0123456789ABCDEF0123456789";
counters.recordLedgerRequest(params, 1000);
}
TEST_F(RPCCountersMockPrometheusRecotdLedgerRequestTest, ledgerHashWithIndexIgnoresIndex)
{
auto& ledgerHashCounterMock = makeMock<CounterInt>("rpc_ledger_hash_requests_total_number", "");
// When both ledger_hash and ledger_index are present, only ledger_hash counter should be
// incremented
EXPECT_CALL(ledgerHashCounterMock, add(1));
// No histogram call should be made
boost::json::object params;
params["ledger_hash"] = "ABCDEF0123456789ABCDEF0123456789ABCDEF0123456789ABCDEF0123456789";
params["ledger_index"] = 900; // This should be ignored
counters.recordLedgerRequest(params, 1000);
}

View File

@@ -414,6 +414,7 @@ TEST_F(NgRpcServerHandlerTest, HandleRequest_Successful_HttpRequest)
EXPECT_CALL(dosguard_, request(ip_, boost::json::parse(requestStr).as_object()))
.WillOnce(Return(true));
EXPECT_CALL(dosguard_, add(ip_, testing::_)).WillOnce(Return(true));
EXPECT_CALL(*rpcEngine_, recordLedgerMetrics);
EXPECT_CALL(*rpcEngine_, post).WillOnce([&](auto&& fn, auto&&) {
EXPECT_CALL(connectionMetadata_, wasUpgraded)
.WillRepeatedly(Return(not request.isHttp()));
@@ -454,6 +455,7 @@ TEST_F(NgRpcServerHandlerTest, HandleRequest_OutdatedWarning)
EXPECT_CALL(dosguard_, request(ip_, boost::json::parse(requestStr).as_object()))
.WillOnce(Return(true));
EXPECT_CALL(dosguard_, add(ip_, testing::_)).WillOnce(Return(true));
EXPECT_CALL(*rpcEngine_, recordLedgerMetrics);
EXPECT_CALL(*rpcEngine_, post).WillOnce([&](auto&& fn, auto&&) {
EXPECT_CALL(connectionMetadata_, wasUpgraded)
.WillRepeatedly(Return(not request.isHttp()));
@@ -541,6 +543,7 @@ TEST_F(NgRpcServerHandlerTest, HandleRequest_Successful_HttpRequest_HasError)
EXPECT_CALL(dosguard_, request(ip_, boost::json::parse(requestStr).as_object()))
.WillOnce(Return(true));
EXPECT_CALL(dosguard_, add(ip_, testing::_)).WillOnce(Return(true));
EXPECT_CALL(*rpcEngine_, recordLedgerMetrics);
EXPECT_CALL(*rpcEngine_, post).WillOnce([&](auto&& fn, auto&&) {
EXPECT_CALL(connectionMetadata_, wasUpgraded)
.WillRepeatedly(Return(not request.isHttp()));
@@ -606,6 +609,7 @@ TEST_F(NgRpcServerHandlerWsTest, HandleRequest_Successful_WsRequest)
EXPECT_CALL(dosguard_, request(ip_, boost::json::parse(requestStr).as_object()))
.WillOnce(Return(true));
EXPECT_CALL(dosguard_, add(ip_, testing::_)).WillOnce(Return(true));
EXPECT_CALL(*rpcEngine_, recordLedgerMetrics);
EXPECT_CALL(*rpcEngine_, post).WillOnce([&](auto&& fn, auto&&) {
EXPECT_CALL(connectionMetadata_, wasUpgraded)
.WillRepeatedly(Return(not request.isHttp()));
@@ -650,6 +654,7 @@ TEST_F(NgRpcServerHandlerWsTest, HandleRequest_Successful_WsRequest_HasError)
EXPECT_CALL(dosguard_, request(ip_, boost::json::parse(requestStr).as_object()))
.WillOnce(Return(true));
EXPECT_CALL(dosguard_, add(ip_, testing::_)).WillOnce(Return(true));
EXPECT_CALL(*rpcEngine_, recordLedgerMetrics);
EXPECT_CALL(*rpcEngine_, post).WillOnce([&](auto&& fn, auto&&) {
EXPECT_CALL(connectionMetadata_, wasUpgraded)
.WillRepeatedly(Return(not request.isHttp()));