diff --git a/OpenTelemetryPlan/Phase8_taskList.md b/OpenTelemetryPlan/Phase8_taskList.md index 61aab8a432..7849990858 100644 --- a/OpenTelemetryPlan/Phase8_taskList.md +++ b/OpenTelemetryPlan/Phase8_taskList.md @@ -107,7 +107,7 @@ ```yaml receivers: filelog: - include: [/var/log/rippled/debug.log] + include: [/var/log/xrpld/*/debug.log] operators: - type: regex_parser regex: '^(?P\S+)\s+(?P\S+):(?P\S+)\s+(?:trace_id=(?P[a-f0-9]+)\s+span_id=(?P[a-f0-9]+)\s+)?(?P.*)$' diff --git a/docker/telemetry/TESTING.md b/docker/telemetry/TESTING.md index 1b65069e0d..ceccc10b5c 100644 --- a/docker/telemetry/TESTING.md +++ b/docker/telemetry/TESTING.md @@ -664,8 +664,11 @@ Expected: > 0 results. 1. Verify the log file mount in docker-compose.yml: ```yaml volumes: - - /tmp/xrpld-integration:/var/log/rippled:ro + - ${XRPLD_LOG_DIR:-./data/logs}:/var/log/xrpld:ro ``` + The mount source defaults to the repo-relative `docker/telemetry/data/logs` + (where the telemetry configs write). Override `XRPLD_LOG_DIR` to tail logs + from another root. 2. Check OTel Collector logs for filelog receiver errors: ```bash docker compose -f docker/telemetry/docker-compose.yml logs otel-collector | grep -i "filelog\|loki\|error" @@ -675,7 +678,7 @@ Expected: > 0 results. curl -s http://localhost:3100/ready ``` 4. Verify the filelog receiver glob pattern matches your log files: - The default pattern is `/var/log/rippled/*/debug.log` + The default pattern is `/var/log/xrpld/*/debug.log` ### Grafana trace-log links not working (Phase 8) diff --git a/docker/telemetry/docker-compose.yml b/docker/telemetry/docker-compose.yml index f5061d11a8..cffe3d139a 100644 --- a/docker/telemetry/docker-compose.yml +++ b/docker/telemetry/docker-compose.yml @@ -36,12 +36,13 @@ services: volumes: # Mount collector pipeline config (receivers → processors → exporters) - ./otel-collector-config.yaml:/etc/otel-collector-config.yaml:ro - # Mount rippled log directories for filelog receiver. - # User-run xrpld writes to /var/log/xrpld//debug.log. - # Integration test still writes to /tmp/xrpld-integration/. - # Both are mounted read-only so the collector can tail debug.log files. - - /var/log/xrpld:/var/log/rippled:ro - - /tmp/xrpld-integration:/var/log/rippled-integration:ro + # Mount the xrpld log root for the filelog receiver. The telemetry + # configs write to docker/telemetry/data/logs//debug.log, so + # the default source is the repo-relative ./data/logs — user-owned and + # needing no root, so `docker compose up` works with no setup. Override + # XRPLD_LOG_DIR to point at another root (e.g. the integration test sets + # it to its own workdir). Mounted read-only so the collector only tails. + - ${XRPLD_LOG_DIR:-./data/logs}:/var/log/xrpld:ro depends_on: - tempo - loki diff --git a/docker/telemetry/integration-test.sh b/docker/telemetry/integration-test.sh index a92633bbc4..2442cdff35 100755 --- a/docker/telemetry/integration-test.sh +++ b/docker/telemetry/integration-test.sh @@ -185,7 +185,10 @@ mkdir -p "$WORKDIR" # Step 2: Start observability stack # --------------------------------------------------------------------------- log "Starting observability stack..." -docker compose -f "$COMPOSE_FILE" up -d +# Point the collector's log mount at this test's workdir so it tails the +# per-node debug.log files this script generates. The compose default +# (./data/logs) is for user-run xrpld; the test owns its own log root. +XRPLD_LOG_DIR="$WORKDIR" docker compose -f "$COMPOSE_FILE" up -d log "Waiting for otel-collector to be ready..." for attempt in $(seq 1 30); do diff --git a/docker/telemetry/otel-collector-config.yaml b/docker/telemetry/otel-collector-config.yaml index de9a3ce06f..0c38a872fd 100644 --- a/docker/telemetry/otel-collector-config.yaml +++ b/docker/telemetry/otel-collector-config.yaml @@ -15,7 +15,7 @@ # span-derived metrics. # # The filelog receiver tails xrpld's debug.log files under -# /var/log/rippled/ (mounted from the host). A regex_parser operator +# /var/log/xrpld/ (mounted from the host). A regex_parser operator # extracts timestamp, partition, severity, and optional trace_id/span_id # fields injected by Logs::format(). Parsed logs are exported to Grafana # Loki for log-trace correlation. @@ -36,11 +36,7 @@ receivers: # trace_id, span_id, message) via regex. The trace_id and span_id are # optional — only present when the log was emitted within an active span. filelog: - # Tails both user-run xrpld logs (/var/log/xrpld/...) - # and integration-test logs (/tmp/xrpld-integration/...). - include: - - /var/log/rippled/*/debug.log - - /var/log/rippled-integration/*/debug.log + include: [/var/log/xrpld/*/debug.log] operators: # Log format emitted by Logs::format() is: # YYYY-Mmm-DD HH:MM:SS.ffffff UTC : [trace_id=... span_id=...] diff --git a/docker/telemetry/xrpld-telemetry-mainnet.cfg b/docker/telemetry/xrpld-telemetry-mainnet.cfg index dd8235d89b..3ef12e7c2f 100644 --- a/docker/telemetry/xrpld-telemetry-mainnet.cfg +++ b/docker/telemetry/xrpld-telemetry-mainnet.cfg @@ -95,7 +95,7 @@ docker/telemetry/data # --- Logging ---------------------------------------------------------------- [debug_logfile] -/var/log/xrpld/mainnet/debug.log +docker/telemetry/data/logs/mainnet/debug.log [rpc_startup] { "command": "log_level", "severity": "warning" } diff --git a/docker/telemetry/xrpld-telemetry.cfg b/docker/telemetry/xrpld-telemetry.cfg index 5868e76eb6..9b4df176b8 100644 --- a/docker/telemetry/xrpld-telemetry.cfg +++ b/docker/telemetry/xrpld-telemetry.cfg @@ -93,7 +93,7 @@ docker/telemetry/data # --- Logging ---------------------------------------------------------------- [debug_logfile] -/tmp/xrpld-integration/devnet/debug.log +docker/telemetry/data/logs/devnet/debug.log [rpc_startup] { "command": "log_level", "severity": "debug" } diff --git a/docs/telemetry-runbook.md b/docs/telemetry-runbook.md index 676b42060c..7cb23c77ac 100644 --- a/docs/telemetry-runbook.md +++ b/docs/telemetry-runbook.md @@ -1157,6 +1157,8 @@ This enables bidirectional navigation between logs and traces in Grafana: Log files are ingested by the OTel Collector's `filelog` receiver, which tails `debug.log` files and parses them with a regex that extracts `timestamp`, `partition`, `severity`, `trace_id`, `span_id`, and `message` fields. Parsed entries are exported to Grafana Loki. +The receiver tails `/var/log/xrpld/*/debug.log` inside the collector container. docker-compose bind-mounts the host log root there; the source defaults to the repo-relative `docker/telemetry/data/logs`, which the telemetry configs write to (`data/logs//debug.log`) and which needs no root. To tail logs from elsewhere, set `XRPLD_LOG_DIR` before `docker compose up` (the integration test does this to point at its own workdir). The single trailing `*` matches one per-network or per-node subdirectory. + ### LogQL Query Examples The OTel Collector emits logs to Loki with `service_name="xrpld"` (not `job="xrpld"`). @@ -1241,10 +1243,10 @@ The `getKBUsed*()` methods require SQLite databases to exist. If running with ### No logs in Loki -- Verify the log file mount in docker-compose.yml points to the correct xrpld log directory +- Verify the log file mount in docker-compose.yml points to the correct xrpld log directory (default source `docker/telemetry/data/logs`, or the `XRPLD_LOG_DIR` override) and that xrpld actually writes `debug.log` there - Check OTel Collector logs for filelog receiver errors: `docker compose logs otel-collector` - Verify Loki is running: `curl http://localhost:3100/ready` -- Check the filelog receiver glob pattern matches your log file paths +- Check the filelog receiver glob `/var/log/xrpld/*/debug.log` matches your log layout — the log file must sit one subdirectory below the mount root ## Performance Tuning diff --git a/include/xrpl/server/NetworkOPs.h b/include/xrpl/server/NetworkOPs.h index ed2dbbb220..dab26dd966 100644 --- a/include/xrpl/server/NetworkOPs.h +++ b/include/xrpl/server/NetworkOPs.h @@ -101,6 +101,13 @@ public: [[nodiscard]] virtual OperatingMode getOperatingMode() const = 0; + /** Time spent in the current operating mode so far, in microseconds. + Same value as `server_state_duration_us` in server_info; exposed as a + lightweight accessor so metrics can read it without building the full + server_info JSON on every collection tick. + */ + [[nodiscard]] virtual std::chrono::microseconds + getServerStateDurationUs() const = 0; [[nodiscard]] virtual std::string strOperatingMode(OperatingMode const mode, bool const admin = false) const = 0; [[nodiscard]] virtual std::string diff --git a/src/xrpld/app/misc/NetworkOPs.cpp b/src/xrpld/app/misc/NetworkOPs.cpp index 7bfa711ee7..da34663698 100644 --- a/src/xrpld/app/misc/NetworkOPs.cpp +++ b/src/xrpld/app/misc/NetworkOPs.cpp @@ -276,6 +276,21 @@ class NetworkOPsImp final : public NetworkOPs .start = start_, .initialSyncUs = initialSyncUs_}; } + + /** + * Time spent in the current operating mode so far. This is the same + * quantity reported as `server_state_duration_us` in json(): the + * elapsed time since the last state transition. Thread-safe. + * + * @return Duration since entering the current state, in microseconds. + */ + std::chrono::microseconds + currentStateDurationUs() const + { + std::scoped_lock const lock(mutex_); + return std::chrono::duration_cast( + std::chrono::steady_clock::now() - start_); + } }; //! Server fees published on `server` subscription @@ -358,6 +373,9 @@ public: OperatingMode getOperatingMode() const override; + std::chrono::microseconds + getServerStateDurationUs() const override; + std::string strOperatingMode(OperatingMode const mode, bool const admin) const override; @@ -981,6 +999,12 @@ NetworkOPsImp::getOperatingMode() const return mode_; } +std::chrono::microseconds +NetworkOPsImp::getServerStateDurationUs() const +{ + return accounting_.currentStateDurationUs(); +} + inline std::string NetworkOPsImp::strOperatingMode(bool const admin /* = false */) const { diff --git a/src/xrpld/perflog/detail/PerfLogImp.cpp b/src/xrpld/perflog/detail/PerfLogImp.cpp index ca3a4d3c8e..f06df3f3ff 100644 --- a/src/xrpld/perflog/detail/PerfLogImp.cpp +++ b/src/xrpld/perflog/detail/PerfLogImp.cpp @@ -362,6 +362,10 @@ PerfLogImp::rpcEnd(std::string const& method, std::uint64_t const requestId, boo { // LCOV_EXCL_START UNREACHABLE("xrpl::perf::PerfLogImp::rpcEnd : valid requestId input"); + // Without an entry, startTime stays default-initialized; returning + // avoids recording a bogus (now - epoch) duration to the counters + // and OTel histogram below. UNREACHABLE does not halt release builds. + return; // LCOV_EXCL_STOP } } diff --git a/src/xrpld/telemetry/MetricsRegistry.cpp b/src/xrpld/telemetry/MetricsRegistry.cpp index 693df1fd5e..040cb47717 100644 --- a/src/xrpld/telemetry/MetricsRegistry.cpp +++ b/src/xrpld/telemetry/MetricsRegistry.cpp @@ -167,6 +167,22 @@ MetricsRegistry::start(std::string const& endpoint, std::string const& instanceI JLOG(journal_.info()) << "MetricsRegistry: starting, endpoint=" << endpoint << ", instanceId=" << instanceId; + initExporterAndProvider(endpoint, instanceId); + initSyncInstruments(); + registerAsyncGauges(); + + JLOG(journal_.info()) << "MetricsRegistry: started successfully"; +#else + (void)endpoint; + (void)instanceId; + (void)enabled_; +#endif // XRPL_ENABLE_TELEMETRY +} + +#ifdef XRPL_ENABLE_TELEMETRY +void +MetricsRegistry::initExporterAndProvider(std::string const& endpoint, std::string const& instanceId) +{ // Configure OTLP/HTTP metric exporter. otlp_http::OtlpHttpMetricExporterOptions exporterOpts; exporterOpts.url = endpoint; @@ -205,9 +221,11 @@ MetricsRegistry::start(std::string const& endpoint, std::string const& instanceI // Get a meter for all xrpld instruments. meter_ = provider_->GetMeter("xrpld", "1.0.0"); +} - // --- Create synchronous instruments --- - +void +MetricsRegistry::initSyncInstruments() +{ // RPC per-method counters and histogram. rpcStartedCounter_ = meter_->CreateUInt64Counter( "xrpld_rpc_method_started_total", "Total RPC method calls started"); @@ -251,17 +269,8 @@ MetricsRegistry::start(std::string const& endpoint, std::string const& instanceI // Note: xrpld_validation_agreements_total / xrpld_validation_missed_total // are monotonic ObservableCounters created in registerValidationTotalsCounters() // (below), observed from ValidationTracker's gross lifetime tallies. - - // Register all observable (async) gauges. - registerAsyncGauges(); - - JLOG(journal_.info()) << "MetricsRegistry: started successfully"; -#else - (void)endpoint; - (void)instanceId; - (void)enabled_; -#endif // XRPL_ENABLE_TELEMETRY } +#endif // XRPL_ENABLE_TELEMETRY void MetricsRegistry::detachCallbacks() noexcept @@ -288,9 +297,12 @@ MetricsRegistry::stop() // to detach first. callbacksDetached_.store(true, std::memory_order_release); - // Force-flush any pending metrics, then destroy the provider. - // This stops the PeriodicExportingMetricReader, which in turn - // stops invoking observable gauge callbacks. + // SDK teardown order: Shutdown() stops the PeriodicExportingMetricReader + // thread (so no further gauge callbacks fire) and performs the final + // collect-and-export drain itself. The trailing ForceFlush() is a + // redundant safety net (a no-op once the reader is shut down), then + // reset() destroys the provider. + provider_->Shutdown(); provider_->ForceFlush(); provider_.reset(); @@ -1018,7 +1030,20 @@ MetricsRegistry::registerPeerQualityGauge() int higherVersionCount = 0; int totalPeers = 0; int divergedCount = 0; - auto const ownVersion = std::string(BuildInfo::getVersionString()); + + // Encode a version string into BuildInfo's comparable numeric + // form. Peers report the full "rippled-3.3.0-b0" string while + // our baseline is the bare "3.3.0-b0", and SemanticVersion + // requires a leading digit, so strip any non-digit prefix + // first. Numeric encoding avoids the lexicographic bug where + // "2.3.0" > "2.10.0" and "rippled-..." > "3...". + auto const encodeVersion = [](std::string_view v) -> std::uint64_t { + auto const firstDigit = v.find_first_of("0123456789"); + if (firstDigit == std::string_view::npos) + return 0; + return BuildInfo::encodeSoftwareVersion(v.substr(firstDigit)); + }; + auto const ownEncoded = encodeVersion(BuildInfo::getVersionString()); app.getOverlay().foreach([&](std::shared_ptr const& peer) { ++totalPeers; @@ -1029,8 +1054,10 @@ MetricsRegistry::registerPeerQualityGauge() } if (pj.isMember(jss::version)) { + // Unparseable peer versions encode below ownEncoded, so + // the comparison correctly leaves them uncounted. auto const pv = pj[jss::version].asString(); - if (!pv.empty() && pv > ownVersion) + if (encodeVersion(pv) > ownEncoded) ++higherVersionCount; } // PeerImp::json() sets "track" to "diverged" when the peer's @@ -1232,9 +1259,11 @@ MetricsRegistry::registerStateTrackingGauge() } observe("state_value", stateValue); - // TODO: Wire time_in_current_state_seconds to StateAccounting - // once a public accessor is available on NetworkOPs. - observe("time_in_current_state_seconds", 0.0); + // Time spent in the current operating mode, sourced from + // NetworkOPs' StateAccounting via a lightweight accessor. + auto const stateDurUs = app.getOPs().getServerStateDurationUs(); + observe( + "time_in_current_state_seconds", static_cast(stateDurUs.count()) / 1e6); } catch (...) // NOLINT(bugprone-empty-catch) { diff --git a/src/xrpld/telemetry/MetricsRegistry.h b/src/xrpld/telemetry/MetricsRegistry.h index f0986b0b33..2cc154bc53 100644 --- a/src/xrpld/telemetry/MetricsRegistry.h +++ b/src/xrpld/telemetry/MetricsRegistry.h @@ -540,6 +540,23 @@ private: opentelemetry::nostd::shared_ptr validationMissedObservable_; + /** Build the OTLP/HTTP exporter, periodic reader, resource attributes and + histogram views, then create the MeterProvider and meter. Extracted + from start() to keep each function under the 80-line limit. + + @param endpoint OTLP/HTTP metrics endpoint URL. + @param instanceId service.instance.id resource attribute (may be empty). + */ + void + initExporterAndProvider(std::string const& endpoint, std::string const& instanceId); + + /** Create the synchronous instruments (RPC and job-queue counters and + histograms, plus the external dashboard parity counters). Extracted + from start() to keep each function under the 80-line limit. + */ + void + initSyncInstruments(); + /** Register all observable gauge callbacks with the OTel SDK. Dispatches to one helper per metric domain so that each helper stays well under the 80-line-per-function limit.