fix(telemetry): Count getobject lookups that reach the NodeStore

Misses were counted as requested - found, so entries the fetch loop
skips as malformed, and anything past the cap, counted as misses. Count
the entries that reach the NodeStore and record misses as
attempted - found. The charge still uses the requested count.

Each metric that was declared at several call sites is now declared
once: getobject_lookups_total in one loop over hit and miss, and
getobject_rejected_total and rpc_in_flight_requests through a small
helper. Two Beast tests pin the counts.
This commit is contained in:
Pratik Mankawde committed 2026-09-30 20:36:05 +01:00
1 parent f5e76b01a9
commit 7934506ca1
7 files changed
+303 -84

No files matched your search

@@ -809,7 +809,7 @@
},
{
"title": "GetObject Lookups by Result",
"description": "###### What this is:\n*NodeStore lookups performed by the handler, split into hits and misses. A miss does a node-store seek while a hit is usually served from cache, so the hit/miss mix is the reason NodeStore Lookup time moves.*\n\n###### How it's computed:\n*Per-second rate of getobject_lookups_total, grouped by the result label. The counter is advanced once per request with the batch totals -- hits are the objects returned, misses are the rest of the request -- not once per object, so the rate is objects per second rather than requests per second.*\n\n###### Reading it:\n*Use this to explain the NodeStore Lookup line on the breakdown panel. A miss-heavy mix makes that line rise for a real reason: seeks, not a regression. A hit-heavy mix with rising lookup time points at the storage layer instead.*\n\n###### Healthy range:\n*Hits dominating on a warm synced node; misses low and driven by genuine catch-up requests.*\n\n###### Watch for:\n*A sustained miss rate far above the hit rate: a peer is asking for hashes this node does not hold, which is either a peer far out of sync or a client requesting objects this node never stored. Cross-check GetObject Charge Distribution, since misses are billed first and at eight times the hit cost.*\n\n###### Keywords:\n- **NodeStore lookup (hit / miss)** *(per node)* \u2014 one object-store fetch by hash; a hit is usually served from cache, a miss does a disk seek.\n- **NodeStore** *(per node)* \u2014 the key-value object store holding ledger data (tree nodes), backed by NuDB.\n- **Resource charge** *(per node)* \u2014 the load cost the resource manager bills a peer per request; crossing the warning then drop threshold sheds the peer.\n\n###### Computation boundary:\n*Result: Per node \u2014 each series is one server's own value.*\n*Computed in xrpld code (MetricsRegistry, OpenTelemetry SDK) and exported as a metric; the collector only forwards it; the Grafana query selects and aggregates it.*\n\n###### Source:\n[PeerImp.cpp](https://github.com/XRPLF/rippled/blob/develop/src/xrpld/overlay/detail/PeerImp.cpp)\n\n###### Function:\n`PeerImp::recordGetObjectMetrics`\n\n###### References:\n[Telemetry glossary](https://github.com/XRPLF/rippled/blob/develop/docs/telemetry-glossary.md#nodestore-lookup-hit-miss)",
"description": "###### What this is:\n*NodeStore lookups performed by the handler, split into hits and misses. A miss does a node-store seek while a hit is usually served from cache, so the hit/miss mix is the reason NodeStore Lookup time moves.*\n\n###### How it's computed:\n*Per-second rate of getobject_lookups_total, grouped by the result label. The counter is advanced once per request with the batch totals -- hits are the objects returned, misses are the lookups that found nothing, and an entry skipped as malformed counts as neither -- not once per object, so the rate is objects per second rather than requests per second.*\n\n###### Reading it:\n*Use this to explain the NodeStore Lookup line on the breakdown panel. A miss-heavy mix makes that line rise for a real reason: seeks, not a regression. A hit-heavy mix with rising lookup time points at the storage layer instead.*\n\n###### Healthy range:\n*Hits dominating on a warm synced node; misses low and driven by genuine catch-up requests.*\n\n###### Watch for:\n*A sustained miss rate far above the hit rate: a peer is asking for hashes this node does not hold, which is either a peer far out of sync or a client requesting objects this node never stored. Cross-check GetObject Charge Distribution, since misses are billed first and at eight times the hit cost.*\n\n###### Keywords:\n- **NodeStore lookup (hit / miss)** *(per node)* \u2014 one object-store fetch by hash; a hit is usually served from cache, a miss does a disk seek.\n- **NodeStore** *(per node)* \u2014 the key-value object store holding ledger data (tree nodes), backed by NuDB.\n- **Resource charge** *(per node)* \u2014 the load cost the resource manager bills a peer per request; crossing the warning then drop threshold sheds the peer.\n\n###### Computation boundary:\n*Result: Per node \u2014 each series is one server's own value.*\n*Computed in xrpld code (MetricsRegistry, OpenTelemetry SDK) and exported as a metric; the collector only forwards it; the Grafana query selects and aggregates it.*\n\n###### Source:\n[PeerImp.cpp](https://github.com/XRPLF/rippled/blob/develop/src/xrpld/overlay/detail/PeerImp.cpp)\n\n###### Function:\n`PeerImp::recordGetObjectMetrics`\n\n###### References:\n[Telemetry glossary](https://github.com/XRPLF/rippled/blob/develop/docs/telemetry-glossary.md#nodestore-lookup-hit-miss)",
"type": "timeseries",
"gridPos": {
"h": 10,
+12 -9
View File
@@ -46,15 +46,17 @@
* @endcode
*
* Example usage -- edge case: the same instrument recorded under two
* different label values, which is why the label key and both values are
* constants rather than literals:
* different label values from one call site, so it is created once. The
* label key and both values are constants rather than literals:
* @code
* XRPL_METRIC_COUNTER_ADD_LABELED(
* app_, kGetObjectLookupsTotal, kGetObjectLookupsTotalDesc, hits,
* {{kLabelResult, std::string(kResultHit)}});
* XRPL_METRIC_COUNTER_ADD_LABELED(
* app_, kGetObjectLookupsTotal, kGetObjectLookupsTotalDesc, misses,
* {{kLabelResult, std::string(kResultMiss)}});
* std::array<std::pair<std::string_view, int>, 2> const split{
* {{kResultHit, hits}, {kResultMiss, misses}}};
* for (auto const& [result, amount] : split)
* {
* XRPL_METRIC_COUNTER_ADD_LABELED(
* app_, kGetObjectLookupsTotal, kGetObjectLookupsTotalDesc, amount,
* {{kLabelResult, std::string(result)}});
* }
* @endcode
*
* @note These are `constexpr char[]`, not `constexpr std::string_view`. The
@@ -95,7 +97,8 @@ inline constexpr char kGetObjectRequestObjects[] = "getobject_request_objects";
inline constexpr char kGetObjectLookupUs[] = "getobject_lookup_us";
/**
* NodeStore lookups performed, split by the `result` label.
* NodeStore lookups attempted, split by the `result` label. An entry skipped
* before the lookup is not counted.
*/
inline constexpr char kGetObjectLookupsTotal[] = "getobject_lookups_total";
+17 -9
View File
@@ -59,17 +59,21 @@
* in which a bare `const char*` selects the boolean alternative, so an
* unwrapped literal is recorded as `true`.
*
* Example usage -- UpDownCounter (edge case: value that can decrease):
* Example usage -- UpDownCounter (edge case: value that can decrease). The
* +1 and the -1 go through one helper, so the name has one call site:
* @code
* void ServerHandler::onRpcStart()
* void addRpcInFlight(ServiceRegistry& app, std::int64_t const delta)
* {
* XRPL_METRIC_UPDOWN_ADD(app_, "rpc_in_flight_requests",
* "RPC requests currently executing", 1);
* XRPL_METRIC_UPDOWN_ADD(app, "rpc_in_flight_requests",
* "RPC requests currently executing", delta);
* }
* void ServerHandler::onRpcFinish()
* void PerfLogImp::rpcStart(std::string_view method, std::uint64_t requestId)
* {
* XRPL_METRIC_UPDOWN_ADD(app_, "rpc_in_flight_requests",
* "RPC requests currently executing", -1);
* addRpcInFlight(app_, 1);
* }
* void PerfLogImp::rpcEnd(std::string_view method, std::uint64_t requestId, bool finish)
* {
* addRpcInFlight(app_, -1);
* }
* @endcode
*
@@ -102,6 +106,10 @@
* once stop() has torn the pipeline down; without that gate a Record on a
* stale SDK instrument would deref a dangling AggregationConfig.
*
* @note Give each metric name one call site. Every expansion creates its own
* instrument, and two whose descriptions differ become two streams under one
* name. Route every value through one helper or loop.
*
* @note Static-init safety: Meter::CreateXxx is declared noexcept in the
* OTel API (opentelemetry/metrics/meter.h), so the function-local static
* that caches the instrument cannot throw during first-call construction.
@@ -192,8 +200,8 @@
} while (false)
// UpDownCounter: like COUNTER_ADD, but the underlying instrument permits a
// negative amount (e.g. in-flight request count, +1 on start / -1 on
// finish from two different points in the same or different call sites).
// negative amount (e.g. in-flight request count: +1 on start and -1 on
// finish, both through one helper so the name has one call site).
// A plain Counter's Add() must never see a negative value per the OTel
// API contract; use this macro, not COUNTER_ADD, whenever the value can
// decrease.
+146 -4
View File
@@ -33,6 +33,7 @@
#include <xrpl.pb.h>
#include <chrono>
#include <cstddef>
#include <memory>
#include <optional>
@@ -149,6 +150,31 @@ class TMGetObjectByHash_test : public beast::unit_test::Suite
return lastChargeContext_;
}
/**
* Capture the counts the handler hands to the metric record, then
* record for real. Same seam as charge(): the override sees the exact
* struct the handler built, so the split it chose is observable.
*/
void
recordGetObjectMetrics(
GetObjectCounts const& counts,
std::chrono::microseconds const lookupElapsed,
resource::Charge const& fee) override
{
lastCounts_ = counts;
PeerImp::recordGetObjectMetrics(counts, lookupElapsed, fee);
}
/**
* The counts captured by the override above, or nullopt if the
* handler never reached the metric record.
*/
[[nodiscard]] std::optional<GetObjectCounts> const&
getLastCounts() const
{
return lastCounts_;
}
// Synchronous test access to the JobQueue-dispatched processor.
// The production path runs this on JtLedgerReq; tests need a
// synchronous entry point to inspect the reply via send().
@@ -212,6 +238,11 @@ class TMGetObjectByHash_test : public beast::unit_test::Suite
* @see getLastChargeContext(). Same threading rules as above.
*/
std::string lastChargeContext_;
/**
* @see getLastCounts(). Same threading rules as above.
*/
std::optional<GetObjectCounts> lastCounts_;
};
shared_context context_{makeSslContext("")};
@@ -631,6 +662,36 @@ class TMGetObjectByHash_test : public beast::unit_test::Suite
return request;
}
/**
* Build a request of numStored stored hashes and numUnstored unstored
* hashes, then numMalformed entries the fetch loop must skip: every even
* one has no hash field, every odd one a hash one byte short.
*
* @param env Environment whose NodeStore receives the writes.
* @param numStored Hashes written to the NodeStore, i.e. hits.
* @param numUnstored Hashes left absent, i.e. misses.
* @param numMalformed Entries skipped before any NodeStore access.
* @return The assembled request.
*/
std::shared_ptr<protocol::TMGetObjectByHash>
buildMixedRequest(Env& env, int const numStored, int const numUnstored, int const numMalformed)
{
std::set<uint256> storedHashes;
auto request = buildInterleavedRequest(env, numStored, numUnstored, storedHashes);
for (int i = 0; i < numMalformed; ++i)
{
auto* object = request->add_objects();
if (i % 2 == 1)
{
object->set_hash(std::string(uint256::size() - 1, 'x'));
}
}
// Setup assertion: the malformed entries were appended.
BEAST_EXPECT(request->objects_size() == numStored + numUnstored + numMalformed);
return request;
}
/**
* Every replied object is a distinct hash drawn from @p storedHashes.
*
@@ -662,8 +723,9 @@ class TMGetObjectByHash_test : public beast::unit_test::Suite
* A mixed request returns exactly the stored objects and nothing else.
*
* This is the split `getobject_lookups_total{result=hit|miss}` records:
* the handler derives the miss count as `requested - found`, so an
* exact reply size is exactly the hit count the metric would report.
* the handler derives the miss count as `attempted - found`, and with no
* malformed entries `attempted == requested`, so an exact reply size is
* exactly the hit count the metric would report.
*
* @param numStored Hashes written to the NodeStore before the call.
* @param numUnstored Hashes that will miss.
@@ -719,6 +781,81 @@ class TMGetObjectByHash_test : public beast::unit_test::Suite
BEAST_EXPECT(peer->peekFeeCharge().cost() == resource::kFeeTrivialPeer.cost());
}
/**
* Malformed entries are skipped before any NodeStore access, so they are
* neither hits nor misses. attempted counts only the entries that reached
* fetchNodeObject(); requested still counts the whole message.
*
* @param numStored Hashes written to the NodeStore before the call.
* @param numUnstored Hashes that will miss.
* @param numMalformed Entries with no hash or a short hash.
*/
void
testMalformedEntriesAreNotLookups(
int const numStored,
int const numUnstored,
int const numMalformed)
{
testcase(
"Malformed Entries Are Not Lookups: " + std::to_string(numStored) + "/" +
std::to_string(numUnstored) + "/" + std::to_string(numMalformed));
Env env(*this);
PeerTest::resetId();
auto peer = createPeer(env);
auto request = buildMixedRequest(env, numStored, numUnstored, numMalformed);
// Setup assertion: nothing has been recorded yet, so the counts below
// can only come from this call.
BEAST_EXPECT(!peer->getLastCounts().has_value());
peer->runProcessGetObjectByHash(request);
auto const& counts = peer->getLastCounts();
BEAST_EXPECT(counts.has_value());
if (!counts)
{
return;
}
BEAST_EXPECT(counts->requested == numStored + numUnstored + numMalformed);
BEAST_EXPECT(counts->attempted == numStored + numUnstored);
BEAST_EXPECT(counts->found == numStored);
// The miss count the metric records: only the unstored hashes.
BEAST_EXPECT(counts->attempted - counts->found == numUnstored);
}
/**
* Past the iteration cap nothing is looked up, so attempted is the cap,
* not the request size. Reachable only by direct call: onMessage()
* rejects an oversized request before dispatch.
*/
void
testAttemptedIsCappedAtHardMax()
{
testcase("Attempted Is Capped At Hard Max");
Env env(*this);
PeerTest::resetId();
auto peer = createPeer(env);
BEAST_EXPECT(!peer->getLastCounts().has_value());
int const requested = static_cast<int>(tuning::kHardMaxReplyNodes) + 3;
peer->runProcessGetObjectByHash(createUnstoredRequest(requested));
auto const& counts = peer->getLastCounts();
BEAST_EXPECT(counts.has_value());
if (!counts)
{
return;
}
BEAST_EXPECT(counts->requested == requested);
BEAST_EXPECT(counts->attempted == static_cast<int>(tuning::kHardMaxReplyNodes));
BEAST_EXPECT(counts->found == 0);
}
/**
* One pricing case: inputs, the derived expectation, and the literal.
*
@@ -1006,8 +1143,8 @@ class TMGetObjectByHash_test : public beast::unit_test::Suite
// observable behaviour of each instrumented code path, which pins
// the values the instruments are fed:
// getobject_request_objects <- the request's objects_size()
// getobject_lookups_total <- reply size (hits) and the derived
// miss count, per testHitMissSplit
// getobject_lookups_total <- the counts captured by
// PeerTest::recordGetObjectMetrics()
// getobject_charge <- the applied resource::Charge,
// captured by PeerTest::charge()
// getobject_rejected_total <- the two gates' exact fee_ values
@@ -1032,6 +1169,11 @@ class TMGetObjectByHash_test : public beast::unit_test::Suite
testHitMissSplit(0, 4);
testHitMissSplit(4, 0);
testMalformedEntriesAreNotLookups(3, 2, 4);
testMalformedEntriesAreNotLookups(0, 0, 6);
testMalformedEntriesAreNotLookups(5, 0, 0);
testAttemptedIsCappedAtHardMax();
testComputeFeeExactValues();
testChargeUsesRequestedCount();
}
+46 -44
View File
@@ -97,6 +97,7 @@
#include <xrpl.pb.h>
#include <algorithm>
#include <array>
#include <atomic>
#include <chrono>
#include <cstddef>
@@ -2822,12 +2823,7 @@ PeerImp::onMessage(std::shared_ptr<protocol::TMGetObjectByHash> const& m)
{
JLOG(pJournal_.debug()) << "GetObj: malformed ledgerhash from peer " << id_;
fee_.update(resource::kFeeMalformedRequest, "get object ledger hash");
XRPL_METRIC_COUNTER_INC_LABELED(
app_,
telemetry::kGetObjectRejectedTotal,
telemetry::kGetObjectRejectedTotalDesc,
{{telemetry::kLabelReason,
std::string(telemetry::kReasonMalformedLedgerHash)}});
recordGetObjectRejected(telemetry::kReasonMalformedLedgerHash);
return;
}
}
@@ -2840,11 +2836,7 @@ PeerImp::onMessage(std::shared_ptr<protocol::TMGetObjectByHash> const& m)
<< "GetObj: oversized request from peer " << id_ << " (" << packet.objects_size()
<< " > " << tuning::kHardMaxReplyNodes << ")";
fee_.update(resource::kFeeInvalidData, "oversized get object request");
XRPL_METRIC_COUNTER_INC_LABELED(
app_,
telemetry::kGetObjectRejectedTotal,
telemetry::kGetObjectRejectedTotalDesc,
{{telemetry::kLabelReason, std::string(telemetry::kReasonOversize)}});
recordGetObjectRejected(telemetry::kReasonOversize);
return;
}
@@ -2971,12 +2963,16 @@ PeerImp::processGetObjectByHash(std::shared_ptr<protocol::TMGetObjectByHash> con
// Stopwatch holds no state in that build.
telemetry::Stopwatch const lookupTimer;
// Entries that reach the NodeStore. A malformed entry is skipped first,
// so it is not a lookup.
int attempted = 0;
for (int i = 0; i < iterLimit; ++i)
{
auto const& obj = packet.objects(i);
if (!obj.has_hash() || !stringIsUInt256Sized(obj.hash()))
continue;
++attempted;
uint256 const hash = uint256::fromRaw(obj.hash());
// VFALCO TODO Move this someplace more sensible so we don't
// need to inject the NodeStore interfaces.
@@ -3012,31 +3008,43 @@ PeerImp::processGetObjectByHash(std::shared_ptr<protocol::TMGetObjectByHash> con
resource::Charge const fee = computeGetObjectByHashFee(requested, reply.objects_size());
charge(fee, "processed get object by hash request");
// Called unconditionally: every statement in the body is an XRPL_METRIC_*
// argument, and those macros discard their arguments when telemetry is
// compiled out. All four values here are already computed for the request
// itself, so passing them costs nothing.
recordGetObjectMetrics(requested, reply.objects_size(), lookupElapsed, fee);
// Called unconditionally: the body only feeds XRPL_METRIC_* macros, which
// discard their arguments when telemetry is compiled out, and every value
// here is already computed for the request itself.
recordGetObjectMetrics(
GetObjectCounts{
.requested = requested, .attempted = attempted, .found = reply.objects_size()},
lookupElapsed,
fee);
JLOG(pJournal_.trace()) << "GetObj: " << reply.objects_size() << " of " << requested;
send(std::make_shared<Message>(reply, protocol::mtGET_OBJECTS));
}
// Reads app_ through the metric macros when telemetry is compiled in and
// touches no member when it is not, so clang-tidy asks for it to be static.
// Making it static would give the two builds different signatures.
// These read app_ through the metric macros when telemetry is compiled in and
// touch no member when it is not, so clang-tidy asks for them to be static.
// Making them static would give the two builds different signatures.
// NOLINTBEGIN(readability-convert-member-functions-to-static)
void
PeerImp::recordGetObjectRejected(std::string_view reason)
{
XRPL_METRIC_COUNTER_INC_LABELED(
app_,
telemetry::kGetObjectRejectedTotal,
telemetry::kGetObjectRejectedTotalDesc,
{{telemetry::kLabelReason, std::string(reason)}});
}
void
PeerImp::recordGetObjectMetrics(
int const requested,
int const found,
GetObjectCounts const& counts,
std::chrono::microseconds const lookupElapsed,
resource::Charge const& fee)
{
using namespace telemetry;
XRPL_METRIC_HISTOGRAM_RECORD(
app_, kGetObjectRequestObjects, kGetObjectRequestObjectsDesc, requested);
app_, kGetObjectRequestObjects, kGetObjectRequestObjectsDesc, counts.requested);
XRPL_METRIC_HISTOGRAM_RECORD(
app_, kGetObjectLookupUs, kGetObjectLookupUsDesc, lookupElapsed.count());
@@ -3047,29 +3055,23 @@ PeerImp::recordGetObjectMetrics(
// per-object increments on a loop bounded by kHardMaxReplyNodes would be
// a measurable cost for no extra information.
//
// `found` is the reply size, which the fetch loop only grows on a
// successful lookup within `iterLimit <= requested`, so `found <=
// requested` always holds. std::max still clamps both values, so a future
// caller passing found > requested cannot make the miss count wrap
// negative -- the counter takes an unsigned amount, where a wrap would
// read as ~1.8e19 rather than as an error.
// Only entries that reached the NodeStore are lookups: misses are the
// attempts that found nothing, so a malformed entry the loop skipped counts
// as neither. std::max keeps a caller that breaks `found <= attempted` from
// wrapping the unsigned amount to ~1.8e19.
//
// Written as two calls rather than a loop over a {hit, miss} pair: the two
// amounts come from different expressions, so there is no single value to
// iterate over.
XRPL_METRIC_COUNTER_ADD_LABELED(
app_,
kGetObjectLookupsTotal,
kGetObjectLookupsTotalDesc,
static_cast<std::uint64_t>(std::max(0, found)),
{{kLabelResult, std::string(kResultHit)}});
XRPL_METRIC_COUNTER_ADD_LABELED(
app_,
kGetObjectLookupsTotal,
kGetObjectLookupsTotalDesc,
static_cast<std::uint64_t>(std::max(0, requested - found)),
{{kLabelResult, std::string(kResultMiss)}});
// One call site for both label values, so the counter is created once.
std::array<std::pair<std::string_view, int>, 2> const split{
{{kResultHit, counts.found}, {kResultMiss, counts.attempted - counts.found}}};
for (auto const& [result, amount] : split)
{
XRPL_METRIC_COUNTER_ADD_LABELED(
app_,
kGetObjectLookupsTotal,
kGetObjectLookupsTotalDesc,
static_cast<std::uint64_t>(std::max(0, amount)),
{{kLabelResult, std::string(result)}});
}
}
// NOLINTEND(readability-convert-member-functions-to-static)
+57 -11
View File
@@ -54,6 +54,7 @@
#include <queue>
#include <shared_mutex>
#include <string>
#include <string_view>
#include <type_traits>
#include <utility>
#include <vector>
@@ -696,38 +697,83 @@ private:
std::shared_ptr<SHAMap const>
getTxSet(std::shared_ptr<protocol::TMGetLedger> const& m) const;
/**
* Counts one TMGetObjectByHash request refused before any NodeStore
* access. The only call site of getobject_rejected_total, so both gates
* share one instrument.
*
* @param reason Which gate refused it: kReasonMalformedLedgerHash or
* kReasonOversize.
*
* @note No-op when telemetry is compiled out or disabled; the macro
* carries that guard.
*/
void
recordGetObjectRejected(std::string_view reason);
protected:
void
processLedgerRequest(
std::shared_ptr<protocol::TMGetLedger> const& m,
std::vector<SHAMapNodeID> nodeIDs);
/**
* The three object counts of one `TMGetObjectByHash` request.
*
* processGetObjectByHash() --> GetObjectCounts --> recordGetObjectMetrics()
*
* `found <= attempted <= requested` always holds. An entry with no hash or
* a wrong-size hash is skipped before the lookup, nothing past
* `kHardMaxReplyNodes` is looked at, and the reply grows only on a hit.
*
* @code
* // 5 entries: 1 malformed, 3 of the other 4 stored.
* GetObjectCounts const counts{.requested = 5, .attempted = 4, .found = 3};
* // Hits 3, misses 1. The malformed entry is neither.
* @endcode
*
* @note A plain value built per request, so there is nothing to lock.
*/
struct GetObjectCounts
{
/**
* Entries in the request, `objects_size()`.
*/
int requested = 0;
/**
* Entries that reached the NodeStore lookup.
*/
int attempted = 0;
/**
* Objects returned in the reply.
*/
int found = 0;
};
/**
* Record the OTel metrics for one completed `TMGetObjectByHash` request.
*
* Called once per request from `processGetObjectByHash()`, after the fetch
* loop and the `charge()` call. A separate method so that one stays within
* the 80-line limit; it holds no logic of its own beyond deriving the
* hit/miss split from `requested` and `found`.
* hit/miss split from the counts. Virtual so a test subclass can capture
* the counts, as it does with `charge()`.
*
* Records `getobject_request_objects`, `getobject_lookup_us`,
* `getobject_charge`, and both label values of
* `getobject_lookups_total`. Every statement is an `XRPL_METRIC_*` record,
* and those macros discard their arguments when telemetry is disabled, so
* the body costs nothing in that build and the call site needs no guard.
* `getobject_lookups_total`, the last from one call site in a loop. The
* macros discard their arguments when telemetry is disabled, so the body
* costs nothing in that build and the call site needs no guard.
*
* @param requested Objects the peer asked for (`objects_size()`).
* @param found Objects returned, i.e. the reply's object count.
* Expected to be `<= requested`; clamped either way
* so the derived miss count cannot go negative.
* @param counts The request's counts. Hits are `found`; misses are
* `attempted - found`.
* @param lookupElapsed Wall time of the whole fetch loop.
* @param fee The dynamic charge that was applied, so the
* recorded value is exactly the one charged.
*/
void
virtual void
recordGetObjectMetrics(
int const requested,
int const found,
GetObjectCounts const& counts,
std::chrono::microseconds const lookupElapsed,
resource::Charge const& fee);
+24 -6
View File
@@ -342,6 +342,25 @@ PerfLogImp::~PerfLogImp()
stop();
}
namespace {
/**
* Adds delta to the count of RPC requests currently executing. The only call
* site of rpc_in_flight_requests, so rpcStart() and rpcEnd() share one
* instrument.
*
* @param app The application, which holds the metrics registry.
* @param delta +1 when a request starts, -1 when it ends.
*/
void
addRpcInFlight(Application& app, std::int64_t const delta)
{
XRPL_METRIC_UPDOWN_ADD(
app, "rpc_in_flight_requests", "RPC requests currently executing", delta);
}
} // namespace
void
PerfLogImp::rpcStart(std::string_view method, std::uint64_t const requestId)
{
@@ -373,11 +392,10 @@ PerfLogImp::rpcStart(std::string_view method, std::uint64_t const requestId)
mr->recordRpcStarted(method);
#endif
// A value that must be able to decrease (UpDownCounter), added at its
// call site with no MetricsRegistry member/init-line/method. Paired with
// the matching -1 in rpcEnd(). Runs on the same path as recordRpcStarted
// above, i.e. only after a methods-map entry exists for this request.
XRPL_METRIC_UPDOWN_ADD(app_, "rpc_in_flight_requests", "RPC requests currently executing", 1);
// Paired with the matching -1 in rpcEnd(). Runs on the same path as
// recordRpcStarted above, i.e. only after a methods-map entry exists for
// this request.
addRpcInFlight(app_, 1);
}
void
@@ -446,7 +464,7 @@ PerfLogImp::rpcEnd(std::string_view method, std::uint64_t const requestId, bool
// Matching -1 for the +1 recorded in rpcStart(). Placed after the early
// returns above so it runs only when this request's methods-map entry was
// found (i.e. a +1 was recorded for it), keeping the in-flight count balanced.
XRPL_METRIC_UPDOWN_ADD(app_, "rpc_in_flight_requests", "RPC requests currently executing", -1);
addRpcInFlight(app_, -1);
}
void