From f649670ef7f5edde78e889c11bd0d39b7f5461cb Mon Sep 17 00:00:00 2001 From: Pratik Mankawde <3397372+pratikmankawde@users.noreply.github.com> Date: Tue, 28 Jul 2026 17:04:28 +0100 Subject: [PATCH] fix(telemetry): address the PR review findings Four defects from the automated review on PR #7875, each verified against the current tree before fixing (one further comment, the row-63 dashboard overlap, was already fixed by an earlier commit and needed nothing). 1. Rule J could not detect an instrument-kind mismatch. instrument_kinds() wrote `kinds[wire] = ...`, so a wire name created through two different factories kept only the kind visited last and whichever emit site the file walk reached last silently decided the verdict. It now collects a set per name and reports the conflict itself -- one name exporting two instruments is the defect, and no suffix can be correct for both. Added a regression test that builds a name as both a counter and an observable gauge and asserts the message names both. 2. A duplicate connection was reported as `tls_fail`. The TLS handshake had in fact succeeded; PeerFinder simply already held a slot for that address, which is ordinary churn on a healthy node. Conflating the two made a rising `tls_fail` unreadable -- it could mean unreachable peers or merely a busy PeerFinder, and those need opposite responses. Added a distinct `duplicate` outcome and carried the widened vocabulary through every place that enumerates it: the panel description, both filter descriptions, the runbook branch table, the runbook outcome list and the expected_spans note. The `dial_outcome` template variable is a label_values() query, so it picks the new value up on its own. 3. ConnectAttempt::onShutdown had no `operation_aborted` guard, unlike the five other handlers in the same file. A clean teardown was therefore counted as `upgrade_fail`, inflating that outcome on any node shutting down with dials in flight. 4. ValidatorSite used the raw configured URI as a Prometheus label. [validator_list_sites] accepts credentials in the URI and ParsedUrl keeps them in username/password, so a configured `https://user:pass@host` would have copied the secret into a metric label and on into the collector, Prometheus and every dashboard. The label is now rebuilt from scheme, host, port and path -- everything needed to tell one site apart, and nothing more. Verified: naming checker exits 0 with Rule J still passing all 40 real instrument names; its unit tests now number 139 and all pass; 15 dashboards validate; both workload JSON files parse; clang-tidy over the full compile database reports no finding on either changed .cpp; pre-commit passes. Not verified: not compiled. Item 4 introduces string concatenation and item 2 a new constexpr, so CI's build is the first real check on both. Co-Authored-By: Claude Opus 5 (1M context) --- .../scripts/otel-naming/check_otel_naming.py | 30 +++++++++++++------ .../otel-naming/test_check_otel_naming.py | 17 +++++++++++ .../dashboards/ledger-sync-health.json | 6 ++-- docker/telemetry/workload/expected_spans.json | 2 +- docs/telemetry-runbook.md | 19 +++++++----- src/xrpld/app/misc/detail/ValidatorSite.cpp | 16 ++++++++-- src/xrpld/overlay/detail/ConnectAttempt.cpp | 15 +++++++++- src/xrpld/overlay/detail/PeerSpanNames.h | 20 +++++++++---- 8 files changed, 96 insertions(+), 29 deletions(-) diff --git a/.github/scripts/otel-naming/check_otel_naming.py b/.github/scripts/otel-naming/check_otel_naming.py index 62c16611fb..fa56475306 100644 --- a/.github/scripts/otel-naming/check_otel_naming.py +++ b/.github/scripts/otel-naming/check_otel_naming.py @@ -1293,9 +1293,9 @@ def iter_sources(root: Path) -> List[Path]: ] -def instrument_kinds(root: Path, wire_by_symbol: Dict[str, str]) -> Dict[str, str]: - """Map each declared instrument's WIRE name to its OTel instrument kind, by - looking at how the emit sites actually create it. +def instrument_kinds(root: Path, wire_by_symbol: Dict[str, str]) -> Dict[str, Set[str]]: + """Map each declared instrument's WIRE name to the set of OTel instrument + kinds its emit sites actually create it with. The kind is what decides which suffix is correct, so it must be read from the emit site rather than guessed from the name -- guessing from words like @@ -1303,10 +1303,15 @@ def instrument_kinds(root: Path, wire_by_symbol: Dict[str, str]) -> Dict[str, st label VALUES (e.g. `nodestore_state` observing `write_mean_us`), which is a legitimate shape, not a violation. - Returns one of `counter`, `histogram`, `gauge`, `updown` per wire name. - A name whose emit site is not found is absent from the result, so Rule J - checks only the shape-independent rules for it.""" - kinds: Dict[str, str] = {} + A SET rather than one kind per name, because one wire name created through + two different factories is itself the defect worth reporting: the SDK would + export two instruments under one name and the collector would see whichever + arrived last. Recording only the last kind visited hid exactly that case. + + Values are drawn from `counter`, `histogram`, `gauge`, `updown`. A name whose + emit site is not found is absent from the result, so Rule J checks only the + shape-independent rules for it.""" + kinds: Dict[str, Set[str]] = {} for path in iter_sources(root): if path.name == "MetricMacros.h" or path.name.endswith("MetricNames.h"): continue @@ -1330,7 +1335,7 @@ def instrument_kinds(root: Path, wire_by_symbol: Dict[str, str]) -> Dict[str, st ) if wire is None: continue - kinds[wire] = classify_instrument_kind(kind) + kinds.setdefault(wire, set()).add(classify_instrument_kind(kind)) return kinds @@ -1404,7 +1409,14 @@ def run_rule_j_metric_suffixes(root: Path, report: Report) -> None: if name.startswith(("xrpld_", "xrpl_")): flag(name, "drop the prefix; the exporter adds it") continue - kind = kinds.get(name) + found_kinds = kinds.get(name) or set() + if len(found_kinds) > 1: + # One wire name created through two factories exports two + # instruments under one name; no suffix can be right for both, so + # report the conflict itself rather than picking one arbitrarily. + flag(name, f"created as {' and '.join(sorted(found_kinds))}; pick one kind") + continue + kind = next(iter(found_kinds), None) if kind == "counter" and not name.endswith(METRIC_COUNTER_SUFFIX): flag(name, "counter must end in _total") elif kind == "histogram" and not name.endswith(METRIC_DURATION_SUFFIXES): diff --git a/.github/scripts/otel-naming/test_check_otel_naming.py b/.github/scripts/otel-naming/test_check_otel_naming.py index 32ac597c0d..5d4205751f 100644 --- a/.github/scripts/otel-naming/test_check_otel_naming.py +++ b/.github/scripts/otel-naming/test_check_otel_naming.py @@ -1264,6 +1264,23 @@ class RuleJMetricSuffixes(unittest.TestCase): # shape-independent rules apply -- a bare gauge-ish name is fine. self.assertEqual(self._run(_mc("syncState", "sync_state")), []) + def test_one_name_created_as_two_kinds_is_flagged(self): + # One wire name built through two different factories exports two + # instruments under a single name, and no suffix can satisfy both. The + # kind map therefore records a SET per name: keeping only the last kind + # visited silently hid this, because whichever emit site the walk + # reached last decided the verdict. + violations = self._run( + _mc("dualKind", "dual_kind_total"), + 'meter_->CreateUInt64Counter(metric::dualKind, "d");\n' + 'meter_->CreateInt64ObservableGauge(metric::dualKind, "d");\n', + ) + self.assertEqual(len(violations), 1, violations) + # The message names both kinds, so the reader sees the conflict rather + # than a suffix complaint that would contradict one of the two sites. + self.assertIn("counter", violations[0][-1]) + self.assertIn("gauge", violations[0][-1]) + def test_skip_when_no_header(self): d = Path(tempfile.mkdtemp()) try: diff --git a/docker/telemetry/grafana/dashboards/ledger-sync-health.json b/docker/telemetry/grafana/dashboards/ledger-sync-health.json index c284dcb596..d7e39cc006 100644 --- a/docker/telemetry/grafana/dashboards/ledger-sync-health.json +++ b/docker/telemetry/grafana/dashboards/ledger-sync-health.json @@ -230,7 +230,7 @@ "type": "prometheus", "uid": "${DS_PROMETHEUS}" }, - "description": "###### What this is:\n*Count of outbound peer connection attempts, split by terminal outcome.*\n\n###### How it's computed:\n*Count over the selected range of finished dials grouped by outcome, per node. Filter the outcome set with the Dial Outcome variable.*\n\n###### Reading it:\n*Connected should dominate. The failure lines name the stage that broke: tcp_fail (no route or refused), tls_fail (TLS handshake), upgrade_fail (HTTP upgrade or protocol negotiation), timeout (no terminal state in time).*\n\n###### Healthy range:\n*Connected rising to the configured peer count, then flat with failures near zero.*\n\n###### Watch for:\n*All attempts landing on one failure outcome and no connected line — the node has no outbound peers and can never sync.*\n\n###### Keywords:\n- **Outbound dial latency** *(per node)* — an outbound peer connection attempt from TCP connect through TLS to protocol upgrade; each attempt ends in exactly one outcome.\n\n###### Computation boundary:\n*Result: Per node — each series is one server's own value.*\n*Computed in xrpld code (MetricsRegistry, OpenTelemetry SDK) and exported as a metric; the collector only forwards it; the Grafana query selects and aggregates it.*\n\n###### Source:\n[ConnectAttempt.cpp](https://github.com/XRPLF/rippled/blob/develop/src/xrpld/overlay/detail/ConnectAttempt.cpp)\n\n###### Function:\n`ConnectAttempt::reportOutcome`\n\n###### References:\n[Telemetry glossary](https://github.com/XRPLF/rippled/blob/develop/docs/telemetry-glossary.md#outbound-dial-latency)", + "description": "###### What this is:\n*Count of outbound peer connection attempts, split by terminal outcome.*\n\n###### How it's computed:\n*Count over the selected range of finished dials grouped by outcome, per node. Filter the outcome set with the Dial Outcome variable.*\n\n###### Reading it:\n*Connected should dominate. The failure lines name the stage that broke: tcp_fail (no route or refused), tls_fail (TLS handshake or shared-value exchange), duplicate (already connected to that address, not a fault), upgrade_fail (HTTP upgrade or protocol negotiation), timeout (no terminal state in time).*\n\n###### Healthy range:\n*Connected rising to the configured peer count, then flat with failures near zero.*\n\n###### Watch for:\n*All attempts landing on one failure outcome and no connected line — the node has no outbound peers and can never sync.*\n\n###### Keywords:\n- **Outbound dial latency** *(per node)* — an outbound peer connection attempt from TCP connect through TLS to protocol upgrade; each attempt ends in exactly one outcome.\n\n###### Computation boundary:\n*Result: Per node — each series is one server's own value.*\n*Computed in xrpld code (MetricsRegistry, OpenTelemetry SDK) and exported as a metric; the collector only forwards it; the Grafana query selects and aggregates it.*\n\n###### Source:\n[ConnectAttempt.cpp](https://github.com/XRPLF/rippled/blob/develop/src/xrpld/overlay/detail/ConnectAttempt.cpp)\n\n###### Function:\n`ConnectAttempt::reportOutcome`\n\n###### References:\n[Telemetry glossary](https://github.com/XRPLF/rippled/blob/develop/docs/telemetry-glossary.md#outbound-dial-latency)", "fieldConfig": { "defaults": { "color": { @@ -5158,7 +5158,7 @@ { "name": "dial_outcome", "label": "Dial Outcome", - "description": "Filter outbound dial attempts by terminal outcome [connected / tcp_fail / tls_fail / upgrade_fail / timeout]", + "description": "Filter outbound dial attempts by terminal outcome [connected / tcp_fail / tls_fail / duplicate / upgrade_fail / timeout]", "type": "query", "query": "label_values(overlay_connect_total, outcome)", "datasource": { @@ -5518,7 +5518,7 @@ { "name": "span_outcome", "label": "Span Outcome", - "description": "Filter the span-derived sync panels by terminal outcome [complete / failed / timeout / abandoned / partial / refused / connected / tcp_fail / tls_fail / upgrade_fail]", + "description": "Filter the span-derived sync panels by terminal outcome [complete / failed / timeout / abandoned / partial / refused / connected / tcp_fail / tls_fail / duplicate / upgrade_fail]", "type": "query", "query": "label_values(span_calls_total, outcome)", "datasource": { diff --git a/docker/telemetry/workload/expected_spans.json b/docker/telemetry/workload/expected_spans.json index fc8c5c43e2..790b7d7968 100644 --- a/docker/telemetry/workload/expected_spans.json +++ b/docker/telemetry/workload/expected_spans.json @@ -395,7 +395,7 @@ "parent": null, "required_attributes": ["remote_endpoint", "outcome", "duration_ms"], "config_flag": "trace_peer", - "note": "One outbound connect attempt (ConnectAttempt), a fresh trace root because a dial is the first thing a starting node does and there is nothing to parent it to. Required: run-full-validation.sh lists the other four nodes in each node's [ips], so every node dials and the span always fires. Telemetry is live in time to catch it -- ApplicationImp::setup() calls startTelemetry() before start() calls overlay_->start(). outcome carries the same five values as the overlay_connect_total counter (connected|tcp_fail|tls_fail|upgrade_fail|timeout) and is set from the same reportOutcome() funnel, so span and counter cannot disagree. remote_endpoint is the span-only dimension the counter cannot carry, since one series per peer address would be unbounded cardinality." + "note": "One outbound connect attempt (ConnectAttempt), a fresh trace root because a dial is the first thing a starting node does and there is nothing to parent it to. Required: run-full-validation.sh lists the other four nodes in each node's [ips], so every node dials and the span always fires. Telemetry is live in time to catch it -- ApplicationImp::setup() calls startTelemetry() before start() calls overlay_->start(). outcome carries the same six values as the overlay_connect_total counter (connected|tcp_fail|tls_fail|duplicate|upgrade_fail|timeout) and is set from the same reportOutcome() funnel, so span and counter cannot disagree. remote_endpoint is the span-only dimension the counter cannot carry, since one series per peer address would be unbounded cardinality." }, { "name": "peer.proposal.receive", diff --git a/docs/telemetry-runbook.md b/docs/telemetry-runbook.md index 4e0a63a249..d2878c01a5 100644 --- a/docs/telemetry-runbook.md +++ b/docs/telemetry-runbook.md @@ -2752,14 +2752,14 @@ outranks every other symptom regardless of what the mode machine says. Peer count flat at zero; _Mode Transitions by Edge_ shows the node never leaving `disconnected`, or churning straight back to it. -| Look at | Healthy | Unhealthy | Conclude | -| ------------------------------------------ | -------------------------------------- | ---------------------------------------------------------------------------------- | ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | -| _DNS Resolve Outcome Rate_ | all rate on `outcome=resolved` | any rate on `empty`, or both flat at zero | a name in `[ips]`/`[ips_fixed]` returns no address, or the list is empty — fix the hostname or use an IP | -| _DNS Resolve Latency (p95)_ | milliseconds | seconds-scale | the resolver is timing out and delaying every dial behind it | -| _Outbound Dial Outcome Rate_ | `connected` non-zero | all attempts on one failure outcome | `tcp_fail` = route/firewall/closed port · `tls_fail` = TLS · `upgrade_fail` = negotiation, go to the next row · `timeout` = never terminal | -| _Outbound Dial Latency (p95)_ | well under the dial timeout | pinned near it | peers accept TCP but never finish the handshake | -| _Handshake Negotiation Failures by Reason_ | flat, or a low background rate | any sustained `reason` | `wrong_network`/`invalid_network_id` is the most common fresh-node fault — the node is on a different network and can never reach quorum; `clock_skew` sends you to branch B | -| _PeerFinder Slot Census_ | `out_active` climbing toward `out_max` | `connecting` non-zero with `out_active` low; or `bootcache` and `livecache` both 0 | dials never complete; or there is nothing to dial at all | +| Look at | Healthy | Unhealthy | Conclude | +| ------------------------------------------ | -------------------------------------- | ---------------------------------------------------------------------------------- | ----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | +| _DNS Resolve Outcome Rate_ | all rate on `outcome=resolved` | any rate on `empty`, or both flat at zero | a name in `[ips]`/`[ips_fixed]` returns no address, or the list is empty — fix the hostname or use an IP | +| _DNS Resolve Latency (p95)_ | milliseconds | seconds-scale | the resolver is timing out and delaying every dial behind it | +| _Outbound Dial Outcome Rate_ | `connected` non-zero | all attempts on one failure outcome | `tcp_fail` = route/firewall/closed port · `tls_fail` = TLS · `duplicate` = already connected, not a fault · `upgrade_fail` = negotiation, go to the next row · `timeout` = never terminal | +| _Outbound Dial Latency (p95)_ | well under the dial timeout | pinned near it | peers accept TCP but never finish the handshake | +| _Handshake Negotiation Failures by Reason_ | flat, or a low background rate | any sustained `reason` | `wrong_network`/`invalid_network_id` is the most common fresh-node fault — the node is on a different network and can never reach quorum; `clock_skew` sends you to branch B | +| _PeerFinder Slot Census_ | `out_active` climbing toward `out_max` | `connecting` non-zero with `out_active` low; or `bootcache` and `livecache` both 0 | dials never complete; or there is nothing to dial at all | **Conclusion:** the node has no usable overlay. Nothing downstream can be diagnosed until `connected` on _Outbound Dial Outcome Rate_ is non-zero. Detail: @@ -2943,6 +2943,9 @@ first one that is wrong and fix it before reading further panels. - `connected` — success; this is the line that must be non-zero. - `tcp_fail` — no route, refused, or the peer port is closed or firewalled. - `tls_fail` — the TLS handshake failed. + - `duplicate` — TLS succeeded but PeerFinder already holds a slot for + that address. Ordinary churn on a healthy node, not a failure; it is + reported separately so a rising `tls_fail` cannot be confused with it. - `upgrade_fail` — TLS succeeded but the HTTP upgrade or protocol negotiation was rejected. This is the outcome that pairs with step 3. - `timeout` — the attempt never reached a terminal state. diff --git a/src/xrpld/app/misc/detail/ValidatorSite.cpp b/src/xrpld/app/misc/detail/ValidatorSite.cpp index f7667e7f90..5af583d1f0 100644 --- a/src/xrpld/app/misc/detail/ValidatorSite.cpp +++ b/src/xrpld/app/misc/detail/ValidatorSite.cpp @@ -393,12 +393,24 @@ ValidatorSite::reportFetchOutcome( // it is always non-null. Unlike activeResource (reset once a fetch // completes) it also keeps the URI exactly as configured, which keeps // the time series stable when a site redirects. + // + // The label is rebuilt from the parsed parts rather than using the raw + // configured URI: [validator_list_sites] accepts credentials in the URI, + // and ParsedUrl keeps them in username/password. Emitting the raw string + // would copy them into a metric label, from which they would reach the + // collector, Prometheus and every dashboard. Scheme, host, port and path + // are all a reader needs to tell one site from another. + auto const& url = sites_[siteIdx].loadedResource->pUrl; + std::string siteLabel = url.scheme + "://" + url.domain; + if (url.port) + siteLabel += ":" + std::to_string(*url.port); + siteLabel += url.path; + XRPL_METRIC_COUNTER_INC_LABELED( app_, telemetry::metric::unlFetchTotal, "Validator list fetch attempts, by site and outcome", - {{telemetry::label::site, std::string(sites_[siteIdx].loadedResource->uri)}, - {telemetry::label::outcome, std::string(outcome)}}); + {{telemetry::label::site, siteLabel}, {telemetry::label::outcome, std::string(outcome)}}); } void diff --git a/src/xrpld/overlay/detail/ConnectAttempt.cpp b/src/xrpld/overlay/detail/ConnectAttempt.cpp index f857442721..d8debe4090 100644 --- a/src/xrpld/overlay/detail/ConnectAttempt.cpp +++ b/src/xrpld/overlay/detail/ConnectAttempt.cpp @@ -354,7 +354,10 @@ ConnectAttempt::onHandshake(error_code ec) if (!overlay_.peerFinder().onConnected( slot_, beast::IPAddressConversion::fromAsio(localEndpoint))) { - reportOutcome(telemetry::peer_span::val::tlsFail); + // Not a TLS failure: the handshake succeeded and PeerFinder simply + // already holds a slot for this address. Reporting it as tls_fail + // conflated ordinary dial churn with peers we cannot speak to. + reportOutcome(telemetry::peer_span::val::duplicate); fail("Duplicate connection"); return; } @@ -460,6 +463,16 @@ ConnectAttempt::onShutdown(error_code ec) return; } + // A cancelled shutdown is us tearing the attempt down, not the peer failing + // it. Every other handler here guards this; without the same guard an + // ordinary overlay stop was counted as upgrade_fail, inflating that outcome + // on any node that shuts down while dials are in flight. + if (ec == boost::asio::error::operation_aborted) + { + close(); + return; + } + if (ec != boost::asio::error::eof) { reportOutcome(telemetry::peer_span::val::upgradeFail); diff --git a/src/xrpld/overlay/detail/PeerSpanNames.h b/src/xrpld/overlay/detail/PeerSpanNames.h index a578036ad5..f9904fdb87 100644 --- a/src/xrpld/overlay/detail/PeerSpanNames.h +++ b/src/xrpld/overlay/detail/PeerSpanNames.h @@ -80,21 +80,31 @@ namespace val { /** * peer.dial outcome values. * - * The identical five slugs `ConnectAttempt::reportOutcome` already passes to - * the `overlay_connect_total` counter, defined here so the span and the - * counter cannot drift apart: the dial state machine names its outcome once - * and both signals receive that same value. + * The identical slugs `ConnectAttempt::reportOutcome` passes to the + * `overlay_connect_total` counter, defined here so the span and the counter + * cannot drift apart: the dial state machine names its outcome once and both + * signals receive that same value. * * - connected: the peer was activated and added to the overlay. * - tcp_fail: the TCP connect or local-endpoint read failed. - * - tls_fail: the TLS handshake, slot check or shared value failed. + * - tls_fail: the TLS handshake or the shared-value exchange failed. + * - duplicate: TLS succeeded but PeerFinder already holds a slot for this + * address, so the attempt was redundant rather than faulty. * - upgrade_fail: TLS succeeded but the HTTP upgrade, protocol negotiation * or activation was rejected. * - timeout: the attempt never reached any terminal state in time. + * + * `duplicate` is separate from `tls_fail` on purpose. Dialling an address we + * are already connected to is normal churn on a healthy node, while a TLS + * failure means the peer could not be spoken to at all. Reporting both as + * `tls_fail` made a rising TLS-failure count unreadable: it could equally mean + * broken peers or merely a busy PeerFinder, and the two need opposite + * responses. */ inline constexpr auto connected = makeStr("connected"); inline constexpr auto tcpFail = makeStr("tcp_fail"); inline constexpr auto tlsFail = makeStr("tls_fail"); +inline constexpr auto duplicate = makeStr("duplicate"); inline constexpr auto upgradeFail = makeStr("upgrade_fail"); inline constexpr auto timeout = makeStr("timeout"); } // namespace val