diff options
| -rw-r--r-- | src/bitcoinrpc.cpp | 1 | ||||
| -rw-r--r-- | src/bitcoinrpc.h | 1 | ||||
| -rw-r--r-- | src/main.cpp | 85 | ||||
| -rw-r--r-- | src/net.cpp | 15 | ||||
| -rw-r--r-- | src/net.h | 12 | ||||
| -rw-r--r-- | src/rpcnet.cpp | 21 |
6 files changed, 131 insertions, 4 deletions
diff --git a/src/bitcoinrpc.cpp b/src/bitcoinrpc.cpp index ef50ccd07f..b0df9c5e28 100644 --- a/src/bitcoinrpc.cpp +++ b/src/bitcoinrpc.cpp @@ -229,6 +229,7 @@ static const CRPCCommand vRPCCommands[] = { "getbestblockhash", &getbestblockhash, true, false, false }, { "getconnectioncount", &getconnectioncount, true, false, false }, { "getpeerinfo", &getpeerinfo, true, false, false }, + { "ping", &ping, true, false, false }, { "addnode", &addnode, true, true, false }, { "getaddednodeinfo", &getaddednodeinfo, true, true, false }, { "getdifficulty", &getdifficulty, true, false, false }, diff --git a/src/bitcoinrpc.h b/src/bitcoinrpc.h index ce1c0e68b7..f495870b38 100644 --- a/src/bitcoinrpc.h +++ b/src/bitcoinrpc.h @@ -153,6 +153,7 @@ extern void EnsureWalletIsUnlocked(); extern json_spirit::Value getconnectioncount(const json_spirit::Array& params, bool fHelp); // in rpcnet.cpp extern json_spirit::Value getpeerinfo(const json_spirit::Array& params, bool fHelp); +extern json_spirit::Value ping(const json_spirit::Array& params, bool fHelp); extern json_spirit::Value addnode(const json_spirit::Array& params, bool fHelp); extern json_spirit::Value getaddednodeinfo(const json_spirit::Array& params, bool fHelp); diff --git a/src/main.cpp b/src/main.cpp index 8df288380a..9cf21a2a1f 100644 --- a/src/main.cpp +++ b/src/main.cpp @@ -3861,6 +3861,63 @@ bool static ProcessMessage(CNode* pfrom, string strCommand, CDataStream& vRecv) } + else if (strCommand == "pong") + { + int64 pingUsecEnd = GetTimeMicros(); + uint64 nonce = 0; + size_t nAvail = vRecv.in_avail(); + bool bPingFinished = false; + std::string sProblem; + + if (nAvail >= sizeof(nonce)) { + vRecv >> nonce; + + // Only process pong message if there is an outstanding ping (old ping without nonce should never pong) + if (pfrom->nPingNonceSent != 0) { + if (nonce == pfrom->nPingNonceSent) { + // Matching pong received, this ping is no longer outstanding + bPingFinished = true; + int64 pingUsecTime = pingUsecEnd - pfrom->nPingUsecStart; + if (pingUsecTime > 0) { + // Successful ping time measurement, replace previous + pfrom->nPingUsecTime = pingUsecTime; + } else { + // This should never happen + sProblem = "Timing mishap"; + } + } else { + // Nonce mismatches are normal when pings are overlapping + sProblem = "Nonce mismatch"; + if (nonce == 0) { + // This is most likely a bug in another implementation somewhere, cancel this ping + bPingFinished = true; + sProblem = "Nonce zero"; + } + } + } else { + sProblem = "Unsolicited pong without ping"; + } + } else { + // This is most likely a bug in another implementation somewhere, cancel this ping + bPingFinished = true; + sProblem = "Short payload"; + } + + if (!(sProblem.empty())) { + LogPrint("net", "pong %s %s: %s, %"PRI64x" expected, %"PRI64x" received, %zu bytes\n" + , pfrom->addr.ToString().c_str() + , pfrom->strSubVer.c_str() + , sProblem.c_str() + , pfrom->nPingNonceSent + , nonce + , nAvail); + } + if (bPingFinished) { + pfrom->nPingNonceSent = 0; + } + } + + else if (strCommand == "alert") { CAlert alert; @@ -4082,14 +4139,34 @@ bool SendMessages(CNode* pto, bool fSendTrickle) if (pto->nVersion == 0) return true; - // Keep-alive ping. We send a nonce of zero because we don't use it anywhere - // right now. + // + // Message: ping + // + bool pingSend = false; + if (pto->fPingQueued) { + // RPC ping request by user + pingSend = true; + } if (pto->nLastSend && GetTime() - pto->nLastSend > 30 * 60 && pto->vSendMsg.empty()) { + // Ping automatically sent as a keepalive + pingSend = true; + } + if (pingSend) { uint64 nonce = 0; - if (pto->nVersion > BIP0031_VERSION) + while (nonce == 0) { + RAND_bytes((unsigned char*)&nonce, sizeof(nonce)); + } + pto->nPingNonceSent = nonce; + pto->fPingQueued = false; + if (pto->nVersion > BIP0031_VERSION) { + // Take timestamp as close as possible before transmitting ping + pto->nPingUsecStart = GetTimeMicros(); pto->PushMessage("ping", nonce); - else + } else { + // Peer is too old to support ping command with nonce, pong will never arrive, disable timing + pto->nPingUsecStart = 0; pto->PushMessage("ping"); + } } // Start block sync diff --git a/src/net.cpp b/src/net.cpp index 781dbfadca..5afedb1fd2 100644 --- a/src/net.cpp +++ b/src/net.cpp @@ -620,6 +620,21 @@ void CNode::copyStats(CNodeStats &stats) X(nSendBytes); X(nRecvBytes); stats.fSyncNode = (this == pnodeSync); + + // It is common for nodes with good ping times to suddenly become lagged, + // due to a new block arriving or other large transfer. + // Merely reporting pingtime might fool the caller into thinking the node was still responsive, + // since pingtime does not update until the ping is complete, which might take a while. + // So, if a ping is taking an unusually long time in flight, + // the caller can immediately detect that this is happening. + int64 nPingUsecWait = 0; + if ((0 != nPingNonceSent) && (0 != nPingUsecStart)) { + nPingUsecWait = GetTimeMicros() - nPingUsecStart; + } + + // Raw ping time is in microseconds, but show it to user as whole seconds (Bitcoin users should be well used to small numbers with many decimal places by now :) + stats.dPingTime = (((double)nPingUsecTime) / 1e6); + stats.dPingWait = (((double)nPingUsecWait) / 1e6); } #undef X @@ -119,6 +119,8 @@ public: uint64 nSendBytes; uint64 nRecvBytes; bool fSyncNode; + double dPingTime; + double dPingWait; }; @@ -234,6 +236,12 @@ public: CCriticalSection cs_inventory; std::multimap<int64, CInv> mapAskFor; + // Ping time measurement + uint64 nPingNonceSent; + int64 nPingUsecStart; + int64 nPingUsecTime; + bool fPingQueued; + CNode(SOCKET hSocketIn, CAddress addrIn, std::string addrNameIn = "", bool fInboundIn=false) : ssSend(SER_NETWORK, MIN_PROTO_VERSION) { nServices = 0; @@ -268,6 +276,10 @@ public: fRelayTxes = false; setInventoryKnown.max_size(SendBufferSize() / 1000); pfilter = new CBloomFilter(); + nPingNonceSent = 0; + nPingUsecStart = 0; + nPingUsecTime = 0; + fPingQueued = false; // Be shy and don't send version until we hear if (hSocket != INVALID_SOCKET && !fInbound) diff --git a/src/rpcnet.cpp b/src/rpcnet.cpp index bd7bc0ba10..7df86cc2db 100644 --- a/src/rpcnet.cpp +++ b/src/rpcnet.cpp @@ -19,6 +19,24 @@ Value getconnectioncount(const Array& params, bool fHelp) return (int)vNodes.size(); } +Value ping(const Array& params, bool fHelp) +{ + if (fHelp || params.size() != 0) + throw runtime_error( + "ping\n" + "Requests that a ping be sent to all other nodes, to measure ping time.\n" + "Results provided in getpeerinfo, pingtime and pingwait fields are decimal seconds.\n" + "Ping command is handled in queue with all other commands, so it measures processing backlog, not just network ping."); + + // Request that each node send a ping during next message processing pass + LOCK(cs_vNodes); + BOOST_FOREACH(CNode* pNode, vNodes) { + pNode->fPingQueued = true; + } + + return Value::null; +} + static void CopyNodeStats(std::vector<CNodeStats>& vstats) { vstats.clear(); @@ -54,6 +72,9 @@ Value getpeerinfo(const Array& params, bool fHelp) obj.push_back(Pair("bytessent", (boost::int64_t)stats.nSendBytes)); obj.push_back(Pair("bytesrecv", (boost::int64_t)stats.nRecvBytes)); obj.push_back(Pair("conntime", (boost::int64_t)stats.nTimeConnected)); + obj.push_back(Pair("pingtime", stats.dPingTime)); + if (stats.dPingWait > 0.0) + obj.push_back(Pair("pingwait", stats.dPingWait)); obj.push_back(Pair("version", stats.nVersion)); obj.push_back(Pair("subver", stats.strSubVer)); obj.push_back(Pair("inbound", stats.fInbound)); |