diff --git a/OpenTelemetryPlan/05-configuration-reference.md b/OpenTelemetryPlan/05-configuration-reference.md index 7e47023f51..cc3a83b347 100644 --- a/OpenTelemetryPlan/05-configuration-reference.md +++ b/OpenTelemetryPlan/05-configuration-reference.md @@ -55,7 +55,7 @@ phases. They will be added as the corresponding subsystems are instrumented: > **TxQ** = Transaction Queue -The parser `setupTelemetry()` in `src/libxrpl/telemetry/TelemetryConfig.cpp` reads the `[telemetry]` `Section` and populates a `Telemetry::Setup` struct, applying the defaults listed in Section 5.1.2 via `section.value_or(...)`. It derives `serviceInstanceId` from the node public key when not overridden, selects the exporter endpoint default by exporter type, and leaves the sampling ratio at its fixed 1.0 default (not read from config — see Section 7.4.2). +The parser `makeTelemetrySetup()` in `src/libxrpl/telemetry/TelemetryConfig.cpp` reads the `[telemetry]` `Section` and populates a `Telemetry::Setup` struct, applying the defaults listed in Section 5.1.2 via `section.value_or(...)`. It derives `serviceInstanceId` from the node public key when not overridden, selects the exporter endpoint default by exporter type, and leaves the sampling ratio at its fixed 1.0 default (not read from config — see Section 7.4.2). --- @@ -69,7 +69,7 @@ The parser `setupTelemetry()` in `src/libxrpl/telemetry/TelemetryConfig.cpp` rea > constructed with an empty `serviceInstanceId` and patched via > `setServiceInstanceId()` once `setup()` has called `getNodeIdentity()`. -`ApplicationImp` (in `src/xrpld/app/main/Application.cpp`) owns a `std::unique_ptr telemetry_`. It is built in the member initializer list via `makeTelemetry(setupTelemetry(...))` with an empty `serviceInstanceId`, then patched in `setup()` by calling `setServiceInstanceId()` with the Base58 node public key (unless the user supplied a custom `service_instance_id`). `start()` and `run()` forward to `telemetry_->start()` / `telemetry_->stop()`, and `getTelemetry()` returns the owned instance. +`ApplicationImp` (in `src/xrpld/app/main/Application.cpp`) owns a `std::unique_ptr telemetry_`. It is built in the member initializer list via `makeTelemetry(makeTelemetrySetup(...))` with an empty `serviceInstanceId`, then patched in `setup()` by calling `setServiceInstanceId()` with the Base58 node public key (unless the user supplied a custom `service_instance_id`). `start()` and `run()` forward to `telemetry_->start()` / `telemetry_->stop()`, and `getTelemetry()` returns the owned instance. ### 5.3.2 ServiceRegistry Interface Addition @@ -135,7 +135,7 @@ flowchart TB end subgraph init["Initialization"] - parse["setupTelemetry()"] + parse["makeTelemetrySetup()"] factory["makeTelemetry()"] end @@ -169,7 +169,7 @@ flowchart TB **Reading the diagram:** - **Configuration Sources**: `xrpld.cfg` provides runtime settings (endpoint, per-component trace toggles) while the CMake flag controls whether telemetry is compiled in at all. Head sampling is fixed at 1.0 and is not a config option; volume reduction happens via tail sampling in the collector. -- **Initialization**: `setupTelemetry()` parses config values, then `makeTelemetry()` constructs the provider, processor, and exporter objects. +- **Initialization**: `makeTelemetrySetup()` parses config values, then `makeTelemetry()` constructs the provider, processor, and exporter objects. - **Runtime Components**: The `TracerProvider` creates spans, the `BatchProcessor` buffers them, and the `OTLP Exporter` serializes and sends them over the wire. - **OTLP arrow to Collector**: Trace data leaves the xrpld process via OTLP/HTTP and enters the external Collector pipeline. (OTLP/gRPC is future work — see design decisions §2.2.2.) - **Collector Pipeline**: `Receivers` ingest OTLP data, `Processors` apply sampling/filtering/enrichment, and `Exporters` forward traces to storage backends (Tempo, etc.). diff --git a/OpenTelemetryPlan/Phase2_taskList.md b/OpenTelemetryPlan/Phase2_taskList.md index 89d9ddd6e0..74d13d54c3 100644 --- a/OpenTelemetryPlan/Phase2_taskList.md +++ b/OpenTelemetryPlan/Phase2_taskList.md @@ -67,7 +67,7 @@ - `src/tests/libxrpl/telemetry/TelemetryConfig.cpp`: - Test Setup defaults (all fields have correct initial values) - - Test `setupTelemetry` config parser (empty section, full section, edge cases) + - Test `makeTelemetrySetup` config parser (empty section, full section, edge cases) - Test `samplingRatio` clamping (values outside 0.0-1.0) - `src/tests/libxrpl/telemetry/SpanGuardFactory.cpp`: diff --git a/src/tests/libxrpl/telemetry/MetricsRegistry.cpp b/src/tests/libxrpl/telemetry/MetricsRegistry.cpp index 1e26926452..6cec383c7a 100644 --- a/src/tests/libxrpl/telemetry/MetricsRegistry.cpp +++ b/src/tests/libxrpl/telemetry/MetricsRegistry.cpp @@ -14,15 +14,17 @@ * on the nodestore_state gauge. Also a public static constexpr inline, * so it runs in both builds for the same reason. * - * 3. The no-op / telemetry-disabled path — construction, start()/stop() - * lifecycle, and the synchronous record*() methods. Guarded, because + * 3. The no-op / telemetry-disabled path — construction, the two-phase + * start() / startAsyncGauges() / stop() lifecycle, and the synchronous + * record*() methods. Guarded, because * when XRPL_ENABLE_TELEMETRY is defined MetricsRegistry.cpp is not * compiled into this binary (see src/tests/libxrpl/CMakeLists.txt) and * its out-of-line symbols are unresolvable here. * * Tests cover: * - Construction with telemetry disabled (no-op behavior). - * - start()/stop() lifecycle when disabled. + * - The two-phase start() / startAsyncGauges() / stop() lifecycle when + * disabled. * - Synchronous instrument recording methods do not crash when disabled. * - Double stop() is safe. * - Destructor handles cleanup without crash. @@ -465,6 +467,7 @@ TEST(MetricsRegistryScaledMean, default_scale_is_one) #include #include #include +#include #include #include @@ -472,6 +475,14 @@ using namespace xrpl; namespace { +/** + * OTLP/HTTP endpoint passed to every start() call below. Nothing ever dials + * it -- these tests exercise the no-op path -- it just has to be a plausible + * URL. start() takes `std::string const&`, so call sites construct one from + * this view rather than repeating the literal. + */ +constexpr std::string_view kTestEndpoint{"http://localhost:4318/v1/metrics"}; + /** * Minimal mock ServiceRegistry for MetricsRegistry testing. * @@ -765,17 +776,108 @@ TEST_F(MetricsRegistryTest, disabled_start_stop) telemetry::MetricsRegistry registry(false, mockApp_, j_); // start() and stop() should be no-ops when disabled. - registry.start("http://localhost:4318/v1/metrics"); + registry.start(std::string{kTestEndpoint}); registry.stop(); // Double stop should be safe. registry.stop(); } +// --------------------------------------------------------------------------- +// The two-phase startup split: start() then startAsyncGauges(). +// +// Why the split exists: start() reads only config strings, while the +// observable-instrument callbacks registered by startAsyncGauges() read live +// Application services (getOverlay() asserts overlay_ is non-null). The split +// lets the meter go live before the first consensus round records its +// mode-transition counter, while the callbacks still wait for the subsystems. +// +// SCOPE OF THESE TESTS -- read before adding to them. MetricsRegistry.cpp is +// compiled into this binary ONLY when telemetry is OFF +// (src/tests/libxrpl/CMakeLists.txt:117-126 -- the `else()` branch; when it is +// ON the .cpp needs concrete xrpld types such as LedgerMaster, TxQ, NetworkOPs, +// Overlay and node_store::Database, which a standalone GTest binary cannot +// link). Both start() and startAsyncGauges() therefore compile here to their +// `#else` branch, which only (void)-casts its arguments. So these tests pin the +// API SURFACE -- that both entry points exist, are callable in either order, +// and leave the object usable -- and NOT the gauge behaviour. Real coverage of +// "gauges observe values only after startAsyncGauges()" is unreachable from +// this target; it needs the enabled path plus an in-memory metric reader. +// +// Two properties the production code does NOT have, so nothing below asserts +// them: startAsyncGauges() has no idempotency guard (a second call on the +// enabled path would create a second set of same-named instruments), and +// callbacksDetached_ is one-way, so detachCallbacks() followed by +// startAsyncGauges() would register permanently-dead instruments. +// --------------------------------------------------------------------------- + +TEST_F(MetricsRegistryTest, async_gauges_start_after_start_is_safe) +{ + telemetry::MetricsRegistry registry(false, mockApp_, j_); + + // The documented order: provider/sync instruments first, gauges second. + registry.start(std::string{kTestEndpoint}); + registry.startAsyncGauges(); + + // State: the enable flag is untouched by either phase. Exact value, not + // merely "falsy" -- a phase that flipped it would be a real defect. + EXPECT_EQ(registry.isEnabled(), false); + + // Synchronous recording must work off phase 1 alone. This is the whole + // point of the split: nothing here needs the gauges to be registered. + registry.recordRpcStarted("server_info"); + registry.recordRpcFinished("server_info", 1000); + + registry.stop(); + EXPECT_EQ(registry.isEnabled(), false); +} + +TEST_F(MetricsRegistryTest, async_gauges_before_start_does_not_break_start) +{ + telemetry::MetricsRegistry registry(false, mockApp_, j_); + + // Negative path: the mis-ordered call, gauges before the provider exists. + // In THIS build it reaches the (void)-cast stub, so what is actually + // proven is only that the entry point tolerates being called first and + // leaves the object usable -- not that the enabled path's `if (!meter_)` + // guard works, since that guard is inside #ifdef XRPL_ENABLE_TELEMETRY and + // is not compiled here. + registry.startAsyncGauges(); + EXPECT_EQ(registry.isEnabled(), false); + + // Phase 1 still works afterwards, so the bad call left no state behind. + registry.start(std::string{kTestEndpoint}); + registry.recordJobQueued("ledgerData", "ProcessLData"); + EXPECT_EQ(registry.isEnabled(), false); + + registry.stop(); +} + +TEST_F(MetricsRegistryTest, async_gauges_respect_the_compile_time_guard) +{ + // Constructed with enabled=true, which on the enabled path would register + // instruments for real. In this build XRPL_ENABLE_TELEMETRY is undefined, + // so both phases compile to the (void)-cast stub branch and neither + // touches the mock -- every MockServiceRegistry accessor throws, so a + // callback that actually ran would surface as a thrown exception here. + telemetry::MetricsRegistry registry(true, mockApp_, j_); + + // Cause, not just state: the flag really is true, so the no-op below is + // attributable to the compile-time guard and not to an early enabled_ + // return. + EXPECT_EQ(registry.isEnabled(), true); + + EXPECT_NO_THROW(registry.start(std::string{kTestEndpoint})); + EXPECT_NO_THROW(registry.startAsyncGauges()); + EXPECT_NO_THROW(registry.stop()); + + EXPECT_EQ(registry.isEnabled(), true); +} + TEST_F(MetricsRegistryTest, disabled_recording_methods) { telemetry::MetricsRegistry registry(false, mockApp_, j_); - registry.start("http://localhost:4318/v1/metrics"); + registry.start(std::string{kTestEndpoint}); // All recording methods should be no-ops (not crash). registry.recordRpcStarted("server_info"); @@ -793,7 +895,7 @@ TEST_F(MetricsRegistryTest, destructor_calls_stop) { // Let the destructor handle cleanup. telemetry::MetricsRegistry registry(false, mockApp_, j_); - registry.start("http://localhost:4318/v1/metrics"); + registry.start(std::string{kTestEndpoint}); } // If we get here without crash, the destructor handled stop. } diff --git a/src/xrpld/app/main/Application.cpp b/src/xrpld/app/main/Application.cpp index d037e325d7..0d44933339 100644 --- a/src/xrpld/app/main/Application.cpp +++ b/src/xrpld/app/main/Application.cpp @@ -1248,28 +1248,56 @@ private: startGenesisLedger(); /** - * Start the tracing and metrics pipelines. + * Start the tracing pipeline and the metrics provider and synchronous + * instruments. First of the two telemetry startup phases. * - * Called once from setup(), just before the [rpc_startup] loop. Starting - * here (rather than in start()) guarantees the OTel MeterProvider is live - * before any metric-emitting code runs — including startup RPCs, whose - * PerfLog instrumentation records a call-site metric. A call-site metric - * macro caches its instrument on first use via std::call_once; if that - * first use happens while the meter is still empty, the instrument latches - * null for the process lifetime and the metric silently never records. + * Called once from setup(), immediately after metricsRegistry_ is + * constructed. Starting here (rather than in start()) guarantees the OTel + * MeterProvider is live before any metric-emitting code runs — including + * the first consensus round, which records a mode-transition counter, and + * the startup RPCs, whose PerfLog instrumentation records a call-site + * metric. A call-site metric macro caches its instrument on first use via + * std::call_once; if that first use happens while the meter is still + * empty, the instrument latches null for the process lifetime and the + * metric silently never records. * - * The call site sits after overlay_ and the other subsystems are - * constructed, because the metrics reader thread starts here and its - * observable-gauge callbacks read that state (e.g. getOverlay()); starting - * earlier would let the reader observe a half-built application. + * Rule for keeping this call site valid: only telemetry work that reads + * NO application subsystem may run here. That holds today — this phase + * uses the config strings and the node identity, and creates only + * push-model counters and histograms, which app code records into once + * it is ready. Anything that registers a callback reading a subsystem + * must go in startTelemetryGauges() instead, because a callback + * registered here can fire on the metrics reader thread while the rest of + * the application is still being built. * * @pre nodeIdentity_ is populated (needed for the service_instance_id - * fallback), metricsRegistry_ is constructed, and overlay_ (and the other - * subsystems read by observable-gauge callbacks) are constructed. + * fallback) and metricsRegistry_ is constructed. */ void startTelemetry(); + /** + * Register the pull-model observable instruments. Second telemetry phase. + * + * Called once from setup(), immediately after overlay_ is constructed. + * Registering an observable instrument arms the metrics reader thread to + * invoke its callback, and those callbacks read application services — + * getOverlay() asserts overlay_ is non-null, and an assert is not caught + * by the callbacks' own try/catch — so this cannot run as early as + * startTelemetry(). + * + * @pre startTelemetry() has run, and every service the callbacks read is + * constructed. overlay_ is the binding one: the rest (networkOPs_, + * ledgerMaster_, openLedger_, txQ_, nodeStore_, nodeFamily_, + * validators_, acceptedLedgerCache_, cachedSLEs_, acquireStats_, + * timeKeeper_, relationalDatabase_, inboundLedgers_, feeTrack_) are + * already live by the time startTelemetry() is callable, and + * overlay_ is the only one built after it. See + * MetricsRegistry::startAsyncGauges() for the full list. + */ + void + startTelemetryGauges(); + std::shared_ptr getLastFullLedger(); @@ -1356,6 +1384,39 @@ ApplicationImp::setup(boost::program_options::variables_map const& cmdline) return false; } + nodeIdentity_ = getNodeIdentity(*this, cmdline); + + // Now that the node identity is known, inject it into the telemetry + // resource attributes — but only if the user didn't already set a + // custom service_instance_id in [telemetry]. The Telemetry object + // was constructed with an empty serviceInstanceId because + // nodeIdentity_ is not available in the member initializer list. + if (!config_->section("telemetry").exists("service_instance_id")) + telemetry_->setServiceInstanceId(toBase58(TokenType::NodePublic, nodeIdentity_->first)); + + // Create the OTel MetricsRegistry for gap-fill metrics (counters, + // histograms, observable gauges). It must exist before startTelemetry(), + // which starts the metrics half of the pipeline. + metricsRegistry_ = std::make_unique( + telemetry_->isEnabled(), *this, logs_->journal("MetricsRegistry")); + + // Start telemetry here, not in start(). Spans and metrics are both emitted + // during the rest of setup() — the first consensus round in + // beginConsensus() below emits spans and records the process's only + // operating-mode transition — and both are dropped unless the pipeline is + // already live. + // + // The position is bounded on both sides: + // - After initRelationalDatabase(): the wallet DB must exist for the node + // identity above, and a DB failure aborts setup(), so starting earlier + // would export a partial stream for a run that never comes up. + // - Before beginConsensus(): that call emits the first consensus spans + // and the only mode-transition counter increment. + // + // Only the observable instruments have to wait for their subsystems; they + // are registered separately by startTelemetryGauges() once overlay_ exists. + startTelemetry(); + if (validatorKeys_.keys) setMaxDisallowedLedger(); @@ -1443,22 +1504,6 @@ ApplicationImp::setup(boost::program_options::variables_map const& cmdline) orderBookDB_->setup(getLedgerMaster().getCurrentLedger()); - nodeIdentity_ = getNodeIdentity(*this, cmdline); - - // Now that the node identity is known, inject it into the telemetry - // resource attributes — but only if the user didn't already set a - // custom service_instance_id in [telemetry]. The Telemetry object - // was constructed with an empty serviceInstanceId because - // nodeIdentity_ is not available in the member initializer list. - if (!config_->section("telemetry").exists("service_instance_id")) - telemetry_->setServiceInstanceId(toBase58(TokenType::NodePublic, nodeIdentity_->first)); - - // Create the OTel MetricsRegistry for gap-fill metrics (counters, - // histograms, observable gauges). It is started later, just before the - // [rpc_startup] loop (see startTelemetry()). - metricsRegistry_ = std::make_unique( - telemetry_->isEnabled(), *this, logs_->journal("MetricsRegistry")); - if (!cluster_->load(config().section(Sections::kClusterNodes))) { JLOG(journal_.fatal()) << "Invalid entry in cluster configuration."; @@ -1534,6 +1579,15 @@ ApplicationImp::setup(boost::program_options::variables_map const& cmdline) collectorManager_->collector()); add(*overlay_); // add to PropertyStream + // Register the observable instruments now that overlay_ exists. This arms + // the metrics reader thread to invoke their callbacks, several of which + // read getOverlay() — registering earlier would let the reader observe a + // half-built application. The reader thread itself already started in + // startTelemetry() above; this is as early as the callbacks can safely be + // attached, and it is still before beginConsensus() so the gauges cover + // the first round. + startTelemetryGauges(); + // start first consensus round if (!networkOPs_->beginConsensus(ledgerMaster_->getClosedLedger()->header().hash, {})) { @@ -1600,16 +1654,6 @@ ApplicationImp::setup(boost::program_options::variables_map const& cmdline) JLOG(journal_.warn()) << "*** standalone signing solution as soon as possible."; } - // Start telemetry and metrics now — before the [rpc_startup] loop below — - // so the OTel meter is live before any metric-emitting code runs. Startup - // RPCs invoke PerfLog instrumentation that records a call-site metric; a - // metric macro caches its instrument on first use, so a first use before - // the meter exists would latch null for the process lifetime. Placed here, - // after overlay_ and the other subsystems the observable-gauge callbacks - // read are constructed, so the metrics reader thread never observes a - // half-built application. - startTelemetry(); - // // Execute start up rpc commands. // @@ -1708,6 +1752,13 @@ ApplicationImp::startTelemetry() } } +void +ApplicationImp::startTelemetryGauges() +{ + if (metricsRegistry_) + metricsRegistry_->startAsyncGauges(); +} + void ApplicationImp::run() { diff --git a/src/xrpld/rpc/detail/PathFindSpanNames.h b/src/xrpld/rpc/detail/PathFindSpanNames.h index 65ce81bb96..6d8fedc7ab 100644 --- a/src/xrpld/rpc/detail/PathFindSpanNames.h +++ b/src/xrpld/rpc/detail/PathFindSpanNames.h @@ -65,10 +65,13 @@ inline constexpr auto discover = makeStr("discover"); } // namespace op // ===== Attribute keys ====================================================== -// -// All pathfind attributes are namespaced under `pathfind_*` (underscore form, -// per Phase 1c naming spec rule 5). Avoids collisions with bare keys like -// `fast` or `num_paths` that other subsystems may introduce. + +/** + * All pathfind attributes are namespaced under `pathfind_*`, in underscore + * form, per the span attribute naming convention in CONTRIBUTING.md. Avoids + * collisions with bare keys like `fast` or `num_paths` that other subsystems + * may introduce. + */ namespace attr { /** diff --git a/src/xrpld/rpc/detail/PathRequest.cpp b/src/xrpld/rpc/detail/PathRequest.cpp index 28a6ad3c5c..155f9e28d0 100644 --- a/src/xrpld/rpc/detail/PathRequest.cpp +++ b/src/xrpld/rpc/detail/PathRequest.cpp @@ -35,6 +35,7 @@ #include #include #include +#include #include #include @@ -587,9 +588,13 @@ PathRequest::findPaths( // that a single RPC call produces one discover span instead of N (one per // candidate source asset). Trade-off: per-asset discovery/ranking timing // is no longer split into individual spans — span count and Tempo storage - // are bounded per RPC at the cost of per-asset visibility. If per-asset - // breakdown is needed in the future, add child spans inside the loop body - // (`Pathfinder::findPaths`/`computePathRanks`) parented off this span. + // are bounded per RPC at the cost of per-asset visibility. + // + // This is an unscoped guard: it takes the ambient span as its own parent, + // but does not itself become the ambient parent. Adding per-asset child + // spans inside the loop body therefore requires either making this a + // ScopedSpanGuard or passing its context explicitly via childSpan(); a + // child created here today would parent to this span's parent, not to it. using namespace telemetry; auto span = SpanGuard::span( TraceCategory::Rpc, pathfind_span::prefix::pathfind, pathfind_span::op::discover); @@ -744,7 +749,20 @@ PathRequest::doUpdate( auto span = ScopedSpanGuard( TraceCategory::Rpc, pathfind_span::prefix::pathfind, pathfind_span::op::compute); span.setAttribute(pathfind_span::attr::fast, fast); - span.setAttribute(pathfind_span::attr::destCurrency, to_string(saDstAmount_.asset()).c_str()); + // to_string(Issue) renders a non-XRP asset as "/" with the + // issuer as a plaintext Base58 address, so it cannot be emitted as-is: every + // account reaching a span is hashed first. Redact just the issuer and keep + // the currency, which is what this attribute is for. An MPT asset renders as + // its issuance ID and carries no address, so it needs no redaction. + span.setAttribute( + pathfind_span::attr::destCurrency, + saDstAmount_.asset().visit( + [](Issue const& issue) { + return isXRP(issue.account) + ? to_string(issue.currency) + : redactAccount(toBase58(issue.account)) + "/" + to_string(issue.currency); + }, + [](MPTIssue const& mpt) { return to_string(mpt.getMptID()); })); JLOG(journal_.debug()) << iIdentifier_ << " update " << (fast ? "fast" : "normal"); diff --git a/src/xrpld/rpc/detail/PathRequestManager.cpp b/src/xrpld/rpc/detail/PathRequestManager.cpp index 9141aaded4..c8c6c12fc2 100644 --- a/src/xrpld/rpc/detail/PathRequestManager.cpp +++ b/src/xrpld/rpc/detail/PathRequestManager.cpp @@ -23,6 +23,7 @@ #include #include #include +#include #include #include @@ -77,15 +78,21 @@ PathRequestManager::updateAll(std::shared_ptr const& inLedger) using namespace telemetry; // updateAll runs on every ledger close. Skip span emission when there are // no active path subscriptions, to avoid a steady stream of empty spans at - // mainnet close cadence. A null guard is used in that case; all other work - // still runs unchanged (notably the isNewPathRequest() flag reset below), - // so behaviour matches the pre-span code path. - auto span = requests.empty() - ? SpanGuard{} - : SpanGuard::span( - TraceCategory::Rpc, pathfind_span::prefix::pathfind, pathfind_span::op::updateAll); - span.setAttribute(pathfind_span::attr::ledgerIndex, static_cast(inLedger->seq())); - span.setAttribute(pathfind_span::attr::numRequests, static_cast(requests.size())); + // mainnet close cadence. All other work still runs unchanged (notably the + // isNewPathRequest() flag reset below), so behaviour matches the pre-span + // code path. + // + // Scoped, so the pathfind.compute spans that doUpdate() creates below on + // this thread nest under it. std::optional because ScopedSpanGuard is + // deliberately non-movable, so it cannot be produced by a ternary. + std::optional span; + if (!requests.empty()) + { + span.emplace( + TraceCategory::Rpc, pathfind_span::prefix::pathfind, pathfind_span::op::updateAll); + span->setAttribute(pathfind_span::attr::ledgerIndex, static_cast(inLedger->seq())); + span->setAttribute(pathfind_span::attr::numRequests, static_cast(requests.size())); + } bool newRequests = app_.getLedgerMaster().isNewPathRequest(); bool mustBreak = false; diff --git a/src/xrpld/rpc/detail/ServerHandler.cpp b/src/xrpld/rpc/detail/ServerHandler.cpp index 25bacc6d73..c12e50fd95 100644 --- a/src/xrpld/rpc/detail/ServerHandler.cpp +++ b/src/xrpld/rpc/detail/ServerHandler.cpp @@ -4,6 +4,7 @@ #include #include #include +#include #include #include #include @@ -107,6 +108,42 @@ statusRequestResponse(http_request_type const& request, boost::beast::http::stat return handoff; } +/** + * Resolve the command attribute for a WebSocket message to a bounded value. + * + * The command/method field is client-supplied and is promoted to a Prometheus + * label by the spanmetrics connector, so the raw string must never be emitted: + * arbitrary request input would drive unbounded label cardinality. Resolving + * against the handler registry keeps per-command attribution for real commands + * and collapses everything else to a single "unknown" series. + * + * A request naming both fields with different values is not a real command + * (processSession rejects it below), so it also resolves to "unknown". + * + * @param jv The parsed WebSocket request object. + * @param config Node config, for the beta-RPC-API flag used to look up the + * handler for the request's API version. + * @return The canonical handler name, or "unknown" for an unrecognized, + * missing, non-string, or self-contradictory command. + */ +static std::string_view +resolveWsCommandSpanName(json::Value const& jv, Config const& config) +{ + bool const hasCommand = jv.isMember(jss::command) && jv[jss::command].isString(); + bool const hasMethod = jv.isMember(jss::method) && jv[jss::method].isString(); + if (!hasCommand && !hasMethod) + return rpc_span::val::unknownCommand; + + std::string const cmd = hasCommand ? jv[jss::command].asString() : jv[jss::method].asString(); + if (hasCommand && hasMethod && cmd != jv[jss::method].asString()) + return rpc_span::val::unknownCommand; + + auto const* handler = + RPC::getHandler(RPC::getAPIVersionNumber(jv, config.betaRpcApi), config.betaRpcApi, cmd); + return (handler != nullptr) ? std::string_view{handler->name} + : std::string_view{rpc_span::val::unknownCommand}; +} + // VFALCO TODO Rewrite to use boost::beast::http::fields static bool authorized(Port const& port, std::map const& h) @@ -434,14 +471,13 @@ ServerHandler::processSession( // Fresh root so each WS message is its own trace. auto span = ScopedSpanGuard::freshRoot( TraceCategory::Rpc, rpc_span::prefix::rpc, rpc_span::op::wsMessage); - if (jv.isMember(jss::command) && jv[jss::command].isString()) - { - span.setAttribute(rpc_span::attr::command, jv[jss::command].asString().c_str()); - } - else if (jv.isMember(jss::method) && jv[jss::method].isString()) - { - span.setAttribute(rpc_span::attr::command, jv[jss::method].asString().c_str()); - } + // The command is client-supplied and becomes a Prometheus label via the + // spanmetrics connector, so it is resolved against the handler registry + // before emission: a recognized command keeps its canonical name, anything + // else collapses to "unknown". Emitting the raw string would let request + // input drive unbounded label cardinality. Mirrors the HTTP path's + // resolveCommandSpanName(). + span.setAttribute(rpc_span::attr::command, resolveWsCommandSpanName(jv, app_.config())); auto is = std::static_pointer_cast(session->appDefined); if (is->getConsumer().disconnect(journal_)) diff --git a/src/xrpld/rpc/handlers/orderbook/PathFind.cpp b/src/xrpld/rpc/handlers/orderbook/PathFind.cpp index bf7fdfe264..9053fdda90 100644 --- a/src/xrpld/rpc/handlers/orderbook/PathFind.cpp +++ b/src/xrpld/rpc/handlers/orderbook/PathFind.cpp @@ -13,6 +13,8 @@ #include #include +#include + namespace xrpl { json::Value @@ -23,10 +25,15 @@ doPathFind(RPC::JsonContext& context) // thread) nest under it. doPathFind does not yield, so scoping is safe. auto span = ScopedSpanGuard( TraceCategory::Rpc, pathfind_span::prefix::pathfind, pathfind_span::op::request); - // Addresses are hashed before emission for privacy. - if (auto const& src = context.params[jss::source_account]; src.isString()) + // Addresses are hashed before emission for privacy. Read through a const + // reference: the non-const json::Value::operator[] inserts a null for a + // missing key, which would make PathRequest::parseJson's isMember() checks + // see an absent field as present and return Malformed instead of Missing. + // Reading for telemetry must not alter what the request looks like. + auto const& params = std::as_const(context.params); + if (auto const& src = params[jss::source_account]; src.isString()) span.setAttribute(pathfind_span::attr::sourceAccount, redactAccount(src.asString())); - if (auto const& dst = context.params[jss::destination_account]; dst.isString()) + if (auto const& dst = params[jss::destination_account]; dst.isString()) span.setAttribute(pathfind_span::attr::destAccount, redactAccount(dst.asString())); if (context.app.config().pathSearchMax == 0) diff --git a/src/xrpld/rpc/handlers/orderbook/RipplePathFind.cpp b/src/xrpld/rpc/handlers/orderbook/RipplePathFind.cpp index f65a41a911..b264fde9ef 100644 --- a/src/xrpld/rpc/handlers/orderbook/RipplePathFind.cpp +++ b/src/xrpld/rpc/handlers/orderbook/RipplePathFind.cpp @@ -34,10 +34,15 @@ doRipplePathFind(RPC::JsonContext& context) // span's log lines stay trace-correlated. auto span = ScopedSpanGuard( TraceCategory::Rpc, pathfind_span::prefix::pathfind, pathfind_span::op::request); - // Addresses are hashed before emission for privacy. - if (auto const& src = context.params[jss::source_account]; src.isString()) + // Addresses are hashed before emission for privacy. Read through a const + // reference: the non-const json::Value::operator[] inserts a null for a + // missing key, which would make PathRequest::parseJson's isMember() checks + // see an absent field as present and return Malformed instead of Missing. + // Reading for telemetry must not alter what the request looks like. + auto const& params = std::as_const(context.params); + if (auto const& src = params[jss::source_account]; src.isString()) span.setAttribute(pathfind_span::attr::sourceAccount, redactAccount(src.asString())); - if (auto const& dst = context.params[jss::destination_account]; dst.isString()) + if (auto const& dst = params[jss::destination_account]; dst.isString()) span.setAttribute(pathfind_span::attr::destAccount, redactAccount(dst.asString())); if (context.app.config().pathSearchMax == 0) diff --git a/src/xrpld/telemetry/MetricsRegistry.cpp b/src/xrpld/telemetry/MetricsRegistry.cpp index af0e3291ab..412dbe240e 100644 --- a/src/xrpld/telemetry/MetricsRegistry.cpp +++ b/src/xrpld/telemetry/MetricsRegistry.cpp @@ -255,14 +255,45 @@ MetricsRegistry::start(std::string const& endpoint, std::string const& instanceI JLOG(journal_.info()) << "MetricsRegistry: starting, endpoint=" << endpoint << ", instanceId=" << instanceId; + // Rule for anything added below: this phase may create only instruments + // whose recording is PUSHED from app code -- counters and histograms. An + // instrument registered here is live immediately, and the reader thread + // may invoke a registered callback before the rest of the Application is + // built, so any observable whose callback reads an Application service + // belongs in startAsyncGauges(), not here. That includes observable + // COUNTERS, not just gauges: jq_trans_overflow_total was created here and + // its callback read getOverlay(), which asserts overlay_ is non-null. initExporterAndProvider(endpoint, instanceId); initSyncInstruments(); + + JLOG(journal_.info()) << "MetricsRegistry: provider and instruments ready"; +#else + (void)endpoint; + (void)instanceId; + (void)enabled_; +#endif // XRPL_ENABLE_TELEMETRY +} + +void +MetricsRegistry::startAsyncGauges() +{ +#ifdef XRPL_ENABLE_TELEMETRY + if (!enabled_) + return; + + // A mis-ordered call must not crash: without a meter there is nothing to + // create instruments on, so registration is skipped entirely. + if (!meter_) + { + JLOG(journal_.warn()) << "MetricsRegistry: startAsyncGauges() called " + "before start(); no gauges registered"; + return; + } + registerAsyncGauges(); JLOG(journal_.info()) << "MetricsRegistry: started successfully"; #else - (void)endpoint; - (void)instanceId; (void)enabled_; #endif // XRPL_ENABLE_TELEMETRY } @@ -428,30 +459,6 @@ MetricsRegistry::initSyncInstruments() // (NetworkOPsImp::setMode) through XRPL_METRIC_COUNTER_INC_LABELED so it // can carry the {from,to} transition labels; a registry-owned instrument // would only give an unlabelled total. - // jq_trans_overflow_total is observed from Overlay's existing cumulative - // atomic (Overlay::getJqTransOverflow()) rather than pushed. The overlay - // owns the only increment site (PeerImp), so an ObservableCounter reads the - // live total each collection cycle without threading a push path through - // develop-owned overlay code. - jqTransOverflowObservable_ = meter_->CreateInt64ObservableCounter( - "jq_trans_overflow_total", "Total job queue transaction overflows"); - jqTransOverflowObservable_->AddCallback( - [](opentelemetry::metrics::ObserverResult result, void* state) { - auto* self = static_cast(state); - if (self->callbacksDetached_.load(std::memory_order_acquire)) - return; - try - { - opentelemetry::nostd::get>>(result) - ->Observe(static_cast(self->app_.getOverlay().getJqTransOverflow())); - } - catch (...) // NOLINT(bugprone-empty-catch) - { - // Silently skip on error. - } - }, - this); ledgerHistoryMismatchCounter_ = meter_->CreateUInt64Counter( metric::ledgerHistoryMismatchTotal, "Total built-vs-validated ledger mismatches by reason"); txqExpiredCounter_ = meter_->CreateUInt64Counter( @@ -652,6 +659,7 @@ MetricsRegistry::registerAsyncGauges() // Each helper creates one observable instrument and attaches one // callback. Keeping the registration bodies in separate methods // preserves the 80-line-per-function limit enforced by CLAUDE.md. + registerJqTransOverflowCounter(); registerCacheHitRateGauge(); registerTxqGauge(); registerObjectCountGauge(); @@ -683,6 +691,40 @@ MetricsRegistry::registerAsyncGauges() registerLedgerQuorumPublishGauge(); } +void +MetricsRegistry::registerJqTransOverflowCounter() +{ + // jq_trans_overflow_total is observed from Overlay's existing cumulative + // atomic (Overlay::getJqTransOverflow()) rather than pushed. The overlay + // owns the only increment site (PeerImp), so an ObservableCounter reads the + // live total each collection cycle without threading a push path through + // develop-owned overlay code. + // + // Registered with the gauges, not with the synchronous instruments: the + // callback reads getOverlay(), which asserts overlay_ is non-null. Arming + // it any earlier would let a reader tick fire before the overlay exists, + // and an assert is not caught by the try block below. + jqTransOverflowObservable_ = meter_->CreateInt64ObservableCounter( + "jq_trans_overflow_total", "Total job queue transaction overflows"); + jqTransOverflowObservable_->AddCallback( + [](opentelemetry::metrics::ObserverResult result, void* state) { + auto* self = static_cast(state); + if (self->callbacksDetached_.load(std::memory_order_acquire)) + return; + try + { + opentelemetry::nostd::get>>(result) + ->Observe(static_cast(self->app_.getOverlay().getJqTransOverflow())); + } + catch (...) // NOLINT(bugprone-empty-catch) + { + // Silently skip on error. + } + }, + this); +} + void MetricsRegistry::registerCacheHitRateGauge() { @@ -1534,14 +1576,13 @@ MetricsRegistry::registerLedgerEconomyGauge() ->Observe(value, {{label::metric, name}}); }; - // Local fee (drops). - observe("base_fee_xrp", static_cast(app.getFeeTrack().getLocalFee())); - - // Reserve values from the validated ledger. + // Fee and reserve values from the validated ledger. auto const ledger = app.getLedgerMaster().getValidatedLedger(); if (ledger) { auto const& fees = ledger->fees(); + // Cost of a reference transaction (drops). + observe("base_fee_xrp", static_cast(fees.base.drops())); // Base reserve = one account, zero owned objects: // accountReserve(ownerCount=0, accountCount=1) == reserve. observe( diff --git a/src/xrpld/telemetry/MetricsRegistry.h b/src/xrpld/telemetry/MetricsRegistry.h index ee77c9c9ee..bd44796ff5 100644 --- a/src/xrpld/telemetry/MetricsRegistry.h +++ b/src/xrpld/telemetry/MetricsRegistry.h @@ -104,11 +104,17 @@ * Example usage: * * @code - * // In Application::setup(), after telemetry_ is created: + * // In Application::setup(), after telemetry_ is created. Phase 1 needs + * // only the config strings, so it runs immediately and the meter is live + * // before any metric-emitting code: * metricsRegistry_ = std::make_unique( * telemetry_->isEnabled(), app, journal); * metricsRegistry_->start(setup.exporterEndpoint); * + * // Later in setup(), once overlay_ exists (the last of the services the + * // callbacks read). Phase 2 registers the observable instruments: + * metricsRegistry_->startAsyncGauges(); + * * // In PerfLogImp::rpcStart(): * if (auto* mr = app_.getMetricsRegistry()) * mr->recordRpcStarted("server_info"); @@ -217,9 +223,9 @@ namespace telemetry { * catch-all try block so a transient failure never crashes * the reader thread. * - ValidationTracker protects its rolling windows internally. - * - start() and stop() are NOT thread-safe with each other and - * must be called from the single Application lifecycle - * thread. + * - start(), startAsyncGauges() and stop() are NOT thread-safe + * with each other and must all be called, in that order, from + * the single Application lifecycle thread. * * @note Lifetime: * - Must be constructed AFTER telemetry_ (reads isEnabled()). @@ -264,7 +270,24 @@ public: operator=(MetricsRegistry const&) = delete; /** - * Initialize the OTel metrics pipeline and register all instruments. + * Initialize the OTel metrics pipeline and create the SYNCHRONOUS + * instruments (counters and histograms). + * + * This is the first of two startup phases, and it can be called as soon + * as the registry is constructed — which is what makes the meter live + * before the first metric-emitting code runs. Startup RPCs and the first + * consensus round both record metrics; a call-site metric macro caches + * its instrument on first use, so a first use before the meter exists + * latches null for the process lifetime. + * + * @note Invariant for future changes: this phase may create only + * instruments with NO Application-reading callback. Push-model + * counters and histograms qualify; app code records into them + * when it is ready. Any observable instrument whose callback + * reads an Application service belongs in `startAsyncGauges()`, + * because registering it here arms the reader thread to invoke + * that callback against a half-built Application. This applies + * to observable COUNTERS as well as gauges. * * @param endpoint OTLP/HTTP endpoint URL for metric export * (e.g. "http://localhost:4318/v1/metrics"). @@ -276,6 +299,37 @@ public: void start(std::string const& endpoint, std::string const& instanceId = {}); + /** + * Register the pull-model observable instruments — the second startup + * phase. Mostly ObservableGauges, plus the ObservableCounters whose + * source value is already cumulative. + * + * Split from `start()` because the two halves have different + * prerequisites. `start()` needs only config strings; these callbacks + * read live Application services, so this half must run later. + * Registering an observable also arms the reader thread to invoke its + * callback on the next tick, which is why the split is about ordering + * and not just tidiness. + * + * @pre `start()` has already run (the meter exists). If it has not, + * this is a logged no-op rather than a crash. + * @pre Every service the callbacks read is constructed. The full set, + * from the `app.get*()` calls in the registration helpers, is: + * Overlay, OPs (NetworkOPs), LedgerMaster, OpenLedger, TxQ, + * NodeStore, NodeFamily, Validators, AcceptedLedgerCache, + * CachedSLEs, AcquireStats, TimeKeeper, RelationalDatabase, + * InboundLedgers and FeeTrack. + * All but Overlay already exist by the time `start()` is + * callable, so Overlay is what fixes this call's position: + * `ServiceRegistry::getOverlay()` `XRPL_ASSERT`s that + * `overlay_` is non-null, and a reader-thread tick before the + * overlay exists aborts a Debug build. The callbacks' catch-all + * try block does not catch an assert. `getTxQ()` and + * `getRelationalDatabase()` assert likewise. + */ + void + startAsyncGauges(); + /** * Detach all ObservableGauge callbacks so they no-op on the next * reader-thread tick. @@ -287,9 +341,15 @@ public: * guarantees that once `detachCallbacks()` returns, no subsequent * callback invocation will dereference an already-stopped service. * - * Idempotent. Safe to call multiple times. Safe to call before - * `start()` (has no effect). The actual SDK-level provider - * shutdown still happens in `stop()`. + * Idempotent, and safe to call multiple times: the flag is one-way, + * only ever set to true, and nothing clears it. The actual + * SDK-level provider shutdown still happens in `stop()`. + * + * @note One-way means this is a shutdown-only call. Calling it before + * `startAsyncGauges()` does not "have no effect" — it + * permanently disarms every gauge the later call registers, so + * the instruments exist but never observe a value. Only call it + * once the process is shutting down. */ void detachCallbacks() noexcept; @@ -1019,15 +1079,22 @@ private: * Register all observable gauge callbacks with the OTel SDK. * Dispatches to one helper per metric domain so that each helper * stays well under the 80-line-per-function limit. + * + * Called only from `startAsyncGauges()`, which owns the enabled_ and + * meter_ guards and the Application-state precondition. */ void registerAsyncGauges(); - // Per-domain gauge registration helpers. Each creates its instrument - // and attaches a single ObservableGauge callback that reads current - // values from Application services. The callbacks run on the OTel + // Per-domain registration helpers for the async (pull-model) phase. + // Each creates its instrument -- an ObservableGauge, or an + // ObservableCounter where the underlying value is cumulative -- and + // attaches a single callback that reads current values from Application + // services. The callbacks run on the OTel // PeriodicExportingMetricReader background thread (~10 s tick). void + registerJqTransOverflowCounter(); // gap-fill: overlay overflow total + void registerCacheHitRateGauge(); // Task 9.2 void registerTxqGauge(); // Task 9.3