diff --git a/.github/scripts/levelization/generate.py b/.github/scripts/levelization/generate.py old mode 100644 new mode 100755 diff --git a/.github/scripts/levelization/results/loops.txt b/.github/scripts/levelization/results/loops.txt index 181cbec44a..66906f48c6 100644 --- a/.github/scripts/levelization/results/loops.txt +++ b/.github/scripts/levelization/results/loops.txt @@ -5,7 +5,7 @@ Loop: test.jtx test.unit_test test.unit_test ~= test.jtx Loop: xrpl.telemetry xrpld.rpc - xrpld.rpc ~= xrpl.telemetry + xrpld.rpc > xrpl.telemetry Loop: xrpld.app xrpld.overlay xrpld.app > xrpld.overlay @@ -19,6 +19,9 @@ Loop: xrpld.app xrpld.rpc Loop: xrpld.app xrpld.shamap xrpld.shamap > xrpld.app +Loop: xrpld.app xrpld.telemetry + xrpld.telemetry == xrpld.app + Loop: xrpld.overlay xrpld.rpc xrpld.rpc ~= xrpld.overlay diff --git a/.github/scripts/levelization/results/ordering.txt b/.github/scripts/levelization/results/ordering.txt index 62b51b4a4f..775645a53b 100644 --- a/.github/scripts/levelization/results/ordering.txt +++ b/.github/scripts/levelization/results/ordering.txt @@ -101,7 +101,6 @@ test.core > xrpl.server test.csf > xrpl.basics test.csf > xrpld.consensus test.csf > xrpl.json -test.csf > xrpl.telemetry test.csf > xrpl.ledger test.csf > xrpl.protocol test.json > test.jtx @@ -196,7 +195,6 @@ tests.libxrpl > xrpl.net tests.libxrpl > xrpl.protocol tests.libxrpl > xrpl.protocol_autogen tests.libxrpl > xrpl.telemetry -tests.libxrpl > xrpld.telemetry xrpl.conditions > xrpl.basics xrpl.conditions > xrpl.protocol xrpl.core > xrpl.basics @@ -240,7 +238,6 @@ xrpld.app > xrpl.basics xrpld.app > xrpl.core xrpld.app > xrpld.consensus xrpld.app > xrpld.core -xrpld.app > xrpld.telemetry xrpld.app > xrpl.json xrpld.app > xrpl.ledger xrpld.app > xrpl.net @@ -257,7 +254,6 @@ xrpld.consensus > xrpl.json xrpld.consensus > xrpl.ledger xrpld.consensus > xrpl.protocol xrpld.consensus > xrpl.telemetry -xrpld.consensus > xrpld.telemetry xrpld.core > xrpl.basics xrpld.core > xrpl.core xrpld.core > xrpl.net @@ -275,6 +271,7 @@ xrpld.overlay > xrpl.protocol xrpld.overlay > xrpl.resource xrpld.overlay > xrpl.server xrpld.overlay > xrpl.shamap +xrpld.overlay > xrpl.telemetry xrpld.overlay > xrpl.tx xrpld.peerfinder > xrpl.basics xrpld.peerfinder > xrpld.core @@ -302,3 +299,5 @@ xrpld.shamap > xrpl.basics xrpld.shamap > xrpld.core xrpld.shamap > xrpl.protocol xrpld.shamap > xrpl.shamap +xrpld.telemetry > xrpl.basics +xrpld.telemetry > xrpl.telemetry diff --git a/OpenTelemetryPlan/02-design-decisions.md b/OpenTelemetryPlan/02-design-decisions.md index 9b0ef51db6..5d68278629 100644 --- a/OpenTelemetryPlan/02-design-decisions.md +++ b/OpenTelemetryPlan/02-design-decisions.md @@ -251,8 +251,8 @@ resource::SemanticConventions::SERVICE_INSTANCE_ID = "xrpl.consensus.proposers_total" = int64 // Total peer positions "xrpl.consensus.agree_count" = int64 // Peers that agree (haveConsensus) "xrpl.consensus.disagree_count" = int64 // Peers that disagree -"xrpl.consensus.threshold_percent" = int64 // Current threshold (50/65/70/95) -"xrpl.consensus.result" = string // "yes", "no", "moved_on" +"xrpl.consensus.threshold_percent" = int64 // Close-time consensus threshold (avCT_CONSENSUS_PCT = 75%) +"xrpl.consensus.result" = string // "yes", "no", "moved_on", "expired" "xrpl.consensus.mode.old" = string // Previous consensus mode "xrpl.consensus.mode.new" = string // New consensus mode ``` diff --git a/OpenTelemetryPlan/06-implementation-phases.md b/OpenTelemetryPlan/06-implementation-phases.md index c12fb8c211..43945b4335 100644 --- a/OpenTelemetryPlan/06-implementation-phases.md +++ b/OpenTelemetryPlan/06-implementation-phases.md @@ -46,10 +46,8 @@ gantt Consensus Tracing :p4, after p3, 2w Consensus Round Spans :p4a, after p3, 3d Proposal Handling :p4b, after p4a, 3d - Validator List & Manifest Tracing :p4f, after p4b, 2d - Amendment Voting Tracing :p4g, after p4f, 2d - SHAMap Sync Tracing :p4h, after p4g, 2d - Validation Tests :p4c, after p4h, 4d + Establish Phase (4a) :p4f, after p4b, 3d + Validation Tests :p4c, after p4f, 4d Buffer & Review :p4e, after p4c, 4d section Phase 5 @@ -162,38 +160,44 @@ and [Phase3_taskList.md Task 3.9](./Phase3_taskList.md) for the full implementat ### Tasks -| Task | Description | -| ---- | ---------------------------------------------- | -| 4.1 | Instrument `RCLConsensusAdaptor::startRound()` | -| 4.2 | Instrument phase transitions | -| 4.3 | Instrument proposal handling | -| 4.4 | Instrument validation handling | -| 4.5 | Add consensus-specific attributes | -| 4.6 | Correlate with transaction traces | -| 4.7 | Validator list and manifest tracing | -| 4.8 | Amendment voting tracing | -| 4.9 | SHAMap sync tracing | -| 4.10 | Multi-validator integration tests | -| 4.11 | Performance validation | +| Task | Description | Status | +| ---- | ---------------------------------------------- | ------------------ | +| 4.1 | Instrument `RCLConsensusAdaptor::startRound()` | ✅ Done (via 4a.2) | +| 4.2 | Instrument phase transitions | ✅ Done | +| 4.3 | Instrument proposal handling | ✅ Done | +| 4.4 | Instrument validation handling | ✅ Done | +| 4.5 | Add consensus-specific attributes | ✅ Done | +| 4.6 | Correlate with transaction traces | ✅ Done | +| 4.7 | Build verification and testing | ✅ Done | +| 4.8 | Validation span enrichment (ext. dashboard) | ❌ Not done | + +**Note**: The original plan doc listed tasks 4.7-4.11 as "Validator list tracing", +"Amendment voting tracing", "SHAMap sync tracing", "Multi-validator integration tests", +and "Performance validation". These were descoped and replaced by the tasklist's 4.7 +(build verification) and 4.8 (validation span enrichment). Validator, amendment, and +SHAMap tracing are not implemented. ### Spans Produced | Span Name | Location | Attributes | | --------------------------- | ---------------------- | --------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | -| `consensus.proposal.send` | `RCLConsensus.cpp:177` | `xrpl.consensus.round` | -| `consensus.ledger_close` | `RCLConsensus.cpp:282` | `xrpl.consensus.ledger.seq`, `xrpl.consensus.mode` | -| `consensus.accept` | `RCLConsensus.cpp:395` | `xrpl.consensus.proposers`, `xrpl.consensus.round_time_ms` | -| `consensus.accept.apply` | `RCLConsensus.cpp:521` | `xrpl.consensus.close_time`, `close_time_correct`, `close_resolution_ms`, `state`, `proposing`, `round_time_ms`, `ledger.seq`, `parent_close_time`, `close_time_self`, `close_time_vote_bins`, `resolution_direction` | -| `consensus.validation.send` | `RCLConsensus.cpp:753` | `xrpl.consensus.proposing` | +| `consensus.phase.open` | `Consensus.h:707` | _(none)_ | +| `consensus.proposal.send` | `RCLConsensus.cpp:232` | `xrpl.consensus.round` | +| `consensus.ledger_close` | `RCLConsensus.cpp:341` | `xrpl.consensus.ledger.seq`, `xrpl.consensus.mode` | +| `consensus.accept` | `RCLConsensus.cpp:492` | `xrpl.consensus.proposers`, `xrpl.consensus.round_time_ms`, `xrpl.consensus.quorum` | +| `consensus.accept.apply` | `RCLConsensus.cpp:541` | `xrpl.consensus.close_time`, `close_time_correct`, `close_resolution_ms`, `state`, `proposing`, `round_time_ms`, `ledger.seq`, `parent_close_time`, `close_time_self`, `close_time_vote_bins`, `resolution_direction` | +| `consensus.validation.send` | `RCLConsensus.cpp:900` | `xrpl.consensus.ledger.seq`, `xrpl.consensus.proposing` | ### Exit Criteria - [x] Complete consensus round traces -- [x] Phase transitions visible -- [x] Proposals and validations traced +- [x] Phase transitions visible (open, establish, close, accept) +- [x] Proposals and validations traced — send and receive; relay deferred to Phase 4b - [x] Close time agreement tracked (per `avCT_CONSENSUS_PCT`) - [x] No impact on consensus timing - [ ] Multi-validator test network validated +- [x] Transaction-consensus correlation (Task 4.6) — `tx.included` events in doAccept +- [ ] Validation span enrichment (Task 4.8) — not implemented ### Implementation Status — Phase 4a Complete @@ -225,43 +229,46 @@ See [Phase4_taskList.md](./Phase4_taskList.md) for the full spec and implementat correlation using deterministic trace IDs derived from `previousLedger.id()`. **Approach**: Direct instrumentation in `Consensus.h` and `RCLConsensus.cpp`. -All spans use `SpanGuard` factory methods with `TraceCategory::Consensus` gating. +All spans use `SpanGuard` factory methods (`span()`, `hashSpan()`, `linkedSpan()`) +with `TraceCategory::Consensus` gating. No macros used — all tracing via direct +`SpanGuard` API calls. ### Tasks -| Task | Description | Effort | Risk | -| ---- | ------------------------------------------------ | ------ | ------ | -| 4a.0 | Prerequisites: extend SpanGuard & Telemetry APIs | 1d | Medium | -| 4a.1 | Adaptor `getTelemetry()` method | 0.5d | Low | -| 4a.2 | Switchable round span with deterministic traceID | 2d | High | -| 4a.3 | Span members in `Consensus.h` | 0.5d | Medium | -| 4a.4 | Instrument `phaseEstablish()` | 1d | Medium | -| 4a.5 | Instrument `updateOurPositions()` | 1d | Medium | -| 4a.6 | Instrument `haveConsensus()` (thresholds) | 1d | Medium | -| 4a.7 | Instrument mode changes | 0.5d | Low | -| 4a.8 | Reparent existing spans under round | 0.5d | Low | -| 4a.9 | Build verification and testing | 1d | Low | +| Task | Description | Effort | Risk | Status | +| ---- | ------------------------------------------------ | ------ | ------ | ------------------------ | +| 4a.0 | Prerequisites: extend SpanGuard & Telemetry APIs | 1d | Medium | ✅ Done (no macros) | +| 4a.1 | Adaptor `getTelemetry()` method | 0.5d | Low | ⏭️ Skipped (not needed) | +| 4a.2 | Switchable round span with deterministic traceID | 2d | High | ✅ Done | +| 4a.3 | Span members in `Consensus.h` | 0.5d | Medium | ✅ Done (with deviation) | +| 4a.4 | Instrument `phaseEstablish()` | 1d | Medium | ✅ Done | +| 4a.5 | Instrument `updateOurPositions()` | 1d | Medium | ✅ Done | +| 4a.6 | Instrument `haveConsensus()` (thresholds) | 1d | Medium | ✅ Done | +| 4a.7 | Instrument mode changes | 0.5d | Low | ✅ Done | +| 4a.8 | Reparent existing spans under round | 0.5d | Low | ✅ Done | +| 4a.9 | Build verification and testing | 1d | Low | ✅ Done | **Total Effort**: 9 days ### Spans Produced -| Span Name | Location | Key Attributes | -| ---------------------------- | ------------------ | ---------------------------------------------------------------- | -| `consensus.round` | `RCLConsensus.cpp` | `round_id`, `ledger_id`, `ledger.seq`, `mode`; link → prev round | -| `consensus.establish` | `Consensus.h` | `converge_percent`, `establish_count`, `proposers` | -| `consensus.update_positions` | `Consensus.h` | `disputes_count`, `converge_percent`, `proposers_agreed/total` | -| `consensus.check` | `Consensus.h` | `agree/disagree_count`, `threshold_percent`, `result` | -| `consensus.mode_change` | `RCLConsensus.cpp` | `mode.old`, `mode.new` | +| Span Name | Location | Key Attributes (actually set) | +| ---------------------------- | ------------------ | ----------------------------------------------------------------------------------------------------------------------------- | +| `consensus.round` | `RCLConsensus.cpp` | `round_id`, `ledger_id`, `ledger.seq`, `mode`, `trace_strategy` | +| `consensus.establish` | `Consensus.h` | `converge_percent`, `establish_count`, `proposers` | +| `consensus.update_positions` | `Consensus.h` | `converge_percent`, `proposers`, `have_close_time_consensus`, `close_time_threshold`, `disputes_count`, `avalanche_threshold` | +| `consensus.check` | `Consensus.h` | `agree/disagree_count`, `converge_percent`, `have_close_time_consensus`, `threshold_percent`, `result` | +| `consensus.mode_change` | `RCLConsensus.cpp` | `mode.old`, `mode.new` | ### Exit Criteria -- [ ] Establish phase internals fully traced (disputes, convergence, thresholds) -- [ ] Cross-node correlation works via deterministic trace_id -- [ ] Strategy switchable via config (`deterministic` / `attribute`) -- [ ] Consecutive rounds linked via follows-from spans -- [ ] Build passes with telemetry ON and OFF -- [ ] No impact on consensus timing +- [x] Establish phase internals traced (establish, update_positions, check spans) +- [x] Establish phase fully traced — `disputes_count`, `avalanche_threshold`, dispute `yays`/`nays` all implemented +- [x] Cross-node correlation works via deterministic trace_id +- [x] Strategy switchable via config (`deterministic` / `attribute`) +- [x] Consecutive rounds linked via follows-from spans +- [x] Build passes with telemetry ON and OFF +- [x] No impact on consensus timing See [Phase4_taskList.md](./Phase4_taskList.md) for full task details. @@ -273,7 +280,7 @@ See [Phase4_taskList.md](./Phase4_taskList.md) for full task details. validations) to enable true distributed tracing between nodes. **Status**: Design documented, NOT implemented. Protobuf fields (field 1001) -and `TraceContextPropagator` class exist. Wiring deferred until Phase 4a is +and `TraceContextPropagator` free functions exist. Wiring deferred until Phase 4a is validated in a multi-node environment. **Prerequisites**: Phase 4a complete and validated. @@ -368,7 +375,7 @@ flowchart TB subgraph run["🏃 RUN (Week 6-9)"] direction LR - r1[Consensus Tracing] ~~~ r2[Validator, Amendment,
SHAMap Tracing] ~~~ r3[Full Correlation] ~~~ r4[Production Deploy] + r1[Consensus Tracing] ~~~ r2[Establish Phase
& Cross-Node Correlation] ~~~ r3[StatsD Integration] ~~~ r4[Production Deploy] end crawl --> walk --> run @@ -396,7 +403,7 @@ flowchart TB - **CRAWL (Weeks 1-2)**: Minimal investment -- set up the SDK, instrument RPC and PathFinding/TxQ handlers, and verify on a single node. Delivers immediate latency visibility. - **WALK (Weeks 3-5)**: Expand to transaction lifecycle tracing, fee escalation, cross-node context propagation, and basic Grafana dashboards. This is where distributed tracing starts working. -- **RUN (Weeks 6-9)**: Full consensus instrumentation, validator/amendment/SHAMap tracing, end-to-end correlation, and production deployment with sampling and alerting. +- **RUN (Weeks 6-9)**: Full consensus instrumentation, establish-phase gap fill, cross-node correlation, StatsD integration, and production deployment with sampling and alerting. - **Arrows (crawl → walk → run)**: Each phase builds on the prior one; you cannot skip ahead because later phases depend on infrastructure established earlier. ### 6.9.2 Quick Wins (Immediate Value) @@ -461,17 +468,17 @@ flowchart TB - Complete consensus round visibility - Phase transition timing - Validator proposal tracking -- Validator list and manifest tracing -- Amendment voting tracing -- SHAMap sync tracing -- Full end-to-end traces (client → RPC → TX → consensus → ledger) +- ~~Validator list and manifest tracing~~ — descoped +- ~~Amendment voting tracing~~ — descoped +- ~~SHAMap sync tracing~~ — descoped +- Full end-to-end traces (client → RPC → TX → consensus → ledger) — partial (tx-consensus correlation not yet done) -**Code Changes**: ~100 lines across 3 consensus files, plus validator/amendment/SHAMap modules +**Code Changes**: ~100 lines across 3 consensus files **Why Do This Last**: - Highest complexity (consensus is critical path) -- Validator, amendment, and SHAMap components are lower priority +- Validator, amendment, and SHAMap components were descoped (lower priority) - Requires thorough testing - Lower relative value (consensus issues are rarer) diff --git a/OpenTelemetryPlan/Phase3_taskList.md b/OpenTelemetryPlan/Phase3_taskList.md index 22e62771e5..7ad43b2683 100644 --- a/OpenTelemetryPlan/Phase3_taskList.md +++ b/OpenTelemetryPlan/Phase3_taskList.md @@ -23,7 +23,7 @@ **What to do**: -- Edit `include/xrpl/proto/xrpl.proto` (or `src/ripple/proto/ripple.proto`, wherever the proto is): +- Edit `include/xrpl/proto/xrpl.proto` (or `src/xrpld/proto/ripple.proto`, wherever the proto is): - Add `TraceContext` message definition: ```protobuf message TraceContext { @@ -224,7 +224,7 @@ > **Upstream**: Phase 2 (RPC span infrastructure must exist). > **Downstream**: Phase 10 (validation checks for this attribute). -**Objective**: Add the relaying peer's rippled version to `tx.receive` spans so operators can correlate transaction issues with peer version mismatches during network upgrades. +**Objective**: Add the relaying peer's xrpld version to `tx.receive` spans so operators can correlate transaction issues with peer version mismatches during network upgrades. **What to do**: @@ -235,9 +235,9 @@ **New span attribute**: -| Attribute | Type | Source | Example | -| ------------------- | ------ | -------------------- | ----------------- | -| `xrpl.peer.version` | string | `peer->getVersion()` | `"rippled-2.4.0"` | +| Attribute | Type | Source | Example | +| ------------------- | ------ | -------------------- | --------------- | +| `xrpl.peer.version` | string | `peer->getVersion()` | `"xrpld-2.4.0"` | **Rationale**: Transaction relay is where version mismatches cause subtle serialization or validation bugs. Tracing "this tx came from a v2.3.0 peer" helps diagnose compatibility issues. The community dashboard tracks peer versions externally; this brings version awareness into the trace itself. diff --git a/OpenTelemetryPlan/Phase4_taskList.md b/OpenTelemetryPlan/Phase4_taskList.md index e31f364fbb..1670e9b57e 100644 --- a/OpenTelemetryPlan/Phase4_taskList.md +++ b/OpenTelemetryPlan/Phase4_taskList.md @@ -17,30 +17,25 @@ --- -## Task 4.1: Instrument Consensus Round Start +## Task 4.1: Instrument Consensus Round Start ✅ **Objective**: Create a root span for each consensus round that captures the round's key parameters. -**What to do**: +**Status**: DONE (implemented via Task 4a.2 `startRoundTracing()` helper). -- Edit `src/xrpld/app/consensus/RCLConsensus.cpp`: - - In `RCLConsensus::startRound()` (or the Adaptor's startRound): - - Create `consensus.round` span using `XRPL_TRACE_CONSENSUS` macro - - Set attributes: - - `xrpl.consensus.ledger.prev` — previous ledger hash - - `xrpl.consensus.ledger.seq` — target ledger sequence - - `xrpl.consensus.proposers` — number of trusted proposers - - `xrpl.consensus.mode` — "proposing" or "observing" - - Store the span context for use by child spans in phase transitions +**What was done**: -- Add a member to hold current round trace context: - - `opentelemetry::context::Context currentRoundContext_` (guarded by `#ifdef`) - - Updated at round start, used by phase transition spans +- `RCLConsensus::Adaptor::startRoundTracing()` creates `consensus.round` span + via `SpanGuard::hashSpan()` (deterministic) or `SpanGuard::span()` (attribute strategy) +- Attributes set: `xrpl.consensus.ledger_id`, `xrpl.consensus.ledger.seq`, + `xrpl.consensus.mode`, `xrpl.consensus.trace_strategy`, `xrpl.consensus.round_id` +- Round span stored as `roundSpan_` member in `RCLConsensus::Adaptor` +- `roundSpanContext_` snapshot captured for cross-thread span linking **Key modified files**: - `src/xrpld/app/consensus/RCLConsensus.cpp` -- `src/xrpld/app/consensus/RCLConsensus.h` (add context member) +- `src/xrpld/app/consensus/RCLConsensus.h` (span and context members) **Reference**: @@ -49,30 +44,27 @@ --- -## Task 4.2: Instrument Phase Transitions +## Task 4.2: Instrument Phase Transitions ✅ **Objective**: Create child spans for each consensus phase (open, establish, accept) to show timing breakdown. -**What to do**: +**Status**: DONE. All consensus phases are now instrumented: -- Edit `src/xrpld/app/consensus/RCLConsensus.cpp`: - - Identify where phase transitions occur (the `Consensus` template drives this) - - For each phase entry: - - Create span as child of `currentRoundContext_`: `consensus.phase.open`, `consensus.phase.establish`, `consensus.phase.accept` - - Set `xrpl.consensus.phase` attribute - - Add `phase.enter` event at start, `phase.exit` event at end - - Record phase duration in milliseconds +- `consensus.establish` — created in `Consensus.h::startEstablishTracing()` +- `consensus.ledger_close` — created in `RCLConsensus.cpp::onClose()` +- `consensus.accept` / `consensus.accept.apply` — created in `onAccept()` / `doAccept()` +- `consensus.phase.open` — `openSpan_` member in `Consensus.h`, created in `startRoundInternal()`, ended in `closeLedger()` - - In the `onClose` adaptor method: - - Create `consensus.ledger_close` span - - Set attributes: close_time, mode, transaction count in initial position +**Design notes**: - - Note: The Consensus template class in `src/xrpld/consensus/Consensus.h` drives phase transitions — Phase 4a instruments directly in the template +- `xrpl.consensus.phase` attribute — phases are distinguished by span names instead +- `phase.enter` / `phase.exit` events — not added (span start/end serves this purpose) +- `xrpl.consensus.phase_duration_ms` attribute — not set (span duration captures this) **Key modified files**: - `src/xrpld/app/consensus/RCLConsensus.cpp` -- Possibly `include/xrpl/consensus/Consensus.h` (for template-level phase tracking) +- `src/xrpld/consensus/Consensus.h` (template-level establish phase tracking) **Reference**: @@ -80,25 +72,26 @@ --- -## Task 4.3: Instrument Proposal Handling +## Task 4.3: Instrument Proposal Handling ✅ **Objective**: Trace proposal send and receive to show validator coordination. -**What to do**: +**Status**: DONE. Both send and receive paths are instrumented. -- Edit `src/xrpld/app/consensus/RCLConsensus.cpp`: - - In `Adaptor::propose()`: - - Create `consensus.proposal.send` span - - Set attributes: `xrpl.consensus.round` (proposal sequence), proposal hash - - Inject trace context into outgoing `TMProposeSet::trace_context` (from Phase 3 protobuf) +**What was done**: - - In `Adaptor::peerProposal()` (or wherever peer proposals are received): - - Extract trace context from incoming `TMProposeSet::trace_context` - - Create `consensus.proposal.receive` span as child of extracted context - - Set attributes: `xrpl.consensus.proposer` (node ID), `xrpl.consensus.round` +- In `Adaptor::propose()`: + - Creates `consensus.proposal.send` span via `SpanGuard::span()` + - Sets `xrpl.consensus.round` attribute - - In `Adaptor::share(RCLCxPeerPos)`: - - Create `consensus.proposal.relay` span for relaying peer proposals +- In `PeerImp::onMessage(TMProposeSet)`: + - Creates `consensus.proposal.receive` span + - Sets `xrpl.consensus.proposal.trusted` attribute (bool) + +**Not implemented** (deferred to Phase 4b — cross-node propagation): + +- `consensus.proposal.relay` span in `share(RCLCxPeerPos)` — requires trace context injection +- Trace context injection/extraction for `TMProposeSet::trace_context` **Key modified files**: @@ -111,73 +104,84 @@ --- -## Task 4.4: Instrument Validation Handling +## Task 4.4: Instrument Validation Handling ✅ **Objective**: Trace validation send and receive to show ledger validation flow. -**What to do**: +**Status**: DONE. Both send and receive paths are instrumented. -- Edit `src/xrpld/app/consensus/RCLConsensus.cpp` (or the validation handler): - - When sending our validation: - - Create `consensus.validation.send` span - - Set attributes: validated ledger hash, sequence, signing time +**What was done**: - - When receiving a peer validation: - - Extract trace context from `TMValidation::trace_context` (if present) - - Create `consensus.validation.receive` span - - Set attributes: `xrpl.consensus.validator` (node ID), ledger hash +- In `Adaptor::validate()` (called from `doAccept()`): + - Creates `consensus.validation.send` span via `Adaptor::createValidationSpan()` + - Uses `SpanGuard::linkedSpan()` to create a follows-from link to the round span + - Thread-safe: uses `roundSpanContext_` snapshot (captured on consensus thread, + read on jtACCEPT thread) + - Sets `xrpl.consensus.ledger.seq` and `xrpl.consensus.proposing` attributes + +- In `PeerImp::onMessage(TMValidation)`: + - Creates `consensus.validation.receive` span + - Sets `xrpl.consensus.validation.trusted` attribute (bool) + - Sets `xrpl.consensus.validation.ledger_seq` attribute + +**Not implemented** (deferred to Phase 4b — cross-node propagation): + +- Validated ledger hash, signing time attributes on send span (see Task 4.8) **Key modified files**: - `src/xrpld/app/consensus/RCLConsensus.cpp` -- `src/xrpld/app/misc/NetworkOPs.cpp` (if validation handling is here) --- -## Task 4.5: Add Consensus-Specific Attributes +## Task 4.5: Add Consensus-Specific Attributes ✅ **Objective**: Enrich consensus spans with detailed attributes for debugging and analysis. -**What to do**: +**Status**: DONE. All core attributes are set across various spans, including the previously missing `tx_count` and `disputes_count`. -- Review all consensus spans and ensure they include: - - `xrpl.consensus.ledger.seq` — target ledger sequence number - - `xrpl.consensus.round` — consensus round number - - `xrpl.consensus.mode` — proposing/observing/wrongLedger - - `xrpl.consensus.phase` — current phase name - - `xrpl.consensus.phase_duration_ms` — time spent in phase - - `xrpl.consensus.proposers` — number of trusted proposers - - `xrpl.consensus.tx_count` — transactions in proposed set - - `xrpl.consensus.disputes` — number of disputed transactions - - `xrpl.consensus.converge_percent` — convergence percentage +**Implemented attributes** (across various spans): + +- `xrpl.consensus.ledger.seq` — on `consensus.round`, `consensus.accept.apply` +- `xrpl.consensus.round` — on `consensus.proposal.send` +- `xrpl.consensus.mode` — on `consensus.round`, `consensus.ledger_close` +- `xrpl.consensus.proposers` — on `consensus.accept`, `consensus.establish`, `consensus.update_positions` +- `xrpl.consensus.converge_percent` — on `consensus.establish`, `consensus.update_positions`, `consensus.check` +- `xrpl.consensus.tx_count` — on `consensus.accept.apply` span (in `doAccept()`) +- `xrpl.consensus.disputes_count` — on `consensus.update_positions` span (in `updateOurPositions()`) + +**Design notes**: + +- `xrpl.consensus.phase` — phases distinguished by span names instead +- `xrpl.consensus.phase_duration_ms` — span duration captures this **Key modified files**: - `src/xrpld/app/consensus/RCLConsensus.cpp` +- `src/xrpld/consensus/Consensus.h` --- -## Task 4.6: Correlate Transaction and Consensus Traces +## Task 4.6: Correlate Transaction and Consensus Traces ✅ **Objective**: Link transaction traces from Phase 3 with consensus traces so you can follow a transaction from submission through consensus into the ledger. -**What to do**: +**Status**: DONE. Transaction-consensus correlation implemented via `tx.included` events in `doAccept()`. -- In `onClose()` or `onAccept()`: - - When building the consensus position, link the round span to individual transaction spans using span links (if OTel SDK supports it) or events - - At minimum, record the transaction hashes included in the consensus set as span events: `tx.included` with `xrpl.tx.hash` attribute +**What was done**: -- In `processTransactionSet()` (NetworkOPs): - - If the consensus round span context is available, create child spans for each transaction applied to the ledger +- In `doAccept()` (RCLConsensus.cpp): + - Records `tx.included` events on the `consensus.accept.apply` span for each transaction in the accepted set + - Each event includes `xrpl.tx.id` attribute with the transaction hash + - This links consensus traces to individual transactions **Key modified files**: - `src/xrpld/app/consensus/RCLConsensus.cpp` -- `src/xrpld/app/misc/NetworkOPs.cpp` --- -## Task 4.7: Build Verification and Testing +## Task 4.7: Build Verification and Testing ✅ **Objective**: Verify all Phase 4 changes compile and don't affect consensus timing. @@ -186,20 +190,20 @@ 1. Build with `telemetry=ON` — verify no compilation errors 2. Build with `telemetry=OFF` — verify no regressions (critical for consensus code) 3. Run existing consensus-related unit tests -4. Verify that all macros expand to no-ops when disabled +4. Verify that `SpanGuard` factory methods compile to no-ops when disabled 5. Check that no consensus-critical code paths are affected by instrumentation overhead **Verification Checklist**: -- [ ] Build succeeds with telemetry ON -- [ ] Build succeeds with telemetry OFF -- [ ] Existing consensus tests pass -- [ ] No new includes in consensus headers when telemetry is OFF -- [ ] Phase timing instrumentation doesn't use blocking operations +- [x] Build succeeds with telemetry ON +- [x] Build succeeds with telemetry OFF +- [x] Existing consensus tests pass +- [x] `SpanGuard` no-op implementation prevents overhead when telemetry is OFF +- [x] Phase timing instrumentation doesn't use blocking operations --- -## Task 4.8: Consensus Validation Span Enrichment — External Dashboard Parity +## Task 4.8: Consensus Validation Span Enrichment — NOT DONE > **Source**: [External Dashboard Parity](../docs/superpowers/specs/2026-03-30-external-dashboard-parity-design.md) — adds validation agreement context inspired by the community [xrpl-validator-dashboard](https://github.com/realgrapedrop/xrpl-validator-dashboard). > @@ -208,6 +212,8 @@ **Objective**: Add ledger hash, validation type, and quorum data to consensus validation spans on both send and receive paths. This enables trace-level validation agreement analysis — filter by ledger hash to see which validators agreed for a given ledger. +**Status**: Not implemented. None of the enrichment attributes are set. The `consensus.validation.send` span only has `ledger.seq` and `proposing`. The `consensus.accept` span has `quorum` set to `result.proposers` (not the actual validator quorum from `app_.validators().quorum()`). No `PeerImp.cpp` changes were made. + **What to do**: - Edit `src/xrpld/app/consensus/RCLConsensus.cpp`: @@ -242,7 +248,7 @@ Phase 7's `ValidationTracker` builds metric-level aggregation (1h/24h agreement %) on top of this data. -**Key modified files**: +**Key modified files (not yet modified)**: - `src/xrpld/app/consensus/RCLConsensus.cpp` - `src/xrpld/overlay/detail/PeerImp.cpp` @@ -259,16 +265,16 @@ Phase 7's `ValidationTracker` builds metric-level aggregation (1h/24h agreement ## Summary -| Task | Description | New Files | Modified Files | Depends On | -| ---- | ------------------------------------------- | --------- | -------------- | ------------- | -| 4.1 | Consensus round start instrumentation | 0 | 2 | Phase 3 | -| 4.2 | Phase transition instrumentation | 0 | 1-2 | 4.1 | -| 4.3 | Proposal handling instrumentation | 0 | 1 | 4.1 | -| 4.4 | Validation handling instrumentation | 0 | 1-2 | 4.1 | -| 4.5 | Consensus-specific attributes | 0 | 1 | 4.2, 4.3, 4.4 | -| 4.6 | Transaction-consensus correlation | 0 | 2 | 4.2, Phase 3 | -| 4.7 | Build verification and testing | 0 | 0 | 4.1-4.6 | -| 4.8 | Validation span enrichment (ext. dashboard) | 0 | 2 | 4.4 | +| Task | Description | Status | New Files | Modified Files | Depends On | +| ---- | ------------------------------------------- | ----------- | --------- | -------------- | ------------- | +| 4.1 | Consensus round start instrumentation | ✅ Done | 0 | 2 | Phase 3 | +| 4.2 | Phase transition instrumentation | ✅ Done | 0 | 1-2 | 4.1 | +| 4.3 | Proposal handling instrumentation | ✅ Done | 0 | 2 | 4.1 | +| 4.4 | Validation handling instrumentation | ✅ Done | 0 | 2 | 4.1 | +| 4.5 | Consensus-specific attributes | ✅ Done | 0 | 2 | 4.2, 4.3, 4.4 | +| 4.6 | Transaction-consensus correlation | ✅ Done | 0 | 1 | 4.2, Phase 3 | +| 4.7 | Build verification and testing | ✅ Done | 0 | 0 | 4.1-4.6 | +| 4.8 | Validation span enrichment (ext. dashboard) | ❌ Not done | 0 | 2 | 4.4 | **Parallel work**: Tasks 4.2, 4.3, and 4.4 can run in parallel after 4.1 is complete. Task 4.5 depends on all three. Task 4.6 depends on 4.2 and Phase 3. Task 4.8 depends on 4.4 (validation spans must exist). @@ -301,10 +307,12 @@ driven by `avCT_CONSENSUS_PCT` (75% validator agreement threshold): **Exit Criteria** (from [06-implementation-phases.md §6.11.4](./06-implementation-phases.md)): - [x] Complete consensus round traces -- [x] Phase transitions visible -- [x] Proposals and validations traced +- [x] Phase transitions visible (open, establish, close, accept) +- [x] Proposals and validations traced — send and receive; relay deferred to Phase 4b - [x] Close time agreement tracked (per `avCT_CONSENSUS_PCT`) - [x] No impact on consensus timing +- [x] Transaction-consensus correlation (Task 4.6) — `tx.included` events in doAccept +- [ ] Validation span enrichment (Task 4.8) — not implemented --- @@ -314,14 +322,13 @@ driven by `avCT_CONSENSUS_PCT` (75% validator agreement threshold): > threshold escalation, mode changes) and establish cross-node correlation using a > deterministic shared trace ID derived from `previousLedger.id()`. > -> **Approach**: Direct instrumentation in `Consensus.h` — the generic consensus -> template has full access to internal state (`convergePercent_`, `result_->disputes`, -> `mode_`, threshold logic). Telemetry access comes via a single new adaptor -> method `getTelemetry()`. Long-lived spans (round, establish) are stored as -> class members using `SpanGuard` directly — NOT the `XRPL_TRACE_*` convenience -> macros (which create local variables named `_xrpl_guard_`). Short-lived -> scoped spans (update_positions, check) can use the macros. All code compiles -> to no-ops when `XRPL_ENABLE_TELEMETRY` is not defined. +> **Approach**: Direct instrumentation in `Consensus.h` and `RCLConsensus.cpp`. +> All spans use `SpanGuard` factory methods (`span()`, `hashSpan()`, `linkedSpan()`) +> with `TraceCategory::Consensus` gating. Long-lived spans (round, establish) are +> stored as `std::optional` class members. Short-lived scoped spans +> (update_positions, check) are local variables. No macros are used — all tracing +> is via direct `SpanGuard` API calls. `SpanGuard` compiles to no-ops when +> telemetry is disabled. > > **Branch**: `pratik/otel-phase4-consensus-tracing` @@ -412,15 +419,18 @@ consensus.round (root — created in RCLConsensus::startRound, closed at accept --- -## Task 4a.0: Prerequisites — Extend SpanGuard and Telemetry APIs +## Task 4a.0: Prerequisites — Extend SpanGuard and Telemetry APIs ✅ **Objective**: Add missing API surface needed by later tasks. -**What to do**: +**Status**: Done, but implemented differently than originally planned. The macro-based +approach (`XRPL_TRACE_CONSENSUS`, `XRPL_TRACE_ADD_EVENT`, `XRPL_TRACE_SET_ATTR`) was +**not used**. Instead, all consensus tracing uses `SpanGuard` factory methods and +direct method calls, which is cleaner and avoids macro control-flow issues. -1. **Add `SpanGuard::addEvent()` with attributes** (needed by Task 4a.5): - The current `addEvent(string_view name)` only accepts a name. Add an - overload that accepts key-value attributes: +**What was done**: + +1. **`SpanGuard::addEvent()` with attributes** — implemented as planned: ```cpp using EventAttribute = std::pair; @@ -429,101 +439,76 @@ consensus.round (root — created in RCLConsensus::startRound, closed at accept std::initializer_list attrs); ``` - The `EventAttribute` type alias (defined in `SpanGuard.h`) keeps the - public API free of OTel SDK types — callers pass plain `string_view` - pairs and the implementation converts internally. + Callers pass plain `string_view` pairs; the implementation converts internally. ```cpp - // Example usage: - guard.addEvent("dispute.resolve", { - {"xrpl.tx.id", txIdStr}, - {"xrpl.dispute.our_vote", voteStr} - }); + // Actual usage in Consensus.h::updateOurPositions(): + span.addEvent( + "dispute.resolve", + {{cons_span::attr::txId, to_string(txId)}, + {cons_span::attr::disputeOurVote, dispute.getOurVote() ? "yes" : "no"}}); ``` -2. **Add a `Telemetry::startSpan()` overload that accepts span links** (needed by Tasks 4a.2, 4a.8): - The current `startSpan()` has no span link support. Add an overload that - accepts a vector of `SpanContext` links for follows-from relationships: +2. **Span link support** — implemented via `SpanGuard::linkedSpan()` static factory + instead of a `Telemetry::startSpan()` overload: ```cpp - virtual opentelemetry::nostd::shared_ptr - startSpan( - std::string_view name, - opentelemetry::context::Context const& parentContext, - std::vector const& links, - opentelemetry::trace::SpanKind kind = opentelemetry::trace::SpanKind::kInternal) = 0; + static SpanGuard linkedSpan( + std::string_view name, SpanContext const& linkTarget); ``` -3. **Add `XRPL_TRACE_ADD_EVENT` macro** (needed by Task 4a.5): - Add to `TracingInstrumentation.h` to expose `addEvent(name, attrs)` through - the macro interface (consistent with `XRPL_TRACE_SET_ATTR` pattern): - ```cpp - #ifdef XRPL_ENABLE_TELEMETRY - #define XRPL_TRACE_ADD_EVENT(name, ...) \ - if (_xrpl_guard_.has_value()) \ - { \ - _xrpl_guard_->addEvent(name, __VA_ARGS__); \ - } - #else - #define XRPL_TRACE_ADD_EVENT(name, ...) ((void)0) - #endif - ``` +3. **No macros added** — `TracingInstrumentation.h` was not created. The `XRPL_TRACE_CONSENSUS`, + `XRPL_TRACE_ADD_EVENT`, and `XRPL_TRACE_SET_ATTR` macros from the original plan were + not implemented. All consensus tracing uses direct `SpanGuard` API: + - `SpanGuard::span()` — create scoped spans + - `SpanGuard::hashSpan()` — create spans with deterministic trace IDs + - `SpanGuard::linkedSpan()` — create spans with follows-from links + - `span.setAttribute()` — set attributes directly + - `span.addEvent()` — add events directly **Key modified files**: -- `include/xrpl/telemetry/SpanGuard.h` — add `addEvent()` overload -- `include/xrpl/telemetry/Telemetry.h` — add `startSpan()` with links -- `src/xrpld/telemetry/Telemetry.cpp` — implement new overload -- `src/xrpld/telemetry/NullTelemetry.cpp` — no-op implementation -- `src/xrpld/telemetry/TracingInstrumentation.h` — add `XRPL_TRACE_ADD_EVENT` macro +- `include/xrpl/telemetry/SpanGuard.h` — `addEvent()` overload, `EventAttribute` type alias +- `src/libxrpl/telemetry/SpanGuard.cpp` — `addEvent()` implementation --- -## Task 4a.1: Adaptor `getTelemetry()` Method +## Task 4a.1: Adaptor `getTelemetry()` Method — NOT DONE (Not Needed) **Objective**: Give `Consensus.h` access to the telemetry subsystem without coupling the generic template to OTel headers. -**What to do**: +**Status**: Not implemented as specified. The `getTelemetry()` adaptor method was +not needed because `SpanGuard::span()` is a static factory method that internally +checks telemetry state via the global `Telemetry` singleton. `Consensus.h` creates +spans by calling `SpanGuard::span(TraceCategory::Consensus, ...)` directly, without +needing adaptor access. Only `RCLConsensus::Adaptor` uses `app_.getTelemetry()` +directly (for `getConsensusTraceStrategy()` in `startRoundTracing()`). -- Add `getTelemetry()` method to the Adaptor concept (returns - `xrpl::telemetry::Telemetry&`). The return type is already forward-declared - behind `#ifdef XRPL_ENABLE_TELEMETRY`. -- Implement in `RCLConsensus::Adaptor` — delegates to `app_.getTelemetry()`. -- In `Consensus.h`, the `XRPL_TRACE_*` macros call - `adaptor_.getTelemetry()` — when telemetry is disabled, the macros expand to - `((void)0)` and the method is never called. - -**Key modified files**: - -- `src/xrpld/app/consensus/RCLConsensus.h` — declare `getTelemetry()` -- `src/xrpld/app/consensus/RCLConsensus.cpp` — implement `getTelemetry()` +**Key insight**: The `XRPL_TRACE_*` macro approach would have required +`adaptor_.getTelemetry()`. Since macros were not used, this task became unnecessary. --- -## Task 4a.2: Switchable Round Span with Deterministic Trace ID +## Task 4a.2: Switchable Round Span with Deterministic Trace ID ✅ **Objective**: Create a `consensus.round` root span in `startRound()` that uses the switchable correlation strategy. Store span context as a member for child spans in `Consensus.h`. -**What to do**: +**Status**: Done. Implemented in `Adaptor::startRoundTracing()`. -- In `RCLConsensus::Adaptor::startRound()` (or a new helper): - - Read `consensus_trace_strategy` from config. - - **Deterministic**: compute `trace_id = SHA256(prevLedgerID)[0:16]`. - Construct a `SpanContext` with this trace_id, then start - `consensus.round` span as child of that context. - - **Attribute**: start normal `consensus.round` span. - - Set attributes on both: `xrpl.consensus.round_id`, - `xrpl.consensus.ledger_id`, `xrpl.consensus.ledger.seq`, - `xrpl.consensus.mode`. - - Store the round span in `Consensus` as a member (see Task 4a.3). - - If a previous round's span context is available, add a **span link** - (follows-from) to establish the round chain. +**What was done**: -- **`SpanGuard::hashSpan()` factory**: The deterministic trace ID logic is - encapsulated in a static factory method on `SpanGuard`: +- `RCLConsensus::Adaptor::startRoundTracing()` helper: + - Reads `consensus_trace_strategy` via `app_.getTelemetry().getConsensusTraceStrategy()` + - **Deterministic**: uses `SpanGuard::hashSpan()` with `prevLgr.id()` data + - **Attribute**: uses `SpanGuard::span(TraceCategory::Consensus, seg::consensus, "round")` + - Sets attributes: `ledger_id`, `ledger.seq`, `mode`, `trace_strategy`, `round_id` + - Captures `roundSpanContext_` snapshot for cross-thread span linking + - Saves `prevRoundContext_` from previous round for follows-from links + +- **`SpanGuard::hashSpan()` factory**: encapsulates deterministic trace ID logic: ```cpp static SpanGuard hashSpan( @@ -531,208 +516,182 @@ spans in `Consensus.h`. std::uint8_t const* hashData, std::size_t hashSize); ``` - `hashSpan()` derives `trace_id = hashData[0:16]` and creates a span whose - trace ID matches on every node that shares the same hash input (e.g. - `previousLedger.id()`). It is the consensus equivalent of `txSpan()` (which - derives trace IDs from transaction hashes). Both factories live in - `SpanGuard.h` and compile to no-ops when telemetry is disabled. + Derives `trace_id = hashData[0:16]` so all nodes in the same round share + the same trace_id. Compiles to no-op when telemetry is disabled. -- Add `createDeterministicTraceId(hash)` utility to - `include/xrpl/telemetry/Telemetry.h` (returns 16-byte trace ID from a - 256-bit hash by truncation). - -- Add `consensus_trace_strategy` to `Telemetry::Setup` and - `TelemetryConfig.cpp` parser: - ```cpp - /** Cross-node correlation strategy: "deterministic" or "attribute". */ - std::string consensusTraceStrategy = "deterministic"; - ``` +- `consensus_trace_strategy` config parsed in `TelemetryConfig.cpp`, + stored in `Telemetry::Setup`, accessible via `Telemetry::getConsensusTraceStrategy()` **Key modified files**: -- `src/xrpld/app/consensus/RCLConsensus.cpp` -- `src/xrpld/app/consensus/ConsensusSpanNames.h` — **(new)** span name constants for consensus spans, following the `*SpanNames.h` colocation pattern (header lives next to its class, not in `telemetry/`) -- `include/xrpl/telemetry/Telemetry.h` — `createDeterministicTraceId()` -- `src/xrpld/telemetry/TelemetryConfig.cpp` — parse new config option +- `src/xrpld/app/consensus/RCLConsensus.cpp` — `startRoundTracing()` implementation +- `src/xrpld/app/consensus/ConsensusSpanNames.h` — **(new)** compile-time span name and attribute key constants +- `include/xrpl/telemetry/Telemetry.h` — `consensusTraceStrategy` in Setup, `getConsensusTraceStrategy()` +- `src/libxrpl/telemetry/TelemetryConfig.cpp` — parse new config option --- -## Task 4a.3: Span Members in `Consensus.h` +## Task 4a.3: Span Members in `Consensus.h` ✅ **Objective**: Add span storage to the `Consensus` class so that spans created in `startRound()` (adaptor) are accessible from `phaseEstablish()`, `updateOurPositions()`, and `haveConsensus()` (template methods). -**What to do**: +**Status**: Done with documented plan deviation. + +**What was done**: + +- `establishSpan_` added to `Consensus` private members (as planned): -- Add to `Consensus` private members (guarded by `#ifdef XRPL_ENABLE_TELEMETRY`): ```cpp - #ifdef XRPL_ENABLE_TELEMETRY - std::optional roundSpan_; std::optional establishSpan_; - opentelemetry::context::Context prevRoundContext_; - #endif ``` -- `roundSpan_` is created in `startRound()` via the adaptor and stored. - Its `SpanGuard::Scope` member keeps the span active on the thread context - for the entire round lifetime. -- `establishSpan_` is created when entering phaseEstablish and cleared on accept. - It becomes a child of `roundSpan_` via OTel's thread-local context propagation. -- `prevRoundContext_` stores the previous round's context for follows-from links. -**Threading assumption**: `startRound()`, `phaseEstablish()`, `updateOurPositions()`, -and `haveConsensus()` all run on the same thread (the consensus job queue thread). -This is required for the `SpanGuard::Scope`-based parent-child hierarchy to work. -The `Consensus` class documentation confirms it is NOT thread-safe and calls are -serialized by the application. +- **Plan deviation**: `roundSpan_`, `prevRoundContext_`, and `roundSpanContext_` + are stored in `RCLConsensus::Adaptor` (not `Consensus.h`) because the adaptor + has access to telemetry config for the deterministic trace ID strategy. -- Add conditional include at top of `Consensus.h`: +- **No `#ifdef XRPL_ENABLE_TELEMETRY` guards**: Members use `std::optional` + and `SpanContext` which have no-op implementations when telemetry is disabled, + so `#ifdef` guards are unnecessary. The members are always present in the class + layout but incur negligible overhead. + +- Includes added unconditionally to `Consensus.h`: ```cpp - #ifdef XRPL_ENABLE_TELEMETRY #include - #include - #endif + #include ``` + No `TracingInstrumentation.h` include (file doesn't exist; macros not used). **Key modified files**: - `src/xrpld/consensus/Consensus.h` +- `src/xrpld/app/consensus/RCLConsensus.h` (round span and context members) --- -## Task 4a.4: Instrument `phaseEstablish()` +## Task 4a.4: Instrument `phaseEstablish()` ✅ **Objective**: Create `consensus.establish` span wrapping the establish phase, with attributes for convergence progress. -**What to do**: +**Status**: Done. Implemented via three private helpers in `Consensus.h`. -- At the start of `phaseEstablish()` (line 1298), if `establishSpan_` is not - yet created, create it as child of `roundSpan_` using the **direct API** - (NOT the `XRPL_TRACE_CONSENSUS` macro, which creates a local variable): +**What was done**: - ```cpp - #ifdef XRPL_ENABLE_TELEMETRY - if (!establishSpan_ && adaptor_.getTelemetry().shouldTraceConsensus()) - { - establishSpan_.emplace( - adaptor_.getTelemetry().startSpan("consensus.establish")); - } - #endif - ``` +- `startEstablishTracing()` — creates `consensus.establish` span via + `SpanGuard::span(TraceCategory::Consensus, seg::consensus, "establish")`. + Called once at start of establish phase. No `#ifdef` guards needed — + `SpanGuard::span()` returns a no-op guard when telemetry is disabled. -- Set attributes on each call: +- `updateEstablishTracing()` — sets attributes on each `phaseEstablish()` call: - `xrpl.consensus.converge_percent` — `convergePercent_` - `xrpl.consensus.establish_count` — `establishCounter_` - `xrpl.consensus.proposers` — `currPeerPositions_.size()` -- On phase exit (transition to accept), close the establish span and record - final duration. +- `endEstablishTracing()` — calls `establishSpan_.reset()` on phase exit. **Key modified files**: -- `src/xrpld/consensus/Consensus.h` — `phaseEstablish()` method +- `src/xrpld/consensus/Consensus.h` — `phaseEstablish()` method + 3 helper methods --- -## Task 4a.5: Instrument `updateOurPositions()` +## Task 4a.5: Instrument `updateOurPositions()` ✅ **Objective**: Trace each position update cycle including dispute resolution details. -**What to do**: +**Status**: DONE. Span, dispute events with yays/nays, and disputes_count attribute are all implemented. -- At the start of `updateOurPositions()` (line 1418), create a scoped child - span. This method is called and returns within a single `phaseEstablish()` - call, so the `XRPL_TRACE_CONSENSUS` macro works here (scoped local): +**What was done**: + +- Creates `consensus.update_positions` scoped span via + `SpanGuard::span(TraceCategory::Consensus, seg::consensus, "update_positions")`: ```cpp - XRPL_TRACE_CONSENSUS(adaptor_.getTelemetry(), "consensus.update_positions"); + auto span = SpanGuard::span(TraceCategory::Consensus, seg::consensus, "update_positions"); ``` -- Set attributes: - - `xrpl.consensus.disputes_count` — `result_->disputes.size()` +- Attributes set: - `xrpl.consensus.converge_percent` — current convergence - - `xrpl.consensus.proposers_agreed` — count of peers with same position - - `xrpl.consensus.proposers_total` — total peer positions + - `xrpl.consensus.proposers` — `currPeerPositions_.size()` + - `xrpl.consensus.have_close_time_consensus` — close time consensus state + - `xrpl.consensus.close_time_threshold` — `avCT_CONSENSUS_PCT` + - `xrpl.consensus.disputes_count` — number of active disputes -- Inside the dispute resolution loop, for each dispute that changes our vote, - add an **event** with attributes using `XRPL_TRACE_ADD_EVENT` (from Task 4a.0): +- Dispute events recorded via direct `span.addEvent()` call with yays/nays: ```cpp - XRPL_TRACE_ADD_EVENT("dispute.resolve", { - {"xrpl.tx.id", std::string(tx_id)}, - {"xrpl.dispute.our_vote", our_vote}, - {"xrpl.dispute.yays", static_cast(yays)}, - {"xrpl.dispute.nays", static_cast(nays)} - }); + span.addEvent( + "dispute.resolve", + {{cons_span::attr::txId, to_string(txId)}, + {cons_span::attr::disputeOurVote, dispute.getOurVote() ? "yes" : "no"}, + {cons_span::attr::disputeYays, std::to_string(dispute.getYays())}, + {cons_span::attr::disputeNays, std::to_string(dispute.getNays())}}); ``` +**Not implemented**: + +- `xrpl.consensus.proposers_agreed` / `xrpl.consensus.proposers_total` attributes — not set + **Key modified files**: - `src/xrpld/consensus/Consensus.h` — `updateOurPositions()` method +- `src/xrpld/consensus/DisputedTx.h` — added `getYays()` / `getNays()` (currently unused) --- -## Task 4a.6: Instrument `haveConsensus()` (Threshold & Convergence) +## Task 4a.6: Instrument `haveConsensus()` (Threshold & Convergence) ✅ -**Objective**: Trace consensus checking including threshold escalation -(`ConsensusParms::AvalancheState::{init, mid, late, stuck}`). +**Objective**: Trace consensus checking including threshold escalation. -**What to do**: +**Status**: DONE. The `consensus.check` span is created with all planned attributes +including the avalanche threshold. -- At the start of `haveConsensus()` (line 1598), create a scoped child span: +**What was done**: + +- Creates `consensus.check` scoped span via + `SpanGuard::span(TraceCategory::Consensus, seg::consensus, "check")`: ```cpp - XRPL_TRACE_CONSENSUS(adaptor_.getTelemetry(), "consensus.check"); + auto span = SpanGuard::span(TraceCategory::Consensus, seg::consensus, "check"); ``` -- Set attributes: +- Attributes set: - `xrpl.consensus.agree_count` — peers that agree with our position - `xrpl.consensus.disagree_count` — peers that disagree - `xrpl.consensus.converge_percent` — convergence percentage - - `xrpl.consensus.result` — ConsensusState result (Yes/No/MovedOn) - -- The free function `checkConsensus()` in `Consensus.cpp` (line 151) determines - thresholds based on `currentAgreeTime`. Threshold values come from - `ConsensusParms::avalancheCutoffs` (defined in `ConsensusParms.h`). - The escalation states are `ConsensusParms::AvalancheState::{init, mid, late, stuck}`. - Record the effective threshold and close time consensus state: - - `xrpl.consensus.threshold_percent` — consensus threshold (avCT_CONSENSUS_PCT = 75%) - - `xrpl.consensus.close_time_threshold` — close time voting threshold (avCT_CONSENSUS_PCT) - - `xrpl.consensus.have_close_time_consensus` — whether close time consensus was reached - - `xrpl.consensus.avalanche_threshold` — the avalanche-escalated weight from `getNeededWeight()` - - These are recorded on both `consensus.update_positions` and `consensus.check` spans. + - `xrpl.consensus.have_close_time_consensus` — close time consensus state + - `xrpl.consensus.threshold_percent` — set to `avCT_CONSENSUS_PCT` (75%) + - `xrpl.consensus.result` — "yes", "no", or "moved_on" + - `xrpl.consensus.avalanche_threshold` — the escalated weight from `getNeededWeight()` on the `consensus.update_positions` span **Key modified files**: -- `src/xrpld/consensus/Consensus.h` — `haveConsensus()` and `updateOurPositions()` methods +- `src/xrpld/consensus/Consensus.h` — `haveConsensus()` method --- -## Task 4a.7: Instrument Mode Changes +## Task 4a.7: Instrument Mode Changes ✅ **Objective**: Trace consensus mode transitions (proposing ↔ observing, wrongLedger, switchedLedger). -**What to do**: +**Status**: Done. -Mode changes are rare (typically 0-1 per round), so a **standalone short-lived -span** is appropriate (not an event). This captures timing of the mode change -itself. +**What was done**: -- In `RCLConsensus::Adaptor::onModeChange()`, create a scoped span: +- In `RCLConsensus::Adaptor::onModeChange()`, creates a scoped span via direct + `SpanGuard::span()` call: ```cpp - XRPL_TRACE_CONSENSUS(app_.getTelemetry(), "consensus.mode_change"); - XRPL_TRACE_SET_ATTR("xrpl.consensus.mode.old", to_string(before).c_str()); - XRPL_TRACE_SET_ATTR("xrpl.consensus.mode.new", to_string(after).c_str()); + auto span = telemetry::SpanGuard::span( + telemetry::TraceCategory::Consensus, telemetry::seg::consensus, "mode_change"); + span.setAttribute(cons_span::attr::modeOld, to_string(before).c_str()); + span.setAttribute(cons_span::attr::modeNew, to_string(after).c_str()); ``` -- Note: `MonitoredMode::set()` (line 304 in `Consensus.h`) calls - `adaptor_.onModeChange(before, after)` — so the span is created in the - adaptor, which already has telemetry access. No instrumentation needed - in `Consensus.h` for this task. +- `MonitoredMode::set()` in `Consensus.h` calls `adaptor_.onModeChange(before, after)`. **Key modified files**: @@ -740,31 +699,36 @@ itself. --- -## Task 4a.8: Reparent Existing Spans Under Round +## Task 4a.8: Reparent Existing Spans Under Round ✅ **Objective**: Make existing consensus spans (`consensus.accept`, `consensus.accept.apply`, `consensus.validation.send`) children of the `consensus.round` root span instead of being standalone. -**What to do**: +**Status**: DONE. All three spans are now parented under the round span. -- The existing spans in `onAccept()`, `doAccept()`, and `validate()` use - `XRPL_TRACE_CONSENSUS(app_.getTelemetry(), ...)` which creates standalone - spans on the current thread's context. -- After Task 4a.2 creates the round span and stores it, these methods run on - the same thread within the round span's scope, so they automatically become - children. Verify this works correctly. -- For `consensus.validation.send`: add a **span link** (follows-from) to the - round span context, since the validation may be processed after the round - completes. +**What was done**: + +- `consensus.validation.send` uses `SpanGuard::linkedSpan()` to create a + follows-from link to `roundSpanContext_`. This is thread-safe because + `roundSpanContext_` is a lightweight `SpanContext` snapshot captured on the + consensus thread and read on the jtACCEPT worker thread. + +- `consensus.accept` and `consensus.accept.apply` now use + `SpanGuard::childSpan(name, roundSpanContext_)` instead of `SpanGuard::span()` + to explicitly parent under the round span context. This solves the cross-thread + parenting problem: + - `doAccept()` runs on the jtACCEPT worker thread (not the consensus thread) + - `childSpan()` explicitly passes the parent context, bypassing OTel's + thread-local context propagation **Key modified files**: -- `src/xrpld/app/consensus/RCLConsensus.cpp` — verify parent-child hierarchy +- `src/xrpld/app/consensus/RCLConsensus.cpp` --- -## Task 4a.9: Build Verification and Testing +## Task 4a.9: Build Verification and Testing ✅ **Objective**: Verify all Phase 4a changes compile cleanly with telemetry ON and OFF, and don't affect consensus timing. @@ -772,11 +736,9 @@ and OFF, and don't affect consensus timing. **What to do**: 1. Build with `telemetry=ON` — verify no compilation errors -2. Build with `telemetry=OFF` — verify macros expand to no-ops, no new includes - leak into `Consensus.h` when disabled +2. Build with `telemetry=OFF` — verify `SpanGuard` compiles to no-ops 3. Run existing consensus unit tests -4. Verify `#ifdef XRPL_ENABLE_TELEMETRY` guards on all new members in - `Consensus.h` +4. Verify `SpanGuard` / `SpanContext` members have negligible overhead when disabled 5. Run `pccl` pre-commit checks **Verification Checklist**: @@ -784,7 +746,7 @@ and OFF, and don't affect consensus timing. - [x] Build succeeds with telemetry ON - [x] Build succeeds with telemetry OFF - [x] Existing consensus tests pass -- [x] `Consensus.h` has zero OTel includes when telemetry is OFF +- [x] `SpanGuard` no-op path verified (no `#ifdef` needed — disabled at runtime) - [x] No new virtual calls in hot consensus paths - [x] `pccl` passes @@ -792,74 +754,91 @@ and OFF, and don't affect consensus timing. ## Phase 4a Summary -| Task | Description | New Files | Modified Files | Depends On | -| ---- | ------------------------------------------------ | --------- | -------------- | ---------- | -| 4a.0 | Prerequisites: extend SpanGuard & Telemetry APIs | 0 | 4 | Phase 4 | -| 4a.1 | Adaptor `getTelemetry()` method | 0 | 2 | Phase 4 | -| 4a.2 | Switchable round span with deterministic traceID | 1 | 3 | 4a.0, 4a.1 | -| 4a.3 | Span members in `Consensus.h` | 0 | 1 | 4a.1 | -| 4a.4 | Instrument `phaseEstablish()` | 0 | 1 | 4a.3 | -| 4a.5 | Instrument `updateOurPositions()` | 0 | 1 | 4a.0, 4a.3 | -| 4a.6 | Instrument `haveConsensus()` (thresholds) | 0 | 1 | 4a.3 | -| 4a.7 | Instrument mode changes | 0 | 1 | 4a.1 | -| 4a.8 | Reparent existing spans under round | 0 | 1 | 4a.0, 4a.2 | -| 4a.9 | Build verification and testing | 0 | 0 | 4a.0-4a.8 | +| Task | Description | Status | New Files | Modified Files | Depends On | +| ---- | ------------------------------------------------ | ------------------------ | --------- | -------------- | ---------- | +| 4a.0 | Prerequisites: extend SpanGuard & Telemetry APIs | ✅ Done (no macros) | 0 | 2 | Phase 4 | +| 4a.1 | Adaptor `getTelemetry()` method | ⏭️ Skipped (not needed) | 0 | 0 | Phase 4 | +| 4a.2 | Switchable round span with deterministic traceID | ✅ Done | 1 | 3 | 4a.0 | +| 4a.3 | Span members in `Consensus.h` | ✅ Done (with deviation) | 0 | 2 | — | +| 4a.4 | Instrument `phaseEstablish()` | ✅ Done | 0 | 1 | 4a.3 | +| 4a.5 | Instrument `updateOurPositions()` | ✅ Done | 0 | 2 | 4a.0, 4a.3 | +| 4a.6 | Instrument `haveConsensus()` (thresholds) | ✅ Done | 0 | 1 | 4a.3 | +| 4a.7 | Instrument mode changes | ✅ Done | 0 | 1 | — | +| 4a.8 | Reparent existing spans under round | ✅ Done | 0 | 1 | 4a.0, 4a.2 | +| 4a.9 | Build verification and testing | ✅ Done | 0 | 0 | 4a.0-4a.8 | **Parallel work**: Tasks 4a.0 and 4a.1 can run in parallel. Tasks 4a.4, 4a.5, 4a.6, and 4a.7 can run in parallel after 4a.3 (and 4a.0 for 4a.5). ### New Spans (Phase 4a) -| Span Name | Location | Key Attributes | -| ---------------------------- | ------------------ | ---------------------------------------------------------------------------------- | -| `consensus.round` | `RCLConsensus.cpp` | `round_id`, `ledger_id`, `ledger.seq`, `mode`; link → prev round | -| `consensus.establish` | `Consensus.h` | `converge_percent`, `establish_count`, `proposers` | -| `consensus.update_positions` | `Consensus.h` | `disputes_count`, `converge_percent`, `proposers_agreed`, `proposers_total` | -| `consensus.check` | `Consensus.h` | `agree_count`, `disagree_count`, `converge_percent`, `result`, `threshold_percent` | -| `consensus.mode_change` | `RCLConsensus.cpp` | `mode.old`, `mode.new` | +| Span Name | Location | Key Attributes (actually set) | +| ---------------------------- | ------------------ | ----------------------------------------------------------------------------------------------------------------------------- | +| `consensus.round` | `RCLConsensus.cpp` | `round_id`, `ledger_id`, `ledger.seq`, `mode`, `trace_strategy` | +| `consensus.establish` | `Consensus.h` | `converge_percent`, `establish_count`, `proposers` | +| `consensus.update_positions` | `Consensus.h` | `converge_percent`, `proposers`, `have_close_time_consensus`, `close_time_threshold`, `disputes_count`, `avalanche_threshold` | +| `consensus.check` | `Consensus.h` | `agree_count`, `disagree_count`, `converge_percent`, `have_close_time_consensus`, `threshold_percent`, `result` | +| `consensus.mode_change` | `RCLConsensus.cpp` | `mode.old`, `mode.new` | ### New Events (Phase 4a) -| Event Name | Parent Span | Attributes | +| Event Name | Parent Span | Attributes (actually set) | | ----------------- | ---------------------------- | ----------------------------------- | | `dispute.resolve` | `consensus.update_positions` | `tx_id`, `our_vote`, `yays`, `nays` | +| `tx.included` | `consensus.accept.apply` | `tx_id` | ### New Attributes (Phase 4a) ```cpp -// Round-level (on consensus.round) +// Round-level (on consensus.round) — ALL IMPLEMENTED "xrpl.consensus.round_id" = int64 // Consensus round number "xrpl.consensus.ledger_id" = string // previousLedger.id() hash "xrpl.consensus.trace_strategy" = string // "deterministic" or "attribute" -// Establish-level +// Establish-level — IMPLEMENTED "xrpl.consensus.converge_percent" = int64 // Convergence % (0-100+) "xrpl.consensus.establish_count" = int64 // Number of establish iterations -"xrpl.consensus.disputes_count" = int64 // Active disputes -"xrpl.consensus.proposers_agreed" = int64 // Peers agreeing with us -"xrpl.consensus.proposers_total" = int64 // Total peer positions "xrpl.consensus.agree_count" = int64 // Peers that agree (haveConsensus) "xrpl.consensus.disagree_count" = int64 // Peers that disagree -"xrpl.consensus.threshold_percent" = int64 // Current threshold (50/65/70/95) +"xrpl.consensus.threshold_percent" = int64 // Current threshold (avCT_CONSENSUS_PCT = 75%) "xrpl.consensus.result" = string // "yes", "no", "moved_on" +"xrpl.consensus.have_close_time_consensus" = bool // Close time consensus reached +"xrpl.consensus.close_time_threshold" = int64 // Close time voting threshold -// Mode change +// Establish-level — IMPLEMENTED +"xrpl.consensus.disputes_count" = int64 // Active disputes (on update_positions) +"xrpl.consensus.avalanche_threshold" = int64 // Escalated weight (on update_positions) + +// Establish-level — NOT IMPLEMENTED +// "xrpl.consensus.proposers_agreed" = int64 // Peers agreeing with us — not set +// "xrpl.consensus.proposers_total" = int64 // Total peer positions — not set (not defined) + +// Mode change — ALL IMPLEMENTED "xrpl.consensus.mode.old" = string // Previous mode "xrpl.consensus.mode.new" = string // New mode ``` ### Implementation Notes +- **No macros**: The planned `XRPL_TRACE_CONSENSUS`, `XRPL_TRACE_ADD_EVENT`, and + `XRPL_TRACE_SET_ATTR` macros were not implemented. All consensus tracing uses + `SpanGuard` factory methods (`span()`, `hashSpan()`, `linkedSpan()`) and direct + method calls (`setAttribute()`, `addEvent()`). This avoids macro control-flow + issues and is cleaner than the planned approach. - **Separation of concerns**: All non-trivial telemetry code extracted to private helpers (`startRoundTracing`, `createValidationSpan`, `startEstablishTracing`, `updateEstablishTracing`, `endEstablishTracing`). Business logic methods contain - only single-line `#ifdef` blocks calling these helpers. + single-line calls to these helpers. - **Thread safety**: `createValidationSpan()` runs on the jtACCEPT worker thread. Instead of accessing `roundSpan_` across threads, a `roundSpanContext_` snapshot (lightweight `SpanContext` value type) is captured on the consensus thread in `startRoundTracing()` and read by `createValidationSpan()`. The job queue provides the happens-before guarantee. -- **Macro safety**: `XRPL_TRACE_ADD_EVENT` uses `do { } while (0)` to prevent - dangling-else issues. +- **No `#ifdef` guards**: Span members use `std::optional` and `SpanContext` + which have no-op implementations when telemetry is disabled. No `#ifdef XRPL_ENABLE_TELEMETRY` + guards needed around members or includes. +- **No `getTelemetry()` adaptor method**: `SpanGuard::span()` is a static factory that + internally checks telemetry state, so `Consensus.h` doesn't need adaptor access + for span creation. Only `RCLConsensus::Adaptor` accesses `app_.getTelemetry()` directly. - **Config validation**: `consensus_trace_strategy` is validated to be either `"deterministic"` or `"attribute"`, falling back to `"deterministic"` for unrecognised values. @@ -924,6 +903,6 @@ share the same trace_id. P2P propagation adds **span-level** linking: ## Prerequisites - Phase 4a (this task list) — establish phase tracing must be in place -- `TraceContextPropagator` class (already exists in +- `TraceContextPropagator` free functions (already exist in `include/xrpl/telemetry/TraceContextPropagator.h`) - Protobuf `TraceContext` message (already exists, field 1001) diff --git a/OpenTelemetryPlan/Phase5_IntegrationTest_taskList.md b/OpenTelemetryPlan/Phase5_IntegrationTest_taskList.md index 28f45afc75..b8d4ea3a38 100644 --- a/OpenTelemetryPlan/Phase5_IntegrationTest_taskList.md +++ b/OpenTelemetryPlan/Phase5_IntegrationTest_taskList.md @@ -178,7 +178,7 @@ Tempo/Prometheus. **Verification**: - [ ] Script completes with all checks passing -- [ ] Tempo UI shows rippled service with all expected span names +- [ ] Tempo UI shows xrpld service with all expected span names - [ ] Grafana dashboards load and show data --- diff --git a/OpenTelemetryPlan/Phase5_taskList.md b/OpenTelemetryPlan/Phase5_taskList.md index 644c842e40..c2d0aa9c60 100644 --- a/OpenTelemetryPlan/Phase5_taskList.md +++ b/OpenTelemetryPlan/Phase5_taskList.md @@ -175,7 +175,7 @@ **What to do**: - Create `docs/telemetry-runbook.md`: - - **Setup**: How to enable telemetry in rippled + - **Setup**: How to enable telemetry in xrpld - **Configuration**: All config options with descriptions - **Collector Deployment**: Docker Compose vs. Kubernetes vs. bare metal - **Troubleshooting**: Common issues and resolutions @@ -199,7 +199,7 @@ **What to do**: 1. Start full Docker stack (Collector, Tempo, Grafana, Prometheus) -2. Build rippled with `telemetry=ON` +2. Build xrpld with `telemetry=ON` 3. Run in standalone mode with telemetry enabled 4. Generate RPC traffic and verify traces in Tempo 5. Verify dashboards populate in Grafana diff --git a/docker/telemetry/integration-test.sh b/docker/telemetry/integration-test.sh index 1a48aa324a..70cd018127 100755 --- a/docker/telemetry/integration-test.sh +++ b/docker/telemetry/integration-test.sh @@ -433,18 +433,8 @@ seq_num=$(echo "$acct_result" | jq -r '.result.account_data.Sequence' 2>/dev/nul 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\" - } - }] -}") +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\"}}]}") 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") diff --git a/include/xrpl/telemetry/Telemetry.h b/include/xrpl/telemetry/Telemetry.h index c74fc3bb7b..92f87f7a70 100644 --- a/include/xrpl/telemetry/Telemetry.h +++ b/include/xrpl/telemetry/Telemetry.h @@ -85,8 +85,7 @@ #include #endif -namespace xrpl { -namespace telemetry { +namespace xrpl::telemetry { class Telemetry { @@ -229,27 +228,27 @@ public: stop() = 0; /** @return true if this instance is actively exporting spans. */ - virtual bool + [[nodiscard]] virtual bool isEnabled() const = 0; /** @return true if transaction processing should be traced. */ - virtual bool + [[nodiscard]] virtual bool shouldTraceTransactions() const = 0; /** @return true if consensus rounds should be traced. */ - virtual bool + [[nodiscard]] virtual bool shouldTraceConsensus() const = 0; /** @return true if RPC request handling should be traced. */ - virtual bool + [[nodiscard]] virtual bool shouldTraceRpc() const = 0; /** @return true if peer-to-peer messages should be traced. */ - virtual bool + [[nodiscard]] virtual bool shouldTracePeer() const = 0; /** @return true if ledger close/accept should be traced. */ - virtual bool + [[nodiscard]] virtual bool shouldTraceLedger() const = 0; /** @return The configured consensus trace correlation strategy. */ @@ -329,5 +328,4 @@ setup_Telemetry( std::string const& version, std::uint32_t networkId); -} // namespace telemetry -} // namespace xrpl +} // namespace xrpl::telemetry diff --git a/src/libxrpl/telemetry/NullTelemetry.cpp b/src/libxrpl/telemetry/NullTelemetry.cpp index 51c134075e..a957330a1a 100644 --- a/src/libxrpl/telemetry/NullTelemetry.cpp +++ b/src/libxrpl/telemetry/NullTelemetry.cpp @@ -10,14 +10,17 @@ its own factory that can return the real TelemetryImpl. */ +#include #include #ifdef XRPL_ENABLE_TELEMETRY #include #endif -namespace xrpl { -namespace telemetry { +#include +#include + +namespace xrpl::telemetry { namespace { @@ -32,7 +35,7 @@ class NullTelemetry : public Telemetry Setup const setup_; public: - explicit NullTelemetry(Setup const& setup) : setup_(setup) + explicit NullTelemetry(Setup setup) : setup_(std::move(setup)) { } @@ -48,37 +51,37 @@ public: Telemetry::setInstance(nullptr); } - bool + [[nodiscard]] bool isEnabled() const override { return false; } - bool + [[nodiscard]] bool shouldTraceTransactions() const override { return false; } - bool + [[nodiscard]] bool shouldTraceConsensus() const override { return false; } - bool + [[nodiscard]] bool shouldTraceRpc() const override { return false; } - bool + [[nodiscard]] bool shouldTracePeer() const override { return false; } - bool + [[nodiscard]] bool shouldTraceLedger() const override { return false; @@ -131,5 +134,4 @@ make_Telemetry(Telemetry::Setup const& setup, beast::Journal) } #endif -} // namespace telemetry -} // namespace xrpl +} // namespace xrpl::telemetry diff --git a/src/libxrpl/telemetry/SpanGuard.cpp b/src/libxrpl/telemetry/SpanGuard.cpp index cf434e2e1a..c8673e6b08 100644 --- a/src/libxrpl/telemetry/SpanGuard.cpp +++ b/src/libxrpl/telemetry/SpanGuard.cpp @@ -27,6 +27,7 @@ #include #include +#include #include #include #include @@ -376,12 +377,11 @@ SpanGuard::addEvent(std::string_view name, std::initializer_list { if (!impl_) return; - // Own the strings to ensure lifetime safety through the AddEvent call. - std::vector> owned; - owned.reserve(attrs.size()); + std::vector> otelAttrs; + otelAttrs.reserve(attrs.size()); for (auto const& [k, v] : attrs) - owned.emplace_back(std::string(k), std::string(v)); - impl_->span->AddEvent(std::string(name), owned); + otelAttrs.emplace_back(k, opentelemetry::common::AttributeValue{v}); + impl_->span->AddEvent(std::string(name), otelAttrs); } void diff --git a/src/libxrpl/telemetry/TelemetryConfig.cpp b/src/libxrpl/telemetry/TelemetryConfig.cpp index be93476ae3..0f4894556d 100644 --- a/src/libxrpl/telemetry/TelemetryConfig.cpp +++ b/src/libxrpl/telemetry/TelemetryConfig.cpp @@ -7,12 +7,14 @@ See cfg/xrpld-example.cfg for the full list of available options. */ +#include #include #include +#include +#include -namespace xrpl { -namespace telemetry { +namespace xrpl::telemetry { namespace { @@ -81,5 +83,4 @@ setup_Telemetry( return setup; } -} // namespace telemetry -} // namespace xrpl +} // namespace xrpl::telemetry diff --git a/src/tests/libxrpl/telemetry/SpanGuardFactory.cpp b/src/tests/libxrpl/telemetry/SpanGuardFactory.cpp index 59ea205a69..d09220b778 100644 --- a/src/tests/libxrpl/telemetry/SpanGuardFactory.cpp +++ b/src/tests/libxrpl/telemetry/SpanGuardFactory.cpp @@ -8,7 +8,7 @@ using namespace xrpl::telemetry; TEST(SpanGuardFactory, null_guard_methods_are_safe) { - auto span = SpanGuard::span("nonexistent.span"); + auto span = SpanGuard::span(TraceCategory::Rpc, "rpc", "nonexistent"); EXPECT_FALSE(span); span.setAttribute("key", "value"); @@ -30,28 +30,28 @@ TEST(SpanGuardFactory, category_span_returns_null_when_disabled) TEST(SpanGuardFactory, child_span_null_when_no_parent) { - auto span = SpanGuard::span("parent.test"); + auto span = SpanGuard::span(TraceCategory::Rpc, "rpc", "parent"); auto child = span.childSpan("child.test"); EXPECT_FALSE(child); } TEST(SpanGuardFactory, linked_span_null_when_no_context) { - auto span = SpanGuard::span("source.test"); + auto span = SpanGuard::span(TraceCategory::Rpc, "rpc", "source"); auto linked = span.linkedSpan("linked.test"); EXPECT_FALSE(linked); } TEST(SpanGuardFactory, capture_context_returns_invalid_on_null) { - auto span = SpanGuard::span("ctx.test"); + auto span = SpanGuard::span(TraceCategory::Rpc, "rpc", "ctx"); auto ctx = span.captureContext(); EXPECT_FALSE(ctx.isValid()); } TEST(SpanGuardFactory, move_construction_transfers_ownership) { - auto span = SpanGuard::span("move.test"); + auto span = SpanGuard::span(TraceCategory::Rpc, "rpc", "move"); auto moved = std::move(span); EXPECT_FALSE(span); moved.setAttribute("key", "value"); diff --git a/src/xrpld/app/consensus/RCLConsensus.cpp b/src/xrpld/app/consensus/RCLConsensus.cpp index 13e9dea6b5..967202ee60 100644 --- a/src/xrpld/app/consensus/RCLConsensus.cpp +++ b/src/xrpld/app/consensus/RCLConsensus.cpp @@ -1,4 +1,3 @@ -#include #include #include @@ -19,6 +18,7 @@ #include #include #include +#include #include #include #include @@ -227,7 +227,9 @@ void RCLConsensus::Adaptor::propose(RCLCxPeerPos::Proposal const& proposal) { auto span = telemetry::SpanGuard::span( - telemetry::TraceCategory::Consensus, telemetry::seg::consensus, "proposal.send"); + telemetry::TraceCategory::Consensus, + telemetry::seg::consensus, + telemetry::cons_span::op::proposalSend); span.setAttribute( telemetry::cons_span::attr::round, static_cast(proposal.proposeSeq())); @@ -334,7 +336,9 @@ RCLConsensus::Adaptor::onClose( ConsensusMode mode) -> Result { auto span = telemetry::SpanGuard::span( - telemetry::TraceCategory::Consensus, telemetry::seg::consensus, "ledger_close"); + telemetry::TraceCategory::Consensus, + telemetry::seg::consensus, + telemetry::cons_span::op::ledgerClose); span.setAttribute( telemetry::cons_span::attr::ledgerSeq, static_cast(ledger.ledger_->header().seq + 1)); @@ -435,7 +439,15 @@ RCLConsensus::Adaptor::onForceAccept( ConsensusMode const& mode, Json::Value&& consensusJson) { - doAccept(result, prevLedger, closeResolution, rawCloseTimes, mode, std::move(consensusJson)); + auto acceptSpan = makeAcceptSpan(result); + doAccept( + result, + prevLedger, + closeResolution, + rawCloseTimes, + mode, + std::move(consensusJson), + std::move(acceptSpan)); } void @@ -448,34 +460,46 @@ RCLConsensus::Adaptor::onAccept( Json::Value&& consensusJson, bool const validating) { - { - auto span = telemetry::SpanGuard::span( - telemetry::TraceCategory::Consensus, telemetry::seg::consensus, "accept"); - span.setAttribute( - telemetry::cons_span::attr::proposers, static_cast(result.proposers)); - span.setAttribute( - telemetry::cons_span::attr::roundTimeMs, - static_cast(result.roundTime.read().count())); - span.setAttribute( - telemetry::cons_span::attr::quorum, static_cast(result.proposers)); - } + auto acceptSpan = makeAcceptSpan(result); app_.getJobQueue().addJob( jtACCEPT, "AcceptLedger", // NOLINTNEXTLINE(cppcoreguidelines-misleading-capture-default-by-value) - [=, this, cj = std::move(consensusJson)]() mutable { + [=, this, cj = std::move(consensusJson), sp = std::move(acceptSpan)]() mutable { // Note that no lock is held or acquired during this job. // This is because generic Consensus guarantees that once a ledger // is accepted, the consensus results and capture by reference state // will not change until startRound is called (which happens via // endConsensus). RclConsensusLogger clog("onAccept", validating, j_); - this->doAccept(result, prevLedger, closeResolution, rawCloseTimes, mode, std::move(cj)); + this->doAccept( + result, + prevLedger, + closeResolution, + rawCloseTimes, + mode, + std::move(cj), + std::move(sp)); this->app_.getOPs().endConsensus(clog.ss()); }); } +std::shared_ptr +RCLConsensus::Adaptor::makeAcceptSpan(Result const& result) +{ + auto span = std::make_shared( + telemetry::SpanGuard::childSpan(telemetry::cons_span::accept, roundSpanContext_)); + span->setAttribute( + telemetry::cons_span::attr::proposers, static_cast(result.proposers)); + span->setAttribute( + telemetry::cons_span::attr::roundTimeMs, + static_cast(result.roundTime.read().count())); + span->setAttribute( + telemetry::cons_span::attr::quorum, static_cast(app_.getValidators().quorum())); + return span; +} + void RCLConsensus::Adaptor::doAccept( Result const& result, @@ -483,7 +507,8 @@ RCLConsensus::Adaptor::doAccept( NetClock::duration closeResolution, ConsensusCloseTimes const& rawCloseTimes, ConsensusMode const& mode, - Json::Value&& consensusJson) + Json::Value&& consensusJson, + std::shared_ptr acceptSpan) { prevProposers_ = result.proposers; prevRoundTime_ = result.roundTime.read(); @@ -511,8 +536,9 @@ RCLConsensus::Adaptor::doAccept( closeTimeCorrect = true; } - auto doAcceptSpan = telemetry::SpanGuard::span( - telemetry::TraceCategory::Consensus, telemetry::seg::consensus, "accept.apply"); + auto doAcceptSpan = acceptSpan + ? acceptSpan->childSpan(telemetry::cons_span::acceptApply) + : telemetry::SpanGuard::childSpan(telemetry::cons_span::acceptApply, roundSpanContext_); doAcceptSpan.setAttribute( telemetry::cons_span::attr::ledgerSeq, static_cast(prevLedger.seq() + 1)); doAcceptSpan.setAttribute( @@ -563,12 +589,18 @@ RCLConsensus::Adaptor::doAccept( JLOG(j_.debug()) << "Building canonical tx set: " << retriableTxs.key(); + int64_t txCount = 0; for (auto const& item : *result.txns.map_) { try { retriableTxs.insert(std::make_shared(SerialIter{item.slice()})); JLOG(j_.debug()) << " Tx: " << item.key(); + ++txCount; + auto const txHash = to_string(item.key()); + doAcceptSpan.addEvent( + telemetry::cons_span::event::txIncluded, + {{telemetry::cons_span::attr::txId, txHash}}); } catch (std::exception const& ex) { @@ -576,6 +608,7 @@ RCLConsensus::Adaptor::doAccept( JLOG(j_.warn()) << " Tx: " << item.key() << " throws: " << ex.what(); } } + doAcceptSpan.setAttribute(telemetry::cons_span::attr::txCount, txCount); auto built = buildLCL( prevLedger, @@ -959,9 +992,11 @@ void RCLConsensus::Adaptor::onModeChange(ConsensusMode before, ConsensusMode after) { auto span = telemetry::SpanGuard::span( - telemetry::TraceCategory::Consensus, telemetry::seg::consensus, "mode_change"); - span.setAttribute(telemetry::cons_span::attr::modeOld, toDisplayString(before).c_str()); - span.setAttribute(telemetry::cons_span::attr::modeNew, toDisplayString(after).c_str()); + telemetry::TraceCategory::Consensus, + telemetry::seg::consensus, + telemetry::cons_span::op::modeChange); + span.setAttribute(telemetry::cons_span::attr::modeOld, to_string(before).c_str()); + span.setAttribute(telemetry::cons_span::attr::modeNew, to_string(after).c_str()); JLOG(j_.info()) << "Consensus mode change before=" << to_string(before) << ", after=" << to_string(after); @@ -1136,10 +1171,7 @@ RCLConsensus::Adaptor::startRoundTracing(RCLCxLedger const& prevLgr) using namespace telemetry; if (roundSpan_) - { - prevRoundContext_ = roundSpan_->captureContext(); roundSpan_.reset(); - } auto const& strategy = app_.getTelemetry().getConsensusTraceStrategy(); @@ -1154,7 +1186,8 @@ RCLConsensus::Adaptor::startRoundTracing(RCLCxLedger const& prevLgr) } else { - roundSpan_.emplace(SpanGuard::span(TraceCategory::Consensus, seg::consensus, "round")); + roundSpan_.emplace( + SpanGuard::span(TraceCategory::Consensus, seg::consensus, cons_span::op::round)); } if (!*roundSpan_) diff --git a/src/xrpld/app/consensus/RCLConsensus.h b/src/xrpld/app/consensus/RCLConsensus.h index c3e804332c..63e440a24b 100644 --- a/src/xrpld/app/consensus/RCLConsensus.h +++ b/src/xrpld/app/consensus/RCLConsensus.h @@ -79,13 +79,6 @@ class RCLConsensus */ std::optional roundSpan_; - /** Context captured from the previous consensus round. - * - * Used to create span links (follows-from) between consecutive - * rounds, establishing a causal chain in the trace backend. - */ - telemetry::SpanContext prevRoundContext_; - /** SpanContext snapshot of the current round span. * * Captured in startRoundTracing() as a lightweight value-type copy @@ -374,8 +367,17 @@ class RCLConsensus void notify(protocol::NodeEvent ne, RCLCxLedger const& ledger, bool haveCorrectLCL); + /** Create a consensus.accept span as a child of the round span. + Returned via shared_ptr so it can be captured into the + jtACCEPT lambda and live until doAccept completes. + */ + std::shared_ptr + makeAcceptSpan(Result const& result); + /** Accept a new ledger based on the given transactions. + @param acceptSpan Parent span created by makeAcceptSpan(); + accept.apply is created as its child. @ref onAccept */ void @@ -385,7 +387,8 @@ class RCLConsensus NetClock::duration closeResolution, ConsensusCloseTimes const& rawCloseTimes, ConsensusMode const& mode, - Json::Value&& consensusJson); + Json::Value&& consensusJson, + std::shared_ptr acceptSpan); /** Build the new last closed ledger. diff --git a/src/xrpld/app/main/Application.cpp b/src/xrpld/app/main/Application.cpp index bc55d22d0f..cad96f382b 100644 --- a/src/xrpld/app/main/Application.cpp +++ b/src/xrpld/app/main/Application.cpp @@ -82,6 +82,7 @@ #include #include #include +#include #include #include #include diff --git a/src/xrpld/app/misc/NetworkOPs.cpp b/src/xrpld/app/misc/NetworkOPs.cpp index d75de3344e..17972c8fa6 100644 --- a/src/xrpld/app/misc/NetworkOPs.cpp +++ b/src/xrpld/app/misc/NetworkOPs.cpp @@ -172,9 +172,16 @@ class NetworkOPsImp final : public NetworkOPs FailHard const failType; bool applied = false; TER result; + /// Keeps the tx.process span alive until the batch processes this entry. + std::shared_ptr span; - TransactionStatus(std::shared_ptr t, bool a, bool l, FailHard f) - : transaction(std::move(t)), admin(a), local(l), failType(f) + TransactionStatus( + std::shared_ptr t, + bool a, + bool l, + FailHard f, + std::shared_ptr s = nullptr) + : transaction(std::move(t)), admin(a), local(l), failType(f), span(std::move(s)) { XRPL_ASSERT( local || failType == FailHard::no, @@ -397,7 +404,8 @@ public: doTransactionAsync( std::shared_ptr transaction, bool bUnlimited, - FailHard failtype); + FailHard failtype, + std::shared_ptr span = nullptr); private: bool @@ -1315,9 +1323,9 @@ NetworkOPsImp::processTransaction( FailHard failType) { using namespace telemetry; - auto span = txProcessSpan(transaction->getID()); - span.setAttribute(tx_span::attr::hash, to_string(transaction->getID()).c_str()); - span.setAttribute(tx_span::attr::local, bLocal); + auto span = std::make_shared(txProcessSpan(transaction->getID())); + span->setAttribute(tx_span::attr::hash, to_string(transaction->getID()).c_str()); + span->setAttribute(tx_span::attr::local, bLocal); auto ev = m_job_queue.makeLoadEvent(jtTXN_PROC, "ProcessTXN"); @@ -1327,13 +1335,13 @@ NetworkOPsImp::processTransaction( if (bLocal) { - span.setAttribute(tx_span::attr::path, tx_span::val::sync); + span->setAttribute(tx_span::attr::path, tx_span::val::sync); doTransactionSync(transaction, bUnlimited, failType); } else { - span.setAttribute(tx_span::attr::path, tx_span::val::async); - doTransactionAsync(transaction, bUnlimited, failType); + span->setAttribute(tx_span::attr::path, tx_span::val::async); + doTransactionAsync(transaction, bUnlimited, failType, std::move(span)); } } @@ -1341,14 +1349,15 @@ void NetworkOPsImp::doTransactionAsync( std::shared_ptr transaction, bool bUnlimited, - FailHard failType) + FailHard failType, + std::shared_ptr span) { std::lock_guard const lock(mMutex); if (transaction->getApplying()) return; - mTransactions.emplace_back(transaction, bUnlimited, false, failType); + mTransactions.emplace_back(transaction, bUnlimited, false, failType, std::move(span)); transaction->setApplying(); if (mDispatchState == DispatchState::none) diff --git a/src/xrpld/app/misc/detail/TxQ.cpp b/src/xrpld/app/misc/detail/TxQ.cpp index 51a5e1e386..32842ab9ad 100644 --- a/src/xrpld/app/misc/detail/TxQ.cpp +++ b/src/xrpld/app/misc/detail/TxQ.cpp @@ -1,8 +1,8 @@ #include -#include #include #include +#include #include #include diff --git a/src/xrpld/consensus/Consensus.h b/src/xrpld/consensus/Consensus.h index 446c6be0a0..a32cdd2c0c 100644 --- a/src/xrpld/consensus/Consensus.h +++ b/src/xrpld/consensus/Consensus.h @@ -1,8 +1,8 @@ #pragma once -#include #include #include +#include #include #include @@ -609,6 +609,11 @@ private: */ std::optional establishSpan_; + /** Span for the open phase of consensus. + * Created in startRoundInternal(); cleared (ended) in closeLedger(). + */ + std::optional openSpan_; + /** Create the establish-phase span if not yet active. * Called on each phaseEstablish() invocation; no-op while span is live. */ @@ -695,6 +700,11 @@ Consensus::startRoundInternal( CLOG(clog) << "startRoundInternal transitioned to ConsensusPhase::open, " "previous ledgerID: " << prevLedgerID << ", seq: " << prevLedger.seq() << ". "; + openSpan_.emplace( + telemetry::SpanGuard::span( + telemetry::TraceCategory::Consensus, + telemetry::seg::consensus, + telemetry::cons_span::op::phaseOpen)); mode_.set(mode, adaptor_); now_ = now; prevLedgerID_ = prevLedgerID; @@ -1420,6 +1430,7 @@ Consensus::closeLedger(std::unique_ptr const& clog) // We should not be closing if we already have a position XRPL_ASSERT(!result_, "xrpl::Consensus::closeLedger : result is not set"); + openSpan_.reset(); phase_ = ConsensusPhase::establish; JLOG(j_.debug()) << "transitioned to ConsensusPhase::establish"; rawCloseTimes_.self = now_; @@ -1477,9 +1488,12 @@ Consensus::updateOurPositions(std::unique_ptr const& XRPL_ASSERT(result_, "xrpl::Consensus::updateOurPositions : result is set"); // NOLINTBEGIN(bugprone-unchecked-optional-access) assert above using namespace telemetry; - auto span = SpanGuard::span(TraceCategory::Consensus, seg::consensus, "update_positions"); + auto span = + SpanGuard::span(TraceCategory::Consensus, seg::consensus, cons_span::op::updatePositions); span.setAttribute(cons_span::attr::convergePercent, static_cast(convergePercent_)); span.setAttribute(cons_span::attr::proposers, static_cast(currPeerPositions_.size())); + span.setAttribute( + cons_span::attr::disputesCount, static_cast(result_->disputes.size())); ConsensusParms const& parms = adaptor_.parms(); // Compute a cutoff time @@ -1540,10 +1554,14 @@ Consensus::updateOurPositions(std::unique_ptr const& mutableSet->erase(txId); } + auto const yaysStr = std::to_string(dispute.getYays()); + auto const naysStr = std::to_string(dispute.getNays()); span.addEvent( - "dispute.resolve", + cons_span::event::disputeResolve, {{cons_span::attr::txId, to_string(txId)}, - {cons_span::attr::disputeOurVote, dispute.getOurVote() ? "yes" : "no"}}); + {cons_span::attr::disputeOurVote, dispute.getOurVote() ? "yes" : "no"}, + {cons_span::attr::disputeYays, yaysStr}, + {cons_span::attr::disputeNays, naysStr}}); } } @@ -1568,6 +1586,7 @@ Consensus::updateOurPositions(std::unique_ptr const& if (newState) closeTimeAvalancheState_ = *newState; CLOG(clog) << "neededWeight " << neededWeight << ". "; + span.setAttribute(cons_span::attr::avalancheThreshold, static_cast(neededWeight)); int participants = currPeerPositions_.size(); if (mode_.get() == ConsensusMode::proposing) @@ -1672,7 +1691,7 @@ Consensus::haveConsensus(std::unique_ptr const& clog XRPL_ASSERT(result_, "xrpl::Consensus::haveConsensus : has result"); // NOLINTBEGIN(bugprone-unchecked-optional-access) assert above using namespace telemetry; - auto span = SpanGuard::span(TraceCategory::Consensus, seg::consensus, "check"); + auto span = SpanGuard::span(TraceCategory::Consensus, seg::consensus, cons_span::op::check); // CHECKME: should possibly count unacquired TX sets as disagreeing int agree = 0, disagree = 0; @@ -1785,6 +1804,8 @@ Consensus::haveConsensus(std::unique_ptr const& clog stateStr = "yes"; else if (result_->state == ConsensusState::MovedOn) stateStr = "moved_on"; + else if (result_->state == ConsensusState::Expired) + stateStr = "expired"; span.setAttribute(cons_span::attr::result, stateStr); CLOG(clog) << "Consensus has been reached. "; @@ -1916,7 +1937,9 @@ Consensus::startEstablishTracing() return; establishSpan_.emplace( telemetry::SpanGuard::span( - telemetry::TraceCategory::Consensus, telemetry::seg::consensus, "establish")); + telemetry::TraceCategory::Consensus, + telemetry::seg::consensus, + telemetry::cons_span::op::establish)); } template diff --git a/src/xrpld/app/consensus/ConsensusSpanNames.h b/src/xrpld/consensus/ConsensusSpanNames.h similarity index 54% rename from src/xrpld/app/consensus/ConsensusSpanNames.h rename to src/xrpld/consensus/ConsensusSpanNames.h index 77c2ad6bb5..868f730860 100644 --- a/src/xrpld/app/consensus/ConsensusSpanNames.h +++ b/src/xrpld/consensus/ConsensusSpanNames.h @@ -2,22 +2,78 @@ /** Compile-time span name constants for consensus tracing. * - * Used by RCLConsensus (app) and Consensus.h (template) for - * consensus lifecycle spans. Built on StaticStr/join() from SpanNames.h. + * Used by RCLConsensus (app), Consensus.h (template), and PeerImp + * (overlay) for consensus lifecycle spans. + * Built on StaticStr/join() from SpanNames.h. * - * Span hierarchy: + * ## Span Hierarchy * - * consensus.round (deterministic trace_id from ledger hash) + * Root span created in Adaptor::startRoundTracing(). In "deterministic" + * strategy the trace-id is derived from the previous ledger hash so all + * nodes tracing the same round share a trace. + * + * consensus.round [main thread, root] + * | Created: Adaptor::startRoundTracing() + * | Attrs: ledger_id, ledger.seq, mode, trace_strategy, round_id * | - * +-- consensus.proposal.send - * +-- consensus.ledger_close - * +-- consensus.establish - * +-- consensus.update_positions - * +-- consensus.check - * +-- consensus.accept - * +-- consensus.accept.apply (jtACCEPT thread) - * +-- consensus.validation.send (jtACCEPT thread, linked) - * +-- consensus.mode_change + * +-- consensus.phase.open [main thread, child] + * | Created: Consensus::startRoundInternal() + * | Ended: Consensus::closeLedger() + * | + * +-- consensus.proposal.send [main thread] + * | Created: Adaptor::propose() + * | Attrs: round (proposeSeq) + * | + * +-- consensus.ledger_close [main thread] + * | Created: Adaptor::onClose() + * | Attrs: ledger.seq, mode + * | + * +-- consensus.establish [main thread, child] + * | Created: Consensus::startEstablishTracing() + * | Ended: Consensus::phaseEstablish() on accept + * | Attrs: converge_percent, establish_count, proposers + * | + * +-- consensus.update_positions [main thread] + * | Created: Consensus::updateOurPositions() + * | Attrs: converge_percent, proposers, disputes_count + * | Events: per-dispute vote details (tx_id, our_vote, yays, nays) + * | + * +-- consensus.check [main thread] + * | Created: Consensus::haveConsensus() + * | Attrs: agree/disagree counts, threshold_percent, result + * | + * +-- consensus.accept [main thread, child of round] + * | Created: Adaptor::makeAcceptSpan(), shared_ptr kept alive + * | until doAccept() completes on jtACCEPT thread + * | Attrs: proposers, round_time_ms, quorum + * | | + * | +-- consensus.accept.apply [jtACCEPT thread, child of accept] + * | Created: Adaptor::doAccept() + * | Attrs: ledger.seq, close_time, close_time_correct, + * | close_resolution_ms, state, proposing, round_time_ms, + * | parent_close_time, close_time_self, close_time_vote_bins, + * | resolution_direction, tx_count + * | Events: tx.included (per tx) + * | + * +~~~ consensus.validation.send [jtACCEPT thread, linked] + * | Created: Adaptor::createValidationSpan() (follows-from link) + * | Attrs: ledger.seq, proposing + * | + * +-- consensus.mode_change [main thread] + * Created: Adaptor::onModeChange() + * Attrs: mode.old, mode.new + * + * Standalone spans (no parent, created per-message in overlay): + * + * consensus.proposal.receive [PeerImp I/O thread] + * Created: PeerImp::onMessage(TMProposeSet) + * + * consensus.validation.receive [PeerImp I/O thread] + * Created: PeerImp::onMessage(TMValidation) + * + * Legend: + * +-- child-of relationship (same trace) + * +~~~ follows-from link (separate sub-tree, causal link) */ #include @@ -28,17 +84,27 @@ namespace cons_span { // ===== Span name segments ==================================================== +namespace part { +inline constexpr auto proposal = makeStr("proposal"); +inline constexpr auto validation = makeStr("validation"); +inline constexpr auto accept = makeStr("accept"); +inline constexpr auto phase = makeStr("phase"); +} // namespace part + namespace op { inline constexpr auto round = makeStr("round"); -inline constexpr auto proposalSend = makeStr("proposal.send"); +inline constexpr auto proposalSend = join(part::proposal, makeStr("send")); inline constexpr auto ledgerClose = makeStr("ledger_close"); inline constexpr auto establish = makeStr("establish"); inline constexpr auto updatePositions = makeStr("update_positions"); inline constexpr auto check = makeStr("check"); inline constexpr auto accept = makeStr("accept"); -inline constexpr auto acceptApply = makeStr("accept.apply"); -inline constexpr auto validationSend = makeStr("validation.send"); +inline constexpr auto acceptApply = join(part::accept, makeStr("apply")); +inline constexpr auto validationSend = join(part::validation, makeStr("send")); inline constexpr auto modeChange = makeStr("mode_change"); +inline constexpr auto proposalReceive = join(part::proposal, makeStr("receive")); +inline constexpr auto validationReceive = join(part::validation, makeStr("receive")); +inline constexpr auto phaseOpen = join(part::phase, makeStr("open")); } // namespace op // ===== Full span names (prefix.op) =========================================== @@ -53,6 +119,9 @@ inline constexpr auto accept = join(seg::consensus, op::accept); inline constexpr auto acceptApply = join(seg::consensus, op::acceptApply); inline constexpr auto validationSend = join(seg::consensus, op::validationSend); inline constexpr auto modeChange = join(seg::consensus, op::modeChange); +inline constexpr auto proposalReceive = join(seg::consensus, op::proposalReceive); +inline constexpr auto validationReceive = join(seg::consensus, op::validationReceive); +inline constexpr auto phaseOpen = join(seg::consensus, op::phaseOpen); // ===== Attribute keys ======================================================== @@ -62,7 +131,7 @@ inline constexpr auto xrplConsensus = join(seg::xrpl, seg::consensus); /// "xrpl.consensus.ledger_id" inline constexpr auto ledgerId = join(xrplConsensus, makeStr("ledger_id")); /// "xrpl.consensus.ledger.seq" -inline constexpr auto ledgerSeq = join(xrplConsensus, makeStr("ledger.seq")); +inline constexpr auto ledgerSeq = join(join(xrplConsensus, makeStr("ledger")), makeStr("seq")); /// "xrpl.consensus.mode" inline constexpr auto mode = join(xrplConsensus, makeStr("mode")); /// "xrpl.consensus.round" @@ -97,9 +166,6 @@ inline constexpr auto resolutionDirection = join(xrplConsensus, makeStr("resolut inline constexpr auto convergePercent = join(xrplConsensus, makeStr("converge_percent")); /// "xrpl.consensus.establish_count" inline constexpr auto establishCount = join(xrplConsensus, makeStr("establish_count")); -/// "xrpl.consensus.proposers_agreed" -inline constexpr auto proposersAgreed = join(xrplConsensus, makeStr("proposers_agreed")); - // Avalanche threshold attributes /// "xrpl.consensus.avalanche_threshold" inline constexpr auto avalancheThreshold = join(xrplConsensus, makeStr("avalanche_threshold")); @@ -120,8 +186,6 @@ inline constexpr auto thresholdPercent = join(xrplConsensus, makeStr("threshold_ inline constexpr auto result = join(xrplConsensus, makeStr("result")); /// "xrpl.consensus.quorum" inline constexpr auto quorum = join(xrplConsensus, makeStr("quorum")); -/// "xrpl.consensus.validation_count" -inline constexpr auto validationCount = join(xrplConsensus, makeStr("validation_count")); // Trace strategy attribute /// "xrpl.consensus.trace_strategy" @@ -131,9 +195,9 @@ inline constexpr auto roundId = join(xrplConsensus, makeStr("round_id")); // Mode change attributes /// "xrpl.consensus.mode.old" -inline constexpr auto modeOld = join(xrplConsensus, makeStr("mode.old")); +inline constexpr auto modeOld = join(join(xrplConsensus, makeStr("mode")), makeStr("old")); /// "xrpl.consensus.mode.new" -inline constexpr auto modeNew = join(xrplConsensus, makeStr("mode.new")); +inline constexpr auto modeNew = join(join(xrplConsensus, makeStr("mode")), makeStr("new")); // Dispute event attributes /// "xrpl.tx.id" @@ -145,8 +209,24 @@ inline constexpr auto disputeOurVote = inline constexpr auto disputeYays = join(join(seg::xrpl, makeStr("dispute")), makeStr("yays")); /// "xrpl.dispute.nays" inline constexpr auto disputeNays = join(join(seg::xrpl, makeStr("dispute")), makeStr("nays")); + +/// "xrpl.consensus.tx_count" +inline constexpr auto txCount = join(xrplConsensus, makeStr("tx_count")); +/// "xrpl.consensus.disputes_count" +inline constexpr auto disputesCount = join(xrplConsensus, makeStr("disputes_count")); +/// "xrpl.consensus.trusted" +inline constexpr auto trusted = join(xrplConsensus, makeStr("trusted")); } // namespace attr +// ===== Event names =========================================================== + +namespace event { +/// "dispute.resolve" +inline constexpr auto disputeResolve = join(makeStr("dispute"), makeStr("resolve")); +/// "tx.included" +inline constexpr auto txIncluded = join(makeStr("tx"), makeStr("included")); +} // namespace event + // ===== Attribute values ====================================================== namespace val { diff --git a/src/xrpld/overlay/detail/PeerImp.cpp b/src/xrpld/overlay/detail/PeerImp.cpp index 16f8484243..3dd83399c9 100644 --- a/src/xrpld/overlay/detail/PeerImp.cpp +++ b/src/xrpld/overlay/detail/PeerImp.cpp @@ -9,6 +9,7 @@ #include #include #include +#include #include #include #include @@ -1442,11 +1443,11 @@ PeerImp::handleTransaction( uint256 const txID = stx->getTransactionID(); using namespace telemetry; - auto span = txReceiveSpan(txID, *m); - span.setAttribute(tx_span::attr::hash, to_string(txID).c_str()); - span.setAttribute(tx_span::attr::peerId, static_cast(id_)); + auto span = std::make_shared(txReceiveSpan(txID, *m)); + span->setAttribute(tx_span::attr::hash, to_string(txID).c_str()); + span->setAttribute(tx_span::attr::peerId, static_cast(id_)); if (auto const version = getVersion(); !version.empty()) - span.setAttribute(tx_span::attr::peerVersion, version.c_str()); + span->setAttribute(tx_span::attr::peerVersion, version.c_str()); // Charge strongly for attempting to relay a txn with tfInnerBatchTxn // LCOV_EXCL_START @@ -1480,11 +1481,11 @@ PeerImp::handleTransaction( if (!app_.getHashRouter().shouldProcess(txID, id_, flags, tx_interval)) { - span.setAttribute(tx_span::attr::suppressed, true); + span->setAttribute(tx_span::attr::suppressed, true); // we have seen this transaction recently if (any(flags & HashRouterFlags::BAD)) { - span.setAttribute(tx_span::attr::status, tx_span::val::knownBad); + span->setAttribute(tx_span::attr::status, tx_span::val::knownBad); fee_.update(Resource::feeUselessData, "known bad"); JLOG(p_journal_.debug()) << "Ignoring known bad tx " << txID; } @@ -1542,7 +1543,8 @@ PeerImp::handleTransaction( flags, checkSignature, batch, - stx]() { + stx, + sp = std::move(span)]() { if (auto peer = weak.lock()) peer->checkTransaction(flags, checkSignature, stx, batch); }); @@ -1957,9 +1959,18 @@ PeerImp::onMessage(std::shared_ptr const& m) app_.getTimeKeeper().closeTime(), calcNodeID(app_.getValidatorManifests().getMasterKey(publicKey))}); + auto span = std::make_shared(telemetry::SpanGuard::span( + telemetry::TraceCategory::Consensus, + telemetry::seg::consensus, + telemetry::cons_span::op::proposalReceive)); + span->setAttribute(telemetry::cons_span::attr::trusted, isTrusted); + span->setAttribute(telemetry::cons_span::attr::round, static_cast(set.proposeseq())); + std::weak_ptr const weak = shared_from_this(); app_.getJobQueue().addJob( - isTrusted ? jtPROPOSAL_t : jtPROPOSAL_ut, "checkPropose", [weak, isTrusted, m, proposal]() { + isTrusted ? jtPROPOSAL_t : jtPROPOSAL_ut, + "checkPropose", + [weak, isTrusted, m, proposal, sp = std::move(span)]() { if (auto peer = weak.lock()) peer->checkPropose(isTrusted, m, proposal); }); @@ -2534,6 +2545,18 @@ PeerImp::onMessage(std::shared_ptr const& m) return; } + auto span = std::make_shared(telemetry::SpanGuard::span( + telemetry::TraceCategory::Consensus, + telemetry::seg::consensus, + telemetry::cons_span::op::validationReceive)); + span->setAttribute(telemetry::cons_span::attr::trusted, isTrusted); + if (val->isFieldPresent(sfLedgerSequence)) + { + span->setAttribute( + telemetry::cons_span::attr::ledgerSeq, + static_cast(val->getFieldU32(sfLedgerSequence))); + } + if (!isTrusted && (tracking_.load() == Tracking::diverged)) { JLOG(p_journal_.debug()) << "Dropping untrusted validation from diverged peer"; @@ -2544,7 +2567,9 @@ PeerImp::onMessage(std::shared_ptr const& m) std::weak_ptr const weak = shared_from_this(); app_.getJobQueue().addJob( - isTrusted ? jtVALIDATION_t : jtVALIDATION_ut, name, [weak, val, m, key]() { + isTrusted ? jtVALIDATION_t : jtVALIDATION_ut, + name, + [weak, val, m, key, sp = std::move(span)]() { if (auto peer = weak.lock()) peer->checkValidation(val, key, m); }); diff --git a/src/xrpld/rpc/detail/RpcSpanNames.h b/src/xrpld/rpc/detail/RpcSpanNames.h index a10fd1af3e..ef46c79782 100644 --- a/src/xrpld/rpc/detail/RpcSpanNames.h +++ b/src/xrpld/rpc/detail/RpcSpanNames.h @@ -37,6 +37,7 @@ inline constexpr auto command = join(seg::rpc, makeStr("command")); namespace op { inline constexpr auto wsMessage = makeStr("ws_message"); +inline constexpr auto wsUpgrade = makeStr("ws_upgrade"); inline constexpr auto httpRequest = makeStr("http_request"); inline constexpr auto process = makeStr("process"); } // namespace op @@ -65,6 +66,7 @@ using telemetry::attr_val::error; using telemetry::attr_val::success; inline constexpr auto admin = makeStr("admin"); inline constexpr auto user = makeStr("user"); +inline constexpr auto unknownCommand = makeStr("unknown_command"); } // namespace val } // namespace rpc_span