Skip to content

fix: delay in TimeOffset applied to AdjustedTime introduced by send/r… - #5946

Closed
techy2 wants to merge 1 commit into
dashpay:masterfrom
techy2:delay_TimeOffset
Closed

fix: delay in TimeOffset applied to AdjustedTime introduced by send/r…#5946
techy2 wants to merge 1 commit into
dashpay:masterfrom
techy2:delay_TimeOffset

Conversation

@techy2

@techy2 techy2 commented Mar 21, 2024

Copy link
Copy Markdown

On busy VPS and shared host with limited resources, the time between when a messages is sent to the
tcpip send or receive queue and when it is sent in the case of send queue, or when it is processed
(ProcessMessage) can be in excess of 30 seconds.This delay introduces a skew in AdjustedTime.

For the receive queue, the post processing uses the receive time prior to entering the queue to
calculate TimeOffset rather than Now() which currently includes the delay in the queue.

For the send queue, the queued message is altered to update the nTime of the message to the actual
time it is being sent rather than the time at which it was queued

Was tested on an hp 370 G6 24 core 3ghz 192gb host with the daemon launched with -par=2 to restrict
the resources of the daemon. Logging was added pre-patch to document the delay through the queue and
was observed for both send and receive to be occasionally > 30 seconds when the daemon was busy
following the tip or during reorgs when the cpu utilization for the assigned core approached 100%.
Significant queue delay occurs most often in the receive queue (several times a minute) and
infrequently in the send queue ( 1 observation in several hours of testing ).

Checklist:

Go over all the following points, and put an x in all the boxes that apply.

  • [x ] I have performed a self-review of my own code
  • [x ] I have commented my code, particularly in hard-to-understand areas
  • I have added or updated relevant unit/integration/functional/e2e tests
  • I have made corresponding changes to the documentation
  • I have assigned this pull request to a milestone (for repository code-owners and collaborators only)

@PastaPastaPasta PastaPastaPasta left a comment

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Overall; I would say this is way to "hacky" as your comments even describe it to be merged. It also introduces technically undefined behavior. I would probably also want to see a test where this issue presents itself

Comment thread src/net.cpp
Comment on lines +927 to +930
if (! *(char *)&bigint) { // if bigendian
nSendtime = bswap_64(uSendbuff.ui64_tm);
nNewSendtime = bswap_64(nNow);
}

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The endianess check is somewhat unconventional. Using a standard library function or a more explicit check might improve clarity.

Comment thread src/net.cpp
int64_t nNow = (pnode->IsInboundConn()) ? GetAdjustedTime() : GetTime();
int64_t nNewSendtime = nNow;
if (! *(char *)&bigint) { // if bigendian
nSendtime = bswap_64(uSendbuff.ui64_tm);

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is (at least technically) undefined behavior here: the last write to the union was into the uchar[8]; then it's being read via uSendbuff.ui64_tm. According to c++17 standard; you may only read from a union the type which was most recently written to; anything else is undefined behavior.

@UdjinM6 UdjinM6 left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

see below + #5460 (comment) + #5460 (comment)

tl;dr:

  1. The fix on the sending side only helps non-malicious peers to behave a bit better under high load, malicious peers still can exploit this. Moreover, adjusted time is meant to be inaccurate by design and we can't fully trust it anyway, so imo we can simply ignore this part.
  2. Using both mockable time and non-mockable time in one equation feels wrong, the fix on the receiving side can cause issues in tests potentially. To lower the impact of malicious peers we could backport bitcoin#23631 instead.
  3. We don't merge into master.

Comment thread src/net_processing.cpp
re-org operations. This delay corrupts AdjustedTime/
*/
// int64_t nTimeOffset = nTime - GetTime();
int64_t nTimeOffset = nTime - (nTimeReceived/1000000);

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

mixing mockable/non-mockable time here (check CNode::ReceiveMsgBytes()), might cause test issues

@github-actions

Copy link
Copy Markdown

This pull request has conflicts, please rebase.

@thepastaclaw

thepastaclaw commented Mar 30, 2026

Copy link
Copy Markdown
Collaborator

⛔ Final review complete — 2 blocking finding(s) (commit d8d1b01)

@thepastaclaw thepastaclaw left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Code Review

The PR's receive-side adjustment (using nTimeReceived/1000000) is directionally sound, but the send-side block in SocketSendData is fundamentally broken and will prevent virtually every outgoing VERSION handshake from being accepted. The header checksum is finalized in prepareForTransport (net.cpp:865-876) before vSendMsg gets the payload, so mutating nTime in the queued payload guarantees a checksum mismatch on the peer. The block also unconditionally reinterprets the front chunk's serialized bytes as a CMessageHeader struct, executes on every SocketSendData() invocation (including after partial sends, when the front chunk may be payload bytes), and uses unsafe hand-rolled endian detection / union type-punning. The change touches AdjustedTime which feeds validation timestamps yet ships with no tests and obvious debug leftovers (HACK marker, commented LogPrintf, typos).

Reviewed commit: d8d1b01

🔴 2 blocking | 🟡 3 suggestion(s) | 💬 3 nitpick(s)

blocking: Send-side rewrite of nTime invalidates the VERSION message checksum and breaks the handshake

src/net.cpp (lines 902-936)

V1TransportSerializer::prepareForTransport (src/net.cpp:865-876) hashes msg.data and writes the first 4 bytes into hdr.pchChecksum before the serialized header is pushed onto vSendMsg. PushMessage then pushes the header chunk and the payload chunk separately (src/net.cpp:4141-4142). This patch mutates the queued payload's nTime field in place (memcpy(... sd.data() + 12, ...)) without recomputing Hash(msg.data) and without rewriting the checksum bytes in the header chunk. Peers verify the checksum in V1TransportDeserializer::GetMessage (src/net.cpp:839-852) and drop messages on CHECKSUM ERROR. Because the guard is nSendtime != nNow (full-second comparison, true whenever any non-trivial scheduling delay elapsed between PushMessage and SocketSendData — i.e. essentially always in the scenario this PR claims to fix), virtually every outgoing VERSION will ship with a stale checksum and be rejected. The handshake is broken in exactly the case this PR targets. The correct fix is to populate nTime at the moment of serialization (e.g. inside PushMessage/prepareForTransport for VERSION) so the checksum is computed over the final payload, not by patching bytes after the checksum has been finalized.

blocking: Front-chunk inspection is unsafe: reinterpret_cast UB, no nSendOffset/empty check, breaks on partial sends

src/net.cpp (lines 907-935)

Three independent correctness problems compound in this block:

  1. auto& sh = *it; runs after auto it = pnode->vSendMsg.begin(); with no empty() check. SocketSendData can be invoked even when there is nothing useful at the front (vSendableNodes membership is not a strict invariant in every code path); dereferencing end() is UB. The pre-existing while (it != pnode->vSendMsg.end()) loop on line 939 exists for exactly this reason.

  2. CMessageHeader* shdr = reinterpret_cast<CMessageHeader*>(sh.data()); shdr->GetCommand(); treats the serialized wire-format bytes (magic[4] | command[12] | size[4] | checksum[4], little-endian) as the in-memory CMessageHeader struct. The struct's member layout, alignment, and integer endianness do not necessarily match the wire layout. GetCommand() reads pchCommand at a struct offset that only coincidentally matches the wire offset on most x86 ABIs — undefined behavior in the C++ object model regardless. Use CMessageHeader::COMMAND_OFFSET and parse the command from the wire bytes directly if you need to do this at all.

  3. SocketSendData is called repeatedly; vSendMsg is std::list<std::vector<unsigned char>> (src/net.h:1128). When a previous invocation sent the header fully but only part of the payload, the header chunk is erased at line 954-958 and the next call sees the payload at the front with a nonzero nSendOffset. This block then (a) reinterprets payload bytes as a header, (b) potentially overwrites bytes that have already been transmitted on the socket. Even when the front is still the original header chunk but it has been partially transmitted, the checksum bytes (offset 20–23) may already be on the wire while the payload nTime is then rewritten — guaranteed mismatch.

Any fix must (a) check vSendMsg.empty(), (b) verify nSendOffset == 0 so no bytes have been transmitted, (c) verify the front chunk is in fact the header chunk and that a payload chunk follows, and (d) parse the command from wire bytes rather than struct reinterpret_cast. As noted in the other blocking finding, even doing all that does not fix the checksum problem — the real fix is to set nTime at serialization time, not after.

suggestion: Asymmetric GetAdjustedTime() for inbound peers risks an adjusted-time feedback loop

src/net.cpp (lines 925-925)

int64_t nNow = (pnode->IsInboundConn()) ? GetAdjustedTime() : GetTime(); substitutes our own adjusted time into the VERSION nTime field we send to inbound peers. The receiver then computes nTimeOffset = nTime - GetTime() and feeds it back into AddTimeData, contributing to their adjusted time. Mixing our already-adjusted clock into the seed for peers' adjustments is a feedback path the original code avoids by always sending GetTime(). The queue-delay correction this PR is attempting does not depend on adjusted-vs-system time at all — both directions should consistently use GetTime().

suggestion: Receive-side fix: remove dead code, fix comment, document units, consider rounding

src/net_processing.cpp (lines 3072-3083)

The replacement int64_t nTimeOffset = nTime - (nTimeReceived/1000000); is the conceptually correct half of this PR — nTimeReceived is sourced from GetTimeMicros() (see CNode::ReceiveMsgBytes at src/net.cpp:721) and nTime is the peer's VERSION timestamp in seconds. Cleanup items: (1) delete the prior int64_t nTimeOffset = nTime - GetTime(); line rather than leaving it commented out (matches Bitcoin/Dash hygiene); (2) the comment block ends with corrupts AdjustedTime/ (stray slash); (3) consider rounding rather than truncating, e.g. (nTimeReceived + 500000) / 1000000, so an in-flight time of 1.7s contributes 2s and not 1s — this is also symmetric with how the peer rounds; (4) add an assert/static_assert or at least a comment that nTimeReceived is in microseconds, since a future change to its units would silently shift time-offset accounting by six orders of magnitude.

nitpick: Hand-rolled endian detection and union type-punning are unnecessary and non-portable

src/net.cpp (lines 902-930)

The codebase already provides portable little-endian helpers (WriteLE64/ReadLE64, ser_writedata64, htole64). Hand-rolling endianness via const int bigint = 1; if (!*(char*)&bigint) together with a union { uint64_t; u_char[8]; } for type punning is unnecessary, harder to read, and the union access is implementation-defined in C++. Even setting aside the more serious bugs, byte access should be WriteLE64(sd.data() + 12, value) (or equivalent) with no runtime endian probe.

nitpick: Debug leftovers: `HACK` marker, commented-out LogPrintf, framing comments

src/net.cpp (lines 931-937)

// LogPrintf("HACK %s size %d %" PRId64 " %" PRId64 "\n", ... is a half-deleted debug statement (and is truncated — four conversion specifiers, three arguments). The Begin ... time offset fix / end time offset fix framing and the HACK label are not appropriate for committed code. Replace with a focused comment explaining the approach (once the approach itself is corrected) or remove entirely.

nitpick: Typos and incorrect container name in comments

src/net.cpp (lines 886-888)

Comments contain folloowing (should be following) at both src/net.cpp:886 and src/net_processing.cpp:3076. The comment at src/net.cpp:888 also calls vSendMsg a std::deque, but it is declared std::list<std::vector<unsigned char>> (src/net.h:1128). The chunked-layout explanation applies to std::list as well, but the type name should be corrected.

suggestion: Consensus-adjacent timekeeping change lands without test coverage

src/net.cpp (lines 883-937)

AdjustedTime feeds validation-side timestamps (block timestamps via GetAdjustedTime()), so changes to how peers populate time offsets warrant tests. This PR adds no unit or functional coverage for: (a) sending a VERSION after a simulated queue delay and verifying the receiver accepts the message and computes the expected offset; (b) the receive-side calculation using nTimeReceived in microseconds; (c) round-trip handshakes with artificial delays. PR description references manual VPS testing only. Given that the current send-side implementation breaks the handshake outright, a regression test for the corrupted-checksum case in particular would have caught this before merge.

_Inline posting via scripts/review_poster.py failed, so I posted the verified findings in the review body instead: Traceback (most recent call last):
File "/Users/claw/.openclaw/workspace/scripts/review_poster.py", line 138, in
result = post_review(repo, pr_number, head_sha, verified, dry_run=dry_run)
File "/Users/claw/.openclaw/workspace/scripts/review_poster.py", line 107, in post_review
result = _gh(
File "/Users/claw/.openclaw/workspace/scripts/review_poster.py", line 23, in gh
raise RuntimeError(f"gh {' '.join(args)} failed: {result.stderr.strip()}")
RuntimeError: gh api /repos/dashpay/dash/pulls/5946/reviews --method POST --input - failed: gh: Unprocessable Entity (HTTP 422)

@PastaPastaPasta
PastaPastaPasta requested a review from knst August 29, 2026 13:17
@PastaPastaPasta

Copy link
Copy Markdown
Member

Closing this rejected transport approach following the maintainer review. Rewriting an already-serialized VERSION message in the send queue is unsafe for its checksum/partial-send contract, and the receive-side calculation mixes mockable and non-mockable clocks. This branch also targets master rather than develop.

Current develop has since removed adjusted time from validation and mining in #7430. Any remaining peer-offset warning or queue-delay issue should be demonstrated against current develop and addressed without mutating queued wire messages.


🤖 Posted autonomously by Codex on behalf of pasta.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Projects

None yet

Development

Successfully merging this pull request may close these issues.

4 participants