feat: Phase 1c: RPC telemetry integration — tracing utils, handler instrumentation - #6438
feat: Phase 1c: RPC telemetry integration — tracing utils, handler instrumentation#6438pratikmankawde wants to merge 118 commits into
Conversation
Codecov Report❌ Patch coverage is 📢 Thoughts on this report? Let us know! |
1bfdf71 to
b5fb71c
Compare
137a55f to
2878ad5
Compare
2878ad5 to
0d91a94
Compare
478d3fe to
db2374b
Compare
| span.setError(rpc_span::val::error); | ||
| } | ||
| else | ||
| { |
There was a problem hiding this comment.
Unguarded .asString() throws on non-string command/method, masking too_busy response. Verify type with .isString():
| { | |
| // Guard field access before calling .asString() | |
| if (context.params.isMember(jss::command) && context.params[jss::command].isString()) { | |
| auto cmd = context.params[jss::command].asString(); | |
| // ... use cmd | |
| } else { | |
| // Fall back for malformed input instead of throwing | |
| return rpc_span::val::unknownCommand; | |
| } |
There was a problem hiding this comment.
✅ Auto-resolved: the latest review no longer flags this issue, so it appears to have been addressed. If that is not correct, reopen this thread and it will be re-checked on the next review.
There was a problem hiding this comment.
✅ Auto-resolved: the latest review no longer flags this issue, so it appears to have been addressed. If that is not correct, reopen this thread and it will be re-checked on the next review.
There was a problem hiding this comment.
✅ Auto-resolved: the latest review no longer flags this issue, so it appears to have been addressed. If that is not correct, reopen this thread and it will be re-checked on the next review.
There was a problem hiding this comment.
✅ Auto-resolved: the latest review no longer flags this issue, so it appears to have been addressed. If that is not correct, reopen this thread and it will be re-checked on the next review.
…hase1c-rpc-integration Signed-off-by: Pratik Mankawde <3397372+pratikmankawde@users.noreply.github.com>
There was a problem hiding this comment.
Rule F has a blind spot: the CALLSITE regex misses ScopedSpanGuard constructor and ::freshRoot() factory methods, allowing literals in these span-creation patterns to bypass validation. This is intentional (to avoid std::span false positives) but leaves a gap—see inline for suggested fix or documentation approach.
| # `span`/`rootSpan`/`childSpan` additionally require the `SpanGuard`/`.`/`->` | ||
| # receiver; `setAttribute`/`addEvent` only ever exist on a guard, so a `.`/`->` | ||
| # suffices. `rootSpan` shares `span`'s (cat, prefix, name) signature. | ||
| CALLSITE = re.compile( |
There was a problem hiding this comment.
Rule F regex doesn't catch ScopedSpanGuard() constructor or ::freshRoot() calls—extend receiver/method alternation and CONSTANT_ARG_POSITIONS, or document the gap:
There was a problem hiding this comment.
✅ Auto-resolved: the latest review no longer flags this issue, so it appears to have been addressed. If that is not correct, reopen this thread and it will be re-checked on the next review.
There was a problem hiding this comment.
✅ Auto-resolved: the latest review no longer flags this issue, so it appears to have been addressed. If that is not correct, reopen this thread and it will be re-checked on the next review.
There was a problem hiding this comment.
✅ Auto-resolved: the latest review no longer flags this issue, so it appears to have been addressed. If that is not correct, reopen this thread and it will be re-checked on the next review.
…hase1c-rpc-integration
…hase1c-rpc-integration
…hase1c-rpc-integration
…hase1c-rpc-integration
…hase1c-rpc-integration # Conflicts: # src/xrpld/app/main/GRPCServer.cpp
…hase1c-rpc-integration
…hase1c-rpc-integration
| // Fresh root so each WS message is its own trace. | ||
| auto span = ScopedSpanGuard::freshRoot( | ||
| TraceCategory::Rpc, rpc_span::prefix::rpc, rpc_span::op::wsMessage); | ||
| span.setError(rpc_span::val::invalidJson); |
There was a problem hiding this comment.
Missing rpc_status attribute on ws_message error. Set alongside setError() to match other error paths:
| span.setError(rpc_span::val::invalidJson); | |
| span.setAttribute(rpc_span::attr::rpcStatus, rpc_span::val::error); |
| span.setError(rpc_span::val::invalidJson); | |
| span.setAttribute(rpc_span::attr::rpcStatus, rpc_span::val::error); | |
| span.setError(rpc_span::val::invalidJson); |
resolveCommandSpanName() and the error span in doCommand() exist only to name and label a telemetry span. With telemetry compiled out the resolver still ran on every RPC that fillHandler() rejects: up to five json isMember lookups, up to three string copies, a virtual config() call and a handler-table lookup, all to build a name nobody records. A storm of malformed requests paid that cost once per request. A runtime `if (span)` guard cannot work here. The resolver's result is the span name itself, passed as the third argument of the ScopedSpanGuard constructor, so no span object exists yet to test. That leaves `#ifdef XRPL_ENABLE_TELEMETRY`, matching the house style used elsewhere. The guard covers the whole telemetry block at the call site and the helper definition too, so the file-static helper does not become an unreferenced function, which the build rejects because warnings are errors. injectError() and the error return stay outside the guard, so behaviour on the failure path is unchanged. No include is orphaned: ErrorCodes.h, SpanGuard.h, RpcSpanNames.h and <string_view> all keep uses outside the guards. With telemetry on nothing changes: only comments and the four directives were added.
…hase1c-rpc-integration
…hase1c-rpc-integration
…hase1c-rpc-integration
There was a problem hiding this comment.
The instrumentation is broadly well-designed (constant-only span names/attributes enforced by a new CI naming check, careful root/child span nesting, and explicit spanHadError/final-status handling in ServerHandler::processRequest). However, there's a repeated gap: three exception (catch (std::exception...)) paths call recordException() and set the custom status attribute to "error", but never call setError() to set the native OTel span status. recordException only attaches an exception event — it does not change span status per the OTel spec — so these spans will report status Unset even though they represent real failures, silently defeating the {status.code=error} queries this PR is built around. The same PR gets this right for the non-exception error paths (e.g. GRPCServer's result.second.ok() branch, and ServerHandler::processRequest's aggregated spanHadError check), which makes the omission in these three spots look like an oversight rather than a deliberate choice.
pratikmankawde
left a comment
There was a problem hiding this comment.
Review of the RPC/gRPC telemetry integration and the new naming check.
New findings: 0 BLOCKING, 1 SHOULD-FIX, 1 NIT.
Pass over the existing threads: 9 were open, 6 are now resolved, 3 remain. Four of the six were resolved because the finding does not hold — the three "catch block is missing setError()" comments all assume recordException() only adds an event, but SpanGuard::recordException (src/libxrpl/telemetry/SpanGuard.cpp:418-430) sets SetStatus(kError, e.what()) on :429 as well, so those spans are already Error. The jr[jss::result][jss::error] suggestion on ServerHandler.cpp:562 would have broken that line, since jr is reassigned to its own nested result on :539.
The most important thing still open is the Rule F regex gap on .github/scripts/otel-naming/check_otel_naming.py:139. I confirmed it by running this branch's own iter_calls(): it sees none of the nine span-creating sites here (the bare ScopedSpanGuard(cat, prefix, name) constructor and ScopedSpanGuard::freshRoot), and the check-otel-naming job on this head still printed OK: F: no string-literal keys/names at telemetry call-sites while include/xrpl/telemetry/CoroAwareContextStorage.h:59 and :68 pass literal span names that Rule F is documented to catch. Details and the incomplete-patch caveat are in the reply on the duplicate thread.
One thing I checked and found correct: the CI wiring for the new gate is complete — added to the should-run path filter, declared as a job, and listed in the aggregate needs, and it runs on this PR in 8s.
| // visible to {status.code=error} queries. | ||
| if (ret) | ||
| { | ||
| span.setError(rpc_span::val::error); |
There was a problem hiding this comment.
[SHOULD-FIX · Low] — The span's error description is the fixed string "error", so the trace records that the request failed but not why.
rpc_span::val::error resolves to "error", and setError's argument is the OTel status description (SpanGuard::setError → SetStatus(kError, std::string(description)), src/libxrpl/telemetry/SpanGuard.cpp:404-408). The status code already says "error", so this description adds nothing: an operator looking at a failed rpc.command.* span in Tempo sees error and has to go to the logs to learn whether it was tooBusy, noPermission, invalidParams or something else.
The reason is in hand at this point. ret is an rpc::Status, which exposes codeString() and message() (src/xrpld/rpc/Status.h:64-65 and :135-136) plus toString() (:144-145). The sibling error path 90 lines below already does the informative thing — RPCHandler.cpp:295 is span.setError(getErrorInfo(error).token.cStr()), which records e.g. tooBusy. Using ret.codeString() or ret.toString() here would make the two paths consistent.
Same fixed-string problem at the second site, src/xrpld/rpc/detail/ServerHandler.cpp:1098, which is also span.setError(rpc_span::val::error). There the reason is available too — the surrounding block already distinguishes spanHadError from httpStatus >= 400 (:1095), so the description could say which. Raising both here rather than twice.
Not fixed downstream: on pratik/otel-phase2-rpc-tracing, pratik/otel-phase5-docs-deployment and pratik/otel-phase10-workload-validation the line is still span.setError(rpc_span::val::error) (at :203 on each), so the same change is wanted here and carries forward.
| if (result.second.ok()) | ||
| { | ||
| span.setAttribute(grpc_span::attr::grpcStatus, grpc_span::val::success); | ||
| span.setOk(); |
There was a problem hiding this comment.
[NIT · Low] — Setting Ok is discouraged for instrumentation by the OpenTelemetry spec, and on this particular span it is the one thing that could suppress an error the code otherwise records correctly.
This PR introduces five setOk() calls: here, src/xrpld/rpc/detail/RPCHandler.cpp:206, and src/xrpld/rpc/detail/ServerHandler.cpp:239, :569, :1102. The OpenTelemetry trace API specification says of instrumentation:
- "Generally, Instrumentation Libraries SHOULD NOT set the status code to
Ok, unless explicitly configured to do so." - "Instrumentation Libraries SHOULD leave the status code as
Unsetunless there is an error." - "Analysis tools SHOULD respond to an
Okstatus by suppressing any errors they would otherwise generate." - "These values form a total order:
Ok > Error > Unset" and "When span status is set toOkit SHOULD be considered final and any further attempts to change it SHOULD be ignored."
Unset is the success signal the spec expects from instrumentation; Ok is reserved for an application or operator asserting verified success, and it carries the extra meaning that analysis tools should stop reporting errors on that span.
Why this site specifically: setOk() on :253 is followed inside the same try by responder_.Finish(...) on :260, and the catch block on :264-270 calls recordException(ex), which itself sets Error (src/libxrpl/telemetry/SpanGuard.cpp:429). Under the finality rule above, an Error arriving after Ok on the same span should be ignored — so if anything after the status decision can throw, this span reports success for a failed call. Dropping the four setOk() calls and letting success stay Unset removes that ordering hazard entirely, and {status.code=error} queries keep working because the error paths all set Error explicitly.
Two things I did not verify and am not claiming: whether gRPC's responder_.Finish can throw, and whether opentelemetry-cpp actually implements the spec's total order (the SDK .cc sources are not shipped in the Conan package, only headers). The spec-conformance point stands on its own regardless, and it matters here because this PR sets the pattern that the nine downstream PRs copy — the same five calls are still present unchanged on pratik/otel-phase10-workload-validation.
Flagged as a nit because nothing observable is wrong today: at the other four sites the Ok is the last status write on its span.
…hase1c-rpc-integration
| # (static factories) | ||
| # - `<obj>.span(` / `<obj>->setAttribute(` etc. (member call) | ||
| # `span`/`rootSpan`/`childSpan` additionally require the `SpanGuard`/`.`/`->` | ||
| # receiver; `setAttribute`/`addEvent` only ever exist on a guard, so a `.`/`->` |
There was a problem hiding this comment.
CALLSITE regex misses ScopedSpanGuard::freshRoot() and bare constructor. Also update CONSTANT_ARG_POSITIONS:
CALLSITE = re.compile(
r"(?:(?:SpanGuard|ScopedSpanGuard)::|\.|->)\s*(setAttribute|addEvent|span|rootSpan|childSpan|freshRoot)\s*\(|"
r"\bScopedSpanGuard\s*\("
)
Add entries: "freshRoot": {1, 2} and "ScopedSpanGuard": {1, 2}.
| // yield in doRipplePathFind: the coro-aware context storage moves this | ||
| // scope with the coroutine on resume (it is never stranded on a worker's | ||
| // thread-local stack), so nesting and log-trace correlation both hold. | ||
| auto span = ScopedSpanGuard(TraceCategory::Rpc, rpc_span::prefix::rpc, rpc_span::op::process); |
There was a problem hiding this comment.
Each HTTP request already starts a rpc.http_request span at the transport boundary. This nested rpc.process span uses the same TraceCategory::Rpc, and SpanGuard::span() maps every span in that category to SpanKind::kServer. As a result, one inbound request produces multiple nested server spans even though rpc.process represents work performed internally after the request has been received.
SpanKind describes an operation's role, not merely its subsystem. Consumers filtering for server spans can therefore treat this internal span as another inbound request, distorting request counts, latency metrics, and service-graph analysis. Please make the kind selectable independently of TraceCategory and use kInternal here, reserving kServer for the actual remote-request boundary.
| * { | ||
| * auto child = parent.childSpan("tx.apply"); | ||
| * child.setAttribute("tx_type", txType); | ||
| * auto child = parent.childSpan(rpc_span::op::process); |
There was a problem hiding this comment.
This example does not create the parent-child relationship described by its heading SpanGuard::span() creates and owns a span but deliberately does not activate it in the runtime context.
Although childSpan() is invoked as a member of parent, its implementation only uses parent to verify that the guard is active; it then obtains the parent context from RuntimeContext::GetCurrent() rather than from parent.impl_->span.
Consequently, if another span was ambient before this example, both parent and child inherit that span and become siblings. If no span was ambient, they become separate roots. Following this example would therefore produce a broken trace hierarchy, preventing viewers from attributing the child operation's duration and errors to the intended parent operation.
May have to use a ScopedSpanGuard so parent is active when childSpan() reads the current context, or capture parent.spanContext() and pass it to the explicit SpanGuard::childSpan(name, context) overload.
| continue | ||
| # PromQL `sum by (a, b)` and `{label="..."}` references. | ||
| labels: Set[str] = set() | ||
| for m in re.finditer(r"by\s*\(([^)]*)\)", text): |
There was a problem hiding this comment.
Could we parse the JSON before checking the query strings? Quotes inside dashboard queries are escaped in the file, so this regex misses selector labels. I tested a dashboard containing rpc_calls_total{bogus_label="x"} with a nonempty L1 set, and Rule D reported no violations, while by (bogus_label) was caught.
A regression test using json.dumps and an unknown selector label would cover this.
import json
import runpy
tests = runpy.run_path(".github/scripts/otel-naming/test_check_otel_naming.py")
check = tests"RuleDDashboards"._run
query = 'rpc_calls_total{bogus_label="x"}'
dashboard = json.dumps({"panels": [{"targets": [{"expr": query}]}]})
found = check(dashboard, {"command"})
assert found == ["bogus_label"], f"Missed unknown label: {found}"
| Status | ||
| callMethod(JsonContext& context, Method method, std::string const& name, Object& result) | ||
| { | ||
| // Scoped so this command nests under rpc.process and becomes the ambient |
There was a problem hiding this comment.
Could we extend the existing HTTP, WebSocket and gRPC tests to enable telemetry and capture the emitted spans with an in-memory exporter? We already have the test application and clients, so this shouldn't need a Collector or Tempo. Alongside the response assertions, check the expected span names, counts and attribute values—the current tests wouldn't notice if a span disappeared or carried incorrect metadata.
| GRPCServerImpl::CallData<Request, Response>::process(std::shared_ptr<JobQueue::Coro> coro) | ||
| { | ||
| using namespace telemetry; | ||
| auto span = SpanGuard::span(TraceCategory::Rpc, grpc_span::prefix::grpc, name_); |
There was a problem hiding this comment.
Could we test the emitted span name and method attribute for each of the four gRPC methods? The existing TLS tests only call GetLedger and check whether the request succeeds; they wouldn't catch a method being given the wrong telemetry name. We could reuse the in-process test server with an in-memory exporter and call each method twice to also check that the name survives the replacement listener created by clone().
|
|
||
| def test_builtin_labels_not_flagged(self): | ||
| self.assertEqual( | ||
| self._run('"expr": "sum by (le, span_name, exported_instance) (x)"', set()), |
There was a problem hiding this comment.
These three tests pass an empty L1 set, which makes Rule D skip validation entirely. I ran them and confirmed that's why they pass—not because the labels were checked and accepted. Please use a nonempty L1 set and check that the rule actually ran. For the infrastructure labels, use explicit test values rather than reading them from the allowlist we're trying to test.
High Level Overview of Change
Instruments the RPC, WebSocket and gRPC entry points with spans, and adds the CI check that keeps span and attribute names consistent from here on.
No need to review tasklist files.
Context of Change
SpanGuard::span(TraceCategory, prefix, name)returns an active span or a zero-cost null guard depending on runtime config; withXRPL_ENABLE_TELEMETRYundefined every method is an inline no-op. Span names are compile-time constants composed withStaticStr<N>/join(), declared in a per-subsystem header next to the code that emits them.Spans added
rpc.http_requestServerHandler::processSession(Session)rpc.ws_message,rpc.ws_upgradeServerHandlerrpc.processServerHandler::processRequest()rpc.command.{name}RPC::callMethod()too_busy, unknown command, no permission)grpc.{method}GRPCServerCallData::process()Naming CI —
.github/scripts/otel-naming/check_otel_naming.pyplusreusable-check-otel-naming.yml, wired intoon-pr.yml. It enforces lower_snake_case attribute keys, forbids stray dotted keys, and rejects string literals in name/key argument positions so every name resolves to a*SpanNames.hconstant. The checker ships with its own pytest suite.API Impact
libxrplchange (xrpl/telemetry/SpanNames.h)Test Plan
pytest .github/scripts/otel-naming/test_check_otel_naming.py