From 24ed292f0524f1bc77c317b60d7ecf265596b3dd Mon Sep 17 00:00:00 2001 From: Bitflash Date: Sat, 1 Aug 2026 12:23:31 -0300 Subject: diag: let the node say what is wrong with it (#81) * Bump to 1.2.11 One change, and it is the reason a node on Windows kept collecting peers it could not hear. FD_SETSIZE was never defined in this tree, so it defaulted to 64 and select() could watch the listen socket plus 63 peers -- everything past that stayed connected and was never read again. Windows FD_SET stops adding once its array is full and says nothing, so there was no error to notice. Because new connections go on the end of vNodes, it was always the newest connection that starved, including the ones dialed to fix connectivity. Measured on two nodes: 277 and 90 CNode objects against 93 and 90 live sockets, 316 and 355 sockets in a bound-but-never-connected state, and a status bar reporting hundreds of peers for a node really talking to thirty. 1.2.11 raises FD_SETSIZE to 1024 on Windows, caps connections at 125, drops a node stuck undeliverable after 60 seconds instead of holding it forever, stops answering a failed select() with POSIX code that has no meaning on Windows, and warns when there are more peers than select can watch. * diag: let the node say what is wrong with it Every hard problem in this project so far was found from outside the node -- sockets read over WMI, committed memory compared against a README, a grep over somebody debug.log. In each case the node knew and had no way to say so. One report, rendered identically for the GUI panel and the log: peers held vs peers actually watched by select(), blocks received and how many arrived without a parent, proof-of-work mode with the live miner thread count, and per peer the age of the last message in each direction plus anything stuck unsent. --- src/net.cpp | 117 ++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 117 insertions(+) (limited to 'src/net.cpp') diff --git a/src/net.cpp b/src/net.cpp index 5ef8316..19893ee 100644 --- a/src/net.cpp +++ b/src/net.cpp @@ -46,6 +46,96 @@ CCriticalSection cs_mapRelay; map mapAlreadyAskedFor; string strBtfConnect; // .btf peer to keep connected to (from /connectbtf) +int nPeersWatched = 0; +int64 nBlocksReceived = 0; +int64 nBlocksWithoutParent = 0; +static int64 nNodeStartTime = 0; + +// Defined further down, next to the counter it reads. The miner keeps its own +// live count -- threads bump it on the way in and on the way out -- which is +// the honest number here: how many are hashing now, not how many were asked to. +static int MinersRunningCount(); + +// Seconds rendered the way a person reads them off a screen. +static string FormatAge(int64 nSeconds) +{ + if (nSeconds < 0) return "never"; + if (nSeconds < 60) return strprintf("%llds", (long long)nSeconds); + if (nSeconds < 3600) + return strprintf("%lldm%02llds", (long long)(nSeconds / 60), (long long)(nSeconds % 60)); + return strprintf("%lldh%02lldm", (long long)(nSeconds / 3600), (long long)((nSeconds % 3600) / 60)); +} + +string GetDiagnosticsText() +{ + int64 nNow = GetTime(); + string str; + + int nInbound = 0, nHeld = 0; + vector vCopy; + CRITICAL_BLOCK(cs_vNodes) + { + vCopy = vNodes; + nHeld = (int)vNodes.size(); + foreach(CNode* pnode, vNodes) + if (pnode->fInbound) + nInbound++; + } + + int nMedian = GetPeerMedianHeight(); + + str += "Bitflash node diagnostics\n"; + str += strprintf(" uptime %s\n", + FormatAge(nNodeStartTime ? nNow - nNodeStartTime : -1).c_str()); + if (nMedian < 0) + str += strprintf(" height %d (no peer has said where it is)\n", nBestHeight); + else + str += strprintf(" height %d (peers report %d, %s)\n", + nBestHeight, nMedian, + nBestHeight >= nMedian ? "level or ahead" + : strprintf("behind by %d", nMedian - nBestHeight).c_str()); + str += strprintf(" peers held %d (%d inbound, %d outbound)\n", + nHeld, nInbound, nHeld - nInbound); + + // The number that would have made the deafness obvious. Anything held but + // not watched is a socket this node will never read again. + str += strprintf(" peers watched %d of %d that select() can hold%s\n", + nPeersWatched, (int)FD_SETSIZE - 1, + nHeld > nPeersWatched ? " <-- NOT ALL PEERS ARE BEING READ" : ""); + + if (nBlocksReceived > 0) + str += strprintf(" blocks received %lld (%lld arrived without a parent, %.1f%%)\n", + (long long)nBlocksReceived, (long long)nBlocksWithoutParent, + 100.0 * nBlocksWithoutParent / nBlocksReceived); + else + str += " blocks received 0\n"; + + int nMining = MinersRunningCount(); + str += strprintf(" proof of work %s mode%s\n", + RandomXFastReady() ? "fast (2 GB dataset)" : "light (256 MB cache)", + nMining > 0 + ? strprintf(", mining on %d thread(s), about %d MB", + nMining, + (RandomXFastReady() ? 2080 : 256) + 2 * nMining).c_str() + : ", not mining"); + + str += "\n peer dir height last recv last send unsent\n"; + foreach(CNode* pnode, vCopy) + { + int nSendSize = 0; + TRY_CRITICAL_BLOCK(pnode->cs_vSend) + nSendSize = (int)pnode->vSend.size(); + str += strprintf(" %-28s %-4s %6d %10s %10s %7d\n", + pnode->addr.ToString().substr(0, 28).c_str(), + pnode->fInbound ? "in" : "out", + pnode->nStartingHeight, + FormatAge(pnode->nLastRecv ? nNow - pnode->nLastRecv : -1).c_str(), + FormatAge(pnode->nLastSend ? nNow - pnode->nLastSend : -1).c_str(), + nSendSize); + } + return str; +} + bool GetMyExternalIP(unsigned int& ipRet) { @@ -1058,6 +1148,24 @@ void ThreadSocketHandler2(void* parg) (int)vNodes.size() - (int)FD_SETSIZE + 1); } } + nPeersWatched = (int)nWatched - 1; // less the listen socket + } + + // Say the state of the node out loud now and then, so a log pulled off + // a machine three weeks later still answers "was it hearing anybody". + { + static int64 nLastReport = 0; + // Wound forward on the first pass so the first report lands about a + // minute in, once peers have had time to connect. A report written + // at second zero says nothing, and waiting ten minutes for the + // first one is ten minutes of a log that cannot answer anything. + if (nLastReport == 0) + nLastReport = GetTime() - 9 * 60; + if (GetTime() - nLastReport > 10 * 60) + { + nLastReport = GetTime(); + printf("%s\n", GetDiagnosticsText().c_str()); + } } vfThreadRunning[0] = false; @@ -1432,6 +1540,14 @@ void ThreadMessageHandler2(void* parg) static CCriticalSection cs_nMinersRunning; static int nMinersRunning = 0; +static int MinersRunningCount() +{ + int n = 0; + CRITICAL_BLOCK(cs_nMinersRunning) + n = nMinersRunning; + return n; +} + void ThreadBitcoinMiner(void* parg) { int nThreadId = (int)(intptr_t)parg; @@ -1490,6 +1606,7 @@ int StartMinerThreads() bool StartNode(string& strError) { strError = ""; + nNodeStartTime = GetTime(); // Sockets startup WSADATA wsadata; -- cgit v1.2.3