mirror of
https://github.com/XRPLF/rippled.git
synced 2026-08-21 22:30:57 +00:00
fix(telemetry): correct integration-test span checks and telemetry docs
The integration test's span assertions never actually ran. check_span() built a Tempo /api/search call with --data-urlencode but no -G, so curl POSTed the params as a body; Tempo answers 200 and ignores the query, so every span name looked present. Verified against a live Tempo 2.9.4: the buggy form returns the store's total trace count for any name, including "zzz.does.not.exist"; with -G a real name returns 1 and a bogus one 0. Fixed alongside it: the RPC check asserted "rpc.request", which is never emitted (ServerHandler.cpp builds "rpc.http_request"). These two had to change together, since -G turns the bogus name from a silent pass into a hard failure. Also in the script: a consensus timeout logged two failures and counted two, because a post-loop else re-reported what the timeout branch had already reported; and three unguarded curl calls aborted the whole script under set -euo pipefail, making the ACCOUNT_ZERO fallback dead code with no cleanup. Guarded the curls and wired an EXIT trap to the existing cleanup(). The trap deliberately fires only before the summary, so a completed run still leaves the stack up as the header documents. Docs corrections, all re-derived from code: - span inventory heading 35 -> 38, attribute heading 83 -> 89 rows (78 unique keys), and the section 6 header table now carries the missing TxApplySpanNames.h row so its columns sum to the same figures - two stale paths: ConsensusSpanNames.h is under include/xrpl/consensus/, TxSpanNames.h under src/xrpld/telemetry/ - consensus_round_id is int64, not string (RCLConsensus.cpp sets prevLgr.seq() + 1); the runbook's TraceQL examples now use a numeric literal instead of an unparseable bare <round_id> - state-accounting duration gauges are cumulative MICROSECONDS, not seconds (NetworkOPs.cpp declares std::chrono::microseconds and publishes dur.count() raw) - sampling_ratio is not a config key; head sampling is fixed at 1.0 and the shipped collector has no tail sampling, so the caveat was rewritten - the plan blurb referenced Jaeger; this stack is Tempo
This commit is contained in:
@@ -84,7 +84,7 @@ always goes through `beast::insight` instead.
|
||||
|
||||
## 1. OpenTelemetry Spans
|
||||
|
||||
### 1.1 Complete Span Inventory (35 spans)
|
||||
### 1.1 Complete Span Inventory (38 spans)
|
||||
|
||||
> **See also**: [02-design-decisions.md §2.3](./02-design-decisions.md#23-span-naming-conventions) for naming conventions and the full span catalog with rationale. [04-code-samples.md §4.6](./04-code-samples.md#46-span-flow-visualization) for span flow diagrams.
|
||||
|
||||
@@ -254,12 +254,14 @@ under an unrelated transaction's trace.
|
||||
|
||||
---
|
||||
|
||||
### 1.2 Complete Attribute Inventory (83 attributes)
|
||||
### 1.2 Complete Attribute Inventory (89 attribute rows, 78 unique keys)
|
||||
|
||||
> **See also**: [02-design-decisions.md §2.4.2](./02-design-decisions.md#242-span-attributes-by-category) for attribute design rationale and privacy considerations.
|
||||
|
||||
Every span can carry key-value attributes that provide context for filtering and aggregation.
|
||||
|
||||
The tables below list one row per attribute per subsystem, so a key shared by two subsystems (for example `ledger_seq`) appears once in each. That is 89 rows over 78 distinct keys. The §6 per-header counts use the same row-based rule, so they sum to 89.
|
||||
|
||||
#### RPC Attributes
|
||||
|
||||
| Attribute | Type | Set On | Description |
|
||||
@@ -374,7 +376,7 @@ Join a transaction's work to its ledger with `{span.current_ledger_seq=<N>}`.
|
||||
| `quorum` | int64 | `consensus.check` | Required quorum for validation |
|
||||
| `validation_count` | int64 | `consensus.check` | Number of validations received |
|
||||
| `trace_strategy` | string | `consensus.round` | Trace sampling strategy used for this round |
|
||||
| `consensus_round_id` | string | `consensus.round` | Deterministic round identifier |
|
||||
| `consensus_round_id` | int64 | `consensus.round` | Deterministic round identifier (previous ledger seq + 1) |
|
||||
| `mode_old` | string | `consensus.mode_change` | Previous consensus mode |
|
||||
| `mode_new` | string | `consensus.mode_change` | New consensus mode |
|
||||
| `tx_id` | string | `consensus.update_positions` | Disputed transaction ID |
|
||||
@@ -474,26 +476,26 @@ prefix=xrpld
|
||||
|
||||
### 2.1 Gauges
|
||||
|
||||
| Prometheus Metric | Source File | Description | Typical Range |
|
||||
| ------------------------------------------------- | --------------------- | ---------------------------------------- | ------------------------------- |
|
||||
| `xrpld_LedgerMaster_Validated_Ledger_Age` | LedgerMaster.h | Seconds since last validated ledger | 0–10 (healthy), >30 (stale) |
|
||||
| `xrpld_LedgerMaster_Published_Ledger_Age` | LedgerMaster.h | Seconds since last published ledger | 0–10 (healthy) |
|
||||
| `xrpld_State_Accounting_Disconnected_duration` | NetworkOPs.cpp | Cumulative seconds in Disconnected state | Monotonic |
|
||||
| `xrpld_State_Accounting_Connected_duration` | NetworkOPs.cpp | Cumulative seconds in Connected state | Monotonic |
|
||||
| `xrpld_State_Accounting_Syncing_duration` | NetworkOPs.cpp | Cumulative seconds in Syncing state | Monotonic |
|
||||
| `xrpld_State_Accounting_Tracking_duration` | NetworkOPs.cpp | Cumulative seconds in Tracking state | Monotonic |
|
||||
| `xrpld_State_Accounting_Full_duration` | NetworkOPs.cpp | Cumulative seconds in Full state | Monotonic (should dominate) |
|
||||
| `xrpld_State_Accounting_Disconnected_transitions` | NetworkOPs.cpp | Count of transitions to Disconnected | Low |
|
||||
| `xrpld_State_Accounting_Connected_transitions` | NetworkOPs.cpp | Count of transitions to Connected | Low |
|
||||
| `xrpld_State_Accounting_Syncing_transitions` | NetworkOPs.cpp | Count of transitions to Syncing | Low |
|
||||
| `xrpld_State_Accounting_Tracking_transitions` | NetworkOPs.cpp | Count of transitions to Tracking | Low |
|
||||
| `xrpld_State_Accounting_Full_transitions` | NetworkOPs.cpp | Count of transitions to Full | Low (should be 1 after startup) |
|
||||
| `xrpld_Peer_Finder_Active_Inbound_Peers` | PeerfinderManager.cpp | Active inbound peer connections | 0–85 |
|
||||
| `xrpld_Peer_Finder_Active_Outbound_Peers` | PeerfinderManager.cpp | Active outbound peer connections | 10–21 |
|
||||
| `xrpld_Overlay_Peer_Disconnects` | OverlayImpl.cpp | Cumulative peer disconnection count | Low growth |
|
||||
| `xrpld_jobq_job_count` | JobQueue.cpp | Current job queue depth (all types) | 0–100 (healthy) |
|
||||
| `xrpld_Node_family_full_below_cache_size` | TaggedCache.h | FullBelowCache entry count | Varies |
|
||||
| `xrpld_Node_family_full_below_cache_hit_rate` | TaggedCache.h | FullBelowCache hit rate percentage | 0–100 |
|
||||
| Prometheus Metric | Source File | Description | Typical Range |
|
||||
| ------------------------------------------------- | --------------------- | --------------------------------------------- | ------------------------------- |
|
||||
| `xrpld_LedgerMaster_Validated_Ledger_Age` | LedgerMaster.h | Seconds since last validated ledger | 0–10 (healthy), >30 (stale) |
|
||||
| `xrpld_LedgerMaster_Published_Ledger_Age` | LedgerMaster.h | Seconds since last published ledger | 0–10 (healthy) |
|
||||
| `xrpld_State_Accounting_Disconnected_duration` | NetworkOPs.cpp | Cumulative microseconds in Disconnected state | Monotonic |
|
||||
| `xrpld_State_Accounting_Connected_duration` | NetworkOPs.cpp | Cumulative microseconds in Connected state | Monotonic |
|
||||
| `xrpld_State_Accounting_Syncing_duration` | NetworkOPs.cpp | Cumulative microseconds in Syncing state | Monotonic |
|
||||
| `xrpld_State_Accounting_Tracking_duration` | NetworkOPs.cpp | Cumulative microseconds in Tracking state | Monotonic |
|
||||
| `xrpld_State_Accounting_Full_duration` | NetworkOPs.cpp | Cumulative microseconds in Full state | Monotonic (should dominate) |
|
||||
| `xrpld_State_Accounting_Disconnected_transitions` | NetworkOPs.cpp | Count of transitions to Disconnected | Low |
|
||||
| `xrpld_State_Accounting_Connected_transitions` | NetworkOPs.cpp | Count of transitions to Connected | Low |
|
||||
| `xrpld_State_Accounting_Syncing_transitions` | NetworkOPs.cpp | Count of transitions to Syncing | Low |
|
||||
| `xrpld_State_Accounting_Tracking_transitions` | NetworkOPs.cpp | Count of transitions to Tracking | Low |
|
||||
| `xrpld_State_Accounting_Full_transitions` | NetworkOPs.cpp | Count of transitions to Full | Low (should be 1 after startup) |
|
||||
| `xrpld_Peer_Finder_Active_Inbound_Peers` | PeerfinderManager.cpp | Active inbound peer connections | 0–85 |
|
||||
| `xrpld_Peer_Finder_Active_Outbound_Peers` | PeerfinderManager.cpp | Active outbound peer connections | 10–21 |
|
||||
| `xrpld_Overlay_Peer_Disconnects` | OverlayImpl.cpp | Cumulative peer disconnection count | Low growth |
|
||||
| `xrpld_jobq_job_count` | JobQueue.cpp | Current job queue depth (all types) | 0–100 (healthy) |
|
||||
| `xrpld_Node_family_full_below_cache_size` | TaggedCache.h | FullBelowCache entry count | Varies |
|
||||
| `xrpld_Node_family_full_below_cache_hit_rate` | TaggedCache.h | FullBelowCache hit rate percentage | 0–100 |
|
||||
|
||||
**Grafana dashboard**: _Node Health (StatsD)_ (`xrpld-statsd-node-health`)
|
||||
|
||||
@@ -894,12 +896,15 @@ All span names and attributes are defined as compile-time constants in colocated
|
||||
| `src/xrpld/rpc/detail/RpcSpanNames.h` | RPC (HTTP/WS) | 5 | 5 | Includes `rpc.ws_upgrade` error path |
|
||||
| `src/xrpld/rpc/detail/PathFindSpanNames.h` | PathFind | 5 | 8 | Covers one-shot and subscription paths |
|
||||
| `src/xrpld/app/main/GrpcSpanNames.h` | gRPC | 1 | 3 | Flat single-span structure per request |
|
||||
| `src/xrpld/app/misc/TxSpanNames.h` | Transaction | 2 | 7 | Includes peer context attributes |
|
||||
| `src/xrpld/app/misc/detail/TxQSpanNames.h` | TxQ | 6 | 11 | Queue lifecycle: enqueue through cleanup |
|
||||
| `src/xrpld/app/consensus/ConsensusSpanNames.h` | Consensus | 10 | 35 | Deterministic trace IDs, close-time details |
|
||||
| `src/xrpld/telemetry/TxSpanNames.h` | Transaction | 2 | 7 | Includes peer context attributes |
|
||||
| `include/xrpl/tx/detail/TxApplySpanNames.h` | Tx Apply | 3 | 6 | Apply pipeline: preflight, preclaim, apply |
|
||||
| `src/xrpld/app/misc/detail/TxQSpanNames.h` | TxQ | 6 | 13 | Queue lifecycle: enqueue through cleanup |
|
||||
| `include/xrpl/consensus/ConsensusSpanNames.h` | Consensus | 10 | 35 | Deterministic trace IDs, close-time details |
|
||||
| `src/xrpld/app/ledger/detail/LedgerSpanNames.h` | Ledger | 4 | 7 | Build, store, validate, tx.apply |
|
||||
| `src/xrpld/overlay/detail/PeerSpanNames.h` | Peer Overlay | 2 | 5 | Proposal and validation receive |
|
||||
|
||||
Column totals: **38 spans** and **89 attribute rows**, matching §1.1 and §1.2. `tx.apply` is counted under `LedgerSpanNames.h`, which defines it; §1.1 lists it with the transaction spans.
|
||||
|
||||
> **Design convention**: SpanNames headers are colocated with their subsystem classes rather than centralized in `telemetry/`. See [memory/feedback_span-names-colocation.md](../.claude/memory/feedback_span-names-colocation.md) for rationale.
|
||||
|
||||
---
|
||||
|
||||
@@ -206,7 +206,7 @@ The appendix contains a glossary of OpenTelemetry and xrpld-specific terms, refe
|
||||
|
||||
## 9. Data Collection Reference
|
||||
|
||||
A single-source-of-truth reference documenting every piece of telemetry data collected by xrpld. Covers all 16 OpenTelemetry spans with their 22 attributes, all StatsD metrics (gauges, counters, histograms, overlay traffic), SpanMetrics-derived Prometheus metrics, and all 10 Grafana dashboards. Includes Jaeger search guides and Prometheus query examples.
|
||||
A single-source-of-truth reference documenting every piece of telemetry data collected by xrpld. Covers all 38 OpenTelemetry spans with their 89 attribute rows (78 unique keys), all StatsD metrics (gauges, counters, histograms, overlay traffic), SpanMetrics-derived Prometheus metrics, and all 10 Grafana dashboards. Includes Tempo trace search guides and Prometheus query examples.
|
||||
|
||||
➡️ **[View Data Collection Reference](./09-data-collection-reference.md)**
|
||||
|
||||
|
||||
@@ -62,7 +62,10 @@ die() {
|
||||
check_span() {
|
||||
local op="$1"
|
||||
local count
|
||||
count=$(curl -sf "$TEMPO/api/search" \
|
||||
# -G is required: it moves the urlencoded params into the query string.
|
||||
# Without it curl POSTs them as a request body, and Tempo answers 200
|
||||
# while ignoring the query — so every span name would look present.
|
||||
count=$(curl -sfG "$TEMPO/api/search" \
|
||||
--data-urlencode "q={resource.service.name=\"xrpld\" && name=\"$op\"}" \
|
||||
--data-urlencode "limit=5" |
|
||||
jq '.traces | length' 2>/dev/null || echo 0)
|
||||
@@ -133,6 +136,23 @@ mkdir -p "$WORKDIR"
|
||||
# ---------------------------------------------------------------------------
|
||||
# Step 2: Start observability stack
|
||||
# ---------------------------------------------------------------------------
|
||||
|
||||
# From here on the script owns the docker stack and the xrpld nodes, so an
|
||||
# abort must tear them down instead of leaving them behind. A run that
|
||||
# reaches the summary deliberately leaves everything up for inspection
|
||||
# (see the header comment), so the trap only fires before that point.
|
||||
RUN_COMPLETED=0
|
||||
on_exit() {
|
||||
local status=$?
|
||||
if [ "$RUN_COMPLETED" -eq 0 ]; then
|
||||
log "Aborted with exit status $status — tearing down."
|
||||
cleanup
|
||||
fi
|
||||
}
|
||||
trap on_exit EXIT
|
||||
trap 'exit 130' INT
|
||||
trap 'exit 143' TERM
|
||||
|
||||
log "Starting observability stack..."
|
||||
docker compose -f "$COMPOSE_FILE" up -d
|
||||
|
||||
@@ -358,12 +378,14 @@ log "Waiting for nodes to reach 'proposing' state (timeout: ${CONSENSUS_TIMEOUT}
|
||||
|
||||
start_time=$(date +%s)
|
||||
nodes_ready=0
|
||||
consensus_timed_out=0
|
||||
|
||||
while [ "$nodes_ready" -lt "$NUM_NODES" ]; do
|
||||
elapsed=$(($(date +%s) - start_time))
|
||||
if [ "$elapsed" -ge "$CONSENSUS_TIMEOUT" ]; then
|
||||
fail "Consensus timeout after ${CONSENSUS_TIMEOUT}s ($nodes_ready/$NUM_NODES nodes ready)"
|
||||
log "Continuing with partial consensus..."
|
||||
consensus_timed_out=1
|
||||
break
|
||||
fi
|
||||
|
||||
@@ -386,7 +408,10 @@ echo ""
|
||||
|
||||
if [ "$nodes_ready" -eq "$NUM_NODES" ]; then
|
||||
ok "All $NUM_NODES nodes reached 'proposing' state"
|
||||
else
|
||||
elif [ "$consensus_timed_out" -eq 0 ]; then
|
||||
# The timeout branch above already called fail(), so reporting again here
|
||||
# would count one timeout twice. Only reachable if the loop ever gains
|
||||
# another early exit.
|
||||
fail "Only $nodes_ready/$NUM_NODES nodes reached 'proposing' state"
|
||||
fi
|
||||
|
||||
@@ -430,9 +455,11 @@ log "Submitting Payment transaction..."
|
||||
|
||||
# Generate a destination wallet
|
||||
log " Generating destination wallet..."
|
||||
# Guarded: under set -e an unguarded curl failure would abort the whole
|
||||
# script, so the fallback below could never run.
|
||||
wallet_result=$(curl -sf "http://localhost:$RPC_PORT_BASE" \
|
||||
-d '{"method":"wallet_propose"}')
|
||||
DEST_ACCOUNT=$(echo "$wallet_result" | jq -r '.result.account_id' 2>/dev/null)
|
||||
-d '{"method":"wallet_propose"}') || wallet_result=""
|
||||
DEST_ACCOUNT=$(echo "$wallet_result" | jq -r '.result.account_id' 2>/dev/null || echo "")
|
||||
if [ -z "$DEST_ACCOUNT" ] || [ "$DEST_ACCOUNT" = "null" ]; then
|
||||
fail "Could not generate destination wallet"
|
||||
DEST_ACCOUNT="rrrrrrrrrrrrrrrrrrrrrhoLvTp" # ACCOUNT_ZERO fallback
|
||||
@@ -441,13 +468,13 @@ log " Destination: $DEST_ACCOUNT"
|
||||
|
||||
# Get genesis account info
|
||||
acct_result=$(curl -sf "http://localhost:$RPC_PORT_BASE" \
|
||||
-d "{\"method\":\"account_info\",\"params\":[{\"account\":\"$GENESIS_ACCOUNT\"}]}")
|
||||
-d "{\"method\":\"account_info\",\"params\":[{\"account\":\"$GENESIS_ACCOUNT\"}]}") || acct_result=""
|
||||
seq_num=$(echo "$acct_result" | jq -r '.result.account_data.Sequence' 2>/dev/null || echo "unknown")
|
||||
log " Genesis account sequence: $seq_num"
|
||||
|
||||
# Submit payment
|
||||
submit_result=$(curl -sf "http://localhost:$RPC_PORT_BASE" \
|
||||
-d "{\"method\":\"submit\",\"params\":[{\"secret\":\"$GENESIS_SEED\",\"tx_json\":{\"TransactionType\":\"Payment\",\"Account\":\"$GENESIS_ACCOUNT\",\"Destination\":\"$DEST_ACCOUNT\",\"Amount\":\"10000000\"}}]}")
|
||||
-d "{\"method\":\"submit\",\"params\":[{\"secret\":\"$GENESIS_SEED\",\"tx_json\":{\"TransactionType\":\"Payment\",\"Account\":\"$GENESIS_ACCOUNT\",\"Destination\":\"$DEST_ACCOUNT\",\"Amount\":\"10000000\"}}]}") || submit_result=""
|
||||
|
||||
engine_result=$(echo "$submit_result" | jq -r '.result.engine_result' 2>/dev/null || echo "unknown")
|
||||
tx_hash=$(echo "$submit_result" | jq -r '.result.tx_json.hash' 2>/dev/null || echo "unknown")
|
||||
@@ -478,7 +505,7 @@ fi
|
||||
|
||||
log ""
|
||||
log "--- RPC Spans ---"
|
||||
check_span "rpc.request"
|
||||
check_span "rpc.http_request"
|
||||
check_span "rpc.process"
|
||||
check_span "rpc.command.server_info"
|
||||
check_span "rpc.command.server_state"
|
||||
@@ -580,6 +607,11 @@ check_statsd_metric "rippled_total_Bytes_In"
|
||||
# ---------------------------------------------------------------------------
|
||||
# Step 11: Summary
|
||||
# ---------------------------------------------------------------------------
|
||||
|
||||
# All checks are done, so the run counts as complete: keep the stack and the
|
||||
# nodes up for inspection even when some checks failed.
|
||||
RUN_COMPLETED=1
|
||||
|
||||
echo ""
|
||||
echo "==========================================================="
|
||||
echo " INTEGRATION TEST RESULTS"
|
||||
|
||||
@@ -160,8 +160,9 @@ hash); `tx.preflight` is stateless and omits both.
|
||||
# Find specific ledger's consensus details
|
||||
{name="consensus.accept.apply"} | ledger_seq = 92345678
|
||||
|
||||
# Find all spans in a consensus round (deterministic trace strategy)
|
||||
{name="consensus.round"} | consensus_round_id = <round_id>
|
||||
# Find all spans in a consensus round (deterministic trace strategy).
|
||||
# consensus_round_id is an int64 — the previous ledger sequence plus one.
|
||||
{name="consensus.round"} | consensus_round_id = 92345679
|
||||
|
||||
# Find dispute resolutions
|
||||
{name="consensus.update_positions"} >> {event:name="dispute.resolve"}
|
||||
@@ -249,10 +250,14 @@ sum by (stage) (rate(traces_span_metrics_calls_total{span_name=~"tx.preflight|tx
|
||||
> a rising `tx.transactor` failure rate points to apply-time problems. Alert per
|
||||
> stage rather than on a single aggregate so the failing stage is obvious.
|
||||
|
||||
> **Sampling caveat**: these stage metrics are span-derived and inherit the
|
||||
> **tracer head-sampling** ratio (`sampling_ratio`). At `sampling_ratio < 1.0`
|
||||
> they undercount proportionally — treat them as relative trends, not absolute
|
||||
> transaction counts. Native StatsD metrics are unsampled.
|
||||
> **Sampling caveat**: these stage metrics are span-derived, so they count only
|
||||
> the spans the collector's spanmetrics connector sees. Head sampling at the node
|
||||
> is fixed at 1.0 and is not configurable (`Telemetry.h`), and the shipped
|
||||
> collector pipeline has no tail sampling, so today nothing is dropped and the
|
||||
> counts are absolute. Volume reduction is delegated to the collector: adding a
|
||||
> tail-sampling processor to the traces pipeline puts it ahead of the spanmetrics
|
||||
> connector, and these metrics would then undercount proportionally — treat them
|
||||
> as relative trends in that case. Native StatsD metrics are never sampled.
|
||||
|
||||
### Transaction Queue Health
|
||||
|
||||
@@ -452,7 +457,7 @@ all its normal attributes, it just lacks a cross-node parent link.
|
||||
{name=~"tx\\..*"} | tx_hash = "<hash>"
|
||||
|
||||
# Find all spans in a cross-node consensus trace
|
||||
{rootServiceName="xrpld"} | consensus_round_id = <round_id>
|
||||
{rootServiceName="xrpld"} | consensus_round_id = 92345679
|
||||
|
||||
# Compare latency between sender and receiver for validations
|
||||
{name="consensus.validation.send" || name="consensus.validation.receive"}
|
||||
@@ -656,7 +661,7 @@ Ten dashboards are pre-provisioned in `docker/telemetry/grafana/dashboards/`:
|
||||
| RPC Latency p95 by Command | timeseries | `histogram_quantile(0.95, sum by (le, command) (rate(traces_span_metrics_duration_milliseconds_bucket{span_name=~"rpc.command.*"}[5m])))` | `command` |
|
||||
| RPC Error Rate | bargauge | Error spans / total spans × 100, grouped by `command` | `command`, `status_code` |
|
||||
| RPC Latency Heatmap | heatmap | `sum(increase(traces_span_metrics_duration_milliseconds_bucket{span_name=~"rpc.command.*"}[5m])) by (le)` | `le` (bucket boundaries) |
|
||||
| Overall RPC Throughput | timeseries | `rpc.request` + `rpc.process` rate | — |
|
||||
| Overall RPC Throughput | timeseries | `rpc.http_request` + `rpc.process` rate | — |
|
||||
| RPC Success vs Error | timeseries | by `status_code` (UNSET vs ERROR) | `status_code` |
|
||||
| Top Commands by Volume | bargauge | `topk(10, ...)` by `command` | `command` |
|
||||
| WebSocket Message Rate | stat | `rpc.ws_message` rate | — |
|
||||
|
||||
Reference in New Issue
Block a user