diff options
Diffstat (limited to 'src')
| -rw-r--r-- | src/Makefile | 4 | ||||
| -rw-r--r-- | src/btfrv.cpp | 49 | ||||
| -rw-r--r-- | src/btftunnel.cpp | 103 | ||||
| -rw-r--r-- | src/gui.cpp | 34 | ||||
| -rw-r--r-- | src/main.cpp | 415 | ||||
| -rw-r--r-- | src/main_gui.cpp | 50 | ||||
| -rw-r--r-- | src/net.cpp | 5 | ||||
| -rw-r--r-- | src/net.h | 73 | ||||
| -rw-r--r-- | src/nostr.cpp | 27 | ||||
| -rw-r--r-- | src/nostr.h | 3 | ||||
| -rw-r--r-- | src/randomx_pow.cpp | 28 | ||||
| -rw-r--r-- | src/readme.txt | 2 | ||||
| -rw-r--r-- | src/rpc.cpp | 90 | ||||
| -rw-r--r-- | src/util.cpp | 153 | ||||
| -rw-r--r-- | src/util.h | 93 |
15 files changed, 1050 insertions, 79 deletions
diff --git a/src/Makefile b/src/Makefile index 1bc3ae8..2c6d304 100644 --- a/src/Makefile +++ b/src/Makefile | |||
| @@ -6,7 +6,9 @@ FUZZ_CXX ?= clang++ | |||
| 6 | 6 | ||
| 7 | SECP_INC ?= /usr/local/include | 7 | SECP_INC ?= /usr/local/include |
| 8 | SECP_LIB ?= /usr/local/lib | 8 | SECP_LIB ?= /usr/local/lib |
| 9 | RANDOMX_DIR ?= $(HOME)/RandomX | 9 | # The root Makefile exports RANDOMX_DIR (default: <repo>/randomx-build, built |
| 10 | # by deps-randomx). This fallback only applies when src/ is built standalone. | ||
| 11 | RANDOMX_DIR ?= $(abspath $(CURDIR)/..)/randomx-build | ||
| 10 | 12 | ||
| 11 | IMGUI_DIR = imgui | 13 | IMGUI_DIR = imgui |
| 12 | 14 | ||
diff --git a/src/btfrv.cpp b/src/btfrv.cpp index 864fe3d..7d705ef 100644 --- a/src/btfrv.cpp +++ b/src/btfrv.cpp | |||
| @@ -40,6 +40,8 @@ typedef int SOCKET; | |||
| 40 | #include <thread> | 40 | #include <thread> |
| 41 | #include <mutex> | 41 | #include <mutex> |
| 42 | #include <atomic> | 42 | #include <atomic> |
| 43 | #include <chrono> | ||
| 44 | #include <system_error> | ||
| 43 | 45 | ||
| 44 | namespace btf | 46 | namespace btf |
| 45 | { | 47 | { |
| @@ -209,8 +211,28 @@ static void HandleIncoming(SOCKET s) | |||
| 209 | bool a = WriteN(svc, &ok, 1); | 211 | bool a = WriteN(svc, &ok, 1); |
| 210 | bool b = WriteN(s, &ok, 1); | 212 | bool b = WriteN(s, &ok, 1); |
| 211 | if (!a || !b) { CLOSESOCK(svc); CLOSESOCK(s); return; } | 213 | if (!a || !b) { CLOSESOCK(svc); CLOSESOCK(s); return; } |
| 212 | std::thread(Forward, s, svc).detach(); | 214 | // One thread pumps s -> svc; this thread pumps svc -> s. Spawning a |
| 213 | std::thread(Forward, svc, s).detach(); | 215 | // thread per direction left no clean way to fail the second spawn: |
| 216 | // std::thread throws std::system_error when pthread_create is refused | ||
| 217 | // (NPROC limit, container pids cgroup, memory pressure), the first | ||
| 218 | // pump was already detached, and closing its sockets from here would | ||
| 219 | // race it -- so nothing caught the throw and it reached | ||
| 220 | // std::terminate, killing the relay over one pair it could not serve. | ||
| 221 | // Running one direction on this thread leaves exactly one spawn to | ||
| 222 | // guard, and a failure here has nothing running yet to race. | ||
| 223 | try | ||
| 224 | { | ||
| 225 | std::thread(Forward, s, svc).detach(); | ||
| 226 | } | ||
| 227 | catch (const std::system_error& e) | ||
| 228 | { | ||
| 229 | fprintf(stderr, "rendezvous relay: cannot spawn forward thread (%s), pair dropped\n", | ||
| 230 | e.what()); | ||
| 231 | CLOSESOCK(svc); | ||
| 232 | CLOSESOCK(s); | ||
| 233 | return; | ||
| 234 | } | ||
| 235 | Forward(svc, s); | ||
| 214 | } | 236 | } |
| 215 | else | 237 | else |
| 216 | { | 238 | { |
| @@ -236,6 +258,7 @@ bool RvRelayRun(unsigned short port) | |||
| 236 | if (bind(g_listen, (struct sockaddr*)&addr, sizeof(addr)) != 0) { CLOSESOCK(g_listen); return false; } | 258 | if (bind(g_listen, (struct sockaddr*)&addr, sizeof(addr)) != 0) { CLOSESOCK(g_listen); return false; } |
| 237 | if (listen(g_listen, 16) != 0) { CLOSESOCK(g_listen); return false; } | 259 | if (listen(g_listen, 16) != 0) { CLOSESOCK(g_listen); return false; } |
| 238 | 260 | ||
| 261 | int nSpawnFails = 0; | ||
| 239 | while (!g_stop) | 262 | while (!g_stop) |
| 240 | { | 263 | { |
| 241 | struct sockaddr_in cli; | 264 | struct sockaddr_in cli; |
| @@ -246,7 +269,27 @@ bool RvRelayRun(unsigned short port) | |||
| 246 | if (g_stop) break; | 269 | if (g_stop) break; |
| 247 | continue; | 270 | continue; |
| 248 | } | 271 | } |
| 249 | std::thread(HandleIncoming, s).detach(); | 272 | try |
| 273 | { | ||
| 274 | std::thread(HandleIncoming, s).detach(); | ||
| 275 | nSpawnFails = 0; | ||
| 276 | } | ||
| 277 | catch (const std::system_error& e) | ||
| 278 | { | ||
| 279 | // A refused pthread_create is backpressure, not a reason to die: | ||
| 280 | // the condition behind it (NPROC, pids cgroup, memory) does not | ||
| 281 | // clear in milliseconds, and the connection count feeding it is | ||
| 282 | // attacker-influenced. Drop this one peer, stop accepting for a | ||
| 283 | // moment -- longer each time, capped -- and keep serving the | ||
| 284 | // connections already established. | ||
| 285 | fprintf(stderr, "rendezvous relay: cannot spawn connection thread (%s), connection dropped\n", | ||
| 286 | e.what()); | ||
| 287 | CLOSESOCK(s); | ||
| 288 | nSpawnFails++; | ||
| 289 | int nWaitMs = nSpawnFails < 5 ? nSpawnFails * 1000 : 5000; | ||
| 290 | for (int i = 0; i < nWaitMs && !g_stop; i += 100) | ||
| 291 | std::this_thread::sleep_for(std::chrono::milliseconds(100)); | ||
| 292 | } | ||
| 250 | } | 293 | } |
| 251 | CLOSESOCK(g_listen); | 294 | CLOSESOCK(g_listen); |
| 252 | g_listen = INVALID_SOCKET; | 295 | g_listen = INVALID_SOCKET; |
diff --git a/src/btftunnel.cpp b/src/btftunnel.cpp index 408476e..4058f6b 100644 --- a/src/btftunnel.cpp +++ b/src/btftunnel.cpp | |||
| @@ -25,8 +25,12 @@ typedef int SOCKET; | |||
| 25 | #endif | 25 | #endif |
| 26 | #include "sockcount.h" | 26 | #include "sockcount.h" |
| 27 | #include <cstring> | 27 | #include <cstring> |
| 28 | #include <cstdio> | ||
| 29 | #include <memory> | ||
| 30 | #include <new> | ||
| 28 | #include <vector> | 31 | #include <vector> |
| 29 | #include <thread> | 32 | #include <thread> |
| 33 | #include <system_error> | ||
| 30 | 34 | ||
| 31 | namespace btf | 35 | namespace btf |
| 32 | { | 36 | { |
| @@ -119,20 +123,111 @@ static void PumpIn(SOCKET pumpEnd, RvSocket rv, std::vector<unsigned char> key) | |||
| 119 | shutdown((SOCKET)rv, SD_BOTH); | 123 | shutdown((SOCKET)rv, SD_BOTH); |
| 120 | } | 124 | } |
| 121 | 125 | ||
| 126 | // The pump end and the rendezvous socket, owned jointly by whoever is still | ||
| 127 | // using them. Closed once, by the last reference to go. | ||
| 128 | // | ||
| 129 | // Joint ownership rather than "the inbound pump owns the cleanup", because | ||
| 130 | // either pump can reach its exit first and BOTH touch BOTH descriptors on the | ||
| 131 | // way out -- PumpOut ends in shutdown(rv), shutdown(pumpEnd) and PumpIn ends in | ||
| 132 | // the mirror image. A single owner therefore has no exit at which the other is | ||
| 133 | // guaranteed to be finished. Holding a reference for the whole body of each | ||
| 134 | // pump gives it one: the close cannot happen until the last pump has stopped | ||
| 135 | // touching the descriptors, so no shutdown() can land on a number that has | ||
| 136 | // already been closed and handed back out by the kernel to an unrelated | ||
| 137 | // connection. | ||
| 138 | struct TunnelEnds | ||
| 139 | { | ||
| 140 | SOCKET pumpEnd; | ||
| 141 | RvSocket rv; | ||
| 142 | TunnelEnds(SOCKET p, RvSocket r) : pumpEnd(p), rv(r) {} | ||
| 143 | ~TunnelEnds() { BtfCloseSocket(pumpEnd); RvClose(rv); } | ||
| 144 | private: | ||
| 145 | TunnelEnds(const TunnelEnds&); | ||
| 146 | TunnelEnds& operator=(const TunnelEnds&); | ||
| 147 | }; | ||
| 148 | |||
| 122 | // Start the two pumps and hand back the app-facing socket. When both pumps | 149 | // Start the two pumps and hand back the app-facing socket. When both pumps |
| 123 | // finish, close the pump end and the rendezvous socket. | 150 | // finish, close the pump end and the rendezvous socket. |
| 151 | // | ||
| 152 | // That sentence used to be a comment describing something the code did not do. | ||
| 153 | // The inbound pump closed both descriptors as soon as it exited, without | ||
| 154 | // waiting for the outbound pump, which then called shutdown() on both at its | ||
| 155 | // own exit. Whether that shutdown hit a live descriptor or a closed one came | ||
| 156 | // down to which pump got there first, and the rendezvous socket dying before | ||
| 157 | // the app socket -- a relay restart, the far side hanging up -- is precisely | ||
| 158 | // the order that puts the inbound pump ahead. Measured over 25 such teardowns | ||
| 159 | // against the real code: 29 shutdowns landed on an already-closed descriptor. | ||
| 160 | // | ||
| 161 | // appEnd is not part of this. It is handed to the caller on success and closed | ||
| 162 | // here on every failure path; no pump ever touches it. | ||
| 163 | // | ||
| 164 | // Every tunnel is two threads, and a tunnel is one peer connection (a .btf | ||
| 165 | // dial or accept, a pool miner, a participant's pool session) -- so the | ||
| 166 | // thread count scales with peer count, which is attacker-influenced. When | ||
| 167 | // pthread_create is refused std::thread throws std::system_error; uncaught it | ||
| 168 | // reached std::terminate and took the whole process down over one connection | ||
| 169 | // it could not serve. Both spawns are guarded, and the failure paths return | ||
| 170 | // INVALID_SOCKET, which every caller already handles by dropping just that | ||
| 171 | // connection. | ||
| 124 | static btf_socket_t StartTunnel(RvSocket rv, const unsigned char shared[32]) | 172 | static btf_socket_t StartTunnel(RvSocket rv, const unsigned char shared[32]) |
| 125 | { | 173 | { |
| 126 | btf_socket_t appEnd, pumpEnd; | 174 | btf_socket_t appEnd, pumpEnd; |
| 127 | if (!MakeLocalPair(appEnd, pumpEnd)) { RvClose(rv); return INVALID_SOCKET; } | 175 | if (!MakeLocalPair(appEnd, pumpEnd)) { RvClose(rv); return INVALID_SOCKET; } |
| 128 | 176 | ||
| 129 | std::vector<unsigned char> key(shared, shared + 32); | 177 | std::vector<unsigned char> key(shared, shared + 32); |
| 130 | std::thread(PumpOut, pumpEnd, rv, key).detach(); | 178 | |
| 131 | std::thread([pumpEnd, rv, key]() { | 179 | // make_shared, not shared_ptr(new ...): it allocates before it constructs, |
| 132 | PumpIn(pumpEnd, rv, key); | 180 | // so it either comes back owning both descriptors or throws having taken |
| 181 | // ownership of neither. The two-step form can run the deleter and then | ||
| 182 | // throw, which would close both here and again below. | ||
| 183 | std::shared_ptr<TunnelEnds> ends; | ||
| 184 | try | ||
| 185 | { | ||
| 186 | ends = std::make_shared<TunnelEnds>(pumpEnd, rv); | ||
| 187 | } | ||
| 188 | catch (const std::bad_alloc&) | ||
| 189 | { | ||
| 190 | fprintf(stderr, "btf tunnel: out of memory starting tunnel, tunnel dropped\n"); | ||
| 133 | BtfCloseSocket(pumpEnd); | 191 | BtfCloseSocket(pumpEnd); |
| 192 | BtfCloseSocket(appEnd); | ||
| 134 | RvClose(rv); | 193 | RvClose(rv); |
| 135 | }).detach(); | 194 | return INVALID_SOCKET; |
| 195 | } | ||
| 196 | |||
| 197 | try | ||
| 198 | { | ||
| 199 | std::thread([ends, key]() { PumpIn(ends->pumpEnd, ends->rv, key); }).detach(); | ||
| 200 | } | ||
| 201 | catch (const std::system_error& e) | ||
| 202 | { | ||
| 203 | // Nothing is running yet: `ends` is the only reference, and returning | ||
| 204 | // drops it, which is what closes pumpEnd and rv. | ||
| 205 | fprintf(stderr, "btf tunnel: cannot spawn inbound pump (%s), tunnel dropped\n", | ||
| 206 | e.what()); | ||
| 207 | BtfCloseSocket(appEnd); | ||
| 208 | return INVALID_SOCKET; | ||
| 209 | } | ||
| 210 | |||
| 211 | try | ||
| 212 | { | ||
| 213 | std::thread([ends, key]() { PumpOut(ends->pumpEnd, ends->rv, key); }).detach(); | ||
| 214 | } | ||
| 215 | catch (const std::system_error& e) | ||
| 216 | { | ||
| 217 | // The inbound pump may be parked in RvReadN(rv) or may already have | ||
| 218 | // exited -- when the spawn is refused because the process is loaded, | ||
| 219 | // the rendezvous socket is often dead for the same reason, and then | ||
| 220 | // PumpIn returns on its first length read. Either way this thread | ||
| 221 | // still holds a reference, so both descriptors are still open: the | ||
| 222 | // shutdown wakes the pump if it is parked and is harmless if it is | ||
| 223 | // not. The close belongs to whichever reference goes last. | ||
| 224 | fprintf(stderr, "btf tunnel: cannot spawn outbound pump (%s), tunnel dropped\n", | ||
| 225 | e.what()); | ||
| 226 | shutdown((SOCKET)ends->rv, SD_BOTH); | ||
| 227 | shutdown(ends->pumpEnd, SD_BOTH); | ||
| 228 | BtfCloseSocket(appEnd); | ||
| 229 | return INVALID_SOCKET; | ||
| 230 | } | ||
| 136 | return appEnd; | 231 | return appEnd; |
| 137 | } | 232 | } |
| 138 | 233 | ||
diff --git a/src/gui.cpp b/src/gui.cpp index 8dcb854..9b3802b 100644 --- a/src/gui.cpp +++ b/src/gui.cpp | |||
| @@ -15,6 +15,7 @@ | |||
| 15 | #include <atomic> | 15 | #include <atomic> |
| 16 | #include <mutex> | 16 | #include <mutex> |
| 17 | #include <thread> | 17 | #include <thread> |
| 18 | #include <system_error> | ||
| 18 | #include "bip32.h" | 19 | #include "bip32.h" |
| 19 | #include "walletcmd.h" | 20 | #include "walletcmd.h" |
| 20 | #include "font_roboto.h" | 21 | #include "font_roboto.h" |
| @@ -910,8 +911,16 @@ static void DrawOptionsDialog() | |||
| 910 | 911 | ||
| 911 | if (nMineMode == MINE_OPERATOR) { | 912 | if (nMineMode == MINE_OPERATOR) { |
| 912 | if (!gPoolServerRunning) { | 913 | if (!gPoolServerRunning) { |
| 913 | gPoolServerRunning = true; | 914 | // Claim the server is up only once it is. The flag used to |
| 914 | _beginthread(ThreadRPCServer, 0, NULL); | 915 | // be set first and the result never looked at, so a refused |
| 916 | // spawn left an operator with a pool that reports itself | ||
| 917 | // running, no RPC server for miners to reach, and nothing | ||
| 918 | // anywhere saying why. The flag also latches: with it set, | ||
| 919 | // this branch is never retried. | ||
| 920 | if (_beginthread(ThreadRPCServer, 0, NULL) == (uintptr_t)-1) | ||
| 921 | printf("Error: _beginthread(ThreadRPCServer) failed -- pool server not started\n"); | ||
| 922 | else | ||
| 923 | gPoolServerRunning = true; | ||
| 915 | } else if (!gPoolRunning) { | 924 | } else if (!gPoolRunning) { |
| 916 | gPoolRunning = true; | 925 | gPoolRunning = true; |
| 917 | } | 926 | } |
| @@ -1124,11 +1133,28 @@ static void DrawRestorePhraseDialog() | |||
| 1124 | } | 1133 | } |
| 1125 | g_restoreDerived.store(0); | 1134 | g_restoreDerived.store(0); |
| 1126 | g_restoreRecovered.store(0); | 1135 | g_restoreRecovered.store(0); |
| 1136 | // Set before the spawn, not after: RestoreThread clears this | ||
| 1137 | // flag itself when it finishes, and a short restore can beat | ||
| 1138 | // us back here and have its `false` overwritten, leaving the | ||
| 1139 | // dialog disabled forever. | ||
| 1127 | g_restoreRunning.store(true); | 1140 | g_restoreRunning.store(true); |
| 1128 | // On its own thread: a restore walks the whole chain once per | 1141 | // On its own thread: a restore walks the whole chain once per |
| 1129 | // batch and would otherwise freeze the window for as long as it | 1142 | // batch and would otherwise freeze the window for as long as it |
| 1130 | // takes. | 1143 | // takes. A refused spawn is one restore that does not happen, |
| 1131 | std::thread(RestoreThread, std::string(g_restoreInput)).detach(); | 1144 | // not a reason to take the window down with an uncaught |
| 1145 | // std::system_error -- and the flag has to come back off, or | ||
| 1146 | // the dialog sits greyed out reporting a search nobody is | ||
| 1147 | // running. | ||
| 1148 | try | ||
| 1149 | { | ||
| 1150 | std::thread(RestoreThread, std::string(g_restoreInput)).detach(); | ||
| 1151 | } | ||
| 1152 | catch (const std::system_error& e) | ||
| 1153 | { | ||
| 1154 | g_restoreRunning.store(false); | ||
| 1155 | std::lock_guard<std::mutex> lock(g_restoreResultMutex); | ||
| 1156 | g_restoreResult = std::string("Could not start the search: ") + e.what(); | ||
| 1157 | } | ||
| 1132 | } | 1158 | } |
| 1133 | } | 1159 | } |
| 1134 | if (fBusy) | 1160 | if (fBusy) |
diff --git a/src/main.cpp b/src/main.cpp index b0bdb8c..6b8e0de 100644 --- a/src/main.cpp +++ b/src/main.cpp | |||
| @@ -14,6 +14,7 @@ | |||
| 14 | #include <atomic> | 14 | #include <atomic> |
| 15 | #include <mutex> | 15 | #include <mutex> |
| 16 | #include <thread> | 16 | #include <thread> |
| 17 | #include <system_error> | ||
| 17 | #include "bip32.h" | 18 | #include "bip32.h" |
| 18 | #include "btfaddr.h" | 19 | #include "btfaddr.h" |
| 19 | #include "btftunnel.h" | 20 | #include "btftunnel.h" |
| @@ -64,6 +65,137 @@ CBlockIndex* pindexBest = NULL; | |||
| 64 | map<uint256, CBlock*> mapOrphanBlocks; | 65 | map<uint256, CBlock*> mapOrphanBlocks; |
| 65 | multimap<uint256, CBlock*> mapOrphanBlocksByPrev; | 66 | multimap<uint256, CBlock*> mapOrphanBlocksByPrev; |
| 66 | 67 | ||
| 68 | // Block bodies we have sent a getdata for and not yet received, so the | ||
| 69 | // failover pass in SendMessages can tell "requested and being served" from | ||
| 70 | // "requested and gone quiet" and re-issue the request to a different peer | ||
| 71 | // (#33). Keyed by block hash; setAsked is the peers already tried since the | ||
| 72 | // round last restarted, so the retry rotates instead of hammering the | ||
| 73 | // announcer that is not serving. Guarded by cs_main, which both the message | ||
| 74 | // handlers and SendMessages already hold. | ||
| 75 | // | ||
| 76 | // Capped small on purpose. At the tip there is one block in flight; during | ||
| 77 | // initial download there are legitimately hundreds outstanding to one peer, | ||
| 78 | // and rotating those would duplicate the whole download to every other peer. | ||
| 79 | // | ||
| 80 | // The cap is a shared resource and nothing on the path from inv to insertion | ||
| 81 | // can tell a real block hash from 32 random bytes -- AlreadyHave only asks | ||
| 82 | // whether we already hold the block, and there is no header to check work | ||
| 83 | // against. So the table does not refuse a new hash when it is full; it makes | ||
| 84 | // room. See MakeRoomInBlockFetch for the rule, which is what stops one peer | ||
| 85 | // filling all eight slots and switching failover off for everybody. | ||
| 86 | // | ||
| 87 | // The initialisers matter: the insertion path uses operator[] and then tests | ||
| 88 | // nTimeFirstAsked == 0 to detect a fresh entry. That worked on | ||
| 89 | // value-initialisation alone, but only for as long as nobody gave this struct | ||
| 90 | // a constructor. | ||
| 91 | struct CBlockFetch | ||
| 92 | { | ||
| 93 | int64 nTimeFirstAsked = 0; // when the first getdata for this block went out | ||
| 94 | int64 nTimeAsked = 0; // when the latest getdata went out | ||
| 95 | CAddress addrAnnounced; // peer whose announcement put this hash here | ||
| 96 | set<CAddress> setAsked; // peers tried since the round last restarted | ||
| 97 | }; | ||
| 98 | map<uint256, CBlockFetch> mapBlockFetch; | ||
| 99 | static const int BLOCK_FETCH_TRACK_MAX = 8; | ||
| 100 | // A block nobody has served for this long is not a fetch problem: the hash may | ||
| 101 | // have been announced and never existed. Drop the entry rather than getdata | ||
| 102 | // forever; a re-announcement recreates it. | ||
| 103 | static const int BLOCK_FETCH_GIVEUP_SECS = 10 * 60; | ||
| 104 | |||
| 105 | // Failover firing at all is worth saying out loud: it means peers are | ||
| 106 | // announcing blocks they then do not serve, which is the pathology of #33 and | ||
| 107 | // the thing nobody could otherwise see. Naming the peer on every re-request is | ||
| 108 | // a different matter. A peer can drive that line as often as it likes by | ||
| 109 | // announcing hashes it will not serve, and what it prints is a peer address, | ||
| 110 | // which is the one thing the .btf transport otherwise takes trouble not to | ||
| 111 | // spread around. So the per-peer detail sits behind the net category and the | ||
| 112 | // unconditional line is a count over a window no peer can shorten: the first | ||
| 113 | // failover after a quiet spell prints at once, because the change from "blocks | ||
| 114 | // arrive" to "blocks are announced and not served" is the event worth seeing, | ||
| 115 | // and everything after it is summarised once a minute. | ||
| 116 | static const int BLOCK_FETCH_REPORT_SECS = 60; | ||
| 117 | static int64 nBlockFetchWindowStart = 0; | ||
| 118 | static int nBlockFetchFailovers = 0; | ||
| 119 | |||
| 120 | // How stale our own best block may be before we stop calling this the tip. | ||
| 121 | // Blocks target two minutes, so this is thirty intervals: far longer than any | ||
| 122 | // stall worth failing over from -- the one in #33 ran sixteen minutes -- and | ||
| 123 | // far shorter than catching up, which starts hours or days back. | ||
| 124 | static const int BLOCK_FETCH_TIP_AGE_SECS = 60 * 60; | ||
| 125 | |||
| 126 | // Whether this node is tracking the tip rather than still catching up. | ||
| 127 | // | ||
| 128 | // Measured off the age of our own best block, not off any height a peer told | ||
| 129 | // us. nStartingHeight is optional in the version message and every node | ||
| 130 | // released so far sends the short form, so it is -1 for essentially every | ||
| 131 | // peer; and where it is filled in later it is filled in from the height of a | ||
| 132 | // block that peer served us, which during catch-up tracks our own height and | ||
| 133 | // would report "at the tip" for the whole download. Block timestamps are the | ||
| 134 | // one clock here that peers cannot move: CheckBlock refuses anything more than | ||
| 135 | // two hours ahead and AcceptBlock refuses anything at or before the previous | ||
| 136 | // median, so the only way to make this read "at the tip" falsely is to mine, | ||
| 137 | // and all that buys is the 15s spacing this code had unconditionally anyway. | ||
| 138 | bool IsBlockFetchNearTip() | ||
| 139 | { | ||
| 140 | return pindexBest && (int64)pindexBest->nTime > GetTime() - BLOCK_FETCH_TIP_AGE_SECS; | ||
| 141 | } | ||
| 142 | |||
| 143 | // Drop one entry so a hash announced by addrNew can be tracked. | ||
| 144 | // | ||
| 145 | // Refusing the insertion instead was a remote off-switch for the whole | ||
| 146 | // feature. An inv carrying eight hashes that never existed filled every slot | ||
| 147 | // -- nothing between inv and here can tell those from real blocks -- and no | ||
| 148 | // genuinely new block was tracked again until the give-up timer expired ten | ||
| 149 | // minutes later, re-armable for one message per ten minutes from a single | ||
| 150 | // connection. | ||
| 151 | // | ||
| 152 | // So evict instead, by occupancy: a peer may only take a slot from a peer | ||
| 153 | // holding strictly more slots than itself, and otherwise recycles one of its | ||
| 154 | // own. That is what keeps eviction from becoming the same attack in a new | ||
| 155 | // shape. A peer that has filled the table is by definition the heaviest | ||
| 156 | // holder, so its own entries are the only ones it can displace, while a peer | ||
| 157 | // announcing its first block holds nothing and therefore always evicts from | ||
| 158 | // the heaviest -- a genuine announcement is never refused a slot, whatever the | ||
| 159 | // attacker holds or however many connections it holds it from. The one case | ||
| 160 | // that costs a real fetch is eight distinct peers holding one entry each, | ||
| 161 | // where a ninth takes the oldest; that is a busy healthy node, not an attack, | ||
| 162 | // and losing the oldest of eight beats refusing the ninth. | ||
| 163 | static void MakeRoomInBlockFetch(const CAddress& addrNew) | ||
| 164 | { | ||
| 165 | if (mapBlockFetch.empty()) | ||
| 166 | return; | ||
| 167 | |||
| 168 | map<CAddress, int> mapHeld; | ||
| 169 | for (map<uint256, CBlockFetch>::iterator mi = mapBlockFetch.begin(); mi != mapBlockFetch.end(); ++mi) | ||
| 170 | mapHeld[(*mi).second.addrAnnounced]++; | ||
| 171 | |||
| 172 | int nMine = mapHeld.count(addrNew) ? mapHeld[addrNew] : 0; | ||
| 173 | |||
| 174 | int nMax = 0; | ||
| 175 | CAddress addrVictim; | ||
| 176 | for (map<CAddress, int>::iterator mi = mapHeld.begin(); mi != mapHeld.end(); ++mi) | ||
| 177 | if ((*mi).second > nMax) | ||
| 178 | { | ||
| 179 | nMax = (*mi).second; | ||
| 180 | addrVictim = (*mi).first; | ||
| 181 | } | ||
| 182 | |||
| 183 | // Nobody is holding more than this peer, so it recycles its own oldest | ||
| 184 | // rather than taking a slot off an equal. | ||
| 185 | if (nMax <= nMine) | ||
| 186 | addrVictim = addrNew; | ||
| 187 | |||
| 188 | map<uint256, CBlockFetch>::iterator miVictim = mapBlockFetch.end(); | ||
| 189 | for (map<uint256, CBlockFetch>::iterator mi = mapBlockFetch.begin(); mi != mapBlockFetch.end(); ++mi) | ||
| 190 | if ((*mi).second.addrAnnounced == addrVictim && | ||
| 191 | (miVictim == mapBlockFetch.end() || | ||
| 192 | (*mi).second.nTimeFirstAsked < (*miVictim).second.nTimeFirstAsked)) | ||
| 193 | miVictim = mi; | ||
| 194 | |||
| 195 | if (miVictim != mapBlockFetch.end()) | ||
| 196 | mapBlockFetch.erase(miVictim); | ||
| 197 | } | ||
| 198 | |||
| 67 | map<uint256, CDataStream*> mapOrphanTransactions; | 199 | map<uint256, CDataStream*> mapOrphanTransactions; |
| 68 | multimap<uint256, CDataStream*> mapOrphanTransactionsByPrev; | 200 | multimap<uint256, CDataStream*> mapOrphanTransactionsByPrev; |
| 69 | 201 | ||
| @@ -1712,7 +1844,7 @@ void CWalletTx::RelayWalletTransaction(CTxDB& txdb) | |||
| 1712 | uint256 hash = GetHash(); | 1844 | uint256 hash = GetHash(); |
| 1713 | if (!txdb.ContainsTx(hash)) | 1845 | if (!txdb.ContainsTx(hash)) |
| 1714 | { | 1846 | { |
| 1715 | if (LogAcceptsCategory("net")) printf("Relaying wtx %s\n", hash.ToString().substr(0,6).c_str()); | 1847 | if (LogAcceptsCategory("relay")) printf("Relaying wtx %s\n", hash.ToString().substr(0,6).c_str()); |
| 1716 | RelayMessage(CInv(MSG_TX, hash), (CTransaction)*this); | 1848 | RelayMessage(CInv(MSG_TX, hash), (CTransaction)*this); |
| 1717 | } | 1849 | } |
| 1718 | } | 1850 | } |
| @@ -2678,7 +2810,18 @@ bool LoadBlockIndex(bool fAllowNew) | |||
| 2678 | // CTxOut(nValue=50.00000000, scriptPubKey=0x5F1DF16B2B704C8A578D0B) | 2810 | // CTxOut(nValue=50.00000000, scriptPubKey=0x5F1DF16B2B704C8A578D0B) |
| 2679 | // vMerkleTree: 4a5e1e | 2811 | // vMerkleTree: 4a5e1e |
| 2680 | 2812 | ||
| 2681 | // Bitflash genesis block -- own header (fair launch, 2026 stable relaunch) | 2813 | // Bitflash genesis block -- own header (fair launch) |
| 2814 | // | ||
| 2815 | // Do not change pszTimestamp, the scriptPubKey, nTime or nNonce. They | ||
| 2816 | // are the inputs to the genesis hash, and the genesis hash is | ||
| 2817 | // consensus. Changing one on its own trips the assert below, which is | ||
| 2818 | // loud and reverts cleanly; changing one and regenerating | ||
| 2819 | // GENESIS_NONCE and hashGenesisBlock to match -- which is exactly what | ||
| 2820 | // the re-mining branch below prints out and invites -- gives a node | ||
| 2821 | // that starts without complaint, builds its own chain from height 0, | ||
| 2822 | // and rejects every real peer as being on a different chain. That one | ||
| 2823 | // fails silently, and the damage scales with how many people run the | ||
| 2824 | // "fixed" build. | ||
| 2682 | char* pszTimestamp = "Bitflash 24/Jul/2026 Fair launch: one CPU one vote, no premine"; | 2825 | char* pszTimestamp = "Bitflash 24/Jul/2026 Fair launch: one CPU one vote, no premine"; |
| 2683 | CTransaction txNew; | 2826 | CTransaction txNew; |
| 2684 | txNew.vin.resize(1); | 2827 | txNew.vin.resize(1); |
| @@ -2691,7 +2834,14 @@ bool LoadBlockIndex(bool fAllowNew) | |||
| 2691 | block.hashPrevBlock = 0; | 2834 | block.hashPrevBlock = 0; |
| 2692 | block.hashMerkleRoot = block.BuildMerkleTree(); | 2835 | block.hashMerkleRoot = block.BuildMerkleTree(); |
| 2693 | block.nVersion = 1; | 2836 | block.nVersion = 1; |
| 2694 | block.nTime = 1753315200; // 2026-07-24 00:00:00 UTC (stable relaunch) | 2837 | // 1753315200 is 2025-07-24T00:00:00Z. The headline in pszTimestamp |
| 2838 | // above reads 2026 and does not match it. This is a known discrepancy | ||
| 2839 | // and not a typo in the constant: the value is only consensus-critical | ||
| 2840 | // as an input to the genesis hash, the block hashes to | ||
| 2841 | // hashGenesisBlock with it, and every node on the network agrees. The | ||
| 2842 | // mismatch is in the launched chain and cannot be corrected -- see the | ||
| 2843 | // warning above before deciding otherwise. | ||
| 2844 | block.nTime = 1753315200; | ||
| 2695 | block.nBits = 0x1f0fffff; // = bnProofOfWorkLimit (Bitflash RandomX floor) | 2845 | block.nBits = 0x1f0fffff; // = bnProofOfWorkLimit (Bitflash RandomX floor) |
| 2696 | block.nNonce = GENESIS_NONCE; | 2846 | block.nNonce = GENESIS_NONCE; |
| 2697 | 2847 | ||
| @@ -2718,6 +2868,11 @@ bool LoadBlockIndex(bool fAllowNew) | |||
| 2718 | printf("powhash = %s\n", block.GetPoWHash().ToString().c_str()); | 2868 | printf("powhash = %s\n", block.GetPoWHash().ToString().c_str()); |
| 2719 | printf("hash = %s\n", block.GetHash().ToString().c_str()); | 2869 | printf("hash = %s\n", block.GetHash().ToString().c_str()); |
| 2720 | printf("merkle = %s\n", block.hashMerkleRoot.ToString().c_str()); | 2870 | printf("merkle = %s\n", block.hashMerkleRoot.ToString().c_str()); |
| 2871 | printf("----------------------------------------\n"); | ||
| 2872 | printf("These constants bring up a NEW chain. Do not paste them\n"); | ||
| 2873 | printf("into a build for this network to make an edited nTime or\n"); | ||
| 2874 | printf("pszTimestamp fit -- a node whose genesis differs starts\n"); | ||
| 2875 | printf("cleanly on a chain of its own and rejects every real peer.\n"); | ||
| 2721 | printf("========================================\n"); | 2876 | printf("========================================\n"); |
| 2722 | } | 2877 | } |
| 2723 | 2878 | ||
| @@ -3263,15 +3418,61 @@ bool ProcessMessage(CNode* pfrom, string strCommand, CDataStream& vRecv) | |||
| 3263 | vRecv >> *pblock; | 3418 | vRecv >> *pblock; |
| 3264 | 3419 | ||
| 3265 | //// debug print | 3420 | //// debug print |
| 3266 | if (LogAcceptsCategory("net")) { printf("received block:\n"); pblock->print(); } | 3421 | if (LogAcceptsCategory("relay")) { printf("received block:\n"); pblock->print(); } |
| 3267 | 3422 | ||
| 3268 | CInv inv(MSG_BLOCK, pblock->GetHash()); | 3423 | CInv inv(MSG_BLOCK, pblock->GetHash()); |
| 3269 | pfrom->AddInventoryKnown(inv); | 3424 | pfrom->AddInventoryKnown(inv); |
| 3270 | 3425 | ||
| 3426 | // GetHash() covers the 80-byte header and nothing else, so the hash | ||
| 3427 | // coming out right does not make this the block we asked for. Every | ||
| 3428 | // peer that saw X announced holds X's header, and can answer our | ||
| 3429 | // getdata with that header bolted onto a transaction list of its own | ||
| 3430 | // invention -- the reply still hashes to X. hashMerkleRoot is the only | ||
| 3431 | // thing binding the header to the body, so check it here, before the | ||
| 3432 | // mapBlockFetch entry is touched and before CheckBlock spends a | ||
| 3433 | // RandomX hash on a body already known to be forged. | ||
| 3434 | // | ||
| 3435 | // There is no honest way to arrive here. Peer traffic rides the .btf | ||
| 3436 | // channel, which is XChaCha20-Poly1305, so a body that arrives at all | ||
| 3437 | // arrived intact: a mismatch is the peer's own construction, not line | ||
| 3438 | // noise. Drop the peer and leave the fetch outstanding so the failover | ||
| 3439 | // sweep asks somebody else for the real X, rather than recording X as | ||
| 3440 | // delivered on the strength of a header anyone could copy. | ||
| 3441 | if (pblock->hashMerkleRoot != pblock->BuildMerkleTree()) | ||
| 3442 | { | ||
| 3443 | if (LogAcceptsCategory("net")) | ||
| 3444 | printf("peer %s served a forged body for %s\n", | ||
| 3445 | pfrom->addr.ToString().c_str(), inv.ToString().c_str()); | ||
| 3446 | // One line per connection: ProcessMessages keeps draining the | ||
| 3447 | // receive buffer after fDisconnect is set, so a peer that packs | ||
| 3448 | // many forged bodies into one buffer must not get one log line | ||
| 3449 | // for each of them. | ||
| 3450 | if (!pfrom->fDisconnect) | ||
| 3451 | printf("block fetch: a peer answered the request for %s with a body that is not " | ||
| 3452 | "that block -- dropping it\n", inv.hash.ToString().substr(0,14).c_str()); | ||
| 3453 | pfrom->fDisconnect = true; | ||
| 3454 | return error("ProcessMessage() : forged block body for %s", | ||
| 3455 | inv.hash.ToString().substr(0,14).c_str()); | ||
| 3456 | } | ||
| 3457 | |||
| 3271 | if (ProcessBlock(pfrom, pblock.release())) | 3458 | if (ProcessBlock(pfrom, pblock.release())) |
| 3272 | { | 3459 | { |
| 3273 | mapAlreadyAskedFor.erase(inv); | 3460 | mapAlreadyAskedFor.erase(inv); |
| 3274 | 3461 | ||
| 3462 | // The body arrived and validated, so the fetch really is over: | ||
| 3463 | // the block is now in mapBlockIndex, or parked in mapOrphanBlocks, | ||
| 3464 | // and either way AlreadyHave answers for it from here on. | ||
| 3465 | // | ||
| 3466 | // This has to stay inside the success branch, next to the erase | ||
| 3467 | // above. When validation rejects a body nothing is stored, | ||
| 3468 | // AlreadyHave stays false, and the mapAskFor entry was already | ||
| 3469 | // consumed when the getdata went out -- so erasing the tracking | ||
| 3470 | // here would leave the block requested from nobody at all until | ||
| 3471 | // some peer happened to re-announce it. That is exactly the stall | ||
| 3472 | // of #33, and erasing before ProcessBlock made it reachable on | ||
| 3473 | // demand. | ||
| 3474 | mapBlockFetch.erase(inv.hash); | ||
| 3475 | |||
| 3275 | // A peer that just handed us a block is demonstrably at least at | 3476 | // A peer that just handed us a block is demonstrably at least at |
| 3276 | // that block's height. Without this, nStartingHeight is a snapshot | 3477 | // that block's height. Without this, nStartingHeight is a snapshot |
| 3277 | // taken once during the version handshake and never touched again, | 3478 | // taken once during the version handshake and never touched again, |
| @@ -3396,12 +3597,119 @@ bool SendMessages(CNode* pto) | |||
| 3396 | const CInv& inv = (*pto->mapAskFor.begin()).second; | 3597 | const CInv& inv = (*pto->mapAskFor.begin()).second; |
| 3397 | if (LogAcceptsCategory("net")) printf("sending getdata: %s\n", inv.ToString().c_str()); | 3598 | if (LogAcceptsCategory("net")) printf("sending getdata: %s\n", inv.ToString().c_str()); |
| 3398 | if (!AlreadyHave(txdb, inv)) | 3599 | if (!AlreadyHave(txdb, inv)) |
| 3600 | { | ||
| 3399 | vAskFor.push_back(inv); | 3601 | vAskFor.push_back(inv); |
| 3602 | // Blocks get their delivery tracked so the failover pass | ||
| 3603 | // below can chase the ones that go quiet. | ||
| 3604 | if (inv.type == MSG_BLOCK) | ||
| 3605 | { | ||
| 3606 | // Full, and this is a hash we are not already tracking: | ||
| 3607 | // make room rather than drop it on the floor, or one peer | ||
| 3608 | // announcing eight hashes turns failover off for everyone. | ||
| 3609 | if (!mapBlockFetch.count(inv.hash) && | ||
| 3610 | mapBlockFetch.size() >= BLOCK_FETCH_TRACK_MAX) | ||
| 3611 | MakeRoomInBlockFetch(pto->addr); | ||
| 3612 | |||
| 3613 | if (mapBlockFetch.count(inv.hash) || | ||
| 3614 | mapBlockFetch.size() < BLOCK_FETCH_TRACK_MAX) | ||
| 3615 | { | ||
| 3616 | CBlockFetch& fetch = mapBlockFetch[inv.hash]; | ||
| 3617 | if (fetch.nTimeFirstAsked == 0) | ||
| 3618 | { | ||
| 3619 | fetch.nTimeFirstAsked = GetTime(); | ||
| 3620 | // Who is answerable for this hash existing. Set | ||
| 3621 | // once, on creation: the failover sweep asks other | ||
| 3622 | // peers later, and none of them chose to announce | ||
| 3623 | // it, so none of them should be charged for it. | ||
| 3624 | fetch.addrAnnounced = pto->addr; | ||
| 3625 | } | ||
| 3626 | fetch.nTimeAsked = GetTime(); | ||
| 3627 | fetch.setAsked.insert(pto->addr); | ||
| 3628 | } | ||
| 3629 | } | ||
| 3630 | } | ||
| 3400 | pto->mapAskFor.erase(pto->mapAskFor.begin()); | 3631 | pto->mapAskFor.erase(pto->mapAskFor.begin()); |
| 3401 | } | 3632 | } |
| 3402 | if (!vAskFor.empty()) | 3633 | if (!vAskFor.empty()) |
| 3403 | pto->PushMessage("getdata", vAskFor); | 3634 | pto->PushMessage("getdata", vAskFor); |
| 3404 | 3635 | ||
| 3636 | |||
| 3637 | // | ||
| 3638 | // Message: getdata (block fetch failover) | ||
| 3639 | // | ||
| 3640 | // A requested block that has not arrived in BLOCK_FETCH_RETRY_SECS is | ||
| 3641 | // not still in transit -- a body is at most 1 MB and somebody | ||
| 3642 | // demonstrably has it -- so ask somebody else instead of waiting on | ||
| 3643 | // whoever was asked first (#33). Each peer the message handler visits | ||
| 3644 | // takes at most one turn per block per round; once every connected | ||
| 3645 | // peer has had its turn and a further interval passes with nobody | ||
| 3646 | // new to ask, the round restarts. A peer that declared itself a | ||
| 3647 | // client cannot serve block bodies and is no use as a target. | ||
| 3648 | if (!pto->fClient) | ||
| 3649 | { | ||
| 3650 | vector<CInv> vFailover; | ||
| 3651 | int64 nNowSecs = GetTime(); | ||
| 3652 | for (map<uint256, CBlockFetch>::iterator mi = mapBlockFetch.begin(); mi != mapBlockFetch.end();) | ||
| 3653 | { | ||
| 3654 | CBlockFetch& fetch = (*mi).second; | ||
| 3655 | CInv inv(MSG_BLOCK, (*mi).first); | ||
| 3656 | if (AlreadyHave(txdb, inv)) | ||
| 3657 | { | ||
| 3658 | // Arrived by some other road -- our own miner, an orphan | ||
| 3659 | // parked in mapOrphanBlocks. Nothing left to chase. | ||
| 3660 | mapBlockFetch.erase(mi++); | ||
| 3661 | continue; | ||
| 3662 | } | ||
| 3663 | if (nNowSecs - fetch.nTimeFirstAsked > BLOCK_FETCH_GIVEUP_SECS) | ||
| 3664 | { | ||
| 3665 | printf("block fetch: giving up on %s -- no peer served it in %d s\n", | ||
| 3666 | inv.ToString().c_str(), (int)(nNowSecs - fetch.nTimeFirstAsked)); | ||
| 3667 | mapBlockFetch.erase(mi++); | ||
| 3668 | continue; | ||
| 3669 | } | ||
| 3670 | if (nNowSecs - fetch.nTimeAsked >= BLOCK_FETCH_RETRY_SECS) | ||
| 3671 | { | ||
| 3672 | // The handler loop visits every peer within ~100ms, so a | ||
| 3673 | // request stale by two full intervals means nobody outside | ||
| 3674 | // setAsked was there to ask. Start the round over. | ||
| 3675 | if (nNowSecs - fetch.nTimeAsked >= 2 * BLOCK_FETCH_RETRY_SECS) | ||
| 3676 | fetch.setAsked.clear(); | ||
| 3677 | if (!fetch.setAsked.count(pto->addr)) | ||
| 3678 | { | ||
| 3679 | // Which block, how long, and which peer we are trying | ||
| 3680 | // next. Behind the category because it names a peer | ||
| 3681 | // and a peer decides how often it is written. | ||
| 3682 | if (LogAcceptsCategory("net")) | ||
| 3683 | printf("block fetch failover: %s unanswered for %d s, re-requesting from %s\n", | ||
| 3684 | inv.ToString().c_str(), (int)(nNowSecs - fetch.nTimeAsked), | ||
| 3685 | pto->addr.ToString().c_str()); | ||
| 3686 | |||
| 3687 | // The unconditional half: no addresses, and at most | ||
| 3688 | // one line per BLOCK_FETCH_REPORT_SECS however hard a | ||
| 3689 | // peer tries. See the counters for the reasoning. | ||
| 3690 | nBlockFetchFailovers++; | ||
| 3691 | if (nNowSecs - nBlockFetchWindowStart >= BLOCK_FETCH_REPORT_SECS) | ||
| 3692 | { | ||
| 3693 | printf("block fetch: %d block request%s went unanswered and %s been " | ||
| 3694 | "re-asked of other peers (%d tracked)\n", | ||
| 3695 | nBlockFetchFailovers, nBlockFetchFailovers == 1 ? "" : "s", | ||
| 3696 | nBlockFetchFailovers == 1 ? "has" : "have", | ||
| 3697 | (int)mapBlockFetch.size()); | ||
| 3698 | nBlockFetchWindowStart = nNowSecs; | ||
| 3699 | nBlockFetchFailovers = 0; | ||
| 3700 | } | ||
| 3701 | |||
| 3702 | vFailover.push_back(inv); | ||
| 3703 | fetch.nTimeAsked = nNowSecs; | ||
| 3704 | fetch.setAsked.insert(pto->addr); | ||
| 3705 | } | ||
| 3706 | } | ||
| 3707 | ++mi; | ||
| 3708 | } | ||
| 3709 | if (!vFailover.empty()) | ||
| 3710 | pto->PushMessage("getdata", vFailover); | ||
| 3711 | } | ||
| 3712 | |||
| 3405 | } | 3713 | } |
| 3406 | return true; | 3714 | return true; |
| 3407 | } | 3715 | } |
| @@ -3937,9 +4245,32 @@ connected: | |||
| 3937 | std::vector<ParticipantShareHit> shareHits; | 4245 | std::vector<ParticipantShareHit> shareHits; |
| 3938 | std::mutex shareHitsMtx; | 4246 | std::mutex shareHitsMtx; |
| 3939 | std::vector<std::thread> hashThreads; | 4247 | std::vector<std::thread> hashThreads; |
| 3940 | for (int i = 0; i < nWorkers; i++) | 4248 | try |
| 3941 | hashThreads.emplace_back(ParticipantHashWorker, &jobShared, i, nWorkers, | 4249 | { |
| 3942 | &shareHits, &shareHitsMtx); | 4250 | for (int i = 0; i < nWorkers; i++) |
| 4251 | hashThreads.emplace_back(ParticipantHashWorker, &jobShared, i, nWorkers, | ||
| 4252 | &shareHits, &shareHitsMtx); | ||
| 4253 | } | ||
| 4254 | catch (const std::system_error& e) | ||
| 4255 | { | ||
| 4256 | // A refused pthread_create used to reach std::terminate here and | ||
| 4257 | // kill the worker mid-session -- observed twice on an otherwise | ||
| 4258 | // healthy participant. Stop the workers that did start the same way | ||
| 4259 | // the disconnect path below does, drop this pool connection, and let | ||
| 4260 | // the caller's reconnect loop try again once the pressure clears. | ||
| 4261 | LogPrint("worker", "[worker] cannot spawn hash threads (%s)" | ||
| 4262 | " -- dropping pool connection\n", e.what()); | ||
| 4263 | SetParticipantMiningStatus("hash thread spawn failed"); | ||
| 4264 | { | ||
| 4265 | std::lock_guard<std::mutex> lk(jobShared.mtx); | ||
| 4266 | jobShared.stop = true; | ||
| 4267 | jobShared.haveJob = false; | ||
| 4268 | } | ||
| 4269 | for (std::thread& t : hashThreads) | ||
| 4270 | t.join(); | ||
| 4271 | closesocket(s); | ||
| 4272 | return false; | ||
| 4273 | } | ||
| 3943 | LogPrint("worker", "[worker] spawned %d hash threads on shared RandomX dataset\n", | 4274 | LogPrint("worker", "[worker] spawned %d hash threads on shared RandomX dataset\n", |
| 3944 | nWorkers); | 4275 | nWorkers); |
| 3945 | const uint64 sessionStartHashes = gParticipantHashes.load(); | 4276 | const uint64 sessionStartHashes = gParticipantHashes.load(); |
| @@ -3950,6 +4281,14 @@ connected: | |||
| 3950 | std::string jobId; | 4281 | std::string jobId; |
| 3951 | unsigned char header[80] = {}; | 4282 | unsigned char header[80] = {}; |
| 3952 | uint256 target; | 4283 | uint256 target; |
| 4284 | // Cached answer to "which block is this job built on", for the | ||
| 4285 | // mining.notify handler below -- see the comment there. Session-local, so | ||
| 4286 | // a reconnect re-resolves rather than trusting an answer obtained before | ||
| 4287 | // a possible change of pool. | ||
| 4288 | uint256 hashPrevResolved; // prevhash the cached answer describes | ||
| 4289 | bool fPrevResolved = false; // whether that answer exists yet | ||
| 4290 | int nPrevHeight = -1; // its height, or -1 == unknown to us | ||
| 4291 | int nBestHeightResolved = -1; // nBestHeight when we last resolved | ||
| 3953 | double currentDifficulty = 1.0; // updated by mining.set_difficulty from pool | 4292 | double currentDifficulty = 1.0; // updated by mining.set_difficulty from pool |
| 3954 | bool haveJob = false; | 4293 | bool haveJob = false; |
| 3955 | bool gotAnyJob = false; // any job at all this session -- the return value | 4294 | bool gotAnyJob = false; // any job at all this session -- the return value |
| @@ -4080,8 +4419,64 @@ connected: | |||
| 4080 | jobShared.jobSeq++; | 4419 | jobShared.jobSeq++; |
| 4081 | jobShared.haveJob = true; | 4420 | jobShared.haveJob = true; |
| 4082 | } | 4421 | } |
| 4083 | LogPrint("worker", "[pool->worker] new job %s received\n", | 4422 | // Log the chain position the pool is |
| 4084 | jobId.c_str()); | 4423 | // building on, so a stale or private |
| 4424 | // fork is auditable from worker logs. | ||
| 4425 | // The prevhash comes from the header we | ||
| 4426 | // actually hash (== p[2] of the notify); | ||
| 4427 | // a brief cs_main lookup is safe here -- | ||
| 4428 | // this thread holds no other lock. | ||
| 4429 | // | ||
| 4430 | // Resolving it is the expensive half, and | ||
| 4431 | // this is the socket-reading thread: block | ||
| 4432 | // validation can hold cs_main for a long | ||
| 4433 | // time, and every moment spent waiting on | ||
| 4434 | // it here is a moment set_difficulty and | ||
| 4435 | // share responses are not being handled. | ||
| 4436 | // Most notifies in a round are a new job | ||
| 4437 | // on the SAME tip, so the answer is cached | ||
| 4438 | // and re-resolved only when it could come | ||
| 4439 | // out differently: a prevhash we have not | ||
| 4440 | // resolved, or one we could NOT resolve | ||
| 4441 | // last time while the chain has since | ||
| 4442 | // moved (unknown -> known). A block's | ||
| 4443 | // height is fixed once mapBlockIndex knows | ||
| 4444 | // it, so a cached "known" never goes | ||
| 4445 | // stale. nBestHeight is read unlocked on | ||
| 4446 | // purpose -- it only decides whether to | ||
| 4447 | // repeat a lookup, never what gets | ||
| 4448 | // printed, so a stale read costs at most | ||
| 4449 | // one deferred or one extra lookup. | ||
| 4450 | // The line still prints in full for every | ||
| 4451 | // job, cached or not. | ||
| 4452 | uint256 hashPrev; | ||
| 4453 | memcpy(&hashPrev, header + 4, 32); | ||
| 4454 | if (LogAcceptsCategory("worker")) | ||
| 4455 | { | ||
| 4456 | int nBestHeightNow = nBestHeight; | ||
| 4457 | if (!fPrevResolved | ||
| 4458 | || hashPrev != hashPrevResolved | ||
| 4459 | || (nPrevHeight < 0 && nBestHeightNow != nBestHeightResolved)) | ||
| 4460 | { | ||
| 4461 | nPrevHeight = -1; | ||
| 4462 | CRITICAL_BLOCK(cs_main) | ||
| 4463 | { | ||
| 4464 | map<uint256, CBlockIndex*>::iterator mi = mapBlockIndex.find(hashPrev); | ||
| 4465 | if (mi != mapBlockIndex.end()) | ||
| 4466 | nPrevHeight = (*mi).second->nHeight; | ||
| 4467 | } | ||
| 4468 | hashPrevResolved = hashPrev; | ||
| 4469 | nBestHeightResolved = nBestHeightNow; | ||
| 4470 | fPrevResolved = true; | ||
| 4471 | } | ||
| 4472 | if (nPrevHeight >= 0) | ||
| 4473 | LogPrint("worker", "[pool->worker] new job %s received, prevhash %s (known, job height %d)\n", | ||
| 4474 | jobId.c_str(), hashPrev.GetHex().c_str(), | ||
| 4475 | nPrevHeight + 1); | ||
| 4476 | else | ||
| 4477 | LogPrint("worker", "[pool->worker] new job %s received, prevhash %s (unknown to our chain)\n", | ||
| 4478 | jobId.c_str(), hashPrev.GetHex().c_str()); | ||
| 4479 | } | ||
| 4085 | SetParticipantMiningStatus("hashing job " + jobId); | 4480 | SetParticipantMiningStatus("hashing job " + jobId); |
| 4086 | } | 4481 | } |
| 4087 | } | 4482 | } |
| @@ -4639,7 +5034,7 @@ bool BitcoinMiner(int nThreadId) | |||
| 4639 | //// debug print | 5034 | //// debug print |
| 4640 | if (LogAcceptsCategory("net")) printf("BitcoinMiner:\n"); | 5035 | if (LogAcceptsCategory("net")) printf("BitcoinMiner:\n"); |
| 4641 | if (LogAcceptsCategory("net")) printf("RandomX proof-of-work found \n powhash: %s \ntarget: %s\n", hash.GetHex().c_str(), hashTarget.GetHex().c_str()); | 5036 | if (LogAcceptsCategory("net")) printf("RandomX proof-of-work found \n powhash: %s \ntarget: %s\n", hash.GetHex().c_str(), hashTarget.GetHex().c_str()); |
| 4642 | if (LogAcceptsCategory("net")) pblock->print(); | 5037 | if (LogAcceptsCategory("relay")) pblock->print(); |
| 4643 | 5038 | ||
| 4644 | SetThreadPriority(GetCurrentThread(), THREAD_PRIORITY_NORMAL); | 5039 | SetThreadPriority(GetCurrentThread(), THREAD_PRIORITY_NORMAL); |
| 4645 | CRITICAL_BLOCK(cs_main) | 5040 | CRITICAL_BLOCK(cs_main) |
diff --git a/src/main_gui.cpp b/src/main_gui.cpp index 211e1e2..0e64985 100644 --- a/src/main_gui.cpp +++ b/src/main_gui.cpp | |||
| @@ -111,6 +111,8 @@ static void PrintUsage() | |||
| 111 | printf(" /help, -help, --help, /?\n"); | 111 | printf(" /help, -help, --help, /?\n"); |
| 112 | printf(" /datadir=PATH\n"); | 112 | printf(" /datadir=PATH\n"); |
| 113 | printf(" /debug\n"); | 113 | printf(" /debug\n"); |
| 114 | printf(" /debugrelay (/debug plus per-message relay chatter and block dumps)\n"); | ||
| 115 | printf(" /maxdebugfilesize=N (roll debug.log at N MB, default 1024; 0 = never)\n"); | ||
| 114 | printf(" /gen\n"); | 116 | printf(" /gen\n"); |
| 115 | printf(" /nogui or /daemon\n"); | 117 | printf(" /nogui or /daemon\n"); |
| 116 | printf(" /selftest=wallet-keypool, wallet-hd, wallet-format, wallet-crypto, wallet-encrypt,\n"); | 118 | printf(" /selftest=wallet-keypool, wallet-hd, wallet-format, wallet-crypto, wallet-encrypt,\n"); |
| @@ -191,6 +193,54 @@ static void ParseStartupArguments(int argc, char* argv[]) | |||
| 191 | if (arg(argc,argv,"/debug") || arg(argc,argv,"-debug")) | 193 | if (arg(argc,argv,"/debug") || arg(argc,argv,"-debug")) |
| 192 | fDebug = true; | 194 | fDebug = true; |
| 193 | 195 | ||
| 196 | // /debugrelay -- everything /debug shows, plus the per-message firehose | ||
| 197 | // ("relay" and "nostrdiscovery" categories: sending: tx, Relaying wtx, | ||
| 198 | // raw CBlock dumps, per-peer discovery lines). That traffic was ~90% of | ||
| 199 | // a 13-hour production debug.log (issue #35), so plain /debug leaves it | ||
| 200 | // off; the message text itself is unchanged for anyone grepping it. | ||
| 201 | if (arg(argc,argv,"/debugrelay") || arg(argc,argv,"-debugrelay")) | ||
| 202 | { | ||
| 203 | fDebug = true; | ||
| 204 | fDebugRelay = true; | ||
| 205 | } | ||
| 206 | |||
| 207 | // /maxdebugfilesize=N -- roll debug.log to debug.log.old once it passes | ||
| 208 | // N MB, checked on each write. Default is 1024 (see util.cpp); 0 turns | ||
| 209 | // the check off and leaves rotation entirely to logrotate. | ||
| 210 | string strMaxDebugSize = argval2(argc, argv, "/maxdebugfilesize", "-maxdebugfilesize"); | ||
| 211 | if (!strMaxDebugSize.empty()) | ||
| 212 | { | ||
| 213 | // Parsed with atoi64() before, which is strtoll() with the endptr | ||
| 214 | // thrown away: it returns 0 for anything it cannot read, so | ||
| 215 | // /maxdebugfilesize=1G and =1024MB both came out as 0 -- "never | ||
| 216 | // roll", identical to asking for that on purpose, with nothing said | ||
| 217 | // to the operator. The old code also multiplied without a range | ||
| 218 | // check, so a big enough N wrapped to a negative cap, which the roll | ||
| 219 | // reads as "off" too. Every rejection is now reported and leaves the | ||
| 220 | // default in place; the value is a plain count of MB, no suffix. | ||
| 221 | const char* psz = strMaxDebugSize.c_str(); | ||
| 222 | char* pszEnd = NULL; | ||
| 223 | errno = 0; | ||
| 224 | int64 nMB = strtoll(psz, &pszEnd, 10); | ||
| 225 | // INT64_MAX, without depending on which limits header this tree pulls in. | ||
| 226 | const int64 nMaxMB = (int64)((~(uint64)0) >> 1) / (1024 * 1024); | ||
| 227 | const char* pszWhy = NULL; | ||
| 228 | if (pszEnd == psz) | ||
| 229 | pszWhy = "not a number"; | ||
| 230 | else if (*pszEnd != '\0') | ||
| 231 | pszWhy = "trailing characters -- the value is a count of MB, with no unit suffix"; | ||
| 232 | else if (errno == ERANGE || nMB < 0) | ||
| 233 | pszWhy = "not a size in MB"; | ||
| 234 | else if (nMB > nMaxMB) | ||
| 235 | pszWhy = "larger than a file size can be"; | ||
| 236 | if (pszWhy) | ||
| 237 | fprintf(stderr, "Ignoring /maxdebugfilesize=%s: %s (keeping %lld MB)\n", | ||
| 238 | strMaxDebugSize.c_str(), pszWhy, | ||
| 239 | (long long)(nMaxDebugFileSize / 1024 / 1024)); | ||
| 240 | else | ||
| 241 | nMaxDebugFileSize = nMB * 1024 * 1024; | ||
| 242 | } | ||
| 243 | |||
| 194 | if (arg(argc,argv,"/gen") || arg(argc,argv,"-gen")) | 244 | if (arg(argc,argv,"/gen") || arg(argc,argv,"-gen")) |
| 195 | { | 245 | { |
| 196 | fGenerateBitcoins = 1; | 246 | fGenerateBitcoins = 1; |
diff --git a/src/net.cpp b/src/net.cpp index fed6123..16038c8 100644 --- a/src/net.cpp +++ b/src/net.cpp | |||
| @@ -2090,7 +2090,7 @@ bool StartNode(string& strError) | |||
| 2090 | if (addrIncoming.ip) | 2090 | if (addrIncoming.ip) |
| 2091 | addrLocalHost.ip = addrIncoming.ip; | 2091 | addrLocalHost.ip = addrIncoming.ip; |
| 2092 | 2092 | ||
| 2093 | _beginthread([](void*) { | 2093 | if (_beginthread([](void*) { |
| 2094 | unsigned int ip = addrLocalHost.ip; | 2094 | unsigned int ip = addrLocalHost.ip; |
| 2095 | if (GetMyExternalIP(ip)) { | 2095 | if (GetMyExternalIP(ip)) { |
| 2096 | addrLocalHost.ip = ip; | 2096 | addrLocalHost.ip = ip; |
| @@ -2098,7 +2098,8 @@ bool StartNode(string& strError) | |||
| 2098 | CWalletDB().WriteSetting("addrIncoming", addrIncoming); | 2098 | CWalletDB().WriteSetting("addrIncoming", addrIncoming); |
| 2099 | printf("External IP updated: %s\n", addrLocalHost.ToStringIP().c_str()); | 2099 | printf("External IP updated: %s\n", addrLocalHost.ToStringIP().c_str()); |
| 2100 | } | 2100 | } |
| 2101 | }, 0, NULL); | 2101 | }, 0, NULL) == (uintptr_t)-1) |
| 2102 | printf("Error: _beginthread(GetMyExternalIP) failed\n"); | ||
| 2102 | 2103 | ||
| 2103 | // Peers that answered last time, dialled straight away. The relays are the | 2104 | // Peers that answered last time, dialled straight away. The relays are the |
| 2104 | // only way to find anyone otherwise, and reaching them plus walking their | 2105 | // only way to find anyone otherwise, and reaching them plus walking their |
| @@ -23,6 +23,12 @@ enum | |||
| 23 | 23 | ||
| 24 | 24 | ||
| 25 | 25 | ||
| 26 | // Defined in main.cpp. True while this node is tracking the tip rather than | ||
| 27 | // still catching up, measured off the age of our own best block -- see there | ||
| 28 | // for why that and not a peer-reported height. Declared here because net.h is | ||
| 29 | // parsed before main.h and CNode::AskFor needs it. | ||
| 30 | bool IsBlockFetchNearTip(); | ||
| 31 | |||
| 26 | bool GetMyExternalIP(unsigned int& ipRet); | 32 | bool GetMyExternalIP(unsigned int& ipRet); |
| 27 | CNode* ConnectNodeBtf(const string& strBtfAddr); | 33 | CNode* ConnectNodeBtf(const string& strBtfAddr); |
| 28 | CNode* ConnectNodeBtfResolved(const string& strBtfAddr, const string& strMeeting, | 34 | CNode* ConnectNodeBtfResolved(const string& strBtfAddr, const string& strMeeting, |
| @@ -89,6 +95,15 @@ static const int BTF_RECV_TIMEOUT_SECS = 30 * 60; | |||
| 89 | static const int BTF_SEND_STALL_SECS = 10 * 60; | 95 | static const int BTF_SEND_STALL_SECS = 10 * 60; |
| 90 | static const int BTF_HANDSHAKE_GRACE_SECS = 60; | 96 | static const int BTF_HANDSHAKE_GRACE_SECS = 60; |
| 91 | 97 | ||
| 98 | // How long a requested block gets before it is asked for again, in seconds. | ||
| 99 | // Used twice: CNode::AskFor spaces the queued per-announcer block retries this | ||
| 100 | // far apart instead of the two minutes transactions get, and the failover | ||
| 101 | // sweep in main.cpp re-issues a getdata to a different peer once a sent | ||
| 102 | // request has gone unanswered this long. A block body is at most 1 MB and | ||
| 103 | // somebody demonstrably has it -- they announced it -- so on this timescale | ||
| 104 | // "not here yet" means "not coming from that peer", not "still in transit". | ||
| 105 | static const int BLOCK_FETCH_RETRY_SECS = 15; | ||
| 106 | |||
| 92 | // A serialized object cannot be larger than MAX_SIZE, so no valid network | 107 | // A serialized object cannot be larger than MAX_SIZE, so no valid network |
| 93 | // message needs the old 256 MB header allowance. Keep the wire cap aligned with | 108 | // message needs the old 256 MB header allowance. Keep the wire cap aligned with |
| 94 | // what the deserializer can accept. How long a peer may sit on a partial | 109 | // what the deserializer can accept. How long a peer may sit on a partial |
| @@ -795,13 +810,51 @@ public: | |||
| 795 | static int64 nLastTime; | 810 | static int64 nLastTime; |
| 796 | nLastTime = nNow = max(nNow, ++nLastTime); | 811 | nLastTime = nNow = max(nNow, ++nLastTime); |
| 797 | 812 | ||
| 798 | // Each retry is 2 minutes after the last | 813 | // Each retry is 2 minutes after the last -- and because nRequestTime |
| 799 | nRequestTime = max(nRequestTime + 2 * 60 * 1000000, nNow); | 814 | // is shared across peers, the same spacing is what strings requests |
| 815 | // for one inv across its announcers. For transactions that is pacing; | ||
| 816 | // for a new block it was the stall of issue #33: nine peers announce | ||
| 817 | // the block, the first one asked does not serve it, and the ninth | ||
| 818 | // candidate is not even asked until sixteen minutes in, with the pool | ||
| 819 | // mining on the stale tip the whole time. | ||
| 820 | // | ||
| 821 | // Blocks retry on the fetch timescale, but only while we are at the | ||
| 822 | // tip. That is where the stall costs something -- the pool keeps | ||
| 823 | // handing out jobs against a dead tip -- and it is also where the | ||
| 824 | // spacing is nearly free: one block is in flight, and its body has | ||
| 825 | // almost always arrived before the second announcer's turn comes | ||
| 826 | // round, so AlreadyHave drops the duplicate before a getdata is sent. | ||
| 827 | // | ||
| 828 | // While catching up neither half holds. A peer working through a | ||
| 829 | // 500-deep queue can be minutes away from block N without anything | ||
| 830 | // being wrong, so at 15s the second announcer is asked at +15s, the | ||
| 831 | // third at +30s, and the bulk download arrives once per announcer -- | ||
| 832 | // up to eight times over. Nothing caps that: the eight-entry cap is on | ||
| 833 | // mapBlockFetch, which is a different mechanism from this spacing. | ||
| 834 | // Two minutes is the right number there, and it is what this line did | ||
| 835 | // before. Failover at the tip does not depend on this being 15s in any | ||
| 836 | // case: mapBlockFetch re-issues a stalled getdata to the next peer on | ||
| 837 | // its own timer, which is what actually fixes #33. | ||
| 838 | bool fFast = (inv.type == MSG_BLOCK && IsBlockFetchNearTip()); | ||
| 839 | int64 nRetryUsecs = (fFast ? BLOCK_FETCH_RETRY_SECS : 2 * 60) * 1000000LL; | ||
| 840 | nRequestTime = max(nRequestTime + nRetryUsecs, nNow); | ||
| 800 | mapAskFor.insert(make_pair(nRequestTime, inv)); | 841 | mapAskFor.insert(make_pair(nRequestTime, inv)); |
| 801 | } | 842 | } |
| 802 | 843 | ||
| 803 | 844 | ||
| 804 | 845 | ||
| 846 | // "sending: tx (N bytes)" alone was ~71% of a 13-hour production | ||
| 847 | // debug.log (issue #35), so tx sends are demoted to the /debugrelay-gated | ||
| 848 | // "relay" category; every other command's send trace stays on "net". | ||
| 849 | // The line is emitted in pieces across BeginMessage/EndMessage/ | ||
| 850 | // AbortMessage, so all three must agree on the category or orphaned | ||
| 851 | // "(N bytes)" fragments would leak into a plain -debug log. | ||
| 852 | // Valid only mid-message (nPushPos != -1). | ||
| 853 | const char* SendLogCategory() const | ||
| 854 | { | ||
| 855 | return strcmp(GetMessageCommand(), "tx") == 0 ? "relay" : "net"; | ||
| 856 | } | ||
| 857 | |||
| 805 | void BeginMessage(const char* pszCommand) | 858 | void BeginMessage(const char* pszCommand) |
| 806 | { | 859 | { |
| 807 | EnterCriticalSection(&cs_vSend); | 860 | EnterCriticalSection(&cs_vSend); |
| @@ -809,17 +862,19 @@ public: | |||
| 809 | AbortMessage(); | 862 | AbortMessage(); |
| 810 | nPushPos = vSend.size(); | 863 | nPushPos = vSend.size(); |
| 811 | vSend << CMessageHeader(pszCommand, 0); | 864 | vSend << CMessageHeader(pszCommand, 0); |
| 812 | if (LogAcceptsCategory("net")) printf("sending: %-12s ", pszCommand); | 865 | if (LogAcceptsCategory(SendLogCategory())) printf("sending: %-12s ", pszCommand); |
| 813 | } | 866 | } |
| 814 | 867 | ||
| 815 | void AbortMessage() | 868 | void AbortMessage() |
| 816 | { | 869 | { |
| 817 | if (nPushPos == -1) | 870 | if (nPushPos == -1) |
| 818 | return; | 871 | return; |
| 872 | // Capture before nPushPos is cleared; GetMessageCommand() needs it. | ||
| 873 | const char* pszCategory = SendLogCategory(); | ||
| 819 | vSend.resize(nPushPos); | 874 | vSend.resize(nPushPos); |
| 820 | nPushPos = -1; | 875 | nPushPos = -1; |
| 821 | LeaveCriticalSection(&cs_vSend); | 876 | LeaveCriticalSection(&cs_vSend); |
| 822 | if (LogAcceptsCategory("net")) printf("(aborted)\n"); | 877 | if (LogAcceptsCategory(pszCategory)) printf("(aborted)\n"); |
| 823 | } | 878 | } |
| 824 | 879 | ||
| 825 | void EndMessage() | 880 | void EndMessage() |
| @@ -827,7 +882,11 @@ public: | |||
| 827 | extern int nDropMessagesTest; | 882 | extern int nDropMessagesTest; |
| 828 | if (nDropMessagesTest > 0 && GetRand(nDropMessagesTest) == 0) | 883 | if (nDropMessagesTest > 0 && GetRand(nDropMessagesTest) == 0) |
| 829 | { | 884 | { |
| 830 | if (LogAcceptsCategory("net")) printf("dropmessages DROPPING SEND MESSAGE\n"); | 885 | // Same category as the "sending: " this line interrupts, so a tx |
| 886 | // does not announce its own drop under "net" having been gated | ||
| 887 | // off under "relay". nPushPos can be -1 here, and then | ||
| 888 | // GetMessageCommand() returns "" and this is "net" as before. | ||
| 889 | if (LogAcceptsCategory(SendLogCategory())) printf("dropmessages DROPPING SEND MESSAGE\n"); | ||
| 831 | AbortMessage(); | 890 | AbortMessage(); |
| 832 | return; | 891 | return; |
| 833 | } | 892 | } |
| @@ -839,10 +898,10 @@ public: | |||
| 839 | unsigned int nSize = vSend.size() - nPushPos - sizeof(CMessageHeader); | 898 | unsigned int nSize = vSend.size() - nPushPos - sizeof(CMessageHeader); |
| 840 | memcpy((char*)&vSend[nPushPos] + offsetof(CMessageHeader, nMessageSize), &nSize, sizeof(nSize)); | 899 | memcpy((char*)&vSend[nPushPos] + offsetof(CMessageHeader, nMessageSize), &nSize, sizeof(nSize)); |
| 841 | 900 | ||
| 842 | if (LogAcceptsCategory("net")) printf("(%d bytes) ", nSize); | 901 | if (LogAcceptsCategory(SendLogCategory())) printf("(%d bytes) ", nSize); |
| 843 | //for (int i = nPushPos+sizeof(CMessageHeader); i < min(vSend.size(), nPushPos+sizeof(CMessageHeader)+20U); i++) | 902 | //for (int i = nPushPos+sizeof(CMessageHeader); i < min(vSend.size(), nPushPos+sizeof(CMessageHeader)+20U); i++) |
| 844 | // printf("%02x ", vSend[i] & 0xff); | 903 | // printf("%02x ", vSend[i] & 0xff); |
| 845 | if (LogAcceptsCategory("net")) printf("\n"); | 904 | if (LogAcceptsCategory(SendLogCategory())) printf("\n"); |
| 846 | 905 | ||
| 847 | nPushPos = -1; | 906 | nPushPos = -1; |
| 848 | LeaveCriticalSection(&cs_vSend); | 907 | LeaveCriticalSection(&cs_vSend); |
diff --git a/src/nostr.cpp b/src/nostr.cpp index e2d839c..f44dc08 100644 --- a/src/nostr.cpp +++ b/src/nostr.cpp | |||
| @@ -151,6 +151,19 @@ string BtfActiveRelay() | |||
| 151 | 151 | ||
| 152 | void BtfSetActiveRelay(const string& relay) | 152 | void BtfSetActiveRelay(const string& relay) |
| 153 | { | 153 | { |
| 154 | // With /rvrelay set, the descriptor must never name anything but the pin. | ||
| 155 | // No caller can reach here with another relay today -- both registration | ||
| 156 | // paths draw their list from BtfAllRelays(), which returns the pin alone -- | ||
| 157 | // but the descriptor is the one thing a miner obeys, so the invariant is | ||
| 158 | // enforced at the sink instead of being retrusted to every future caller. | ||
| 159 | if (fBtfRelayPinned && | ||
| 160 | find(vBtfMeetingRelays.begin(), vBtfMeetingRelays.end(), relay) == vBtfMeetingRelays.end()) | ||
| 161 | { | ||
| 162 | LogPrint("pool", "refusing to advertise meeting relay %s: /rvrelay pins %s\n", | ||
| 163 | relay.c_str(), | ||
| 164 | vBtfMeetingRelays.empty() ? "an empty list" : vBtfMeetingRelays[0].c_str()); | ||
| 165 | return; | ||
| 166 | } | ||
| 154 | CRITICAL_BLOCK(cs_activeRelay) | 167 | CRITICAL_BLOCK(cs_activeRelay) |
| 155 | strBtfActiveRelay = relay; | 168 | strBtfActiveRelay = relay; |
| 156 | } | 169 | } |
| @@ -223,6 +236,18 @@ vector<string> BtfAllRelays() | |||
| 223 | return all; | 236 | return all; |
| 224 | } | 237 | } |
| 225 | 238 | ||
| 239 | // Relays learned from Nostr, whether or not a pin is in force. Reporting only: | ||
| 240 | // it exists so the pool can name what /rvrelay is excluding. Anything choosing | ||
| 241 | // a relay to register or dial at must keep using BtfAllRelays(). | ||
| 242 | vector<string> BtfDiscoveredRelays() | ||
| 243 | { | ||
| 244 | vector<string> out; | ||
| 245 | CRITICAL_BLOCK(cs_discoveredRelays) | ||
| 246 | foreach(const string& r, g_discoveredRelays) | ||
| 247 | out.push_back(r); | ||
| 248 | return out; | ||
| 249 | } | ||
| 250 | |||
| 226 | 251 | ||
| 227 | // | 252 | // |
| 228 | // Utilities | 253 | // Utilities |
| @@ -1440,7 +1465,7 @@ static bool SeedFromRelay(CNostrKey& key, const string& relay) | |||
| 1440 | else if (createdAt > it->second) it->second = createdAt; // refresh | 1465 | else if (createdAt > it->second) it->second = createdAt; // refresh |
| 1441 | } | 1466 | } |
| 1442 | if (fNew && fDebug) | 1467 | if (fNew && fDebug) |
| 1443 | LogPrint("nostr", "Nostr: discovered .btf peer %s\n", peerAddr.c_str()); | 1468 | LogPrint("nostrdiscovery", "Nostr: discovered .btf peer %s\n", peerAddr.c_str()); |
| 1444 | if (++nPeers > 500) break; | 1469 | if (++nPeers > 500) break; |
| 1445 | } | 1470 | } |
| 1446 | else if (type == "EOSE") | 1471 | else if (type == "EOSE") |
diff --git a/src/nostr.h b/src/nostr.h index 6dbbe26..0dd919d 100644 --- a/src/nostr.h +++ b/src/nostr.h | |||
| @@ -60,6 +60,9 @@ extern bool fBtfRelayPinned; | |||
| 60 | bool LooksLikeRelay(const std::string& r); | 60 | bool LooksLikeRelay(const std::string& r); |
| 61 | // Every relay to try: curated seeds + relays discovered from Nostr announcements. | 61 | // Every relay to try: curated seeds + relays discovered from Nostr announcements. |
| 62 | std::vector<std::string> BtfAllRelays(); | 62 | std::vector<std::string> BtfAllRelays(); |
| 63 | // Relays discovered from Nostr, ignoring the pin. For reporting what a pin | ||
| 64 | // excludes -- never for choosing a relay to register or dial at. | ||
| 65 | std::vector<std::string> BtfDiscoveredRelays(); | ||
| 63 | 66 | ||
| 64 | struct BtfPoolAnnouncement | 67 | struct BtfPoolAnnouncement |
| 65 | { | 68 | { |
diff --git a/src/randomx_pow.cpp b/src/randomx_pow.cpp index 1d058d4..9c59364 100644 --- a/src/randomx_pow.cpp +++ b/src/randomx_pow.cpp | |||
| @@ -8,6 +8,7 @@ | |||
| 8 | #include <thread> | 8 | #include <thread> |
| 9 | #include <vector> | 9 | #include <vector> |
| 10 | #include <mutex> | 10 | #include <mutex> |
| 11 | #include <system_error> | ||
| 11 | 12 | ||
| 12 | // Fixed key (seed) that determines the RandomX cache/dataset. Keeping it | 13 | // Fixed key (seed) that determines the RandomX cache/dataset. Keeping it |
| 13 | // constant avoids per-epoch "reseed" logic; for the CPU+RAM fairness goal | 14 | // constant avoids per-epoch "reseed" logic; for the CPU+RAM fairness goal |
| @@ -101,13 +102,28 @@ bool RandomXInitDataset(int nThreads) | |||
| 101 | 102 | ||
| 102 | std::vector<std::thread> workers; | 103 | std::vector<std::thread> workers; |
| 103 | unsigned long per = total / nThreads; | 104 | unsigned long per = total / nThreads; |
| 104 | for (int i = 0; i < nThreads; i++) | 105 | try |
| 105 | { | 106 | { |
| 106 | unsigned long start = i * per; | 107 | for (int i = 0; i < nThreads; i++) |
| 107 | unsigned long count = (i == nThreads - 1) ? (total - start) : per; | 108 | { |
| 108 | workers.emplace_back([start, count]() { | 109 | unsigned long start = i * per; |
| 109 | randomx_init_dataset(g_dataset, g_cache, start, count); | 110 | unsigned long count = (i == nThreads - 1) ? (total - start) : per; |
| 110 | }); | 111 | workers.emplace_back([start, count]() { |
| 112 | randomx_init_dataset(g_dataset, g_cache, start, count); | ||
| 113 | }); | ||
| 114 | } | ||
| 115 | } | ||
| 116 | catch (const std::system_error& e) | ||
| 117 | { | ||
| 118 | // Same refusal as the allocation failure above: light mode is slow | ||
| 119 | // but alive, std::terminate is neither. Join the workers that did | ||
| 120 | // start before releasing the dataset out from under them. | ||
| 121 | for (auto& w : workers) w.join(); | ||
| 122 | randomx_release_dataset(g_dataset); | ||
| 123 | g_dataset = NULL; | ||
| 124 | printf("RandomX: cannot spawn dataset init threads (%s), staying in light mode\n", | ||
| 125 | e.what()); | ||
| 126 | return false; | ||
| 111 | } | 127 | } |
| 112 | for (auto& w : workers) w.join(); | 128 | for (auto& w : workers) w.join(); |
| 113 | 129 | ||
diff --git a/src/readme.txt b/src/readme.txt index 752be66..7490a9a 100644 --- a/src/readme.txt +++ b/src/readme.txt | |||
| @@ -16,7 +16,7 @@ This product includes software developed by the OpenSSL Project. | |||
| 16 | Differences from the original Bitcoin | 16 | Differences from the original Bitcoin |
| 17 | ------------------------------------- | 17 | ------------------------------------- |
| 18 | - Own genesis block (22/Jul/2026 headline, independent chain) | 18 | - Own genesis block (22/Jul/2026 headline, independent chain) |
| 19 | - Own magic bytes (0xbf 0x1a 0x5c 0xfd) and P2P port 8433 | 19 | - Own magic bytes (0xbf 0x20 0x5c 0xfd) and P2P port 8433 |
| 20 | - Addresses start with "B" (ADDRESSVERSION = 25) | 20 | - Addresses start with "B" (ADDRESSVERSION = 25) |
| 21 | - Consensus fixes applied: value overflow (CVE-2010-5139), duplicate inputs, | 21 | - Consensus fixes applied: value overflow (CVE-2010-5139), duplicate inputs, |
| 22 | money range checks (MoneyRange) | 22 | money range checks (MoneyRange) |
diff --git a/src/rpc.cpp b/src/rpc.cpp index a4b53ca..bd5fd8b 100644 --- a/src/rpc.cpp +++ b/src/rpc.cpp | |||
| @@ -1732,7 +1732,9 @@ static void FlushMaturePayouts() | |||
| 1732 | } | 1732 | } |
| 1733 | int64 total = 0; | 1733 | int64 total = 0; |
| 1734 | for (auto& kv : it->amounts) total += kv.second; | 1734 | for (auto& kv : it->amounts) total += kv.second; |
| 1735 | LogPrint("payout", "[payout] block %d (%s) was orphaned -- voiding %zu" | 1735 | // Always: one line per voided entry, never a collapsed summary. |
| 1736 | // A reorg voids these in a burst from this one source line. | ||
| 1737 | LogPrintAlways("payout", "[payout] block %d (%s) was orphaned -- voiding %zu" | ||
| 1736 | " payment(s) totalling %s\n", | 1738 | " payment(s) totalling %s\n", |
| 1737 | it->blockHeight, it->blockHash.ToString().substr(0, 14).c_str(), | 1739 | it->blockHeight, it->blockHash.ToString().substr(0, 14).c_str(), |
| 1738 | it->amounts.size(), FormatMoney(total).c_str()); | 1740 | it->amounts.size(), FormatMoney(total).c_str()); |
| @@ -1931,7 +1933,7 @@ static void RecordPayoutTxid(const PayingRecord& r, const std::string& txid) | |||
| 1931 | // disagreeing. | 1933 | // disagreeing. |
| 1932 | static void ForfeitPayoutRecipient(const PayingRecord& r, const std::string& reason) | 1934 | static void ForfeitPayoutRecipient(const PayingRecord& r, const std::string& reason) |
| 1933 | { | 1935 | { |
| 1934 | LogPrint("payout", "[payout] writing off %s owed to %s for block %d: %s\n", | 1936 | LogPrintAlways("payout", "[payout] writing off %s owed to %s for block %d: %s\n", |
| 1935 | FormatMoney(r.amount).c_str(), r.address.c_str(), r.blockHeight, | 1937 | FormatMoney(r.amount).c_str(), r.address.c_str(), r.blockHeight, |
| 1936 | reason.c_str()); | 1938 | reason.c_str()); |
| 1937 | VersionedBlob blob; | 1939 | VersionedBlob blob; |
| @@ -2036,7 +2038,7 @@ static void PayoutThreadFn(void*) | |||
| 2036 | // funding block can land at any point in that window. Upstream has | 2038 | // funding block can land at any point in that window. Upstream has |
| 2037 | // no equivalent -- it decides once, when the entry matures. | 2039 | // no equivalent -- it decides once, when the entry matures. |
| 2038 | if (!PayoutBlockStillOnChain(r.blockHash)) { | 2040 | if (!PayoutBlockStillOnChain(r.blockHash)) { |
| 2039 | LogPrint("payout", "[payout] block %d (%s) orphaned while queued" | 2041 | LogPrintAlways("payout", "[payout] block %d (%s) orphaned while queued" |
| 2040 | " -- dropping %s to %s\n", | 2042 | " -- dropping %s to %s\n", |
| 2041 | r.blockHeight, r.blockHash.ToString().substr(0, 14).c_str(), | 2043 | r.blockHeight, r.blockHash.ToString().substr(0, 14).c_str(), |
| 2042 | FormatMoney(r.amount).c_str(), r.address.c_str()); | 2044 | FormatMoney(r.amount).c_str(), r.address.c_str()); |
| @@ -2080,7 +2082,7 @@ static void PayoutThreadFn(void*) | |||
| 2080 | const std::string reason = | 2082 | const std::string reason = |
| 2081 | strprintf("'%s' is not a valid address, so no transaction" | 2083 | strprintf("'%s' is not a valid address, so no transaction" |
| 2082 | " can pay it", r.address.c_str()); | 2084 | " can pay it", r.address.c_str()); |
| 2083 | LogPrint("payout", "[payout] SKIPPED bad address '%s' --" | 2085 | LogPrintAlways("payout", "[payout] SKIPPED bad address '%s' --" |
| 2084 | " %s owed for block %d cannot be paid\n", | 2086 | " %s owed for block %d cannot be paid\n", |
| 2085 | r.address.c_str(), FormatMoney(r.amount).c_str(), | 2087 | r.address.c_str(), FormatMoney(r.amount).c_str(), |
| 2086 | r.blockHeight); | 2088 | r.blockHeight); |
| @@ -2205,7 +2207,7 @@ static void PayoutThreadFn(void*) | |||
| 2205 | // described by at least one of them at every instant. | 2207 | // described by at least one of them at every instant. |
| 2206 | RecordPayoutTxid(r, wtx.GetHash().GetHex()); | 2208 | RecordPayoutTxid(r, wtx.GetHash().GetHex()); |
| 2207 | ForgetPayment(r); | 2209 | ForgetPayment(r); |
| 2208 | LogPrint("payout", "[payout] paid %s to %s (tx %s)\n", | 2210 | LogPrintAlways("payout", "[payout] paid %s to %s (tx %s)\n", |
| 2209 | FormatMoney(r.amount).c_str(), r.address.c_str(), | 2211 | FormatMoney(r.amount).c_str(), r.address.c_str(), |
| 2210 | wtx.GetHash().ToString().substr(0, 12).c_str()); | 2212 | wtx.GetHash().ToString().substr(0, 12).c_str()); |
| 2211 | } else { | 2213 | } else { |
| @@ -2263,7 +2265,7 @@ static void PayoutThreadFn(void*) | |||
| 2263 | // going away must not turn the log into one line a minute | 2265 | // going away must not turn the log into one line a minute |
| 2264 | // forever, and must not go quiet either. | 2266 | // forever, and must not go quiet either. |
| 2265 | if (r.retries <= 5 || r.retries % 60 == 0) | 2267 | if (r.retries <= 5 || r.retries % 60 == 0) |
| 2266 | LogPrint("payout", "[payout] FAILED to pay %s to %s" | 2268 | LogPrintAlways("payout", "[payout] FAILED to pay %s to %s" |
| 2267 | " (%s spendable, wallet unlocked, block %d on" | 2269 | " (%s spendable, wallet unlocked, block %d on" |
| 2268 | " the main chain) -- attempt %d, retrying in" | 2270 | " the main chain) -- attempt %d, retrying in" |
| 2269 | " 60s; this debt stands until it is paid\n", | 2271 | " 60s; this debt stands until it is paid\n", |
| @@ -4947,13 +4949,19 @@ static void AcceptOneFn(void* arg) | |||
| 4947 | std::string host = relay.substr(0, colon); | 4949 | std::string host = relay.substr(0, colon); |
| 4948 | int port = atoi(relay.substr(colon + 1).c_str()); | 4950 | int port = atoi(relay.substr(colon + 1).c_str()); |
| 4949 | 4951 | ||
| 4950 | LogPrint("pool", "[pool] accept thread started for relay %s\n", relay.c_str()); | 4952 | LogPrint("pool", "[pool] accept thread started for relay %s%s\n", relay.c_str(), |
| 4953 | fBtfRelayPinned ? " (/rvrelay pin)" : ""); | ||
| 4954 | |||
| 4955 | // Registration health for this relay. A pin has no fallback, so a pin that | ||
| 4956 | // never registers means the pool is simply unreachable -- and that has to | ||
| 4957 | // be loud. The 2026-07-30 incident went unnoticed because this loop logged | ||
| 4958 | // failures at one flat line and success not at all, so "which relay is this | ||
| 4959 | // pool actually registered at" could not be answered from the log. | ||
| 4960 | int nConsecFail = 0; | ||
| 4961 | int64 nFirstFail = 0; | ||
| 4962 | bool fEverRegistered = false; | ||
| 4951 | 4963 | ||
| 4952 | while (!fShutdown && gPoolRunning) { | 4964 | while (!fShutdown && gPoolRunning) { |
| 4953 | // Advertise this relay as the pool's meeting node BEFORE registering, | ||
| 4954 | // so that miners which resolve our descriptor find a relay where the | ||
| 4955 | // pool (not the node's peer-accept) holds the registration. | ||
| 4956 | BtfSetActiveRelay(relay); | ||
| 4957 | // Returns as soon as the relay lists us -- registered, not yet paired. | 4965 | // Returns as soon as the relay lists us -- registered, not yet paired. |
| 4958 | btf::RvSocket rv = btf::RvServiceRegister(host.c_str(), (unsigned short)port, pk); | 4966 | btf::RvSocket rv = btf::RvServiceRegister(host.c_str(), (unsigned short)port, pk); |
| 4959 | 4967 | ||
| @@ -4962,12 +4970,36 @@ static void AcceptOneFn(void* arg) | |||
| 4962 | break; | 4970 | break; |
| 4963 | } | 4971 | } |
| 4964 | if (rv == btf::RV_INVALID) { | 4972 | if (rv == btf::RV_INVALID) { |
| 4965 | LogPrint("pool", "[pool] relay %s: RvServiceRegister failed" | 4973 | nConsecFail++; |
| 4966 | " -- backing off 30s before retry\n", relay.c_str()); | 4974 | if (nFirstFail == 0) nFirstFail = GetTime(); |
| 4975 | LogPrint("pool", "[pool] relay %s: registration failed (attempt %d," | ||
| 4976 | " failing for %llds) -- backing off 30s before retry\n", | ||
| 4977 | relay.c_str(), nConsecFail, (long long)(GetTime() - nFirstFail)); | ||
| 4978 | if (fBtfRelayPinned && (nConsecFail == 3 || nConsecFail % 10 == 0)) | ||
| 4979 | LogPrint("pool", "[pool] WARNING: pinned relay %s refused registration" | ||
| 4980 | " %d times running (%llds); /rvrelay leaves no fallback, so" | ||
| 4981 | " miners cannot reach this pool%s\n", | ||
| 4982 | relay.c_str(), nConsecFail, (long long)(GetTime() - nFirstFail), | ||
| 4983 | fEverRegistered ? "" : " -- it has never registered once"); | ||
| 4967 | for (int i = 0; i < 30 && !fShutdown && gPoolRunning; i++) Sleep(1000); | 4984 | for (int i = 0; i < 30 && !fShutdown && gPoolRunning; i++) Sleep(1000); |
| 4968 | continue; | 4985 | continue; |
| 4969 | } | 4986 | } |
| 4970 | 4987 | ||
| 4988 | // Advertise THIS relay only now. Setting it before the call published a | ||
| 4989 | // meeting node we were not yet listed at, so a miner resolving the | ||
| 4990 | // descriptor inside that window burned its dial on a relay holding no | ||
| 4991 | // registration for us. net.cpp's peer-accept has always ordered it this | ||
| 4992 | // way round; the pool had not. | ||
| 4993 | BtfSetActiveRelay(relay); | ||
| 4994 | if (!fEverRegistered || nConsecFail > 0) | ||
| 4995 | LogPrint("pool", "[pool] registered at relay %s%s%s -- advertising it as" | ||
| 4996 | " the pool's meeting node\n", relay.c_str(), | ||
| 4997 | fBtfRelayPinned ? " (/rvrelay pin)" : "", | ||
| 4998 | nConsecFail > 0 ? ", recovered" : ""); | ||
| 4999 | fEverRegistered = true; | ||
| 5000 | nConsecFail = 0; | ||
| 5001 | nFirstFail = 0; | ||
| 5002 | |||
| 4971 | // Block for a miner to actually arrive. RvServiceRegister used to do | 5003 | // Block for a miner to actually arrive. RvServiceRegister used to do |
| 4972 | // this itself and returned with the relay's 0x01 pairing byte already | 5004 | // this itself and returned with the relay's 0x01 pairing byte already |
| 4973 | // consumed; it no longer does. Without waiting here, BtfServiceWrap | 5005 | // consumed; it no longer does. Without waiting here, BtfServiceWrap |
| @@ -5022,9 +5054,21 @@ static void AcceptLoopFn(void*) | |||
| 5022 | LogPrint("pool", "[pool] .btf identity ready after %ds\n", waitSecs * 2); | 5054 | LogPrint("pool", "[pool] .btf identity ready after %ds\n", waitSecs * 2); |
| 5023 | 5055 | ||
| 5024 | std::set<std::string> spawned; // relays we've already started a thread for | 5056 | std::set<std::string> spawned; // relays we've already started a thread for |
| 5057 | std::set<std::string> skipped; // discovered relays the pin excluded, logged once each | ||
| 5025 | 5058 | ||
| 5026 | while (!fShutdown && gPoolRunning) { | 5059 | while (!fShutdown && gPoolRunning) { |
| 5060 | // BtfAllRelays() already honours the pin: with /rvrelay set it returns | ||
| 5061 | // vBtfMeetingRelays alone, so no thread is ever spawned for a | ||
| 5062 | // discovered relay. Name the ones it drops -- a pool registering at a | ||
| 5063 | // stranger's relay is exactly the thing that should not be silent. | ||
| 5027 | vector<string> relays = BtfAllRelays(); | 5064 | vector<string> relays = BtfAllRelays(); |
| 5065 | if (fBtfRelayPinned) { | ||
| 5066 | for (const string& r : BtfDiscoveredRelays()) | ||
| 5067 | if (std::find(relays.begin(), relays.end(), r) == relays.end() && | ||
| 5068 | skipped.insert(r).second) | ||
| 5069 | LogPrint("pool", "[pool] not registering at discovered relay %s" | ||
| 5070 | " -- /rvrelay pins the relay list\n", r.c_str()); | ||
| 5071 | } | ||
| 5028 | if (relays.empty()) { | 5072 | if (relays.empty()) { |
| 5029 | LogPrint("pool", "[pool] no relays available -- miners cannot connect yet\n"); | 5073 | LogPrint("pool", "[pool] no relays available -- miners cannot connect yet\n"); |
| 5030 | } else { | 5074 | } else { |
| @@ -5040,8 +5084,9 @@ static void AcceptLoopFn(void*) | |||
| 5040 | relay.c_str()); | 5084 | relay.c_str()); |
| 5041 | } else { | 5085 | } else { |
| 5042 | spawned.insert(relay); | 5086 | spawned.insert(relay); |
| 5043 | LogPrint("pool", "[pool] accept thread spawned for relay %s" | 5087 | LogPrint("pool", "[pool] accept thread spawned for relay %s%s" |
| 5044 | " (%zu total)\n", relay.c_str(), spawned.size()); | 5088 | " (%zu total)\n", relay.c_str(), |
| 5089 | fBtfRelayPinned ? " (/rvrelay pin)" : "", spawned.size()); | ||
| 5045 | } | 5090 | } |
| 5046 | } | 5091 | } |
| 5047 | } | 5092 | } |
| @@ -5077,10 +5122,17 @@ void ThreadRPCServer(void*) | |||
| 5077 | // armed for its one wallet probe before it is allowed to send. | 5122 | // armed for its one wallet probe before it is allowed to send. |
| 5078 | ReconcilePayouts(); | 5123 | ReconcilePayouts(); |
| 5079 | 5124 | ||
| 5080 | _beginthread(AcceptLoopFn, 0, NULL); | 5125 | // _beginthread cannot throw (it reports -1), but an unchecked failure |
| 5081 | _beginthread(LocalAcceptFn, 0, NULL); | 5126 | // leaves the pool running deaf: nobody accepts, announces, or pays, and |
| 5082 | _beginthread(ThreadBtfPoolAnnouncer, 0, NULL); | 5127 | // nothing in the log says why. |
| 5083 | _beginthread(PayoutThreadFn, 0, NULL); | 5128 | if (_beginthread(AcceptLoopFn, 0, NULL) == (uintptr_t)-1) |
| 5129 | LogPrint("pool", "[pool] FATAL: accept loop thread failed to spawn -- miners cannot connect\n"); | ||
| 5130 | if (_beginthread(LocalAcceptFn, 0, NULL) == (uintptr_t)-1) | ||
| 5131 | LogPrint("pool", "[pool] local accept thread failed to spawn\n"); | ||
| 5132 | if (_beginthread(ThreadBtfPoolAnnouncer, 0, NULL) == (uintptr_t)-1) | ||
| 5133 | LogPrint("pool", "[pool] announcer thread failed to spawn -- pool will not be advertised\n"); | ||
| 5134 | if (_beginthread(PayoutThreadFn, 0, NULL) == (uintptr_t)-1) | ||
| 5135 | LogPrint("pool", "[pool] FATAL: payout thread failed to spawn -- no one gets paid\n"); | ||
| 5084 | 5136 | ||
| 5085 | PoolEventLoop(); // blocks until gPoolRunning = false or fShutdown | 5137 | PoolEventLoop(); // blocks until gPoolRunning = false or fShutdown |
| 5086 | 5138 | ||
diff --git a/src/util.cpp b/src/util.cpp index 0cd0133..ab29178 100644 --- a/src/util.cpp +++ b/src/util.cpp | |||
| @@ -7,6 +7,12 @@ | |||
| 7 | 7 | ||
| 8 | 8 | ||
| 9 | bool fDebug = false; | 9 | bool fDebug = false; |
| 10 | bool fDebugRelay = false; | ||
| 11 | |||
| 12 | // In-process cap for debug.log, in bytes. Default matches the 1G trigger of | ||
| 13 | // the shipped logrotate policy so a long-running node stays bounded even | ||
| 14 | // without it; -maxdebugfilesize=N (MB) tunes it, 0 disables. | ||
| 15 | int64 nMaxDebugFileSize = 1024 * 1024 * (int64)1024; | ||
| 10 | 16 | ||
| 11 | // --------------------------------------------------------------------------- | 17 | // --------------------------------------------------------------------------- |
| 12 | // Categorized, burst-collapsing logging -- see the LogPrint doc comment in | 18 | // Categorized, burst-collapsing logging -- see the LogPrint doc comment in |
| @@ -26,10 +32,22 @@ static bool LogCategoryDefaultOn(const char* category) | |||
| 26 | strcmp(category, "payout") == 0; | 32 | strcmp(category, "payout") == 0; |
| 27 | } | 33 | } |
| 28 | 34 | ||
| 35 | // Categories so noisy they drown out everything else even under -debug: | ||
| 36 | // per-message send traces, wallet relay rebroadcasts, raw CBlock dumps and | ||
| 37 | // per-address discovery lines made up ~90% of a 13-hour production capture | ||
| 38 | // (issue #35). They need /debugrelay, not merely /debug. | ||
| 39 | static bool LogCategoryVerboseOnly(const char* category) | ||
| 40 | { | ||
| 41 | return strcmp(category, "relay") == 0 || | ||
| 42 | strcmp(category, "nostrdiscovery") == 0; | ||
| 43 | } | ||
| 44 | |||
| 29 | bool LogAcceptsCategory(const char* category) | 45 | bool LogAcceptsCategory(const char* category) |
| 30 | { | 46 | { |
| 31 | if (LogCategoryDefaultOn(category)) | 47 | if (LogCategoryDefaultOn(category)) |
| 32 | return true; | 48 | return true; |
| 49 | if (LogCategoryVerboseOnly(category)) | ||
| 50 | return fDebugRelay; | ||
| 33 | return fDebug; | 51 | return fDebug; |
| 34 | } | 52 | } |
| 35 | 53 | ||
| @@ -47,6 +65,61 @@ struct LogDedupState { | |||
| 47 | static std::map<std::string, LogDedupState> g_logDedup; | 65 | static std::map<std::string, LogDedupState> g_logDedup; |
| 48 | static CCriticalSection cs_logDedup; | 66 | static CCriticalSection cs_logDedup; |
| 49 | 67 | ||
| 68 | // A pending "(N similar)" summary, lifted out of the table while the lock is | ||
| 69 | // held and written after it is released. | ||
| 70 | struct LogDedupFlush { | ||
| 71 | std::string category; | ||
| 72 | int suppressed; | ||
| 73 | int64 elapsed; // how long the window that counted them ran | ||
| 74 | std::string lastMsg; | ||
| 75 | }; | ||
| 76 | |||
| 77 | static int64 g_logDedupLastSweep = 0; | ||
| 78 | |||
| 79 | static void EmitDedupSummary(const LogDedupFlush& f) | ||
| 80 | { | ||
| 81 | OutputDebugStringF("[%s] (%d similar in %llds, last: %s)\n", | ||
| 82 | f.category.c_str(), f.suppressed, | ||
| 83 | (long long)f.elapsed, f.lastMsg.c_str()); | ||
| 84 | } | ||
| 85 | |||
| 86 | // A window is otherwise only closed out when its own call site fires again, so | ||
| 87 | // a burst that simply stops -- 100 ledger entries voided in one pass and then | ||
| 88 | // silence -- leaves its count sitting in the table and the summary is never | ||
| 89 | // written at all. That is how 99 of 100 voids went unreported, with no "(N | ||
| 90 | // similar)" line to say anything was missing (issue #3). Sweep every expired | ||
| 91 | // window instead, so a finished burst is summarised as soon as anything at all | ||
| 92 | // is logged. | ||
| 93 | // | ||
| 94 | // Expired entries are erased rather than reopened: the window is over, so there | ||
| 95 | // is no state left worth keeping, and the next call from that site then takes | ||
| 96 | // the "first time" path and prints directly -- exactly what the rollover branch | ||
| 97 | // below would have done. It also stops the table growing without bound. | ||
| 98 | // | ||
| 99 | // Caller holds cs_logDedup; the summaries are written after it is released. | ||
| 100 | static void SweepExpiredWindowsLocked(int64 now, std::vector<LogDedupFlush>& out) | ||
| 101 | { | ||
| 102 | for (std::map<std::string, LogDedupState>::iterator it = g_logDedup.begin(); | ||
| 103 | it != g_logDedup.end(); ) | ||
| 104 | { | ||
| 105 | if (now - it->second.windowStart < DEDUP_WINDOW_SECS) | ||
| 106 | { | ||
| 107 | ++it; | ||
| 108 | continue; | ||
| 109 | } | ||
| 110 | if (it->second.suppressed > 0) | ||
| 111 | { | ||
| 112 | LogDedupFlush f; | ||
| 113 | f.category = it->first.substr(0, it->first.find('|')); | ||
| 114 | f.suppressed = it->second.suppressed; | ||
| 115 | f.elapsed = now - it->second.windowStart; | ||
| 116 | f.lastMsg = it->second.lastMsg; | ||
| 117 | out.push_back(f); | ||
| 118 | } | ||
| 119 | g_logDedup.erase(it++); | ||
| 120 | } | ||
| 121 | } | ||
| 122 | |||
| 50 | void LogPrintDedup(const char* category, const char* file, int line, const std::string& msgIn) | 123 | void LogPrintDedup(const char* category, const char* file, int line, const std::string& msgIn) |
| 51 | { | 124 | { |
| 52 | // Call sites follow the existing printf() convention of ending their | 125 | // Call sites follow the existing printf() convention of ending their |
| @@ -61,11 +134,19 @@ void LogPrintDedup(const char* category, const char* file, int line, const std:: | |||
| 61 | 134 | ||
| 62 | int64 now = GetTime(); | 135 | int64 now = GetTime(); |
| 63 | bool fEmitNow = false; | 136 | bool fEmitNow = false; |
| 64 | int suppressedToFlush = 0; | 137 | std::vector<LogDedupFlush> flushes; |
| 65 | std::string flushedMsg; | ||
| 66 | 138 | ||
| 67 | CRITICAL_BLOCK(cs_logDedup) | 139 | CRITICAL_BLOCK(cs_logDedup) |
| 68 | { | 140 | { |
| 141 | // At most once a second. The table holds one entry per call site that | ||
| 142 | // has fired in the last few seconds, so the walk is short, but it must | ||
| 143 | // not run once per line of a burst. | ||
| 144 | if (now != g_logDedupLastSweep) | ||
| 145 | { | ||
| 146 | g_logDedupLastSweep = now; | ||
| 147 | SweepExpiredWindowsLocked(now, flushes); | ||
| 148 | } | ||
| 149 | |||
| 69 | std::map<std::string, LogDedupState>::iterator it = g_logDedup.find(key); | 150 | std::map<std::string, LogDedupState>::iterator it = g_logDedup.find(key); |
| 70 | if (it == g_logDedup.end()) | 151 | if (it == g_logDedup.end()) |
| 71 | { | 152 | { |
| @@ -76,10 +157,18 @@ void LogPrintDedup(const char* category, const char* file, int line, const std:: | |||
| 76 | } | 157 | } |
| 77 | else if (now - it->second.windowStart >= DEDUP_WINDOW_SECS) | 158 | else if (now - it->second.windowStart >= DEDUP_WINDOW_SECS) |
| 78 | { | 159 | { |
| 79 | // Window rolled over: flush what was suppressed during it (if | 160 | // Window rolled over within the same second as the last sweep: |
| 80 | // anything), then start a new window with this call printed. | 161 | // flush what was suppressed during it (if anything), then start a |
| 81 | suppressedToFlush = it->second.suppressed; | 162 | // new window with this call printed. |
| 82 | flushedMsg = it->second.lastMsg; | 163 | if (it->second.suppressed > 0) |
| 164 | { | ||
| 165 | LogDedupFlush f; | ||
| 166 | f.category = category; | ||
| 167 | f.suppressed = it->second.suppressed; | ||
| 168 | f.elapsed = now - it->second.windowStart; | ||
| 169 | f.lastMsg = it->second.lastMsg; | ||
| 170 | flushes.push_back(f); | ||
| 171 | } | ||
| 83 | it->second.windowStart = now; | 172 | it->second.windowStart = now; |
| 84 | it->second.suppressed = 0; | 173 | it->second.suppressed = 0; |
| 85 | it->second.lastMsg = msg; | 174 | it->second.lastMsg = msg; |
| @@ -94,13 +183,23 @@ void LogPrintDedup(const char* category, const char* file, int line, const std:: | |||
| 94 | } | 183 | } |
| 95 | } | 184 | } |
| 96 | 185 | ||
| 97 | if (suppressedToFlush > 0) | 186 | for (size_t i = 0; i < flushes.size(); i++) |
| 98 | OutputDebugStringF("[%s] (%d similar in %llds, last: %s)\n", | 187 | EmitDedupSummary(flushes[i]); |
| 99 | category, suppressedToFlush, (long long)DEDUP_WINDOW_SECS, flushedMsg.c_str()); | ||
| 100 | if (fEmitNow) | 188 | if (fEmitNow) |
| 101 | OutputDebugStringF("[%s] %s\n", category, msg.c_str()); | 189 | OutputDebugStringF("[%s] %s\n", category, msg.c_str()); |
| 102 | } | 190 | } |
| 103 | 191 | ||
| 192 | // LogPrintAlways() -- see the doc comment in util.h. No window, no counting, | ||
| 193 | // no table entry: every call writes its own line. | ||
| 194 | void LogPrintNoCollapse(const char* category, const std::string& msgIn) | ||
| 195 | { | ||
| 196 | std::string msg = msgIn; | ||
| 197 | while (!msg.empty() && (msg.back() == '\n' || msg.back() == '\r')) | ||
| 198 | msg.pop_back(); | ||
| 199 | |||
| 200 | OutputDebugStringF("[%s] %s\n", category, msg.c_str()); | ||
| 201 | } | ||
| 202 | |||
| 104 | 203 | ||
| 105 | 204 | ||
| 106 | 205 | ||
| @@ -397,13 +496,37 @@ bool FileExists(const char* psz) | |||
| 397 | #endif | 496 | #endif |
| 398 | } | 497 | } |
| 399 | 498 | ||
| 400 | int GetFilesize(FILE* file) | 499 | #ifndef _WIN32 |
| 500 | // If off_t is 32 bits wide, ftello() truncates exactly like the int this | ||
| 501 | // function used to return. Fail the build rather than ship the silent | ||
| 502 | // version of the bug (32-bit hosts need -D_FILE_OFFSET_BITS=64). | ||
| 503 | static_assert(sizeof(off_t) >= 8, "GetFilesize needs a 64-bit off_t"); | ||
| 504 | #endif | ||
| 505 | |||
| 506 | // Returns the file's size in bytes, or -1 if it cannot be determined. | ||
| 507 | // | ||
| 508 | // This used to hold ftell()'s long in an int, so a file of 2 GiB or more came | ||
| 509 | // back negative. Its only caller is the debug.log roll in util.h, which skips | ||
| 510 | // the roll on a negative size -- i.e. rotation switched itself off for good at | ||
| 511 | // exactly the size the roll exists to prevent, and any cap of 2048 MB or more | ||
| 512 | // could never be exceeded at all. Both failures were silent. | ||
| 513 | int64 GetFilesize(FILE* file) | ||
| 401 | { | 514 | { |
| 402 | int nSavePos = ftell(file); | 515 | #ifdef _WIN32 |
| 403 | int nFilesize = -1; | 516 | __int64 nSavePos = _ftelli64(file); |
| 404 | if (fseek(file, 0, SEEK_END) == 0) | 517 | int64 nFilesize = -1; |
| 405 | nFilesize = ftell(file); | 518 | if (nSavePos >= 0 && _fseeki64(file, 0, SEEK_END) == 0) |
| 406 | fseek(file, nSavePos, SEEK_SET); | 519 | nFilesize = _ftelli64(file); |
| 520 | if (nSavePos >= 0) | ||
| 521 | _fseeki64(file, nSavePos, SEEK_SET); | ||
| 522 | #else | ||
| 523 | off_t nSavePos = ftello(file); | ||
| 524 | int64 nFilesize = -1; | ||
| 525 | if (nSavePos >= 0 && fseeko(file, 0, SEEK_END) == 0) | ||
| 526 | nFilesize = ftello(file); | ||
| 527 | if (nSavePos >= 0) | ||
| 528 | fseeko(file, nSavePos, SEEK_SET); | ||
| 529 | #endif | ||
| 407 | return nFilesize; | 530 | return nFilesize; |
| 408 | } | 531 | } |
| 409 | 532 | ||
| @@ -87,6 +87,15 @@ inline T& REF(const T& val) | |||
| 87 | 87 | ||
| 88 | extern bool fDebug; | 88 | extern bool fDebug; |
| 89 | 89 | ||
| 90 | // /debugrelay: the per-message firehose ("relay" and "nostrdiscovery" | ||
| 91 | // categories) that even -debug keeps off. See LogAcceptsCategory(). | ||
| 92 | extern bool fDebugRelay; | ||
| 93 | |||
| 94 | // debug.log is rolled to debug.log.old once it grows past this many bytes | ||
| 95 | // (set from -maxdebugfilesize, in MB; 0 disables the check). See the roll | ||
| 96 | // site in OutputDebugStringF() below. | ||
| 97 | extern int64 nMaxDebugFileSize; | ||
| 98 | |||
| 90 | // --------------------------------------------------------------------------- | 99 | // --------------------------------------------------------------------------- |
| 91 | // Categorized, burst-collapsing logging | 100 | // Categorized, burst-collapsing logging |
| 92 | // | 101 | // |
| @@ -106,15 +115,29 @@ extern bool fDebug; | |||
| 106 | // 2. Burst collapse: repeated LogPrint() calls from the *same source line* | 115 | // 2. Burst collapse: repeated LogPrint() calls from the *same source line* |
| 107 | // only emit one line per DEDUP_WINDOW_SECS; if more calls land inside | 116 | // only emit one line per DEDUP_WINDOW_SECS; if more calls land inside |
| 108 | // that window they're counted instead of reprinted, and the count is | 117 | // that window they're counted instead of reprinted, and the count is |
| 109 | // flushed as a single "(xN similar in Ws)" line the moment the window | 118 | // flushed as a single "(xN similar in Ws)" line once the window expires |
| 110 | // rolls over. A loop discovering 500 peers by address now produces a | 119 | // -- whether or not that call site ever fires again. A loop discovering |
| 111 | // small, bounded number of lines instead of 500 -- log growth is capped | 120 | // 500 peers by address now produces a small, bounded number of lines |
| 112 | // by elapsed time, not by how many similar events happen to fire. | 121 | // instead of 500 -- log growth is capped by elapsed time, not by how |
| 122 | // many similar events happen to fire. | ||
| 123 | // | ||
| 124 | // Use LogPrintAlways() instead for anything that reports an irreversible | ||
| 125 | // change to money: an obligation voided, a payment sent, a payment that | ||
| 126 | // failed. One line standing in for an unknown number of identical events is | ||
| 127 | // a tidy report of peer chatter and a false report of a ledger. A reorg | ||
| 128 | // voiding 100 entries hits one source line 100 times inside one window; | ||
| 129 | // under LogPrint() that read as a single block losing a single 49.49 BTF | ||
| 130 | // payment, while 4,950 BTF of obligations were actually destroyed, and the | ||
| 131 | // discrepancy was only found by counting entries in pending_payouts.json | ||
| 132 | // (issue #3). Bounded log growth is not worth that ambiguity here. | ||
| 113 | // --------------------------------------------------------------------------- | 133 | // --------------------------------------------------------------------------- |
| 114 | bool LogAcceptsCategory(const char* category); | 134 | bool LogAcceptsCategory(const char* category); |
| 115 | void LogPrintDedup(const char* category, const char* file, int line, const std::string& msg); | 135 | void LogPrintDedup(const char* category, const char* file, int line, const std::string& msg); |
| 136 | void LogPrintNoCollapse(const char* category, const std::string& msg); | ||
| 116 | #define LogPrint(category, ...) \ | 137 | #define LogPrint(category, ...) \ |
| 117 | do { if (LogAcceptsCategory(category)) LogPrintDedup((category), __FILE__, __LINE__, strprintf(__VA_ARGS__)); } while (0) | 138 | do { if (LogAcceptsCategory(category)) LogPrintDedup((category), __FILE__, __LINE__, strprintf(__VA_ARGS__)); } while (0) |
| 139 | #define LogPrintAlways(category, ...) \ | ||
| 140 | do { if (LogAcceptsCategory(category)) LogPrintNoCollapse((category), strprintf(__VA_ARGS__)); } while (0) | ||
| 118 | 141 | ||
| 119 | // Every format string in this project goes through one of the four functions | 142 | // Every format string in this project goes through one of the four functions |
| 120 | // below -- `printf` itself is remapped to OutputDebugStringF just above, and | 143 | // below -- `printf` itself is remapped to OutputDebugStringF just above, and |
| @@ -145,7 +168,7 @@ void ParseString(const string& str, char c, vector<string>& v); | |||
| 145 | string FormatMoney(int64 n, bool fPlus=false); | 168 | string FormatMoney(int64 n, bool fPlus=false); |
| 146 | bool ParseMoney(const char* pszIn, int64& nRet); | 169 | bool ParseMoney(const char* pszIn, int64& nRet); |
| 147 | bool FileExists(const char* psz); | 170 | bool FileExists(const char* psz); |
| 148 | int GetFilesize(FILE* file); | 171 | int64 GetFilesize(FILE* file); |
| 149 | uint64 GetRand(uint64 nMax); | 172 | uint64 GetRand(uint64 nMax); |
| 150 | int64 GetTime(); | 173 | int64 GetTime(); |
| 151 | int64 GetAdjustedTime(); | 174 | int64 GetAdjustedTime(); |
| @@ -199,7 +222,7 @@ protected: | |||
| 199 | public: | 222 | public: |
| 200 | char* pszFile; | 223 | char* pszFile; |
| 201 | int nLine; | 224 | int nLine; |
| 202 | explicit CCriticalSection() { InitializeCriticalSection(&cs); } | 225 | explicit CCriticalSection() : pszFile(NULL), nLine(0) { InitializeCriticalSection(&cs); } |
| 203 | ~CCriticalSection() { DeleteCriticalSection(&cs); } | 226 | ~CCriticalSection() { DeleteCriticalSection(&cs); } |
| 204 | void Enter() { EnterCriticalSection(&cs); } | 227 | void Enter() { EnterCriticalSection(&cs); } |
| 205 | void Leave() { LeaveCriticalSection(&cs); } | 228 | void Leave() { LeaveCriticalSection(&cs); } |
| @@ -390,7 +413,65 @@ inline int OutputDebugStringF(const char* pszFormat, ...) | |||
| 390 | else | 413 | else |
| 391 | strDebugFile = "debug.log"; | 414 | strDebugFile = "debug.log"; |
| 392 | } | 415 | } |
| 416 | // Latched by a failed rename in the roll below, which cannot be | ||
| 417 | // retried usefully and must not be retried endlessly. | ||
| 418 | static bool fRollDisabled = false; | ||
| 393 | FILE* fileout = fopen(strDebugFile.c_str(), "a"); | 419 | FILE* fileout = fopen(strDebugFile.c_str(), "a"); |
| 420 | if (fileout && nMaxDebugFileSize > 0 && !fRollDisabled) | ||
| 421 | { | ||
| 422 | // Roll an overgrown debug.log before adding to it. Nothing in the | ||
| 423 | // tree shrinks this file once the process is running (there is no | ||
| 424 | // ShrinkDebugFile, and even Bitcoin's only ran at startup), so a | ||
| 425 | // node that stays up for months grows the log without bound -- | ||
| 426 | // production hit ~2 GiB. The file is opened and closed per line, | ||
| 427 | // so a rename is safe here: the next line simply reopens the | ||
| 428 | // path. One generation is kept as debug.log.old; logrotate | ||
| 429 | // (contrib/logrotate/) handles anything longer-term. | ||
| 430 | int64 nSize = GetFilesize(fileout); | ||
| 431 | if (nSize >= 0 && nSize > nMaxDebugFileSize) | ||
| 432 | { | ||
| 433 | fclose(fileout); | ||
| 434 | string strOldFile = strDebugFile + ".old"; | ||
| 435 | remove(strOldFile.c_str()); // rename() won't clobber on Windows | ||
| 436 | bool fRolled = (rename(strDebugFile.c_str(), strOldFile.c_str()) == 0); | ||
| 437 | int nRenameErrno = errno; // before fopen() can overwrite it | ||
| 438 | fileout = fopen(strDebugFile.c_str(), "a"); | ||
| 439 | if (fRolled) | ||
| 440 | { | ||
| 441 | if (fileout) | ||
| 442 | fprintf(fileout, | ||
| 443 | "debug.log grew past %lld MB; previous contents moved to debug.log.old (-maxdebugfilesize)\n", | ||
| 444 | (long long)(nMaxDebugFileSize / 1024 / 1024)); | ||
| 445 | } | ||
| 446 | else if (nRenameErrno == ENOENT) | ||
| 447 | { | ||
| 448 | // The file went away between the size check and the | ||
| 449 | // rename, so an external rotator (logrotate) got there | ||
| 450 | // first. Nothing left to roll and nothing wrong: the | ||
| 451 | // fopen above has already recreated it. Latching on this | ||
| 452 | // would let a benign race with logrotate switch the cap | ||
| 453 | // off for the rest of the run. | ||
| 454 | } | ||
| 455 | else | ||
| 456 | { | ||
| 457 | // The file is still over the cap, so this branch would be | ||
| 458 | // reached again on the next line and every line after it. | ||
| 459 | // Unlatched, the complaint about failing to roll becomes | ||
| 460 | // the runaway growth the roll exists to prevent. Say it | ||
| 461 | // once and stop trying -- on stderr too, because whatever | ||
| 462 | // blocked the rename (read-only mount, permissions, EXDEV | ||
| 463 | // across a bind mount) may equally block the log write. | ||
| 464 | fRollDisabled = true; | ||
| 465 | fprintf(stderr, | ||
| 466 | "cannot roll %s (rename to .old failed: %s); -maxdebugfilesize disabled for this run\n", | ||
| 467 | strDebugFile.c_str(), strerror(nRenameErrno)); | ||
| 468 | if (fileout) | ||
| 469 | fprintf(fileout, | ||
| 470 | "cannot roll debug.log (rename to .old failed: %s); -maxdebugfilesize disabled for this run\n", | ||
| 471 | strerror(nRenameErrno)); | ||
| 472 | } | ||
| 473 | } | ||
| 474 | } | ||
| 394 | if (fileout) | 475 | if (fileout) |
| 395 | { | 476 | { |
| 396 | va_list arg_ptr; | 477 | va_list arg_ptr; |