From 9aebdc292c248d8342f7e318c02586270ead59b7 Mon Sep 17 00:00:00 2001 From: Pratik Mankawde <3397372+pratikmankawde@users.noreply.github.com> Date: Mon, 7 Sep 2026 13:16:32 +0100 Subject: [PATCH 01/11] docs(telemetry): fix stale symbols, attribute keys and TraceQL in the plan docs Review feedback on the plan documents. Four kinds of error: - Symbols that do not exist: ConsensusProposal::prevLedger_ (it is previousLedger_), RCLConsensusAdaptor (it is RCLConsensus::Adaptor, and startRound() is on RCLConsensus itself), and RPCHandler::doCommand (a free function, xrpl::rpc::doCommand). - Attribute keys: the tables used ledger_index, which no telemetry code emits. Same concept as ledger_seq but a different referent, so the code disambiguates by prefix: current_ledger_seq for the open ledger a transaction targeted, ledger_seq for a closed or validated one. A note now states which is which. - TraceQL that does not parse: span-field predicates need braces, status.code is not an intrinsic (status = error), and avg(duration) does not take a by clause (avg_over_time does). All five re-tested against Tempo. - The StatsD comparison omitted the Histogram instrument, which aggregates at the point of measure, and the when-to-use table had no row for a metric that spans cannot afford to carry. --- OpenTelemetryPlan/00-tracing-fundamentals.md | 6 +-- OpenTelemetryPlan/02-design-decisions.md | 52 +++++++++++++------ .../05-configuration-reference.md | 14 ++--- OpenTelemetryPlan/06-implementation-phases.md | 28 +++++----- .../07-observability-backends.md | 2 +- 5 files changed, 62 insertions(+), 40 deletions(-) diff --git a/OpenTelemetryPlan/00-tracing-fundamentals.md b/OpenTelemetryPlan/00-tracing-fundamentals.md index 9c6f96d7af..1c7675243a 100644 --- a/OpenTelemetryPlan/00-tracing-fundamentals.md +++ b/OpenTelemetryPlan/00-tracing-fundamentals.md @@ -297,9 +297,9 @@ XRPL has a unique advantage: its core workflows produce **globally unique 256-bi Transaction: STTx::getTransactionID() → uint256 tid_ TMTransaction::rawTransaction → recompute hash from bytes -Consensus: ConsensusProposal::prevLedger_ → uint256 (previous ledger hash) - ConsensusProposal::position_ → uint256 (TxSet hash) - LedgerHeader::seq → uint32_t (ledger sequence) +Consensus: ConsensusProposal::previousLedger_ → uint256 (previous ledger hash) + ConsensusProposal::position_ → uint256 (TxSet hash) + LedgerHeader::seq → uint32_t (ledger sequence) Validation: STValidation::getLedgerHash() → uint256 STValidation::getNodeID() → NodeID (160-bit) diff --git a/OpenTelemetryPlan/02-design-decisions.md b/OpenTelemetryPlan/02-design-decisions.md index c7930454e5..dae5e8fe82 100644 --- a/OpenTelemetryPlan/02-design-decisions.md +++ b/OpenTelemetryPlan/02-design-decisions.md @@ -236,17 +236,19 @@ keys (the dotted form is reserved for resource scope per §2.3.3). #### Transaction Attributes -| Key | Type | Description | -| -------------- | ------ | ------------------------------------- | -| `tx_hash` | string | Transaction hash (hex) | -| `tx_type` | string | `"Payment"`, `"OfferCreate"`, etc. | -| `tx_account` | string | Source account (redacted in prod) | -| `tx_sequence` | int64 | Account sequence number | -| `tx_fee` | int64 | Fee in drops | -| `tx_result` | string | `"tesSUCCESS"`, `"tecPATH_DRY"`, etc. | -| `ledger_index` | int64 | Ledger containing transaction | -| `relay_count` | int64 | Peers the transaction was relayed to | -| `suppressed` | bool | `true` when HashRouter dropped a dup | +| Key | Type | Description | +| -------------------- | ------ | ------------------------------------- | +| `tx_hash` | string | Transaction hash (hex) | +| `tx_type` | string | `"Payment"`, `"OfferCreate"`, etc. | +| `tx_account` | string | Source account (redacted in prod) | +| `tx_sequence` | int64 | Account sequence number | +| `tx_fee` | int64 | Fee in drops | +| `tx_result` | string | `"tesSUCCESS"`, `"tecPATH_DRY"`, etc. | +| `current_ledger_seq` | int64 | Open ledger the transaction targeted | +| `relay_count` | int64 | Peers the transaction was relayed to | +| `suppressed` | bool | `true` when HashRouter dropped a dup | + +> **Note:** `current_ledger_seq` and `ledger_seq` are the same concept — a ledger's sequence number — but they name different ledgers, so the design keeps two keys rather than one. `current_ledger_seq` is the open or in-flight ledger a transaction's work was applied into; it is named after the RPC field `ledger_current_index`. `ledger_seq` (see [Ledger & Job Attributes](#ledger--job-attributes)) is a closed or validated ledger, set by the ledger and consensus spans. Neither is spelled `ledger_index`: per rule 2 of [Telemetry span attribute naming](../CONTRIBUTING.md#telemetry-span-attribute-naming), one concept gets one key reused verbatim, and a different referent is disambiguated with a prefix rather than a synonym. #### Consensus Attributes @@ -289,7 +291,7 @@ keys (the dotted form is reserved for resource scope per §2.3.3). | Key | Type | Description | | --------------------------- | ------- | --------------------------------- | | `ledger_hash` | string | Ledger hash | -| `ledger_index` | int64 | Ledger sequence/index | +| `ledger_seq` | int64 | Closed/validated ledger sequence | | `close_time_ripple_epoch_s` | int64 | Close time (Ripple epoch seconds) | | `ledger_tx_count` | int64 | Transaction count | | `job_type` | string | Job type name | @@ -348,11 +350,11 @@ The following table summarizes what data is collected by category: | Category | Attributes Collected | Purpose | | --------------- | ------------------------------------------------------------------------------------------------- | ---------------------------- | -| **Transaction** | `tx_hash`, `tx_type`, `tx_result`, `tx_fee`, `ledger_index` | Trace transaction lifecycle | +| **Transaction** | `tx_hash`, `tx_type`, `tx_result`, `tx_fee`, `current_ledger_seq` | Trace transaction lifecycle | | **Consensus** | `consensus_round`, `consensus_phase`, `consensus_mode`, `proposers`, `round_time_ms` | Analyze consensus timing | | **RPC** | `command`, `version`, `rpc_status`, `duration_ms` | Monitor RPC performance | | **Peer** | `peer_id` (public key), `peer_latency_ms`, `message_type`, `message_size_bytes` | Network topology analysis | -| **Ledger** | `ledger_hash`, `ledger_index`, `close_time`, `ledger_tx_count` | Ledger progression tracking | +| **Ledger** | `ledger_hash`, `ledger_seq`, `close_time`, `ledger_tx_count` | Ledger progression tracking | | **Job** | `job_type`, `job_queue_ms`, `job_worker` | JobQueue performance | | **PathFinding** | `pathfind_source_currency`, `pathfind_dest_currency`, `pathfind_path_count`, `pathfind_cache_hit` | Payment path analysis | | **TxQ** | `txq_queue_depth`, `txq_fee_level`, `txq_eviction_reason` | Queue depth and fee tracking | @@ -492,9 +494,12 @@ A PerfLog entry is a JSON object with fields such as `time`, `method`, - No request-level detail - No causal relationships - Single-node perspective + - Aggregation happens on the StatsD server, not in the process In xrpld, Beast Insight is used through `increment` (counters), `gauge` -(point-in-time values), and `timing` (durations) calls. +(point-in-time values), and `timing` (durations) calls. A `timing` call sends +each measured value as its own raw `|ms` sample, so the histogram a dashboard +reads is built by the StatsD server from that stream of values. #### OpenTelemetry (NEW) @@ -503,6 +508,7 @@ In xrpld, Beast Insight is used through `increment` (counters), `gauge` - **Cross-node correlation** via `trace_id` - Parent-child span relationships - Rich attributes per span + - A `Histogram` instrument that aggregates **at the point of measure** - Industry standard (CNCF) - **Limitations**: - Requires collector infrastructure @@ -512,6 +518,13 @@ A span is created via `startSpan` (e.g. `"tx.relay"`), annotated with attributes such as `tx_hash` and `peer_id`, and is automatically linked to its parent through the active context. +OpenTelemetry is not only spans. The same SDK offers a `Histogram` instrument, +and a `Record()` call folds the value straight into bucket counts inside the +process — no per-event record is shipped and no server-side aggregation step is +needed. That is what makes it affordable in a hot loop where one span per event +would not be, and it is the one thing Beast Insight cannot do, because its +`timing` path ships raw values and aggregates them on the StatsD server. + ### 2.6.3 When to Use Each | Scenario | PerfLog | StatsD | OpenTelemetry | @@ -522,6 +535,15 @@ parent through the active context. | "Which node delayed consensus?" | ❌ | ❌ | ✅ | | "What happened on node X at time T?" | ✅ | ❌ | ✅ | | "Show me the TX journey across 5 nodes" | ❌ | ❌ | ✅ | +| "p99 NodeStore fetch latency?" | ❌ | ❌ | ✅ | + +The last row is the case a span cannot answer. One `TMGetObjectByHash` message +requests up to `tuning::kHardMaxReplyNodes` objects, so a span per NodeStore +fetch is not affordable in that loop. Instead the fetch loop's wall time is +recorded once per message into an OpenTelemetry `Histogram` +(`getobject_lookup_us`), and the quantile is read off its buckets. StatsD is +marked ❌ because that instrument is recorded on the native OpenTelemetry metrics +path, not through Beast Insight. ### 2.6.4 Coexistence Strategy diff --git a/OpenTelemetryPlan/05-configuration-reference.md b/OpenTelemetryPlan/05-configuration-reference.md index cf0f993dda..15b594f0e1 100644 --- a/OpenTelemetryPlan/05-configuration-reference.md +++ b/OpenTelemetryPlan/05-configuration-reference.md @@ -75,7 +75,7 @@ The parser `setup_Telemetry()` in `src/libxrpl/telemetry/TelemetryConfig.cpp` re > available on both. Components that hold a `ServiceRegistry&` (e.g. > `NetworkOPsImp`) call `registry_.get().getTelemetry()`. Components that > still hold an `Application&` (e.g. `ServerHandler`, `PeerImp`, -> `RCLConsensusAdaptor`) call `app_.getTelemetry()` directly. +> `RCLConsensus::Adaptor`) call `app_.getTelemetry()` directly. --- @@ -196,7 +196,7 @@ An example `xrpld RPC Performance` dashboard (uid `xrpld-rpc-performance`) sourc ### 5.8.4 Example Dashboard: Transaction Tracing -An example `xrpld Transaction Tracing` dashboard (uid `xrpld-tx-tracing`) over Tempo provides three panels: transaction throughput (`tx.receive` rate, stat), cross-node relay count (average `span.relay_count` on `tx.relay`, timeseries), and a table of transaction validation errors (`tx.validate` with `status.code=error`). +An example `xrpld Transaction Tracing` dashboard (uid `xrpld-tx-tracing`) over Tempo provides three panels: transaction throughput (`tx.receive` rate, stat), cross-node relay count (average `span.relay_count` on `tx.relay`, timeseries), and a table of transaction validation errors (`tx.validate` with `status = error`). ### 5.8.5 TraceQL Query Examples @@ -207,19 +207,19 @@ Common queries for xrpld traces: {resource.service.name="xrpld" && span.tx_hash="ABC123..."} # Find slow RPC commands (>100ms) -{resource.service.name="xrpld" && name=~"rpc.command.*"} | duration > 100ms +{resource.service.name="xrpld" && name=~"rpc.command.*"} | { duration > 100ms } # Find consensus rounds taking >5 seconds -{resource.service.name="xrpld" && name="consensus.round"} | duration > 5s +{resource.service.name="xrpld" && name="consensus.round"} | { duration > 5s } # Find failed transactions with error details -{resource.service.name="xrpld" && name="tx.validate" && status.code=error} +{resource.service.name="xrpld" && name="tx.validate" && status = error} # Find transactions relayed to many peers -{resource.service.name="xrpld" && name="tx.relay"} | span.relay_count > 10 +{resource.service.name="xrpld" && name="tx.relay"} | { span.relay_count > 10 } # Compare latency across nodes -{resource.service.name="xrpld" && name="rpc.command.account_info"} | avg(duration) by (resource.service.instance.id) +{resource.service.name="xrpld" && name="rpc.command.account_info"} | avg_over_time(duration) by (resource.service.instance.id) ``` ### 5.8.6 Correlation with PerfLog diff --git a/OpenTelemetryPlan/06-implementation-phases.md b/OpenTelemetryPlan/06-implementation-phases.md index 12eea9c67b..cf1e58f779 100644 --- a/OpenTelemetryPlan/06-implementation-phases.md +++ b/OpenTelemetryPlan/06-implementation-phases.md @@ -97,7 +97,7 @@ gantt | ---- | -------------------------------------------------------------------------- | | 2.1 | Implement W3C Trace Context HTTP header extraction | | 2.2 | Instrument `ServerHandler::onRequest()` | -| 2.3 | Instrument `RPCHandler::doCommand()` | +| 2.3 | Instrument `xrpl::rpc::doCommand()` | | 2.4 | Add RPC-specific attributes | | 2.5 | Instrument WebSocket handler | | 2.6 | PathFinding instrumentation (`pathfind.request`, `pathfind.compute` spans) | @@ -150,19 +150,19 @@ gantt ### Tasks -| Task | Description | -| ---- | ---------------------------------------------- | -| 4.1 | Instrument `RCLConsensusAdaptor::startRound()` | -| 4.2 | Instrument phase transitions | -| 4.3 | Instrument proposal handling | -| 4.4 | Instrument validation handling | -| 4.5 | Add consensus-specific attributes | -| 4.6 | Correlate with transaction traces | -| 4.7 | Validator list and manifest tracing | -| 4.8 | Amendment voting tracing | -| 4.9 | SHAMap sync tracing | -| 4.10 | Multi-validator integration tests | -| 4.11 | Performance validation | +| Task | Description | +| ---- | --------------------------------------- | +| 4.1 | Instrument `RCLConsensus::startRound()` | +| 4.2 | Instrument phase transitions | +| 4.3 | Instrument proposal handling | +| 4.4 | Instrument validation handling | +| 4.5 | Add consensus-specific attributes | +| 4.6 | Correlate with transaction traces | +| 4.7 | Validator list and manifest tracing | +| 4.8 | Amendment voting tracing | +| 4.9 | SHAMap sync tracing | +| 4.10 | Multi-validator integration tests | +| 4.11 | Performance validation | ### Exit Criteria diff --git a/OpenTelemetryPlan/07-observability-backends.md b/OpenTelemetryPlan/07-observability-backends.md index 4ebb6028fd..ecca8320d3 100644 --- a/OpenTelemetryPlan/07-observability-backends.md +++ b/OpenTelemetryPlan/07-observability-backends.md @@ -245,7 +245,7 @@ A Tempo-backed dashboard (uid `xrpld-node-overview`) with four panels: - **Active Nodes** (stat): count of distinct `resource.service.instance.id` values seen for the `xrpld` service. - **Total Transactions (1h)** (stat): count of `tx.receive` spans. -- **Error Rate** (gauge, percent): ratio of `status.code=error` spans to all spans, with yellow/red thresholds at 1%/5%. +- **Error Rate** (gauge, percent): ratio of `status = error` spans to all spans, with yellow/red thresholds at 1%/5%. - **Service Map** (nodeGraph): Tempo-generated service dependency graph. ### 7.6.3 Alert Rules From 4d2841ccda0dc02e5556bae3a57362cd8e67a978 Mon Sep 17 00:00:00 2001 From: Pratik Mankawde <3397372+pratikmankawde@users.noreply.github.com> Date: Mon, 7 Sep 2026 13:16:59 +0100 Subject: [PATCH 02/11] fix(telemetry): reject invalid [telemetry] batch settings and make isValid() honest Two review findings on the telemetry library. SpanContext::isValid() returned impl_ != nullptr, so it answered true for a context holding no span. threadLocalContext() wraps whatever GetCurrent() returns, and that is an empty Context on a thread with no active span, which contradicted the documented "invalid context if none is active". It now asks the Context for its span. childSpan(name, ctx) is the one caller whose behaviour changes: a context with no span used to produce a new root span, and now returns a null guard as its @return already promised. The three batch settings went to the OTel BatchSpanProcessor unchecked. Three ways that failed: zero was accepted for all of them; batch_size could exceed max_queue_size, which the SDK documents as a precondition and does not enforce; and a mistyped value let boost::bad_lexical_cast escape, which derives from std::bad_cast rather than std::runtime_error, so the operator saw a bare "bad cast" naming no key. Reading unsigned also turned "-1" into 4294967295 instead of failing, so the value is parsed signed and negatives are rejected. xrpld-example.cfg now states the ranges. --- cfg/xrpld-example.cfg | 8 ++- src/libxrpl/telemetry/SpanGuard.cpp | 5 +- src/libxrpl/telemetry/TelemetryConfig.cpp | 87 ++++++++++++++++++++++- 3 files changed, 93 insertions(+), 7 deletions(-) diff --git a/cfg/xrpld-example.cfg b/cfg/xrpld-example.cfg index 90f6c4f086..a476830280 100644 --- a/cfg/xrpld-example.cfg +++ b/cfg/xrpld-example.cfg @@ -1751,19 +1751,21 @@ validators.txt # # Maximum number of spans in one export request. A batch is sent once # this many spans have queued up, or once batch_delay_ms has elapsed, -# whichever happens first. Default: 512. +# whichever happens first. Must be at least 1 and must not exceed +# max_queue_size. Default: 512. # # batch_delay_ms=5000 # # Longest a queued span waits before its batch is exported, in # milliseconds. Lower it for fresher traces at the cost of more -# export requests. Default: 5000 (5 seconds). +# export requests. Must be at least 1. Default: 5000 (5 seconds). # # max_queue_size=2048 # # Maximum number of spans held in memory awaiting export. Spans are # dropped once the queue is full, so raise this if the collector is -# slow or briefly unreachable. Default: 2048. +# slow or briefly unreachable. Must be at least 1 and at least as +# large as batch_size. Default: 2048. # # trace_rpc=1 # diff --git a/src/libxrpl/telemetry/SpanGuard.cpp b/src/libxrpl/telemetry/SpanGuard.cpp index a165d0ad5a..63c48c9a72 100644 --- a/src/libxrpl/telemetry/SpanGuard.cpp +++ b/src/libxrpl/telemetry/SpanGuard.cpp @@ -77,7 +77,10 @@ SpanContext::SpanContext(std::shared_ptr impl) : impl_(std::move(impl)) bool SpanContext::isValid() const noexcept { - return impl_ != nullptr; + // Holding a Context is not proof of holding a span. GetCurrent() hands back + // an empty Context on a thread with no active span, and threadLocalContext() + // wraps that too. Ask the Context for its span instead of trusting impl_. + return impl_ != nullptr && otel_trace::GetSpan(impl_->ctx)->GetContext().IsValid(); } // ===== SpanGuard::Impl ==================================================== diff --git a/src/libxrpl/telemetry/TelemetryConfig.cpp b/src/libxrpl/telemetry/TelemetryConfig.cpp index 4cbbbf2a98..4f3698383c 100644 --- a/src/libxrpl/telemetry/TelemetryConfig.cpp +++ b/src/libxrpl/telemetry/TelemetryConfig.cpp @@ -8,11 +8,15 @@ * See cfg/xrpld-example.cfg for the full list of available options. */ +#include #include #include #include #include +#include +#include +#include #include namespace xrpl::telemetry { @@ -60,6 +64,71 @@ constexpr std::uint32_t batchDelayMs = 5000u; constexpr std::uint32_t maxQueueSize = 2048u; } // namespace dflt +/** + * Smallest accepted value for the three batch settings. + * + * All three size a queue or a timer, so zero is meaningless for every one of + * them. The OTel BatchSpanProcessor takes them as given and does not validate, + * so the config parser is the only place a nonsense value can be rejected. + */ +constexpr std::uint32_t kMinBatchSetting = 1u; + +/** + * Section name used in error messages, so the operator knows where to look. + */ +constexpr char const* kSectionLabel = "[telemetry]"; + +/** + * Read a config value and reject anything outside minValue..UINT32_MAX. + * + * Section::get() lets boost::bad_lexical_cast escape. That derives from + * std::bad_cast, not std::runtime_error, so a mistyped value gives the operator + * a bare "bad cast" naming no key. Wrap it and rethrow with the key name. + * + * @param section The [telemetry] section to read from. + * @param name Key to read, as documented in cfg/xrpld-example.cfg. + * @param absentValue Value returned when the key is absent. + * @param minValue Smallest accepted value. + * @return The configured value, or absentValue if the key is absent. + * @note Throws std::runtime_error for a value that is not a whole number, and + * for one out of range, with a different message for each. + */ +[[nodiscard]] std::uint32_t +readBounded( + Section const& section, + char const* name, + std::uint32_t absentValue, + std::uint32_t minValue) +{ + // Read as signed. boost::lexical_cast to an unsigned type wraps a leading + // minus instead of failing ("-1" yields 4294967295), so reading signed is + // the only way to see a negative value and reject it below. + std::optional parsed; + try + { + parsed = section.get(name); + } + catch (...) + { + Throw( + std::string("Invalid value '") + name + "' in " + kSectionLabel + + ": must be a whole number."); + } + + if (!parsed) + return absentValue; + + constexpr auto maxValue = static_cast(std::numeric_limits::max()); + if (*parsed < static_cast(minValue) || *parsed > maxValue) + { + Throw( + std::string("Invalid value '") + name + "' in " + kSectionLabel + ": must be between " + + std::to_string(minValue) + " and " + std::to_string(maxValue) + "."); + } + + return static_cast(*parsed); +} + /** * Derive a human-readable network type label from the numeric network ID. * @param networkId The network identifier from [network_id] config. @@ -108,10 +177,22 @@ makeTelemetrySetup( // traces; volume reduction is delegated to the collector's tail sampling. // setup.samplingRatio is a const member fixed at 1.0; nothing to parse. - setup.batchSize = section.valueOr(key::batchSize, dflt::batchSize); + setup.batchSize = readBounded(section, key::batchSize, dflt::batchSize, kMinBatchSetting); setup.batchDelay = std::chrono::milliseconds{ - section.valueOr(key::batchDelayMs, dflt::batchDelayMs)}; - setup.maxQueueSize = section.valueOr(key::maxQueueSize, dflt::maxQueueSize); + readBounded(section, key::batchDelayMs, dflt::batchDelayMs, kMinBatchSetting)}; + setup.maxQueueSize = + readBounded(section, key::maxQueueSize, dflt::maxQueueSize, kMinBatchSetting); + + // The OTel SDK documents max_export_batch_size <= max_queue_size as a + // precondition of BatchSpanProcessorOptions and does not enforce it, so + // reject the pair here rather than hand the SDK a state it forbids. + if (setup.batchSize > setup.maxQueueSize) + { + Throw( + std::string("Invalid value '") + key::batchSize + "' in " + kSectionLabel + + ": must not exceed '" + key::maxQueueSize + "' (" + std::to_string(setup.maxQueueSize) + + ")."); + } setup.networkId = networkId; setup.networkType = networkTypeFromId(networkId); From f8e0a19b9fd985691e1372145b067151e33c10a3 Mon Sep 17 00:00:00 2001 From: Pratik Mankawde <3397372+pratikmankawde@users.noreply.github.com> Date: Mon, 7 Sep 2026 13:25:22 +0100 Subject: [PATCH 03/11] fix(telemetry): correct the childSpan doc examples and make Rule D tests real Review feedback on the RPC integration PR. The childSpan examples could not work as written. childSpan() takes its parent from the ambient context and uses impl_ only as a liveness gate, so an unscoped SpanGuard parent produced two siblings rather than a parent and child. The parent is now a ScopedSpanGuard, the child no longer reuses the parent's name, and the examples pass a full dotted constant because childSpan() takes the name verbatim. Five of the ten Rule D tests could not fail. Four passed an empty L1 key set, which makes the rule skip validation altogether; the fifth asserted an empty result against an escaped-quote selector that extracted no labels at all. Each now passes a nonempty L1 set and carries a known-bad label in the same expression, so it asserts both that the intended labels are accepted and that Rule D ran. Verified by disabling the rule: the old tests stay green, the new ones all fail. Span kind is not fixed here. categoryToSpanKind and the span factories belong to the telemetry library, so the role parameter is routed to that branch, and the two call sites here follow once it exists. --- .../otel-naming/test_check_otel_naming.py | 52 +++++++++++++++---- include/xrpl/telemetry/SpanGuard.h | 2 +- include/xrpl/telemetry/Telemetry.h | 12 +++-- 3 files changed, 52 insertions(+), 14 deletions(-) diff --git a/.github/scripts/otel-naming/test_check_otel_naming.py b/.github/scripts/otel-naming/test_check_otel_naming.py index c24bc063b4..4fd225ad6e 100644 --- a/.github/scripts/otel-naming/test_check_otel_naming.py +++ b/.github/scripts/otel-naming/test_check_otel_naming.py @@ -738,28 +738,54 @@ class RuleDDashboards(unittest.TestCase): ["bogus_label"], ) + # Rule D returns early on an empty L1 set, so a test that passes one asserts + # nothing. Each test below passes a nonempty L1 set and puts `bogus_label` in + # the same expression as the labels under test: the assertion then pins both + # halves at once — the accepted labels are absent from the result, and Rule D + # demonstrably ran because it flagged the bad one. + def test_builtin_labels_not_flagged(self): self.assertEqual( - self._run('"expr": "sum by (le, span_name, exported_instance) (x)"', set()), - [], + self._run( + '"expr": "sum by (le, span_name, exported_instance, bogus_label) (x)"', + {"command"}, + ), + ["bogus_label"], ) def test_external_infra_labels_not_flagged(self): # EXTERNAL_INFRA_LABELS (perf-iac identity labels with no in-tree - # source) must be recognized as valid, distinct from `builtins`. - expr = "sum by (" + ", ".join(sorted(chk.EXTERNAL_INFRA_LABELS)) + ") (x)" - self.assertEqual(self._run(f'"expr": "{expr}"', set()), []) + # source) must be recognized as valid, distinct from `builtins`. The + # names are spelled out rather than joined from chk.EXTERNAL_INFRA_LABELS + # because building the query from the set that validates it passes for + # whatever that set happens to hold — including an empty one. + self.assertEqual( + self._run( + '"expr": "sum by (xrpl_branch, xrpl_node_role, bogus_label) (x)"', + {"command"}, + ), + ["bogus_label"], + ) def test_prometheus_name_label_not_flagged(self): # `__name__` is the Prometheus reserved metric-name label; the renamed # system-*.json dashboards use `sum by (le, __name__)`. self.assertEqual( - self._run('"expr": "sum by (le, __name__) (rate(x[5m]))"', set()), - [], + self._run( + '"expr": "sum by (le, __name__, bogus_label) (rate(x[5m]))"', + {"command"}, + ), + ["bogus_label"], ) def test_l1_label_passes(self): - self.assertEqual(self._run('"q": "{command=\\"x\\"}"', {"command"}), []) + # `by (...)` form, not a `{command="x"}` selector: a dashboard stores the + # query inside a JSON string, so its quotes are escaped on disk and the + # selector branch extracts nothing from them here. + self.assertEqual( + self._run('"expr": "sum by (command, bogus_label) (x)"', {"command"}), + ["bogus_label"], + ) def test_traceql_span_prefix_stripped(self): # `span.establish_count` must validate against the bare L1 key. @@ -772,7 +798,15 @@ class RuleDDashboards(unittest.TestCase): ) def test_traceql_resource_prefix_stripped(self): - self.assertEqual(self._run('"q": "{resource.service_name=\\"x\\"}"', set()), []) + # `resource.service_name` must validate against the bare builtin, same as + # the `span.` case above. + self.assertEqual( + self._run( + '"expr": "count_over_time(x) by (resource.service_name, bogus_label)"', + {"command"}, + ), + ["bogus_label"], + ) def test_native_metric_label_passes(self): # `job_type` / `reason` are emitted by MetricsRegistry, not span attrs. diff --git a/include/xrpl/telemetry/SpanGuard.h b/include/xrpl/telemetry/SpanGuard.h index 9f6d4c0ae9..39b589e655 100644 --- a/include/xrpl/telemetry/SpanGuard.h +++ b/include/xrpl/telemetry/SpanGuard.h @@ -99,7 +99,7 @@ * auto ctx = span.spanContext(); * * // Thread B: create child with captured context - * auto child = SpanGuard::childSpan(rpc_span::op::process, ctx); + * auto child = SpanGuard::childSpan(rpc_span::prefix::command, ctx); * @endcode * * 4. Conditional check (rarely needed — methods are no-ops on null): diff --git a/include/xrpl/telemetry/Telemetry.h b/include/xrpl/telemetry/Telemetry.h index 68efe4965c..ab694abdae 100644 --- a/include/xrpl/telemetry/Telemetry.h +++ b/include/xrpl/telemetry/Telemetry.h @@ -53,14 +53,18 @@ * * 2. Child span for a sub-operation (scoped child): * @code - * auto parent = SpanGuard::span( + * auto parent = ScopedSpanGuard( * TraceCategory::Rpc, rpc_span::prefix::rpc, rpc_span::op::process); * { - * auto child = parent.childSpan(rpc_span::op::process); - * child.setAttribute(rpc_span::attr::version, apiVersion); + * auto child = parent.childSpan(rpc_span::prefix::command); + * child.setAttribute(rpc_span::attr::version, static_cast(apiVersion)); * // child ends here * } * @endcode + * childSpan() parents to the ambient scope, so the parent must be a + * ScopedSpanGuard. A plain SpanGuard is not ambient: pass its spanContext() + * to childSpan(name, ctx) instead. childSpan() takes the name verbatim, so + * pass a full dotted constant, never a bare op:: suffix. * * 3. Unrelated span (cross-scope, same thread): * @code @@ -78,7 +82,7 @@ * auto ctx = parentGuard.spanContext(); * * // Thread B: create child span with explicit parent - * auto child = SpanGuard::childSpan(rpc_span::op::process, ctx); + * auto child = SpanGuard::childSpan(rpc_span::prefix::command, ctx); * @endcode * * @note Thread safety: The Telemetry interface is safe for concurrent reads From 18abd100b5ac5bc7c047f7ffd31e3a5ee484ff53 Mon Sep 17 00:00:00 2001 From: Pratik Mankawde <3397372+pratikmankawde@users.noreply.github.com> Date: Mon, 7 Sep 2026 13:39:57 +0100 Subject: [PATCH 04/11] feat(telemetry): let a call site choose a span's role, not just its category Span kind was derived from TraceCategory alone, so every Rpc-category span was kServer. A category cannot tell an inbound handler from the internal work under it, and trace backends pair kServer with kClient, so internal spans left as kServer become unpaired edges in a service graph and read as extra inbound requests. SpanRole is a new xrpl-owned enum, orthogonal to TraceCategory: the category names the subsystem and gates the span on config, the role says whether the span handles a remote call. It is a defaulted fourth parameter on span(), freshRoot() and the ScopedSpanGuard equivalents, defaulting to SpanRole::FromCategory, so no existing call site changes. resolveSpanKind() applies an explicit role and falls back to the category map, which keeps its single responsibility. The telemetry-disabled stubs mirror all four signatures. No call site passes a role yet. The two that need it are on a later branch. Also fixes a ScopedSpanGuard example that passed a bare op:: suffix to childSpan(), which takes the name verbatim. Naming the child rpc.command made it a child of rpc.command., inverting the hierarchy, so the example's parent is now rpc.process and the command attribute moved onto the command span. --- include/xrpl/telemetry/SpanGuard.h | 102 ++++++++++++++++++++++++---- src/libxrpl/telemetry/SpanGuard.cpp | 70 +++++++++++++++---- 2 files changed, 147 insertions(+), 25 deletions(-) diff --git a/include/xrpl/telemetry/SpanGuard.h b/include/xrpl/telemetry/SpanGuard.h index 284815a900..46f1dcb63b 100644 --- a/include/xrpl/telemetry/SpanGuard.h +++ b/include/xrpl/telemetry/SpanGuard.h @@ -155,6 +155,22 @@ * }); * @endcode * + * 8. Internal work inside a category whose default role is Server: + * @code + * #include + * using namespace xrpl::telemetry; + * + * // Only the inbound handler is the server side of a remote call. + * // Work below it is internal, so pass the role explicitly: the + * // category default (Server) would read as a second inbound + * // request and leave an unpaired edge in a service graph. + * auto span = SpanGuard::span( + * TraceCategory::Rpc, + * rpc_span::prefix::rpc, + * rpc_span::op::process, + * SpanRole::Internal); + * @endcode + * * @note Thread safety: SpanGuard is thread-free. It holds only the * span (no Scope), so it never binds to a thread-local context stack * and may be moved to and destroyed on any thread. To make a span the @@ -196,6 +212,25 @@ namespace xrpl::telemetry { */ enum class TraceCategory { Rpc, Transactions, Consensus, Peer, Ledger }; +/** + * Role a span plays in a call relationship. Each value maps to the OTel + * span kind of the same name; see Telemetry::startSpan() for what those + * mean. + * + * Orthogonal to TraceCategory. The category names the subsystem and gates + * the span on config (`trace_rpc=1`); the role says whether the span + * handles a remote call or is internal work. An Rpc-category span can be + * either: the inbound request handler is Server, everything it calls into + * is Internal. + * + * FromCategory takes the category's own role, so a call site that does not + * care passes nothing. Pick a role explicitly where the category default + * is wrong: trace backends pair Server with Client and Consumer with + * Producer, so internal work left as Server becomes an unpaired edge in a + * service graph. + */ +enum class SpanRole { FromCategory, Internal, Server, Client, Producer, Consumer }; + /** * Opaque wrapper for an OTel context snapshot. * @@ -291,9 +326,16 @@ public: * @param cat Trace subsystem category. * @param prefix Span name prefix (e.g. "rpc.command"). * @param name Span name suffix (e.g. "submit"). + * @param role Call-relationship role; defaults to the category's own + * role. Pass Internal for work the category maps to Server or Consumer + * but that handles no remote call. */ [[nodiscard]] static SpanGuard - span(TraceCategory cat, std::string_view prefix, std::string_view name) noexcept; + span( + TraceCategory cat, + std::string_view prefix, + std::string_view name, + SpanRole role = SpanRole::FromCategory) noexcept; /** * Create a span that always starts a fresh trace root. @@ -308,10 +350,16 @@ public: * @param cat Trace subsystem category. * @param prefix Span name prefix (e.g. "peer"). * @param name Span name suffix (e.g. "validation.receive"). + * @param role Call-relationship role; defaults to the category's own + * role. See span(). * @return An active root-span guard, or a null guard if disabled. */ [[nodiscard]] static SpanGuard - freshRoot(TraceCategory cat, std::string_view prefix, std::string_view name) noexcept; + freshRoot( + TraceCategory cat, + std::string_view prefix, + std::string_view name, + SpanRole role = SpanRole::FromCategory) noexcept; // --- Child / linked span creation ---------------------------------- @@ -528,10 +576,12 @@ public: * using namespace xrpl::telemetry; * * ScopedSpanGuard span( - * TraceCategory::Rpc, rpc_span::prefix::command, commandName); - * span.setAttribute(rpc_span::attr::command, commandName); - * // childSpan parents to `span` because it is active on this thread - * auto child = span.childSpan(rpc_span::op::process); + * TraceCategory::Rpc, rpc_span::prefix::rpc, rpc_span::op::process); + * // childSpan takes the name verbatim, so pass a full dotted constant, + * // never a bare op:: suffix. The child parents to `span` because + * // `span` is active on this thread. + * auto child = span.childSpan(rpc_span::prefix::command); + * child.setAttribute(rpc_span::attr::command, commandName); * @endcode * * 2. Capture on this thread, hand off to another (edge case): @@ -578,8 +628,14 @@ public: * @param cat Trace subsystem category. * @param prefix Span name prefix (e.g. "rpc.command"). * @param name Span name suffix (e.g. "submit"). + * @param role Call-relationship role; defaults to the category's own + * role. See SpanGuard::span(). */ - ScopedSpanGuard(TraceCategory cat, std::string_view prefix, std::string_view name) noexcept; + ScopedSpanGuard( + TraceCategory cat, + std::string_view prefix, + std::string_view name, + SpanRole role = SpanRole::FromCategory) noexcept; ~ScopedSpanGuard(); @@ -598,10 +654,16 @@ public: * @param cat Trace subsystem category. * @param prefix Span name prefix. * @param name Span name suffix. + * @param role Call-relationship role; defaults to the category's own + * role. See SpanGuard::span(). * @return An active scoped root-span guard, or a null one if disabled. */ [[nodiscard]] static ScopedSpanGuard - freshRoot(TraceCategory cat, std::string_view prefix, std::string_view name) noexcept; + freshRoot( + TraceCategory cat, + std::string_view prefix, + std::string_view name, + SpanRole role = SpanRole::FromCategory) noexcept; // --- Child / linked span creation ---------------------------------- @@ -893,13 +955,21 @@ public: operator=(SpanGuard const&) = delete; [[nodiscard]] static SpanGuard - span(TraceCategory, std::string_view, std::string_view) noexcept + span( + TraceCategory, + std::string_view, + std::string_view, + SpanRole = SpanRole::FromCategory) noexcept { return {}; } [[nodiscard]] static SpanGuard - freshRoot(TraceCategory, std::string_view, std::string_view) noexcept + freshRoot( + TraceCategory, + std::string_view, + std::string_view, + SpanRole = SpanRole::FromCategory) noexcept { return {}; } @@ -1004,7 +1074,11 @@ class ScopedSpanGuard ScopedSpanGuard() = default; public: - ScopedSpanGuard(TraceCategory, std::string_view, std::string_view) noexcept + ScopedSpanGuard( + TraceCategory, + std::string_view, + std::string_view, + SpanRole = SpanRole::FromCategory) noexcept { } /** @@ -1025,7 +1099,11 @@ public: operator=(ScopedSpanGuard const&) = delete; [[nodiscard]] static ScopedSpanGuard - freshRoot(TraceCategory, std::string_view, std::string_view) noexcept + freshRoot( + TraceCategory, + std::string_view, + std::string_view, + SpanRole = SpanRole::FromCategory) noexcept { return {}; } diff --git a/src/libxrpl/telemetry/SpanGuard.cpp b/src/libxrpl/telemetry/SpanGuard.cpp index 63c48c9a72..28d1572531 100644 --- a/src/libxrpl/telemetry/SpanGuard.cpp +++ b/src/libxrpl/telemetry/SpanGuard.cpp @@ -168,11 +168,13 @@ namespace { constexpr char const* kLinkTypeKey = "link_type"; constexpr char const* kLinkTypeFollowsFrom = "follows_from"; -// Map a TraceCategory to an OTel SpanKind so Tempo's service-graph / -// RED metrics see the correct direction. RPC spans are emitted at the -// server entry point (handler dispatch), Peer spans at inbound-message -// receipt. Transactions / Consensus / Ledger are internal processing -// and keep the default kInternal. +// Per-category default OTel SpanKind, used when a call site passes no +// SpanRole. A category cannot tell an inbound entry point from the +// internal work under it, so RPC and Peer default to the entry-point +// kind and any call site below the entry point passes SpanRole::Internal +// instead. Transactions / Consensus / Ledger are internal throughout. +// The kind drives direction in Tempo's service-graph / RED metrics, +// which pair kServer with kClient and kConsumer with kProducer. otel_trace::SpanKind categoryToSpanKind(TraceCategory cat) { @@ -190,6 +192,38 @@ categoryToSpanKind(TraceCategory cat) return otel_trace::SpanKind::kInternal; // unreachable } +/** + * Resolve the span kind to start a span with. + * + * An explicit SpanRole wins; SpanRole::FromCategory falls back to the + * category default above. Role and category are separate axes, so a single + * category can emit both an inbound handler and the internal work under it. + * + * @param cat Trace subsystem category. Read only for SpanRole::FromCategory. + * @param role Role the caller asked for. + * @return The OTel span kind for this span. + */ +[[nodiscard]] otel_trace::SpanKind +resolveSpanKind(TraceCategory cat, SpanRole role) +{ + switch (role) + { + case SpanRole::FromCategory: + return categoryToSpanKind(cat); + case SpanRole::Internal: + return otel_trace::SpanKind::kInternal; + case SpanRole::Server: + return otel_trace::SpanKind::kServer; + case SpanRole::Client: + return otel_trace::SpanKind::kClient; + case SpanRole::Producer: + return otel_trace::SpanKind::kProducer; + case SpanRole::Consumer: + return otel_trace::SpanKind::kConsumer; + } + return categoryToSpanKind(cat); // unreachable +} + /** * Join a span-name prefix and suffix into the dotted full name. * @@ -221,7 +255,11 @@ joinSpanName(std::string_view prefix, std::string_view name) noexcept } // namespace SpanGuard -SpanGuard::span(TraceCategory cat, std::string_view prefix, std::string_view name) noexcept +SpanGuard::span( + TraceCategory cat, + std::string_view prefix, + std::string_view name, + SpanRole role) noexcept { auto* tel = Telemetry::getInstance(); if ((tel == nullptr) || !tel->isEnabled() || !isCategoryEnabled(*tel, cat)) @@ -229,11 +267,15 @@ SpanGuard::span(TraceCategory cat, std::string_view prefix, std::string_view nam auto const fullName = joinSpanName(prefix, name); if (!fullName) return {}; - return SpanGuard(std::make_unique(tel->startSpan(*fullName, categoryToSpanKind(cat)))); + return SpanGuard(std::make_unique(tel->startSpan(*fullName, resolveSpanKind(cat, role)))); } SpanGuard -SpanGuard::freshRoot(TraceCategory cat, std::string_view prefix, std::string_view name) noexcept +SpanGuard::freshRoot( + TraceCategory cat, + std::string_view prefix, + std::string_view name, + SpanRole role) noexcept { auto* tel = Telemetry::getInstance(); if ((tel == nullptr) || !tel->isEnabled() || !isCategoryEnabled(*tel, cat)) @@ -244,7 +286,7 @@ SpanGuard::freshRoot(TraceCategory cat, std::string_view prefix, std::string_vie // Force a fresh trace root: do NOT inherit this thread's active span. auto rootCtx = opentelemetry::context::Context{otel_trace::kIsRootSpanKey, true}; return SpanGuard( - std::make_unique(tel->startSpan(*fullName, rootCtx, categoryToSpanKind(cat)))); + std::make_unique(tel->startSpan(*fullName, rootCtx, resolveSpanKind(cat, role)))); } // ===== Child / linked span creation ======================================== @@ -532,8 +574,9 @@ ScopedSpanGuard::~ScopedSpanGuard() ScopedSpanGuard::ScopedSpanGuard( TraceCategory cat, std::string_view prefix, - std::string_view name) noexcept - : ScopedSpanGuard(SpanGuard::span(cat, prefix, name)) + std::string_view name, + SpanRole role) noexcept + : ScopedSpanGuard(SpanGuard::span(cat, prefix, name, role)) { } @@ -541,9 +584,10 @@ ScopedSpanGuard ScopedSpanGuard::freshRoot( TraceCategory cat, std::string_view prefix, - std::string_view name) noexcept + std::string_view name, + SpanRole role) noexcept { - return ScopedSpanGuard(SpanGuard::freshRoot(cat, prefix, name)); + return ScopedSpanGuard(SpanGuard::freshRoot(cat, prefix, name, role)); } ScopedSpanGuard From b5415233cd2070b190b22ce285afac2729b6f71a Mon Sep 17 00:00:00 2001 From: Pratik Mankawde <3397372+pratikmankawde@users.noreply.github.com> Date: Mon, 7 Sep 2026 13:42:29 +0100 Subject: [PATCH 05/11] fix(telemetry): stop reporting applied_direct for a failed direct apply tryDirectApply returns an engaged optional whenever the fee bar was cleared, including when xrpl::apply() failed, so testing the optional labelled failures as applied. TxQ_test's fail-in-preclaim case hits exactly this: the fee clears the bar and preclaim then rejects with terINSUF_FEE_B. The stamp now branches on ApplyResult::applied. A failure reports failed rather than falling through to the default rejected, because rejected means the transaction got nowhere, while this one cleared the fee bar and ran through apply(). ter_code is recorded either way, so the failure is diagnosable. Both values already existed and are used the same way by the queued-apply path in this file, so the vocabulary is unchanged. The value set in the phase-3 task list is updated to match, including a ter_code row for txq.accept_tx that was already emitted but undocumented. --- OpenTelemetryPlan/Phase3_taskList.md | 4 +++- src/xrpld/app/misc/detail/TxQ.cpp | 11 ++++++++++- 2 files changed, 13 insertions(+), 2 deletions(-) diff --git a/OpenTelemetryPlan/Phase3_taskList.md b/OpenTelemetryPlan/Phase3_taskList.md index 92d7529c82..5224148814 100644 --- a/OpenTelemetryPlan/Phase3_taskList.md +++ b/OpenTelemetryPlan/Phase3_taskList.md @@ -496,12 +496,14 @@ This gives the best of both worlds: guaranteed cross-node correlation via determ | `tx.process` | `applied` | bool | `e.applied` (set after batch application) | | `tx.receive` | `tx_type` | string | `TxFormats::getInstance().findByType(stx->getTxnType())->getName()` | | `txq.enqueue` | `tx_type` | string | same pattern as above | -| `txq.enqueue` | `txq_status` | string | `queued` / `applied_direct` / `applied` / `rejected` | +| `txq.enqueue` | `txq_status` | string | `queued` / `applied_direct` / `applied` / `failed` / `rejected` | +| `txq.enqueue` | `ter_code` | string | `transToken(directApplied->ter)` (set on the direct-apply path) | | `txq.enqueue` | `fee_level_paid` | int64 | `getFeeLevelPaid(view, *tx).value()` | | `txq.enqueue` | `required_fee_level` | int64 | `getRequiredFeeLevel(...).value()` | | `txq.batch_clear` | `num_cleared` | int64 | queued txs cleared ahead of the applying tx | | `txq.cleanup` | `expired_count` | int64 | entries dropped for passed `LastLedgerSequence` | | `txq.accept_tx` | `txq_status` | string | `applied` / `failed` / `retried` | +| `txq.accept_tx` | `ter_code` | string | `transToken(txnResult)` (set before branching on the outcome) | | `txq.accept` | `ledger_changed` | bool | set at end of accept loop | **New attr keys**: `TxSpanNames.h` (`txType`, `fee`, `sequence`, `terResult`, `applied`), `TxQSpanNames.h` (`txType`). diff --git a/src/xrpld/app/misc/detail/TxQ.cpp b/src/xrpld/app/misc/detail/TxQ.cpp index bb83e4ad9f..d98736e9f2 100644 --- a/src/xrpld/app/misc/detail/TxQ.cpp +++ b/src/xrpld/app/misc/detail/TxQ.cpp @@ -801,7 +801,16 @@ TxQ::apply( // into the ledger. if (auto directApplied = tryDirectApply(app, view, tx, flags, j)) { - span.setAttribute(txq_span::attr::txqStatus, txq_span::val::appliedDirect); + // A result comes back even when the apply failed, so branch on the outcome. + // transToken() builds a string, so the whole block is guarded. + if (span) + { + span.setAttribute(txq_span::attr::terCode, transToken(directApplied->ter).c_str()); + if (directApplied->applied) + span.setAttribute(txq_span::attr::txqStatus, txq_span::val::appliedDirect); + else + span.setAttribute(txq_span::attr::txqStatus, txq_span::val::failed); + } return *directApplied; } From 623e3d8ad3c850fb240e347d7b1910e8d8b56ed1 Mon Sep 17 00:00:00 2001 From: Pratik Mankawde <3397372+pratikmankawde@users.noreply.github.com> Date: Mon, 7 Sep 2026 13:51:44 +0100 Subject: [PATCH 06/11] feat(telemetry): add batch-size and discovered-path histograms Review feedback asked for a Histogram rather than a span attribute at these two places. Both, not either: the attribute answers how big one sampled request was, which an aggregate cannot, and the histogram answers the distribution across all requests, which an unsampled trace never reveals. Both attributes stay. The metrics land here rather than with the attributes because neither HistogramBuckets.h nor the metric macro exists on the branch that added them. Both use kObjectCountBuckets. The argument is the floor, not the ceiling: the SDK default edges start 0,5,10,25, so an ordinary batch of one to five falls in a single bucket and every quantile becomes an interpolation on one edge. The object ladder puts five edges over the mass of both distributions. Path count is bounded at 352 by kMaxPaths times kMaxAutoSrcCur and cannot saturate. Batch size can, at roughly 333k, but no measured traffic goes near it, so the ladder is not widened for a range nothing occupies; the runbook records the overflow query and a test asserts it stays readable. --- .../scripts/levelization/results/ordering.txt | 2 + .../09-data-collection-reference.md | 65 ++++- docs/telemetry-runbook.md | 39 +++ include/xrpl/telemetry/RpcMetricNames.h | 101 ++++++++ .../libxrpl/telemetry/RpcMetricNames.cpp | 232 ++++++++++++++++++ src/xrpld/rpc/detail/PathRequest.cpp | 19 ++ src/xrpld/rpc/detail/ServerHandler.cpp | 20 ++ src/xrpld/telemetry/MetricsRegistry.cpp | 17 ++ 8 files changed, 490 insertions(+), 5 deletions(-) create mode 100644 include/xrpl/telemetry/RpcMetricNames.h create mode 100644 src/tests/libxrpl/telemetry/RpcMetricNames.cpp diff --git a/.github/scripts/levelization/results/ordering.txt b/.github/scripts/levelization/results/ordering.txt index d9c4f24ecf..be1115a063 100644 --- a/.github/scripts/levelization/results/ordering.txt +++ b/.github/scripts/levelization/results/ordering.txt @@ -193,6 +193,7 @@ tests.libxrpl > xrpl.config tests.libxrpl > xrpl.consensus tests.libxrpl > xrpl.core tests.libxrpl > xrpld.app +tests.libxrpl > xrpld.rpc tests.libxrpl > xrpld.telemetry tests.libxrpl > xrpl.json tests.libxrpl > xrpl.ledger @@ -313,6 +314,7 @@ xrpld.rpc > xrpl.basics xrpld.rpc > xrpl.config xrpld.rpc > xrpl.core xrpld.rpc > xrpld.core +xrpld.rpc > xrpld.telemetry xrpld.rpc > xrpl.json xrpld.rpc > xrpl.ledger xrpld.rpc > xrpl.net diff --git a/OpenTelemetryPlan/09-data-collection-reference.md b/OpenTelemetryPlan/09-data-collection-reference.md index 0e2a69139d..cee514ce78 100644 --- a/OpenTelemetryPlan/09-data-collection-reference.md +++ b/OpenTelemetryPlan/09-data-collection-reference.md @@ -1148,6 +1148,10 @@ repeated here: [Per-Job-Type Metrics](#per-job-type-metrics-synchronous-countershistogram). - Five `getobject_*` instruments covering the `TMGetObjectByHash` request path — see [GetObject Request Path](#getobject-request-path-synchronous-countershistograms). +- Two request-count histograms, `rpc_batch_size` and `pathfind_discovered_paths`, + which give the aggregate distribution of two values that until now existed only + as span attributes on a sampled trace — see + [RPC Request-Count Histograms](#rpc-request-count-histograms). - Three per-job-type queue gauge families (`jobq__waiting` / `_running` / `_deferred`). These travel the `beast::insight` pipeline, not the OTel SDK one, so they are documented in @@ -1518,6 +1522,55 @@ macro (see `src/xrpld/telemetry/MetricMacros.h` and `PerfLogImp.cpp`), not throu `MetricsRegistry` member. As an UpDownCounter it carries no `_total` suffix (that is reserved for monotonic counters). +#### RPC Request-Count Histograms + +Two histograms describing how much work one request asks for. Names and +descriptions are the `constexpr` constants in +`include/xrpl/telemetry/RpcMetricNames.h`; both are recorded at their call sites +via `XRPL_METRIC_*`, and both have an explicit-bucket view registered in +`src/xrpld/telemetry/MetricsRegistry.cpp`. + +| Prometheus Metric | Type | Labels | Description | +| --------------------------- | --------- | ------ | ------------------------------------------------------- | +| `rpc_batch_size` | Histogram | (none) | Sub-requests per batch JSON-RPC call | +| `pathfind_discovered_paths` | Histogram | (none) | Payment paths produced per pathfinding pass, all assets | + +| Metric | Recorded at | Beside the span attribute | +| --------------------------- | ----------------------------------------------- | ------------------------- | +| `rpc_batch_size` | `ServerHandler::processRequest`, `method=batch` | `batch_size` | +| `pathfind_discovered_paths` | `PathRequest::findPaths`, after the asset loop | `pathfind_num_paths` | + +**Why both a span attribute and a histogram for the same value.** The attribute +answers "how big was this one request" on a trace someone is already looking at. +It cannot give a distribution, because an unsampled trace is never read. The +histogram answers "how big are these requests" across every call. Neither +replaces the other, so both stay. + +`rpc_batch_size` is recorded only when `method == "batch"`, matching the +attribute. Recording a plain single request would add the value 1 on every RPC +and bury the batch distribution. + +`pathfind_discovered_paths` records inside the existing +`#ifdef XRPL_ENABLE_TELEMETRY` block, because the running total it reports is +only maintained in a telemetry build. Zero is a normal and interesting value: a +pass that found no path at all records it. + +**Both use `buckets::kObjectCountBuckets`, and the reason is the floor.** The SDK +default boundaries begin `0, 5, 10, 25`, so every batch of one to five +sub-requests — the ordinary case — lands in a single bucket and +`histogram_quantile` returns that edge scaled by the quantile rather than a +count. The object-count ladder's `1, 2, 4, 8, 16` edges sit where both +distributions have their mass. + +- **Path counts cannot saturate.** `PathRequest::kMaxPaths` (4) per source asset + times `tuning::kMaxAutoSrcCur` (88) bounds a pass at 352 paths, well under the + ladder's 12288 top edge. +- **Batch sizes can.** Nothing caps the sub-request count; the only bound is + `tuning::kMaxRequestSize` (1 MB) over the smallest sub-request an array can + hold, about 333,000. The ladder is not extended into a range no measured + workload occupies, so an over-ceiling batch lands in `+Inf` and is read as + `rpc_batch_size_count - rpc_batch_size_bucket{le="12288"}` instead. + #### Per-Job-Type Metrics (Synchronous Counters/Histogram) | Prometheus Metric | Type | Labels | Description | @@ -1595,8 +1648,8 @@ information the batch totals do not already carry. **All three histograms need an explicit bucket view.** The SDK's default histogram boundaries top out at 10000. Every one of these three exceeds that, so -without a view their top quantiles would all read as a flat 10000. Six views are -registered in `src/xrpld/telemetry/MetricsRegistry.cpp`, and three of the six are +without a view their top quantiles would all read as a flat 10000. Eight views are +registered in `src/xrpld/telemetry/MetricsRegistry.cpp`, and three of the eight are for this family: | Instrument | View helper | Boundaries | @@ -1605,9 +1658,11 @@ for this family: | `getobject_request_objects` | `addHistogramView()`, own set | `1, 2, 4, 8, 16, 64, 256, 1024, 4096, 12288` | | `getobject_charge` | `addHistogramView()`, own set | `0, 100, 500, 1000, 5000, 10000, 25000, 50000, 100000` | -The other three views are `addMicrosecondHistogramView()` on `job_queued_us`, -`job_running_us`, and `rpc_method_us` — four µs-ladder views plus these two -custom sets. +The other five views are `addMicrosecondHistogramView()` on `job_queued_us`, +`job_running_us` and `rpc_method_us`, plus `rpc_batch_size` and +`pathfind_discovered_paths` on the object-count ladder — four µs-ladder views and +four custom-boundary ones. See +[RPC Request-Count Histograms](#rpc-request-count-histograms) for the latter two. **Why the latter two do not use the µs ladder.** They are not durations. The µs ladder's buckets are chosen for time (sub-millisecond jobs through multi-second diff --git a/docs/telemetry-runbook.md b/docs/telemetry-runbook.md index 4705c26ced..f58c7b777c 100644 --- a/docs/telemetry-runbook.md +++ b/docs/telemetry-runbook.md @@ -1930,6 +1930,45 @@ Aggregation choices worth knowing when reading these: > peer sends an oversized request. Verify its panel with a synthetic oversized > request; do not assume it works because the query parses. +#### RPC Request-Count Metrics + +Two histograms describing how much work one RPC asks for. Names and descriptions +are the `constexpr` constants in `include/xrpl/telemetry/RpcMetricNames.h`; both +are recorded at their call sites and both get an explicit-bucket view in +`MetricsRegistry.cpp`. + +| Prometheus Metric | Kind | Labels | Recorded at | Description | +| --------------------------- | --------- | ------ | ----------------------------------------------- | --------------------------------------------------------- | +| `rpc_batch_size` | Histogram | none | `ServerHandler::processRequest`, `method=batch` | Sub-requests per batch JSON-RPC call | +| `pathfind_discovered_paths` | Histogram | none | `PathRequest::findPaths`, after the asset loop | Payment paths produced per pass, across all source assets | + +Reading them: + +- Each one sits beside a span attribute carrying the same value — + `batch_size` and `pathfind_num_paths`. Use the attribute to ask what one slow + request did; use the histogram to ask what requests do in general. An attribute + cannot answer the second question, because an unsampled trace is never read. +- `rpc_batch_size` records **only for `method == "batch"`**. A non-batch request + is not a batch of one, and recording it would put the value 1 on every RPC and + bury the distribution. +- `pathfind_discovered_paths` counts zero when a pass found no path, and that is + the most interesting reading on this instrument. It shares the lowest bucket + with "found exactly one path"; everything above is separated. +- Both use the object-count bucket ladder, not the µs one. They are counts, and + the SDK's default boundaries start `0, 5, 10, 25` — which puts every ordinary + batch in one bucket and makes each quantile an interpolation on the edge. +- **`rpc_batch_size` can saturate.** Nothing caps the sub-request count except + the 1 MB request-size limit, so a batch above the ladder's 12288 top edge lands + in `+Inf`. Read the overflow directly rather than trusting p99 there: + +```promql +rpc_batch_size_count - rpc_batch_size_bucket{le="12288"} +``` + +> On a healthy local network `rpc_batch_size` has **no series at all** — nothing +> issues batch RPCs. An empty panel is the expected reading, not a wiring fault. +> Verify it by sending one batch request, not by looking for a series. + #### Adding a New Metric diff --git a/include/xrpl/telemetry/RpcMetricNames.h b/include/xrpl/telemetry/RpcMetricNames.h new file mode 100644 index 0000000000..1869fd44d0 --- /dev/null +++ b/include/xrpl/telemetry/RpcMetricNames.h @@ -0,0 +1,101 @@ +#pragma once + +// cspell:ignore ISTOGRAM +// The all-caps macro name XRPL_METRIC_HISTOGRAM_RECORD trips cspell's +// compound-word splitter, which emits the subword "ISTOGRAM"; ignore it here. + +/** + * Metric names and descriptions for the RPC request-count histograms. + * + * These two instruments measure how much work one request asks for. A span + * attribute cannot answer that in aggregate: it is readable only on a trace + * that was sampled, so it describes one call and never the distribution over + * all of them. The span attributes stay in place for single-request + * debugging; these histograms carry the shape. + * + * Each name is used at two sites, which is why they are shared constants + * rather than literals: + * + * RpcMetricNames.h + * | + * +--> ServerHandler.cpp (records kRpcBatchSize) + * | + * +--> PathRequest.cpp (records kPathfindDiscoveredPaths) + * | + * +--> MetricsRegistry.cpp (addHistogramView: registers the + * explicit bucket edges for both) + * + * A drifted name silently drops the bucket override. The SDK default edges + * start at 0, 5, 10, 25, so every batch of one to five sub-requests would + * then land in one bucket and every quantile would be an interpolation + * inside it. + * + * Placed under `include/xrpl/telemetry/` for the same reason + * GetObjectMetricNames.h is: the record sites are `xrpld.rpc` and the view + * registration is `xrpld.telemetry`, and `include/xrpl/` is the one level + * both modules are allowed to reach. + * + * Example usage -- recording the batch size: + * @code + * if (batch) + * { + * span.setAttribute(rpc_span::attr::batchSize, static_cast(size)); + * XRPL_METRIC_HISTOGRAM_RECORD(app_, kRpcBatchSize, kRpcBatchSizeDesc, size); + * } + * @endcode + * + * Example usage -- edge case: a pathfinding pass that produced no paths still + * records, because "found nothing" is the observation that matters most on + * this instrument: + * @code + * std::int64_t totalPaths = 0; // no source asset yielded a path + * XRPL_METRIC_HISTOGRAM_RECORD( + * app_, kPathfindDiscoveredPaths, kPathfindDiscoveredPathsDesc, totalPaths); + * @endcode + * + * @note These are `constexpr char[]`, not `std::string_view`. The OTel C++ + * API takes `nostd::string_view`, which has no converting constructor from + * `std::string_view` on this build, so a `string_view` constant would not + * compile at the call sites. Same convention as GetObjectMetricNames.h. + * + * @note Both share `buckets::kObjectCountBuckets`, whose top edge is 12288. + * A pathfinding pass cannot reach it. A batch can: nothing caps the + * sub-request count except the one-megabyte request-size limit. An + * over-ceiling batch lands in `+Inf` and stays countable as + * `rpc_batch_size_count - rpc_batch_size_bucket{le="12288"}`, so the overflow + * is visible rather than lost. No measured workload occupies that range, so + * the ladder is not extended into it. + * + * @note Header-only constants with no runtime state, so there is nothing to + * synchronize -- safe to include from any thread context. + */ + +namespace xrpl::telemetry { + +// ===== Metric names ========================================================== + +/** + * Distribution of the sub-request count in a batch JSON-RPC call. + * + * Recorded only for `method == "batch"`. A plain single request would + * otherwise flood the histogram with the value 1 and bury the batch + * distribution this instrument exists to show. + */ +inline constexpr char kRpcBatchSize[] = "rpc_batch_size"; + +/** + * Distribution of the payment paths one pathfinding pass produced, summed + * across every candidate source asset. + */ +inline constexpr char kPathfindDiscoveredPaths[] = "pathfind_discovered_paths"; + +// ===== Instrument descriptions =============================================== + +/** @{ */ +inline constexpr char kRpcBatchSizeDesc[] = "Sub-requests per batch JSON-RPC call"; + +inline constexpr char kPathfindDiscoveredPathsDesc[] = + "Payment paths produced per pathfinding pass, across all source assets"; +/** @} */ + +} // namespace xrpl::telemetry diff --git a/src/tests/libxrpl/telemetry/RpcMetricNames.cpp b/src/tests/libxrpl/telemetry/RpcMetricNames.cpp new file mode 100644 index 0000000000..ea27f80f28 --- /dev/null +++ b/src/tests/libxrpl/telemetry/RpcMetricNames.cpp @@ -0,0 +1,232 @@ +/** + * GTest unit tests for the RPC request-count metric names and their bucket fit. + * + * Two facts here have no other guard in CI. First, a metric NAME is the + * Prometheus series every panel and alert selects on, and + * `check_otel_naming.py` checks span attribute keys, not metric names -- so a + * rename or a stray unit suffix would pass every gate and blank the panels. + * Second, the reason these two histograms need an explicit-bucket view is the + * ladder FLOOR, which is invisible in a dashboard: a quantile that falls inside + * bucket 0 is interpolated from the bucket edge and reads back as a plausible + * number. The bucket-index tests below pin that with the SDK's own placement + * rule rather than leaving it to review. + */ + +#include + +#include + +#include + +#include + +#include +#include +#include +#include +#include + +namespace xrpl::telemetry { + +namespace { + +/** + * Placement rule the OTel SDK uses: the bucket index of a sample is the count + * of edges strictly below it, found with `std::lower_bound` over the ascending + * edge list. Recomputed here rather than asserted from memory, so a ladder edit + * moves the expected indices with it. + * + * @param ladder Bucket upper bounds, ascending. + * @param sample Value to place. + * @return Zero-based bucket index; `ladder.size()` means the `+Inf` bucket. + */ +[[nodiscard]] std::size_t +bucketIndex(std::span ladder, double sample) +{ + return static_cast(std::ranges::lower_bound(ladder, sample) - ladder.begin()); +} + +/** + * Last underscore-separated segment of a metric name. + * + * @param name Metric name. + * @return The text after the final underscore, or the whole name when there is + * no underscore. + */ +[[nodiscard]] std::string_view +lastSegment(std::string_view name) +{ + auto const pos = name.rfind('_'); + return pos == std::string_view::npos ? name : name.substr(pos + 1); +} + +/** + * The opentelemetry-cpp default explicit-bucket boundaries, quoted from the + * SDK because they are the ladder these two instruments would fall back to if + * their view were dropped. Not a repo constant, so there is no symbol to read + * them from. + */ +inline constexpr std::array kSdkDefaultBuckets{ + 0.0, + 5.0, + 10.0, + 25.0, + 50.0, + 75.0, + 100.0, + 250.0, + 500.0, + 750.0, + 1'000.0, + 2'500.0, + 5'000.0, + 7'500.0, + 10'000.0}; + +/** + * Smallest number of bytes one batch sub-request can occupy inside the + * `params` array: the two braces of an empty object plus its separating comma. + * An empty object still passes `isObject()`, so the handler iterates over it. + */ +inline constexpr int kMinBatchItemBytes = 3; + +} // namespace + +TEST(RpcMetricNames, namesAreTheExactExportedSeriesNames) +{ + // These strings ARE the Prometheus series. Changing one is a + // dashboard-breaking change, so it has to be a deliberate edit here too. + EXPECT_EQ(std::string_view{kRpcBatchSize}, "rpc_batch_size"); + EXPECT_EQ(std::string_view{kPathfindDiscoveredPaths}, "pathfind_discovered_paths"); +} + +TEST(RpcMetricNames, descriptionsAreTheExactExportedHelpText) +{ + // The description becomes the Prometheus `# HELP` line, so it is part of + // the exported surface, not a code comment. + EXPECT_EQ(std::string_view{kRpcBatchSizeDesc}, "Sub-requests per batch JSON-RPC call"); + EXPECT_EQ( + std::string_view{kPathfindDiscoveredPathsDesc}, + "Payment paths produced per pathfinding pass, across all source assets"); +} + +TEST(RpcMetricNames, namesAreLowerSnakeCase) +{ + for (std::string_view const name : + {std::string_view{kRpcBatchSize}, std::string_view{kPathfindDiscoveredPaths}}) + { + ASSERT_FALSE(name.empty()); + EXPECT_TRUE(name.front() >= 'a' && name.front() <= 'z') + << name << " must start with a lowercase letter"; + EXPECT_NE(name.back(), '_') << name << " must not end with an underscore"; + for (char const c : name) + { + EXPECT_TRUE((c >= 'a' && c <= 'z') || (c >= '0' && c <= '9') || c == '_') + << name << " contains '" << c << "', which is not lower_snake_case"; + } + EXPECT_EQ(name.find("__"), std::string_view::npos) + << name << " must not contain a double underscore"; + } +} + +TEST(RpcMetricNames, namesEndInTheCountedNounAndNotAUnitOrCounterSuffix) +{ + // Both instruments count things. `_total` is the Prometheus counter suffix + // and `_count`/`_sum`/`_bucket` are the ones the exporter appends to a + // histogram, so a base name ending in any of them collides with a series + // the exporter generates. `_us`/`_ms`/`_bytes` would claim a unit these + // values do not have. + EXPECT_EQ(lastSegment(kRpcBatchSize), "size"); + EXPECT_EQ(lastSegment(kPathfindDiscoveredPaths), "paths"); + + for (std::string_view const name : + {std::string_view{kRpcBatchSize}, std::string_view{kPathfindDiscoveredPaths}}) + { + for (std::string_view const reserved : + {"total", "count", "sum", "bucket", "us", "ms", "s", "seconds", "bytes"}) + { + EXPECT_NE(lastSegment(name), reserved) + << name << " ends in the reserved suffix _" << reserved; + } + } +} + +TEST(RpcMetricBucketFit, objectCountLadderSeparatesTheSmallestCounts) +{ + using buckets::kObjectCountBuckets; + + // The five edges that carry both distributions. Stated exactly: raising the + // floor is the defect this test exists to catch. + ASSERT_GE(kObjectCountBuckets.size(), 5u); + EXPECT_EQ(kObjectCountBuckets[0], 1.0); + EXPECT_EQ(kObjectCountBuckets[1], 2.0); + EXPECT_EQ(kObjectCountBuckets[2], 4.0); + EXPECT_EQ(kObjectCountBuckets[3], 8.0); + EXPECT_EQ(kObjectCountBuckets[4], 16.0); + + std::span const ladder{kObjectCountBuckets}; + + // A pathfinding pass that found nothing shares bucket 0 with a pass that + // found exactly one path; every larger count is separated. + EXPECT_EQ(bucketIndex(ladder, 0.0), 0u); + EXPECT_EQ(bucketIndex(ladder, 1.0), 0u); + EXPECT_EQ(bucketIndex(ladder, 2.0), 1u); + EXPECT_EQ(bucketIndex(ladder, 3.0), 2u); + EXPECT_EQ(bucketIndex(ladder, 4.0), 2u); + EXPECT_EQ(bucketIndex(ladder, 8.0), 3u); + EXPECT_EQ(bucketIndex(ladder, 16.0), 4u); +} + +TEST(RpcMetricBucketFit, theSdkDefaultLadderWouldCollapseEverySmallBatch) +{ + // This is why both instruments get an explicit-bucket view. On the SDK + // default ladder every batch from 1 to 5 sub-requests lands in one bucket, + // so histogram_quantile interpolates inside it and returns the edge scaled + // by the quantile -- a number that looks like a batch size and is not one. + std::span const sdk{kSdkDefaultBuckets}; + EXPECT_EQ(bucketIndex(sdk, 1.0), 1u); + EXPECT_EQ(bucketIndex(sdk, 2.0), 1u); + EXPECT_EQ(bucketIndex(sdk, 4.0), 1u); + EXPECT_EQ(bucketIndex(sdk, 5.0), 1u); + + // The chosen ladder spreads those same four values over three buckets. + std::span const chosen{buckets::kObjectCountBuckets}; + EXPECT_EQ(bucketIndex(chosen, 1.0), 0u); + EXPECT_EQ(bucketIndex(chosen, 2.0), 1u); + EXPECT_EQ(bucketIndex(chosen, 4.0), 2u); + EXPECT_EQ(bucketIndex(chosen, 5.0), 3u); +} + +TEST(RpcMetricBucketFit, aMaximumSizedBatchStillOverflowsTheLadderCeiling) +{ + // The documented limitation of rpc_batch_size, as an executable fact. + // Nothing caps the sub-request count except the request-size limit, so the + // largest possible batch is far above the ladder's top edge and lands in + // `+Inf`. RpcMetricNames.h documents the query that counts the overflow. + // If the ladder is ever raised past this bound, this test goes red and that + // note has to change with it. + constexpr int kLargestPossibleBatch = rpc::tuning::kMaxRequestSize / kMinBatchItemBytes; + EXPECT_EQ(kLargestPossibleBatch, 333'333); + EXPECT_EQ(buckets::kObjectCountBuckets.back(), 12'288.0); + EXPECT_GT(static_cast(kLargestPossibleBatch), buckets::kObjectCountBuckets.back()); + + // A pass-through check on the placement helper: the overflow really does + // land in the +Inf bucket, whose index is one past the last edge. + std::span const ladder{buckets::kObjectCountBuckets}; + EXPECT_EQ(bucketIndex(ladder, static_cast(kLargestPossibleBatch)), ladder.size()); +} + +// The placement helper must also disagree with the ladder when it should. A +// helper that always returned 0 would let every index assertion above pass. +TEST(RpcMetricBucketFit, bucketIndexPlacesAboveAndBelowEveryEdge) +{ + constexpr std::array probe{10.0, 20.0}; + std::span const ladder{probe}; + EXPECT_EQ(bucketIndex(ladder, 9.9), 0u); + EXPECT_EQ(bucketIndex(ladder, 10.0), 0u); + EXPECT_EQ(bucketIndex(ladder, 10.1), 1u); + EXPECT_EQ(bucketIndex(ladder, 20.0), 1u); + EXPECT_EQ(bucketIndex(ladder, 20.1), 2u); +} + +} // namespace xrpl::telemetry diff --git a/src/xrpld/rpc/detail/PathRequest.cpp b/src/xrpld/rpc/detail/PathRequest.cpp index 1154109fc9..b61bf1edee 100644 --- a/src/xrpld/rpc/detail/PathRequest.cpp +++ b/src/xrpld/rpc/detail/PathRequest.cpp @@ -1,3 +1,7 @@ +// cspell:ignore ISTOGRAM +// The all-caps macro name XRPL_METRIC_HISTOGRAM_RECORD trips cspell's +// compound-word splitter, which emits the subword "ISTOGRAM"; ignore it here. + #include #include @@ -8,6 +12,7 @@ #include #include #include +#include #include #include @@ -50,6 +55,14 @@ #include #include +// The path-count metric name and description. Both are only ever used inside an +// XRPL_METRIC_* argument list, and those macros expand to nothing when +// telemetry is off, so the include is guarded like its uses -- clang-tidy's +// misc-include-cleaner rejects an include nothing references. +#ifdef XRPL_ENABLE_TELEMETRY +#include +#endif // XRPL_ENABLE_TELEMETRY + namespace xrpl { PathRequest::PathRequest( @@ -745,6 +758,12 @@ PathRequest::findPaths( #ifdef XRPL_ENABLE_TELEMETRY span.setAttribute(pathfind_span::attr::numPaths, totalPaths); + // The attribute answers "how many paths did THIS pass find" on one sampled + // trace. The histogram answers "how many paths do passes find" across all + // of them, which no attribute can, since an unsampled trace is never read. + // Inside the guard because totalPaths only exists when telemetry is built. + XRPL_METRIC_HISTOGRAM_RECORD( + app_, kPathfindDiscoveredPaths, kPathfindDiscoveredPathsDesc, totalPaths); #endif /* The resource fee is based on the number of source currencies used. diff --git a/src/xrpld/rpc/detail/ServerHandler.cpp b/src/xrpld/rpc/detail/ServerHandler.cpp index 3c797d3fcb..38dddb1850 100644 --- a/src/xrpld/rpc/detail/ServerHandler.cpp +++ b/src/xrpld/rpc/detail/ServerHandler.cpp @@ -1,3 +1,7 @@ +// cspell:ignore ISTOGRAM +// The all-caps macro name XRPL_METRIC_HISTOGRAM_RECORD trips cspell's +// compound-word splitter, which emits the subword "ISTOGRAM"; ignore it here. + #include #include @@ -10,6 +14,7 @@ #include #include #include // IWYU pragma: keep +#include #include #include @@ -77,6 +82,14 @@ #include #include +// The batch-size metric name and description. Both are only ever used inside an +// XRPL_METRIC_* argument list, and those macros expand to nothing when +// telemetry is off, so the include is guarded like its uses -- clang-tidy's +// misc-include-cleaner rejects an include nothing references. +#ifdef XRPL_ENABLE_TELEMETRY +#include +#endif // XRPL_ENABLE_TELEMETRY + namespace xrpl { using namespace telemetry; @@ -760,7 +773,14 @@ ServerHandler::processRequest( } span.setAttribute(rpc_span::attr::isBatch, batch); if (batch) + { span.setAttribute(rpc_span::attr::batchSize, static_cast(size)); + // The attribute answers "how big was THIS batch" on one sampled trace. + // The histogram answers "how big are batches" across all of them, which + // no attribute can, since an unsampled trace is never read. + XRPL_METRIC_HISTOGRAM_RECORD( + app_, telemetry::kRpcBatchSize, telemetry::kRpcBatchSizeDesc, size); + } json::Value reply(batch ? json::ValueType::Array : json::ValueType::Object); diff --git a/src/xrpld/telemetry/MetricsRegistry.cpp b/src/xrpld/telemetry/MetricsRegistry.cpp index a3e706a73c..f335e26925 100644 --- a/src/xrpld/telemetry/MetricsRegistry.cpp +++ b/src/xrpld/telemetry/MetricsRegistry.cpp @@ -68,6 +68,7 @@ #include #include #include +#include #include // For networkTypeFromId(), the one xrpl.network.type mapping both export // paths use. Adds no levelization edge: xrpld.telemetry > xrpl.telemetry @@ -335,6 +336,22 @@ MetricsRegistry::initExporterAndProvider(StartOptions const& options) // so a dashboard can show how close charges run to each. addHistogramView(*views, kGetObjectCharge, buckets::toVector(buckets::kChargeBuckets)); + // The two RPC request-count histograms are recorded at their ServerHandler + // and PathRequest call sites, so the names come from the shared constants + // all three sites use. Both are small counts, and the reason they need a + // view is the FLOOR rather than the ceiling: the SDK default edges start + // 0, 5, 10, 25, so a batch of one to five sub-requests -- the normal case -- + // would land in a single bucket and every quantile over it would be an + // interpolation inside that bucket rather than a measurement. + // + // The object-count ladder is the fit: its 1, 2, 4, 8, 16 edges sit exactly + // where both distributions have their mass. Path counts are hard-bounded at + // kMaxPaths * kMaxAutoSrcCur = 352, well under its 12288 top. Batch sizes + // have no such cap; see the ceiling note in RpcMetricNames.h. + addHistogramView(*views, kRpcBatchSize, buckets::toVector(buckets::kObjectCountBuckets)); + addHistogramView( + *views, kPathfindDiscoveredPaths, buckets::toVector(buckets::kObjectCountBuckets)); + // Create MeterProvider with resource, then attach the metric reader. provider_ = metric_sdk::MeterProviderFactory::Create(std::move(views), resourceAttrs); provider_->AddMetricReader(std::move(reader)); From b89a83f8f81d73cac5d8727003626a0ff144c83b Mon Sep 17 00:00:00 2001 From: Pratik Mankawde <3397372+pratikmankawde@users.noreply.github.com> Date: Mon, 7 Sep 2026 14:39:50 +0100 Subject: [PATCH 07/11] fix(telemetry): stamp the round span's mode when the engine applies it startRoundTracing runs as an argument to Consensus::startRound, so it creates consensus.round before startRoundInternal applies the new mode. Reading mode_ there recorded the previous round's value, and a validator switching from observing to proposing got a round span labelled observing that nothing corrected. The attribute is now written in onModeChange, from the mode being applied. All three MonitoredMode::set paths funnel through there, so round start, a wrong-ledger switch and a bow-out all correct the parent span with one statement. Every path reaches it under RCLConsensus::mutex_ on the thread that created the span. The stale write is removed rather than kept alongside: neither Consensus::startRound nor startRoundInternal has an early return before mode_.set, so every round span is stamped. If a future path ever skipped it the attribute would be absent, which reads as a gap, instead of confidently wrong. onClose also sets consensus_mode, from the engine's own parameter, and is correct as it stands. Also tests addEvent's attribute overload on a live span, reading the exported event name and each value back off the in-memory exporter. It was previously only ever called on a null guard, so a dropped attribute exported nothing and failed nothing. --- include/xrpl/consensus/ConsensusSpanNames.h | 10 +- .../libxrpl/telemetry/SpanGuardScope.cpp | 91 +++++++++++++++++++ src/xrpld/app/consensus/RCLConsensus.cpp | 13 ++- 3 files changed, 111 insertions(+), 3 deletions(-) diff --git a/include/xrpl/consensus/ConsensusSpanNames.h b/include/xrpl/consensus/ConsensusSpanNames.h index e337fa56c6..3c09dded41 100644 --- a/include/xrpl/consensus/ConsensusSpanNames.h +++ b/include/xrpl/consensus/ConsensusSpanNames.h @@ -15,8 +15,9 @@ * * consensus.round [main thread, root] * | Created: Adaptor::startRoundTracing() - * | Attrs: consensus_ledger_id, ledger_seq, consensus_mode, - * | trace_strategy, consensus_round_id + * | Attrs: consensus_ledger_id, ledger_seq, trace_strategy, + * | consensus_round_id; consensus_mode from + * | Adaptor::onModeChange() * | * +-- consensus.phase.open [main thread, child] * | Created: Consensus::startRoundInternal() @@ -151,6 +152,11 @@ using ::xrpl::telemetry::attr::ledgerSeq; * Use `_` underscore form for TraceQL ergonomics. */ inline constexpr auto ledgerId = makeStr("consensus_ledger_id"); +/** + * Consensus mode. On consensus.round it is written by onModeChange, the point + * at which the engine applies the mode; on consensus.ledger_close the engine + * passes the mode in. + */ inline constexpr auto mode = makeStr("consensus_mode"); inline constexpr auto round = makeStr("consensus_round"); inline constexpr auto roundId = makeStr("consensus_round_id"); diff --git a/src/tests/libxrpl/telemetry/SpanGuardScope.cpp b/src/tests/libxrpl/telemetry/SpanGuardScope.cpp index 62890950e5..b14102f96f 100644 --- a/src/tests/libxrpl/telemetry/SpanGuardScope.cpp +++ b/src/tests/libxrpl/telemetry/SpanGuardScope.cpp @@ -15,6 +15,10 @@ // - DeterministicIdGenerator (installed by the test TracerProvider) mints a // caller-pinned trace_id for a forced-root span. PendingTraceId pins the id // for one root span; an ambient child under a live parent never adopts it. +// - addEvent records the event name and every attribute onto the exported +// span. The attribute overload copies each pair into an OTel +// key-value-iterable, so the values are read back off the exported SpanData +// rather than trusted. // // The whole file is telemetry-only: when XRPL_ENABLE_TELEMETRY is not defined // SpanGuard is a no-op stub and the OpenTelemetry SDK headers are unavailable, @@ -23,9 +27,11 @@ #ifdef XRPL_ENABLE_TELEMETRY #include +#include #include #include #include +#include #include #include @@ -34,6 +40,7 @@ #include #include #include +#include #include #include #include @@ -57,6 +64,7 @@ #include #include #include +#include #include #include @@ -249,6 +257,28 @@ countSpans( return count; } +/** + * Read one string attribute off an exported span event. + * + * Returns a sentinel instead of asserting so the caller's EXPECT_EQ prints the + * key that was wrong. + * + * @param event Exported event to read. + * @param key Attribute key to look up. + * @return The attribute's string value; "" when the key is absent, + * "" when it holds another variant alternative. + */ +std::string +eventAttribute(otel_sdk_trace::SpanDataEvent const& event, std::string_view key) +{ + auto const& attrs = event.GetAttributes(); + auto const it = attrs.find(std::string(key)); + if (it == attrs.end()) + return ""; + auto const* const value = opentelemetry::nostd::get_if(&it->second); + return value != nullptr ? *value : ""; +} + /** * Build the 16-byte deterministic trace_id used by the generator tests * (bytes 1..16). Kept out of line so every generator test pins the same id. @@ -566,6 +596,67 @@ TEST_F(SpanGuardScopeTest, activate_sets_ambient_without_owning) EXPECT_EQ(txSpan->GetSpanId(), activeId); } +// addEvent(name, attrs) on a LIVE span must reach the exporter with the event +// name and every attribute value intact. The overload rebuilds each pair into an +// OTel key-value-iterable, so a dropped or mistyped pair would be invisible +// without reading the exported event back. Values are asserted individually as +// well as by count: two attributes with one value blanked still counts as two. +TEST_F(SpanGuardScopeTest, spanGuard_addEvent_records_name_and_attribute_values) +{ + namespace cs = consensus::span; + + static constexpr std::string_view kEventName{cs::event::txIncluded}; + static constexpr std::string_view kTxIdKey{cs::attr::txId}; + static constexpr std::string_view kTxId{"6B5F1A2C3D4E5F60718293A4B5C6D7E8"}; + static constexpr std::string_view kStateKey{cs::attr::consensusState}; + static constexpr std::string_view kState{cs::val::finished}; + + { + auto guard = SpanGuard::span(TraceCategory::Consensus, seg::consensus, cs::op::acceptApply); + ASSERT_TRUE(static_cast(guard)); + guard.addEvent(kEventName, {{kTxIdKey, kTxId}, {kStateKey, kState}}); + } // guard ends the span, exporting it. + + auto spans = spanData()->GetSpans(); + auto* applySpan = findSpan(spans, cs::acceptApply); + ASSERT_NE(applySpan, nullptr); + + auto const& events = applySpan->GetEvents(); + ASSERT_EQ(events.size(), 1u); + auto const& event = events.front(); + + EXPECT_EQ(event.GetName(), std::string(kEventName)); + EXPECT_EQ(event.GetAttributes().size(), 2u); + EXPECT_EQ(event.GetDroppedAttributesCount(), 0u); + EXPECT_EQ(eventAttribute(event, kTxIdKey), std::string(kTxId)); + EXPECT_EQ(eventAttribute(event, kStateKey), std::string(kState)); +} + +// The name-only overload records the event with NO attributes, so a regression +// that leaked attributes between the two overloads shows up here rather than as +// an extra key on a production event. +TEST_F(SpanGuardScopeTest, spanGuard_addEvent_without_attributes_records_bare_event) +{ + namespace cs = consensus::span; + + static constexpr std::string_view kEventName{cs::event::phaseAccepted}; + + { + auto guard = SpanGuard::span(TraceCategory::Consensus, seg::consensus, cs::op::round); + ASSERT_TRUE(static_cast(guard)); + guard.addEvent(kEventName); + } + + auto spans = spanData()->GetSpans(); + auto* roundSpan = findSpan(spans, cs::round); + ASSERT_NE(roundSpan, nullptr); + + auto const& events = roundSpan->GetEvents(); + ASSERT_EQ(events.size(), 1u); + EXPECT_EQ(events.front().GetName(), std::string(kEventName)); + EXPECT_EQ(events.front().GetAttributes().size(), 0u); +} + // A forced-root span started while a PendingTraceId is active adopts that // pinned 16-byte trace_id and remains a true root (no parent). TEST_F(SpanGuardScopeTest, deterministicIdGenerator_forced_root_gets_pending_trace_id) diff --git a/src/xrpld/app/consensus/RCLConsensus.cpp b/src/xrpld/app/consensus/RCLConsensus.cpp index 460a447631..ac627e2519 100644 --- a/src/xrpld/app/consensus/RCLConsensus.cpp +++ b/src/xrpld/app/consensus/RCLConsensus.cpp @@ -1145,6 +1145,14 @@ RCLConsensus::Adaptor::onModeChange(ConsensusMode before, ConsensusMode after) censorshipDetector_.reset(); mode_ = after; + + // consensus.round is created before the engine applies the mode, so this is + // the first point where the round's mode is known. Every mode transition, + // including the one at round start, reaches here. + if (roundSpan_ && *roundSpan_) + { + roundSpan_->setAttribute(cs::attr::mode, toDisplayString(after).c_str()); + } } json::Value @@ -1374,7 +1382,6 @@ RCLConsensus::Adaptor::startRoundTracing(RCLCxLedger const& prevLgr) roundSpan_->setAttribute(cs::attr::ledgerId, to_string(prevLgr.id()).c_str()); roundSpan_->setAttribute(cs::attr::ledgerSeq, static_cast(prevLgr.seq()) + 1); - roundSpan_->setAttribute(cs::attr::mode, toDisplayString(mode_.load()).c_str()); roundSpan_->setAttribute(cs::attr::traceStrategy, strategy.c_str()); roundSpan_->setAttribute(cs::attr::roundId, static_cast(prevLgr.seq()) + 1); roundSpan_->setAttribute(cs::attr::previousLedgerSeq, static_cast(prevLgr.seq())); @@ -1383,6 +1390,10 @@ RCLConsensus::Adaptor::startRoundTracing(RCLCxLedger const& prevLgr) cs::attr::previousRoundTimeMs, static_cast(prevRoundTime_.load().count())); roundSpan_->setAttribute(cs::attr::consensusPhase, cs::val::phaseOpen); + // consensus_mode is stamped by onModeChange, which the engine calls just + // after this with the mode it is applying. Setting it here would record the + // previous round's mode. + roundSpan_->addEvent(cs::event::phaseOpen); // roundSpanContext_ is the durable handle that child spans on other From 0128feb70f861770f9e1463a58f80da6ca890089 Mon Sep 17 00:00:00 2001 From: Pratik Mankawde <3397372+pratikmankawde@users.noreply.github.com> Date: Mon, 7 Sep 2026 14:50:41 +0100 Subject: [PATCH 08/11] fix(telemetry): count each validated ledger once in ValidationTracker Both record entry points reached their record with pending_[ledgerHash], and operator[] default-constructs on a missing key. An all-zero recordTime was the only signal for "first time seeing this ledger", so it could not tell a new ledger apart from one already counted and evicted. Reconciled entries are removed on purpose once they leave the late-repair window, and reconcile() adds a ledger to the totals only on its first reconcile. A validation arriving after its entry was counted and removed therefore rebuilt a blank record, looked new, and was counted a second time - in the lifetime totals and in all three rolling windows, so the agreement percentages skewed too. A re-arrival carrying only one side manufactured a miss for a ledger first counted as an agreement. Both entry points now go through pendingEvent(), which looks in pending_ first so a ledger still awaiting late repair keeps updating its record, then checks tallied_ and records nothing for a ledger already counted. That retires the all-zero sentinel, which was the defect itself. tallied_ holds hashes only, since the record is gone by then, and is bounded at kMaxTalliedEvents with oldest-first eviction to match evictOldPending. A validation for a ledger counted more than that many ledgers ago is counted again; the comment says so. The message counters keep incrementing on every call, including for an ignored ledger. They count messages rather than ledgers. kMaxPendingEvents becomes public so the new test sizes its fill from the production constant instead of copying the number. Its value and meaning are unchanged. --- .../libxrpl/telemetry/ValidationTracker.cpp | 71 +++++++++++++++++++ src/xrpld/telemetry/ValidationTracker.h | 52 +++++++++++++- .../telemetry/detail/ValidationTracker.cpp | 58 ++++++++++----- 3 files changed, 161 insertions(+), 20 deletions(-) diff --git a/src/tests/libxrpl/telemetry/ValidationTracker.cpp b/src/tests/libxrpl/telemetry/ValidationTracker.cpp index 05dcec22c0..9a4d3d3b4b 100644 --- a/src/tests/libxrpl/telemetry/ValidationTracker.cpp +++ b/src/tests/libxrpl/telemetry/ValidationTracker.cpp @@ -287,3 +287,74 @@ TEST_F(ValidationTrackerTest, OnlyWeValidated) EXPECT_EQ(tracker_.missed1h(), 1u); EXPECT_DOUBLE_EQ(tracker_.agreementPct1h(), 0.0); } + +// --------------------------------------------------------------- +// 10. A counted ledger is never counted twice +// reconcile() drops the oldest reconciled events once the +// pending map passes kMaxPendingEvents. A validation arriving +// for one of those ledgers afterwards must not reach the +// agreement or missed totals a second time. +// +// Two hashes are made the oldest so the trim drops both: +// - evictedMiss (network only) reconciles as a miss. Our late +// validation cannot repair an entry the trim dropped, so +// totalMissed staying at 1 proves the trim really dropped +// it. A fixture where the trim did not run would repair it +// and report 0 misses. +// - evictedAgreed (both sides) reconciles as an agreement. +// Re-recording both sides is what double-counts an +// agreement. +// --------------------------------------------------------------- +TEST_F(ValidationTrackerTest, CountedLedgerNotCountedTwice) +{ + // The trim drops the oldest reconciled entries first. Each pause makes + // the next record time strictly larger, so these two are the oldest. + auto const evictedMiss = makeHash(1); + tracker_.recordNetworkValidation(evictedMiss, 1); + std::this_thread::sleep_for(std::chrono::milliseconds(5)); + + auto const evictedAgreed = makeHash(2); + tracker_.recordOurValidation(evictedAgreed, 2); + tracker_.recordNetworkValidation(evictedAgreed, 2); + std::this_thread::sleep_for(std::chrono::milliseconds(5)); + + // Fill to three over the bound so the trim drops three entries: the two + // above plus one filler. + constexpr std::size_t kFill = ValidationTracker::kMaxPendingEvents + 1; + for (std::size_t i = 0; i < kFill; ++i) + { + auto const hash = makeHash(i + 3); + auto const seq = static_cast(i + 3); + tracker_.recordOurValidation(hash, seq); + tracker_.recordNetworkValidation(hash, seq); + } + + std::this_thread::sleep_for(std::chrono::seconds(9)); + tracker_.reconcile(); + + // Every filler plus evictedAgreed agrees; evictedMiss is the one miss. + EXPECT_EQ(tracker_.totalAgreements(), kFill + 1); + EXPECT_EQ(tracker_.totalMissed(), 1u); + EXPECT_EQ(tracker_.agreements1h(), kFill + 1); + EXPECT_EQ(tracker_.missed1h(), 1u); + + // Validations arrive again for the two dropped ledgers. + tracker_.recordOurValidation(evictedMiss, 1); + tracker_.recordOurValidation(evictedAgreed, 2); + tracker_.recordNetworkValidation(evictedAgreed, 2); + + // Long enough for a re-created pending entry to pass the grace period. + std::this_thread::sleep_for(std::chrono::seconds(9)); + tracker_.reconcile(); + + // Both ledgers were already counted, so every total is unchanged. + EXPECT_EQ(tracker_.totalAgreements(), kFill + 1); + EXPECT_EQ(tracker_.totalMissed(), 1u); + EXPECT_EQ(tracker_.agreements1h(), kFill + 1); + EXPECT_EQ(tracker_.missed1h(), 1u); + + // The send and check counters count messages, not ledgers, so the + // repeated validations do count towards them. + EXPECT_EQ(tracker_.totalValidationsSent(), kFill + 3); + EXPECT_EQ(tracker_.totalValidationsChecked(), kFill + 3); +} diff --git a/src/xrpld/telemetry/ValidationTracker.h b/src/xrpld/telemetry/ValidationTracker.h index 278332ad8e..3c4d26dc6e 100644 --- a/src/xrpld/telemetry/ValidationTracker.h +++ b/src/xrpld/telemetry/ValidationTracker.h @@ -47,6 +47,7 @@ namespace xrpl::telemetry { * | ValidationTracker | * |---------------------------| * | pending_ (hash_map) |----> LedgerEvent per hash + * | tallied_ (hash_set) |----> hashes already counted * | window1h_ (deque) |----> WindowEvent sliding window * | window24h_ (deque) |----> WindowEvent sliding window * | atomic totals | @@ -104,6 +105,13 @@ public: */ using TimePoint = Clock::time_point; + /** + * Maximum number of pending (unreconciled + recently reconciled) events. + * Once the pending map passes this size, reconcile() drops the oldest + * reconciled events. Public so a test can size a fixture against it. + */ + static constexpr std::size_t kMaxPendingEvents = 1000; + /** * Record that this node sent a validation for the given ledger. * @param ledgerHash Hash of the ledger we validated. @@ -267,9 +275,12 @@ private: static constexpr auto kLateRepairWindow = std::chrono::minutes(5); /** - * Maximum number of pending (unreconciled + recently reconciled) events. + * Maximum number of ledger hashes remembered as already counted. + * At one ledger every four seconds this spans about eleven hours. + * A validation arriving for a ledger counted before that is counted + * again. */ - static constexpr std::size_t kMaxPendingEvents = 1000; + static constexpr std::size_t kMaxTalliedEvents = 10000; /** * Duration of the short rolling window. @@ -287,7 +298,8 @@ private: static constexpr auto kWindow7d = std::chrono::hours(168); /** - * Protects pending_, window1h_, window24h_, and window7d_. + * Protects pending_, tallied_, talliedOrder_, window1h_, window24h_, + * and window7d_. */ mutable std::mutex mutex_; @@ -296,6 +308,19 @@ private: */ hash_map pending_; + /** + * Ledger hashes already counted into the agreement and missed totals. + * Membership survives eviction from pending_, so a ledger reaches the + * totals once. Holds at most kMaxTalliedEvents hashes. + */ + hash_set tallied_; + + /** + * The hashes in tallied_ in the order they were counted. The front is + * the oldest and is dropped first once the bound is reached. + */ + std::deque talliedOrder_; + /** * Sliding window of reconciled events (last 1 hour). */ @@ -331,6 +356,27 @@ private: */ std::atomic totalValidationsChecked_{0}; + /** + * Locate the pending event for a ledger, creating it on first sight. + * @param ledgerHash Hash of the ledger being recorded. + * @param seq Ledger sequence number, stored only on creation. + * @return Pointer to the event, or nullptr for a ledger that already + * reached the totals and left pending_. The caller records nothing in + * that case. + * @note Called with mutex_ held. + */ + [[nodiscard]] LedgerEvent* + pendingEvent(uint256 const& ledgerHash, LedgerIndex seq); + + /** + * Remember a ledger hash as counted, dropping the oldest remembered + * hash once kMaxTalliedEvents is reached. + * @param ledgerHash Hash of the ledger just counted into the totals. + * @note Called with mutex_ held. + */ + void + noteTallied(uint256 const& ledgerHash); + /** * Remove entries older than their respective window durations. * @param now Current time point. diff --git a/src/xrpld/telemetry/detail/ValidationTracker.cpp b/src/xrpld/telemetry/detail/ValidationTracker.cpp index b198913959..1609cf696c 100644 --- a/src/xrpld/telemetry/detail/ValidationTracker.cpp +++ b/src/xrpld/telemetry/detail/ValidationTracker.cpp @@ -17,35 +17,58 @@ namespace xrpl::telemetry { +ValidationTracker::LedgerEvent* +ValidationTracker::pendingEvent(uint256 const& ledgerHash, LedgerIndex seq) +{ + if (auto const it = pending_.find(ledgerHash); it != pending_.end()) + return &it->second; + + // A hash in tallied_ already reached the totals and left pending_. + // Building a fresh record for it would count the same ledger twice. + if (tallied_.contains(ledgerHash)) + return nullptr; + + auto& evt = pending_[ledgerHash]; + evt.ledgerHash = ledgerHash; + evt.seq = seq; + evt.recordTime = Clock::now(); + return &evt; +} + +void +ValidationTracker::noteTallied(uint256 const& ledgerHash) +{ + if (!tallied_.insert(ledgerHash).second) + return; + + talliedOrder_.push_back(ledgerHash); + while (talliedOrder_.size() > kMaxTalliedEvents) + { + tallied_.erase(talliedOrder_.front()); + talliedOrder_.pop_front(); + } +} + void ValidationTracker::recordOurValidation(uint256 const& ledgerHash, LedgerIndex seq) { std::scoped_lock const lock(mutex_); - auto& evt = pending_[ledgerHash]; - if (evt.recordTime == TimePoint{}) - { - // First time seeing this ledger hash -- initialize. - evt.ledgerHash = ledgerHash; - evt.seq = seq; - evt.recordTime = Clock::now(); - } - evt.weValidated = true; totalValidationsSent_.fetch_add(1, std::memory_order_relaxed); + + // The counter above counts messages, so it also counts a ledger that is + // already tallied. Only the per-ledger record is skipped. + if (auto* const evt = pendingEvent(ledgerHash, seq)) + evt->weValidated = true; } void ValidationTracker::recordNetworkValidation(uint256 const& ledgerHash, LedgerIndex seq) { std::scoped_lock const lock(mutex_); - auto& evt = pending_[ledgerHash]; - if (evt.recordTime == TimePoint{}) - { - evt.ledgerHash = ledgerHash; - evt.seq = seq; - evt.recordTime = Clock::now(); - } - evt.networkValidated = true; totalValidationsChecked_.fetch_add(1, std::memory_order_relaxed); + + if (auto* const evt = pendingEvent(ledgerHash, seq)) + evt->networkValidated = true; } void @@ -61,6 +84,7 @@ ValidationTracker::reconcile() // Initial reconciliation after grace period. evt.reconciled = true; evt.agreed = evt.weValidated && evt.networkValidated; + noteTallied(hash); if (evt.agreed) { From 0f49aecbf0db0ea21e22c89d4a9dd8971d5840b0 Mon Sep 17 00:00:00 2001 From: Pratik Mankawde <3397372+pratikmankawde@users.noreply.github.com> Date: Mon, 7 Sep 2026 14:56:29 +0100 Subject: [PATCH 09/11] docs(telemetry): pass a full dotted constant in the childSpan pseudocode childSpan() takes the span name verbatim, so a bare op:: suffix names the span "process" rather than "rpc.process". The same defect was corrected in the SpanGuard and Telemetry examples; this is the last copy. --- include/xrpl/telemetry/DeterministicIdGenerator.h | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/include/xrpl/telemetry/DeterministicIdGenerator.h b/include/xrpl/telemetry/DeterministicIdGenerator.h index 60d4aa5c4a..390b5b6f84 100644 --- a/include/xrpl/telemetry/DeterministicIdGenerator.h +++ b/include/xrpl/telemetry/DeterministicIdGenerator.h @@ -75,7 +75,7 @@ namespace xrpl::telemetry { * @code * // With an active parent span, startSpan() inherits the parent's trace_id * // and the SDK does NOT call GenerateTraceId(), so no PendingTraceId is used. - * // auto child = parentGuard.childSpan(rpc_span::op::process); // random/parent trace_id + * // auto child = parentGuard.childSpan(rpc_span::prefix::command); // random/parent trace_id * @endcode */ class DeterministicIdGenerator final : public opentelemetry::sdk::trace::IdGenerator From 72372c42dbc55beaa6f82a884d206da42a872c3e Mon Sep 17 00:00:00 2001 From: Pratik Mankawde <3397372+pratikmankawde@users.noreply.github.com> Date: Mon, 7 Sep 2026 14:58:00 +0100 Subject: [PATCH 10/11] fix(telemetry): mark the internal RPC spans Internal rather than Server The category mapped every Rpc span to kServer, so one inbound request emitted several nested server spans. Per the trace spec, SERVER covers server-side handling of a remote request the client awaits, while INTERNAL is an operation with a local parent. rpc.process and both rpc.command sites have a local parent, so they now pass SpanRole::Internal. The four transport-edge roots keep the category default: rpc.http_request, rpc.ws_upgrade, rpc.ws_message and the gRPC span each begin a remote call. This matters to Tempo's service-graph and span-metrics generators, which pair server spans with client spans and leave a surplus one unpaired. --- src/xrpld/rpc/detail/RPCHandler.cpp | 10 +++++++--- src/xrpld/rpc/detail/ServerHandler.cpp | 4 +++- 2 files changed, 10 insertions(+), 4 deletions(-) diff --git a/src/xrpld/rpc/detail/RPCHandler.cpp b/src/xrpld/rpc/detail/RPCHandler.cpp index e3f136c4fe..88c32f1133 100644 --- a/src/xrpld/rpc/detail/RPCHandler.cpp +++ b/src/xrpld/rpc/detail/RPCHandler.cpp @@ -164,8 +164,10 @@ callMethod(JsonContext& context, Method method, std::string const& name, Object& { // Scoped so this command nests under rpc.process and becomes the ambient // parent of any command-internal spans (e.g. pathfind.request). Coro-aware - // storage keeps the scope correct across doRipplePathFind's yield. - auto span = ScopedSpanGuard(TraceCategory::Rpc, rpc_span::prefix::command, name); + // storage keeps the scope correct across doRipplePathFind's yield. Internal + // rather than Server: the inbound boundary is above rpc.process. + auto span = + ScopedSpanGuard(TraceCategory::Rpc, rpc_span::prefix::command, name, SpanRole::Internal); span.setAttribute(rpc_span::attr::command, name.c_str()); span.setAttribute(rpc_span::attr::version, static_cast(context.apiVersion)); span.setAttribute( @@ -282,7 +284,9 @@ doCommand(rpc::JsonContext& context, json::Value& result) // registered handler names (plus "unknown") — see the helper for why // raw request input must not reach the telemetry pipeline. auto const cmdName = resolveCommandSpanName(context); - auto span = ScopedSpanGuard(TraceCategory::Rpc, rpc_span::prefix::command, cmdName); + // Internal for the same reason as the success path above. + auto span = ScopedSpanGuard( + TraceCategory::Rpc, rpc_span::prefix::command, cmdName, SpanRole::Internal); span.setAttribute(rpc_span::attr::command, cmdName); // Mirror the attribute set callMethod() puts on a successful command // span, so error spans stay filterable by API version and role. diff --git a/src/xrpld/rpc/detail/ServerHandler.cpp b/src/xrpld/rpc/detail/ServerHandler.cpp index d896722ee5..e15ed7b10b 100644 --- a/src/xrpld/rpc/detail/ServerHandler.cpp +++ b/src/xrpld/rpc/detail/ServerHandler.cpp @@ -652,7 +652,9 @@ ServerHandler::processRequest( // yield in doRipplePathFind: the coro-aware context storage moves this // scope with the coroutine on resume (it is never stranded on a worker's // thread-local stack), so nesting and log-trace correlation both hold. - auto span = ScopedSpanGuard(TraceCategory::Rpc, rpc_span::prefix::rpc, rpc_span::op::process); + // Internal, not Server: the inbound boundary is rpc.http_request above. + auto span = ScopedSpanGuard( + TraceCategory::Rpc, rpc_span::prefix::rpc, rpc_span::op::process, SpanRole::Internal); auto rpcJ = app_.getJournal("RPC"); // Tracks whether any failure occurred. Set on every error path (early From 161d28b6dd91d6c4009c8fece32bfe1297dec49d Mon Sep 17 00:00:00 2001 From: Pratik Mankawde <3397372+pratikmankawde@users.noreply.github.com> Date: Mon, 7 Sep 2026 15:02:48 +0100 Subject: [PATCH 11/11] test(telemetry): cover the [telemetry] batch-setting bounds Guards the validation the parser gained upstream: zero rejected for all three keys, a non-numeric value raising std::runtime_error rather than leaking boost::bad_lexical_cast, a negative value rejected instead of wrapping to 4294967295, both bounds accepted exactly, and batch_size held at or below max_queue_size. The catch is std::runtime_error, not std::exception, on purpose: if the parser ever stops wrapping, a bad_cast escapes and the suite fails loudly instead of swallowing it. --- .../libxrpl/telemetry/TelemetryConfig.cpp | 203 ++++++++++++++++++ 1 file changed, 203 insertions(+) diff --git a/src/tests/libxrpl/telemetry/TelemetryConfig.cpp b/src/tests/libxrpl/telemetry/TelemetryConfig.cpp index 152511e0a5..bef61c3d25 100644 --- a/src/tests/libxrpl/telemetry/TelemetryConfig.cpp +++ b/src/tests/libxrpl/telemetry/TelemetryConfig.cpp @@ -4,8 +4,85 @@ #include +#include +#include +#include +#include +#include +#include +#include + using namespace xrpl; +namespace { + +/** + * Batch-setting keys of the [telemetry] section. + * + * Spelled once so every case below matches what the parser reads. A + * misspelling cannot hide: the accepting cases would see the default instead + * of the value they wrote, and the rejecting cases would stop rejecting. + */ +namespace key { +constexpr char const* batchSize = "batch_size"; +constexpr char const* batchDelayMs = "batch_delay_ms"; +constexpr char const* maxQueueSize = "max_queue_size"; +} // namespace key + +/** + * The upper bound quoted in the expected messages below. + * + * makeTelemetrySetup() derives it from std::uint32_t, so pin the literal to + * that type here rather than repeating an unanchored number in 5 messages. + */ +static_assert(std::numeric_limits::max() == 4294967295u); + +using KeyValue = std::pair; + +/** + * Parse a [telemetry] section holding only the given keys. + * + * A key that is not listed stays absent, so its default applies. + * + * @param values Key/value pairs to write into the section. + * @return The populated Setup struct. + */ +telemetry::Telemetry::Setup +parseBatch(std::initializer_list values) +{ + Section section; + for (auto const& [name, value] : values) + section.set(name, value); + return telemetry::makeTelemetrySetup(section, "nHUtest123", "2.0.0", 0); +} + +/** + * Parse and return the rejection message. + * + * Only std::runtime_error is caught. A boost::bad_lexical_cast escaping the + * parser derives from std::bad_cast, so it propagates and fails the test + * instead of being mistaken for a clean rejection. That is the point of the + * not-a-number cases. + * + * @param values Key/value pairs to write into the section. + * @return The exception message, or "" if the parse succeeded. + */ +std::string +batchRejection(std::initializer_list values) +{ + try + { + static_cast(parseBatch(values)); + return {}; + } + catch (std::runtime_error const& e) + { + return e.what(); + } +} + +} // namespace + TEST(TelemetryConfig, setup_defaults) { telemetry::Telemetry::Setup const s; @@ -39,6 +116,11 @@ TEST(TelemetryConfig, parse_empty_section) EXPECT_EQ(setup.serviceVersion, "2.0.0"); EXPECT_EQ(setup.serviceInstanceId, "nHUtest123"); EXPECT_DOUBLE_EQ(setup.samplingRatio, 1.0); + // An absent key takes the documented default. setup_defaults covers the + // struct's own initializers; these three cover the parser applying them. + EXPECT_EQ(setup.batchSize, 512u); + EXPECT_EQ(setup.batchDelay, std::chrono::milliseconds{5000}); + EXPECT_EQ(setup.maxQueueSize, 2048u); EXPECT_TRUE(setup.traceRpc); EXPECT_TRUE(setup.traceTransactions); EXPECT_TRUE(setup.traceConsensus); @@ -83,6 +165,127 @@ TEST(TelemetryConfig, parse_full_section) EXPECT_FALSE(setup.traceLedger); } +TEST(TelemetryConfig, batch_settings_accept_the_lower_bound_exactly) +{ + auto const setup = + parseBatch({{key::batchSize, "1"}, {key::batchDelayMs, "1"}, {key::maxQueueSize, "1"}}); + EXPECT_EQ(setup.batchSize, 1u); + EXPECT_EQ(setup.batchDelay, std::chrono::milliseconds{1}); + EXPECT_EQ(setup.maxQueueSize, 1u); +} + +TEST(TelemetryConfig, batch_settings_accept_the_upper_bound_exactly) +{ + auto const setup = parseBatch( + {{key::batchSize, "4294967295"}, + {key::batchDelayMs, "4294967295"}, + {key::maxQueueSize, "4294967295"}}); + EXPECT_EQ(setup.batchSize, 4294967295u); + EXPECT_EQ(setup.batchDelay, std::chrono::milliseconds{4294967295}); + EXPECT_EQ(setup.maxQueueSize, 4294967295u); +} + +TEST(TelemetryConfig, batch_size_zero_is_rejected) +{ + EXPECT_EQ( + batchRejection({{key::batchSize, "0"}}), + "Invalid value 'batch_size' in [telemetry]: must be between 1 and 4294967295."); +} + +TEST(TelemetryConfig, batch_delay_ms_zero_is_rejected) +{ + EXPECT_EQ( + batchRejection({{key::batchDelayMs, "0"}}), + "Invalid value 'batch_delay_ms' in [telemetry]: must be between 1 and 4294967295."); +} + +TEST(TelemetryConfig, max_queue_size_zero_is_rejected) +{ + EXPECT_EQ( + batchRejection({{key::maxQueueSize, "0"}}), + "Invalid value 'max_queue_size' in [telemetry]: must be between 1 and 4294967295."); +} + +TEST(TelemetryConfig, batch_size_not_a_number_is_rejected_as_runtime_error) +{ + // Section::get() reaches boost::lexical_cast, which throws a std::bad_cast. + // Catching only std::runtime_error is the point: this fails unless the + // parser turned that into a message naming the key. + EXPECT_EQ( + batchRejection({{key::batchSize, "abc"}}), + "Invalid value 'batch_size' in [telemetry]: must be a whole number."); +} + +TEST(TelemetryConfig, batch_delay_ms_not_a_number_is_rejected_as_runtime_error) +{ + EXPECT_EQ( + batchRejection({{key::batchDelayMs, "abc"}}), + "Invalid value 'batch_delay_ms' in [telemetry]: must be a whole number."); +} + +TEST(TelemetryConfig, max_queue_size_not_a_number_is_rejected_as_runtime_error) +{ + EXPECT_EQ( + batchRejection({{key::maxQueueSize, "abc"}}), + "Invalid value 'max_queue_size' in [telemetry]: must be a whole number."); +} + +TEST(TelemetryConfig, batch_size_fractional_is_rejected) +{ + // A batch counts spans, so "512.5" must not silently truncate to 512. + EXPECT_EQ( + batchRejection({{key::batchSize, "512.5"}}), + "Invalid value 'batch_size' in [telemetry]: must be a whole number."); +} + +TEST(TelemetryConfig, batch_settings_reject_negative_rather_than_wrapping) +{ + // boost::lexical_cast to an unsigned type turns "-1" into 4294967295 + // instead of failing, so a negative must land on the range check. + EXPECT_EQ( + batchRejection({{key::batchSize, "-1"}}), + "Invalid value 'batch_size' in [telemetry]: must be between 1 and 4294967295."); + EXPECT_EQ( + batchRejection({{key::batchDelayMs, "-1"}}), + "Invalid value 'batch_delay_ms' in [telemetry]: must be between 1 and 4294967295."); + EXPECT_EQ( + batchRejection({{key::maxQueueSize, "-1"}}), + "Invalid value 'max_queue_size' in [telemetry]: must be between 1 and 4294967295."); +} + +TEST(TelemetryConfig, max_queue_size_above_the_upper_bound_is_rejected) +{ + EXPECT_EQ( + batchRejection({{key::maxQueueSize, "4294967296"}}), + "Invalid value 'max_queue_size' in [telemetry]: must be between 1 and 4294967295."); +} + +TEST(TelemetryConfig, batch_size_above_max_queue_size_is_rejected) +{ + // The OTel SDK documents max_export_batch_size <= max_queue_size as a + // precondition and does not enforce it, so the parser must. + EXPECT_EQ( + batchRejection({{key::batchSize, "600"}, {key::maxQueueSize, "512"}}), + "Invalid value 'batch_size' in [telemetry]: must not exceed 'max_queue_size' (512)."); +} + +TEST(TelemetryConfig, batch_size_above_a_lowered_max_queue_size_is_rejected) +{ + // The likely operator mistake: lowering only max_queue_size and leaving + // batch_size at its 512 default. + EXPECT_EQ( + batchRejection({{key::maxQueueSize, "256"}}), + "Invalid value 'batch_size' in [telemetry]: must not exceed 'max_queue_size' (256)."); +} + +TEST(TelemetryConfig, batch_size_equal_to_max_queue_size_is_accepted) +{ + // The cross-check rejects only batchSize > maxQueueSize, so equal passes. + auto const setup = parseBatch({{key::batchSize, "512"}, {key::maxQueueSize, "512"}}); + EXPECT_EQ(setup.batchSize, 512u); + EXPECT_EQ(setup.maxQueueSize, 512u); +} + TEST(TelemetryConfig, null_telemetry_factory) { telemetry::Telemetry::Setup setup;