From 7675af41ec85f71d3036e399473c14882dffc333 Mon Sep 17 00:00:00 2001 From: Pratik Mankawde <3397372+pratikmankawde@users.noreply.github.com> Date: Fri, 6 Mar 2026 17:18:30 +0000 Subject: [PATCH] Add consensus.accept.apply span with ledger close time attributes Add a new trace span in doAccept() capturing ledger close time details: - xrpl.consensus.close_time: agreed-upon close time (epoch seconds) - xrpl.consensus.close_time_correct: whether validators converged (per avCT_CONSENSUS_PCT = 75% threshold) - xrpl.consensus.close_resolution_ms: time rounding granularity - xrpl.consensus.state: "finished" or "moved_on" (consensus failure) - xrpl.consensus.proposing: whether this node was proposing Update Tempo datasource with close time filters, plan docs with new span inventory, and add test coverage for the attribute pattern. Co-Authored-By: Claude Opus 4.6 --- OpenTelemetryPlan/06-implementation-phases.md | 11 +++++++ OpenTelemetryPlan/Phase4_taskList.md | 23 +++++++++++++++ .../provisioning/datasources/tempo.yaml | 17 ++++++++++- src/tests/libxrpl/telemetry/TracingMacros.cpp | 29 +++++++++++++++++++ src/xrpld/app/consensus/RCLConsensus.cpp | 21 ++++++++++++++ 5 files changed, 100 insertions(+), 1 deletion(-) diff --git a/OpenTelemetryPlan/06-implementation-phases.md b/OpenTelemetryPlan/06-implementation-phases.md index e11836c1fa..3c5ff05554 100644 --- a/OpenTelemetryPlan/06-implementation-phases.md +++ b/OpenTelemetryPlan/06-implementation-phases.md @@ -152,11 +152,22 @@ gantt **Total Effort**: 11 days +### 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:453` | `xrpl.consensus.close_time`, `close_time_correct`, `close_resolution_ms`, `state`, `proposing`, `round_time_ms`, `ledger.seq` | +| `consensus.validation.send` | `RCLConsensus.cpp:753` | `xrpl.consensus.proposing` | + ### Exit Criteria - [x] Complete consensus round traces - [x] Phase transitions visible - [x] Proposals and validations traced +- [x] Close time agreement tracked (per `avCT_CONSENSUS_PCT`) - [x] No impact on consensus timing - [ ] Multi-validator test network validated diff --git a/OpenTelemetryPlan/Phase4_taskList.md b/OpenTelemetryPlan/Phase4_taskList.md index a5ef457efd..64cc703265 100644 --- a/OpenTelemetryPlan/Phase4_taskList.md +++ b/OpenTelemetryPlan/Phase4_taskList.md @@ -213,9 +213,32 @@ **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. +### Implemented Spans + +| Span Name | Method | Key Attributes | +| --------------------------- | ---------------------------------- | ----------------------------------------------------------------------------------------------------------------------------- | +| `consensus.proposal.send` | `Adaptor::propose` | `xrpl.consensus.round` | +| `consensus.ledger_close` | `Adaptor::onClose` | `xrpl.consensus.ledger.seq`, `xrpl.consensus.mode` | +| `consensus.accept` | `Adaptor::onAccept` | `xrpl.consensus.proposers`, `xrpl.consensus.round_time_ms` | +| `consensus.accept.apply` | `Adaptor::doAccept` | `xrpl.consensus.close_time`, `close_time_correct`, `close_resolution_ms`, `state`, `proposing`, `round_time_ms`, `ledger.seq` | +| `consensus.validation.send` | `Adaptor::onAccept` (via validate) | `xrpl.consensus.proposing` | + +#### Close Time Attributes (consensus.accept.apply) + +The `consensus.accept.apply` span captures ledger close time agreement details +driven by `avCT_CONSENSUS_PCT` (75% validator agreement threshold): + +- **`xrpl.consensus.close_time`** — Agreed-upon ledger close time (epoch seconds). When validators disagree (`consensusCloseTime == epoch`), this is synthetically set to `prevCloseTime + 1s`. +- **`xrpl.consensus.close_time_correct`** — `true` if validators reached agreement, `false` if they "agreed to disagree" (close time forced to prev+1s). +- **`xrpl.consensus.close_resolution_ms`** — Rounding granularity for close time (starts at 30s, decreases as ledger interval stabilizes). +- **`xrpl.consensus.state`** — `"finished"` (normal) or `"moved_on"` (consensus failed, adopted best available). +- **`xrpl.consensus.proposing`** — Whether this node was proposing. +- **`xrpl.consensus.round_time_ms`** — Total consensus round duration. + **Exit Criteria** (from [06-implementation-phases.md §6.11.4](./06-implementation-phases.md)): - [ ] Complete consensus round traces - [ ] Phase transitions visible - [ ] Proposals and validations traced +- [ ] Close time agreement tracked (per `avCT_CONSENSUS_PCT`) - [ ] No impact on consensus timing diff --git a/docker/telemetry/grafana/provisioning/datasources/tempo.yaml b/docker/telemetry/grafana/provisioning/datasources/tempo.yaml index c4bb82fd30..1c372461d7 100644 --- a/docker/telemetry/grafana/provisioning/datasources/tempo.yaml +++ b/docker/telemetry/grafana/provisioning/datasources/tempo.yaml @@ -8,7 +8,7 @@ # Phase 1b (infra): Base filters — node identity, service, span name, status. # Phase 2 (RPC): RPC command, status, role filters. # Phase 3 (TX): Transaction hash, local/peer origin, status. -# Phase 4 (Cons): Consensus mode, round, ledger sequence. +# Phase 4 (Cons): Consensus mode, round, ledger sequence, close time. apiVersion: 1 @@ -130,3 +130,18 @@ datasources: operator: "=" scope: span type: static + - id: consensus-close-time-correct + tag: xrpl.consensus.close_time_correct + operator: "=" + scope: span + type: dynamic + - id: consensus-state + tag: xrpl.consensus.state + operator: "=" + scope: span + type: dynamic + - id: consensus-close-resolution + tag: xrpl.consensus.close_resolution_ms + operator: "=" + scope: span + type: dynamic diff --git a/src/tests/libxrpl/telemetry/TracingMacros.cpp b/src/tests/libxrpl/telemetry/TracingMacros.cpp index a8c1bb5e86..c65fb92488 100644 --- a/src/tests/libxrpl/telemetry/TracingMacros.cpp +++ b/src/tests/libxrpl/telemetry/TracingMacros.cpp @@ -82,6 +82,35 @@ TEST(TracingMacros, conditional_guards) } } +TEST(TracingMacros, consensus_close_time_attributes) +{ + // Verify the consensus.accept.apply attribute pattern compiles and + // doesn't crash with NullTelemetry. Mirrors the real instrumentation + // in RCLConsensus::Adaptor::doAccept(). + telemetry::Telemetry::Setup setup; + setup.enabled = false; + beast::Journal::Sink& sink = beast::Journal::getNullSink(); + beast::Journal j(sink); + auto tel = telemetry::make_Telemetry(setup, j); + + { + XRPL_TRACE_CONSENSUS(*tel, "consensus.accept.apply"); + XRPL_TRACE_SET_ATTR("xrpl.consensus.ledger.seq", static_cast(42)); + XRPL_TRACE_SET_ATTR("xrpl.consensus.close_time", static_cast(780000000)); + XRPL_TRACE_SET_ATTR("xrpl.consensus.close_time_correct", true); + XRPL_TRACE_SET_ATTR("xrpl.consensus.close_resolution_ms", static_cast(30000)); + XRPL_TRACE_SET_ATTR("xrpl.consensus.state", std::string("finished")); + XRPL_TRACE_SET_ATTR("xrpl.consensus.proposing", true); + XRPL_TRACE_SET_ATTR("xrpl.consensus.round_time_ms", static_cast(3500)); + } + // close_time_correct=false path (agreed to disagree) + { + XRPL_TRACE_CONSENSUS(*tel, "consensus.accept.apply"); + XRPL_TRACE_SET_ATTR("xrpl.consensus.close_time_correct", false); + XRPL_TRACE_SET_ATTR("xrpl.consensus.state", std::string("moved_on")); + } +} + #ifdef XRPL_ENABLE_TELEMETRY TEST(TracingMacros, span_guard_raii) diff --git a/src/xrpld/app/consensus/RCLConsensus.cpp b/src/xrpld/app/consensus/RCLConsensus.cpp index d94bea9636..debd9a4bac 100644 --- a/src/xrpld/app/consensus/RCLConsensus.cpp +++ b/src/xrpld/app/consensus/RCLConsensus.cpp @@ -443,6 +443,27 @@ RCLConsensus::Adaptor::doAccept( closeTimeCorrect = true; } + // Trace the ledger application phase with close time details. + // This span runs on the jtACCEPT job queue thread (posted by onAccept), + // separate from the consensus.accept span which fires synchronously in + // onAccept. It captures the agreed-upon close time, whether validators + // converged on it (per avCT_CONSENSUS_PCT), and the consensus outcome. + XRPL_TRACE_CONSENSUS(app_.getTelemetry(), "consensus.accept.apply"); + XRPL_TRACE_SET_ATTR("xrpl.consensus.ledger.seq", static_cast(prevLedger.seq() + 1)); + XRPL_TRACE_SET_ATTR( + "xrpl.consensus.close_time", + static_cast(consensusCloseTime.time_since_epoch().count())); + XRPL_TRACE_SET_ATTR("xrpl.consensus.close_time_correct", closeTimeCorrect); + XRPL_TRACE_SET_ATTR( + "xrpl.consensus.close_resolution_ms", + static_cast( + std::chrono::duration_cast(closeResolution).count())); + XRPL_TRACE_SET_ATTR( + "xrpl.consensus.state", std::string(consensusFail ? "moved_on" : "finished")); + XRPL_TRACE_SET_ATTR("xrpl.consensus.proposing", proposing); + XRPL_TRACE_SET_ATTR( + "xrpl.consensus.round_time_ms", static_cast(result.roundTime.read().count())); + JLOG(j_.debug()) << "Report: Prop=" << (proposing ? "yes" : "no") << " val=" << (validating_ ? "yes" : "no") << " corLCL=" << (haveCorrectLCL ? "yes" : "no")