feat: Phase 3: Transaction tracing — protobuf context, PeerImp, NetworkOPs - #6425
feat: Phase 3: Transaction tracing — protobuf context, PeerImp, NetworkOPs#6425pratikmankawde wants to merge 155 commits into
Conversation
04ddafd to
9d7d59a
Compare
Codecov Report❌ Patch coverage is 📢 Thoughts on this report? Let us know! |
751792d to
1a25348
Compare
1a25348 to
b4d7297
Compare
b4d7297 to
587d312
Compare
587d312 to
f504d9b
Compare
f504d9b to
a6d831e
Compare
a6d831e to
71c9bba
Compare
| */ | ||
| if (stx->isFlag(tfInnerBatchTxn)) | ||
| { | ||
| span->setAttribute(tx_span::attr::txStatus, tx_span::val::rejectedInnerBatch); |
There was a problem hiding this comment.
Missing suppressed attribute violates stated invariant (every exit sets it). Set to false alongside tx_status:
| span->setAttribute(tx_span::attr::txStatus, tx_span::val::rejectedInnerBatch); | |
| span.setAttribute("suppressed", false); |
| span->setAttribute(tx_span::attr::txStatus, tx_span::val::rejectedInnerBatch); | |
| span->setAttribute(tx_span::attr::suppressed, false); | |
| span->setAttribute(tx_span::attr::txStatus, tx_span::val::rejectedInnerBatch); |
isValidSpanId and std::uint8_t are named only inside the telemetry-enabled branch of txReceiveSpan, so with telemetry compiled out both includes are unused and clang-tidy fails the build on warnings-as-errors.
Both tx.receive and tx.process set their attributes unconditionally, so the work happened even when nothing consumed it: a 64-char hash string allocation, a getCurrentLedgerIndex() call that takes the ledger master's lock, a TxFormats lookup, a peer-version string copy, and in tx.process a fee and sequence decode. tx.receive runs before the duplicate check, so duplicate relays paid for it too. Guard both blocks on the span being live. When telemetry is compiled out the guard's operator bool() is a literal false and the block is eliminated; when it is compiled in the block is skipped for any span that is not being recorded, which the previous code could not do. Behaviour is unchanged where the span is live, and setAttribute on a null guard was already a no-op. The remaining attributes at the exit paths keep their unconditional calls: their arguments are compile-time constants, so there is nothing to save.
The tx.receive and tx.process spans were built with make_shared whatever the build, so a node without telemetry allocated once per inbound, submitted and relayed transaction -- duplicates included, since tx.receive runs before the duplicate check -- to hold an empty object. Leave the handle null in that build instead. Nothing needed to change to carry it: both doTransaction* overloads already default the span to nullptr, the job capture and activateIfLive() accept a null handle, and the apply loop already tested `e.span && *e.span` before using it. The remaining uses now test the handle, which they have to do anyway once it can be null. With telemetry compiled in the behaviour is unchanged, and the attribute block is still skipped for any span that is not being recorded.
…corded Transactor::operator()() set its apply-stage attributes unconditionally, so every transaction applied paid for a TxFormats::findByType() lookup and a 64-char string built from the view's parent hash, plus one or two transToken() lookups in the exit funnel, whether or not anything recorded them. Guard both blocks on the span being active. This is the pattern the sibling preflight and preclaim spans already use in applySteps.cpp, with a comment giving this exact reason -- the apply stage was simply missed. Behaviour is unchanged where the span is live, and setAttribute on an inactive guard was already a no-op.
…ecorded TxQ::apply set its enqueue-span attributes unconditionally, so every transaction paid for two 64-char hash strings and a TxFormats lookup whether or not anything recorded them. The open-ledger rebuild replays transactions through this same path, so it was paid more than once each. Guard the block on the span being active, as the tx apply-pipeline spans do.
TxQ::accept set two of its per-transaction span attributes unconditionally, so every queued transaction the loop tried to apply to the open ledger paid for a 64-char string built from the transaction id and a transToken() lookup that builds a string, whether or not anything recorded them. That is once per candidate clearing the required fee level, on every ledger close. Guard both on the span being active, as the enqueue path in TxQ::apply and the apply-pipeline spans already do. The transaction apply itself stays outside the guard; only the attribute that reads its result is telemetry.
The comments claimed the guard skips work for a span that is "not being recorded", which reads as sampling awareness. It has none: operator bool() is impl_ != nullptr, and the span factories return an empty guard only when telemetry is absent, disabled at runtime, or the trace category is off. A span that exists but was sampled out still pays. There is no isRecording() in the telemetry API, so the guard is still the strongest available; only the justification was overstated.
The existing helper takes the TraceContext submessage, so every caller writes *msg.mutable_trace_context(). On a protobuf optional field that allocates the submessage and sets its has-bit before the helper runs, so a message ships an empty TraceContext whenever nothing is recorded and its peers take their has_trace_context() branch to extract nothing. Add an overload taking the parent message, which decides whether to create the submessage at all, and correct the header note that claimed the old helper was already free.
mutable_ on a protobuf optional submessage allocates it and sets its has-bit at the call site, before the helper can decide there is nothing to write. A caller that dereferences it ships an empty TraceContext whenever nothing is recorded, and its peers each take a branch to extract nothing. Document the rule with the right and wrong forms side by side.
The table of contents in this file indexes third- and fourth-level headings, so a new subsection that is absent from it is a gap rather than a style choice.
TxTracing.h declares txReceiveSpan() and txProcessSpan(). Both call sites sit inside an XRPL_ENABLE_TELEMETRY guard, so with telemetry off the header is included but nothing from it is used, which clang-tidy reports as an unused header. Guard the include the same way so it is still there for the default build.
pratikmankawde
left a comment
There was a problem hiding this comment.
Fresh review pass. The 22 previously-unresolved threads were triaged separately: 11 answered and resolved (3 addressed, 4 factually wrong, 4 duplicates) and 11 left open. A 23rd thread arrived mid-review as a fifth report of the same hashSpan line and was answered too.
Counts: BLOCKING 1 · SHOULD-FIX 2 · NIT 0.
Refuted by reading the callee, so no fix is needed. Four separate threads asked for categoryToSpanKind(cat) to be passed to the cross-node hashSpan's startSpan call, and two more asked for setError after recordException. Both are already correct: startSpan's kind parameter defaults to kInternal (include/xrpl/telemetry/Telemetry.h:376-380), which is exactly what categoryToSpanKind(TraceCategory::Transactions) returns (src/libxrpl/telemetry/SpanGuard.cpp:191-194), and txReceiveSpan is that overload's only caller; and SpanGuard::recordException ends with SetStatus(StatusCode::kError, e.what()) at SpanGuard.cpp:526, the same call setError makes at :501-505. Details are on each thread.
Left open, with the one I would fix first named. The real defect in that group is that invokePreclaim's non-exception path (src/libxrpl/tx/applySteps.cpp:313-317) sets ter_result but never calls setError, while invokePreflight does at :226-227 — so preclaim rejections end Unset and per-stage error rates read from span status show zero preclaim failures. Also open: whether a tec-class result should mark the apply span as Error (Transactor::operator(); the repo's own TER.h:256-267 describes the class ambiguously, so it is a design call), and the suppressed attribute being absent on the tfInnerBatchTxn exit in PeerImp::handleTransaction (:1383-1384) although the comment at :1360 says every exit sets it.
Checked and clean, worth recording. The levelization baseline is up to date — I regenerated ordering.txt and loops.txt from this tree and both came back byte-identical. check_otel_naming.py exits 0 here, and both records of the new xrpl.libxrpl.tx -> xrpl.libxrpl.telemetry dependency were updated (cmake/XrplCore.cmake:239-243 plus ordering.txt), with add_module(xrpl telemetry) at :226 correctly declared before add_module(xrpl tx) at :239. Every hashSpan/childSpan call passes a fully joined span-name constant, not a bare suffix. telemetry::SpanContext is declared outside the #ifdef (SpanGuard.h:227), so the new TxQ::apply parameter compiles with telemetry off.
Not posted because existing threads already cover it. There is still no test that drives txReceiveSpan, isValidSpanId or the hashSize < 16 / parentSpanSize != 8 early returns in hashSpan — the propagator suite tests extractFromProtobuf/injectToProtobuf, which as noted below are not the code the daemon runs. That overlaps a resolved thread on untested trace-context validation, so it is a note rather than a new comment; it is worth confirming that thread's fix actually landed.
|
|
||
| ## Threat Model | ||
|
|
||
| xrpld has **two distinct attack surfaces**, not one. The original guide conflates them under "trace context spoofing"; for xrpld they need separate defenses. |
There was a problem hiding this comment.
[BLOCKING · High] — this new 240-line document publishes an xrpld threat model, including a control it states has not been built yet, into a repository anyone can read.
XRPLF/rippled is public. The section starting on this line enumerates named surfaces with an attacker, a vector and a defence for each, and then records at :191-194 and :214 that one of the two xrpld-specific defences is still outstanding, with :231-240 listing the whole design as a "Next Step". I checked the gap is current rather than stale text: grep -rniE 'rate.?limit|sampleRate' src/xrpld/telemetry/ include/xrpl/telemetry/ src/libxrpl/telemetry/ returns nothing at this tip.
Why it matters: a reader gets the surface inventory and which control is missing, in one place, before the control lands. .claude/instructions.md already rules this out for code comments ("no reference to attack surfaces or potential exploitation techniques"), and a document is a stronger version of the same thing.
Suggested shape: keep in-tree only what the code already does — include/xrpl/telemetry/TraceContextValidation.h and its predicates are a fine thing to document — and move the surface inventory, the approach comparison and the outstanding items to the internal tracker, referenced by ticket id.
Two smaller problems in the same file while it is open:
:193and:238point atsrc/xrpld/telemetry/ConsensusReceiveTracing.h, which does not exist in this PR.git ls-tree -r --name-only <this branch> -- src/xrpld/telemetry/lists onlyPropagationHelpers.h,TxSpanNames.handTxTracing.h; that file first appears onpratik/otel-phase4-consensus-tracing.:193is a markdown link, so it renders as a dead link for anyone reading this PR.:142-145is a filled-inAuthorizationheader example. Even with a placeholder value, a copy-paste-ready credential line reads better as<base64 of user:password>.
The bare review-discussion link at :149 is already tracked on its own thread, so I have not repeated it.
| * @return An OTel Context with the extracted parent span, or an empty | ||
| * context if the protobuf fields are missing or invalid. | ||
| */ | ||
| inline opentelemetry::context::Context |
There was a problem hiding this comment.
[SHOULD-FIX · Medium] — neither function in this new public header has a production caller; the shipping paths marshal the same three protobuf fields through a second, separate implementation.
grep -rn 'extractFromProtobuf|injectToProtobuf' src include at this tip finds them only in this header and in src/tests/libxrpl/telemetry/TraceContextPropagator.cpp (156 lines of tests). What the daemon actually runs:
- send:
src/xrpld/app/misc/NetworkOPs.cpp:1966-1967callstelemetry::injectSpanContext(*e.span, tx), and that helper writestrace_id/span_id/trace_flagsitself fromSpanGuard::getTraceBytes()(src/xrpld/telemetry/PropagationHelpers.h:56-66). It never callsinjectToProtobufat:79-80here. - receive:
txReceiveSpan(src/xrpld/telemetry/TxTracing.h:36-56) checksisValidSpanIdand then builds the parent context insideSpanGuard::hashSpan, not viaextractFromProtobuf.
So the PR adds a libxrpl public header — listed under "API Impact" in the description — plus its own test suite, for code nothing in the daemon calls, and the same wire fields are now produced by two routines that have to be kept in agreement by hand.
Either route the production paths through this header, which would also give the receive side the isValidTraceContext check at :52, or drop the header and let PropagationHelpers.h be the single implementation.
Not a correctness bug today: the two implementations do agree on the field set, and the send-side null handling is right (if (e.span && *e.span) at NetworkOPs.cpp:1966).
| | `trace_rpc` | 0 or 1 | `1` | Enable RPC tracing | | ||
| | `trace_peer` | 0 or 1 | `1` | Enable peer message tracing (high volume) | | ||
| | `trace_ledger` | 0 or 1 | `1` | Enable ledger tracing | | ||
| | `tx_trace_strategy` | string | `"deterministic"` | TX trace ID strategy: `"deterministic"` (trace_id = txHash[0:16]) or `"attribute"` (random) | |
There was a problem hiding this comment.
[SHOULD-FIX · Medium] — tx_trace_strategy is listed here as an implemented option with a type and a default, but nothing parses it.
grep -rn 'tx_trace_strategy|consensus_trace_strategy' src/ include/ cfg/ returns nothing at this tip. That is load-bearing because §5.2 at :56 says the parser "reads the [telemetry] Section and populates a Telemetry::Setup struct, applying the defaults listed in Section 5.1.2" — so this table is a statement that these keys are read. An operator who sets tx_trace_strategy=attribute in xrpld.cfg gets deterministic trace ids anyway, with no warning and no way to tell.
This is the PR to fix it in either direction: the deterministic transaction trace id is exactly what this PR implements (SpanGuard::hashSpan), so either add the toggle or move this row down into the "Planned (not yet implemented)" table at :41-48. The consensus_trace_strategy row at :33 has the extra problem of appearing in BOTH tables; that half is already tracked on its own thread and I have not repeated it.
Related row in the same table: trace_txq at :45 is still listed as "Planned — Phase 3", but this PR ships six txq.* spans (src/xrpld/app/misc/detail/TxQSpanNames.h:68-73, all six used in TxQ.cpp). They are gated on TraceCategory::Transactions rather than a trace_txq toggle, so that row is either stale or a missing feature.
The three apply-pipeline stages disagreed on span status. preflight set Error on any non-success TER, preclaim never set it at all, and the apply stage recorded nothing when a transaction threw. - preclaim now sets Error for any non-success result, matching preflight. Routine retryable results (terPRE_SEQ, telINSUF_FEE_P) are included, so stage=preclaim error rates will rise and track normal queueing. - The apply span no longer keys Error on canApply. A dry run reports tesSUCCESS with canApply false, which was recorded as an error. Every other path with canApply false already has a non-success result, so !isTesSuccess covers them. - Exceptions escaping the apply stage set ter_result=tefEXCEPTION and record an exception event, then rethrow unchanged, mirroring what invokePreflight and invokePreclaim already do. The caller still maps the exception to tefEXCEPTION, so behaviour is unchanged. - Two comments claimed every exit funnels through the logger lambda. A throw does not, so they now say each return path.
… nodiscard The trace-context checks validate bytes received from a peer, so a discarded result means untrusted input was accepted unchecked. hashSpan(), txReceiveSpan() and txProcessSpan() return an RAII guard; discarding one ends the span on the same line it began. The telemetry-disabled twins of both hashSpan overloads already carried the attribute, so the two #ifdef arms now agree. Both hashSpan overloads also gain the @return line their siblings already had, now that the result cannot be dropped. No caller in the chain discards any of these results.
Conflict in OpenTelemetryPlan/05-configuration-reference.md: phase-3 had widened the options table and added the tx_trace_strategy and consensus_trace_strategy rows, while the incoming side renamed the endpoint option. Composed both — phase-3's wider layout and its two extra rows are kept, with the endpoint row renamed to traces_endpoint.
NetworkOPs.cpp include block: develop replaced DeliveredAmount.h, MPTokenIssuanceID.h and NFTSyntheticSerializer.h with the single rpc/detail/SyntheticFields.h. Kept that and this branch's two telemetry includes.
|
This PR has conflicts, please resolve them in order for the PR to be reviewed. |
|
All conflicts have been resolved. Assigned reviewers can now start or resume their review. |
| opentelemetry::nostd::shared_ptr<otel_trace::Span>( | ||
| new otel_trace::DefaultSpan(combinedCtx))); | ||
|
|
||
| return SpanGuard(std::make_unique<Impl>(tel->startSpan(std::string(name), parentCtx))); |
There was a problem hiding this comment.
SpanKind not passed to startSpan in cross-node overload. Pass categoryToSpanKind(cat) parameter:
| return SpanGuard(std::make_unique<Impl>(tel->startSpan(std::string(name), parentCtx))); | |
| return SpanGuard(std::make_unique<Impl>(tel->startSpan(std::string(name), parentCtx, categoryToSpanKind(cat)))); |
| return SpanGuard(std::make_unique<Impl>(tel->startSpan(std::string(name), parentCtx))); | |
| return SpanGuard(std::make_unique<Impl>(tel->startSpan(std::string(name), parentCtx, categoryToSpanKind(cat)))); |
| catch (std::exception const& e) | ||
| { | ||
| // The caller's doApply() maps this to tefEXCEPTION. Record it on the | ||
| // span before unwinding so per-stage error counts include exceptions. |
There was a problem hiding this comment.
span.setError() not called on exception. Add error marking before recordException:
span.setError(transToken(tefEXCEPTION));
recordException(e);
| // span before unwinding so per-stage error counts include exceptions. | ||
| span.setAttribute( | ||
| telemetry::tx_apply_span::attr::terResult, transToken(tefEXCEPTION).c_str()); | ||
| span.recordException(e); |
There was a problem hiding this comment.
span.setError() not called on exception. Add error marking before recordException:
span.setError(transToken(tefEXCEPTION));
recordException(e);
| span.recordException(e); | |
| span.recordException(e); | |
| span.setError(transToken(tefEXCEPTION)); |
| // span before unwinding so per-stage error counts include exceptions. | ||
| span.setAttribute( | ||
| telemetry::tx_apply_span::attr::terResult, transToken(tefEXCEPTION).c_str()); | ||
| span.recordException(e); |
There was a problem hiding this comment.
span.setError() not called on exception. Add error marking before recordException:
span.setError(transToken(tefEXCEPTION));
recordException(e);
| span.recordException(e); | |
| span.recordException(e); | |
| span.setError(transToken(tefEXCEPTION)); |
| // into the ledger. | ||
| if (auto directApplied = tryDirectApply(app, view, tx, flags, j)) | ||
| { | ||
| span.setAttribute(txq_span::attr::txqStatus, txq_span::val::appliedDirect); |
There was a problem hiding this comment.
This reports applied_direct even when the direct-apply attempt fails. The condition checks whether the optional contains a result, not whether result.applied is true: tryDirectApply() calls xrpl::apply() at line 1795 and returns ApplyResult{txnResult, didApply, metadata} at line 1818 even when didApply is false.
A concrete example is the existing testFailInPreclaim() case in src/test/app/TxQ_test.cpp:941–954: Alice has 1,000 XRP and submits a transaction with a 100,000 XRP fee. The offered fee clears the direct-apply threshold, but preclaim rejects it with terINSUF_FEE_B because she cannot pay it. This branch then overwrites the default rejected status with applied_direct, despite nothing being applied.
Keep failed attempts as rejected and only report applied_direct when directApplied->applied is true. If this value is intended to describe the attempted route rather than the outcome, record that separately from txq_status. Please also cover the exported status for this failure case and a successful direct apply; the existing test checks the engine result, not the telemetry.
High Level Overview of Change
Transaction-lifecycle tracing: receive, process, per-stage apply, and queue spans, plus cross-node trace-context propagation over
TMTransaction.No need to review tasklist files.
Context of Change
Spans
tx.receivePeerImp::handleTransaction()— attrs: peer_id, peer_version, tx_hash, suppressed, tx_statustx.processNetworkOPsImp::processTransaction()— attrs: tx_hash, local, path (sync/async)tx.preflight,tx.preclaim,tx.transactorapplySteps.cpp/Transactor.cpp— attrs: tx_type, ter_result, appliedtxq.enqueue,txq.apply_direct,txq.batch_clear,txq.accept,txq.accept_tx,txq.cleanupTxQ.cpp— fee levels, queue size, retries, expirySplitting apply into preflight / preclaim / transactor is what makes it possible to tell a rejected-on-validation transaction from one that failed at apply time.
Cross-node propagation (TX only) — a
TraceContextprotobuf message is added and field 1001 is reserved onTMTransaction,TMProposeSetandTMValidation; onlyTMTransactionis wired here.NetworkOPs::apply()injects the activetx.processcontext before relay;txReceiveSpan()extracts it so the receiver'stx.receivebecomes a child of the sender's span. Peers that omitTraceContextsimply produce parentlesstx.receivespans — no loss of local data.Attribute keys use the lower_snake_case form the naming check enforces (
tx_hash, notxrpl.tx.hash), which keeps TraceQL free of escaping.API Impact
TraceContextmessage, reserved field 1001. Backward compatible with peers that never set it.libxrplchange (TraceContextPropagator.h,tx/detail/TxApplySpanNames.h)Test Plan
./xrpl_tests --gtest_filter='*TraceContextPropagator*:*TxApplySpanNames*'tx.receivelands in the same trace as A'stx.process.