diff --git a/.github/scripts/levelization/results/ordering.txt b/.github/scripts/levelization/results/ordering.txt index 8cc20d8fba..200bc1d082 100644 --- a/.github/scripts/levelization/results/ordering.txt +++ b/.github/scripts/levelization/results/ordering.txt @@ -203,6 +203,7 @@ tests.libxrpl > xrpl.nodestore tests.libxrpl > xrpl.peerfinder tests.libxrpl > xrpl.protocol tests.libxrpl > xrpl.protocol_autogen +tests.libxrpl > xrpl.rdb tests.libxrpl > xrpl.resource tests.libxrpl > xrpl.server tests.libxrpl > xrpl.shamap diff --git a/.github/scripts/telemetry/test_check_regression_bounds.py b/.github/scripts/telemetry/test_check_regression_bounds.py index 44222e6576..896829d03b 100644 --- a/.github/scripts/telemetry/test_check_regression_bounds.py +++ b/.github/scripts/telemetry/test_check_regression_bounds.py @@ -247,7 +247,7 @@ class TestRules(CheckerCase): """A hand-edited bound that is a string must be named, not raise.""" self.edit_json( THRESHOLDS, - lambda d: d["overrides"]["span.ledger.build"]["p99"].update( + lambda d: d["overrides"]["span.ledger.build"]["p95"].update( max_abs_increase_ms="5.5" ), ) diff --git a/.github/workflows/reusable-check-otel-naming.yml b/.github/workflows/reusable-check-otel-naming.yml index 4f0e39bc3f..4bec030a8a 100644 --- a/.github/workflows/reusable-check-otel-naming.yml +++ b/.github/workflows/reusable-check-otel-naming.yml @@ -75,3 +75,4 @@ jobs: run: | python3 docker/telemetry/workload/test_validate_telemetry.py python3 docker/telemetry/workload/test_capture_timings.py + python3 docker/telemetry/workload/test_tx_submitter.py diff --git a/OpenTelemetryPlan/05-configuration-reference.md b/OpenTelemetryPlan/05-configuration-reference.md index 41796b3590..967f79a96c 100644 --- a/OpenTelemetryPlan/05-configuration-reference.md +++ b/OpenTelemetryPlan/05-configuration-reference.md @@ -13,56 +13,43 @@ The authoritative `[telemetry]` example lives in `cfg/xrpld-example.cfg`. Telemetry is disabled by default (`enabled=0`); enabling it turns on distributed tracing for transaction flow, consensus, and RPC calls, with traces exported to an OpenTelemetry Collector over OTLP. Head sampling is intentionally fixed at 1.0 (sample everything) and is not configurable — per-node head-sampling would produce broken/partial distributed traces, so volume reduction is delegated to the collector's tail sampling (see Section 7.4.2). Transaction trace IDs are always deterministic (`trace_id = txHash[0:16]`); there is no strategy switch for the transaction path. The full option reference follows. -> **`service_instance_id` is effectively required for `beast::insight` -> metrics — and only for those.** Three producers resolve the instance id -> independently, and exactly one of them lacks a node-key fallback: +> **`service_instance_id` defaults to the node public key for every producer.** +> `Main.cpp` resolves the identity before `ApplicationImp` is constructed and it +> is never empty, so all three producers below stamp the node key when the config +> key is unset. They still build their resources at three different times, which +> is what decides how each behaves if the identity ever changes mid-run: > -> | Producer | Resource built by | Unset `service_instance_id` yields | -> | ------------------------------------------- | -------------------------------------------- | ---------------------------------------------- | -> | Traces (and therefore all `span_*` metrics) | `Telemetry::start()` | Base58 node public key | -> | Native `XRPL_METRIC_*` (`MetricsRegistry`) | `MetricsRegistry::initExporterAndProvider()` | Base58 node public key | -> | `beast::insight` (`[insight] server=otel`) | `TelemetryImpl` **constructor** | **`service.instance.id` absent** — no fallback | +> | Producer | Resource built by | Unset `service_instance_id` yields | +> | ------------------------------------------- | -------------------------------------------- | ---------------------------------- | +> | Traces (and therefore all `span_*` metrics) | `Telemetry::start()`, during `setup()` | Base58 node public key | +> | Native `XRPL_METRIC_*` (`MetricsRegistry`) | `MetricsRegistry::initExporterAndProvider()` | Base58 node public key | +> | `beast::insight` (`[insight] server=otel`) | `TelemetryImpl` **constructor** | Base58 node public key | > -> - **Traces**: the tracer resource is built in `Telemetry::start()` -> (`Telemetry.cpp:380-387`), which runs after `ApplicationImp::setup()` has -> called `setServiceInstanceId()` (`Application.cpp:1323`) with the Base58 -> node public key. An unset key therefore still yields the node key. The -> `spanmetrics` connector derives `span_calls_total` / -> `span_duration_milliseconds_*` from those spans, so span metrics inherit -> the correct id too. -> - **Native `XRPL_METRIC_*` metrics** build their **own** MeterProvider -> resource in `MetricsRegistry::initExporterAndProvider()` -> (`MetricsRegistry.cpp:280`, `:296-304`, provider created at `:339`), and -> `ApplicationImp::startTelemetry()` supplies the id with an explicit node-key -> fallback (`Application.cpp:1674-1679`: read the config key, and -> `if (instanceId.empty() && nodeIdentity_)` substitute -> `toBase58(TokenType::NodePublic, …)`). By then `setup()` has resolved -> `nodeIdentity_` (`Application.cpp:1315`), so these metrics carry the node -> key even with the config key unset. -> - **`beast::insight` metrics** are the exception. They use the **global** -> MeterProvider, whose resource is built in the `TelemetryImpl` -> **constructor** (`Telemetry.cpp:321-338`, `initMetrics()` at `:447`), -> because insight instruments are created eagerly in subsystem constructors -> and would otherwise bind to the noop provider forever. At that point -> `serviceInstanceId` is still `""` (`Application.cpp:348` passes an empty -> node key), and the code comment at `Telemetry.cpp:333-336` states plainly -> that the later setter "cannot change this immutable resource". Worse, -> `initMetrics()` sets the attribute **unconditionally** -> (`Telemetry.cpp:488`), so the resource carries `service.instance.id=""` -> rather than omitting it — whereas `MetricsRegistry` guards the same write -> with `if (!instanceId.empty())` (`MetricsRegistry.cpp:302-303`). +> - **Traces**: the tracer resource is built in `Telemetry::start()`, which runs +> inside `setup()` after `getNodeIdentity()` has persisted the identity, so it +> is the one resource that can still be corrected by +> `setServiceInstanceId()`. The `spanmetrics` connector derives +> `span_calls_total` / `span_duration_milliseconds_*` from those spans, so span +> metrics inherit the same id. +> - **Native `XRPL_METRIC_*` metrics** build their **own** MeterProvider resource +> in `MetricsRegistry::initExporterAndProvider()`, called from the registry's +> constructor. `makeMetricsRegistryOptions()` in `Application.cpp` supplies the +> id: the config key when set, else the resolved node key. +> - **`beast::insight` metrics** use the **global** MeterProvider, whose resource +> is built in the `TelemetryImpl` **constructor**, because insight instruments +> are created eagerly in subsystem constructors and would otherwise bind to the +> noop provider forever. It receives the same resolved key. Note it writes the +> attribute **unconditionally**, where `MetricsRegistry` guards the write with +> `if (!options.serviceInstanceId.empty())`, so a deliberately blank +> `service_instance_id` yields `service.instance.id=""` there and an absent +> attribute here. > -> Result: with `service_instance_id` unset, `beast::insight` metrics — and only -> those — export with an empty `service.instance.id`. Every shipped Grafana -> dashboard filters on `service_instance_id=~"$node"`, so **insight-backed -> panels** lose their per-node dimension; span-metric and `XRPL_METRIC_*` -> panels are unaffected. Set the key explicitly on any node whose insight -> metrics are dashboarded. -> -> **Known issue.** The asymmetry is a defect, not a design: `MetricsRegistry` -> already demonstrates the node-key fallback that the global provider needs. -> A fix would have to resolve the node identity before `TelemetryImpl` is -> constructed, or make the insight metrics use a late-built provider. +> The one case where the three can disagree: a node whose wallet already holds an +> identity different from the resolved one (another process wrote it between +> construction and `setup()`). `setServiceInstanceId()` then corrects the tracer, +> and both metric resources, already frozen, need a restart to follow. Every +> shipped Grafana dashboard filters on `service_instance_id=~"$node"`, so that run +> shows its metrics under the resolved key and its traces under the stored one. ### 5.1.2 Configuration Options Summary @@ -70,7 +57,7 @@ The authoritative `[telemetry]` example lives in `cfg/xrpld-example.cfg`. Teleme | -------------------------- | ------ | ---------------------------------- | ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------ | | `enabled` | 0 or 1 | `0` | Enable/disable telemetry | | `traces_endpoint` | string | `http://localhost:4318/v1/traces` | OTLP/HTTP collector endpoint for **traces** | -| `metrics_endpoint` | string | `http://localhost:4318/v1/metrics` | OTLP/HTTP collector endpoint for the native metrics pipeline (`MetricsRegistry`). Read in `Application.cpp:1670` | +| `metrics_endpoint` | string | `http://localhost:4318/v1/metrics` | OTLP/HTTP collector endpoint for the native metrics pipeline (`MetricsRegistry`). Read by `makeMetricsRegistryOptions()` in `Application.cpp` | | `use_tls` | 0 or 1 | `0` | Enable TLS for exporter connection | | `tls_ca_cert` | string | `""` | Path to CA certificate file | | `tls_client_cert` | string | `""` | Client cert (PEM) for mTLS; empty = one-way; if `enabled=1`, needs key + `use_tls=1` or startup fails | @@ -119,7 +106,7 @@ the corresponding subsystems are instrumented: 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.valueOr(...)`. It takes `serviceInstanceId` from the `nodePublicKey` argument when the key is absent, applies one unconditional `traces_endpoint` default (`dflt::tracesEndpoint`) — the parser has no notion of exporter type — and leaves the sampling ratio at its fixed 1.0 default (a `static constexpr` member, so there is nothing to parse). It also rejects two contradictory mTLS configurations outright (`tls_client_cert` without `tls_client_key`, and either without `use_tls=1`) rather than failing open at handshake time. -`metrics_endpoint` reaches `MetricsRegistry` by a second route: `ApplicationImp::startTelemetry()` reads it from the same `Section` and passes it to `MetricsRegistry::start()`, because `Telemetry` does not expose the `Setup` it parsed. Both metric exporters resolve to that one key: +`metrics_endpoint` reaches `MetricsRegistry` by a second route: `makeMetricsRegistryOptions()` in `Application.cpp` reads it from the same `Section` and passes it to the registry's constructor, because `Telemetry` does not expose the `Setup` it parsed. Both metric exporters resolve to that one key: | Metric source | Exporter built by | URL comes from | | ------------------------------------------ | -------------------------------------------- | -------------------------------------------------------------------- | @@ -134,20 +121,23 @@ Setting `traces_endpoint` therefore moves traces only; both metric pipelines fol ### 5.3.1 ApplicationImp Changes -> **Deferred identity**: The node public key (`nodeIdentity_`) is not -> available during `ApplicationImp`'s member initializer list — it is -> resolved later in `setup()`. The `Telemetry` object is therefore -> constructed with an empty `serviceInstanceId` and patched via -> `setServiceInstanceId()` once `setup()` has called `getNodeIdentity()`. -> **This patch reaches traces only.** The **global** MeterProvider resource — -> the one `beast::insight` metrics use — is already frozen by then (§5.1.1), so -> those metrics keep whatever `service_instance_id` the config supplied (`""` -> if it supplied none). Native `XRPL_METRIC_*` metrics do not go through this -> patch at all: `startTelemetry()` re-reads the config key and applies its own -> node-key fallback when building `MetricsRegistry`'s separate resource -> (`Application.cpp:1674-1679`). +> **Identity before construction**: telemetry stamps the node public key into +> resources that are immutable once built, and it builds them during +> `ApplicationImp`'s member initializer list. So `Main.cpp` calls +> `resolveNodeIdentity()` first, from the config and command line alone, and +> passes the keypair to `makeApplication()`. It never comes back empty: a +> configured `[node_seed]` decides it, else the wallet database supplies it if +> one already exists, else it is minted. Every producer therefore carries the +> node key from the start — the tracer, the **global** MeterProvider the +> `beast::insight` metrics use, and `MetricsRegistry`'s separate one. +> `ApplicationImp::setup()` then calls `getNodeIdentity()`, which stores that +> keypair when the wallet holds none and otherwise adopts what the wallet holds. +> Only in that second case can the two differ, and then +> `setServiceInstanceId()` corrects the tracer alone: both metric resources are +> frozen once their providers are built, so those metrics need a restart to +> report the stored key. -`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. +`ApplicationImp` (in `src/xrpld/app/main/Application.cpp`) owns a `std::pair nodeIdentity_`, declared before `std::unique_ptr telemetry_` and `std::unique_ptr metricsRegistry_` so both resources can be built from it. All three are built in the member initializer list, before every subsystem. `setup()` persists the identity, starts tracing with `startTelemetry()` before the first consensus round, and arms the registry's observable gauges with `startTelemetryGauges()` once `overlay_` exists. `run()` stops both observers before any service, then stops telemetry last; `~ApplicationImp` repeats those stops for the paths that never reach `run()`. `getTelemetry()` and `getMetricsRegistry()` return the owned instances. ### 5.3.2 ServiceRegistry Interface Addition @@ -353,7 +343,7 @@ The authoritative development stack lives in the repo at `docker/telemetry/docke | `loki` | `grafana/loki:3.7.6` | `3100` | Log storage for log↔trace correlation | | `prometheus` | `prom/prometheus:v3.13.2` | `9090` | Scrapes the collector's `:8889` | | `grafana` | `grafana/grafana:13.1.2` | `3000` | Dashboards + provisioned datasources/alerts, anonymous admin | -| `renderer` | `grafana/grafana-image-renderer:v5.12.0` | `8081` | Panel→PNG rendering for image export and alert screenshots | +| `renderer` | `grafana/grafana-image-renderer:v5.12.0` | none | Panel→PNG rendering for image export and alert screenshots | Two corrections to earlier drafts: diff --git a/OpenTelemetryPlan/09-data-collection-reference.md b/OpenTelemetryPlan/09-data-collection-reference.md index 8cef37dbc6..2c50b8e6a3 100644 --- a/OpenTelemetryPlan/09-data-collection-reference.md +++ b/OpenTelemetryPlan/09-data-collection-reference.md @@ -2066,11 +2066,13 @@ query, an alert — matches nothing and should be pointed at the live keys above | Dashboard | UID | Data Source | Key Panels | | ------------------ | --------------------------- | ----------- | ---------------------------------------------------------------------- | -| Validator Health | `validator-health` | Prometheus | Server state timeline, proposer count, converge time, amendment voting | +| Validator Health | `validator-health-external` | Prometheus | Server state timeline, proposer count, converge time, amendment voting | | Network Topology | `xrpld-network-topology` | Prometheus | Peer count, version distribution, latency distribution, diverged peers | | Fee Market (Ext) | `xrpld-fee-market-external` | Prometheus | Fee levels, queue depth, load factor breakdown, escalation timeline | | DEX & AMM Overview | `xrpld-dex-amm` | Prometheus | AMM TVL, order book depth, spread trends, trading fee revenue | +Grafana keys a dashboard by its UID, so two dashboards sharing one UID overwrite each other — whichever the provisioner loads last wins, and it does so silently. Phase 9 already ships `validator-health` (the row above), so the Phase 11 dashboard uses `validator-health-external`, the same way Fee Market is disambiguated as `xrpld-fee-market-external`. `OpenTelemetryPlan/Phase11_taskList.md` § Task 11.9 carries the same rule and the filename that goes with it. + ### Prometheus Alerting Rules (Phase 11) | Alert Name | Severity | Condition | For | diff --git a/OpenTelemetryPlan/OpenTelemetryPlan.md b/OpenTelemetryPlan/OpenTelemetryPlan.md index f2855643a8..e914e8062c 100644 --- a/OpenTelemetryPlan/OpenTelemetryPlan.md +++ b/OpenTelemetryPlan/OpenTelemetryPlan.md @@ -166,11 +166,11 @@ Configuration is handled through the `[telemetry]` section in `xrpld.cfg` with o Endpoints are spread across **three** keys in two sections, not one "traces and metrics" pair: -| Signal | Key | Default | Source | -| ---------------------------------------------------- | ------------------------------ | ---------------------------------- | --------------------------- | -| Traces | `[telemetry] endpoint` | `http://localhost:4318/v1/traces` | `TelemetryConfig.cpp:36,61` | -| Native metrics (`XRPL_METRIC_*` / `MetricsRegistry`) | `[telemetry] metrics_endpoint` | `http://localhost:4318/v1/metrics` | `Application.cpp:1670` | -| `beast::insight` metrics (`server=otel`) | `[insight] endpoint` | `http://localhost:4318/v1/metrics` | `CollectorManager.cpp:50` | +| Signal | Key | Default | Source | +| ---------------------------------------------------- | ------------------------------ | ---------------------------------- | --------------------------------------------------- | +| Traces | `[telemetry] endpoint` | `http://localhost:4318/v1/traces` | `TelemetryConfig.cpp:36,61` | +| Native metrics (`XRPL_METRIC_*` / `MetricsRegistry`) | `[telemetry] metrics_endpoint` | `http://localhost:4318/v1/metrics` | `makeMetricsRegistryOptions()` in `Application.cpp` | +| `beast::insight` metrics (`server=otel`) | `[insight] endpoint` | `http://localhost:4318/v1/metrics` | `CollectorManager.cpp:50` | `[telemetry]` itself has exactly **one** `endpoint` key, and it is traces-only. diff --git a/docker/telemetry/TESTING.md b/docker/telemetry/TESTING.md index 738fe71fac..8c4568bb0e 100644 --- a/docker/telemetry/TESTING.md +++ b/docker/telemetry/TESTING.md @@ -10,17 +10,14 @@ pipeline end-to-end, from span generation through the observability stack ### Build xrpld with telemetry -Follow [BUILD.md](../../BUILD.md) with `-o telemetry=True` added. From a build directory (`.build/`): +Build as [BUILD.md](../../BUILD.md) **§ Steps** describes, adding +`-o telemetry=True` to the `conan install` line. That is the only change: +Conan carries `telemetry=ON` into the generated CMake toolchain, so no extra +CMake flag is needed. For the full telemetry build, including how to turn it +off, see [`docs/build/telemetry.md`](../../docs/build/telemetry.md). -```bash -conan install .. --output-folder . --build missing -o telemetry=True --settings build_type=Release -cmake -DCMAKE_TOOLCHAIN_FILE:FILEPATH=build/generators/conan_toolchain.cmake -DCMAKE_BUILD_TYPE=Release -Dxrpld=ON -Dtelemetry=ON .. -cmake --build . --target xrpld -``` - -Conan also writes a `conan-release` preset, so `cmake --preset conan-release -Dtelemetry=ON` works too. There is no preset named `default`. - -The binary is at `.build/xrpld`. +This document assumes the `.build/` layout, so the binary is at `.build/xrpld` +and every command below runs from the repo root. ### Required tools @@ -61,29 +58,31 @@ XRPLD_UID=$(id -u) XRPLD_GID=$(id -g) \ Wait for services to be ready: ```bash -# otel-collector readiness: any HTTP response on the OTLP/HTTP port means the -# receiver is listening. Do NOT use `curl -sf` here — a GET of / returns 404, -# which -f treats as failure even when the collector is healthy. -[ "$(curl -so /dev/null -w '%{http_code}' http://localhost:4318/)" != "000" ] && - echo "collector ready" +# otel-collector readiness: the health_check extension answers on 13133, which +# docker-compose.yml publishes. +curl -sf http://localhost:13133/ >/dev/null && echo "collector ready" # Tempo readiness curl -sf http://localhost:3200/ready >/dev/null && echo "tempo ready" ``` -> The collector's `health_check` extension listens on **13133**, but -> `docker-compose.yml` publishes only 4317, 4318 and 8889 — so 13133 is not -> reachable from the host with the base stack. It is published only by the -> workload validation stack (`docker-compose.workload.yaml`). - ### Step 2: Start xrpld in standalone mode +`xrpld-telemetry.cfg` is a Devnet config whose `[node_db]`, `[database_path]` and `[debug_logfile]` all resolve under `docker/telemetry/data`. Standalone builds its own private chain, so pointing it at that store leaves one NuDB holding two unrelated chains. This is the same rule stated for the key-generation node in Test 2, and the reason the sibling mainnet config keeps its store under `data/mainnet/`. Give standalone its own prefix: + ```bash -.build/xrpld --conf docker/telemetry/xrpld-telemetry.cfg -a --start +sed -e 's|^path=docker/telemetry/data/nudb$|path=docker/telemetry/data/standalone/nudb|' \ + -e 's|^docker/telemetry/data$|docker/telemetry/data/standalone|' \ + -e 's|^data/logs/xrpld-devnet/debug.log$|data/logs/xrpld-standalone/debug.log|' \ + docker/telemetry/xrpld-telemetry.cfg >/tmp/xrpld-standalone.cfg + +.build/xrpld --conf /tmp/xrpld-standalone.cfg -a --start ``` Wait a few seconds for the node to initialize. +> Separating the store is required whether or not `--start` is passed. `--start` selects `StartUpType::Fresh`, but the default `Normal` reaches `startGenesisLedger()` through the same branch chain in `ApplicationImp::setup`, so every standalone run writes a genesis ledger into whichever store the config names. Dropping the flag does not avoid it; only a separate path does. `--start` additionally seeds the amendments this build desires into that genesis ledger. + ### Step 3: Exercise RPC spans ```bash @@ -103,7 +102,12 @@ curl -s http://localhost:5005 \ ### Step 4: Submit a transaction -Close the ledger first (required in standalone mode): +Close the ledger to drive a simulated consensus round — that round is what +produces the `consensus.*` spans. It is not required for `submit` itself: +standalone puts the node in `OperatingMode::FULL` at startup +(`NetworkOPsImp::setStandAlone()`), and the one validated-ledger-age gate on +the submit path is skipped when `config.standalone()` is set +(`checkTxJsonFields()` in `src/xrpld/rpc/detail/TransactionSign.cpp`). ```bash curl -s http://localhost:5005 -d '{"method":"ledger_accept"}' @@ -119,7 +123,7 @@ curl -s http://localhost:5005 -d '{ "tx_json": { "TransactionType": "Payment", "Account": "rHb9CJAWyB4rj91VRWn96DkukG4bwdtyTh", - "Destination": "rPMh7Pi9ct699iZUTWzJaUMR1o42VEfGqF", + "Destination": "rN7n7otQDd6FczFgLdSqtcsAUxDkw6fzRH", "Amount": "10000000" } }] @@ -128,6 +132,12 @@ curl -s http://localhost:5005 -d '{ Expected result: `"tesSUCCESS"`. +The destination does not have to exist yet. 10 XRP is exactly the default base +reserve (`FeeSetup::accountReserve` in `src/xrpld/core/Config.h`), so the +payment creates and funds the account. `integration-test.sh` does not hardcode +a destination at all — it calls `wallet_propose` and uses the `account_id` that +comes back. + Close the ledger again to finalize: ```bash @@ -144,7 +154,7 @@ Or open Grafana Explore with Tempo datasource: http://localhost:3000 ```bash # Kill xrpld (Ctrl+C or) -kill $(pgrep -f 'xrpld.*xrpld-telemetry') +pkill -f 'xrpld --conf docker/telemetry/xrpld-telemetry\.cfg' # Stop observability stack docker compose -f docker/telemetry/docker-compose.yml down @@ -153,21 +163,70 @@ docker compose -f docker/telemetry/docker-compose.yml down rm -rf docker/telemetry/data/ ``` +The pattern is anchored on the whole `--conf ` argument with the `.` +escaped, so it matches this node and not another xrpld run or an editor whose +command line happens to name the same file. `pkill` is also a no-op when +nothing matches, where `kill $(pgrep ...)` errors out with no arguments. + ### Expected spans (standalone mode) -| Span Name | Expected | Notes | -| ---------------------------------------------------------------------------------------------------------- | -------- | ------------------------------------------------- | -| `rpc.http_request` | Yes | Every HTTP RPC call | -| `rpc.process` | Yes | Every RPC processing | -| `rpc.command.server_info` | Yes | server_info RPC | -| `rpc.command.server_state` | Yes | server_state RPC | -| `rpc.command.ledger` | Yes | ledger RPC | -| `rpc.command.submit` | Yes | submit RPC | -| `rpc.command.ledger_accept` | Yes | ledger_accept RPC | -| `tx.process` | Yes | Transaction submission | -| `tx.receive` | No | No peers in standalone | -| `consensus.round`, `.phase.open`, `.ledger_close`, `.accept`, `.accept.apply` | Yes | `ledger_accept` drives a simulated round | -| `consensus.establish`, `.update_positions`, `.check`, `.proposal.*`, `.validation.receive`, `.mode_change` | No | `simulate` jumps straight to `Accepted`; no peers | +| Span Name | Expected | Notes | +| ----------------------------------------------------------------------------- | -------- | ------------------------------------------ | +| `rpc.http_request` | Yes | Every HTTP RPC call | +| `rpc.process` | Yes | Every RPC processing | +| `rpc.command.server_info` | Yes | server_info RPC | +| `rpc.command.server_state` | Yes | server_state RPC | +| `rpc.command.ledger` | Yes | ledger RPC | +| `rpc.command.submit` | Yes | submit RPC | +| `rpc.command.ledger_accept` | Yes | ledger_accept RPC | +| `rpc.ws_upgrade`, `rpc.ws_message` | No | Need a WebSocket client | +| `tx.process` | Yes | Transaction submission | +| `tx.preflight`, `tx.preclaim`, `tx.transactor` | Yes | Apply stages of the Payment | +| `tx.apply` | Yes | Ledger build applies the tx set | +| `tx.receive` | No | No peers in standalone | +| `txq.enqueue`, `txq.apply_direct` | Yes | `TxQ::apply` on the submit path | +| `txq.accept`, `txq.cleanup` | Yes | Run on every ledger close | +| `txq.accept_tx`, `txq.batch_clear` | No | Nothing is ever queued here | +| `ledger.build`, `ledger.store` | Yes | `buildLCL` builds, then stores | +| `ledger.validate` | No | `checkAccept` is unreachable in standalone | +| `consensus.round`, `.phase.open`, `.ledger_close`, `.accept`, `.accept.apply` | Yes | `ledger_accept` drives a simulated round | +| `consensus.mode_change` | Yes | Fires once per round start | +| `consensus.establish`, `.update_positions`, `.check` | No | `phaseEstablish()` never runs | +| `consensus.proposal.send`, `.validation.send` | No | The config carries no validator key | +| `consensus.proposal.receive`, `.validation.receive` | No | No peers | +| `peer.proposal.receive`, `peer.validation.receive` | No | No peers | +| `pathfind.*` | No | No path request, no path subscription | +| `grpc.*` | No | No `[port_grpc]` in the config | + +Four of the "No" rows have a reason worth spelling out. + +- `ledger.validate` belongs to `LedgerMaster::checkAccept`, and standalone never + reaches it: `consensusBuilt` returns early when standalone, and `switchLCL` + takes its standalone branch instead of calling `checkAccept`. That + `getNeededValidations()` returns 0 in standalone is therefore not enough on its + own. +- `consensus.establish`, `.update_positions` and `.check` are started from + `phaseEstablish()`. `simulate` does call `closeLedger({})` — which is exactly + why `.phase.open` and `.ledger_close` do fire — and then sets the phase to + `Accepted` itself, so `phaseEstablish()` is never entered. +- `.proposal.send` and `.validation.send` are absent for a different reason + again: `xrpld-telemetry.cfg` carries no `validation_seed` or + `validator_token`, so `preStartRound` leaves `validating_` false. The node + observes rather than proposes, and `validate()` — the owner of + `.validation.send` — is never called. +- `pathfind.update_all` is emitted only while at least one path subscription is + active, and this test makes no `path_find` or `ripple_path_find` call. + +`.mode_change` is in the "Yes" rows because it does not depend on the mode +actually changing. `startRoundInternal` calls `mode_.set()`, `MonitoredMode::set` +calls `onModeChange` with no equality test, and `onModeChange` creates the span +before the `before != after` check — that check guards only the censorship-detector +reset. + +One `consensus.round` span reaches Tempo, not two. `roundSpan_` is reset only at +the top of the next `startRoundTracing()`, so after the two `ledger_accept` calls +the first round's span has ended and been exported while the second is still open. +Only ended spans are exported. --- @@ -186,7 +245,7 @@ bash docker/telemetry/integration-test.sh It checks prerequisites, clears the previous run, brings up the observability stack, generates six validator key pairs and their node configs, starts the nodes, waits for consensus and then for a validated ledger, exercises RPC and submits a transaction, verifies traces in Tempo and both the span_metrics and the native `beast::insight` metrics that arrive over OTLP in Prometheus, checks that no StatsD listener is needed, then prints a summary and leaves the stack running. -The script announces each step as it runs, so read its `Step N:` headers for the authoritative sequence — they are not restated here, because a numbered copy of them drifts as soon as a step is added. +The authoritative sequence is the 14 `# Step N:` banner comments in the script source, so read the file rather than the console — none of the script's 48 runtime `log` lines print a step number. The sequence is not restated here, because a numbered copy of it drifts as soon as a step is added. Its Tempo checks cover the RPC, transaction, consensus, ledger and peer span categories from a fixed list, which is narrower than the loop in the "Verification Queries" section below. @@ -197,34 +256,82 @@ If you prefer to run the steps manually: #### Step 1: Start observability stack ```bash -docker compose -f docker/telemetry/docker-compose.yml up -d +XRPLD_LOG_DIR=/tmp/xrpld-integration \ + docker compose -f docker/telemetry/docker-compose.yml up -d ``` +The override is required here. The collector's log mount defaults to the +repo-relative `docker/telemetry/data/logs`, but this test writes its logs under +`/tmp/xrpld-integration`, so without it the `file_log` receiver tails the wrong +root, no log line reaches Loki, and Test 3 Step 3 finds nothing with no error. + #### Step 2: Generate validator keys -Start a temporary standalone xrpld: +Give the throwaway node a config of its own, under the same temp root the rest +of this test uses: ```bash -.build/xrpld --conf docker/telemetry/xrpld-telemetry.cfg -a --start & +mkdir -p /tmp/xrpld-integration/temp-keygen +cat >/tmp/xrpld-integration/temp-keygen/xrpld.cfg <<'EOCFG' +[server] +port_rpc_temp + +[port_rpc_temp] +port = 5099 +ip = 127.0.0.1 +admin = 127.0.0.1 +protocol = http + +[node_db] +type=NuDB +path=/tmp/xrpld-integration/temp-keygen/nudb +online_delete=256 + +[database_path] +/tmp/xrpld-integration/temp-keygen/db + +[debug_logfile] +/tmp/xrpld-integration/temp-keygen/debug.log + +[ssl_verify] +0 +EOCFG +``` + +Do not point this node at `docker/telemetry/xrpld-telemetry.cfg`. That is a +Devnet config whose `[node_db]`, `[database_path]` and `[debug_logfile]` all +resolve under `docker/telemetry/data`, so `--start` (a fresh-genesis start) +would write a genesis chain into the Devnet store, and deleting that directory +afterwards would also destroy the sibling mainnet node's store and every log +under `data/logs/`. Its RPC port is 5005, which is node 1's port later in this +test. + +Start it and wait for RPC before asking for keys: + +```bash +.build/xrpld --conf /tmp/xrpld-integration/temp-keygen/xrpld.cfg -a --start & TEMP_PID=$! -sleep 5 +until curl -sf http://localhost:5099 -d '{"method":"server_info"}' >/dev/null; do + sleep 1 +done ``` Generate 6 key pairs: ```bash for i in $(seq 1 6); do - curl -s http://localhost:5005 \ + curl -s http://localhost:5099 \ -d '{"method":"validation_create"}' | jq '.result' done ``` Record the `validation_seed` and `validation_public_key` for each. -Kill the temporary node: +Stop the temporary node and remove only its own directory: ```bash kill $TEMP_PID -rm -rf docker/telemetry/data/ +wait $TEMP_PID 2>/dev/null +rm -rf /tmp/xrpld-integration/temp-keygen ``` #### Step 3: Create node configs @@ -247,16 +354,19 @@ port = {51234 + node_number} ip = 0.0.0.0 protocol = peer +[network_id] +1025 + [node_db] type=NuDB -path=/tmp/xrpld-integration/node{N}/nudb +path=/tmp/xrpld-integration/Node-{N}/nudb online_delete=256 [database_path] -/tmp/xrpld-integration/node{N}/db +/tmp/xrpld-integration/Node-{N}/db [debug_logfile] -/tmp/xrpld-integration/node{N}/debug.log +/tmp/xrpld-integration/Node-{N}/debug.log [validation_seed] {seed from step 2} @@ -287,16 +397,36 @@ trace_peer=1 trace_ledger=1 [insight] +# server=otel is the only load-bearing key here -- it selects OTelCollector. +# The export endpoint comes from [telemetry] metrics_endpoint, and [insight]'s +# own service_instance_id/service_name keys are ignored. server=otel -endpoint=http://localhost:4318/v1/metrics [rpc_startup] -{ "command": "log_level", "severity": "warning" } +{ "command": "log_level", "severity": "info" } [ssl_verify] 0 ``` +`[network_id]` has to be a private id (anything other than 0, 1 or 2), because +the config default is id 0 and the telemetry resource maps that to `mainnet` — +without the stanza every span and metric this local cluster emits is stamped +`xrpl.network.type=mainnet` and lands on the same dashboard series as real +mainnet data. Only 0, 1 and 2 have names, so a private id is stamped +`xrpl.network.type=unknown`. That is the value to select in the dashboards' +Network Type filter when looking at this cluster. + +The per-node directory name must equal `[telemetry] service_instance_id`: the +collector reads the node name off the log file's path and stamps it as the Loki +label `service_instance_id`, so a mismatch leaves the logs labelled with a node +name that no trace or metric shares. + +`log_level` is `info`, not `warning`. A log line carries trace context only when +it is emitted inside an active span, and the pair that reliably carries it — the +`CNF Val` / `CNF buildLCL` branches inside the consensus accept span, one of +which fires for every accepted ledger — logs at `info`. + #### Step 4: Create validators.txt ```ini @@ -351,7 +481,7 @@ curl -s http://localhost:5005 -d '{ "tx_json": { "TransactionType": "Payment", "Account": "rHb9CJAWyB4rj91VRWn96DkukG4bwdtyTh", - "Destination": "rPMh7Pi9ct699iZUTWzJaUMR1o42VEfGqF", + "Destination": "rN7n7otQDd6FczFgLdSqtcsAUxDkw6fzRH", "Amount": "10000000" } }] @@ -360,9 +490,13 @@ curl -s http://localhost:5005 -d '{ Expected result: `"tesSUCCESS"`, the same as Test 1 Step 4. -Wait 15 seconds for consensus and batch export. +Wait 15 seconds for the consensus round and the trace batch export. Prometheus +needs longer: `integration-test.sh` waits a further 20 s before its span_metrics +queries and another 20 s before its StatsD queries, so 35 s and 55 s after the +submit. Querying the metrics block at 15 s returns no series, which looks like a +broken pipeline and is not one. -#### Step 8: Verify in Tempo +#### Step 8: Verify in Tempo and Prometheus See the "Verification Queries" section below. @@ -387,45 +521,51 @@ One hole worth knowing: the runbook's Span Reference tables have no row for `method`, `grpc_role` and `grpc_status`, emitted from `GRPCServer.cpp` with the key constants in `src/xrpld/app/main/GrpcSpanNames.h`. -If you find an older inline span inventory in this file or elsewhere, do not -trust it — the copy that used to live here had drifted badly (18 rows under a -"16 spans" heading, whole families missing, and pre-rename dotted `xrpl.*` -attribute keys the code no longer emits). The code and the runbook are the source -of truth. - ### Span → How to Trigger "Test" is the section of this file that exercises the family. `T1` = Test 1 (standalone), `T2` = Test 2 (6-node network). -| Span family (count) | Config toggle | How to trigger | Test | -| ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------ | -------------------- | --------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | ------- | -| **RPC** (5 total, 3 here): `rpc.http_request`, `rpc.process`, `rpc.command.` | `trace_rpc=1` | Any HTTP JSON-RPC call: `curl -s http://localhost:5005 -d '{"method":"server_info"}'`. `rpc.command.` is one family — the command name is part of the span name. | T1 | -| **RPC** (cont.): `rpc.ws_message`, `rpc.ws_upgrade` | `trace_rpc=1` | Needs a WebSocket client against `[port_ws_public]` (**6005**) or `[port_ws_admin_local]` (6006). `rpc.ws_upgrade` covers the handshake — force a failure to see its error path. `curl` alone will not do it. | — | -| **gRPC** (1): `grpc.` | `trace_rpc=1` | Call a gRPC method (`GetLedger`, `GetLedgerData`, …). **Requires a `[port_grpc]` stanza — the shipped `xrpld-telemetry*.cfg` files define none**, so add one first. | — | -| **Transaction** (6 total, 4 here): `tx.process`, `tx.preflight`, `tx.preclaim`, `tx.transactor` | `trace_transactions` | Submit any transaction (T1 Step 4). The three apply-stage spans share the tx's deterministic trace id; the `stage` attribute says where a failing tx stopped. | T1 | -| **Transaction** (cont.): `tx.receive` | `trace_transactions` | A **peer** relays a transaction. Never appears in standalone — submit on one node of the cluster and look on another. | T2 | -| **Transaction** (cont.): `tx.apply` | `trace_transactions` | Ledger close with a non-empty transaction set: submit, then `ledger_accept` (T1) or wait for consensus (T2). | T1 / T2 | -| **TxQ** (6): `txq.enqueue`, `txq.apply_direct`, `txq.batch_clear`, `txq.accept`, `txq.accept_tx`, `txq.cleanup` | `trace_transactions` | `txq.enqueue`/`apply_direct` on every submission; `txq.accept`/`accept_tx`/`cleanup` on every ledger close. To force real queueing, submit faster than ledgers close or with a fee below the required fee level. | T1 | -| **Consensus** (13): `consensus.round`, `.phase.open`, `.establish`, `.update_positions`, `.check`, `.proposal.send`, `.ledger_close`, `.accept`, `.accept.apply`, `.validation.send`, `.mode_change`, `.proposal.receive`, `.validation.receive` | `trace_consensus=1` | Requires real consensus — **standalone emits none of these**. Bring up T2 and wait for nodes to reach `proposing`; one `consensus.round` per close. `.mode_change` needs an actual mode transition (stop/start a node). | T2 | -| **Ledger** (4 total, 3 here): `ledger.build`, `ledger.validate`, `ledger.store` | `trace_ledger=1` | Any ledger close: `ledger_accept` in standalone, or consensus in T2. | T1 / T2 | -| **Ledger** (cont.): `ledger.acquire` | `trace_ledger=1` | Node fetches a **missing** ledger from peers. Start a node with no history against a running cluster, or restart one node after the others have advanced. | T2 | -| **Peer** (2): `peer.proposal.receive`, `peer.validation.receive` | `trace_peer=1` | Inbound consensus messages from peers; fresh trace roots. T2 only, and high volume. | T2 | -| **PathFind** (4): `pathfind.request`, `pathfind.compute`, `pathfind.discover`, `pathfind.update_all` | `trace_rpc=1` | `curl -s http://localhost:5005 -d '{"method":"ripple_path_find","params":[{"source_account":"…","destination_account":"…","destination_amount":"100"}]}'`. `pathfind.update_all` fires on ledger close while a request is active. | T1 | +| Span family (count) | Config toggle | How to trigger | Test | +| ------------------------------------------------------------------------------------------------------------------------------- | -------------------- | ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------ | ------- | +| **RPC** (5 total, 3 here): `rpc.http_request`, `rpc.process`, `rpc.command.` | `trace_rpc=1` | Any HTTP JSON-RPC call: `curl -s http://localhost:5005 -d '{"method":"server_info"}'`. `rpc.command.` is one family — the command name is part of the span name. | T1 | +| **RPC** (cont.): `rpc.ws_message`, `rpc.ws_upgrade` | `trace_rpc=1` | Needs a WebSocket client against `[port_ws_public]` (**6005**) or `[port_ws_admin_local]` (6006). `rpc.ws_upgrade` covers the handshake — force a failure to see its error path. `curl` alone will not do it. | — | +| **gRPC** (1): `grpc.` | `trace_rpc=1` | Call a gRPC method (`GetLedger`, `GetLedgerData`, …). **Requires a `[port_grpc]` stanza — the shipped `xrpld-telemetry*.cfg` files define none**, so add one first. | — | +| **Transaction** (6 total, 4 here): `tx.process`, `tx.preflight`, `tx.preclaim`, `tx.transactor` | `trace_transactions` | Submit any transaction (T1 Step 4). The three apply-stage spans share the tx's deterministic trace id; the `stage` attribute says where a failing tx stopped. | T1 | +| **Transaction** (cont.): `tx.receive` | `trace_transactions` | A **peer** relays a transaction. Never appears in standalone — submit on one node of the cluster and look on another. | T2 | +| **Transaction** (cont.): `tx.apply` | `trace_transactions` | Ledger close with a non-empty transaction set: submit, then `ledger_accept` (T1) or wait for consensus (T2). | T1 / T2 | +| **TxQ** (6): `txq.enqueue`, `txq.apply_direct`, `txq.batch_clear`, `txq.accept`, `txq.accept_tx`, `txq.cleanup` | `trace_transactions` | `txq.enqueue`/`apply_direct` on every submission; `txq.accept`/`accept_tx`/`cleanup` on every ledger close. To force real queueing, submit faster than ledgers close or with a fee below the required fee level. | T1 | +| **Consensus** (13 total, 6 here): `consensus.round`, `.phase.open`, `.mode_change`, `.ledger_close`, `.accept`, `.accept.apply` | `trace_consensus=1` | A standalone `ledger_accept` drives a whole simulated round, so these six fire in T1 as well as on every real close in T2. Note `consensus.round` is ended by the **next** round's start, so a single `ledger_accept` leaves it open and Tempo will not return it. | T1 / T2 | +| **Consensus** (cont., 3): `.establish`, `.update_positions`, `.check` | `trace_consensus=1` | Need the establish phase, which the simulated round skips by jumping straight to `Accepted`. Bring up T2 and wait for a timer-driven round. | T2 | +| **Consensus** (cont., 2): `.proposal.send`, `.validation.send` | `trace_consensus=1` | Need the node to propose, which needs a **validator key** — not peers. The shipped `xrpld-telemetry*.cfg` set no `[validation_seed]`/`[validator_token]`, so a standalone node only observes. | T2 | +| **Consensus** (cont., 2): `.proposal.receive`, `.validation.receive` | `trace_consensus=1` | A peer's consensus message arriving. T2 only. | T2 | +| **Ledger** (4 total, 2 here): `ledger.build`, `ledger.store` | `trace_ledger=1` | Any ledger close: `ledger_accept` in standalone, or consensus in T2. | T1 / T2 | +| **Ledger** (cont.): `ledger.validate` | `trace_ledger=1` | Belongs to `LedgerMaster::checkAccept`, which standalone never reaches — `consensusBuilt` returns early and `switchLCL` takes its standalone branch instead. Needs peers or an inbound validation. | T2 | +| **Ledger** (cont.): `ledger.acquire` | `trace_ledger=1` | Node fetches a **missing** ledger from peers. Start a node with no history against a running cluster, or restart one node after the others have advanced. | T2 | +| **Peer** (2): `peer.proposal.receive`, `peer.validation.receive` | `trace_peer=1` | Inbound consensus messages from peers; fresh trace roots. T2 only, and high volume. | T2 | +| **PathFind** (4): `pathfind.request`, `pathfind.compute`, `pathfind.discover`, `pathfind.update_all` | `trace_rpc=1` | `curl -s http://localhost:5005 -d '{"method":"ripple_path_find","params":[{"source_account":"…","destination_account":"…","destination_amount":"100"}]}'`. `pathfind.update_all` fires on ledger close while a request is active. | T1 | Notes that matter when a span you expect is missing: - **Toggles are per-subsystem and all default to on** (`trace_rpc`, `trace_transactions`, `trace_consensus`, `trace_peer`, `trace_ledger`), but `[telemetry] enabled` defaults to **0** — nothing is emitted until it is `1`. -- **`consensus.*` and `peer.*` cannot be produced in standalone mode.** If Test 1 - shows none, that is correct behaviour, not a regression — see "Expected spans - (standalone mode)" above. +- **`peer.*` cannot be produced in standalone mode.** Both peer spans are created + in inbound message handlers, and `-a` turns peerfinder's `autoConnect` off, so + the node opens no outbound peer connections and receives nothing. If Test 1 + shows none, that is correct behaviour, not a regression. +- **`consensus.*` is only partly absent in standalone.** `consensus.round`, + `.phase.open`, `.mode_change`, `.ledger_close`, `.accept` and `.accept.apply` + all fire on a `ledger_accept`; the other seven need the establish phase, a + validator key, or a peer — see the Consensus rows above. - **`rpc.ws_*` and `grpc.*` need a client and a port the quick tests do not use.** Absence in T1/T2 is expected. -- Trace ids are deterministic for transactions (`txID[0:16]`) and consensus - rounds (`prevLedgerHash[0:16]`), so you can compute the id you expect rather - than searching for it. +- Trace ids are deterministic for transactions (from `txID`) and consensus rounds + (from `prevLedgerHash`): the trace id is the hash's first **16 bytes**, so from + a hex-printed hash take the first **32 characters**. This holds under the + default `consensus_trace_strategy=deterministic`; set it to `random` and each + node gives its round a random trace id instead, joinable only by the + `consensus_ledger_id` attribute. --- @@ -435,29 +575,76 @@ Notes that matter when a span you expect is missing: Base URL: `http://localhost:3200` +Run `RUN_START=$(date +%s)` **before** starting xrpld (Test 1 Step 2, Test 2 +Step 5), in the same shell you will run the block below in. Tempo keeps blocks +for `block_retention` (`tempo.yaml`, 1h) on a named volume, so a search with no +time bound is answered by the previous run's traces. + ```bash TEMPO="http://localhost:3200" +# Refuse to run unbounded rather than report a previous run's traces. +: "${RUN_START:?record RUN_START=\$(date +%s) before starting xrpld}" + # List all services curl -s "$TEMPO/api/v2/search/tag/resource.service.name/values" | jq '.tagValues[].value' -# Query traces by operation -for op in "rpc.http_request" "rpc.ws_upgrade" "rpc.ws_message" "rpc.process" \ +# Count traces per span name. Test 1 produces a subset of this list — read it +# against the "Expected spans (standalone mode)" table above, not as pass/fail. +# +# -G is required: it moves the urlencoded parameters into the query string. +# Without it curl POSTs them as a request body, Tempo answers 200 and ignores +# the query, and every span name comes back non-zero. start/end bound the +# search to this run; the end margin covers spans exported while the query is +# in flight. +for op in "rpc.http_request" "rpc.process" \ "rpc.command.server_info" "rpc.command.server_state" "rpc.command.ledger" \ + "rpc.command.submit" "rpc.command.ledger_accept" \ "tx.process" "tx.receive" "tx.apply" \ - "consensus.proposal.send" "consensus.ledger_close" \ + "tx.preflight" "tx.preclaim" "tx.transactor" \ + "txq.enqueue" "txq.apply_direct" "txq.accept" "txq.cleanup" \ + "consensus.round" "consensus.phase.open" "consensus.ledger_close" \ + "consensus.establish" "consensus.update_positions" "consensus.check" \ "consensus.accept" "consensus.accept.apply" \ - "consensus.validation.send" \ + "consensus.proposal.send" "consensus.validation.send" \ + "consensus.mode_change" \ + "consensus.proposal.receive" "consensus.validation.receive" \ "ledger.build" "ledger.validate" "ledger.store" \ "peer.proposal.receive" "peer.validation.receive"; do - count=$(curl -s "$TEMPO/api/search" \ + count=$(curl -sfG "$TEMPO/api/search" \ --data-urlencode "q={resource.service.name=\"xrpld\" && name=\"$op\"}" \ + --data-urlencode "start=$RUN_START" \ + --data-urlencode "end=$(($(date +%s) + 60))" \ --data-urlencode "limit=5" | jq '.traces | length') printf "%-35s %s traces\n" "$op" "$count" done ``` +Eight more span families exist but need a trigger neither test performs, so they +are counted separately — a zero here is the expected answer, not a failure. +`rpc.ws_*` need a WebSocket client, the `pathfind.*` family needs a `path_find` +or `ripple_path_find` call, and the two `txq` names need a transaction sitting in +the queue. + +```bash +for op in "rpc.ws_upgrade" "rpc.ws_message" \ + "pathfind.request" "pathfind.compute" "pathfind.discover" "pathfind.update_all" \ + "txq.accept_tx" "txq.batch_clear"; do + count=$(curl -sfG "$TEMPO/api/search" \ + --data-urlencode "q={resource.service.name=\"xrpld\" && name=\"$op\"}" \ + --data-urlencode "start=$RUN_START" \ + --data-urlencode "end=$(($(date +%s) + 60))" \ + --data-urlencode "limit=5" | + jq '.traces | length') + printf "%-35s %s traces\n" "$op" "$count" +done +``` + +The remaining family is `grpc.`, whose span name is the gRPC method, so +it has no fixed string to query and needs a `[port_grpc]` stanza neither test +configures. + ### Prometheus API Base URL: `http://localhost:9090` @@ -499,8 +686,11 @@ registration. For what each dashboard covers, see [`docs/telemetry-runbook.md`](../../docs/telemetry-runbook.md) **§ Grafana -Dashboards** — the per-dashboard reference. Listing them here would be a second -copy that rots (this section previously named 5 of the 15 provisioned). +Dashboards**. That reference is partial: 9 of the 15 provisioned dashboards have +a section there, and six — `fee-market`, `job-queue`, `ledger-data-sync`, +`overlay-traffic-detail`, `peer-quality` and `validator-health` — do not. For +those, open a panel's info icon in Grafana; the panel descriptions carry the same +reference format. Pre-configured datasources: @@ -566,11 +756,17 @@ Consequences worth knowing before you debug against the cloud stack: pipeline, so `span_*` rates stay exact while only ~1 trace in 200 is retrievable by trace ID. A trace you can see in a metric may not exist in Tempo. -- **Pathfinding account hashing does not happen on the cloud export.** The base - config's `attributes/hash` processor hashes `pathfind_source_account` and - `pathfind_dest_account`. It is absent from every cloud pipeline, so those two - attributes leave for Grafana Cloud (and, on that config, for Tempo) with their - raw account values. +- **The same account carries a different token on each config.** No raw account + address leaves the node: the path-finding handlers under + `src/xrpld/rpc/handlers/orderbook/` pass both accounts through + `redactAccount()` first, which is a prefix of the address's SHA-512Half digest + (contract in `include/xrpl/telemetry/Redaction.h`). The base config's + `attributes/hash` processor then hashes that token a second time; no cloud + pipeline has it. The token is deterministic, so one account stays correlatable + across nodes and restarts — but only within one config. A trace stored while + the collector ran the base config must not be joined against a trace stored + under the cloud config, because the same account appears under two different + tokens. ### Step 4: Verify data reaches Grafana Cloud @@ -579,7 +775,7 @@ Cloud instance and confirm: - **Traces**: Explore → hosted Tempo datasource → search `{resource.service.name="xrpld"}` - **Metrics**: Explore → hosted Prometheus/Mimir → query `span_calls_total` -- **Logs**: Explore → hosted Loki → query `{service_name="xrpld"}` (requires `warning`+ file logging). **Not `{job="xrpld"}`** — see the note under Test 3 Step 3. +- **Logs**: Explore → hosted Loki → query `{service_name="xrpld"}` (requires file logging, at a level low enough to keep the correlated lines — the shipped devnet config's `debug` does, the mainnet config's `warning` suppresses them). **Not `{job="xrpld"}`** — see the note under Test 3 Step 3. If nothing appears, check the collector logs for auth/export errors: @@ -603,19 +799,28 @@ end-to-end log-trace correlation pipeline. ### Step 1: Verify trace_id in log output After running Test 1 or Test 2 (which generate RPC spans), check the -xrpld debug.log for trace context: +xrpld debug.log for trace context. A Test 1 run writes +`docker/telemetry/data/logs/xrpld-devnet/debug.log`; the mainnet config writes +`docker/telemetry/data/logs/mainnet/debug.log` instead. ```bash -grep 'trace_id=[a-f0-9]\{32\} span_id=[a-f0-9]\{16\}' /path/to/debug.log +grep 'trace_id=[a-f0-9]\{32\} span_id=[a-f0-9]\{16\}' \ + docker/telemetry/data/logs/xrpld-devnet/debug.log ``` Expected: log lines with `trace_id=<32hex> span_id=<16hex>` between the severity code and the message. Example: ``` -2024-Jan-15 10:30:45.123456789 UTC RPCHandler:NFO trace_id=abc123def456789012345678abcdef01 span_id=0123456789abcdef Calling server_info +2024-Jan-15 10:30:45.123456789 UTC RPCHandler:DBG trace_id=abc123def456789012345678abcdef01 span_id=0123456789abcdef RPC call server_info completed in 0.000123seconds ``` +That example is a Test 1 line. `xrpld-telemetry.cfg` logs at `debug`, so the +in-span RPC statement above appears. Test 2's nodes log at `info`, which +suppresses it — there, look for the `CNF Val` / `CNF buildLCL` lines from the +consensus accept span instead. Either carries trace context; only the message +differs. + Lines emitted outside of an active span (background tasks, startup) will NOT have trace context — this is expected. @@ -624,7 +829,8 @@ NOT have trace context — this is expected. Extract a `trace_id` from the log and verify it exists in Tempo: ```bash -TRACE_ID=$(grep -m1 -o 'trace_id=[a-f0-9]\{32\}' /path/to/debug.log | cut -d= -f2) +TRACE_ID=$(grep -m1 -o 'trace_id=[a-f0-9]\{32\}' \ + docker/telemetry/data/logs/xrpld-devnet/debug.log | cut -d= -f2) echo "Checking trace: $TRACE_ID" curl -s "http://localhost:3200/api/traces/$TRACE_ID" | jq '.batches | length' ``` @@ -656,23 +862,25 @@ Use `query_range`, not `query`. Loki rejects a bare log selector on the instant `/query` endpoint with HTTP 400 and a `text/plain` body ("log queries are not supported as an instant query type"), so `jq` fails to parse it and the step never prints a number — even when ingestion is working. -Only metric queries such as `sum(count_over_time(...))` are allowed there, -which is why the validation scripts can use the instant endpoint. -Timestamps are unix nanoseconds, matching `workload/validate_telemetry.py`. +Only metric queries such as `sum(count_over_time(...))` are allowed there, so a +check that needs a count rather than the lines themselves can use the instant +endpoint. `query_range` timestamps are unix nanoseconds. Counting `.data.result | length` would count streams, not log lines. > **Use `service_name`, not `job`.** The local stack's `resource/logs` processor -> sets one key, `service.name=xrpld` (`otel-collector-config.yaml:84-86`); its +> sets one key, `service.name=xrpld`, in `otel-collector-config.yaml`; its > comment there explains that a custom `job` attribute is not promoted to a > stream label and tells you to select on `service_name`. Only the Grafana Cloud -> variant also sets `job=xrpld` (`otel-collector-config.grafanacloud.yaml:73-75`). +> variant also sets `job=xrpld`, in `otel-collector-config.grafanacloud.yaml`. > Either way `{job="xrpld"}` does not work as a selector: on OTLP ingest Loki > promotes only an allow-listed set of resource attributes to indexed stream -> labels (`service.name` → `service_name`, plus `service.namespace`, -> `service.instance.id`, `deployment.environment`, `k8s.*`, `cloud.*`), and `job` -> is not on the list. This repo mounts no Loki config override — the `loki` +> labels. On the pinned `grafana/loki:3.7.6` that list is a fixed 18 keys, +> including `service.name` → `service_name`, `service.namespace`, +> `service.instance.id`, `deployment.environment` and `container.name`. `k8s.*` +> and `cloud.*` are enumerated key lists (ten and two entries), not wildcards. +> `job` is not on the list. This repo mounts no Loki config override — the `loki` > service runs the image's built-in `/etc/loki/local-config.yaml` -> (`docker-compose.yml:116`) — so `job` lands in **structured metadata**, which +> named in `docker-compose.yml` — so `job` lands in **structured metadata**, which > cannot be a stream selector. `{job="xrpld"}` therefore returns **zero results > with no error**, which reads exactly like "logs are not being ingested". If > this query is empty, check `{service_name="xrpld"}` before debugging the @@ -684,7 +892,7 @@ Counting `.data.result | length` would count streams, not log lines. 1. Open Grafana at http://localhost:3000 2. Navigate to **Explore** -> select **Tempo** datasource 3. Search for a trace (e.g., operation `rpc.command.server_info`) -4. Click **"Logs for this trace"** in the trace detail view +4. Expand a span and click **"Logs for this span"** in its **Links** row 5. Verify that Loki log lines appear, filtered by the trace's `trace_id` ### Step 5: Verify Grafana Loki-to-Tempo correlation @@ -696,15 +904,15 @@ Counting `.data.result | length` would count streams, not log lines. ### Expected results -| Check | Expected | -| ------------------------------ | ---------------------------------------- | -| `trace_id=` in debug.log | Present in log lines within active spans | -| `span_id=` in debug.log | Present alongside trace_id | -| Logs without active span | No trace_id/span_id fields | -| trace_id in Tempo | Matches a valid trace | -| Loki log ingestion | Logs visible via LogQL | -| Tempo -> Loki "Logs for trace" | Shows correlated log lines | -| Loki -> Tempo TraceID link | Navigates to correct trace | +| Check | Expected | +| --------------------------- | ---------------------------------------- | +| `trace_id=` in debug.log | Present in log lines within active spans | +| `span_id=` in debug.log | Present alongside trace_id | +| Logs without active span | No trace_id/span_id fields | +| trace_id in Tempo | Matches a valid trace | +| Loki log ingestion | Logs visible via LogQL | +| Tempo -> Loki span log link | Shows correlated log lines | +| Loki -> Tempo TraceID link | Navigates to correct trace | --- @@ -717,11 +925,9 @@ Counting `.data.result | length` would count streams, not log lines. docker compose -f docker/telemetry/docker-compose.yml logs otel-collector ``` 2. Verify xrpld telemetry config has `enabled=1` and correct endpoint -3. Check that otel-collector port 4318 is accessible (`-f` would fail on the - receiver's 404 for `GET /`, so test for any HTTP status instead): - ```bash - curl -so /dev/null -w '%{http_code}\n' http://localhost:4318/ - ``` +3. Check the collector is up — the readiness check in Test 1 Step 1. Probe + `health_check` on 13133, not the OTLP/HTTP port 4318, which answers 404 to a + `GET /` 4. Increase `batch_delay_ms` or decrease `batch_size` in xrpld config ### Nodes not reaching "proposing" state @@ -735,7 +941,11 @@ Counting `.data.result | length` would count streams, not log lines. 2. Verify `[ips_fixed]` lists the 5 other peer ports, and not the node's own 3. Verify `validators.txt` has all 6 public keys 4. Check node debug logs: `tail -50 /tmp/xrpld-integration/Node-1/debug.log` -5. Ensure `[peer_private]` is set to `1` (prevents reaching out to public network) +5. Ensure `[peer_private]` is set to `1`. In `src/libxrpl/peerfinder/Config.cpp` + it sets both `autoConnect = !standalone && !peerPrivate` and + `wantIncoming = (!config.peerPrivate) && (port != 0)`, so it stops the node + reaching out to the public network **and** stops it accepting inbound peers. + The nodes here find each other through `[ips_fixed]`, which is unaffected. ### Transaction not processing @@ -802,11 +1012,13 @@ Counting `.data.result | length` would count streams, not log lines. processors: [resource/tier, resource/stripsdk, batch] exporters: [prometheus] ``` - Both receivers are required. `spanmetrics` carries the span-derived + Both receivers are required. `span_metrics` carries the span-derived `span_*` series; `otlp` carries the node's native `beast::insight` / MetricsRegistry metrics, which arrive on the same OTLP port. Dropping `otlp` silently removes every native metric while the `span_*` ones keep - working — so the dashboards only half-break. + working — so the dashboards only half-break. (The cloud config, + `otel-collector-config.grafanacloud.yaml`, spells the same connector + `spanmetrics`; both are valid ids for it.) 3. Verify Prometheus can reach collector: ```bash curl -s http://localhost:9090/api/v1/targets | jq '.data.activeTargets' diff --git a/docker/telemetry/docker-compose.yml b/docker/telemetry/docker-compose.yml index 1cd02c9647..1cb821734d 100644 --- a/docker/telemetry/docker-compose.yml +++ b/docker/telemetry/docker-compose.yml @@ -214,8 +214,10 @@ services: # Shared secret for the JWT-authenticated render requests Grafana 13 # sends. Must match GF_RENDERING_RENDERER_TOKEN on the grafana service. - AUTH_TOKEN=${GF_RENDERING_RENDERER_TOKEN:-xrpld-local-render} - ports: - - "8081:8081" # Renderer HTTP endpoint (called by grafana) + # No `ports:` on purpose. Grafana reaches this over the compose network at + # http://renderer:8081, so publishing 8081 on the host adds nothing the + # stack needs. AUTH_TOKEN above is the only guard on the endpoint, and its + # default is a fixed string in this file, so keep the service off the host. networks: - xrpld-telemetry # Named volume for Tempo trace storage (WAL and compacted blocks). diff --git a/docker/telemetry/integration-test.sh b/docker/telemetry/integration-test.sh index 92122bbd19..a0bf2c4306 100755 --- a/docker/telemetry/integration-test.sh +++ b/docker/telemetry/integration-test.sh @@ -444,6 +444,12 @@ port = $PEER_PORT ip = 0.0.0.0 protocol = peer +# A private id, so telemetry stamps xrpl.network.type=unknown. The config +# default is id 0, which maps to "mainnet" -- this cluster's spans and metrics +# would then share dashboard series with real mainnet data. +[network_id] +1025 + [node_db] type=NuDB path=$NODE_DIR/nudb @@ -479,7 +485,6 @@ trace_transactions=1 trace_consensus=1 trace_peer=1 trace_ledger=1 -metrics_endpoint=http://localhost:4318/v1/metrics [insight] # server=otel is the only load-bearing key here -- it selects OTelCollector so diff --git a/docker/telemetry/otel-collector-config.yaml b/docker/telemetry/otel-collector-config.yaml index 1ce96abe8e..3fdb624e6c 100644 --- a/docker/telemetry/otel-collector-config.yaml +++ b/docker/telemetry/otel-collector-config.yaml @@ -92,16 +92,17 @@ processors: # and arrives as the label `service_name`, which is what the LogQL # examples in the runbook and TESTING.md select on. # - # A custom `job` attribute is NOT on that list. Verified against - # grafana/loki:3.4.2 with the default config: after ingesting through - # this pipeline, /loki/api/v1/labels returned only `service_name` and - # `deployment_environment`, `{job="xrpld"}` matched 0 streams, and + # A custom `job` attribute is NOT on that list: the pinned + # grafana/loki:3.7.6 prints an 18-key default list under + # limits_config.otlp_config, and `job` is not one of them. Ingesting + # through this pipeline, /loki/api/v1/labels returned only `service_name` + # and `deployment_environment`, `{job="xrpld"}` matched 0 streams, and # `job` appeared as structured metadata instead — which a `{...}` # stream selector cannot match. Promoting it would mean mounting a Loki # config and adding it to limits_config.otlp_config.resource_attributes # (additive to Loki's defaults unless ignore_defaults is set), which is # not worth a constant value — especially as Loki caps index labels at - # 15 and already promotes ~17 by default. Select on `service_name`. + # 15 and already promotes 18 by default. Select on `service_name`. - key: service.name value: xrpld action: upsert diff --git a/docker/telemetry/workload/baselines/baseline-timings.json b/docker/telemetry/workload/baselines/baseline-timings.json index f7060cbbd5..1ce5c004a4 100644 --- a/docker/telemetry/workload/baselines/baseline-timings.json +++ b/docker/telemetry/workload/baselines/baseline-timings.json @@ -1,89 +1,87 @@ { - "captured_at": "2026-08-26T11:54:41Z", - "git_sha": "8418d474a7a63aa981a4854aa94388a556517b0d", + "captured_at": "2026-09-10T18:05:00Z", + "git_sha": "a0385c53cb8f1e9ab77379b5584367a92d0a9014", "metrics": { "job.acceptLedger.queued.p95": { "unit": "us", - "value": 166.13636363636323 + "value": 95.58333333333331 }, "job.acceptLedger.running.p95": { "unit": "us", - "value": 6142.857142857149 + "value": 15967.741935483866 }, "job.transaction.queued.p95": { "unit": "us", - "value": 426.19047619047586 + "value": 403.74177631578937 }, "job.transaction.running.p95": { "unit": "us", - "value": 599.9999999999986 + "value": 376.7512077294688 }, "span.consensus.accept.p50": { "unit": "ms", - "value": 0.5287356321839081 + "value": 1.4363636363636365 }, "span.consensus.accept.p95": { "unit": "ms", - "value": 8.969696969696969 + "value": 8.811111111111114 }, "span.consensus.accept.p99": { "unit": "ms", - "value": 20.800000000000026 + "value": 20.928571428571445 }, "span.consensus.ledger_close.p95": { "unit": "ms", - "value": 0.7829999999999997 + "value": 0.6749999999999998 }, "span.consensus.ledger_close.p99": { "unit": "ms", - "value": 2.0299999999999896 + "value": 3.049999999999991 }, "span.ledger.build.p95": { "unit": "ms", - "value": 4.53333333333333 - }, - "span.ledger.build.p99": { - "unit": "ms", - "value": 9.109090909090913 + "value": 4.7714285714285705 }, "span.ledger.validate.p50": { "unit": "ms", - "value": 0.06471894002114831 + "value": 0.059761904761904766 }, "span.rpc.ws_message.p50": { "unit": "ms", - "value": 0.16003451676528602 + "value": 0.16282758747645082 }, "span.rpc.ws_message.p95": { "unit": "ms", - "value": 0.6977397260273974 + "value": 0.8122454466253443 }, "span.rpc.ws_message.p99": { "unit": "ms", - "value": 0.9757123287671235 + "value": 0.9872660098522166 }, "span.tx.apply.p95": { "unit": "ms", - "value": 3.524999999999999 + "value": 4.639716312056738 }, "span.tx.apply.p99": { "unit": "ms", - "value": 5.066666666666704 + "value": 4.9733333333333345 }, "span.tx.process.p50": { "unit": "ms", - "value": 0.20062219789579117 + "value": 0.21390674968918655 }, "span.tx.process.p95": { "unit": "ms", - "value": 0.6100467289719625 + "value": 0.49949970576841685 }, "span.tx.process.p99": { "unit": "ms", - "value": 2.758787878787877 + "value": 0.9939697679594013 } }, "profile": "full-validation", "schema_version": 1, + "source_runs": [34495527952, 34505215266, 34507425933], + "statistic": "median of three clean full-validation runs", "window": "3m" } diff --git a/docker/telemetry/workload/regression-metrics.json b/docker/telemetry/workload/regression-metrics.json index 70508085ad..f68c3f027c 100644 --- a/docker/telemetry/workload/regression-metrics.json +++ b/docker/telemetry/workload/regression-metrics.json @@ -1,21 +1,30 @@ { "_description": "Metric surface for the OTel-driven regression gate. Each entry names a metric, the quantiles to capture, and how to query Prometheus. The comparator compares current run against baseline-timings.json under these exact keys.", - "_key_format": "{category}.{name}.p{quantile} (e.g. span.tx.process.p99, job.transaction.queued.p95). Only the categories defined below are captured; there is no rpc_methods group, so no rpc.* key is produced or gated (FU-4).", - "_excluded_spans": "rpc.process is deliberately absent from spans.names. It is created only in ServerHandler::processRequest() on the HTTP/JSON-RPC path, which the workload load generators, being WebSocket-only, never reach, so its quantiles were captured as null every run and could never gate. (The harness shell scripts do issue a few HTTP JSON-RPC health polls, far too few to produce a meaningful quantile.) See baselines/README.md.", - "_excluded_ledger_store": "ledger.store is deliberately absent from spans.names too, for a different reason: it is below the ladder's resolution. The 2026-08-24 capture returned p50/p95/p99 of exactly 0.005/0.0095/0.0099 ms, which is 0.5/0.95/0.99 x the ladder's first edge of 0.01 ms — the signature of every sample landing in the first bucket, so the numbers are interpolation arithmetic on the bucket floor rather than latencies. That is physically plausible: LedgerMaster.cpp:470 wraps an in-memory ledgerHistory_.insert, which completes in single-digit microseconds. While all mass stays under 10 us the reported quantile cannot move materially, so NO absolute bound can gate it — every ledger.store slowing from 2 us to 9 us, 4.5x, leaves the reported value unchanged. Three keys that read as covered but cannot fire are worse than no keys (the same argument that excluded rpc.process), so they were removed rather than left in with a bound that looks derived. Restoring the key needs sub-10us edges on the collector's spanmetrics ladder (for example 0.001ms and 0.005ms) plus the matching entries in HistogramBuckets.h — that is the ladder's branch, not this file. ledger.store presence is still asserted by expected_spans.json and docker/telemetry/integration-test.sh, and its rate is still on the ledger-operations dashboard; only the latency gate drops it.", + "_excluded_ledger_store": "ledger.store is deliberately absent from spans.names too, for a different reason: it is below the ladder's resolution. The 2026-08-24 capture returned p50/p95/p99 of exactly 0.005/0.0095/0.0099 ms, which is 0.5/0.95/0.99 x the ladder's first edge of 0.01 ms \u2014 the signature of every sample landing in the first bucket, so the numbers are interpolation arithmetic on the bucket floor rather than latencies. That is physically plausible: LedgerMaster.cpp:470 wraps an in-memory ledgerHistory_.insert, which completes in single-digit microseconds. While all mass stays under 10 us the reported quantile cannot move materially, so NO absolute bound can gate it \u2014 every ledger.store slowing from 2 us to 9 us, 4.5x, leaves the reported value unchanged. Three keys that read as covered but cannot fire are worse than no keys (the same argument that excluded rpc.process), so they were removed rather than left in with a bound that looks derived. Restoring the key needs sub-10us edges on the collector's spanmetrics ladder (for example 0.001ms and 0.005ms) plus the matching entries in HistogramBuckets.h \u2014 that is the ladder's branch, not this file. ledger.store presence is still asserted by expected_spans.json and docker/telemetry/integration-test.sh, and its rate is still on the ledger-operations dashboard; only the latency gate drops it.", "_excluded_quantiles": "A THIRD KIND OF EXCLUSION, and the only one that deleting a name cannot express. spans.names lists span NAMES while _quantiles is shared across all of them, so the declared surface is the names x quantiles product and dropping ONE quantile of ONE span needs a subtraction. excluded_keys below is that subtraction: a flat {category}.{name}.p{quantile} key, exactly as _key_format defines it, mapped to the reason it is not gated. It can only ever remove a key, never add one, so a typo cannot silently start gating something new -- and check_regression_bounds.py rule F rejects an entry that would not otherwise be declared, an entry with an empty reason, and an entry that still carries a threshold override or a baseline value, so the exclusion cannot rot into dead config. Both prom_queries.py (which builds the capture plan) and check_regression_bounds.py (rule A) subtract it, so an excluded key is not queried, never reaches timings.json, and is not expected in the baseline. NOTHING ELSE CHANGES: the quantile is still computable from Prometheus with the _query_template above, the span is still asserted by expected_spans.json, and its rate is still on the ledger-operations dashboard. Only the latency gate drops it.", "_excluded_shape": "ALL FIVE ENTRIES BELOW SHARE ONE SHAPE, and it is worth naming because it will recur: the observed maximum across CI runs exceeds (baseline + bound), so an ordinary run clears the trip point with nothing having regressed. Two mechanisms produce that, and both are visible here. (1) A baseline that lands in the ladder's LOW buckets gets a tiny derived bound, because the bound IS the distance to the next edge up -- span.tx.apply.p50 at 0.0060 ms sits in the first bucket (0, 0.01] and gets 0.0440 ms of headroom, against a metric that has been measured at 2.3378 ms. (2) A spread so large that no bucket of headroom could absorb it -- span.ledger.validate.p99's 66.8x range reaches 25.8750 ms against a 10 ms trip point even though its bound is a comparatively generous 8.94 ms. The first mechanism is the one that excludes three keys here, and it is a property of WHERE THE CAPTURED RUN LANDED rather than of the metric: the same span.tx.apply.p50 has read 0.7917 ms, mid-distribution, where the identical rule produces a 4.21 ms bound that absorbs the whole range. Whether the gate functioned was therefore decided by luck of the draw. THE FOLLOW-UP THAT WOULD RESTORE COVERAGE, stated so it is not left implied: a baseline captured from a SINGLE run cannot support these keys, because one sample carries no information about spread and the bound is derived from that one sample alone. What would let them be gated again is a multi-run baseline -- or a spread measurement captured alongside the baseline, so a bound can be sized against observed variance instead of against the ladder only. That is not implemented; it is the design change these five exclusions are waiting on. Until then, do NOT re-gate any of them by re-baselining until a run happens to land favourably, which is the failure this note exists to prevent.", + "_excluded_spans": "rpc.process is deliberately absent from spans.names. It is created only in ServerHandler::processRequest() on the HTTP/JSON-RPC path, which the workload load generators, being WebSocket-only, never reach, so its quantiles were captured as null every run and could never gate. (The harness shell scripts do issue a few HTTP JSON-RPC health polls, far too few to produce a meaningful quantile.) See baselines/README.md.", + "_key_format": "{category}.{name}.p{quantile} (e.g. span.tx.process.p99, job.transaction.queued.p95). Only the categories defined below are captured; there is no rpc_methods group, so no rpc.* key is produced or gated (FU-4).", "excluded_keys": { "span.consensus.ledger_close.p50": "Run-to-run variance exceeds the bound this ladder can derive, the same limit as the ledger.validate pair and the same mechanism as the two sibling p50 keys excluded alongside it. Baseline 0.0387 ms sits in the low bucket (0.01, 0.05], so hi_next is 0.1 ms and the derived bound is 0.0613 ms -- a 2.58x trip point. Measured across three CI runs the value spans 0.0387 to 0.2377 ms, a 6.1x spread (5.9x over four runs), and run 32867433073 read 0.2377 ms, 2.38x the trip point, on the SAME post-path-finding-removal workload as this baseline. So a healthy run reddens CI. This is a variance limit, not a defect and not a missing bound: widening is unavailable, because a bound tolerating 0.2377 ms would reach past the 0.25 ms edge and gate almost nothing. Do NOT re-gate by widening, and do NOT re-baseline until a run lands higher -- see _excluded_shape.", "span.ledger.build.p50": "The same mechanism as span.consensus.ledger_close.p50, one bucket up. Baseline 0.1151 ms sits in (0.1, 0.25], so hi_next is 0.5 ms and the bound is 0.3849 ms -- a 4.34x trip point. Across three CI runs the value spans 0.1151 to 2.3826 ms, a 20.7x spread (25.3x over four runs), and the observed maximum is 4.77x the trip point. Note what the previous baseline hid: at 1.0612 ms the same rule gave a 8.94 ms bound and a 10 ms trip point, which absorbed the entire range, so this key read as gated purely because that capture landed mid-distribution. Ledger construction is the hot path this gate most wants to guard, which makes the loss real and worth fixing properly -- with a baseline that carries spread information, not with a wider bound.", - "span.tx.apply.p50": "The most extreme case of the low-bucket mechanism, and the clearest evidence that a single-run baseline cannot size a bound for these keys. Baseline 0.00597 ms lands in the ladder's FIRST bucket (0, 0.01], so hi_next is 0.05 ms and the bound is 0.0440 ms. Across three CI runs the value spans 0.00597 to 2.3378 ms, a 391.8x spread (364x over four runs), putting the observed maximum at 46.76x its trip point -- by far the worst of the five. The previous baseline read 0.7917 ms for the same key on the same workload, a 132x difference between two runs, and at that value the identical rule produced a 4.21 ms bound whose 5 ms trip point absorbed the full range. Nothing about the metric changed between those two captures; only where the sampled run fell in its own distribution did. Separately, a baseline inside the first bucket means the reported figure is interpolation across that bucket and tracks the FRACTION of applies finishing under 10 us rather than a latency, which is the ledger.store problem in embryo -- so restoring this key needs a finer low-end ladder as well as a spread-aware baseline. Rule E does not flag it because the value is not quantile x first_edge exactly.", + "span.ledger.build.p99": "Run-to-run variance exceeds the bound this ladder can derive, measured on the first three runs after the account-funding race was fixed. Baseline 8.944 ms (median of CI runs 34495527952, 34505215266, 34507425933) sits in (5, 10], so hi_next is 25 ms, the bound is 16.056 ms and the trip point is 25 ms. Across those three runs the value read 29.000, 7.060 and 8.944 ms -- a 4.11x spread, and the maximum is 1.16x the trip point, so a healthy run reddens CI. Run 34495527952 is that run: it turned the workload gate red on this key alone while all 200 span and metric checks passed and every phase reported 0 errors. Two corroborating details. First, its 29.000 ms reading is shared to the last digit with span.consensus.accept.p99 in the same run, which is the signature of histogram_quantile interpolating a thin tail inside one bucket rather than of ledger construction slowing down. Second, the previous baseline hid this: at 9.109 ms the same rule also gave a 25 ms trip point, and the key read as gated only because both the capture and the comparison runs happened to land low -- the 2026-08-26 capture predated the funding fix, so its phases submitted little or no traffic. Widening is not available: a bound tolerating 29.000 ms would be 20.06 ms and reach into the (25, 50] bucket, restoring exactly the single-crossing false positive the derivation rule exists to remove. Ledger construction is not left unguarded -- span.ledger.build.p95 stays gated and sits at 0.48 of its trip point. Do NOT re-gate this key by widening the bound; it needs a spread-aware baseline, or a finer ladder edge between 10 ms and 25 ms.", "span.ledger.validate.p95": "Run-to-run variance is larger than the bound this ladder can derive. Measured across four CI runs the value spans 0.1281 to 0.7500 ms, a 5.9x spread, against a baseline of 0.2404 ms whose trip point is the next ladder edge at 0.5 ms -- so an ordinary run clears the trip point with nothing having regressed. Run 32867433073 read 0.7500 ms, +212%, and turned CI red. The derived bound models QUANTIZATION noise only (hi_next - baseline is one bucket of headroom); the dominant noise term for this span is peer-validation arrival timing in a 5-node cluster, and that term was never measured before the key was gated. Widening is not available: a bound that tolerated 0.7500 ms would reach past the 1 ms edge and leave the key gating nothing. This is a variance limit, not a defect and not a missing bound -- do NOT re-gate it by widening.", - "span.ledger.validate.p99": "The same mechanism as p95, two orders of magnitude worse. Across the same four runs the value spans 0.3875 to 25.8750 ms, a 66.8x spread, against a baseline of 1.0600 ms and a 10 ms trip point; run 32862589645 read 25.8750 ms, +2341%. The span opens only once a quorum-completing validation arrives (LedgerMaster.cpp:1003, inside checkAccept, past the tvc < minVal early return) and wraps the promotion work that follows -- setValidated, setFull, setValidLedger, pendSaveValidated -- so its duration tracks peer-validation arrival timing and what promotion then triggers. One slow consensus round therefore dominates the tail of a 3m rate window, and which round that is differs every run. A bound tolerating 25.8750 ms would be ~24.8 ms against a 1.0600 ms baseline, which gates nothing at all. Note that the two CI failures landed on DIFFERENT quantiles in different runs while the other quantile stayed well inside its bound in the same run: that asymmetry is the signature of variance, not of a regression." + "span.ledger.validate.p99": "The same mechanism as p95, two orders of magnitude worse. Across the same four runs the value spans 0.3875 to 25.8750 ms, a 66.8x spread, against a baseline of 1.0600 ms and a 10 ms trip point; run 32862589645 read 25.8750 ms, +2341%. The span opens only once a quorum-completing validation arrives (LedgerMaster.cpp:1003, inside checkAccept, past the tvc < minVal early return) and wraps the promotion work that follows -- setValidated, setFull, setValidLedger, pendSaveValidated -- so its duration tracks peer-validation arrival timing and what promotion then triggers. One slow consensus round therefore dominates the tail of a 3m rate window, and which round that is differs every run. A bound tolerating 25.8750 ms would be ~24.8 ms against a 1.0600 ms baseline, which gates nothing at all. Note that the two CI failures landed on DIFFERENT quantiles in different runs while the other quantile stayed well inside its bound in the same run: that asymmetry is the signature of variance, not of a regression.", + "span.tx.apply.p50": "The most extreme case of the low-bucket mechanism, and the clearest evidence that a single-run baseline cannot size a bound for these keys. Baseline 0.00597 ms lands in the ladder's FIRST bucket (0, 0.01], so hi_next is 0.05 ms and the bound is 0.0440 ms. Across three CI runs the value spans 0.00597 to 2.3378 ms, a 391.8x spread (364x over four runs), putting the observed maximum at 46.76x its trip point -- by far the worst of the five. The previous baseline read 0.7917 ms for the same key on the same workload, a 132x difference between two runs, and at that value the identical rule produced a 4.21 ms bound whose 5 ms trip point absorbed the full range. Nothing about the metric changed between those two captures; only where the sampled run fell in its own distribution did. Separately, a baseline inside the first bucket means the reported figure is interpolation across that bucket and tracks the FRACTION of applies finishing under 10 us rather than a latency, which is the ledger.store problem in embryo -- so restoring this key needs a finer low-end ladder as well as a spread-aware baseline. Rule E does not flag it because the value is not quantile x first_edge exactly." + }, + "job_queue": { + "_phases": ["queued", "running"], + "_quantiles": [0.95], + "_queued_template": "histogram_quantile({quantile}, sum by (le) (rate(job_queued_us_bucket{job_type=\"{name}\"}[{window}])))", + "_running_template": "histogram_quantile({quantile}, sum by (le) (rate(job_running_us_bucket{job_type=\"{name}\"}[{window}])))", + "_unit": "us", + "names": ["transaction", "acceptLedger"] }, "spans": { + "_quantiles": [0.5, 0.95, 0.99], "_query_template": "histogram_quantile({quantile}, sum by (le) (rate(span_duration_milliseconds_bucket{span_name=\"{name}\"}[{window}])))", "_unit": "ms", - "_quantiles": [0.5, 0.95, 0.99], "names": [ "rpc.ws_message", "tx.process", @@ -25,13 +34,5 @@ "consensus.ledger_close", "consensus.accept" ] - }, - "job_queue": { - "_queued_template": "histogram_quantile({quantile}, sum by (le) (rate(job_queued_us_bucket{job_type=\"{name}\"}[{window}])))", - "_running_template": "histogram_quantile({quantile}, sum by (le) (rate(job_running_us_bucket{job_type=\"{name}\"}[{window}])))", - "_unit": "us", - "_quantiles": [0.95], - "_phases": ["queued", "running"], - "names": ["transaction", "acceptLedger"] } } diff --git a/docker/telemetry/workload/regression-thresholds.json b/docker/telemetry/workload/regression-thresholds.json index ff50363116..76c2b9850c 100644 --- a/docker/telemetry/workload/regression-thresholds.json +++ b/docker/telemetry/workload/regression-thresholds.json @@ -1,146 +1,142 @@ { - "_description": "Per-metric regression thresholds. A metric regresses when current - baseline exceeds BOTH the percentage and absolute bounds (AND, not OR \u2014 this tolerates small-value noise). Defaults apply unless a per-metric override exists.", + "_absolute_bound_derivation": "HOW EVERY max_abs_increase_* NUMBER BELOW WAS OBTAINED. Rule: locate the baseline value in the half-open bucket (lo, hi] of its own ladder, take hi_next = the next edge above hi, and set the bound to (hi_next - baseline). The trip point is therefore exactly hi_next: the gate fires only when the reported value EXCEEDS the top of the bucket above the baseline's own bucket. WHY THAT AND NOT A MULTIPLE OF THE BUCKET WIDTH: histogram_quantile returns a value interpolated inside whichever bucket the true quantile falls in, so a reading taken while the true quantile sits anywhere in the baseline's bucket OR anywhere in the one immediately above is at most hi_next and cannot fire. Firing requires the true quantile to have moved at least two buckets up. A multiple of the ENCLOSING width cannot deliver that, because once the quantile crosses hi the interpolation happens across the NEXT bucket, which on this ladder is up to 8x wider \u2014 (0.5,1] has width 0.5 and (1,5] has width 4 \u2014 so the reading's excursion is not bounded by any multiple of the enclosing width. Worked example: span.tx.process.p99 has baseline 2.7588ms in bucket (1, 5], hi_next = 10, so its bound is 7.2412ms and the gate fires only above 10ms. Bounds are stored as exact doubles rather than rounded figures so that rounding cannot break the guarantee and so check_regression_bounds.py can assert each one against the ladder to within a 1e-12 relative tolerance -- tight enough that a bound rounded for readability, such as 7.2412 for 7.241212121212123, is rejected; _derivation_table below shows the arithmetic for each one. Measured over the committed baseline this rule yields a detection floor of 2.21x to 16.28x of baseline, per key. WHAT THIS RULE DOES NOT COVER, AND THE ONE CHECK TO RUN BEFORE GATING ANY KEY: hi_next - baseline is derived from the LADDER, so it budgets for QUANTIZATION noise -- one bucket of interpolation headroom -- and for nothing else. It knows nothing about how much the metric itself moves between runs on identical code. Where run-to-run workload variance is the larger term the bound is simply the wrong size, and the gate reddens on a healthy run. So before adding a key here, capture it over several runs and check its OBSERVED MAXIMUM against its trip point (baseline + bound); gate it only if the observed maximum stays below that trip point with margin. Spread on its own proves nothing -- it is spread RELATIVE TO THE TRIP POINT that decides, and a baseline that lands at the LOW end of a metric's own range shrinks that trip point even though nothing about the metric changed. THREE KEYS FAILED THIS TEST ON THE 2026-08-26 BASELINE AND ARE NOW EXCLUDED, all of them p50: span.tx.apply.p50 (bound 0.0440ms, trips at 0.05ms, observed max 2.3378ms = 46.76x its trip point), span.ledger.build.p50 (bound 0.3849ms, trips at 0.5ms, observed max 2.3826ms = 4.77x) and span.consensus.ledger_close.p50 (bound 0.0613ms, trips at 0.1ms, observed max 0.2377ms = 2.38x). Their spreads across three runs are 391.8x, 20.7x and 6.1x. This is the general rule above being APPLIED, not a new exception: a key is gateable only when its run-to-run spread fits inside its bound, and these three do not. The evidence that settles it is span.tx.apply.p50's own history -- it read 0.7917ms in the previous baseline and 0.00597ms in this one, a 132x difference between two runs of the SAME workload. At the old value the identical rule produced a 4.21ms bound whose 5ms trip point absorbed the whole range; at the new one it produces 0.0440ms and cannot. Whether the gate functioned was therefore decided by where in its distribution the captured run happened to land, which is not a threshold needing tuning but a key that cannot be gated from a single-run baseline at all. Before the exclusion, replaying the two preceding CI runs 32862589645 and 32867433073 against this baseline reported exactly those three and nothing else on BOTH runs, and 32867433073 carries the same post-path-finding-removal workload as the baseline itself -- so the movement was metric variance, not a workload difference. After it, both runs replay clean. The remaining 20 keys sit at or below 0.58 of their trip points, the worst being span.consensus.accept.p50. See _excluded_shape in regression-metrics.json for what all five excluded keys have in common and for the multi-run-baseline work that would let them be gated again. A key that fails this test is not fixed by widening its bound: see excluded_keys in regression-metrics.json. WHAT THIS REPLACED, IN TWO GENERATIONS: (1) a single flat pair of bounds (10ms for span p50/p95, 15ms for span p99, 20000us for job_queue p95) justified as 'roughly two bucket widths in the 5-25ms band where most span quantiles actually sit'. The 2026-08-24 capture falsifies that premise \u2014 18 of the 28 quantiles gated at that time sat below 1ms \u2014 so the absolute bound sat 1.15x to 2000x above the metric it guarded and, because the rule is an AND, the percentage bound could never carry a regression on its own; a 10x regression injected into each key in turn was caught on only 5 of 28, and a 100x regression injected into span.ledger.store.p95 produced 0 regressions and exit 0. (2) a first correction to 2 \u00d7 the ENCLOSING bucket width, which caught 10x on 28 of 28 but placed the trip point INSIDE the adjacent bucket -- and so left a single-crossing false positive reachable -- on 21 of the 25 keys gated at the time, 4 of them tripping on a tail-mass shift under 1.5% of samples. That is the assumption this rule removes. RE-DERIVE THESE NUMBERS whenever baseline-timings.json is refreshed or either ladder changes: a refreshed baseline can land in a different bucket, which changes hi_next. .github/scripts/telemetry/check_regression_bounds.py enforces the rule in CI so a stale bound cannot survive a baseline refresh. LIMITATION \u2014 WHICH KEYS ARE ONLY WEAKLY GUARDED: the guarantee costs sensitivity wherever the ladder is coarse, and the detection floor is hi_next/baseline, so a baseline sitting just above an edge is guarded loosely. job.acceptLedger.running.p95 (baseline 6142.86us, fires at 100000us, 16.28x) is NOT meaningfully guarded, and it is now the one key a 10x regression does NOT catch: measured, 10x reaches 61429us and passes, and the gate first fires at 16.28x. It sits just above the 5000us edge while hi_next is 100000us, two steps up. Its floor moved there in this refresh, from 5.74x, because its baseline fell 17428.57us to 6142.86us while hi_next stayed at 100000us -- it does NOT fire on any observed run, so it stays gated, but the weak floor is recorded here so it is visible rather than surprising. span.consensus.accept.p50 (9.46x), job.transaction.running.p95 (8.33x), span.tx.process.p95 (8.20x), span.rpc.ws_message.p95 (7.17x), span.consensus.ledger_close.p95 (6.39x) and span.rpc.ws_message.p99 (5.12x) are also weak. Four of the seven are limited by the 1ms\u21925ms step; the rest by 1000us\u21925000us (job.transaction.running.p95) and 25000us\u2192100000us (job.acceptLedger.running.p95). The fix is a 2ms edge (and ideally 3ms) in the collector's spanmetrics ladder plus the matching edges in kMillisecondBuckets, and 2000us plus 50000us edges in kMicrosecondBuckets \u2014 that work belongs to the branch that owns the ladders, not here. Until then do not read these keys as guarded. span.ledger.store is absent from the overrides below because it is excluded from the gated surface entirely: its quantiles are the ladder floor times the quantile, so no bound can gate it. See _excluded_ledger_store in regression-metrics.json. REFRESHED 2026-09-10 from the median of CI runs 34495527952, 34505215266 and 34507425933, the first three runs with the account-funding race fixed. The 2026-08-26 baseline predated that fix, so the phases that lost their traffic captured artificially low ledger and transaction timings; job.transaction.queued.p95 and job.transaction.running.p95 could not be captured at all. Applying the observed-maximum test to the refreshed numbers leaves 19 of 20 keys between 0.17 and 0.76 of their trip points, and disqualifies span.ledger.build.p99 -- see excluded_keys in regression-metrics.json. span.tx.process.p95 is the tightest survivor at 0.76 and is the key to re-measure first if the gate reddens again.", "_bucket_note": "SpanMetrics latency histograms use explicit buckets [0.01,0.05,0.1,0.25,0.5,1,5,10,25,50,100,250,500]ms then [1,2,3,4,5,10,30]s (20 edges; docker/telemetry/otel-collector-config.yaml is the authoritative list). Second-scale consensus spans have 2s/3s/4s boundaries, so their quantiles quantize to ~1s widths there \u2014 the ladder is NOT uniformly 2x-or-coarser, which matters for _percentage_bound_note. The native job_queue histograms are microsecond-valued on the ladder [1,2,5,10,25,50,100,250,500,1000,5000,25000,100000,500000]us then [1,5,10,30,60]s (19 edges; include/xrpl/telemetry/HistogramBuckets.h is authoritative). NOTE: BOTH ladders were re-cut, and a baseline captured before its own ladder changed is an interpolation artefact, not a latency. The job_queue floor moved 100us \u2192 1us. The span floor is 0.01ms; a span baseline captured against a 1ms floor is void below 1ms \u2014 a p95 reading 0.95ms there is 0.95 \u00d7 that 1ms first edge, not a measurement. Do not assume a surviving span baseline is unaffected by ladder work: every span quantile below 1ms is affected. Only the band from 1ms to 1s is safe: those edges are byte-identical across the two ladders. The re-cut also ADDED edges above 1s (2s/3s/4s/10s/30s), so a span whose quantiles land in the second-scale range \u2014 consensus.round ~3.9s, consensus.establish ~1.9s, the ledger.acquire tail \u2014 is distorted just as much, and any pre-2026-08-04 baseline for it is equally void. Do not read this note as licensing a stale second-scale baseline.", - "_absolute_bound_derivation": "HOW EVERY max_abs_increase_* NUMBER BELOW WAS OBTAINED. Rule: locate the baseline value in the half-open bucket (lo, hi] of its own ladder, take hi_next = the next edge above hi, and set the bound to (hi_next - baseline). The trip point is therefore exactly hi_next: the gate fires only when the reported value EXCEEDS the top of the bucket above the baseline's own bucket. WHY THAT AND NOT A MULTIPLE OF THE BUCKET WIDTH: histogram_quantile returns a value interpolated inside whichever bucket the true quantile falls in, so a reading taken while the true quantile sits anywhere in the baseline's bucket OR anywhere in the one immediately above is at most hi_next and cannot fire. Firing requires the true quantile to have moved at least two buckets up. A multiple of the ENCLOSING width cannot deliver that, because once the quantile crosses hi the interpolation happens across the NEXT bucket, which on this ladder is up to 8x wider \u2014 (0.5,1] has width 0.5 and (1,5] has width 4 \u2014 so the reading's excursion is not bounded by any multiple of the enclosing width. Worked example: span.tx.process.p99 has baseline 2.7588ms in bucket (1, 5], hi_next = 10, so its bound is 7.2412ms and the gate fires only above 10ms. Bounds are stored as exact doubles rather than rounded figures so that rounding cannot break the guarantee and so check_regression_bounds.py can assert each one against the ladder to within a 1e-12 relative tolerance -- tight enough that a bound rounded for readability, such as 7.2412 for 7.241212121212123, is rejected; _derivation_table below shows the arithmetic for each one. Measured over the committed baseline this rule yields a detection floor of 2.21x to 16.28x of baseline, per key. WHAT THIS RULE DOES NOT COVER, AND THE ONE CHECK TO RUN BEFORE GATING ANY KEY: hi_next - baseline is derived from the LADDER, so it budgets for QUANTIZATION noise -- one bucket of interpolation headroom -- and for nothing else. It knows nothing about how much the metric itself moves between runs on identical code. Where run-to-run workload variance is the larger term the bound is simply the wrong size, and the gate reddens on a healthy run. So before adding a key here, capture it over several runs and check its OBSERVED MAXIMUM against its trip point (baseline + bound); gate it only if the observed maximum stays below that trip point with margin. Spread on its own proves nothing -- it is spread RELATIVE TO THE TRIP POINT that decides, and a baseline that lands at the LOW end of a metric's own range shrinks that trip point even though nothing about the metric changed. THREE KEYS FAILED THIS TEST ON THE 2026-08-26 BASELINE AND ARE NOW EXCLUDED, all of them p50: span.tx.apply.p50 (bound 0.0440ms, trips at 0.05ms, observed max 2.3378ms = 46.76x its trip point), span.ledger.build.p50 (bound 0.3849ms, trips at 0.5ms, observed max 2.3826ms = 4.77x) and span.consensus.ledger_close.p50 (bound 0.0613ms, trips at 0.1ms, observed max 0.2377ms = 2.38x). Their spreads across three runs are 391.8x, 20.7x and 6.1x. This is the general rule above being APPLIED, not a new exception: a key is gateable only when its run-to-run spread fits inside its bound, and these three do not. The evidence that settles it is span.tx.apply.p50's own history -- it read 0.7917ms in the previous baseline and 0.00597ms in this one, a 132x difference between two runs of the SAME workload. At the old value the identical rule produced a 4.21ms bound whose 5ms trip point absorbed the whole range; at the new one it produces 0.0440ms and cannot. Whether the gate functioned was therefore decided by where in its distribution the captured run happened to land, which is not a threshold needing tuning but a key that cannot be gated from a single-run baseline at all. Before the exclusion, replaying the two preceding CI runs 32862589645 and 32867433073 against this baseline reported exactly those three and nothing else on BOTH runs, and 32867433073 carries the same post-path-finding-removal workload as the baseline itself -- so the movement was metric variance, not a workload difference. After it, both runs replay clean. The remaining 20 keys sit at or below 0.58 of their trip points, the worst being span.consensus.accept.p50. See _excluded_shape in regression-metrics.json for what all five excluded keys have in common and for the multi-run-baseline work that would let them be gated again. A key that fails this test is not fixed by widening its bound: see excluded_keys in regression-metrics.json. WHAT THIS REPLACED, IN TWO GENERATIONS: (1) a single flat pair of bounds (10ms for span p50/p95, 15ms for span p99, 20000us for job_queue p95) justified as 'roughly two bucket widths in the 5-25ms band where most span quantiles actually sit'. The 2026-08-24 capture falsifies that premise \u2014 18 of the 28 quantiles gated at that time sat below 1ms \u2014 so the absolute bound sat 1.15x to 2000x above the metric it guarded and, because the rule is an AND, the percentage bound could never carry a regression on its own; a 10x regression injected into each key in turn was caught on only 5 of 28, and a 100x regression injected into span.ledger.store.p95 produced 0 regressions and exit 0. (2) a first correction to 2 \u00d7 the ENCLOSING bucket width, which caught 10x on 28 of 28 but placed the trip point INSIDE the adjacent bucket -- and so left a single-crossing false positive reachable -- on 21 of the 25 keys gated at the time, 4 of them tripping on a tail-mass shift under 1.5% of samples. That is the assumption this rule removes. RE-DERIVE THESE NUMBERS whenever baseline-timings.json is refreshed or either ladder changes: a refreshed baseline can land in a different bucket, which changes hi_next. .github/scripts/telemetry/check_regression_bounds.py enforces the rule in CI so a stale bound cannot survive a baseline refresh. LIMITATION \u2014 WHICH KEYS ARE ONLY WEAKLY GUARDED: the guarantee costs sensitivity wherever the ladder is coarse, and the detection floor is hi_next/baseline, so a baseline sitting just above an edge is guarded loosely. job.acceptLedger.running.p95 (baseline 6142.86us, fires at 100000us, 16.28x) is NOT meaningfully guarded, and it is now the one key a 10x regression does NOT catch: measured, 10x reaches 61429us and passes, and the gate first fires at 16.28x. It sits just above the 5000us edge while hi_next is 100000us, two steps up. Its floor moved there in this refresh, from 5.74x, because its baseline fell 17428.57us to 6142.86us while hi_next stayed at 100000us -- it does NOT fire on any observed run, so it stays gated, but the weak floor is recorded here so it is visible rather than surprising. span.consensus.accept.p50 (9.46x), job.transaction.running.p95 (8.33x), span.tx.process.p95 (8.20x), span.rpc.ws_message.p95 (7.17x), span.consensus.ledger_close.p95 (6.39x) and span.rpc.ws_message.p99 (5.12x) are also weak. Four of the seven are limited by the 1ms\u21925ms step; the rest by 1000us\u21925000us (job.transaction.running.p95) and 25000us\u2192100000us (job.acceptLedger.running.p95). The fix is a 2ms edge (and ideally 3ms) in the collector's spanmetrics ladder plus the matching edges in kMillisecondBuckets, and 2000us plus 50000us edges in kMicrosecondBuckets \u2014 that work belongs to the branch that owns the ladders, not here. Until then do not read these keys as guarded. span.ledger.store is absent from the overrides below because it is excluded from the gated surface entirely: its quantiles are the ladder floor times the quantile, so no bound can gate it. See _excluded_ledger_store in regression-metrics.json.", - "_percentage_bound_note": "For every key gated today the absolute bound is the binding half of the AND and the percentage bound never decides the outcome: measured, (bound / baseline) ranges from 121% (span.ledger.build.p95) to 1528% (job.acceptLedger.running.p95), all above the 50% and 5% percentage bounds configured here, and the minimum trip multiple of all 20 keys is set by the absolute bound. THIS IS NOT A GENERAL GUARANTEE. Do not reason from 'every step of both ladders is at least a factor of 2' -- that premise is false. The span ladder breaks it three times at the top: 2s->3s is 1.5x, 3s->4s is 1.33x, 4s->5s is 1.25x, so second-scale consensus quantiles quantize to ~1s widths there. Because the bound is (hi_next - baseline), a baseline between about 2667ms and 3000ms, or between about 3334ms and 4000ms, gets an absolute bound worth less than 50% of itself and the PERCENTAGE bound becomes the operative one -- at which point the metric fires on a 50% move that is smaller than one bucket width, and the single-crossing guarantee in _absolute_bound_derivation is lost. That band is not hypothetical: the collector config names consensus.round (~3.9s) as a reason those edges exist, and 3900ms sits in the second sub-band with an absolute bound of 5000 - 3900 = 1100, only 28.2% of baseline. Whoever gates a key whose baseline lands in either sub-band MUST lower its max_pct_increase below (bound / baseline) for that key, or state explicitly that the metric is percentage-gated and the bucket guarantee does not hold for it. check_regression_bounds.py enforces this as rule D so the trap cannot be walked into silently. The percentage entries are required and still meaningful regardless: compare_to_baseline.py treats a missing max_pct_increase as 'no threshold configured' and would stop gating the metric entirely; they record the intended relative tolerance (consensus spans 5%, everything else 50%); and they are the operative bound on the defaults path (see _defaults_note).", "_defaults_note": "A MISSING OVERRIDE IS DETECTED BY CI, NOT BY THESE DEFAULTS. .github/scripts/telemetry/check_regression_bounds.py fails the build at lint time, naming the key and the exact value its bound should have, before the workload ever runs. That is the mechanism; the defaults below are only a runtime backstop for the case where that check is bypassed. The defaults carry the FLOOR of each ladder as their absolute bound \u2014 0.01ms for spans, 1us for job_queue \u2014 deliberately too small to bind for any real metric, which leaves max_pct_increase (50%) as the operative bound on this path. Measured: a metric with no override and a baseline of 3900ms passes at +49% and fires at +51%; a job metric with a baseline of 5000us behaves the same. The backstop is honestly imperfect and should not be oversold. At 50% relative it CAN false-fire: a metric whose baseline is 1.06ms inside the 4ms-wide (1,5] bucket fires on a single-bucket-width move (measured: 1.06 \u2192 5.06ms, +377%, regressed). That false fire is NOT to be read as 'the intended signal that the override is missing' \u2014 CI prints REGRESSION and a reader cannot tell it from a real one, and rejecting a tighter alternative for exactly that cries-wolf risk while shipping it here would be inconsistent. The check is what makes the signal legible. The backstop is kept only because a metric silently not gated at all is the worse of the two failures.", "_derivation_table": { "_format": "override key: in -> hi_next - baseline = ", - "job.acceptLedger.queued": "p95 166.13636363636323 in (100,250] -> hi_next 500 - baseline = 333.8636363636368", - "job.acceptLedger.running": "p95 6142.857142857149 in (5000,25000] -> hi_next 100000 - baseline = 93857.14285714286", - "job.transaction.queued": "p95 426.19047619047586 in (250,500] -> hi_next 1000 - baseline = 573.8095238095241", - "job.transaction.running": "p95 599.9999999999986 in (500,1000] -> hi_next 5000 - baseline = 4400.000000000002", - "span.consensus.accept": "p50 0.5287356321839081 in (0.5,1] -> hi_next 5 - baseline = 4.471264367816092 | p95 8.969696969696969 in (5,10] -> hi_next 25 - baseline = 16.03030303030303 | p99 20.800000000000026 in (10,25] -> hi_next 50 - baseline = 29.199999999999974", - "span.consensus.ledger_close": "p95 0.7829999999999997 in (0.5,1] -> hi_next 5 - baseline = 4.2170000000000005 | p99 2.0299999999999896 in (1,5] -> hi_next 10 - baseline = 7.97000000000001 (p50 is NOT gated -- see excluded_keys in regression-metrics.json)", - "span.ledger.build": "p95 4.53333333333333 in (1,5] -> hi_next 10 - baseline = 5.46666666666667 | p99 9.109090909090913 in (5,10] -> hi_next 25 - baseline = 15.890909090909087 (p50 is NOT gated -- see excluded_keys in regression-metrics.json)", - "span.ledger.validate": "p50 0.06471894002114831 in (0.05,0.1] -> hi_next 0.25 - baseline = 0.1852810599788517 (p95 and p99 are NOT gated -- see excluded_keys in regression-metrics.json: their run-to-run spread, 5.9x and 66.8x over four CI runs, exceeds any bound this rule can derive)", - "span.rpc.ws_message": "p50 0.16003451676528602 in (0.1,0.25] -> hi_next 0.5 - baseline = 0.339965483234714 | p95 0.6977397260273974 in (0.5,1] -> hi_next 5 - baseline = 4.302260273972602 | p99 0.9757123287671235 in (0.5,1] -> hi_next 5 - baseline = 4.024287671232877", - "span.tx.apply": "p95 3.524999999999999 in (1,5] -> hi_next 10 - baseline = 6.475000000000001 | p99 5.066666666666704 in (5,10] -> hi_next 25 - baseline = 19.933333333333294 (p50 is NOT gated -- see excluded_keys in regression-metrics.json)", - "span.tx.process": "p50 0.20062219789579117 in (0.1,0.25] -> hi_next 0.5 - baseline = 0.29937780210420883 | p95 0.6100467289719625 in (0.5,1] -> hi_next 5 - baseline = 4.389953271028038 | p99 2.758787878787877 in (1,5] -> hi_next 10 - baseline = 7.241212121212123" + "job.acceptLedger.queued": "p95 95.58333333333331 in (50,100] -> hi_next 250 - baseline = 154.41666666666669", + "job.acceptLedger.running": "p95 15967.741935483866 in (5000,25000] -> hi_next 100000 - baseline = 84032.25806451614", + "job.transaction.queued": "p95 403.74177631578937 in (250,500] -> hi_next 1000 - baseline = 596.2582236842106", + "job.transaction.running": "p95 376.7512077294688 in (250,500] -> hi_next 1000 - baseline = 623.2487922705312", + "span.consensus.accept": "p50 1.4363636363636365 in (1,5] -> hi_next 10 - baseline = 8.563636363636363 | p95 8.811111111111114 in (5,10] -> hi_next 25 - baseline = 16.188888888888886 | p99 20.928571428571445 in (10,25] -> hi_next 50 - baseline = 29.071428571428555", + "span.consensus.ledger_close": "p95 0.6749999999999998 in (0.5,1] -> hi_next 5 - baseline = 4.325 | p99 3.049999999999991 in (1,5] -> hi_next 10 - baseline = 6.950000000000009", + "span.ledger.build": "p95 4.7714285714285705 in (1,5] -> hi_next 10 - baseline = 5.2285714285714295", + "span.ledger.validate": "p50 0.059761904761904766 in (0.05,0.1] -> hi_next 0.25 - baseline = 0.19023809523809523", + "span.rpc.ws_message": "p50 0.16282758747645082 in (0.1,0.25] -> hi_next 0.5 - baseline = 0.3371724125235492 | p95 0.8122454466253443 in (0.5,1] -> hi_next 5 - baseline = 4.187754553374655 | p99 0.9872660098522166 in (0.5,1] -> hi_next 5 - baseline = 4.012733990147783", + "span.tx.apply": "p95 4.639716312056738 in (1,5] -> hi_next 10 - baseline = 5.360283687943262 | p99 4.9733333333333345 in (1,5] -> hi_next 10 - baseline = 5.0266666666666655", + "span.tx.process": "p50 0.21390674968918655 in (0.1,0.25] -> hi_next 0.5 - baseline = 0.28609325031081345 | p95 0.49949970576841685 in (0.25,0.5] -> hi_next 1 - baseline = 0.5005002942315832 | p99 0.9939697679594013 in (0.5,1] -> hi_next 5 - baseline = 4.006030232040599" }, + "_description": "Per-metric regression thresholds. A metric regresses when current - baseline exceeds BOTH the percentage and absolute bounds (AND, not OR \u2014 this tolerates small-value noise). Defaults apply unless a per-metric override exists.", + "_percentage_bound_note": "For every key gated today the absolute bound is the binding half of the AND and the percentage bound never decides the outcome: measured, (bound / baseline) ranges from 121% (span.ledger.build.p95) to 1528% (job.acceptLedger.running.p95), all above the 50% and 5% percentage bounds configured here, and the minimum trip multiple of all 20 keys is set by the absolute bound. THIS IS NOT A GENERAL GUARANTEE. Do not reason from 'every step of both ladders is at least a factor of 2' -- that premise is false. The span ladder breaks it three times at the top: 2s->3s is 1.5x, 3s->4s is 1.33x, 4s->5s is 1.25x, so second-scale consensus quantiles quantize to ~1s widths there. Because the bound is (hi_next - baseline), a baseline between about 2667ms and 3000ms, or between about 3334ms and 4000ms, gets an absolute bound worth less than 50% of itself and the PERCENTAGE bound becomes the operative one -- at which point the metric fires on a 50% move that is smaller than one bucket width, and the single-crossing guarantee in _absolute_bound_derivation is lost. That band is not hypothetical: the collector config names consensus.round (~3.9s) as a reason those edges exist, and 3900ms sits in the second sub-band with an absolute bound of 5000 - 3900 = 1100, only 28.2% of baseline. Whoever gates a key whose baseline lands in either sub-band MUST lower its max_pct_increase below (bound / baseline) for that key, or state explicitly that the metric is percentage-gated and the bucket guarantee does not hold for it. check_regression_bounds.py enforces this as rule D so the trap cannot be walked into silently. The percentage entries are required and still meaningful regardless: compare_to_baseline.py treats a missing max_pct_increase as 'no threshold configured' and would stop gating the metric entirely; they record the intended relative tolerance (consensus spans 5%, everything else 50%); and they are the operative bound on the defaults path (see _defaults_note).", "defaults": { - "span": { - "p50": { - "max_pct_increase": 50.0, - "max_abs_increase_ms": 0.01 - }, - "p95": { - "max_pct_increase": 50.0, - "max_abs_increase_ms": 0.01 - }, - "p99": { - "max_pct_increase": 50.0, - "max_abs_increase_ms": 0.01 - } - }, "job_queue": { "p95": { - "max_pct_increase": 50.0, - "max_abs_increase_us": 1.0 + "max_abs_increase_us": 1.0, + "max_pct_increase": 50.0 + } + }, + "span": { + "p50": { + "max_abs_increase_ms": 0.01, + "max_pct_increase": 50.0 + }, + "p95": { + "max_abs_increase_ms": 0.01, + "max_pct_increase": 50.0 + }, + "p99": { + "max_abs_increase_ms": 0.01, + "max_pct_increase": 50.0 } } }, "overrides": { "job.acceptLedger.queued": { "p95": { - "max_pct_increase": 50.0, - "max_abs_increase_us": 333.8636363636368 + "max_abs_increase_us": 154.41666666666669, + "max_pct_increase": 50.0 } }, "job.acceptLedger.running": { "p95": { - "max_pct_increase": 50.0, - "max_abs_increase_us": 93857.14285714286 + "max_abs_increase_us": 84032.25806451614, + "max_pct_increase": 50.0 } }, "job.transaction.queued": { "p95": { - "max_pct_increase": 50.0, - "max_abs_increase_us": 573.8095238095241 + "max_abs_increase_us": 596.2582236842106, + "max_pct_increase": 50.0 } }, "job.transaction.running": { "p95": { - "max_pct_increase": 50.0, - "max_abs_increase_us": 4400.000000000002 + "max_abs_increase_us": 623.2487922705312, + "max_pct_increase": 50.0 } }, "span.consensus.accept": { "p50": { - "max_pct_increase": 5.0, - "max_abs_increase_ms": 4.471264367816092 + "max_abs_increase_ms": 8.563636363636363, + "max_pct_increase": 5.0 }, "p95": { - "max_pct_increase": 5.0, - "max_abs_increase_ms": 16.03030303030303 + "max_abs_increase_ms": 16.188888888888886, + "max_pct_increase": 5.0 }, "p99": { - "max_pct_increase": 5.0, - "max_abs_increase_ms": 29.199999999999974 + "max_abs_increase_ms": 29.071428571428555, + "max_pct_increase": 5.0 } }, "span.consensus.ledger_close": { "p95": { - "max_pct_increase": 5.0, - "max_abs_increase_ms": 4.2170000000000005 + "max_abs_increase_ms": 4.325, + "max_pct_increase": 5.0 }, "p99": { - "max_pct_increase": 5.0, - "max_abs_increase_ms": 7.97000000000001 + "max_abs_increase_ms": 6.950000000000009, + "max_pct_increase": 5.0 } }, "span.ledger.build": { "p95": { - "max_pct_increase": 50.0, - "max_abs_increase_ms": 5.46666666666667 - }, - "p99": { - "max_pct_increase": 50.0, - "max_abs_increase_ms": 15.890909090909087 + "max_abs_increase_ms": 5.2285714285714295, + "max_pct_increase": 50.0 } }, "span.ledger.validate": { "p50": { - "max_pct_increase": 50.0, - "max_abs_increase_ms": 0.1852810599788517 + "max_abs_increase_ms": 0.19023809523809523, + "max_pct_increase": 50.0 } }, "span.rpc.ws_message": { "p50": { - "max_pct_increase": 50.0, - "max_abs_increase_ms": 0.339965483234714 + "max_abs_increase_ms": 0.3371724125235492, + "max_pct_increase": 50.0 }, "p95": { - "max_pct_increase": 50.0, - "max_abs_increase_ms": 4.302260273972602 + "max_abs_increase_ms": 4.187754553374655, + "max_pct_increase": 50.0 }, "p99": { - "max_pct_increase": 50.0, - "max_abs_increase_ms": 4.024287671232877 + "max_abs_increase_ms": 4.012733990147783, + "max_pct_increase": 50.0 } }, "span.tx.apply": { "p95": { - "max_pct_increase": 50.0, - "max_abs_increase_ms": 6.475000000000001 + "max_abs_increase_ms": 5.360283687943262, + "max_pct_increase": 50.0 }, "p99": { - "max_pct_increase": 50.0, - "max_abs_increase_ms": 19.933333333333294 + "max_abs_increase_ms": 5.0266666666666655, + "max_pct_increase": 50.0 } }, "span.tx.process": { "p50": { - "max_pct_increase": 50.0, - "max_abs_increase_ms": 0.29937780210420883 + "max_abs_increase_ms": 0.28609325031081345, + "max_pct_increase": 50.0 }, "p95": { - "max_pct_increase": 50.0, - "max_abs_increase_ms": 4.389953271028038 + "max_abs_increase_ms": 0.5005002942315832, + "max_pct_increase": 50.0 }, "p99": { - "max_pct_increase": 50.0, - "max_abs_increase_ms": 7.241212121212123 + "max_abs_increase_ms": 4.006030232040599, + "max_pct_increase": 50.0 } } } diff --git a/docker/telemetry/workload/test_tx_submitter.py b/docker/telemetry/workload/test_tx_submitter.py new file mode 100644 index 0000000000..766a07e511 --- /dev/null +++ b/docker/telemetry/workload/test_tx_submitter.py @@ -0,0 +1,264 @@ +#!/usr/bin/env python3 +"""Tests for tx_submitter.py's account-funding confirmation. + +Run with plain python3 -- there is no pytest in the harness requirements, and +this file needs nothing but the standard library: + + python3 docker/telemetry/workload/test_tx_submitter.py + +What is under test is how setup decides an account is usable. The old code +submitted the funding Payment, slept a flat 10 seconds, and read each sequence +once. Under the txq-burst and mixed-peak phases the open-ledger fee is +escalated on purpose, so the funding transactions sit in the TxQ, every account +reads Sequence 0, and the phase aborts with "only 0 of 8 created accounts were +funded". Every way of getting the wait wrong is expensive rather than silent: +the phase sends no traffic and the whole run reddens. + +Both halves are covered: that a late confirmation is still seen, and that a +confirmation which never arrives ends at a deadline instead of hanging. +""" + +import asyncio +import itertools +import json +import logging +import sys +from pathlib import Path +from typing import Any + +sys.path.insert(0, str(Path(__file__).parent)) + +import tx_submitter as tx # noqa: E402 + +# The functions under test log per account per poll, and the deadline tests +# poll until they time out. At INFO that buries the PASS/FAIL lines in hundreds +# of kilobytes of expected output. +tx.logger.setLevel(logging.CRITICAL) + + +class FakeWs: + """Minimal stand-in for a rippled WebSocket connection. + + Speaks enough of the native protocol for ws_request to work: it echoes the + request id and wraps the canned payload in ``result``. Driving the real + ws_request rather than stubbing it keeps the id-matching logic in the test + path, since that is where a reply can be mis-attributed. + + Args: + sequences: Per-account iterables of the Sequence values account_info + should report on successive calls. A value of 0 means the + account root does not exist yet. + fee_result: Payload for the ``fee`` command. + """ + + def __init__( + self, + sequences: dict[str, Any] | None = None, + fee_result: dict[str, Any] | None = None, + ) -> None: + self._sequences = {k: iter(v) for k, v in (sequences or {}).items()} + self._fee_result = fee_result + self._outbox: list[str] = [] + self.commands: list[str] = [] + self.account_info_calls = 0 + + async def send(self, payload: str) -> None: + request = json.loads(payload) + command = request["command"] + self.commands.append(command) + + if command == "account_info": + self.account_info_calls += 1 + account = request["account"] + try: + seq = next(self._sequences[account]) + except StopIteration: + seq = 0 + # rippled omits account_data entirely for an account that does not + # exist, which is what get_account_sequence turns into 0. + result: dict[str, Any] = ( + {"account_data": {"Sequence": seq}} if seq else {"error": "actNotFound"} + ) + elif command == "fee": + result = self._fee_result if self._fee_result is not None else {} + else: + result = {"engine_result": "tesSUCCESS"} + + self._outbox.append( + json.dumps({"id": request["id"], "status": "success", "result": result}) + ) + + async def recv(self) -> str: + return self._outbox.pop(0) + + +def _accounts(*names: str) -> list[tx.Account]: + """Accounts whose addresses are their names, so fakes can key on them.""" + return [tx.Account(name=n, account=n, seed=f"seed-{n}") for n in names] + + +def test_late_confirmation_is_still_seen() -> None: + """A sequence that only appears on a later poll must still confirm. + + This is the whole defect: the funding transaction was queued, so the first + reads report nothing. Confirming late is the normal case under load, not an + error. + + The production change that makes this fail: reading each sequence once, or + going back to a fixed sleep followed by a single read. + """ + accts = _accounts("alice", "bob") + ws = FakeWs(sequences={"alice": [0, 0, 7], "bob": [0, 0, 9]}) + + confirmed = asyncio.run( + tx.wait_for_funding(ws, accts, timeout_sec=5.0, poll_sec=0.0) + ) + + assert confirmed == 2, confirmed + assert [a.funded for a in accts] == [True, True] + assert [a.sequence for a in accts] == [7, 9] + + +def test_returns_as_soon_as_everything_confirms() -> None: + """A healthy cluster must not pay any waiting cost. + + The old code slept 10 seconds unconditionally, on every transaction phase. + One pass over the accounts is enough when they are already funded. + + The production change that makes this fail: polling to the deadline + regardless, or sleeping before the first read instead of after a miss. + """ + accts = _accounts("alice", "bob", "carol") + ws = FakeWs(sequences={"alice": [3], "bob": [4], "carol": [5]}) + + confirmed = asyncio.run( + tx.wait_for_funding(ws, accts, timeout_sec=30.0, poll_sec=10.0) + ) + + assert confirmed == 3, confirmed + # Exactly one account_info per account: a second round would mean it kept + # polling after everything had already confirmed. + assert ws.account_info_calls == 3, ws.account_info_calls + + +def test_deadline_is_honoured_when_nothing_confirms() -> None: + """A cluster that never funds must end at the deadline, not hang. + + The generator runs under a phase budget, so an unbounded wait would be + killed by the orchestrator and report as a timeout rather than as a funding + failure, which points at the wrong component. + + The production change that makes this fail: looping while any account is + unconfirmed without checking elapsed time. + """ + accts = _accounts("alice", "bob") + ws = FakeWs(sequences={"alice": itertools.repeat(0), "bob": itertools.repeat(0)}) + + confirmed = asyncio.run( + tx.wait_for_funding(ws, accts, timeout_sec=0.05, poll_sec=0.01) + ) + + assert confirmed == 0, confirmed + assert [a.funded for a in accts] == [False, False] + + +def test_only_confirmed_accounts_are_marked_funded() -> None: + """Partial funding must leave the unconfirmed account unusable. + + The builders address accounts by position, so an unfunded account left in + the usable list fails every transaction it is picked for. + + The production change that makes this fail: setting funded for the whole + list once any account confirms, or leaving funded at its submit-time value. + """ + accts = _accounts("alice", "bob") + ws = FakeWs(sequences={"alice": [0, 11], "bob": itertools.repeat(0)}) + + confirmed = asyncio.run( + tx.wait_for_funding(ws, accts, timeout_sec=0.05, poll_sec=0.01) + ) + + assert confirmed == 1, confirmed + assert accts[0].funded is True and accts[0].sequence == 11 + assert accts[1].funded is False + + +def test_open_ledger_fee_is_read_from_the_fee_rpc() -> None: + """The funding fee must come from current load, not a constant. + + Escalation is deliberate in the txq-burst phase, so a funding Payment at + the base fee is exactly the one that gets queued. + + The production change that makes this fail: returning the fallback + unconditionally, or reading base_fee instead of open_ledger_fee. + """ + ws = FakeWs(fee_result={"drops": {"base_fee": "10", "open_ledger_fee": "5320"}}) + + assert asyncio.run(tx.get_open_ledger_fee(ws)) == 5320 + + +def test_open_ledger_fee_falls_back_when_absent() -> None: + """A missing fee field must not abort account setup. + + Fee lookup is an optimisation for the funding path. If the field is absent + or unparseable, funding should still be attempted at a sane fee. + + The production change that makes this fail: indexing the response directly, + or letting a ValueError from int() escape. + """ + assert asyncio.run(tx.get_open_ledger_fee(FakeWs(fee_result={}))) == ( + tx.FUNDING_FEE_FALLBACK_DROPS + ) + ws = FakeWs(fee_result={"drops": {"open_ledger_fee": "not-a-number"}}) + assert asyncio.run(tx.get_open_ledger_fee(ws)) == tx.FUNDING_FEE_FALLBACK_DROPS + + +def test_funding_wait_fits_inside_the_orchestrator_budget() -> None: + """The funding wait must not outlast the grace the orchestrator allows. + + Setup can wait twice, once after the first submit and once after the retry. + If that exceeds SUBPROCESS_GRACE_SEC the generator is killed mid-wait and the + phase records a timeout, which points at the orchestrator instead of at the + funding that actually failed. These are two constants in two files with + nothing but this test tying them together. + + The production change that makes this fail: raising + FUNDING_CONFIRM_TIMEOUT_SEC without raising SUBPROCESS_GRACE_SEC. + """ + import workload_orchestrator as wo + + worst_case = 2 * tx.FUNDING_CONFIRM_TIMEOUT_SEC + assert worst_case < wo.SUBPROCESS_GRACE_SEC, ( + f"funding can wait {worst_case}s but the grace is " + f"{wo.SUBPROCESS_GRACE_SEC}s" + ) + + +def main() -> int: + tests = [v for k, v in sorted(globals().items()) if k.startswith("test_")] + # Collecting nothing is a failure, not a pass -- the same silent-green trap + # the tests themselves guard against, reproduced in the runner. + if not tests: + print("FAIL: no tests were collected") + return 1 + failed = 0 + for test in tests: + try: + test() + except AssertionError as exc: + failed += 1 + print(f"FAIL {test.__name__}: {exc}") + except SystemExit as exc: + failed += 1 + print(f"ERROR {test.__name__}: SystemExit({exc.code})") + except Exception as exc: # noqa: BLE001 - report any error as a failure + failed += 1 + print(f"ERROR {test.__name__}: {type(exc).__name__}: {exc}") + else: + print(f"PASS {test.__name__}") + print(f"\n{len(tests) - failed}/{len(tests)} passed") + return 1 if failed else 0 + + +if __name__ == "__main__": + sys.exit(main()) diff --git a/docker/telemetry/workload/tx_submitter.py b/docker/telemetry/workload/tx_submitter.py index b05b567bbf..8a987770d3 100644 --- a/docker/telemetry/workload/tx_submitter.py +++ b/docker/telemetry/workload/tx_submitter.py @@ -108,6 +108,29 @@ SEQ_CONSUMING_RESULTS = frozenset({"tesSUCCESS", "terQUEUED"}) # it triggers within a few seconds, well before the periodic refresh below. SEQ_REFETCH_AFTER_FAILURES = 5 +# How long account setup waits for the funding transactions to be validated, +# and how often it re-reads the ledger while waiting. A fixed sleep cannot work +# here: the txq-burst phase escalates the open-ledger fee on purpose, so funding +# can sit in the TxQ for several ledger closes. +# +# Setup can wait twice -- once after the first submit, once after the retry -- +# so the ceiling is 2x this. It must stay inside the orchestrator's +# SUBPROCESS_GRACE_SEC or a slow fund is killed as a timeout instead of being +# reported as a funding failure. At a ~4s close, 30s is about 7 closes, and a +# funding transaction paying FUNDING_FEE_MULTIPLIER times the open-ledger fee +# should clear the next one. +FUNDING_CONFIRM_TIMEOUT_SEC = 30.0 +FUNDING_POLL_INTERVAL_SEC = 2.0 + +# Multiple of the current open-ledger fee paid for funding transactions. +# Genesis holds every drop, so overpaying costs nothing and keeps funding ahead +# of the load the workload phases create deliberately. +FUNDING_FEE_MULTIPLIER = 20 + +# Fee used when the fee RPC reports no usable open-ledger fee. Well above the +# 10-drop base fee, so funding still clears a mildly loaded queue. +FUNDING_FEE_FALLBACK_DROPS = 1000 + # How often the submission loop re-reads every account's sequence from the # ledger, to stay close to sequences other submitters have advanced. SEQ_REFRESH_INTERVAL_S = 10.0 @@ -338,16 +361,23 @@ async def fund_account( ws: websockets.ClientConnection, dest: Account, genesis_seq: int, + fee_drops: int, ) -> tuple[bool, int]: - """Fund a test account from genesis. + """Submit a funding Payment to a test account from genesis. + + The returned flag means the submit was accepted, not that the account + exists. Only a ledger read proves that, so callers must confirm with + wait_for_funding rather than trusting this result. Args: ws: Open WebSocket connection. dest: Destination account to fund. genesis_seq: Current genesis account sequence number. + fee_drops: Fee to pay, in drops. Set explicitly so funding is not + queued behind the load a workload phase creates. Returns: - Tuple of (funded: bool, next_genesis_sequence: int). The sequence is + Tuple of (submitted: bool, next_genesis_sequence: int). The sequence is unchanged when the ledger did not consume it. """ resp = await ws_request( @@ -361,6 +391,7 @@ async def fund_account( "Destination": dest.account, "Amount": FUND_AMOUNT, "Sequence": genesis_seq, + "Fee": str(fee_drops), }, }, ) @@ -405,6 +436,97 @@ async def get_account_sequence(ws: websockets.ClientConnection, account: str) -> return resp["account_data"].get("Sequence", 0) +async def get_open_ledger_fee(ws: websockets.ClientConnection) -> int: + """Read the current open-ledger fee in drops. + + Returns FUNDING_FEE_FALLBACK_DROPS when the fee RPC reports no usable + value. The lookup only sizes the funding fee, so a missing field must not + stop funding being attempted. + + Args: + ws: Open WebSocket connection. + + Returns: + Open-ledger fee in drops, or the fallback. + """ + resp = await ws_request(ws, "fee") + raw = resp.get("drops", {}).get("open_ledger_fee") + try: + fee = int(raw) # type: ignore[arg-type] + except (TypeError, ValueError): + logger.warning( + "fee RPC reported no usable open_ledger_fee (%r); using %d drops", + raw, + FUNDING_FEE_FALLBACK_DROPS, + ) + return FUNDING_FEE_FALLBACK_DROPS + return fee if fee > 0 else FUNDING_FEE_FALLBACK_DROPS + + +async def wait_for_funding( + ws: websockets.ClientConnection, + accounts: list[Account], + timeout_sec: float = FUNDING_CONFIRM_TIMEOUT_SEC, + poll_sec: float = FUNDING_POLL_INTERVAL_SEC, +) -> int: + """Poll the ledger until every account has a sequence number. + + Sets ``sequence`` and ``funded`` from what the ledger reports, so a queued + or dropped funding transaction can never leave an account marked usable. + Returns as soon as every account confirms, so a healthy cluster pays no + waiting cost. + + Args: + ws: Open WebSocket connection. + accounts: Accounts whose funding was submitted. + timeout_sec: Give up after this long. The generator runs under a phase + budget, so an unbounded wait would be killed as a timeout + and point at the wrong component. + poll_sec: Delay between rounds. + + Returns: + Number of accounts confirmed on the ledger. + """ + deadline = time.monotonic() + timeout_sec + pending = list(accounts) + + while True: + still_pending: list[Account] = [] + for acct in pending: + try: + seq = await get_account_sequence(ws, acct.account) + except Exception as exc: # noqa: BLE001 - a read failure is a retry + logger.warning(" Failed to read sequence for %s: %s", acct.name, exc) + seq = 0 + if seq > 0: + acct.sequence = seq + acct.funded = True + logger.info(" %s funded, sequence %d", acct.name, seq) + else: + still_pending.append(acct) + + pending = still_pending + confirmed = sum(1 for acct in accounts if acct.funded) + if not pending: + return confirmed + + if time.monotonic() >= deadline: + for acct in pending: + acct.funded = False + logger.warning( + " %s never got a ledger sequence — treating as unfunded", + acct.name, + ) + return confirmed + + logger.info( + "Waiting for %d of %d accounts to be funded...", + len(pending), + len(accounts), + ) + await asyncio.sleep(poll_sec) + + # --------------------------------------------------------------------------- # Transaction builders # --------------------------------------------------------------------------- @@ -681,8 +803,10 @@ async def setup_accounts( ) -> list[Account]: """Create and fund test accounts from genesis. - Generates NUM_TEST_ACCOUNTS accounts via wallet_propose, then funds - each with FUND_AMOUNT XRP from genesis. + Generates NUM_TEST_ACCOUNTS accounts via wallet_propose, then funds each + with FUND_AMOUNT XRP from genesis. Funding is confirmed against the ledger, + not from the submit result, and the accounts that did not confirm are + resubmitted once. Args: ws: Open WebSocket connection to a rippled node. @@ -704,42 +828,44 @@ async def setup_accounts( genesis_seq = await get_account_sequence(ws, GENESIS_ACCOUNT) logger.info("Genesis sequence: %d", genesis_seq) - # Fund all accounts. - logger.info("Funding test accounts...") + # Fund all accounts. An explicit fee keeps the funding Payments ahead of + # the load a phase creates on purpose; without it they queue behind it. + fee_drops = await get_open_ledger_fee(ws) * FUNDING_FEE_MULTIPLIER + logger.info("Funding test accounts (fee %d drops)...", fee_drops) for acct in accounts: - acct.funded, genesis_seq = await fund_account(ws, acct, genesis_seq) - if acct.funded: - logger.info(" Funded %s", acct.name) - else: - logger.warning(" Failed to fund %s", acct.name) + submitted, genesis_seq = await fund_account(ws, acct, genesis_seq, fee_drops) + if not submitted: + logger.warning(" Failed to submit funding for %s", acct.name) - # Wait for funding transactions to be validated. - logger.info("Waiting 10s for funding transactions to validate...") - await asyncio.sleep(10) + confirmed = await wait_for_funding(ws, accounts) - # Refresh sequence numbers, and confirm funding against the ledger rather - # than trusting the submit result. get_account_sequence returns 0 when - # account_info reports no account_data, which means the account root was - # never created; a sequence we cannot read also makes the account - # unusable, so either way it must not be submitted from. - for acct in accounts: - try: - acct.sequence = await get_account_sequence(ws, acct.account) - except Exception as exc: - logger.warning(" Failed to get sequence for %s: %s", acct.name, exc) - if acct.sequence > 0: - logger.info(" %s sequence: %d", acct.name, acct.sequence) - else: - acct.funded = False - logger.warning( - " %s has no ledger sequence — treating as unfunded", acct.name + # One retry round. A queued funding transaction can be dropped, and + # consumes_sequence has already advanced the local genesis sequence past it, + # so re-read genesis from the ledger first. Retrying on the drifted counter + # would put every resubmit on a future sequence and fund nothing. + if confirmed < MIN_FUNDED_ACCOUNTS: + unfunded = [acct for acct in accounts if not acct.funded] + genesis_seq = await get_account_sequence(ws, GENESIS_ACCOUNT) + fee_drops = await get_open_ledger_fee(ws) * FUNDING_FEE_MULTIPLIER + logger.warning( + "Only %d of %d accounts funded; retrying %d from genesis sequence " + "%d at %d drops", + confirmed, + len(accounts), + len(unfunded), + genesis_seq, + fee_drops, + ) + for acct in unfunded: + submitted, genesis_seq = await fund_account( + ws, acct, genesis_seq, fee_drops ) + if not submitted: + logger.warning(" Retry failed to submit funding for %s", acct.name) + await wait_for_funding(ws, unfunded) + confirmed = sum(1 for acct in accounts if acct.funded) - logger.info( - "Funded %d of %d created accounts", - sum(1 for a in accounts if a.funded), - len(accounts), - ) + logger.info("Funded %d of %d created accounts", confirmed, len(accounts)) return accounts diff --git a/docker/telemetry/workload/workload_orchestrator.py b/docker/telemetry/workload/workload_orchestrator.py index 3df9d80ea4..5231ca8ca7 100755 --- a/docker/telemetry/workload/workload_orchestrator.py +++ b/docker/telemetry/workload/workload_orchestrator.py @@ -56,11 +56,16 @@ PROFILES_FILE = SCRIPT_DIR / "workload-profiles.json" # Wall-clock allowance for a generator on top of its phase's configured # duration. It has to cover the work the generators do outside their timed # loop: tx_submitter.py creates and funds 8 accounts (~25 WebSocket round -# trips) and then waits a fixed 10s for those funding transactions to -# validate, and both generators drain in-flight requests while shutting down. +# trips), then polls the ledger until those funding transactions validate, and +# both generators drain in-flight requests while shutting down. # A generator that outruns this is killed and the phase records the timeout as # an error, so one wedged process cannot stall the whole profile. -SUBPROCESS_GRACE_SEC = 90.0 +# +# The funding wait is the largest term and it can run twice, so this must stay +# above 2 x tx_submitter.FUNDING_CONFIRM_TIMEOUT_SEC (2 x 30s) plus the round +# trips. Otherwise a slow fund is killed here and reported as a timeout, which +# points at the orchestrator rather than at the funding it actually was. +SUBPROCESS_GRACE_SEC = 120.0 # How long to keep reading a killed process's output before giving up on it. SUBPROCESS_DRAIN_TIMEOUT_SEC = 10.0 @@ -264,24 +269,60 @@ async def run_subprocess( # --------------------------------------------------------------------------- +def _write_generator_log( + report_path: Path, label: str, returncode: int, stdout: str, stderr: str +) -> None: + """Save a generator's full output beside its JSON report. + + Only the last 200 characters of stderr reach the phase error, and stdout was + dropped entirely, so a setup failure inside a generator left nothing to read + in CI. Written on success too, because the warnings that explain a thin run + appear on runs that still pass. + + Args: + report_path: The generator's JSON report path; the log sits next to it. + label: "rpc" or "tx". + returncode: Subprocess exit code. + stdout: Captured stdout text. + stderr: Captured stderr text. + """ + log_path = report_path.with_suffix(".log") + try: + with open(log_path, "w") as f: + f.write(f"=== {label} generator exited with {returncode} ===\n") + f.write("--- stdout ---\n") + f.write(stdout) + f.write("\n--- stderr ---\n") + f.write(stderr) + f.write("\n") + except OSError as exc: + # Losing the log must not fail the phase; it is a diagnostic aid. + logger.warning("Failed to write %s generator log %s: %s", label, log_path, exc) + + def _collect_task_result( label: str, returncode: int, + stdout: str, stderr: str, report_path: Path, result: PhaseResult, ) -> None: """Process the result of a completed subprocess task. - Reads the JSON report file (if it exists) and records any errors. + Reads the JSON report file (if it exists), saves the generator's full + output, and records any errors. Args: label: "rpc" or "tx". returncode: Subprocess exit code. + stdout: Captured stdout text. stderr: Captured stderr text. report_path: Path to the JSON report file. result: PhaseResult to update. """ + _write_generator_log(report_path, label, returncode, stdout, stderr) + if report_path.exists(): try: with open(report_path) as f: @@ -384,6 +425,8 @@ def _launch_phase_tasks( if rpc_cfg: rpc_out = report_dir / f"{prefix}-rpc.json" rpc_out.unlink(missing_ok=True) + # Same reason as the report: a stale log must not read as this run's. + rpc_out.with_suffix(".log").unlink(missing_ok=True) cmd = _build_rpc_cmd(endpoints, rpc_cfg, duration, rpc_out) task = asyncio.create_task(run_subprocess(cmd, f"RPC [{name}]", timeout)) tasks.append(("rpc", rpc_out, task)) @@ -392,6 +435,8 @@ def _launch_phase_tasks( if tx_cfg: tx_out = report_dir / f"{prefix}-tx.json" tx_out.unlink(missing_ok=True) + # Same reason as the report: a stale log must not read as this run's. + tx_out.with_suffix(".log").unlink(missing_ok=True) cmd = _build_tx_cmd(endpoints[0], tx_cfg, duration, tx_out) task = asyncio.create_task(run_subprocess(cmd, f"TX [{name}]", timeout)) tasks.append(("tx", tx_out, task)) @@ -449,8 +494,8 @@ async def run_phase( return result for label, report_path, task in tasks: - returncode, _stdout, stderr = await task - _collect_task_result(label, returncode, stderr, report_path, result) + returncode, stdout, stderr = await task + _collect_task_result(label, returncode, stdout, stderr, report_path, result) result.actual_sec = time.monotonic() - t0 logger.info( diff --git a/include/xrpl/server/Wallet.h b/include/xrpl/server/Wallet.h index af6c92b83d..8a1a76c55c 100644 --- a/include/xrpl/server/Wallet.h +++ b/include/xrpl/server/Wallet.h @@ -7,6 +7,7 @@ #include #include #include +#include #include #include @@ -83,6 +84,46 @@ saveManifests( void addValidatorManifest(soci::session& session, std::string const& serialized); +/** + * The seed a configured [node_seed] or --nodeid names. + * + * The command-line value wins when both are set. A cmdline value is parsed + * with parseGenericSeed(rfc1751=false); a config value is parsed as Base58 + * only. Empty inputs count as supplied-but-invalid and throw. + * + * @param cmdlineSeed The --nodeid value, or std::nullopt when not passed. + * @param configSeed The first line of [node_seed], or std::nullopt when the + * section is absent. An empty section is passed as "". + * @return The parsed seed, or std::nullopt when neither is set. + * @throws std::runtime_error if the value present is malformed. + */ +[[nodiscard]] std::optional +parseNodeIdentitySeed( + std::optional const& cmdlineSeed, + std::optional const& configSeed); + +/** + * Pick this node's keypair from a pre-parsed seed and a stored-key reader. + * + * A configured seed wins outright and the reader is not consulted. When + * newNodeId is set, mint a fresh pair and skip the reader too. Otherwise + * consult the reader; return its pair if it has one, else mint. + * + * Lifting the decision out of the Application layer lets libxrpl-level + * tests drive every branch without an xrpld Config. + * + * @param configuredSeed Seed from parseNodeIdentitySeed(), or std::nullopt. + * @param newNodeId True when --newnodeid was passed. + * @param readStored Callable that returns the wallet's stored pair, or + * std::nullopt when nothing is stored. + * @return This node's keypair. + */ +[[nodiscard]] std::pair +selectNodeIdentity( + std::optional const& configuredSeed, + bool newNodeId, + std::function>()> const& readStored); + /** * Delete any saved public/private key associated with this node. */ @@ -102,6 +143,22 @@ clearNodeIdentity(soci::session& session); std::optional> readNodeIdentity(soci::session& session); +/** + * Persist a keypair as this node's identity. + * + * Write-only counterpart of readNodeIdentity(). The caller must have found the + * table empty: this inserts a row without clearing, so storing twice leaves two + * and readNodeIdentity() then returns whichever the query yields first. + * + * Exists because xrpld resolves its identity before the Application, and so + * before any database, is built; setup() persists that keypair here. + * + * @param session Session with the database. + * @param keys The keypair to store. + */ +void +storeNodeIdentity(soci::session& session, std::pair const& keys); + /** * Returns a stable public and private key for this node. * diff --git a/include/xrpl/telemetry/Telemetry.h b/include/xrpl/telemetry/Telemetry.h index 899034d3af..21f0440a3d 100644 --- a/include/xrpl/telemetry/Telemetry.h +++ b/include/xrpl/telemetry/Telemetry.h @@ -134,6 +134,25 @@ inline constexpr std::string_view kMeterName{"xrpld"}; * OTel instrumentation scope version reported for the meter. */ inline constexpr std::string_view kMeterVersion{"1.0.0"}; + +/** + * A meter whose instruments record nothing. + * + * For every path that must hand out a usable meter without a pipeline behind + * it: telemetry disabled, or an exporter that failed to build. Callers then + * need no null check, because an instrument always comes back. + * + * Two details are easy to get wrong alone, which is why this is shared: the + * provider must be reached through a base `MeterProvider` pointer, because + * `NoopMeterProvider`'s override hides the base class's defaulted overload; + * and the version must be @ref kMeterVersion, or the meter identity differs + * from the one the histogram views select on. + * + * @param name Instrumentation scope name to report. + * @return An inert meter. Never empty. + */ +[[nodiscard]] opentelemetry::nostd::shared_ptr +noopMeter(std::string_view name = kMeterName); #endif /** diff --git a/src/libxrpl/beast/insight/OTelCollector.cpp b/src/libxrpl/beast/insight/OTelCollector.cpp index bb720ad086..25f313b689 100644 --- a/src/libxrpl/beast/insight/OTelCollector.cpp +++ b/src/libxrpl/beast/insight/OTelCollector.cpp @@ -512,17 +512,25 @@ public: /** * @brief Register a hook for periodic invocation. - * @param hook Pointer to the hook to register. + * + * Takes the owning shared_ptr so the list can store a weak reference. + * Called from makeHook() rather than the hook's constructor, because a + * weak_ptr cannot be formed until the shared_ptr owns the object. + * + * @param hook Owning pointer to the hook to register. */ void - addHook(OTelHookImpl* hook); + addHook(std::shared_ptr const& hook); /** - * @brief Unregister a hook. - * @param hook Pointer to the hook to unregister. + * @brief Drop entries for hooks that have been destroyed. + * + * Called from ~OTelHookImpl. The dying hook's weak_ptr has already + * expired by then, so the entry is identified by expiry rather than by + * address. */ void - removeHook(OTelHookImpl* hook); + removeExpiredHooks(); /** * @brief Invoke all registered hooks. @@ -541,17 +549,25 @@ public: /** * @brief Register a gauge for observable callback reading. - * @param gauge Pointer to the gauge to register. + * + * Takes the owning shared_ptr so the list can store a weak reference. + * Called from makeGauge() rather than the gauge's constructor, because a + * weak_ptr cannot be formed until the shared_ptr owns the object. + * + * @param gauge Owning pointer to the gauge to register. */ void - addGauge(OTelGaugeImpl* gauge); + addGauge(std::shared_ptr const& gauge); /** - * @brief Unregister a gauge. - * @param gauge Pointer to the gauge to unregister. + * @brief Drop entries for gauges that have been destroyed. + * + * Called from ~OTelGaugeImpl. The dying gauge's weak_ptr has already + * expired by then, so the entry is identified by expiry rather than by + * address. */ void - removeGauge(OTelGaugeImpl* gauge); + removeExpiredGauges(); /** @} */ /** @@ -600,13 +616,30 @@ private: /** * Registered hooks called during observable callbacks. + * + * Weak, not owning, and not raw. callHooks() must invoke handlers with + * mutex_ released, because a handler may drop the last reference to a + * hook and ~OTelHookImpl re-acquires mutex_. A raw pointer copied out of + * this list could therefore be dangling by the time it is dereferenced. + * Locking a weak_ptr instead keeps the hook alive for exactly the + * duration of its own handler call, and an already-destroyed hook is + * skipped rather than followed. */ - std::vector hooks_; + std::vector> hooks_; /** * Registered gauges read during observable callbacks. + * + * Weak for the same reason as hooks_. onCollectionReady() and + * onCollectionStopping() snapshot this list and then call arm()/disarm() + * with mutex_ released, because both enter the SDK's observable registry + * lock. A raw pointer copied out of the list could be dangling by then, + * since ~OTelGaugeImpl only re-acquires mutex_ to prune its own entry. + * Locking a weak_ptr keeps the gauge alive for exactly the duration of + * that arm or disarm call, and one destroyed since the snapshot is + * skipped rather than followed. */ - std::vector gauges_; + std::vector> gauges_; /** * @brief Shortest gap between two hook invocations. @@ -637,12 +670,14 @@ private: OTelHookImpl::OTelHookImpl(HandlerType handler, std::shared_ptr impl) : impl_(std::move(impl)), handler_(std::move(handler)) { - impl_->addHook(this); + // Registration happens in OTelCollectorImp::makeHook(), not here: the + // list holds weak references, and no weak_ptr to this object exists + // until the owning shared_ptr does. } OTelHookImpl::~OTelHookImpl() { - impl_->removeHook(this); + impl_->removeExpiredHooks(); } void @@ -699,7 +734,8 @@ OTelEventImpl::notify(value_type const& value) OTelGaugeImpl::OTelGaugeImpl(std::string name, std::shared_ptr const& collector) : name_(std::move(name)), collector_(collector) { - collector_->addGauge(this); + // Registration happens in makeGauge(), not here: no weak_ptr to this + // object exists until the owning shared_ptr does. } void @@ -749,7 +785,7 @@ OTelGaugeImpl::~OTelGaugeImpl() // callback for this instrument is in flight — removal is synchronous. // A no-op when never armed, or already disarmed at shutdown. disarm(); - collector_->removeGauge(this); + collector_->removeExpiredGauges(); } void @@ -852,7 +888,9 @@ OTelCollectorImp::~OTelCollectorImp() Hook OTelCollectorImp::makeHook(HookImpl::HandlerType const& handler) { - return Hook(std::make_shared(handler, shared_from_this())); + auto hook = std::make_shared(handler, shared_from_this()); + addHook(hook); + return Hook(hook); } Counter @@ -876,7 +914,9 @@ OTelCollectorImp::makeEvent(std::string const& name, Unit unit) Gauge OTelCollectorImp::makeGauge(std::string const& name) { - return Gauge(std::make_shared(formatName(name), shared_from_this())); + auto gauge = std::make_shared(formatName(name), shared_from_this()); + addGauge(gauge); + return Gauge(gauge); } Meter @@ -886,17 +926,17 @@ OTelCollectorImp::makeMeter(std::string const& name) } void -OTelCollectorImp::addHook(OTelHookImpl* hook) +OTelCollectorImp::addHook(std::shared_ptr const& hook) { std::scoped_lock const lock(mutex_); - hooks_.push_back(hook); + hooks_.emplace_back(hook); } void -OTelCollectorImp::removeHook(OTelHookImpl* hook) +OTelCollectorImp::removeExpiredHooks() { std::scoped_lock const lock(mutex_); - std::erase(hooks_, hook); + std::erase_if(hooks_, [](std::weak_ptr const& hook) { return hook.expired(); }); } void @@ -913,29 +953,37 @@ OTelCollectorImp::callHooks() // Copy the hook list under the lock, then invoke handlers outside it. // A handler may drop the last reference to an OTelHookImpl, whose - // destructor calls removeHook() and re-acquires mutex_; invoking - // handlers while holding the (non-recursive) lock would deadlock. - std::vector hooks; + // destructor re-acquires mutex_; invoking handlers while holding the + // (non-recursive) lock would deadlock. + std::vector> hooks; { std::scoped_lock const lock(mutex_); hooks = hooks_; } - for (auto* hook : hooks) - hook->callHandler(); + + // Locking each entry keeps that hook alive across its own handler call, + // so releasing mutex_ above cannot leave a dangling reference. A hook + // destroyed since the snapshot was taken locks to null and is skipped. + for (auto const& weakHook : hooks) + { + if (auto const hook = weakHook.lock()) + hook->callHandler(); + } } void -OTelCollectorImp::addGauge(OTelGaugeImpl* gauge) +OTelCollectorImp::addGauge(std::shared_ptr const& gauge) { std::scoped_lock const lock(mutex_); - gauges_.push_back(gauge); + gauges_.emplace_back(gauge); } void -OTelCollectorImp::removeGauge(OTelGaugeImpl* gauge) +OTelCollectorImp::removeExpiredGauges() { std::scoped_lock const lock(mutex_); - std::erase(gauges_, gauge); + std::erase_if( + gauges_, [](std::weak_ptr const& gauge) { return gauge.expired(); }); } void @@ -945,15 +993,24 @@ OTelCollectorImp::onCollectionReady() // observable registry lock, and the reader thread takes that lock before // calling callHooks(), which wants mutex_. callHooks() copies its hook list // for the same reason. - std::vector gauges; + std::vector> gauges; { std::scoped_lock const lock(mutex_); gauges = gauges_; } std::size_t armed = 0; - for (auto* gauge : gauges) + std::size_t live = 0; + for (auto const& weakGauge : gauges) { + // Locking keeps this gauge alive across its own arm() call. One + // destroyed since the snapshot locks to null and is skipped, and is + // not counted in the total below: it has no metric to register. + auto const gauge = weakGauge.lock(); + if (!gauge) + continue; + ++live; + // Telemetry must never stop the node, so one bad instrument costs only // its own metric. try @@ -974,8 +1031,7 @@ OTelCollectorImp::onCollectionReady() if (auto stream = journal_.info()) { - stream << "OTelCollector: registered " << armed << " of " << gauges.size() - << " observable gauges"; + stream << "OTelCollector: registered " << armed << " of " << live << " observable gauges"; } } @@ -984,17 +1040,26 @@ OTelCollectorImp::onCollectionStopping() { // Same lock discipline as onCollectionReady(): snapshot, then act outside // the lock, because disarm() enters the SDK's observable registry lock. - std::vector gauges; + std::vector> gauges; { std::scoped_lock const lock(mutex_); gauges = gauges_; } - for (auto* gauge : gauges) - gauge->disarm(); + // Locking keeps each gauge alive across its own disarm() call. One already + // destroyed disarmed itself in ~OTelGaugeImpl, so skipping it is correct. + std::size_t disarmed = 0; + for (auto const& weakGauge : gauges) + { + if (auto const gauge = weakGauge.lock()) + { + gauge->disarm(); + ++disarmed; + } + } if (auto stream = journal_.info()) - stream << "OTelCollector: stopped observing " << gauges.size() << " gauges"; + stream << "OTelCollector: stopped observing " << disarmed << " gauges"; } opentelemetry::nostd::shared_ptr const& diff --git a/src/libxrpl/server/Wallet.cpp b/src/libxrpl/server/Wallet.cpp index 92317d40f6..d1b36fb143 100644 --- a/src/libxrpl/server/Wallet.cpp +++ b/src/libxrpl/server/Wallet.cpp @@ -3,13 +3,16 @@ #include #include #include +#include #include #include #include +#include #include #include #include #include +#include #include #include #include @@ -33,6 +36,7 @@ #include #include #include +#include #include #include #include @@ -142,6 +146,55 @@ addValidatorManifest(soci::session& session, std::string const& serialized) tr.commit(); } +std::optional +parseNodeIdentitySeed( + std::optional const& cmdlineSeed, + std::optional const& configSeed) +{ + if (cmdlineSeed) + { + auto seed = parseGenericSeed(*cmdlineSeed, false); + if (!seed) + Throw("Invalid 'nodeid' in command line"); + return seed; + } + + if (configSeed) + { + auto seed = parseBase58(*configSeed); + if (!seed) + { + Throw( + std::string("Invalid [") + Sections::kNodeSeed + "] in configuration file"); + } + return seed; + } + + return std::nullopt; +} + +std::pair +selectNodeIdentity( + std::optional const& configuredSeed, + bool newNodeId, + std::function>()> const& readStored) +{ + if (configuredSeed) + { + auto const sk = generateSecretKey(KeyType::Secp256k1, *configuredSeed); + return {derivePublicKey(KeyType::Secp256k1, sk), sk}; + } + + // --newnodeid discards whatever is stored, so mint now. + if (!newNodeId) + { + if (auto stored = readStored()) + return *stored; + } + + return randomKeyPair(KeyType::Secp256k1); +} + void clearNodeIdentity(soci::session& session) { @@ -171,6 +224,16 @@ readNodeIdentity(soci::session& session) return std::nullopt; } +void +storeNodeIdentity(soci::session& session, std::pair const& keys) +{ + session << std::format( + "INSERT INTO NodeIdentity (PublicKey,PrivateKey) " + "VALUES ('{}','{}');", + toBase58(TokenType::NodePublic, keys.first), + toBase58(TokenType::NodePrivate, keys.second)); +} + std::pair getNodeIdentity(soci::session& session) { @@ -178,15 +241,9 @@ getNodeIdentity(soci::session& session) return *stored; // If a valid identity wasn't found, we randomly generate a new one: - auto [newpublicKey, newsecretKey] = randomKeyPair(KeyType::Secp256k1); - - session << std::format( - "INSERT INTO NodeIdentity (PublicKey,PrivateKey) " - "VALUES ('{}','{}');", - toBase58(TokenType::NodePublic, newpublicKey), - toBase58(TokenType::NodePrivate, newsecretKey)); - - return {newpublicKey, newsecretKey}; + auto const keys = randomKeyPair(KeyType::Secp256k1); + storeNodeIdentity(session, keys); + return keys; } std::unordered_set, KeyEqual> diff --git a/src/libxrpl/telemetry/NullTelemetry.cpp b/src/libxrpl/telemetry/NullTelemetry.cpp index a8dd40f322..e6bac72d65 100644 --- a/src/libxrpl/telemetry/NullTelemetry.cpp +++ b/src/libxrpl/telemetry/NullTelemetry.cpp @@ -25,7 +25,6 @@ #ifdef XRPL_ENABLE_TELEMETRY #include #include -#include #include #include #include @@ -141,11 +140,11 @@ public: } opentelemetry::nostd::shared_ptr - getMeter(std::string_view) override + getMeter(std::string_view name) override { - static auto noopMeter = opentelemetry::nostd::shared_ptr( - new opentelemetry::metrics::NoopMeter()); - return noopMeter; + // Route through the shared helper so the meter identity (name + + // kMeterVersion) matches every other noop path in the process. + return noopMeter(name); } #endif }; diff --git a/src/libxrpl/telemetry/Telemetry.cpp b/src/libxrpl/telemetry/Telemetry.cpp index 56705cfd8d..c18d8c84d1 100644 --- a/src/libxrpl/telemetry/Telemetry.cpp +++ b/src/libxrpl/telemetry/Telemetry.cpp @@ -261,11 +261,8 @@ public: [[nodiscard]] opentelemetry::nostd::shared_ptr getMeter(std::string_view name) override { - // Serve a meter from a process-wide noop provider, mirroring the - // noop tracer above. Instruments created from it are inert. - static auto noopProvider = opentelemetry::nostd::shared_ptr( - new metrics_api::NoopMeterProvider()); - return noopProvider->GetMeter(std::string(name), std::string(kMeterVersion)); + // Mirrors the noop tracer above: instruments created from it are inert. + return noopMeter(name); } [[nodiscard]] opentelemetry::nostd::shared_ptr @@ -727,6 +724,16 @@ public: } // namespace +opentelemetry::nostd::shared_ptr +noopMeter(std::string_view name) +{ + // One provider for the process: it holds a single inert meter, so nothing + // is gained by building another. + static auto const provider = opentelemetry::nostd::shared_ptr( + new metrics_api::NoopMeterProvider()); + return provider->GetMeter(std::string(name), std::string(kMeterVersion)); +} + opentelemetry::exporter::otlp::OtlpHttpExporterOptions makeTraceExporterOptions(Telemetry::Setup const& setup) { diff --git a/src/libxrpl/telemetry/TelemetryConfig.cpp b/src/libxrpl/telemetry/TelemetryConfig.cpp index 469ffc3fc9..8c985fbb17 100644 --- a/src/libxrpl/telemetry/TelemetryConfig.cpp +++ b/src/libxrpl/telemetry/TelemetryConfig.cpp @@ -343,7 +343,13 @@ makeTelemetrySetup( setup.enabled = section.valueOr(key::enabled, 0) != 0; setup.serviceName = section.valueOr(key::serviceName, dflt::serviceName); setup.serviceVersion = version; + // Match makeMetricsRegistryOptions() in Application.cpp: an empty + // configured value is treated as absent and falls back to the node key, + // so traces and metrics stamp the same identity. Otherwise one node + // reports two identities and every $node filter shows half the series. setup.serviceInstanceId = section.valueOr(key::serviceInstanceId, nodePublicKey); + if (setup.serviceInstanceId.empty()) + setup.serviceInstanceId = nodePublicKey; setup.tracesEndpoint = section.valueOr(key::tracesEndpoint, dflt::tracesEndpoint); setup.metricsEndpoint = diff --git a/src/tests/libxrpl/beast/insight/OTelCollectorHooks.cpp b/src/tests/libxrpl/beast/insight/OTelCollectorHooks.cpp new file mode 100644 index 0000000000..18f35e2f8a --- /dev/null +++ b/src/tests/libxrpl/beast/insight/OTelCollectorHooks.cpp @@ -0,0 +1,208 @@ +#ifdef XRPL_ENABLE_TELEMETRY + +#include +#include +#include +#include +#include + +#include +#include +#include +#include +#include +#include +#include +#include +#include + +#include +#include +#include +#include +#include + +namespace beast::insight { + +namespace metrics_api = opentelemetry::metrics; +namespace metrics_sdk = opentelemetry::sdk::metrics; + +/** + * A MetricReader that collects only when the test asks it to. + * + * The SDK ships only PeriodicExportingMetricReader, whose background thread + * would make these tests depend on timing. MetricReader::Collect() is public + * and synchronous, so a minimal subclass lets a test drive one collection pass + * on the calling thread. That pass is what invokes an observable gauge's + * callback, which is the only path that reaches the collector's hooks. + * + * @code + * auto reader = std::make_shared(); + * provider->AddMetricReader(reader); + * reader->collectOnce(); // runs every registered observable callback + * @endcode + */ +class ManualMetricReader : public metrics_sdk::MetricReader +{ +public: + /** + * @brief Run exactly one collection pass, discarding the metric data. + * + * The tests assert on hook side effects, not on exported points, so the + * callback returns true without inspecting what it was handed. + */ + void + collectOnce() + { + Collect([](metrics_sdk::ResourceMetrics&) { return true; }); + } + + metrics_sdk::AggregationTemporality + GetAggregationTemporality(metrics_sdk::InstrumentType) const noexcept override + { + return metrics_sdk::AggregationTemporality::kCumulative; + } + + bool + OnForceFlush(std::chrono::microseconds) noexcept override + { + return true; + } + + bool + OnShutDown(std::chrono::microseconds) noexcept override + { + return true; + } +}; + +/** + * Installs a real SDK MeterProvider so observable gauges actually fire. + * + * OTelCollector takes its Meter from the global provider. Under the default + * noop provider an observable gauge's callback is never invoked, so a hook + * test would pass whatever the collector did. The fixture swaps in an SDK + * provider with a ManualMetricReader and restores the previous global provider + * afterwards, so it leaks no state into other telemetry tests in this binary. + */ +class OTelCollectorHooks : public ::testing::Test +{ +protected: + void + SetUp() override + { + previous_ = metrics_api::Provider::GetMeterProvider(); + reader_ = std::make_shared(); + auto provider = metrics_sdk::MeterProviderFactory::Create(); + provider->AddMetricReader(reader_); + provider_ = std::shared_ptr(std::move(provider)); + metrics_api::Provider::SetMeterProvider( + opentelemetry::nostd::shared_ptr(provider_)); + } + + void + TearDown() override + { + metrics_api::Provider::SetMeterProvider(previous_); + provider_.reset(); + reader_.reset(); + } + + /** + * @brief Build a collector, plus the armed gauge that drives its hooks. + * + * A collection pass only reaches the hooks through an observable gauge's + * callback, and a gauge is armed by onCollectionReady(), so every test + * needs both. The gauge is returned because dropping it would unregister + * the callback. + * + * Each test builds its own collector: the hook debounce is keyed to the + * time of the last invocation, which starts unset, so the first collection + * on a fresh collector always runs the hooks. + */ + static std::pair + makeArmedCollector() + { + auto collector = OTelCollector::New( + "http://127.0.0.1:4318/v1/metrics", + "", + "test-instance", + "xrpld", + "test", + Journal(Journal::getNullSink())); + auto gauge = collector->makeGauge("hook_test_gauge"); + collector->onCollectionReady(); + return {std::move(collector), std::move(gauge)}; + } + + opentelemetry::nostd::shared_ptr previous_; + std::shared_ptr reader_; + std::shared_ptr provider_; +}; + +// --------------------------------------------------------------------------- +// 1. A hook that is still alive runs on a collection pass. +// This is the registration path: makeHook() puts the hook on the +// collector's list, and an observable gauge callback invokes it. Without +// this, a hook that is never registered is indistinguishable from one that +// is registered and skipped. +// --------------------------------------------------------------------------- +TEST_F(OTelCollectorHooks, live_hook_runs_once_per_collection) +{ + auto [collector, gauge] = makeArmedCollector(); + + std::size_t calls = 0; + auto const hook = collector->makeHook([&calls] { ++calls; }); + + reader_->collectOnce(); + + EXPECT_EQ(calls, 1u); +} + +// --------------------------------------------------------------------------- +// 2. A hook destroyed before the collection pass is skipped, not called. +// The collector holds weak references, so the destroyed hook's entry locks +// to null. Asserting zero (not "did not crash") is what makes this a real +// check: a stale entry that was still followed would run the handler and +// increment the counter through freed memory. +// --------------------------------------------------------------------------- +TEST_F(OTelCollectorHooks, destroyed_hook_is_skipped) +{ + auto [collector, gauge] = makeArmedCollector(); + + std::size_t calls = 0; + { + auto const hook = collector->makeHook([&calls] { ++calls; }); + } + + reader_->collectOnce(); + + EXPECT_EQ(calls, 0u); +} + +// --------------------------------------------------------------------------- +// 3. Destroying one hook leaves its siblings registered. +// Guards the pruning step: removeExpiredHooks() erases by expiry rather +// than by address, so an over-broad predicate would drop live hooks too and +// silently stop their metrics updating. +// --------------------------------------------------------------------------- +TEST_F(OTelCollectorHooks, destroying_one_hook_keeps_the_others) +{ + auto [collector, gauge] = makeArmedCollector(); + + std::size_t kept = 0; + std::size_t dropped = 0; + auto const keptHook = collector->makeHook([&kept] { ++kept; }); + { + auto const droppedHook = collector->makeHook([&dropped] { ++dropped; }); + } + + reader_->collectOnce(); + + EXPECT_EQ(kept, 1u); + EXPECT_EQ(dropped, 0u); +} + +} // namespace beast::insight + +#endif // XRPL_ENABLE_TELEMETRY diff --git a/src/tests/libxrpl/beast/insight/StatsDCollector.cpp b/src/tests/libxrpl/beast/insight/StatsDCollector.cpp index aaab3e571e..8d8c6692b0 100644 --- a/src/tests/libxrpl/beast/insight/StatsDCollector.cpp +++ b/src/tests/libxrpl/beast/insight/StatsDCollector.cpp @@ -1,5 +1,7 @@ #include +#include +#include #include #include diff --git a/src/tests/libxrpl/server/NodeIdentity.cpp b/src/tests/libxrpl/server/NodeIdentity.cpp new file mode 100644 index 0000000000..086b63bbcf --- /dev/null +++ b/src/tests/libxrpl/server/NodeIdentity.cpp @@ -0,0 +1,361 @@ +/** + * @file NodeIdentity.cpp + * GTest unit tests for the wallet's node-identity helpers and the pure + * decision logic behind resolveNodeIdentity(). + * + * Two groups of functions share the NodeIdentity table: + * - readNodeIdentity() / storeNodeIdentity() / clearNodeIdentity() are the + * wallet-layer primitives xrpld composes at startup. + * - getNodeIdentity(session&) is the read-or-mint helper. It persists a + * freshly minted pair, so a second call after a mint returns the same + * key: that is the property that keeps a node's identity stable across + * restarts. + * + * parseNodeIdentitySeed() and selectNodeIdentity() are the libxrpl-level + * decision helpers that xrpld's resolveNodeIdentity() marshals its inputs + * into. Every outcome branch of resolveNodeIdentity() reduces to one of + * these two, so testing them here covers the decision tree without an + * xrpld Config. + * + * Each database-backed test gets its own file in a temporary directory, so + * nothing here depends on order or on the developer's data directory. + */ + +#include +#include +#include +#include +#include +#include +#include +#include + +#include +#include +#include + +#include +#include +#include +#include +#include +#include +#include +#include + +using namespace xrpl; + +namespace { + +/** + * A wallet database in its own temporary directory, removed on destruction. + * + * `makeTestWalletDB()` creates the schema, so every fixture starts with an + * empty `NodeIdentity` table. + */ +class TempWalletDb +{ +public: + explicit TempWalletDb(std::string const& name) + : dir_(std::filesystem::temp_directory_path() / ("xrpl-node-identity-" + name)) + { + std::filesystem::remove_all(dir_); + std::filesystem::create_directories(dir_); + + DatabaseCon::Setup setup; + setup.dataDir = dir_; + db_ = makeTestWalletDB(setup, "wallet.db", beast::Journal{beast::Journal::getNullSink()}); + } + + ~TempWalletDb() + { + db_.reset(); + std::error_code ec; + std::filesystem::remove_all(dir_, ec); + } + + TempWalletDb(TempWalletDb const&) = delete; + TempWalletDb& + operator=(TempWalletDb const&) = delete; + + [[nodiscard]] DatabaseCon& + operator*() const noexcept + { + return *db_; + } + +private: + std::filesystem::path dir_; + std::unique_ptr db_; +}; + +} // namespace + +TEST(WalletNodeIdentity, store_then_read_returns_the_same_pair) +{ + // The store step exists so a key minted before the Application is built + // can be persisted afterwards. Reading it back must give the same pair, or + // the two halves of one run report two identities. + TempWalletDb const wallet("store-then-read"); + auto const minted = randomKeyPair(KeyType::Secp256k1); + + { + auto db = (*wallet).checkoutDb(); + ASSERT_FALSE(readNodeIdentity(*db).has_value()) << "a fresh wallet must hold no identity"; + storeNodeIdentity(*db, minted); + } + + auto db = (*wallet).checkoutDb(); + auto const stored = readNodeIdentity(*db); + ASSERT_TRUE(stored.has_value()); + EXPECT_EQ(stored->first, minted.first); + EXPECT_EQ(stored->second, minted.second); +} + +TEST(WalletNodeIdentity, store_appends_rather_than_replacing) +{ + // Catches storeNodeIdentity being changed into an UPSERT: the wallet + // helper deliberately inserts without clearing, and the caller + // (getNodeIdentity(session&) or resolveNodeIdentity+setup) is what makes + // sure the table is empty first. Two stores must leave two rows. + TempWalletDb const wallet("store-appends"); + auto const first = randomKeyPair(KeyType::Secp256k1); + auto const second = randomKeyPair(KeyType::Secp256k1); + ASSERT_NE(first.first, second.first) + << "the two pairs must differ for this test to mean anything"; + + auto db = (*wallet).checkoutDb(); + storeNodeIdentity(*db, first); + storeNodeIdentity(*db, second); + + int rowCount = 0; + *db << "SELECT COUNT(*) FROM NodeIdentity;", soci::into(rowCount); + EXPECT_EQ(rowCount, 2) << "storeNodeIdentity must not clear the table"; + + // The read has no ORDER BY, so pin only that ONE of the two stored keys + // comes back -- not which one. + auto const stored = readNodeIdentity(*db); + ASSERT_TRUE(stored.has_value()); + EXPECT_TRUE(stored->first == first.first || stored->first == second.first) + << "readNodeIdentity must return one of the two stored pairs"; +} + +TEST(WalletNodeIdentity, clear_then_store_installs_the_new_pair) +{ + // --newnodeid clears the row and then persists the freshly minted pair. + // Both steps are needed: clearing alone would leave the node with no + // stored identity at all. + TempWalletDb const wallet("clear-then-store"); + auto db = (*wallet).checkoutDb(); + + auto const first = getNodeIdentity(*db); + auto const replacement = randomKeyPair(KeyType::Secp256k1); + ASSERT_NE(first.first, replacement.first); + + clearNodeIdentity(*db); + EXPECT_FALSE(readNodeIdentity(*db).has_value()) << "clear must leave the table empty"; + + storeNodeIdentity(*db, replacement); + auto const stored = readNodeIdentity(*db); + ASSERT_TRUE(stored.has_value()); + EXPECT_EQ(stored->first, replacement.first); + EXPECT_EQ(stored->second, replacement.second); +} + +TEST(WalletNodeIdentity, get_mints_and_persists_when_the_table_is_empty) +{ + // The mint path must persist, not just return: a second call has to give + // the same key. This is the property --newnodeid relies on to be + // meaningful, and the one a caller that only reads would break. + TempWalletDb const wallet("mint-and-persist"); + auto db = (*wallet).checkoutDb(); + + auto const minted = getNodeIdentity(*db); + + auto const stored = readNodeIdentity(*db); + ASSERT_TRUE(stored.has_value()) << "getNodeIdentity() must persist what it mints"; + EXPECT_EQ(stored->first, minted.first); + EXPECT_EQ(getNodeIdentity(*db).first, minted.first); +} + +// ----------------------------------------------------------------------------- +// parseNodeIdentitySeed() +// +// The seed-parsing half of resolveNodeIdentity(). Each test drives one branch +// of the review's outcome list: cmdline valid, cmdline malformed, config valid, +// config malformed, neither, and cmdline-wins-over-config. +// ----------------------------------------------------------------------------- + +namespace { + +// A base58 seed known to parse (from the "masterpassphrase" node in +// src/test/protocol/Seed_test.cpp). +constexpr auto kValidSeed = "snoPBrXtMeMyMHUVTgbuqAfg1SUTb"; + +// Public key derived from kValidSeed (secp256k1), same source. +constexpr auto kValidSeedPublic = "n94a1u4jAz288pZLtw6yFWVbi89YamiC6JBXPVUj5zmExe5fTVg9"; + +// A second base58 seed to prove cmdline-wins-over-config. +constexpr auto kOtherSeed = "snMKnVku798EnBwUfxeSD8953sLYA"; + +} // namespace + +TEST(ParseNodeIdentitySeed, both_absent_returns_nullopt) +{ + // Catches replacing the fallthrough with a throw, or making it mint a + // random seed. resolveNodeIdentity() then falls through to the wallet. + EXPECT_FALSE(parseNodeIdentitySeed(std::nullopt, std::nullopt).has_value()); +} + +TEST(ParseNodeIdentitySeed, valid_cmdline_returns_that_seed) +{ + // Catches swapping parseGenericSeed to always return nullopt, or reading + // configSeed instead of cmdlineSeed. Pin the concrete public key derived + // from the seed so the returned optional cannot silently be a different + // valid seed. + auto const seed = parseNodeIdentitySeed(std::string{kValidSeed}, std::nullopt); + ASSERT_TRUE(seed.has_value()); + + auto const sk = generateSecretKey(KeyType::Secp256k1, *seed); + auto const pk = derivePublicKey(KeyType::Secp256k1, sk); + EXPECT_EQ(toBase58(TokenType::NodePublic, pk), std::string{kValidSeedPublic}); +} + +TEST(ParseNodeIdentitySeed, valid_config_returns_that_seed) +{ + // Catches ignoring the config branch. Same public-key pin as above so the + // result cannot silently drift to another seed. + auto const seed = parseNodeIdentitySeed(std::nullopt, std::string{kValidSeed}); + ASSERT_TRUE(seed.has_value()); + + auto const sk = generateSecretKey(KeyType::Secp256k1, *seed); + auto const pk = derivePublicKey(KeyType::Secp256k1, sk); + EXPECT_EQ(toBase58(TokenType::NodePublic, pk), std::string{kValidSeedPublic}); +} + +TEST(ParseNodeIdentitySeed, malformed_cmdline_throws) +{ + // Catches removing the throw. An empty string flunks parseGenericSeed( + // rfc1751=false) because the first check inside is str.empty(). A base58 + // public key would too, but empty is the shorter probe. + EXPECT_THROW( + static_cast(parseNodeIdentitySeed(std::string{}, std::nullopt)), std::runtime_error); +} + +TEST(ParseNodeIdentitySeed, malformed_config_throws) +{ + // Catches removing the throw. "garbage" is neither valid base58 nor a + // valid seed encoding, so parseBase58 returns nullopt and the + // config branch throws. + EXPECT_THROW( + static_cast(parseNodeIdentitySeed(std::nullopt, std::string{"garbage"})), + std::runtime_error); +} + +TEST(ParseNodeIdentitySeed, cmdline_wins_over_config) +{ + // Catches swapping the two if-branches. Passing DIFFERENT valid seeds on + // each input and asserting the returned seed derives to kValidSeed's + // public key proves which one won. + auto const seed = parseNodeIdentitySeed(std::string{kValidSeed}, std::string{kOtherSeed}); + ASSERT_TRUE(seed.has_value()); + + auto const sk = generateSecretKey(KeyType::Secp256k1, *seed); + auto const pk = derivePublicKey(KeyType::Secp256k1, sk); + EXPECT_EQ(toBase58(TokenType::NodePublic, pk), std::string{kValidSeedPublic}); +} + +// ----------------------------------------------------------------------------- +// selectNodeIdentity() +// +// The decision half of resolveNodeIdentity(). Every remaining branch from the +// review's outcome list reduces to one of these four cases, because +// storedIdentity() catches its own exceptions and returns std::nullopt for +// every failure mode (standalone non-Load, wallet absent, invalid row, read +// throws) -- see storedIdentity() in NodeIdentity.cpp. +// ----------------------------------------------------------------------------- + +namespace { + +// Reader that records whether it was called. resolveNodeIdentity()'s reader +// is a filesystem-touching lambda, so pinning "was it consulted" catches the +// mutations that flip which cases open the wallet. +struct TrackingReader +{ + bool called{false}; + std::optional> value; + + std::function>()> + fn() + { + return [this] { + called = true; + return value; + }; + } +}; + +} // namespace + +TEST(SelectNodeIdentity, seed_wins_and_reader_not_consulted) +{ + // Catches removing the seed branch (or checking newNodeId first). The + // returned pair must be keysFromSeed(kValidSeed); if the seed branch is + // gone the reader gets called and its recorded pair or a fresh mint + // comes back instead. + TrackingReader reader; + reader.value = randomKeyPair(KeyType::Secp256k1); + + auto const seed = parseBase58(std::string{kValidSeed}); + ASSERT_TRUE(seed.has_value()); + + auto const result = selectNodeIdentity(seed, /*newNodeId=*/false, reader.fn()); + + EXPECT_FALSE(reader.called) << "the reader must not run when a seed is configured"; + EXPECT_EQ(toBase58(TokenType::NodePublic, result.first), std::string{kValidSeedPublic}); +} + +TEST(SelectNodeIdentity, newnodeid_mints_fresh_and_skips_reader) +{ + // Catches removing the `!newNodeId` guard. With a stored pair available, + // the mint path must still run and the stored pair must not come back. + TrackingReader reader; + reader.value = randomKeyPair(KeyType::Secp256k1); + auto const storedPair = *reader.value; + + auto const result = selectNodeIdentity(std::nullopt, /*newNodeId=*/true, reader.fn()); + + EXPECT_FALSE(reader.called) << "--newnodeid must not open the wallet"; + EXPECT_NE(result.first, storedPair.first) << "the stored pair must be discarded"; +} + +TEST(SelectNodeIdentity, returns_stored_when_reader_has_one) +{ + // Catches replacing the stored-return with a mint. Also catches the + // reader being called but its result discarded. + TrackingReader reader; + reader.value = randomKeyPair(KeyType::Secp256k1); + auto const storedPair = *reader.value; + + auto const result = selectNodeIdentity(std::nullopt, /*newNodeId=*/false, reader.fn()); + + EXPECT_TRUE(reader.called); + EXPECT_EQ(result.first, storedPair.first); + EXPECT_EQ(result.second, storedPair.second); +} + +TEST(SelectNodeIdentity, mints_when_nothing_stored) +{ + // Catches removing the mint fallback. With the reader returning + // nullopt, selectNodeIdentity must still produce a keypair, and it must + // differ from anything it could have accidentally reused. + TrackingReader reader; // value stays std::nullopt. + + auto const result = selectNodeIdentity(std::nullopt, /*newNodeId=*/false, reader.fn()); + + EXPECT_TRUE(reader.called); + // The mint path is randomKeyPair(), so the two calls must yield distinct + // keys. Same probe the wallet-side tests use. + auto const another = randomKeyPair(KeyType::Secp256k1); + EXPECT_NE(result.first, another.first); +} diff --git a/src/tests/libxrpl/telemetry/MetricMacros.cpp b/src/tests/libxrpl/telemetry/MetricMacros.cpp index 85520884cb..86f943928a 100644 --- a/src/tests/libxrpl/telemetry/MetricMacros.cpp +++ b/src/tests/libxrpl/telemetry/MetricMacros.cpp @@ -9,7 +9,7 @@ * These tests exercise the macros against a bare SDK MeterProvider (no * OTLP exporter, no network, no background thread), the same technique * GetMeter.cpp uses. The macros are duck-typed: they only ever call - * app.getMetricsRegistry(), then isEnabled() and meter() on the result. + * app.getMetricsRegistry(), then recording() and meter() on the result. * The tests therefore drive them through a tiny FakeApp/FakeMetricsRegistry * pair instead of the real telemetry::MetricsRegistry, whose enabled-path * .cpp drags xrpld link dependencies (LedgerMaster, TxQ, NetworkOPs, ...) @@ -63,7 +63,7 @@ namespace { /** * Duck-typed stand-in for telemetry::MetricsRegistry. The macros only - * ever call isEnabled() and meter() on the registry pointer, so this + * ever call recording() and meter() on the registry pointer, so this * minimal type is all they need -- and it links without pulling in the * real MetricsRegistry.cpp's xrpld dependencies. */ @@ -78,9 +78,21 @@ public: configure(bool enabled, opentelemetry::nostd::shared_ptr meter) { enabled_ = enabled; + stopped_ = false; meter_ = std::move(meter); } + /** + * Simulate MetricsRegistry::stop(): the recording gate flips closed even + * while enabled_ stays true, matching the real class where a call after + * stop() must not touch the SDK instrument cache. + */ + void + stop() noexcept + { + stopped_ = true; + } + /** * Number of times meter() has been consulted, so a test can assert the * create-once (function-local static) and disabled-gating behavior exactly. @@ -97,6 +109,16 @@ public: return enabled_; } + /** + * Mirrors MetricsRegistry::recording(): the macros consult this instead of + * isEnabled() so a stopped registry records nothing. + */ + [[nodiscard]] bool + recording() const noexcept + { + return enabled_ && !stopped_; + } + [[nodiscard]] opentelemetry::nostd::shared_ptr meter() const noexcept { @@ -106,10 +128,16 @@ public: private: /** - * Master enable flag the macro consults via isEnabled(). + * Master enable flag; recording() folds it in. */ bool enabled_ = true; + /** + * Set by stop() to model the real registry's post-shutdown state: + * enabled_ stays true but recording() flips to false. + */ + bool stopped_ = false; + /** * Meter handed to the macro; sourced from a bare SDK provider. */ @@ -489,7 +517,7 @@ wire(FakeApp& app, bool enabled) * CollectingProvider so the recorded values are collectable. * * @param app The duck-typed app the macros will be driven through. - * @param enabled What the macros' isEnabled() gate will observe. + * @param enabled What the macros' recording() gate will observe. * @param meter The meter the macros will create their instruments on. */ void @@ -635,11 +663,33 @@ TEST(MetricMacros, observable_counter_and_updown_register_do_not_crash) EXPECT_EQ(app.registry().meterCalls(), 2); } +TEST(MetricMacros, stopped_registry_records_nothing) +{ + ScopedBareProvider const bareProvider; + FakeApp app; + wire(app, /*enabled=*/true); + + // Simulate MetricsRegistry::stop(): recording() flips closed even while + // isEnabled() stays true, because the OTel provider is torn down in + // stop() and a Record on a stale SDK instrument would deref a dangling + // AggregationConfig for a first-seen attribute set. + app.registry().stop(); + ASSERT_TRUE(app.registry().isEnabled()); + ASSERT_FALSE(app.registry().recording()); + + XRPL_METRIC_COUNTER_INC( + app, "test_macro_stopped_counter_total", "Counter after stop() must be inert"); + + // The recording() gate short-circuits before the create-once static path + // runs, so meter() is never consulted. + EXPECT_EQ(app.registry().meterCalls(), 0); +} + TEST(MetricMacros, disabled_registry_is_noop) { ScopedBareProvider const bareProvider; FakeApp app; - // enabled=false: the macro's isEnabled() gate short-circuits before it + // enabled=false: the macro's recording() gate short-circuits before it // ever touches meter(), so nothing is created or recorded. wire(app, /*enabled=*/false); @@ -1024,7 +1074,7 @@ TEST(MetricMacros, sync_diagnostics_metrics_emit_nothing_when_registry_disabled) // Nothing else leaked in either: the collection is completely empty. EXPECT_EQ(data.size(), 0u); - // Cause, not just state: the isEnabled() gate short-circuited before the + // Cause, not just state: the recording() gate short-circuited before the // macro ever asked for a meter. EXPECT_EQ(app.registry().meterCalls(), 0); } @@ -1266,7 +1316,7 @@ TEST(MetricMacros, state_changes_total_emits_nothing_when_registry_disabled) EXPECT_EQ(data.count("state_changes_total"), 0u); EXPECT_EQ(data.size(), 0u); - // Cause, not just state: the isEnabled() gate short-circuited before the + // Cause, not just state: the recording() gate short-circuited before the // macro asked for a meter. EXPECT_EQ(app.registry().meterCalls(), 0); } @@ -1617,7 +1667,7 @@ TEST(MetricMacros, acquire_counters_emit_nothing_when_registry_disabled) EXPECT_EQ(data.count("sync_addnode_total"), 0u); EXPECT_EQ(data.size(), 0u); - // Cause, not just state: the isEnabled() gate short-circuited before the + // Cause, not just state: the recording() gate short-circuited before the // macros asked for a meter. EXPECT_EQ(app.registry().meterCalls(), 0); } @@ -2599,7 +2649,7 @@ TEST(MetricMacros, sync_supply_counters_emit_nothing_when_registry_disabled) EXPECT_EQ(data.count("ledger_jump_total"), 0u); EXPECT_EQ(data.size(), 0u); - // Cause, not just state: the isEnabled() gate short-circuited before the + // Cause, not just state: the recording() gate short-circuited before the // macros asked for a meter, so no instrument was created either. EXPECT_EQ(app.registry().meterCalls(), 0); } @@ -2721,7 +2771,7 @@ TEST(MetricMacros, ledger_replay_counters_emit_nothing_when_disabled) EXPECT_EQ(data.count("ledger_replay_outcome_total"), 0u); EXPECT_EQ(data.size(), 0u); - // Cause, not just state: the isEnabled() gate short-circuited before the + // Cause, not just state: the recording() gate short-circuited before the // macros ever asked for a meter, so no instrument was created. EXPECT_EQ(app.registry().meterCalls(), 0); } @@ -2942,7 +2992,7 @@ TEST(MetricMacros, consensus_round_duration_emits_nothing_when_registry_disabled // State: no series at all under that name, and nothing else leaked in. EXPECT_EQ(data.count("consensus_round_duration_ms"), 0u); EXPECT_EQ(data.size(), 0u); - // Cause, not just state: the isEnabled() gate short-circuited before the + // Cause, not just state: the recording() gate short-circuited before the // macro ever asked for a meter. EXPECT_EQ(app.registry().meterCalls(), 0); } diff --git a/src/tests/libxrpl/telemetry/MetricsRegistry.cpp b/src/tests/libxrpl/telemetry/MetricsRegistry.cpp index cc5bd3795d..2938692590 100644 --- a/src/tests/libxrpl/telemetry/MetricsRegistry.cpp +++ b/src/tests/libxrpl/telemetry/MetricsRegistry.cpp @@ -20,17 +20,17 @@ * real producer, xrpl::to_string(RangeSet), rather than restating its * format. * - * 4. 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. + * 4. The no-op / telemetry-disabled path — construction (which is where the + * pipeline and the synchronous instruments are built), startAsyncGauges(), + * stop(), 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). - * - The two-phase start() / startAsyncGauges() / stop() lifecycle when - * disabled. + * - The startAsyncGauges() / stop() lifecycle when disabled. * - Synchronous instrument recording methods do not crash when disabled. * - Double stop() is safe. * - Destructor handles cleanup without crash. @@ -639,22 +639,21 @@ using namespace xrpl; namespace { /** - * OTLP/HTTP endpoint used by every start() call below. Nothing ever dials it + * OTLP/HTTP endpoint given to every registry below. Nothing ever dials it * -- these tests exercise the no-op path -- it just has to be a plausible URL. - * It reaches start() through @ref kTestStartOptions. + * It reaches the constructor through @ref kTestOptions. */ constexpr std::string_view kTestEndpoint{"http://localhost:4318/v1/metrics"}; /** - * The only StartOptions field these tests need. + * The only Options field these tests need. * - * start() takes the StartOptions aggregate, not a string. The other fields -- - * resource identity, network id, TLS paths -- are never read on the no-op - * path, and their defaults already mean "unset". One shared value keeps all - * six call sites on the same endpoint. + * The constructor takes the Options aggregate, not a string. The other fields + * -- resource identity, network id, TLS paths -- are never read on the no-op + * path, and their defaults already mean "unset". One shared value keeps every + * construction on the same endpoint. */ -telemetry::MetricsRegistry::StartOptions const kTestStartOptions{ - .endpoint = std::string{kTestEndpoint}}; +telemetry::MetricsRegistry::Options const kTestOptions{.endpoint = std::string{kTestEndpoint}}; /** * Minimal mock ServiceRegistry for MetricsRegistry testing. @@ -940,16 +939,15 @@ protected: TEST_F(MetricsRegistryTest, disabled_construction) { // Construct with enabled=false; should be a no-op. - telemetry::MetricsRegistry const registry(false, mockApp_, j_); + telemetry::MetricsRegistry const registry(false, mockApp_, j_, kTestOptions); EXPECT_FALSE(registry.isEnabled()); } -TEST_F(MetricsRegistryTest, disabled_start_stop) +TEST_F(MetricsRegistryTest, disabled_construct_stop) { - telemetry::MetricsRegistry registry(false, mockApp_, j_); + telemetry::MetricsRegistry registry(false, mockApp_, j_, kTestOptions); - // start() and stop() should be no-ops when disabled. - registry.start(kTestStartOptions); + // stop() should be a no-op when disabled. registry.stop(); // Double stop should be safe. @@ -957,48 +955,41 @@ TEST_F(MetricsRegistryTest, disabled_start_stop) } // --------------------------------------------------------------------------- -// The two-phase startup split: start() then startAsyncGauges(). +// The two startup phases: construction, 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. +// Why two phases: the constructor needs only config strings, so it can run in +// the Application's member-init list, before any subsystem that records a +// metric exists. The observable-instrument callbacks registered by +// startAsyncGauges() read live Application services (getOverlay() asserts +// overlay_ is non-null), so they wait until those services are built. // // 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, +// (src/tests/libxrpl/CMakeLists.txt -- 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() have a single definition whose -// whole body sits inside #ifdef XRPL_ENABLE_TELEMETRY, so here they compile to -// an empty body with a [[maybe_unused]] parameter. 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. +// link). The constructor body and startAsyncGauges() sit inside +// #ifdef XRPL_ENABLE_TELEMETRY, so here they compile to empty bodies. So these +// tests pin the API SURFACE -- that the entry points exist, are callable in +// the documented 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. // --------------------------------------------------------------------------- -TEST_F(MetricsRegistryTest, async_gauges_start_after_start_is_safe) +TEST_F(MetricsRegistryTest, async_gauges_after_construction_is_safe) { - telemetry::MetricsRegistry registry(false, mockApp_, j_); + telemetry::MetricsRegistry registry(false, mockApp_, j_, kTestOptions); - // The documented order: provider/sync instruments first, gauges second. - registry.start(kTestStartOptions); + // The documented order: instruments at construction, gauges second. 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. + // Synchronous recording must work off construction alone. Nothing here + // needs the gauges to be registered. registry.recordRpcStarted("server_info"); registry.recordRpcFinished("server_info", 1000); @@ -1006,42 +997,35 @@ TEST_F(MetricsRegistryTest, async_gauges_start_after_start_is_safe) EXPECT_EQ(registry.isEnabled(), false); } -TEST_F(MetricsRegistryTest, async_gauges_before_start_does_not_break_start) +TEST_F(MetricsRegistryTest, async_gauges_twice_is_safe) { - telemetry::MetricsRegistry registry(false, mockApp_, j_); + telemetry::MetricsRegistry registry(false, mockApp_, j_, kTestOptions); - // 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. + // A second arm must be a no-op, not a second set of instruments. On the + // enabled path the Phase guard logs and returns; here the stub returns. + registry.startAsyncGauges(); registry.startAsyncGauges(); EXPECT_EQ(registry.isEnabled(), false); - // Phase 1 still works afterwards, so the bad call left no state behind. - registry.start(kTestStartOptions); 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_); + // Constructed with enabled=true, which on the enabled path would build the + // pipeline and register instruments for real. In this build + // XRPL_ENABLE_TELEMETRY is undefined, so both phases compile to the 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_, kTestOptions); // 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(kTestStartOptions)); EXPECT_NO_THROW(registry.startAsyncGauges()); EXPECT_NO_THROW(registry.stop()); @@ -1050,8 +1034,7 @@ TEST_F(MetricsRegistryTest, async_gauges_respect_the_compile_time_guard) TEST_F(MetricsRegistryTest, disabled_recording_methods) { - telemetry::MetricsRegistry registry(false, mockApp_, j_); - registry.start(kTestStartOptions); + telemetry::MetricsRegistry registry(false, mockApp_, j_, kTestOptions); // All recording methods should be no-ops (not crash). registry.recordRpcStarted("server_info"); @@ -1068,8 +1051,7 @@ TEST_F(MetricsRegistryTest, destructor_calls_stop) { { // Let the destructor handle cleanup. - telemetry::MetricsRegistry registry(false, mockApp_, j_); - registry.start(kTestStartOptions); + telemetry::MetricsRegistry const registry(false, mockApp_, j_, kTestOptions); } // If we get here without crash, the destructor handled stop. } @@ -1114,7 +1096,7 @@ TEST_F(MetricsRegistryTest, disabled_build_exposes_no_meter_accessor) // The enable flag is still queryable and reports exactly false -- the class // is a no-op, not an absent type. - telemetry::MetricsRegistry const registry(false, mockApp_, j_); + telemetry::MetricsRegistry const registry(false, mockApp_, j_, kTestOptions); EXPECT_FALSE(registry.isEnabled()); } @@ -1124,9 +1106,9 @@ TEST_F(MetricsRegistryTest, disabled_build_exposes_no_meter_accessor) // so reaching the end without an exception proves no callback ran. TEST_F(MetricsRegistryTest, disabled_lifecycle_never_consults_gauge_services) { - telemetry::MetricsRegistry registry(false, mockApp_, j_); + telemetry::MetricsRegistry registry(false, mockApp_, j_, kTestOptions); - // start() is where registerAsyncGauges() -- and with it + // startAsyncGauges() is where registerAsyncGauges() -- and with it // registerUnlQuorumGauge() / registerClockSkewGauge() / // registerSyncStateGauge() / registerStallEventsCounter() / // registerSyncAcquireGauge() / registerCacheHitRateDetailGauge() / @@ -1134,14 +1116,14 @@ TEST_F(MetricsRegistryTest, disabled_lifecycle_never_consults_gauge_services) // registerPeerLedgerSupplyGauge() / registerSlotCensusGauge() / // registerAmendmentBlockGauge() / registerNodeStoreGauge() -- // would run. - EXPECT_NO_THROW(registry.start(kTestStartOptions)); + EXPECT_NO_THROW(registry.startAsyncGauges()); // detachCallbacks() is the shutdown hook the real gauges honour. It must be // safe and idempotent even though there is nothing to detach. EXPECT_NO_THROW(registry.detachCallbacks()); EXPECT_NO_THROW(registry.detachCallbacks()); - // Still disabled after a full start(): start() must not flip the flag. + // Still disabled after startAsyncGauges(): it must not flip the flag. EXPECT_FALSE(registry.isEnabled()); EXPECT_NO_THROW(registry.stop()); @@ -1189,12 +1171,12 @@ TEST_F(MetricsRegistryTest, disabled_lifecycle_never_consults_gauge_services) // Even asking for enabled=true registers no sync-diagnostics gauge on a // telemetry-off build. isEnabled() faithfully echoes the constructor argument // (the flag lives outside the #ifdef), so the flag alone does NOT prove the -// gauges are inert -- the mock does: a full start()/stop() cycle with +// gauges are inert -- the mock does: a full startAsyncGauges()/stop() cycle with // enabled=true still consults no service, so no callback was ever registered. // Asserts the exact flag value on BOTH construction paths. TEST_F(MetricsRegistryTest, enabled_flag_alone_registers_no_gauges_when_compiled_out) { - telemetry::MetricsRegistry enabledRequest(true, mockApp_, j_); + telemetry::MetricsRegistry enabledRequest(true, mockApp_, j_, kTestOptions); // The flag is echoed back exactly, true not false: it is a plain member, // not gated on XRPL_ENABLE_TELEMETRY. @@ -1211,12 +1193,12 @@ TEST_F(MetricsRegistryTest, enabled_flag_alone_registers_no_gauges_when_compiled // getLoadManager()/getInboundLedgers()/getNodeFamily()/getJobQueue()/ // getOverlay()/getAmendmentTable()/getNodeStore() and // throw std::logic_error. - EXPECT_NO_THROW(enabledRequest.start(kTestStartOptions)); + EXPECT_NO_THROW(enabledRequest.startAsyncGauges()); EXPECT_NO_THROW(enabledRequest.detachCallbacks()); EXPECT_NO_THROW(enabledRequest.stop()); // Contrast: enabled=false reports exactly false. - telemetry::MetricsRegistry const disabledRequest(false, mockApp_, j_); + telemetry::MetricsRegistry const disabledRequest(false, mockApp_, j_, kTestOptions); EXPECT_FALSE(disabledRequest.isEnabled()); } diff --git a/src/tests/libxrpl/telemetry/SpanGuardScope.cpp b/src/tests/libxrpl/telemetry/SpanGuardScope.cpp index 32f49157b4..a6afb3c9b7 100644 --- a/src/tests/libxrpl/telemetry/SpanGuardScope.cpp +++ b/src/tests/libxrpl/telemetry/SpanGuardScope.cpp @@ -193,10 +193,7 @@ public: opentelemetry::nostd::shared_ptr getMeter(std::string_view name) override { - static auto noopProvider = - opentelemetry::nostd::shared_ptr( - new opentelemetry::metrics::NoopMeterProvider()); - return noopProvider->GetMeter(std::string(name), std::string(kMeterVersion)); + return noopMeter(name); } opentelemetry::nostd::shared_ptr diff --git a/src/tests/libxrpl/telemetry/TelemetryConfig.cpp b/src/tests/libxrpl/telemetry/TelemetryConfig.cpp index c92e92a7ef..64cf521e1c 100644 --- a/src/tests/libxrpl/telemetry/TelemetryConfig.cpp +++ b/src/tests/libxrpl/telemetry/TelemetryConfig.cpp @@ -322,6 +322,18 @@ TEST(TelemetryConfig, parse_empty_section) EXPECT_TRUE(setup.traceLedger); } +TEST(TelemetryConfig, empty_service_instance_id_falls_back_to_node_key) +{ + // An empty value is indistinguishable from an unset key on the metrics + // side (makeMetricsRegistryOptions falls back to the node key), so the + // trace side must do the same. Without this fallback traces stamp "" while + // metrics stamp the node key and every $node filter shows half the series. + Section section; + section.set("service_instance_id", ""); + auto const setup = telemetry::makeTelemetrySetup(section, "nHUtest123", "2.0.0", 0); + EXPECT_EQ(setup.serviceInstanceId, "nHUtest123"); +} + TEST(TelemetryConfig, parse_full_section) { // The CA path has to name a real file: with enabled=1 and use_tls=1 the diff --git a/src/xrpld/app/main/Application.cpp b/src/xrpld/app/main/Application.cpp index 24a4e42d16..988a5ead55 100644 --- a/src/xrpld/app/main/Application.cpp +++ b/src/xrpld/app/main/Application.cpp @@ -88,9 +88,11 @@ #include #include #include // IWYU pragma: keep +#include #include #include #include +#include #include #include // IWYU pragma: keep #include @@ -150,6 +152,65 @@ namespace xrpl { static void fixConfigPorts(Config& config, Endpoints const& endpoints); +/** + * Read the native metrics pipeline settings from [telemetry] and [network_id]. + * + * The identity and TLS values must match what makeTelemetrySetup() gives the + * trace pipeline, or this node reports two identities. Telemetry does not + * expose the Setup it parsed, so those keys are read here a second time. The + * export cadence is the registry's own (10 s) and is not read from config. + * + * @param config The loaded server config. + * @param nodeKey Base58 node public key, resolved before construction. + * @return Options for MetricsRegistry's constructor. + */ +static telemetry::MetricsRegistry::Options +makeMetricsRegistryOptions(Config const& config, std::string const& nodeKey) +{ + auto const& section = config.section("telemetry"); + telemetry::MetricsRegistry::Options options; + + // metrics_endpoint is a full URL of its own, not a host to be joined. The + // default is the one Telemetry::Setup carries, so both pipelines fall back + // to the same collector. + options.endpoint = telemetry::Telemetry::Setup{}.metricsEndpoint; + set(options.endpoint, "metrics_endpoint", section); + + // Same default and same key as makeTelemetrySetup(), so traces and + // metrics carry one service.name. systemName() is "xrpld". + options.serviceName = systemName(); + set(options.serviceName, "service_name", section); + + // Not from config: the build's version, the same source the trace + // resource takes it from. + options.serviceVersion = build_info::getVersionString(); + + // service_instance_id is the label every dashboard filters $node on. + // xrpl.node.id carries the same key and cannot be overridden by config. + // Both come from the identity resolveNodeIdentity() decided before + // construction, the same source Telemetry's own metrics resource uses. + set(options.serviceInstanceId, "service_instance_id", section); + if (options.serviceInstanceId.empty()) + options.serviceInstanceId = nodeKey; + options.nodeId = nodeKey; + + // xrpl.network.id, and the xrpl.network.type label the registry derives + // from it. Without this the collector's insert rule fills in its own + // default and a devnet node reports mainnet on this pipeline. + options.networkId = config.networkId; + + // The exporter connection reads the same four TLS keys the trace exporter + // does, so one [telemetry] block covers both signals. use_tls is an int + // compared to 0, matching makeTelemetrySetup(). + int useTls = 0; + set(useTls, "use_tls", section); + options.useTls = useTls != 0; + set(options.tlsCaCertPath, "tls_ca_cert", section); + set(options.tlsClientCertPath, "tls_client_cert", section); + set(options.tlsClientKeyPath, "tls_client_key", section); + return options; +} + // VFALCO TODO Move the function definitions into the class declaration class ApplicationImp : public Application, public BasicApp { @@ -228,10 +289,20 @@ public: beast::Journal journal_; std::unique_ptr perfLog_; + /** + * This node's keypair, resolved before construction by + * resolveNodeIdentity() and persisted by setup(). Declared before + * telemetry_ because that builds resource attributes from it, and they are + * immutable once built. + */ + std::pair nodeIdentity_; std::unique_ptr telemetry_; /** * OTel metrics registry for gap-fill metrics (counters, histograms, - * observable gauges). Created after telemetry_ during setup(). + * observable gauges). Its constructor builds the pipeline and every + * synchronous instrument, so it must stay declared after telemetry_ and + * before every subsystem that records a metric. Declaration order is the + * whole guarantee. Gauges are armed later by startTelemetryGauges(). */ std::unique_ptr metricsRegistry_; Application::MutexType masterMutex_; @@ -260,7 +331,6 @@ public: NodeCache tempNodeCache_; CachedSLEs cachedSLEs_; std::unique_ptr networkIDService_; - std::optional> nodeIdentity_; ValidatorKeys const validatorKeys_; std::unique_ptr resourceManager_; @@ -341,7 +411,7 @@ public: std::unique_ptr config, std::unique_ptr logs, std::unique_ptr timeKeeper, - std::optional const& nodePublicKey) + std::pair const& resolvedIdentity) : BasicApp(numberOfThreads(*config)) , config_(std::move(config)) , logs_(std::move(logs)) @@ -355,26 +425,31 @@ public: *this, logs_->journal("PerfLog"), [this] { signalStop("PerfLog"); })) + , nodeIdentity_(resolvedIdentity) // Telemetry publishes the MeterProvider on construction, so it must // precede collectorManager_ below and every subsystem that creates an // instrument. Its resource is immutable, so the instance id has to be - // supplied now; empty means this run reports none. + // supplied now, from the identity resolved above. , telemetry_( telemetry::makeTelemetry( telemetry::makeTelemetrySetup( config_->section("telemetry"), - nodePublicKey.value_or(""), + toBase58(TokenType::NodePublic, nodeIdentity_.first), build_info::getVersionString(), config_->networkId), logs_->journal("Telemetry"))) - // Built here, not in setup(): getMetricsRegistry() is read from the job - // queue and io threads, which are already running, so assigning the - // handle later would race with those reads. + // Built here, not in setup(), for two reasons: getMetricsRegistry() is + // read from job-queue and io threads that are already running, and the + // constructor creates every synchronous instrument, which must happen + // before any subsystem below can record one. , metricsRegistry_( std::make_unique( telemetry_->isEnabled(), *this, - logs_->journal("MetricsRegistry"))) + logs_->journal("MetricsRegistry"), + makeMetricsRegistryOptions( + *config_, + toBase58(TokenType::NodePublic, nodeIdentity_.first)))) , txMaster_(*this) , collectorManager_(makeCollectorManager( @@ -553,16 +628,16 @@ public: } /** - * Stop observing and stop telemetry before the members are destroyed. + * Stop both observers and stop telemetry before the members are destroyed. * - * The metrics reader thread runs callbacks that read the services member - * destruction is about to tear down. telemetry_ is declared early because - * the collector needs its MeterProvider, so reverse-order member destruction - * would take it down last. + * The insight collector and the metrics registry each own a reader thread + * whose callbacks read the services member destruction is about to tear + * down. Both are declared early, so reverse-order destruction would take + * them down last. * - * run() does both on the normal path; this covers the paths that never - * reach it -- every `return false` in setup(), and the unit tests. Both - * calls are idempotent. + * run() does all of this on the normal path; this covers the paths that + * never reach it -- every `return false` in setup(), and the unit tests. + * Every call here is idempotent. */ ~ApplicationImp() override { @@ -571,6 +646,7 @@ public: try { collectorManager_->collector()->onCollectionStopping(); + stopMetricsRegistry(); telemetry_->stop(); } catch (std::exception const& e) @@ -651,10 +727,7 @@ public: std::pair const& nodeIdentity() override { - if (nodeIdentity_) - return *nodeIdentity_; - - logicError("Accessing Application::nodeIdentity() before it is initialized."); + return nodeIdentity_; } std::optional @@ -1315,30 +1388,18 @@ private: startGenesisLedger(); /** - * Start the tracing pipeline and the metrics provider and synchronous - * instruments. First of the two telemetry startup phases. + * Start the tracing pipeline. * - * 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. + * Called once from setup(), after the node identity is known and before + * beginConsensus() emits the first spans. SpanGuard drops a span whenever + * the global Telemetry instance is not yet live, so this cannot wait for + * start(). * - * 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 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. + * The metrics pipeline is not started here: metricsRegistry_'s constructor + * built it, so its instruments exist before any subsystem does. * - * The resource attributes, including service.instance.id, were supplied at - * construction. + * @pre nodeIdentity_ is populated, so setServiceInstanceId() has already + * supplied the tracer's service.instance.id. */ void startTelemetry() const; @@ -1350,21 +1411,27 @@ private: * 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(). + * by the callbacks' own try/catch — so this cannot run at construction. * - * @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 + * @pre 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 built earlier in setup(). See * MetricsRegistry::startAsyncGauges() for the full list. */ void startTelemetryGauges() const; + /** + * Stop the metrics registry: detach its gauge callbacks and join its + * reader thread. Idempotent. Called from run() before any observed + * service stops, and again from ~ApplicationImp for the paths that never + * reach run(). + */ + void + stopMetricsRegistry() const; + std::shared_ptr getLastFullLedger(); @@ -1460,33 +1527,38 @@ ApplicationImp::setup(boost::program_options::variables_map const& cmdline) return false; } - nodeIdentity_ = getNodeIdentity(*this, cmdline); + // Persist the identity resolved before construction, or adopt the one the + // wallet already holds. Telemetry is already reporting the resolved key. + nodeIdentity_ = getNodeIdentity(*this, cmdline, nodeIdentity_); // The metrics resource was fixed at construction, but the tracer resource is - // built by start() below, so a key minted just now can still reach spans. - if (!config_->section("telemetry").exists("service_instance_id")) - telemetry_->setServiceInstanceId(toBase58(TokenType::NodePublic, nodeIdentity_->first)); + // built by start() below, so the stored key still reaches spans if it + // differs from the resolved one. Treat an empty configured value as absent, + // matching makeMetricsRegistryOptions() and makeTelemetrySetup(), so the + // trace side does not keep an empty instance id while the metrics side + // holds the node key. + if (config_->section("telemetry").valueOr("service_instance_id", "").empty()) + telemetry_->setServiceInstanceId(toBase58(TokenType::NodePublic, nodeIdentity_.first)); // xrpl.node.id always carries the node public key. Unlike // service_instance_id it is not configurable, so traces and metrics keep a // stable per-node key whatever [telemetry] says. - telemetry_->setNodeId(toBase58(TokenType::NodePublic, nodeIdentity_->first)); + telemetry_->setNodeId(toBase58(TokenType::NodePublic, nodeIdentity_.first)); - // 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. + // Start tracing here, not in start(). Spans are emitted during the rest of + // setup() — the first consensus round in beginConsensus() below — and are + // dropped unless the global Telemetry instance 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. + // would export a partial trace stream for a run that never comes up. + // - Before beginConsensus(): that call emits the first consensus spans. // - // Only the observable instruments have to wait for their subsystems; they - // are registered separately by startTelemetryGauges() once overlay_ exists. + // Metrics need nothing here: metricsRegistry_'s constructor built the + // pipeline and the synchronous instruments before any subsystem existed. + // Only the observable instruments wait for their subsystems; they are + // registered by startTelemetryGauges() once overlay_ exists. startTelemetry(); if (validatorKeys_.keys) @@ -1803,67 +1875,23 @@ ApplicationImp::start(bool withTimers) void ApplicationImp::startTelemetry() const { - // Start tracing first so subsequent startup/early activity can be traced. telemetry_->start(); - - // Start the metrics pipeline after telemetry. Everything below is read - // from [telemetry] here because Telemetry does not expose the Setup it - // parsed. Every value must match what makeTelemetrySetup() gave the trace - // pipeline above, or this node reports two identities. - if (metricsRegistry_) - { - auto const& section = config_->section("telemetry"); - - telemetry::MetricsRegistry::StartOptions options; - - // metrics_endpoint is a full URL of its own, not a host to be joined. - options.endpoint = "http://localhost:4318/v1/metrics"; - set(options.endpoint, "metrics_endpoint", section); - - // Same default and same key as makeTelemetrySetup(), so traces and - // metrics carry one service.name. systemName() is "xrpld". - options.serviceName = systemName(); - set(options.serviceName, "service_name", section); - - // Not from config: the build's version, the same source the trace - // resource takes it from at construction. - options.serviceVersion = build_info::getVersionString(); - - // The MeterProvider Resource carries service_instance_id, which - // Prometheus turns into the label every dashboard filters $node on. - set(options.serviceInstanceId, "service_instance_id", section); - if (options.serviceInstanceId.empty() && nodeIdentity_) - options.serviceInstanceId = toBase58(TokenType::NodePublic, nodeIdentity_->first); - - // The node public key also goes on its own resource attribute, - // xrpl.node.id, which config cannot override. - if (nodeIdentity_) - options.nodeId = toBase58(TokenType::NodePublic, nodeIdentity_->first); - - // xrpl.network.id, and the xrpl.network.type label the registry - // derives from it. Without this the collector's insert rule fills in - // its own default and a devnet node reports mainnet on this pipeline. - options.networkId = config_->networkId; - - // The exporter connection reads the same four TLS keys the trace - // exporter does, so one [telemetry] block covers both signals. use_tls - // is an int compared to 0, matching makeTelemetrySetup(). - int useTls = 0; - set(useTls, "use_tls", section); - options.useTls = useTls != 0; - set(options.tlsCaCertPath, "tls_ca_cert", section); - set(options.tlsClientCertPath, "tls_client_cert", section); - set(options.tlsClientKeyPath, "tls_client_key", section); - - metricsRegistry_->start(options); - } } void ApplicationImp::startTelemetryGauges() const { - if (metricsRegistry_) - metricsRegistry_->startAsyncGauges(); + metricsRegistry_->startAsyncGauges(); +} + +void +ApplicationImp::stopMetricsRegistry() const +{ + // stop() detaches the callbacks and then shuts the provider down, which + // joins the reader thread, so once it returns no callback is running or + // can start. The cost is that metrics recorded after this point are not + // exported. + metricsRegistry_->stop(); } void @@ -1938,32 +1966,19 @@ ApplicationImp::run() return getValidators().trustedPublisher(pubKey); }); - // Stop observing before any service below is stopped: the collector's gauge - // callbacks run hook handlers that read ledgerMaster_, networkOPs_, the peer - // finder, the job queue and overlay_. Returns once no callback is running. + // Both observers stop before any service below is stopped. The collector's + // gauge callbacks run hook handlers that read ledgerMaster_, networkOPs_, + // the peer finder, the job queue and overlay_; the registry's callbacks + // run on the OTel reader thread and read nodeStore_, overlay_, networkOPs_, + // loadManager_, ledgerMaster, inboundLedgers and more. Each call returns + // once no callback is running or can start. collectorManager_->collector()->onCollectionStopping(); + stopMetricsRegistry(); // The order of these stop calls is delicate. // Re-ordering them risks undefined behavior. loadManager_->stop(); - // Stop the metrics pipeline BEFORE any service its callbacks read. Those - // callbacks run on the OTel reader thread and touch nodeStore_, overlay_, - // networkOPs_, ledgerMaster, inboundLedgers and more, so a tick arriving - // after one of them has stopped would read dangling state. - // - // detachCallbacks() alone would not be enough: it flips a flag that each - // callback checks on entry, which leaves a callback that is already past - // that check running. stop() shuts the provider down, which joins the - // reader thread, so once it returns no callback is running or can start. - // The cost is that metrics recorded during the remaining shutdown steps - // are not exported. - if (metricsRegistry_) - { - metricsRegistry_->detachCallbacks(); - metricsRegistry_->stop(); - } - shaMapStore_->stop(); jobQueue_->stop(); if (overlay_) @@ -2545,7 +2560,13 @@ makeApplication( std::unique_ptr logs, std::unique_ptr timeKeeper) { - return makeApplication(std::move(config), std::move(logs), std::move(timeKeeper), std::nullopt); + // No identity supplied, so mint one. setup() stores it if the wallet holds + // none, which is what a standalone run and a test Application do anyway. + return makeApplication( + std::move(config), + std::move(logs), + std::move(timeKeeper), + randomKeyPair(KeyType::Secp256k1)); } std::unique_ptr @@ -2553,10 +2574,10 @@ makeApplication( std::unique_ptr config, std::unique_ptr logs, std::unique_ptr timeKeeper, - std::optional const& nodePublicKey) + std::pair const& nodeIdentity) { return std::make_unique( - std::move(config), std::move(logs), std::move(timeKeeper), nodePublicKey); + std::move(config), std::move(logs), std::move(timeKeeper), nodeIdentity); } void diff --git a/src/xrpld/app/main/Application.h b/src/xrpld/app/main/Application.h index 1d7125cd64..8791a6ec8f 100644 --- a/src/xrpld/app/main/Application.h +++ b/src/xrpld/app/main/Application.h @@ -175,18 +175,21 @@ makeApplication( std::unique_ptr timeKeeper); /** - * Construct the application with a known node public key. + * Construct the application with a known node identity. * * Telemetry builds its resource attributes during construction and they are - * immutable, so the base58 node public key must be supplied here. Pass - * std::nullopt when it is unknown; that run reports no instance id. See - * resolveNodePublicKey(). + * immutable, so the node keypair must be supplied here. See + * resolveNodeIdentity(), which decides it from the config and command line + * alone; setup() then persists it. + * + * The three-argument overload above mints a keypair, which is what a test + * Application and a standalone run get anyway. */ std::unique_ptr makeApplication( std::unique_ptr config, std::unique_ptr logs, std::unique_ptr timeKeeper, - std::optional const& nodePublicKey); + std::pair const& resolvedIdentity); } // namespace xrpl diff --git a/src/xrpld/app/main/Main.cpp b/src/xrpld/app/main/Main.cpp index fcae528737..bb42bbec04 100644 --- a/src/xrpld/app/main/Main.cpp +++ b/src/xrpld/app/main/Main.cpp @@ -807,13 +807,14 @@ run(int argc, char** argv) if (vm.contains("debug")) setDebugLogSink(logs->makeSink("Debug", beast::Severity::Trace)); - // Telemetry needs the node public key at construction, so read it here - // where a config error can still be reported and the process can exit - // cleanly. getNodeIdentity() in setup() stays authoritative. - std::optional nodePublicKey; + // Telemetry stamps the node public key into resources it builds during + // construction, so the identity is decided here, where a malformed + // [node_seed] can still be reported and the process can exit cleanly. + // setup() persists it; see getNodeIdentity(). + std::optional> nodeIdentity; try { - nodePublicKey = resolveNodePublicKey(*config, vm, logs->journal("Application")); + nodeIdentity = resolveNodeIdentity(*config, vm, logs->journal("Application")); } catch (std::exception const& e) { @@ -821,14 +822,6 @@ run(int argc, char** argv) return -1; } - if (!nodePublicKey) - { - JLOG(logs->journal("Application").warn()) - << "Telemetry: no node identity available yet, so this run reports an empty " - "service.instance.id. Set [telemetry] service_instance_id, or restart once " - "the node key exists."; - } - // Application construction runs member initializers that validate // config (for example the [telemetry] section) and can throw. A throw // from a member-initializer list cannot be recovered inside the @@ -840,14 +833,15 @@ run(int argc, char** argv) // // Only the construction is covered. The [telemetry] section is parsed // near the top of the member list, before the job queue and node store - // are built, so unwinding that throw destroys very little. setup() is + // are built, so unwinding that throw destroys little: the metrics + // registry, whose destructor joins its export thread. setup() is // left outside deliberately: it starts subsystems whose shutdown order // is delicate, and only the normal stop sequence gets that order right. std::unique_ptr app; try { app = makeApplication( - std::move(config), std::move(logs), std::make_unique(), nodePublicKey); + std::move(config), std::move(logs), std::make_unique(), *nodeIdentity); } catch (std::exception const& e) { diff --git a/src/xrpld/app/main/NodeIdentity.cpp b/src/xrpld/app/main/NodeIdentity.cpp index 3860bbe3c6..76a9fe94dd 100644 --- a/src/xrpld/app/main/NodeIdentity.cpp +++ b/src/xrpld/app/main/NodeIdentity.cpp @@ -4,15 +4,11 @@ #include #include -#include #include #include #include -#include #include #include -#include -#include #include #include #include @@ -23,111 +19,47 @@ #include #include #include -#include #include #include #include namespace xrpl { -std::pair -getNodeIdentity(Application& app, boost::program_options::variables_map const& cmdline) +namespace { + +/** + * The stored identity, read without creating or modifying anything. + * + * Runs before the Application, so it opens the wallet itself rather than going + * through getWalletDB(). Three things keep that safe: the file must already + * exist, the init SQL is empty so the schema is never created, and the global + * pragmas are off because they include journal_mode, which rewrites the + * database header. The connection closes before this returns. + * + * @param config The server configuration. + * @param journal Journal for reporting an unreadable database. + * @return The stored keypair, or std::nullopt when there is none to read. + */ +std::optional> +storedIdentity(Config const& config, beast::Journal journal) { - std::optional seed; - - if (cmdline.contains("nodeid")) - { - seed = parseGenericSeed(cmdline["nodeid"].as(), false); - - if (!seed) - Throw("Invalid 'nodeid' in command line"); - } - else if (app.config().exists(Sections::kNodeSeed)) - { - seed = parseBase58(app.config().section(Sections::kNodeSeed).lines().front()); - - if (!seed) - { - Throw( - std::string("Invalid [") + Sections::kNodeSeed + "] in configuration file"); - } - } - - if (seed) - { - auto secretKey = generateSecretKey(KeyType::Secp256k1, *seed); - auto publicKey = derivePublicKey(KeyType::Secp256k1, secretKey); - - return {publicKey, secretKey}; - } - - auto db = app.getWalletDB().checkoutDb(); - - if (cmdline.contains("newnodeid")) - clearNodeIdentity(*db); - - return getNodeIdentity(*db); -} - -std::optional -resolveNodePublicKey( - Config const& config, - boost::program_options::variables_map const& cmdline, - beast::Journal journal) -{ - std::optional seed; - bool seedConfigured = false; - - if (cmdline.contains("nodeid")) - { - seedConfigured = true; - seed = parseGenericSeed(cmdline["nodeid"].as(), false); - } - else if (config.exists(Sections::kNodeSeed)) - { - seedConfigured = true; - if (auto const& lines = config.section(Sections::kNodeSeed).lines(); !lines.empty()) - seed = parseBase58(lines.front()); - } - - // A configured seed decides the identity outright. A malformed or missing - // one is reported by getNodeIdentity(), which runs later. - if (seedConfigured) - { - if (!seed) - return std::nullopt; - - auto const secretKey = generateSecretKey(KeyType::Secp256k1, *seed); - return toBase58(TokenType::NodePublic, derivePublicKey(KeyType::Secp256k1, secretKey)); - } - - // --newnodeid discards whatever is stored. - if (cmdline.contains("newnodeid")) - return std::nullopt; - try { auto setup = setupDatabaseCon(config, journal); - // Standalone uses a temporary database, so nothing is persisted and this - // run will mint a fresh key. + // Standalone gets a private temporary database, so there is nothing + // persisted to read and nothing setup() could read back either. if (setup.standAlone && setup.startUp != StartUpType::Load && setup.startUp != StartUpType::LoadFile && setup.startUp != StartUpType::Replay) { return std::nullopt; } - // The global pragmas include journal_mode, which rewrites the database - // header. The wallet is opened without them everywhere else. setup.useGlobalPragma = false; - // Only read an existing file: SQLite would otherwise create one. if (std::error_code ec; !std::filesystem::exists(setup.dataDir / kWalletDbName, ec)) - { return std::nullopt; - } - // Empty init SQL: open the existing schema, never create it. DatabaseCon walletDb{ setup, kWalletDbName, @@ -136,8 +68,7 @@ resolveNodePublicKey( journal}; auto db = walletDb.checkoutDb(); - if (auto const stored = readNodeIdentity(*db)) - return toBase58(TokenType::NodePublic, stored->first); + return readNodeIdentity(*db); } catch (std::exception const& e) { @@ -147,4 +78,65 @@ resolveNodePublicKey( return std::nullopt; } +} // namespace + +std::pair +resolveNodeIdentity( + Config const& config, + boost::program_options::variables_map const& cmdline, + beast::Journal journal) +{ + // Marshal Config and the cmdline into the libxrpl-level primitives the + // decision helpers take. Keeping the decision in libxrpl lets its tests + // cover every branch without an xrpld Config. + std::optional cmdlineSeed; + if (cmdline.contains("nodeid")) + cmdlineSeed = cmdline["nodeid"].as(); + + std::optional configSeedLine; + if (config.exists(Sections::kNodeSeed)) + { + auto const& lines = config.section(Sections::kNodeSeed).lines(); + // Present-but-empty stays as an empty string, so parseNodeIdentitySeed + // throws the same "invalid [node_seed]" error the old code did. + configSeedLine = lines.empty() ? std::string{} : lines.front(); + } + + auto const seed = parseNodeIdentitySeed(cmdlineSeed, configSeedLine); + bool const newNodeId = cmdline.contains("newnodeid"); + + // storedIdentity() catches its own exceptions and returns std::nullopt on + // any read failure, so a wallet that will not open collapses into "mint". + return selectNodeIdentity(seed, newNodeId, [&] { return storedIdentity(config, journal); }); +} + +std::pair +getNodeIdentity( + Application& app, + boost::program_options::variables_map const& cmdline, + std::pair const& resolved) +{ + // A configured seed reaches neither the reader nor the writer. + if (cmdline.contains("nodeid") || app.config().exists(Sections::kNodeSeed)) + return resolved; + + auto db = app.getWalletDB().checkoutDb(); + + if (cmdline.contains("newnodeid")) + clearNodeIdentity(*db); + + // What is stored wins, so a restart keeps the node's identity even if + // another process wrote one between construction and here. Telemetry's + // resources are already built from `resolved`, so on that one run the two + // would disagree; it needs a restart to line up, as the configuration + // reference records. + if (auto const stored = readNodeIdentity(*db)) + return *stored; + + // Nothing stored, or --newnodeid just cleared it. Persist the pair + // telemetry is already reporting, so both agree from now on. + storeNodeIdentity(*db, resolved); + return resolved; +} + } // namespace xrpl diff --git a/src/xrpld/app/main/NodeIdentity.h b/src/xrpld/app/main/NodeIdentity.h index 7309f6007a..837d07184b 100644 --- a/src/xrpld/app/main/NodeIdentity.h +++ b/src/xrpld/app/main/NodeIdentity.h @@ -16,34 +16,47 @@ namespace xrpl { /** - * The cryptographic credentials identifying this server instance. + * This server's identity, resolved before the Application exists. * - * @param app The application object - * @param cmdline The command line parameters passed into the application. - */ -std::pair -getNodeIdentity(Application& app, boost::program_options::variables_map const& cmdline); - -/** - * This server's public key, read without creating or modifying anything. + * Telemetry stamps the node public key into resource attributes that are + * immutable once built, and those resources are built in ApplicationImp's + * member-init list. So the identity has to be decided before construction, + * from the config and the command line alone. * - * For callers that need the identity before the Application exists, such as - * telemetry building its resource attributes in the member-init list. Derives - * from a configured seed when there is one, otherwise reads the wallet database - * only if it already exists. - * - * getNodeIdentity() remains authoritative and mints a key when none exists. + * Always returns a keypair. It derives one from a configured seed, else reads + * the wallet database if it already exists, else mints one. Nothing is created + * or written here: getNodeIdentity() persists the result once setup() has + * opened the database. * * @param config The server configuration. * @param cmdline The command line parameters passed into the application. * @param journal Journal for reporting an unreadable database. - * @return The base58-encoded node public key, or std::nullopt if none can be - * read. + * @return This node's keypair. + * @throws std::runtime_error if a configured seed is malformed. */ -std::optional -resolveNodePublicKey( +std::pair +resolveNodeIdentity( Config const& config, boost::program_options::variables_map const& cmdline, beast::Journal journal); +/** + * The cryptographic credentials identifying this server instance, persisted. + * + * Called from setup(), once the wallet database is open. Stores @p resolved + * when the database holds no identity, and returns whatever the database holds + * when it does. + * + * @param app The application object + * @param cmdline The command line parameters passed into the application. + * @param resolved The keypair resolveNodeIdentity() decided before + * construction, which telemetry is already reporting. + * @return This node's keypair. + */ +std::pair +getNodeIdentity( + Application& app, + boost::program_options::variables_map const& cmdline, + std::pair const& resolved); + } // namespace xrpl diff --git a/src/xrpld/telemetry/MetricMacros.h b/src/xrpld/telemetry/MetricMacros.h index 1b008cd6c5..ae6c820468 100644 --- a/src/xrpld/telemetry/MetricMacros.h +++ b/src/xrpld/telemetry/MetricMacros.h @@ -7,7 +7,7 @@ * field, no init line, no wrapper method in MetricsRegistry. Covers every * instrument kind the OTel Metrics API defines: * - * Synchronous (create-once via std::call_once, then record on every call): + * Synchronous (created once on first use, then record on every call): * Counter XRPL_METRIC_COUNTER_INC / _ADD [+ _LABELED] * UpDownCounter XRPL_METRIC_UPDOWN_ADD [+ _LABELED] * Histogram XRPL_METRIC_HISTOGRAM_RECORD [+ _LABELED] @@ -87,10 +87,21 @@ * MetricsRegistry::initExporterAndProvider() as today; the * histogram-record call itself can still use the macro. * - * @note Only call the SYNCHRONOUS macros (Counter/UpDownCounter/ - * Histogram/Gauge) from code that runs AFTER MetricsRegistry::start() has - * completed (RPC handlers, job callbacks, consensus rounds, tx apply, peer - * message handlers). + * @note The SYNCHRONOUS macros (Counter/UpDownCounter/Histogram/Gauge) + * create their instrument once, on first use, from + * MetricsRegistry::meter(). The registry builds that meter in its + * constructor, before any subsystem exists, and guarantees it is never + * empty while the registry is enabled (a no-op meter stands in if the + * pipeline failed to build, and again after stop()). So a call site holds + * a valid instrument from its first call and needs no check of its own. + * The only branch on the hot path is the recording() gate, which is false + * once stop() has torn the pipeline down; without that gate a Record on a + * stale SDK instrument would deref a dangling AggregationConfig. + * + * @note Static-init safety: Meter::CreateXxx is declared noexcept in the + * OTel API (opentelemetry/metrics/meter.h), so the function-local static + * that caches the instrument cannot throw during first-call construction. + * A throw there would call std::terminate. * * @note The OBSERVABLE registration macros are the opposite: call them * EAGERLY, exactly once, from constructor/init code -- never from a hot @@ -124,82 +135,57 @@ #ifdef XRPL_ENABLE_TELEMETRY #include // IWYU pragma: keep -#include // IWYU pragma: keep -#define XRPL_METRIC_COUNTER_INC(app, name, description) \ - do \ - { \ - if (auto* xrpl_mr_ = (app).getMetricsRegistry(); xrpl_mr_ && xrpl_mr_->isEnabled()) \ - { \ - static opentelemetry::nostd::unique_ptr> \ - xrpl_counter_; \ - static std::once_flag xrpl_once_; \ - std::call_once(xrpl_once_, [&] { \ - if (auto xrpl_m_ = xrpl_mr_->meter()) \ - xrpl_counter_ = xrpl_m_->CreateUInt64Counter((name), (description)); \ - }); \ - if (xrpl_counter_) \ - xrpl_counter_->Add(1); \ - } \ +#define XRPL_METRIC_COUNTER_INC(app, name, description) \ + do \ + { \ + if (auto* xrpl_mr_ = (app).getMetricsRegistry(); xrpl_mr_ && xrpl_mr_->recording()) \ + { \ + static auto const xrpl_counter_ = \ + xrpl_mr_->meter()->CreateUInt64Counter((name), (description)); \ + xrpl_counter_->Add(1); \ + } \ } while (false) // The label set is passed as trailing variadic arguments so a // brace-enclosed initializer list (e.g. {{"reason", std::string("x")}}), // which contains a top-level comma, survives preprocessing as a single // logical argument. __VA_ARGS__ re-joins it verbatim into the Add() call. -#define XRPL_METRIC_COUNTER_INC_LABELED(app, name, description, ...) \ - do \ - { \ - if (auto* xrpl_mr_ = (app).getMetricsRegistry(); xrpl_mr_ && xrpl_mr_->isEnabled()) \ - { \ - static opentelemetry::nostd::unique_ptr> \ - xrpl_counter_; \ - static std::once_flag xrpl_once_; \ - std::call_once(xrpl_once_, [&] { \ - if (auto xrpl_m_ = xrpl_mr_->meter()) \ - xrpl_counter_ = xrpl_m_->CreateUInt64Counter((name), (description)); \ - }); \ - if (xrpl_counter_) \ - xrpl_counter_->Add(1, __VA_ARGS__); \ - } \ +#define XRPL_METRIC_COUNTER_INC_LABELED(app, name, description, ...) \ + do \ + { \ + if (auto* xrpl_mr_ = (app).getMetricsRegistry(); xrpl_mr_ && xrpl_mr_->recording()) \ + { \ + static auto const xrpl_counter_ = \ + xrpl_mr_->meter()->CreateUInt64Counter((name), (description)); \ + xrpl_counter_->Add(1, __VA_ARGS__); \ + } \ } while (false) // Same as XRPL_METRIC_COUNTER_INC, but increments by a caller-supplied amount // instead of a fixed 1 (e.g. bytes transferred, batch sizes). -#define XRPL_METRIC_COUNTER_ADD(app, name, description, amount) \ - do \ - { \ - if (auto* xrpl_mr_ = (app).getMetricsRegistry(); xrpl_mr_ && xrpl_mr_->isEnabled()) \ - { \ - static opentelemetry::nostd::unique_ptr> \ - xrpl_counter_; \ - static std::once_flag xrpl_once_; \ - std::call_once(xrpl_once_, [&] { \ - if (auto xrpl_m_ = xrpl_mr_->meter()) \ - xrpl_counter_ = xrpl_m_->CreateUInt64Counter((name), (description)); \ - }); \ - if (xrpl_counter_) \ - xrpl_counter_->Add(amount); \ - } \ +#define XRPL_METRIC_COUNTER_ADD(app, name, description, amount) \ + do \ + { \ + if (auto* xrpl_mr_ = (app).getMetricsRegistry(); xrpl_mr_ && xrpl_mr_->recording()) \ + { \ + static auto const xrpl_counter_ = \ + xrpl_mr_->meter()->CreateUInt64Counter((name), (description)); \ + xrpl_counter_->Add(amount); \ + } \ } while (false) // amount is fixed; the trailing variadic args carry the label set (see the // note on XRPL_METRIC_COUNTER_INC_LABELED for why labels are variadic). -#define XRPL_METRIC_COUNTER_ADD_LABELED(app, name, description, amount, ...) \ - do \ - { \ - if (auto* xrpl_mr_ = (app).getMetricsRegistry(); xrpl_mr_ && xrpl_mr_->isEnabled()) \ - { \ - static opentelemetry::nostd::unique_ptr> \ - xrpl_counter_; \ - static std::once_flag xrpl_once_; \ - std::call_once(xrpl_once_, [&] { \ - if (auto xrpl_m_ = xrpl_mr_->meter()) \ - xrpl_counter_ = xrpl_m_->CreateUInt64Counter((name), (description)); \ - }); \ - if (xrpl_counter_) \ - xrpl_counter_->Add(amount, __VA_ARGS__); \ - } \ +#define XRPL_METRIC_COUNTER_ADD_LABELED(app, name, description, amount, ...) \ + do \ + { \ + if (auto* xrpl_mr_ = (app).getMetricsRegistry(); xrpl_mr_ && xrpl_mr_->recording()) \ + { \ + static auto const xrpl_counter_ = \ + xrpl_mr_->meter()->CreateUInt64Counter((name), (description)); \ + xrpl_counter_->Add(amount, __VA_ARGS__); \ + } \ } while (false) // UpDownCounter: like COUNTER_ADD, but the underlying instrument permits a @@ -208,79 +194,53 @@ // A plain Counter's Add() must never see a negative value per the OTel // API contract; use this macro, not COUNTER_ADD, whenever the value can // decrease. -#define XRPL_METRIC_UPDOWN_ADD(app, name, description, amount) \ - do \ - { \ - if (auto* xrpl_mr_ = (app).getMetricsRegistry(); xrpl_mr_ && xrpl_mr_->isEnabled()) \ - { \ - static opentelemetry::nostd::unique_ptr< \ - opentelemetry::metrics::UpDownCounter> \ - xrpl_updown_; \ - static std::once_flag xrpl_once_; \ - std::call_once(xrpl_once_, [&] { \ - if (auto xrpl_m_ = xrpl_mr_->meter()) \ - xrpl_updown_ = xrpl_m_->CreateInt64UpDownCounter((name), (description)); \ - }); \ - if (xrpl_updown_) \ - xrpl_updown_->Add(amount); \ - } \ +#define XRPL_METRIC_UPDOWN_ADD(app, name, description, amount) \ + do \ + { \ + if (auto* xrpl_mr_ = (app).getMetricsRegistry(); xrpl_mr_ && xrpl_mr_->recording()) \ + { \ + static auto const xrpl_updown_ = \ + xrpl_mr_->meter()->CreateInt64UpDownCounter((name), (description)); \ + xrpl_updown_->Add(amount); \ + } \ } while (false) // amount may be negative; the trailing variadic args carry the label set // (see the note on XRPL_METRIC_COUNTER_INC_LABELED for why labels are variadic). -#define XRPL_METRIC_UPDOWN_ADD_LABELED(app, name, description, amount, ...) \ - do \ - { \ - if (auto* xrpl_mr_ = (app).getMetricsRegistry(); xrpl_mr_ && xrpl_mr_->isEnabled()) \ - { \ - static opentelemetry::nostd::unique_ptr< \ - opentelemetry::metrics::UpDownCounter> \ - xrpl_updown_; \ - static std::once_flag xrpl_once_; \ - std::call_once(xrpl_once_, [&] { \ - if (auto xrpl_m_ = xrpl_mr_->meter()) \ - xrpl_updown_ = xrpl_m_->CreateInt64UpDownCounter((name), (description)); \ - }); \ - if (xrpl_updown_) \ - xrpl_updown_->Add(amount, __VA_ARGS__); \ - } \ +#define XRPL_METRIC_UPDOWN_ADD_LABELED(app, name, description, amount, ...) \ + do \ + { \ + if (auto* xrpl_mr_ = (app).getMetricsRegistry(); xrpl_mr_ && xrpl_mr_->recording()) \ + { \ + static auto const xrpl_updown_ = \ + xrpl_mr_->meter()->CreateInt64UpDownCounter((name), (description)); \ + xrpl_updown_->Add(amount, __VA_ARGS__); \ + } \ } while (false) -#define XRPL_METRIC_HISTOGRAM_RECORD(app, name, description, value) \ - do \ - { \ - if (auto* xrpl_mr_ = (app).getMetricsRegistry(); xrpl_mr_ && xrpl_mr_->isEnabled()) \ - { \ - static opentelemetry::nostd::unique_ptr> \ - xrpl_hist_; \ - static std::once_flag xrpl_once_; \ - std::call_once(xrpl_once_, [&] { \ - if (auto xrpl_m_ = xrpl_mr_->meter()) \ - xrpl_hist_ = xrpl_m_->CreateDoubleHistogram((name), (description)); \ - }); \ - if (xrpl_hist_) \ - xrpl_hist_->Record(static_cast(value), opentelemetry::context::Context{}); \ - } \ +#define XRPL_METRIC_HISTOGRAM_RECORD(app, name, description, value) \ + do \ + { \ + if (auto* xrpl_mr_ = (app).getMetricsRegistry(); xrpl_mr_ && xrpl_mr_->recording()) \ + { \ + static auto const xrpl_hist_ = \ + xrpl_mr_->meter()->CreateDoubleHistogram((name), (description)); \ + xrpl_hist_->Record(static_cast(value), opentelemetry::context::Context{}); \ + } \ } while (false) // value is fixed; the trailing variadic args carry the label set (see the // note on XRPL_METRIC_COUNTER_INC_LABELED for why labels are variadic). -#define XRPL_METRIC_HISTOGRAM_RECORD_LABELED(app, name, description, value, ...) \ - do \ - { \ - if (auto* xrpl_mr_ = (app).getMetricsRegistry(); xrpl_mr_ && xrpl_mr_->isEnabled()) \ - { \ - static opentelemetry::nostd::unique_ptr> \ - xrpl_hist_; \ - static std::once_flag xrpl_once_; \ - std::call_once(xrpl_once_, [&] { \ - if (auto xrpl_m_ = xrpl_mr_->meter()) \ - xrpl_hist_ = xrpl_m_->CreateDoubleHistogram((name), (description)); \ - }); \ - if (xrpl_hist_) \ - xrpl_hist_->Record( \ - static_cast(value), __VA_ARGS__, opentelemetry::context::Context{}); \ - } \ +#define XRPL_METRIC_HISTOGRAM_RECORD_LABELED(app, name, description, value, ...) \ + do \ + { \ + if (auto* xrpl_mr_ = (app).getMetricsRegistry(); xrpl_mr_ && xrpl_mr_->recording()) \ + { \ + static auto const xrpl_hist_ = \ + xrpl_mr_->meter()->CreateDoubleHistogram((name), (description)); \ + xrpl_hist_->Record( \ + static_cast(value), __VA_ARGS__, opentelemetry::context::Context{}); \ + } \ } while (false) // Synchronous Gauge: last-value snapshot, not a distribution (contrast @@ -297,41 +257,28 @@ // instrument kind (misusing Histogram or UpDownCounter as a gauge // substitute is explicitly discouraged -- see Design/taxonomy section). #if OPENTELEMETRY_ABI_VERSION_NO >= 2 -#define XRPL_METRIC_GAUGE_RECORD(app, name, description, value) \ - do \ - { \ - if (auto* xrpl_mr_ = (app).getMetricsRegistry(); xrpl_mr_ && xrpl_mr_->isEnabled()) \ - { \ - static opentelemetry::nostd::unique_ptr> \ - xrpl_gauge_; \ - static std::once_flag xrpl_once_; \ - std::call_once(xrpl_once_, [&] { \ - if (auto xrpl_m_ = xrpl_mr_->meter()) \ - xrpl_gauge_ = xrpl_m_->CreateDoubleGauge((name), (description)); \ - }); \ - if (xrpl_gauge_) \ - xrpl_gauge_->Record( \ - static_cast(value), opentelemetry::context::Context{}); \ - } \ +#define XRPL_METRIC_GAUGE_RECORD(app, name, description, value) \ + do \ + { \ + if (auto* xrpl_mr_ = (app).getMetricsRegistry(); xrpl_mr_ && xrpl_mr_->recording()) \ + { \ + static auto const xrpl_gauge_ = \ + xrpl_mr_->meter()->CreateDoubleGauge((name), (description)); \ + xrpl_gauge_->Record(static_cast(value), opentelemetry::context::Context{}); \ + } \ } while (false) // value is fixed; the trailing variadic args carry the label set (see the // note on XRPL_METRIC_COUNTER_INC_LABELED for why labels are variadic). -#define XRPL_METRIC_GAUGE_RECORD_LABELED(app, name, description, value, ...) \ - do \ - { \ - if (auto* xrpl_mr_ = (app).getMetricsRegistry(); xrpl_mr_ && xrpl_mr_->isEnabled()) \ - { \ - static opentelemetry::nostd::unique_ptr> \ - xrpl_gauge_; \ - static std::once_flag xrpl_once_; \ - std::call_once(xrpl_once_, [&] { \ - if (auto xrpl_m_ = xrpl_mr_->meter()) \ - xrpl_gauge_ = xrpl_m_->CreateDoubleGauge((name), (description)); \ - }); \ - if (xrpl_gauge_) \ - xrpl_gauge_->Record( \ - static_cast(value), __VA_ARGS__, opentelemetry::context::Context{}); \ - } \ +#define XRPL_METRIC_GAUGE_RECORD_LABELED(app, name, description, value, ...) \ + do \ + { \ + if (auto* xrpl_mr_ = (app).getMetricsRegistry(); xrpl_mr_ && xrpl_mr_->recording()) \ + { \ + static auto const xrpl_gauge_ = \ + xrpl_mr_->meter()->CreateDoubleGauge((name), (description)); \ + xrpl_gauge_->Record( \ + static_cast(value), __VA_ARGS__, opentelemetry::context::Context{}); \ + } \ } while (false) #else #define XRPL_METRIC_GAUGE_RECORD(app, name, description, value) \ @@ -370,88 +317,81 @@ // the registry itself) -- do not "fix" this with a smart pointer that // frees before the reader thread's last collection tick. // ----------------------------------------------------------------- -#define XRPL_METRIC_OBSERVABLE_GAUGE_REGISTER(app, name, description, valueFn) \ - do \ - { \ - if (auto* xrpl_mr_ = (app).getMetricsRegistry(); xrpl_mr_ && xrpl_mr_->isEnabled()) \ - { \ - if (auto xrpl_m_ = xrpl_mr_->meter()) \ - { \ - auto* xrpl_fn_ = new std::function(valueFn); \ - auto xrpl_inst_ = xrpl_m_->CreateInt64ObservableGauge((name), (description)); \ - xrpl_inst_->AddCallback( \ - [](opentelemetry::metrics::ObserverResult result, void* state) { \ - auto* fn = static_cast*>(state); \ - try \ - { \ - opentelemetry::nostd::get>>(result) \ - ->Observe((*fn)()); \ - } \ - catch (...) \ - { \ - } \ - }, \ - xrpl_fn_); \ - } \ - } \ - } while (false) - -#define XRPL_METRIC_OBSERVABLE_COUNTER_REGISTER(app, name, description, valueFn) \ - do \ - { \ - if (auto* xrpl_mr_ = (app).getMetricsRegistry(); xrpl_mr_ && xrpl_mr_->isEnabled()) \ - { \ - if (auto xrpl_m_ = xrpl_mr_->meter()) \ - { \ - auto* xrpl_fn_ = new std::function(valueFn); \ - auto xrpl_inst_ = xrpl_m_->CreateInt64ObservableCounter((name), (description)); \ - xrpl_inst_->AddCallback( \ - [](opentelemetry::metrics::ObserverResult result, void* state) { \ - auto* fn = static_cast*>(state); \ - try \ - { \ - opentelemetry::nostd::get>>(result) \ - ->Observe((*fn)()); \ - } \ - catch (...) \ - { \ - } \ - }, \ - xrpl_fn_); \ - } \ - } \ - } while (false) - -#define XRPL_METRIC_OBSERVABLE_UPDOWN_REGISTER(app, name, description, valueFn) \ +#define XRPL_METRIC_OBSERVABLE_GAUGE_REGISTER(app, name, description, valueFn) \ do \ { \ - if (auto* xrpl_mr_ = (app).getMetricsRegistry(); xrpl_mr_ && xrpl_mr_->isEnabled()) \ + if (auto* xrpl_mr_ = (app).getMetricsRegistry(); xrpl_mr_ && xrpl_mr_->recording()) \ { \ - if (auto xrpl_m_ = xrpl_mr_->meter()) \ - { \ - auto* xrpl_fn_ = new std::function(valueFn); \ - auto xrpl_inst_ = \ - xrpl_m_->CreateInt64ObservableUpDownCounter((name), (description)); \ - xrpl_inst_->AddCallback( \ - [](opentelemetry::metrics::ObserverResult result, void* state) { \ - auto* fn = static_cast*>(state); \ - try \ - { \ - opentelemetry::nostd::get>>(result) \ - ->Observe((*fn)()); \ - } \ - catch (...) \ - { \ - } \ - }, \ - xrpl_fn_); \ - } \ + auto xrpl_m_ = xrpl_mr_->meter(); \ + auto* xrpl_fn_ = new std::function(valueFn); \ + auto xrpl_inst_ = xrpl_m_->CreateInt64ObservableGauge((name), (description)); \ + xrpl_inst_->AddCallback( \ + [](opentelemetry::metrics::ObserverResult result, void* state) { \ + auto* fn = static_cast*>(state); \ + try \ + { \ + opentelemetry::nostd::get>>(result) \ + ->Observe((*fn)()); \ + } \ + catch (...) \ + { \ + } \ + }, \ + xrpl_fn_); \ } \ } while (false) +#define XRPL_METRIC_OBSERVABLE_COUNTER_REGISTER(app, name, description, valueFn) \ + do \ + { \ + if (auto* xrpl_mr_ = (app).getMetricsRegistry(); xrpl_mr_ && xrpl_mr_->recording()) \ + { \ + auto xrpl_m_ = xrpl_mr_->meter(); \ + auto* xrpl_fn_ = new std::function(valueFn); \ + auto xrpl_inst_ = xrpl_m_->CreateInt64ObservableCounter((name), (description)); \ + xrpl_inst_->AddCallback( \ + [](opentelemetry::metrics::ObserverResult result, void* state) { \ + auto* fn = static_cast*>(state); \ + try \ + { \ + opentelemetry::nostd::get>>(result) \ + ->Observe((*fn)()); \ + } \ + catch (...) \ + { \ + } \ + }, \ + xrpl_fn_); \ + } \ + } while (false) + +#define XRPL_METRIC_OBSERVABLE_UPDOWN_REGISTER(app, name, description, valueFn) \ + do \ + { \ + if (auto* xrpl_mr_ = (app).getMetricsRegistry(); xrpl_mr_ && xrpl_mr_->recording()) \ + { \ + auto xrpl_m_ = xrpl_mr_->meter(); \ + auto* xrpl_fn_ = new std::function(valueFn); \ + auto xrpl_inst_ = xrpl_m_->CreateInt64ObservableUpDownCounter((name), (description)); \ + xrpl_inst_->AddCallback( \ + [](opentelemetry::metrics::ObserverResult result, void* state) { \ + auto* fn = static_cast*>(state); \ + try \ + { \ + opentelemetry::nostd::get>>(result) \ + ->Observe((*fn)()); \ + } \ + catch (...) \ + { \ + } \ + }, \ + xrpl_fn_); \ + } \ + } while (false) + #else // !XRPL_ENABLE_TELEMETRY #define XRPL_METRIC_COUNTER_INC(app, name, description) \ diff --git a/src/xrpld/telemetry/MetricsRegistry.cpp b/src/xrpld/telemetry/MetricsRegistry.cpp index f785b6094c..2d26d96768 100644 --- a/src/xrpld/telemetry/MetricsRegistry.cpp +++ b/src/xrpld/telemetry/MetricsRegistry.cpp @@ -103,6 +103,7 @@ #include #include #include +#include #include #include #include @@ -167,7 +168,8 @@ addHistogramView( auto selector = metric_sdk::InstrumentSelectorFactory::Create( metric_sdk::InstrumentType::kHistogram, name, ""); - auto meterSelector = metric_sdk::MeterSelectorFactory::Create("xrpld", "1.0.0", ""); + auto meterSelector = metric_sdk::MeterSelectorFactory::Create( + std::string(xrpl::telemetry::kMeterName), std::string(xrpl::telemetry::kMeterVersion), ""); auto view = metric_sdk::ViewFactory::Create(name, "", metric_sdk::AggregationType::kHistogram, config); @@ -251,23 +253,14 @@ namespace xrpl::telemetry { MetricsRegistry::MetricsRegistry( [[maybe_unused]] bool enabled, [[maybe_unused]] ServiceRegistry& app, - [[maybe_unused]] beast::Journal journal) + [[maybe_unused]] beast::Journal journal, + [[maybe_unused]] Options const& options) : enabled_(enabled) #ifdef XRPL_ENABLE_TELEMETRY , app_(app) , journal_(journal) #endif { -} - -MetricsRegistry::~MetricsRegistry() -{ - stop(); -} - -void -MetricsRegistry::start([[maybe_unused]] StartOptions const& options) -{ #ifdef XRPL_ENABLE_TELEMETRY if (!enabled_) return; @@ -281,21 +274,58 @@ MetricsRegistry::start([[maybe_unused]] StartOptions const& options) << ", nodeId=" << options.nodeId << ", networkId=" << options.networkId << ", useTls=" << options.useTls; - // 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(options); - initSyncInstruments(); + // A broken pipeline must not stop the node. The SDK is third-party code, + // so the catch-all is deliberate, as in ~ApplicationImp. + try + { + initExporterAndProvider(options); + + // Rule for anything added below: the constructor 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. + initSyncInstruments(); + } + catch (std::exception const& e) + { + disablePipeline(e.what()); + return; + } + catch (...) + { + disablePipeline("unknown exception"); + return; + } JLOG(journal_.info()) << "MetricsRegistry: provider and instruments ready"; #endif // XRPL_ENABLE_TELEMETRY } +#ifdef XRPL_ENABLE_TELEMETRY +void +MetricsRegistry::disablePipeline(std::string_view reason) +{ + provider_.reset(); + // A no-op meter keeps the invariant the XRPL_METRIC_* macros rely on: an + // enabled registry always has a meter, so every call site gets an inert + // instrument here with no check of its own. + meter_ = noopMeter(kMeterName); + JLOG(journal_.error()) << "MetricsRegistry: metrics pipeline failed to initialise, " + "continuing without native metrics: " + << reason; +} +#endif // XRPL_ENABLE_TELEMETRY + +MetricsRegistry::~MetricsRegistry() +{ + stop(); +} + void MetricsRegistry::startAsyncGauges() { @@ -303,15 +333,31 @@ MetricsRegistry::startAsyncGauges() 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_) + // One arm per life. A second call would create a second set of + // same-named instruments, and a call after stop() would register on a + // provider that is gone. Checked before the pipeline, so a call after + // stop() is reported as what it is and not as a build failure. + auto const currentPhase = phase_.load(std::memory_order_relaxed); + if (currentPhase != Phase::Ready) { JLOG(journal_.warn()) << "MetricsRegistry: startAsyncGauges() called " - "before start(); no gauges registered"; + << (currentPhase == Phase::Stopped ? "after stop()" : "twice") + << "; ignored"; return; } + // The pipeline failed to build: the meter is a no-op, so registering + // gauges on it would only log a success that is not one. phase_ stays + // at Ready, so a second call lands here again and logs the same message. + // Idempotent. + if (!provider_) + { + JLOG(journal_.warn()) << "MetricsRegistry: startAsyncGauges() without a pipeline; " + "no gauges registered"; + return; + } + phase_.store(Phase::GaugesArmed, std::memory_order_relaxed); + registerAsyncGauges(); JLOG(journal_.info()) << "MetricsRegistry: started successfully"; @@ -320,7 +366,7 @@ MetricsRegistry::startAsyncGauges() #ifdef XRPL_ENABLE_TELEMETRY void -MetricsRegistry::initExporterAndProvider(StartOptions const& options) +MetricsRegistry::initExporterAndProvider(Options const& options) { // Configure OTLP/HTTP metric exporter. The TLS settings come from the one // [telemetry] block that also drives the trace exporter in Telemetry.cpp, @@ -484,7 +530,7 @@ MetricsRegistry::initExporterAndProvider(StartOptions const& options) provider_->AddMetricReader(std::move(reader)); // Get a meter for all xrpld instruments. - meter_ = provider_->GetMeter("xrpld", "1.0.0"); + meter_ = provider_->GetMeter(std::string(kMeterName), std::string(kMeterVersion)); } void @@ -546,6 +592,12 @@ void MetricsRegistry::stop() { #ifdef XRPL_ENABLE_TELEMETRY + // Store Stopped with release ordering BEFORE the pipeline goes away. + // Every recording thread reads phase_ through recording() with acquire + // ordering, so any record that has not yet passed the gate will see + // Stopped and skip. Idempotent: destructor calls this after run() or + // ~ApplicationImp already did. + phase_.store(Phase::Stopped, std::memory_order_release); if (!provider_) return; @@ -558,11 +610,23 @@ MetricsRegistry::stop() // to detach first. callbacksDetached_.store(true, std::memory_order_release); + // meter_ is left alone on purpose. Job threads are still running here and + // may be inside a macro, so writing meter_ would race with their read. + // The recording() gate is what keeps them off the dying pipeline: only the + // macros read meter_, and none of them does so once phase_ is Stopped. + // // SDK teardown order: Shutdown() stops the PeriodicExportingMetricReader // thread (so no further gauge callbacks fire) and performs the final // collect-and-export drain itself. The trailing ForceFlush() is a // redundant safety net (a no-op once the reader is shut down), then // reset() destroys the provider. + // + // provider_.reset() destroys MeterProvider -> MeterContext -> ViewRegistry + // -> each View -> its shared_ptr. Live SDK + // SyncMetricStorage instances cached in call-site statics still hold a + // raw AggregationConfig pointer; a Record with a NEW attribute set after + // this point would fire the factory lambda and deref that dangling + // pointer, and a late meter()->CreateXxx would return null. provider_->Shutdown(); provider_->ForceFlush(); provider_.reset(); @@ -579,7 +643,7 @@ void MetricsRegistry::recordRpcStarted([[maybe_unused]] std::string_view method) { #ifdef XRPL_ENABLE_TELEMETRY - if (!enabled_ || !rpcStartedCounter_) + if (!recording() || !rpcStartedCounter_) return; rpcStartedCounter_->Add(1, {{"method", std::string(method)}}); #endif @@ -591,7 +655,7 @@ MetricsRegistry::recordRpcFinished( [[maybe_unused]] std::int64_t durationUs) { #ifdef XRPL_ENABLE_TELEMETRY - if (!enabled_ || !rpcFinishedCounter_) + if (!recording() || !rpcFinishedCounter_) return; rpcFinishedCounter_->Add(1, {{"method", std::string(method)}}); if (rpcDurationHistogram_) @@ -610,7 +674,7 @@ MetricsRegistry::recordRpcErrored( [[maybe_unused]] std::int64_t durationUs) { #ifdef XRPL_ENABLE_TELEMETRY - if (!enabled_ || !rpcErroredCounter_) + if (!recording() || !rpcErroredCounter_) return; rpcErroredCounter_->Add(1, {{"method", std::string(method)}}); if (rpcDurationHistogram_) @@ -633,7 +697,7 @@ MetricsRegistry::recordJobQueued( [[maybe_unused]] std::string_view jobName) { #ifdef XRPL_ENABLE_TELEMETRY - if (!enabled_ || !jobQueuedCounter_) + if (!recording() || !jobQueuedCounter_) return; jobQueuedCounter_->Add( 1, @@ -649,7 +713,7 @@ MetricsRegistry::recordJobStarted( [[maybe_unused]] std::int64_t queuedDurUs) { #ifdef XRPL_ENABLE_TELEMETRY - if (!enabled_ || !jobStartedCounter_) + if (!recording() || !jobStartedCounter_) return; // Build the attribute pair once: both the counter and the histogram // must carry the identical label set or they cannot be joined. @@ -676,7 +740,7 @@ MetricsRegistry::recordJobFinished( [[maybe_unused]] std::int64_t runningDurUs) { #ifdef XRPL_ENABLE_TELEMETRY - if (!enabled_ || !jobFinishedCounter_) + if (!recording() || !jobFinishedCounter_) return; std::string const handler(sanitiseHandler(jobName)); jobFinishedCounter_->Add( @@ -2459,7 +2523,7 @@ void MetricsRegistry::incrementLedgersClosed() { #ifdef XRPL_ENABLE_TELEMETRY - if (enabled_ && ledgersClosedCounter_) + if (recording() && ledgersClosedCounter_) ledgersClosedCounter_->Add(1); #endif } @@ -2468,7 +2532,7 @@ void MetricsRegistry::incrementValidationsSent() { #ifdef XRPL_ENABLE_TELEMETRY - if (enabled_ && validationsSentCounter_) + if (recording() && validationsSentCounter_) validationsSentCounter_->Add(1); #endif } @@ -2477,7 +2541,7 @@ void MetricsRegistry::incrementValidationsChecked() { #ifdef XRPL_ENABLE_TELEMETRY - if (enabled_ && validationsCheckedCounter_) + if (recording() && validationsCheckedCounter_) validationsCheckedCounter_->Add(1); #endif } @@ -2486,7 +2550,7 @@ void MetricsRegistry::incrementLedgerHistoryMismatch(std::string_view reason) { #ifdef XRPL_ENABLE_TELEMETRY - if (enabled_ && ledgerHistoryMismatchCounter_) + if (recording() && ledgerHistoryMismatchCounter_) ledgerHistoryMismatchCounter_->Add(1, {{"reason", std::string(reason)}}); #endif } @@ -2495,7 +2559,7 @@ void MetricsRegistry::incrementTxqExpired() { #ifdef XRPL_ENABLE_TELEMETRY - if (enabled_ && txqExpiredCounter_) + if (recording() && txqExpiredCounter_) txqExpiredCounter_->Add(1); #endif } @@ -2504,7 +2568,7 @@ void MetricsRegistry::incrementTxqDropped(std::string_view reason) { #ifdef XRPL_ENABLE_TELEMETRY - if (enabled_ && txqDroppedCounter_) + if (recording() && txqDroppedCounter_) txqDroppedCounter_->Add(1, {{"reason", std::string(reason)}}); #endif } diff --git a/src/xrpld/telemetry/MetricsRegistry.h b/src/xrpld/telemetry/MetricsRegistry.h index 4189576e8c..fb1641ca06 100644 --- a/src/xrpld/telemetry/MetricsRegistry.h +++ b/src/xrpld/telemetry/MetricsRegistry.h @@ -104,17 +104,16 @@ * Example usage: * * @code - * // 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); - * // The endpoint, the TLS settings and the resource identity come from - * // [telemetry] and [network_id], read directly in Application::setup() - * // rather than through Telemetry::Setup. - * metricsRegistry_->start(startOptions); + * // In ApplicationImp's member-init list, right after telemetry_ and before + * // every subsystem. The constructor builds the pipeline and every + * // synchronous instrument, so no producer can exist before they do. The + * // endpoint, the TLS settings and the resource identity come from + * // [telemetry] and [network_id], read by Application.cpp rather than + * // through Telemetry::Setup. + * metricsRegistry_(std::make_unique( + * telemetry_->isEnabled(), *this, journal, options)) * - * // Later in setup(), once overlay_ exists (the last of the services the + * // Later, in setup(), once overlay_ exists (the last of the services the * // callbacks read). Phase 2 registers the observable instruments: * metricsRegistry_->startAsyncGauges(); * @@ -134,13 +133,16 @@ * if (auto* mr = app_.getMetricsRegistry()) * mr->recordJobQueued("ledgerData", "ProcessLData"); * - * // Shutdown: + * // Shutdown, before any service the callbacks read is stopped. Idempotent, + * // so run() and ~ApplicationImp both call it: * metricsRegistry_->stop(); * @endcode * * Caveats: * - The MetricsRegistry must be created AFTER the Telemetry object because - * it reads isEnabled() to decide whether to initialize the OTel SDK. + * it reads isEnabled() to decide whether to initialize the OTel SDK, and + * BEFORE every subsystem that records a metric. Declaration order in + * ApplicationImp is the guarantee; keep the member where it is. * - Observable gauge callbacks capture a reference to the Application; the * Application must outlive the MetricsRegistry (guaranteed because * MetricsRegistry is stopped before Application teardown). @@ -238,15 +240,19 @@ namespace telemetry { * catch-all try block so a transient failure never crashes * the reader thread. * - ValidationTracker protects its rolling windows internally. - * - start(), startAsyncGauges() and stop() are NOT thread-safe + * - The constructor, 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()). - * - Must be stopped BEFORE Application services it observes are - * destroyed; the Application owns it via unique_ptr so normal - * teardown guarantees this. + * @note Lifetime, in three phases (see Phase): + * - Ready: the constructor built the pipeline and the synchronous + * instruments. Runs in ApplicationImp's member-init list, so it precedes + * every subsystem that could record. + * - GaugesArmed: startAsyncGauges() registered the observable callbacks. + * Runs once overlay_ exists, the last service those callbacks read. + * - Stopped: stop() joined the reader thread. Runs before any observed + * service stops, from run() and again from ~ApplicationImp for the + * paths that never reach run(). * * @note Extending: * - Adding a new CountedObject type is auto-picked up by the @@ -273,61 +279,42 @@ class MetricsRegistry { public: /** - * Construct a MetricsRegistry. - * - * @param enabled Whether OTel metric export is active. When false, - * all methods become no-ops. - * @param app Reference to the ServiceRegistry (Application) for - * reading current metric values in gauge callbacks. - * @param journal Journal for log output. - */ - MetricsRegistry(bool enabled, ServiceRegistry& app, beast::Journal journal); - - ~MetricsRegistry(); - - /** - * Non-copyable, non-movable. - */ - MetricsRegistry(MetricsRegistry const&) = delete; - MetricsRegistry& - operator=(MetricsRegistry const&) = delete; - - /** - * Everything `start()` needs from config: where to export, how to secure - * the connection, and the process identity stamped on the OTel resource. + * Everything the constructor needs from config: where to export, how to + * secure the connection, and the process identity stamped on the OTel + * resource. * * The values come from the `[telemetry]` section plus `[network_id]`, read - * in `ApplicationImp::startTelemetry()`. They must match what - * `makeTelemetrySetup()` gives the trace pipeline, or one node reports two - * identities and a dashboard filter shows half its series. + * by `makeMetricsRegistryOptions()` in `Application.cpp`. They must match + * what `makeTelemetrySetup()` gives the trace pipeline, or one node reports + * two identities and a dashboard filter shows half its series. * * A struct rather than ten positional parameters: seven of them are * strings, so a swapped pair would compile and silently stamp the wrong * label. Designated initializers name every value at the call site. * * @code - * MetricsRegistry::StartOptions opts{ + * MetricsRegistry::Options opts{ * .endpoint = "http://localhost:4318/v1/metrics", * .serviceName = "xrpld", * .serviceVersion = build_info::getVersionString(), * .serviceInstanceId = nodePublicKey, * .nodeId = nodePublicKey, * .networkId = 2}; - * registry.start(opts); + * MetricsRegistry registry(enabled, app, journal, opts); * * // Edge case: mutual TLS to a collector that requires it. * opts.useTls = true; * opts.tlsCaCertPath = "/etc/xrpld/otel-ca.pem"; * opts.tlsClientCertPath = "/etc/xrpld/node.pem"; * opts.tlsClientKeyPath = "/etc/xrpld/node.key"; - * registry.start(opts); + * MetricsRegistry secure(enabled, app, journal, opts); * @endcode * * @note Plain aggregate, no invariants enforced. `networkType` is not a - * field: it is derived from @ref networkId inside `start()` so the - * two can never disagree. + * field: it is derived from @ref networkId inside the constructor so + * the two can never disagree. */ - struct StartOptions + struct Options { /** * OTLP/HTTP endpoint URL for metric export, from @@ -393,17 +380,17 @@ public: }; /** - * Initialize the OTel metrics pipeline and create the SYNCHRONOUS - * instruments (counters and histograms). + * Construct the registry and, when enabled, build the whole metrics + * pipeline: OTLP exporter, periodic reader, MeterProvider and every + * SYNCHRONOUS instrument (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. + * Doing this in the constructor is what fixes the init order. The + * Application declares its registry before every subsystem, so no + * producer can exist before the instruments do. A failure to build the + * pipeline is logged and leaves the registry a no-op; it never stops the + * node. * - * @note Invariant for future changes: this phase may create only + * @note Invariant for future changes: the constructor 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 @@ -412,34 +399,51 @@ public: * that callback against a half-built Application. This applies * to observable COUNTERS as well as gauges. * + * @param enabled False makes every method a no-op (telemetry disabled). + * @param app Services the observable-gauge callbacks read. + * @param journal Log output. * @param options Endpoint, TLS settings and resource identity, all read - * from config by the caller. See @ref StartOptions. + * from config by the caller. See @ref Options. */ - void - start(StartOptions const& options); + MetricsRegistry( + bool enabled, + ServiceRegistry& app, + beast::Journal journal, + Options const& options); + + /** + * Stops the pipeline if run() or ~ApplicationImp did not already. + */ + ~MetricsRegistry(); + + /** + * Non-copyable, non-movable. + */ + MetricsRegistry(MetricsRegistry const&) = delete; + MetricsRegistry& + operator=(MetricsRegistry const&) = delete; /** * Register the pull-model observable instruments — the second startup * phase. Mostly ObservableGauges, plus the ObservableCounters whose * source value is already cumulative. * - * A separate entry point 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 separation is about ordering - * and not just tidiness. + * A separate entry point from the constructor because the two halves have + * different prerequisites. The constructor 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 separation is about + * ordering and not just tidiness. + * + * Calling it twice, or after stop(), logs a warning and does nothing. * - * @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: + * Overlay is built last, so it 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 @@ -476,6 +480,11 @@ public: /** * Flush pending metrics and shut down the pipeline. * + * Stores `Phase::Stopped` first so `recording()` reads false on every + * later record call, then destroys the SDK provider. meter_ is not + * touched: record threads may still be running, and the gate is what + * keeps them off the dying pipeline. Idempotent. + * * @pre `detachCallbacks()` should have been called earlier in the * shutdown sequence; otherwise there is a narrow race between * the final reader-thread tick and the destruction of @@ -493,6 +502,28 @@ public: return enabled_; } + /** + * @return true when a record call is safe to run. + * + * False when the registry is disabled, or after stop() has torn down the + * export pipeline. After stop() the SDK's SyncMetricStorage still holds a + * raw pointer to an AggregationConfig owned by a destroyed View, so a + * record with a first-seen attribute set would fire the factory lambda + * and deref that dangling pointer. Every XRPL_METRIC_* macro reads this + * once before touching an instrument. + * + * One acquire atomic load in the hot path. + */ + [[nodiscard]] bool + recording() const noexcept + { +#ifdef XRPL_ENABLE_TELEMETRY + return enabled_ && phase_.load(std::memory_order_acquire) != Phase::Stopped; +#else + return enabled_; +#endif + } + // ----------------------------------------------------------------- // Synchronous instrument recording (called from PerfLog hot paths) // ----------------------------------------------------------------- @@ -854,9 +885,15 @@ public: * Access the shared OTel Meter for call-site instrument creation. * Used by the XRPL_METRIC_* macros (MetricMacros.h) so new synchronous * counters/histograms can be declared at their call site instead of as - * MetricsRegistry members. Returns an empty (falsy) shared_ptr before - * start() has run or when disabled. - * @return The shared Meter, or empty if not yet started. + * MetricsRegistry members. + * + * Invariant: never empty while recording() is true. The constructor sets + * it to the real meter, or to a no-op meter when the pipeline failed to + * build, and never writes it again, so reads need no lock. After stop() + * the meter's SDK context is gone; the macros gate on recording() first, + * so no caller reaches it then. + * + * @return The shared Meter. */ [[nodiscard]] opentelemetry::nostd::shared_ptr meter() const noexcept @@ -972,6 +1009,23 @@ private: */ beast::Journal const journal_; + /** + * Where the registry is in its life. Construction ends in `Ready`; + * startAsyncGauges() moves to `GaugesArmed`; stop() to `Stopped`. A call + * that does not fit the current phase logs a warning and does nothing. + * + * After `Stopped` the SDK pipeline is gone. recording() reads false, so + * no macro touches meter_ or a cached instrument. + */ + enum class Phase { Ready, GaugesArmed, Stopped }; + + /** + * Current phase. Written from the Application lifecycle thread with + * release ordering; read from record threads via `recording()` with + * acquire ordering, so no record starts once stop() has stored `Stopped`. + */ + std::atomic phase_{Phase::Ready}; + /** * Set by detachCallbacks() during shutdown so every ObservableGauge * callback returns early before reading Application services that @@ -1256,29 +1310,39 @@ private: /** * Build the OTLP/HTTP exporter, periodic reader, resource attributes and * histogram views, then create the MeterProvider and meter. Extracted - * from start() to keep each function under the 80-line limit. + * from the constructor to keep each function under the 80-line limit. * * @param options Endpoint, TLS settings and resource identity, forwarded - * unchanged from `start()`. See @ref StartOptions. + * unchanged from the constructor. See @ref Options. */ void - initExporterAndProvider(StartOptions const& options); + initExporterAndProvider(Options const& options); /** * Create the synchronous instruments (RPC and job-queue counters and * histograms, plus the external dashboard parity counters). Extracted - * from start() to keep each function under the 80-line limit. + * from the constructor to keep each function under the 80-line limit. */ void initSyncInstruments(); + /** + * Give up the pipeline after a build failure: drop the provider, hand + * out a no-op meter so every call site still gets an instrument, and log + * why. The registry stays enabled and inert for the process. + * + * @param reason What failed, for the log line. + */ + void + disablePipeline(std::string_view reason); + /** * 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. + * Called only from `startAsyncGauges()`, which owns the enabled_, + * phase_ and provider_ guards and the Application-state precondition. */ void registerAsyncGauges();