From 30d165da433e1d73a3e1b3ee9d412dbce03351db Mon Sep 17 00:00:00 2001 From: Pratik Mankawde <3397372+pratikmankawde@users.noreply.github.com> Date: Tue, 8 Sep 2026 16:43:41 +0100 Subject: [PATCH] fix(telemetry): bound integration-test assertions to the run under test check_statsd_metric queried rippled_rpc_requests, which no pipeline produces: the collector's statsd receiver runs with is_monotonic_counter, so the Prometheus exporter appends _total. A wrong name returns zero series rather than an error, so the assertion could not be told apart from a broken pipeline. All eight assertions were re-derived from how each metric is created in code; this was the only counter. Tempo searches carried no start/end, and tempo-data is a named volume that `docker compose down` preserves under a one-hour block retention, so the 17 span assertions could pass on an earlier local run's traces. Bound every search to this run, and tear the stack down with -v before starting so no earlier data is present to match. The service-name check now matches a whole line, because the tag-values endpoint ignores start/end. Add a gtest for the StatsD gauge that publishes its initial zero and for the counter that must publish nothing. Assert two metrics the harness never checked: a traffic-category gauge no message reaches, and io_context latency. --- docker/telemetry/integration-test.sh | 53 +++++- .../libxrpl/beast/insight/StatsDCollector.cpp | 153 ++++++++++++++++++ 2 files changed, 200 insertions(+), 6 deletions(-) create mode 100644 src/tests/libxrpl/beast/insight/StatsDCollector.cpp diff --git a/docker/telemetry/integration-test.sh b/docker/telemetry/integration-test.sh index c0327a7508..ddc9e79522 100755 --- a/docker/telemetry/integration-test.sh +++ b/docker/telemetry/integration-test.sh @@ -42,6 +42,11 @@ PROM="http://localhost:9090" PASS=0 FAIL=0 +# Unix seconds just before this run's nodes start. Every Tempo search is +# bounded to this run, so a previous run's traces cannot satisfy an assertion. +# Set in Step 5; check_span refuses to run while it is empty. +RUN_START="" + # --------------------------------------------------------------------------- # Helpers # --------------------------------------------------------------------------- @@ -62,11 +67,19 @@ die() { check_span() { local op="$1" local count + [ -n "$RUN_START" ] || die "check_span called before RUN_START was set" # -G is required: it moves the urlencoded params into the query string. # Without it curl POSTs them as a request body, and Tempo answers 200 # while ignoring the query — so every span name would look present. + # + # start/end bound the search to this run. Tempo keeps blocks for + # block_retention (tempo.yaml, 1h) on a named volume, so without a bound + # an older run's spans answer for this one. The end margin covers spans + # exported while this query is in flight. count=$(curl -sfG "$TEMPO/api/search" \ --data-urlencode "q={resource.service.name=\"xrpld\" && name=\"$op\"}" \ + --data-urlencode "start=$RUN_START" \ + --data-urlencode "end=$(($(date +%s) + 60))" \ --data-urlencode "limit=5" | jq '.traces | length' 2>/dev/null || echo 0) if [ "$count" -gt 0 ]; then @@ -88,8 +101,9 @@ cleanup() { done # Also kill any straggling xrpld processes from our workdir pkill -f "$WORKDIR" 2>/dev/null || true - # Stop docker stack - docker compose -f "$COMPOSE_FILE" down 2>/dev/null || true + # Stop docker stack. -v also drops the tempo-data volume: plain `down` + # keeps it, and retained traces would then answer a later run's searches. + docker compose -f "$COMPOSE_FILE" down -v 2>/dev/null || true # Remove workdir rm -rf "$WORKDIR" log "Cleanup complete." @@ -131,6 +145,10 @@ pkill -f "$WORKDIR" 2>/dev/null || true pkill -f "xrpld-telemetry.cfg" 2>/dev/null || true sleep 2 rm -rf "$WORKDIR" +# A run that reached the summary left the stack up, so nothing has torn it +# down. Do it here, with -v: Tempo's traces and Prometheus' samples must not +# survive into this run, or an assertion can pass on the previous run's data. +docker compose -f "$COMPOSE_FILE" down -v 2>/dev/null || true mkdir -p "$WORKDIR" # --------------------------------------------------------------------------- @@ -361,6 +379,10 @@ done # --------------------------------------------------------------------------- log "Starting $NUM_NODES xrpld nodes..." +# Lower bound for every Tempo search below. Only these nodes have a +# [telemetry] section, so nothing before this instant belongs to this run. +RUN_START=$(date +%s) + for i in $(seq 1 "$NUM_NODES"); do NODE_DIR="$WORKDIR/node$i" "$XRPLD" --conf "$NODE_DIR/xrpld.cfg" --start >"$NODE_DIR/stdout.log" 2>&1 & @@ -497,7 +519,10 @@ log "Verifying spans in Tempo..." # Check service registration services=$(curl -sf "$TEMPO/api/v2/search/tag/resource.service.name/values" | jq -r '.tagValues[].value' 2>/dev/null || echo "") -if echo "$services" | grep -q "xrpld"; then +# Whole-line match: a substring match would also accept a value that merely +# contains "xrpld". This endpoint ignores start/end (measured), so its only +# protection against a previous run is the teardown in Step 1. +if echo "$services" | grep -Fxq "xrpld"; then ok "Service 'xrpld' registered in Tempo" else fail "Service 'xrpld' NOT found in Tempo (found: $services)" @@ -598,12 +623,28 @@ check_statsd_metric "rippled_State_Accounting_Full_duration" check_statsd_metric "rippled_Peer_Finder_Active_Inbound_Peers" check_statsd_metric "rippled_Peer_Finder_Active_Outbound_Peers" -# RPC counters (only if RPC was exercised — should be true from Steps 5-8) -check_statsd_metric "rippled_rpc_requests" +# RPC counters (only if RPC was exercised — should be true from Steps 5-8). +# This one is a beast::insight Counter, and the statsd receiver runs with +# is_monotonic_counter: true, so the Prometheus exporter appends _total. The +# gauges above keep their bare name. +check_statsd_metric "rippled_rpc_requests_total" -# Overlay traffic +# Overlay traffic. "total" is the TrafficCount category name, not a Prometheus +# suffix — the metric is a gauge, so nothing is appended. check_statsd_metric "rippled_total_Bytes_In" +# A gauge for a traffic category no message reaches on a private 6-node +# network: ledger replay is off, so nothing is ever counted here. A StatsD +# gauge is only re-sent when its value changes, so this series exists solely +# because a gauge starts dirty and flushes its initial zero. +check_statsd_metric "rippled_replay_delta_request_Messages_In" + +# io_context latency is an Event, so it reaches Prometheus only when notify() +# is called: on the first sample, and after that only at >= 10 ms. This covers +# the metric arriving at all, not the first-sample path on its own — a busy +# startup can also produce a >= 10 ms sample. +check_statsd_metric "rippled_ios_latency_count" + # --------------------------------------------------------------------------- # Step 11: Summary # --------------------------------------------------------------------------- diff --git a/src/tests/libxrpl/beast/insight/StatsDCollector.cpp b/src/tests/libxrpl/beast/insight/StatsDCollector.cpp new file mode 100644 index 0000000000..7024318ec8 --- /dev/null +++ b/src/tests/libxrpl/beast/insight/StatsDCollector.cpp @@ -0,0 +1,153 @@ +#include + +#include +#include +#include +#include + +#include +#include +#include +#include +#include + +#include + +#include +#include +#include +#include + +namespace beast::insight { + +/** + * Reads the datagrams a StatsDCollector sends, over loopback. + * + * StatsDCollector ──UDP──> LoopbackStatsDServer + * │ + * └── owns ──> boost::asio::io_context + * + * Binds an ephemeral port, so a caller must read port() and point the + * collector at it. The collector flushes on a one-second timer, so receive() + * takes a timeout rather than blocking forever. + * + * @code + * // Primary use: read the one datagram a metric produces. + * LoopbackStatsDServer server; + * auto collector = StatsDCollector::make( + * ip::Endpoint::fromString("127.0.0.1:" + std::to_string(server.port())), + * "test", + * Journal(Journal::getNullSink())); + * auto const gauge = collector->makeGauge("g"); + * EXPECT_EQ(server.receive(std::chrono::seconds(10)), "test.g:0|g\n"); + * + * // Edge case: nothing was sent, so the wait runs out and returns empty. + * EXPECT_EQ(server.receive(std::chrono::seconds(3)), std::string()); + * @endcode + * + * @note Not thread-safe, and receive() must not be called concurrently with + * itself. + * @note Returns one datagram per call. A test that needs several must call + * receive() again; there is no accumulation. + */ +class LoopbackStatsDServer +{ +public: + LoopbackStatsDServer() + : socket_( + ioContext_, + boost::asio::ip::udp::endpoint(boost::asio::ip::make_address_v4("127.0.0.1"), 0)) + { + } + + /** + * The loopback port to point the collector at. + * + * @return the ephemeral port this server is bound to. + */ + [[nodiscard]] unsigned short + port() const + { + return socket_.local_endpoint().port(); + } + + /** + * Waits for one datagram. + * + * @param timeout How long to wait before giving up. + * @return the datagram's bytes, or an empty string if none arrived in + * time. + */ + std::string + receive(std::chrono::milliseconds timeout) + { + std::string received; + socket_.async_receive( + boost::asio::buffer(buffer_), + [&received, this](boost::system::error_code const& ec, std::size_t bytes) { + if (!ec) + received.assign(buffer_.data(), bytes); + }); + ioContext_.restart(); + ioContext_.run_for(timeout); + socket_.cancel(); + return received; + } + +private: + /** + * Drives the receive. Restarted per receive() call. + */ + boost::asio::io_context ioContext_; + + /** + * Bound to 127.0.0.1 on an ephemeral port for the object's lifetime. + */ + boost::asio::ip::udp::socket socket_; + + /** + * Landing space for one datagram. Sized well above the collector's + * 1472-byte packet limit. + */ + std::array buffer_{}; +}; + +/** + * A gauge nobody touches still publishes its zero. + * + * A gauge is only marked dirty when its value changes, so a gauge left at zero + * would otherwise never be sent and would never exist downstream. Absent and + * zero must not look the same to an operator. + */ +TEST(StatsDCollector, UntouchedGaugePublishesInitialZero) +{ + LoopbackStatsDServer server; + auto const address = ip::Endpoint::fromString("127.0.0.1:" + std::to_string(server.port())); + + auto collector = StatsDCollector::make(address, "test", Journal(Journal::getNullSink())); + // Created and then left alone: no set(), no increment(). + auto const gauge = collector->makeGauge("untouched"); + + EXPECT_EQ(server.receive(std::chrono::seconds(10)), std::string("test.untouched:0|g\n")); +} + +/** + * A counter nobody increments publishes nothing. + * + * This is the other half of the rule above, and it is why the fix is a gauge + * starting dirty rather than a flush of everything on the first tick. A counter + * reports events, so an unsent counter and a zero counter mean the same thing. + */ +TEST(StatsDCollector, UntouchedCounterPublishesNothing) +{ + LoopbackStatsDServer server; + auto const address = ip::Endpoint::fromString("127.0.0.1:" + std::to_string(server.port())); + + auto collector = StatsDCollector::make(address, "test", Journal(Journal::getNullSink())); + auto const counter = collector->makeCounter("untouched"); + + // Three seconds spans several one-second flush ticks. + EXPECT_EQ(server.receive(std::chrono::seconds(3)), std::string()); +} + +} // namespace beast::insight