Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Open
wants to merge 1 commit into
base: master
Choose a base branch
from
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
56 changes: 56 additions & 0 deletions src/net.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -880,6 +880,62 @@ size_t CConnman::SocketSendData(CNode *pnode) EXCLUSIVE_LOCKS_REQUIRED(pnode->cs
auto it = pnode->vSendMsg.begin();
size_t nSentSize = 0;

/* Begin queue send delay time offset fix
The Sendtime is not the time this message was put in the queue,
it is Now(). Observed queue delays of 30 seconds or more are introduced
on hosts with restricted resources during "tip" folloowing and chain
re-org operations. This delay corrupts AdjustedTime on the receiving host
format of VERSION message in std::deque, not contiguous
(4) message start
(12) command = version
(4) size
(4) checksum
------- chunk 2 -------
(4) nVersion
(8) nServiceInt
(8) nTime
(x) CAddress addrMe
(x) CAddress addrFrom
(8) nNonce
........ and so on...
*/
union uS
{
uint64_t ui64_tm;
u_char uchr_tm[8];
};
union uS uSendbuff;
const int bigint = 1;
auto& sh = *it;
// at front of deque, hdrbuf is first
CMessageHeader * shdr = reinterpret_cast<CMessageHeader*>(sh.data());
std::string strCommand = shdr->GetCommand();
if (strCommand == NetMsgType::VERSION) {
/* do not increment "it", it corrupts deque
header and message are in 2 sequential non-contiguious chunks in the deque, see:
void CConnman::PushMessage(CNode* pnode, CSerializedNetMsg&& msg)
...
pnode->vSendMsg.push_back(std::move(serializedHeader));
if (nMessageSize)
pnode->vSendMsg.push_back(std::move(msg.data));
*/
auto& sd = *(std::next(it, 1)); // point to next data chunk
memcpy(uSendbuff.uchr_tm, reinterpret_cast<unsigned char*>(sd.data() + 12), 8);
int64_t nSendtime = uSendbuff.ui64_tm;
int64_t nNow = (pnode->IsInboundConn()) ? GetAdjustedTime() : GetTime();
int64_t nNewSendtime = nNow;
if (! *(char *)&bigint) { // if bigendian
nSendtime = bswap_64(uSendbuff.ui64_tm);
Copy link
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.

nNewSendtime = bswap_64(nNow);
}
Comment on lines +927 to +930
Copy link
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.

// LogPrintf("HACK %s size %d %" PRId64 " %" PRId64 "\n", strCommand.c_str(), shdr->nMessageSize, nSendtime
if (nSendtime != nNow) {
uSendbuff.ui64_tm = nNewSendtime;
memcpy(reinterpret_cast<unsigned char*>(sd.data() + 12), uSendbuff.uchr_tm, 8);
}
}
// end time offset fix

while (it != pnode->vSendMsg.end()) {
const auto &data = *it;
assert(data.size() > pnode->nSendOffset);
Expand Down
11 changes: 10 additions & 1 deletion src/net_processing.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -3069,7 +3069,16 @@ void PeerManagerImpl::ProcessMessage(
pfrom.nStartingHeight, addrMe.ToString(), pfrom.GetId(),
remoteAddr);

int64_t nTimeOffset = nTime - GetTime();
/* Begin queue receive delay time offset fix
The receive time is not the time this message is processed, it it the time
it was put in the queue nTimeReceived.
Observed queue delays of 30 seconds or more are introduced
on hosts with restricted resources during "tip" folloowing and chain
re-org operations. This delay corrupts AdjustedTime/
*/
// int64_t nTimeOffset = nTime - GetTime();
int64_t nTimeOffset = nTime - (nTimeReceived/1000000);
Copy link

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


pfrom.nTimeOffset = nTimeOffset;
AddTimeData(pfrom.addr, nTimeOffset);

Expand Down