upleb.uk

Public git repos — served from a NIP-34 GRASP relay at git.upleb.uk

summaryrefslogtreecommitdiff
path: root/src
diff options
context:
space:
mode:
Diffstat (limited to 'src')
-rw-r--r--src/Makefile4
-rw-r--r--src/btfrv.cpp65
-rw-r--r--src/btfrv.h19
-rw-r--r--src/btftunnel.cpp140
-rw-r--r--src/btftunnel.h25
-rw-r--r--src/gui.cpp34
-rw-r--r--src/main.cpp521
-rw-r--r--src/main_gui.cpp50
-rw-r--r--src/net.cpp5
-rw-r--r--src/net.h73
-rw-r--r--src/nostr.cpp27
-rw-r--r--src/nostr.h3
-rw-r--r--src/randomx_pow.cpp28
-rw-r--r--src/readme.txt2
-rw-r--r--src/rpc.cpp398
-rw-r--r--src/util.cpp153
-rw-r--r--src/util.h93
17 files changed, 1534 insertions, 106 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
7SECP_INC ?= /usr/local/include 7SECP_INC ?= /usr/local/include
8SECP_LIB ?= /usr/local/lib 8SECP_LIB ?= /usr/local/lib
9RANDOMX_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.
11RANDOMX_DIR ?= $(abspath $(CURDIR)/..)/randomx-build
10 12
11IMGUI_DIR = imgui 13IMGUI_DIR = imgui
12 14
diff --git a/src/btfrv.cpp b/src/btfrv.cpp
index 133eb89..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
44namespace btf 46namespace 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;
@@ -334,17 +377,29 @@ bool RvServiceWaitPaired(RvSocket s, int nTimeoutSecs)
334} 377}
335 378
336RvSocket RvClientConnect(const char* relay_host, unsigned short port, 379RvSocket RvClientConnect(const char* relay_host, unsigned short port,
337 const unsigned char target_pubkey[32]) 380 const unsigned char target_pubkey[32],
381 RvClientFail* pFail)
338{ 382{
383 if (pFail) *pFail = RVC_FAIL_DIAL;
339 if (!RvInit()) return RV_INVALID; 384 if (!RvInit()) return RV_INVALID;
340 SOCKET s = ConnectTo(relay_host, port); 385 SOCKET s = ConnectTo(relay_host, port);
341 if (s == INVALID_SOCKET) return RV_INVALID; 386 if (s == INVALID_SOCKET) return RV_INVALID;
387 if (pFail) *pFail = RVC_FAIL_PAIR;
342 unsigned char hdr[33]; 388 unsigned char hdr[33];
343 hdr[0] = (unsigned char)'C'; 389 hdr[0] = (unsigned char)'C';
344 memcpy(hdr + 1, target_pubkey, 32); 390 memcpy(hdr + 1, target_pubkey, 32);
345 if (!WriteN(s, hdr, 33)) { CLOSESOCK(s); return RV_INVALID; } 391 if (!WriteN(s, hdr, 33)) { CLOSESOCK(s); return RV_INVALID; }
346 unsigned char paired = 0; 392 unsigned char paired = 0;
347 if (!ReadN(s, &paired, 1) || paired != 0x01) { CLOSESOCK(s); return RV_INVALID; } 393 if (!ReadN(s, &paired, 1)) { CLOSESOCK(s); return RV_INVALID; }
394 if (paired != 0x01)
395 {
396 // The relay answered and declined: HandleIncoming writes 0x00 and
397 // closes when no service is parked under this pubkey right now.
398 if (pFail) *pFail = RVC_FAIL_REFUSED;
399 CLOSESOCK(s);
400 return RV_INVALID;
401 }
402 if (pFail) *pFail = RVC_FAIL_NONE;
348 return (RvSocket)s; 403 return (RvSocket)s;
349} 404}
350 405
diff --git a/src/btfrv.h b/src/btfrv.h
index 9cd7476..1e85cb0 100644
--- a/src/btfrv.h
+++ b/src/btfrv.h
@@ -57,10 +57,25 @@ RvSocket RvServiceRegister(const char* relay_host, unsigned short port,
57bool RvServiceWaitPaired(RvSocket s, int nTimeoutSecs = 0); 57bool RvServiceWaitPaired(RvSocket s, int nTimeoutSecs = 0);
58 58
59// ---- client side (the node dialing a .btf address) ---- 59// ---- client side (the node dialing a .btf address) ----
60// Where a failed RvClientConnect stopped. RV_INVALID alone collapses three
61// different situations -- relay unreachable, relay reachable but nobody
62// registered, connection died mid-pairing -- and they point at different
63// components. The caller can only report the right one if this side says
64// which it saw.
65enum RvClientFail
66{
67 RVC_FAIL_NONE = 0,
68 RVC_FAIL_DIAL, // TCP connect to the relay itself failed
69 RVC_FAIL_REFUSED, // relay answered 0x00: no service registered under this pubkey
70 RVC_FAIL_PAIR, // relay connection died before pairing completed
71};
72
60// Connect through the relay to the service registered under `target_pubkey`. 73// Connect through the relay to the service registered under `target_pubkey`.
61// Returns the paired socket, or RV_INVALID on error. 74// Returns the paired socket, or RV_INVALID on error -- with `pFail`, if
75// given, naming the stage that failed.
62RvSocket RvClientConnect(const char* relay_host, unsigned short port, 76RvSocket RvClientConnect(const char* relay_host, unsigned short port,
63 const unsigned char target_pubkey[32]); 77 const unsigned char target_pubkey[32],
78 RvClientFail* pFail = 0);
64 79
65// Blocking read/write of exactly n bytes over a rendezvous socket. Return false 80// Blocking read/write of exactly n bytes over a rendezvous socket. Return false
66// on error/EOF. 81// on error/EOF.
diff --git a/src/btftunnel.cpp b/src/btftunnel.cpp
index 63d178b..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
31namespace btf 35namespace btf
32{ 36{
@@ -119,35 +123,155 @@ 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.
138struct TunnelEnds
139{
140 SOCKET pumpEnd;
141 RvSocket rv;
142 TunnelEnds(SOCKET p, RvSocket r) : pumpEnd(p), rv(r) {}
143 ~TunnelEnds() { BtfCloseSocket(pumpEnd); RvClose(rv); }
144private:
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.
124static btf_socket_t StartTunnel(RvSocket rv, const unsigned char shared[32]) 172static 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
234const char* TunnelFailText(TunnelFail f)
235{
236 switch (f)
237 {
238 case TUNNEL_FAIL_NONE: return "no failure";
239 case TUNNEL_FAIL_INIT: return "local socket/crypto init failed";
240 case TUNNEL_FAIL_DIAL: return "meeting node unreachable (tcp dial failed)";
241 case TUNNEL_FAIL_REFUSED: return "relay reachable, but no service registered there for this address";
242 case TUNNEL_FAIL_PAIR: return "relay connection died before pairing completed";
243 case TUNNEL_FAIL_HANDSHAKE: return "end-to-end handshake failed";
244 case TUNNEL_FAIL_LOCAL: return "local tunnel setup failed";
245 }
246 return "unknown failure";
247}
248
139btf_socket_t BtfClientTunnel(const char* meeting_host, unsigned short port, 249btf_socket_t BtfClientTunnel(const char* meeting_host, unsigned short port,
140 const unsigned char target_pubkey[32], 250 const unsigned char target_pubkey[32],
141 const unsigned char service_enc_pub[32]) 251 const unsigned char service_enc_pub[32],
252 TunnelFail* pFail)
142{ 253{
254 if (pFail) *pFail = TUNNEL_FAIL_INIT;
143 if (!TunnelInit()) return INVALID_SOCKET; 255 if (!TunnelInit()) return INVALID_SOCKET;
144 RvSocket rv = RvClientConnect(meeting_host, port, target_pubkey); 256 RvClientFail rvFail = RVC_FAIL_NONE;
145 if (rv == RV_INVALID) return INVALID_SOCKET; 257 RvSocket rv = RvClientConnect(meeting_host, port, target_pubkey, &rvFail);
258 if (rv == RV_INVALID)
259 {
260 if (pFail)
261 *pFail = rvFail == RVC_FAIL_DIAL ? TUNNEL_FAIL_DIAL
262 : rvFail == RVC_FAIL_REFUSED ? TUNNEL_FAIL_REFUSED
263 : TUNNEL_FAIL_PAIR;
264 return INVALID_SOCKET;
265 }
146 266
147 unsigned char eph_pub[32], shared[32]; 267 unsigned char eph_pub[32], shared[32];
268 if (pFail) *pFail = TUNNEL_FAIL_HANDSHAKE;
148 if (!ChanClientHandshake(service_enc_pub, eph_pub, shared)) { RvClose(rv); return INVALID_SOCKET; } 269 if (!ChanClientHandshake(service_enc_pub, eph_pub, shared)) { RvClose(rv); return INVALID_SOCKET; }
149 if (!RvWriteN(rv, eph_pub, 32)) { RvClose(rv); return INVALID_SOCKET; } 270 if (!RvWriteN(rv, eph_pub, 32)) { RvClose(rv); return INVALID_SOCKET; }
150 return StartTunnel(rv, shared); 271 if (pFail) *pFail = TUNNEL_FAIL_LOCAL;
272 btf_socket_t app = StartTunnel(rv, shared);
273 if (app != INVALID_SOCKET && pFail) *pFail = TUNNEL_FAIL_NONE;
274 return app;
151} 275}
152 276
153btf_socket_t BtfServiceWrap(RvSocket rv, const unsigned char my_enc_sk[32]) 277btf_socket_t BtfServiceWrap(RvSocket rv, const unsigned char my_enc_sk[32])
diff --git a/src/btftunnel.h b/src/btftunnel.h
index 24a7509..3cc87cd 100644
--- a/src/btftunnel.h
+++ b/src/btftunnel.h
@@ -36,12 +36,33 @@ namespace btf
36// Initialize (sockets + libsodium). Idempotent. 36// Initialize (sockets + libsodium). Idempotent.
37bool TunnelInit(); 37bool TunnelInit();
38 38
39// Which stage of BtfClientTunnel failed. INVALID_SOCKET alone says only "no
40// tunnel"; a caller that then guesses at causes in its log line sends whoever
41// reads it to the wrong component (issue #17: "relay unreachable or pool not
42// listening" blamed two healthy parts). The stage is what this side actually
43// knows -- report that.
44enum TunnelFail
45{
46 TUNNEL_FAIL_NONE = 0,
47 TUNNEL_FAIL_INIT, // local socket/crypto init failed
48 TUNNEL_FAIL_DIAL, // TCP connect to the meeting node failed
49 TUNNEL_FAIL_REFUSED, // relay reachable, but no service registered under the pubkey
50 TUNNEL_FAIL_PAIR, // relay connection died before pairing completed
51 TUNNEL_FAIL_HANDSHAKE, // end-to-end channel handshake failed
52 TUNNEL_FAIL_LOCAL, // local pump plumbing (socket pair / threads) failed
53};
54
55// Short description of a TunnelFail for log lines.
56const char* TunnelFailText(TunnelFail f);
57
39// Client: dial the service registered under `target_pubkey` at the meeting node 58// Client: dial the service registered under `target_pubkey` at the meeting node
40// (host:port), box to its static x25519 `service_enc_pub`, and return a local 59// (host:port), box to its static x25519 `service_enc_pub`, and return a local
41// plaintext SOCKET tunneled end-to-end to the service. INVALID_SOCKET on error. 60// plaintext SOCKET tunneled end-to-end to the service. INVALID_SOCKET on error
61// -- with `pFail`, if given, naming the stage that failed.
42btf_socket_t BtfClientTunnel(const char* meeting_host, unsigned short port, 62btf_socket_t BtfClientTunnel(const char* meeting_host, unsigned short port,
43 const unsigned char target_pubkey[32], 63 const unsigned char target_pubkey[32],
44 const unsigned char service_enc_pub[32]); 64 const unsigned char service_enc_pub[32],
65 TunnelFail* pFail = 0);
45 66
46// Service: wrap an already-paired rendezvous socket (RvServiceRegister followed 67// Service: wrap an already-paired rendezvous socket (RvServiceRegister followed
47// by RvServiceWaitPaired -- the pairing byte MUST already be consumed) with 68// by RvServiceWaitPaired -- the pairing byte MUST already be consumed) with
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 7b3e555..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;
64map<uint256, CBlock*> mapOrphanBlocks; 65map<uint256, CBlock*> mapOrphanBlocks;
65multimap<uint256, CBlock*> mapOrphanBlocksByPrev; 66multimap<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.
91struct 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};
98map<uint256, CBlockFetch> mapBlockFetch;
99static 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.
103static 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.
116static const int BLOCK_FETCH_REPORT_SECS = 60;
117static int64 nBlockFetchWindowStart = 0;
118static 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.
124static 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.
138bool 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.
163static 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
67map<uint256, CDataStream*> mapOrphanTransactions; 199map<uint256, CDataStream*> mapOrphanTransactions;
68multimap<uint256, CDataStream*> mapOrphanTransactionsByPrev; 200multimap<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}
@@ -3662,6 +3970,14 @@ static void ParticipantHashWorker(ParticipantJobShared* sh, int idx, int nWorker
3662 RandomXDestroyMinerVM(vm); 3970 RandomXDestroyMinerVM(vm);
3663} 3971}
3664 3972
3973// Run one participant session: resolve the pool, open the tunnel, subscribe,
3974// hash, submit shares. Returns true only if the pool actually handed out work
3975// -- at least one well-formed mining.notify arrived. Everything else is false,
3976// including a tunnel that opened and was dropped before any job.
3977//
3978// The caller's reconnect backoff keys off this return value, so any path added
3979// here that leaves the session without work MUST return false. "The session
3980// ended tidily" is not the question being asked.
3665static bool PoolParticipantMiner() 3981static bool PoolParticipantMiner()
3666{ 3982{
3667 // ------------------------------------------------------------------ 3983 // ------------------------------------------------------------------
@@ -3739,6 +4055,33 @@ static bool PoolParticipantMiner()
3739 } 4055 }
3740 LogPrint("worker", "[worker] pool resolved to meeting node %s\n", meetingHostPort.c_str()); 4056 LogPrint("worker", "[worker] pool resolved to meeting node %s\n", meetingHostPort.c_str());
3741 4057
4058 // The descriptor names ONE meeting node, but the pool parks a
4059 // registration at every relay it knows (one accept thread per relay,
4060 // rpc.cpp:AcceptOneFn), so any seed relay can pair us. Insisting on the
4061 // advertised entry forever turns one bad path into a miner that idles
4062 // indefinitely while a working path exists (issue #17); after a few
4063 // consecutive tunnel failures, rotate the seed relays into the attempts
4064 // too. Only ONE participant session runs (StartMinerThreads), so these
4065 // statics are single-threaded.
4066 static const int TUNNEL_FAILOVER_AFTER = 3;
4067 static int nTunnelFails = 0; // consecutive tunnel failures, this pool
4068 static size_t iFailoverRelay = 0; // rotation cursor over vBtfMeetingRelays
4069 static std::string strFailPool; // pool the counters belong to
4070 if (strFailPool != strParticipantPool) {
4071 strFailPool = strParticipantPool;
4072 nTunnelFails = 0;
4073 iFailoverRelay = 0;
4074 }
4075 if (nTunnelFails >= TUNNEL_FAILOVER_AFTER && !vBtfMeetingRelays.empty()) {
4076 std::string alt = vBtfMeetingRelays[iFailoverRelay++ % vBtfMeetingRelays.size()];
4077 if (alt != meetingHostPort) {
4078 LogPrint("worker", "[worker] advertised meeting node %s failed %d"
4079 " times in a row -- trying seed relay %s instead\n",
4080 meetingHostPort.c_str(), nTunnelFails, alt.c_str());
4081 meetingHostPort = alt;
4082 }
4083 }
4084
3742 size_t colon = meetingHostPort.rfind(':'); 4085 size_t colon = meetingHostPort.rfind(':');
3743 if (colon == std::string::npos) { 4086 if (colon == std::string::npos) {
3744 LogPrint("worker", "[worker] bad meeting node format '%s'\n", meetingHostPort.c_str()); 4087 LogPrint("worker", "[worker] bad meeting node format '%s'\n", meetingHostPort.c_str());
@@ -3758,15 +4101,18 @@ static bool PoolParticipantMiner()
3758 // Step 2b: open encrypted tunnel to pool 4101 // Step 2b: open encrypted tunnel to pool
3759 // ------------------------------------------------------------------ 4102 // ------------------------------------------------------------------
3760 SetParticipantMiningStatus("opening tunnel"); 4103 SetParticipantMiningStatus("opening tunnel");
4104 btf::TunnelFail tunnelFail = btf::TUNNEL_FAIL_NONE;
3761 s = btf::BtfClientTunnel(host.c_str(), (unsigned short)port, 4105 s = btf::BtfClientTunnel(host.c_str(), (unsigned short)port,
3762 target_pubkey, service_enc_pub); 4106 target_pubkey, service_enc_pub, &tunnelFail);
3763 if (s == INVALID_SOCKET) { 4107 if (s == INVALID_SOCKET) {
3764 LogPrint("worker", "[worker] tunnel connect FAILED via %s" 4108 nTunnelFails++;
3765 " (relay unreachable or pool not listening)\n", 4109 LogPrint("worker", "[worker] tunnel connect FAILED via %s: %s\n",
3766 meetingHostPort.c_str()); 4110 meetingHostPort.c_str(), btf::TunnelFailText(tunnelFail));
3767 SetParticipantMiningStatus("tunnel connect failed"); 4111 SetParticipantMiningStatus(std::string("tunnel connect failed: ")
4112 + btf::TunnelFailText(tunnelFail));
3768 return false; 4113 return false;
3769 } 4114 }
4115 nTunnelFails = 0;
3770 LogPrint("worker", "[worker] tunnel open via %s\n", meetingHostPort.c_str()); 4116 LogPrint("worker", "[worker] tunnel open via %s\n", meetingHostPort.c_str());
3771 SetParticipantMiningStatus("tunnel open"); 4117 SetParticipantMiningStatus("tunnel open");
3772 } 4118 }
@@ -3899,9 +4245,32 @@ connected:
3899 std::vector<ParticipantShareHit> shareHits; 4245 std::vector<ParticipantShareHit> shareHits;
3900 std::mutex shareHitsMtx; 4246 std::mutex shareHitsMtx;
3901 std::vector<std::thread> hashThreads; 4247 std::vector<std::thread> hashThreads;
3902 for (int i = 0; i < nWorkers; i++) 4248 try
3903 hashThreads.emplace_back(ParticipantHashWorker, &jobShared, i, nWorkers, 4249 {
3904 &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 }
3905 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",
3906 nWorkers); 4275 nWorkers);
3907 const uint64 sessionStartHashes = gParticipantHashes.load(); 4276 const uint64 sessionStartHashes = gParticipantHashes.load();
@@ -3912,8 +4281,17 @@ connected:
3912 std::string jobId; 4281 std::string jobId;
3913 unsigned char header[80] = {}; 4282 unsigned char header[80] = {};
3914 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
3915 double currentDifficulty = 1.0; // updated by mining.set_difficulty from pool 4292 double currentDifficulty = 1.0; // updated by mining.set_difficulty from pool
3916 bool haveJob = false; 4293 bool haveJob = false;
4294 bool gotAnyJob = false; // any job at all this session -- the return value
3917 bool gotSubscribeAck = false; 4295 bool gotSubscribeAck = false;
3918 bool gotAuthorizeAck = false; 4296 bool gotAuthorizeAck = false;
3919 int64 authWaitStart = 0; 4297 int64 authWaitStart = 0;
@@ -4030,8 +4408,9 @@ connected:
4030 jobId = newJobId; 4408 jobId = newJobId;
4031 memcpy(header, hdrBytes.data(), 80); 4409 memcpy(header, hdrBytes.data(), 80);
4032 memcpy(&target, tgtBytes.data(), 32); 4410 memcpy(&target, tgtBytes.data(), 32);
4033 haveJob = true; 4411 haveJob = true;
4034 nNonce = 1; 4412 gotAnyJob = true;
4413 nNonce = 1;
4035 { 4414 {
4036 std::lock_guard<std::mutex> lk(jobShared.mtx); 4415 std::lock_guard<std::mutex> lk(jobShared.mtx);
4037 memcpy(jobShared.header, header, 80); 4416 memcpy(jobShared.header, header, 80);
@@ -4040,8 +4419,64 @@ connected:
4040 jobShared.jobSeq++; 4419 jobShared.jobSeq++;
4041 jobShared.haveJob = true; 4420 jobShared.haveJob = true;
4042 } 4421 }
4043 LogPrint("worker", "[pool->worker] new job %s received\n", 4422 // Log the chain position the pool is
4044 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 }
4045 SetParticipantMiningStatus("hashing job " + jobId); 4480 SetParticipantMiningStatus("hashing job " + jobId);
4046 } 4481 }
4047 } 4482 }
@@ -4167,7 +4602,11 @@ connected:
4167 (unsigned long long)hashesSinceSample, 4602 (unsigned long long)hashesSinceSample,
4168 (unsigned long long)sessionSharesSent, 4603 (unsigned long long)sessionSharesSent,
4169 (unsigned long long)sessionSharesAccepted); 4604 (unsigned long long)sessionSharesAccepted);
4170 return true; 4605 // Not "we got here", which is true of a tunnel the pool accepted and then
4606 // dropped without ever sending a job -- exactly the case the caller's
4607 // backoff exists for. Reaching the end of the session is not evidence the
4608 // session was worth anything; a job is.
4609 return gotAnyJob;
4171} 4610}
4172 4611
4173// --------------------------------------------------------------------------- 4612// ---------------------------------------------------------------------------
@@ -4364,11 +4803,51 @@ bool BitcoinMiner(int nThreadId)
4364 // Participant mode: connect to external pool instead of mining solo/operator 4803 // Participant mode: connect to external pool instead of mining solo/operator
4365 if (nMineMode == MINE_PARTICIPANT) 4804 if (nMineMode == MINE_PARTICIPANT)
4366 { 4805 {
4806 // An attempt that never got work backs off (10s doubling to 120s)
4807 // instead of hammering the same path every flat 10s, and a streak
4808 // lasting minutes is said at printf level: the identical once-per-10s
4809 // LogPrint line is how a worker idled all night unnoticed (issue #17).
4810 //
4811 // Only a session the pool actually sent a job to resets either. The
4812 // weaker test -- "the session returned" -- was gameable: a pool that
4813 // completes the tunnel and drops without ever sending work leaves by
4814 // the same tidy cleanup path a healthy one does, which would pin the
4815 // retry at 10s forever and defeat the backoff in exactly the scenario
4816 // it exists for.
4817 int nRetrySecs = 10;
4818 int64 nFailingSince = 0;
4367 while (fGenerateBitcoins && nMineMode == MINE_PARTICIPANT && !fShutdown) { 4819 while (fGenerateBitcoins && nMineMode == MINE_PARTICIPANT && !fShutdown) {
4368 PoolParticipantMiner(); 4820 bool fGotWork = PoolParticipantMiner();
4369 if (fGenerateBitcoins && nMineMode == MINE_PARTICIPANT && !fShutdown) { 4821 if (fGenerateBitcoins && nMineMode == MINE_PARTICIPANT && !fShutdown) {
4370 LogPrint("worker", "PoolParticipantMiner: reconnecting in 10s\n"); 4822 if (fGotWork) {
4371 for (int i = 0; i < 10 && !fShutdown; i++) Sleep(1000); 4823 nRetrySecs = 10;
4824 nFailingSince = 0;
4825 } else {
4826 if (nFailingSince == 0)
4827 nFailingSince = GetTime();
4828 int64 nMins = (GetTime() - nFailingSince) / 60;
4829 if (nMins >= 1)
4830 printf("[worker] connection to pool %s has been failing"
4831 " for %lld minutes\n",
4832 strParticipantPool.c_str(), (long long)nMins);
4833 }
4834 LogPrint("worker", "PoolParticipantMiner: reconnecting in %ds\n",
4835 nRetrySecs);
4836 // Poll everything the enclosing while polls, not just
4837 // fShutdown. Raising the ceiling to 120s made a
4838 // shutdown-only predicate expensive: after the operator
4839 // clears Generate or switches to Relay, the session -- and
4840 // the vfThreadRunning[3] slot that gates restarting it --
4841 // would stay held for up to two minutes. Measured 119s
4842 // before, 1s after.
4843 for (int i = 0; i < nRetrySecs && !fShutdown && fGenerateBitcoins
4844 && nMineMode == MINE_PARTICIPANT; i++)
4845 Sleep(1000);
4846 if (!fGotWork && nRetrySecs < 120) {
4847 nRetrySecs *= 2;
4848 if (nRetrySecs > 120)
4849 nRetrySecs = 120;
4850 }
4372 } 4851 }
4373 } 4852 }
4374 return true; 4853 return true;
@@ -4555,7 +5034,7 @@ bool BitcoinMiner(int nThreadId)
4555 //// debug print 5034 //// debug print
4556 if (LogAcceptsCategory("net")) printf("BitcoinMiner:\n"); 5035 if (LogAcceptsCategory("net")) printf("BitcoinMiner:\n");
4557 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());
4558 if (LogAcceptsCategory("net")) pblock->print(); 5037 if (LogAcceptsCategory("relay")) pblock->print();
4559 5038
4560 SetThreadPriority(GetCurrentThread(), THREAD_PRIORITY_NORMAL); 5039 SetThreadPriority(GetCurrentThread(), THREAD_PRIORITY_NORMAL);
4561 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
diff --git a/src/net.h b/src/net.h
index 9f3c7e4..fc48d0b 100644
--- a/src/net.h
+++ b/src/net.h
@@ -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.
30bool IsBlockFetchNearTip();
31
26bool GetMyExternalIP(unsigned int& ipRet); 32bool GetMyExternalIP(unsigned int& ipRet);
27CNode* ConnectNodeBtf(const string& strBtfAddr); 33CNode* ConnectNodeBtf(const string& strBtfAddr);
28CNode* ConnectNodeBtfResolved(const string& strBtfAddr, const string& strMeeting, 34CNode* ConnectNodeBtfResolved(const string& strBtfAddr, const string& strMeeting,
@@ -89,6 +95,15 @@ static const int BTF_RECV_TIMEOUT_SECS = 30 * 60;
89static const int BTF_SEND_STALL_SECS = 10 * 60; 95static const int BTF_SEND_STALL_SECS = 10 * 60;
90static const int BTF_HANDSHAKE_GRACE_SECS = 60; 96static 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".
105static 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
152void BtfSetActiveRelay(const string& relay) 152void 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().
242vector<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;
60bool LooksLikeRelay(const std::string& r); 60bool 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.
62std::vector<std::string> BtfAllRelays(); 62std::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.
65std::vector<std::string> BtfDiscoveredRelays();
63 66
64struct BtfPoolAnnouncement 67struct 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.
16Differences from the original Bitcoin 16Differences 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 be6c80d..1d53fb2 100644
--- a/src/rpc.cpp
+++ b/src/rpc.cpp
@@ -115,15 +115,28 @@ static uint256 ShareTargetFromDifficulty(double difficulty)
115{ 115{
116 if (difficulty <= 0.0) difficulty = 1.0; 116 if (difficulty <= 0.0) difficulty = 1.0;
117 static const uint256 diff1 = CBigNum(bnProofOfWorkLimit).getuint256(); 117 static const uint256 diff1 = CBigNum(bnProofOfWorkLimit).getuint256();
118 // Representability floor. shareTarget = diff1 / difficulty, and diff1 is
119 // ~uint256(0) >> 12, i.e. a hair under 2^244 -- so the true target stops
120 // fitting in a uint256 once difficulty reaches 2^-12 (= 1/4096), and the
121 // fixed-point divide below breaks even earlier in a second way: the
122 // (uint64)(difficulty * 65536.0) divisor truncates to zero for any
123 // difficulty under 2^-16. Both thresholds sit far below VARDIFF_MIN
124 // (0.001), so live operation never comes near this, but a caller that
125 // bypasses vardiff (or a future VARDIFF_MIN) must not divide by zero or
126 // hand back getuint256()'s low-256-bit truncation of an oversized
127 // quotient -- a wrapped target is not merely wrong, it is arbitrarily
128 // HARDER than difficulty 1. At these difficulties every hash is meant to
129 // be a share, so the honest answer is the easiest representable target.
130 // (This replaces a dead branch that read `if (t < diff1 && difficulty <
131 // 1.0)`: t = diff1/difficulty, so difficulty < 1.0 implies t > diff1 and
132 // the two conditions could never both hold.)
133 if (difficulty < 1.0 / 4096.0) return ~uint256(0);
118 // shareTarget = diff1 / difficulty 134 // shareTarget = diff1 / difficulty
119 CBigNum bn; bn.setuint256(diff1); 135 CBigNum bn; bn.setuint256(diff1);
120 // Multiply by 2^16 to keep precision, divide, shift back 136 // Multiply by 2^16 to keep precision, divide, shift back
121 bn <<= 16; 137 bn <<= 16;
122 bn /= (uint64)(difficulty * 65536.0); 138 bn /= (uint64)(difficulty * 65536.0);
123 uint256 t = bn.getuint256(); 139 return bn.getuint256();
124 // Cap at all-ones (maximum, easiest possible)
125 if (t < diff1 && difficulty < 1.0) t = ~uint256(0);
126 return t;
127} 140}
128 141
129// Expected number of hashes to find one share at a given Stratum difficulty, 142// Expected number of hashes to find one share at a given Stratum difficulty,
@@ -223,6 +236,29 @@ static bool RebuildJob()
223 // From the pool, so the template's payout key is in wallet.dat before 236 // From the pool, so the template's payout key is in wallet.dat before
224 // any miner is handed work against it. 237 // any miner is handed work against it.
225 vector<unsigned char> vchPubKey = GetKeyFromPool(); 238 vector<unsigned char> vchPubKey = GetKeyFromPool();
239 if (vchPubKey.empty()) {
240 // Empty means the wallet could not produce a key: encrypted and
241 // locked, or key generation itself failed. Serialised, an empty
242 // vector is a zero-length push, so the coinbase would become
243 // `<empty> OP_CHECKSIG` -- a script nobody can satisfy. Every
244 // block mined against such a job burns its whole subsidy, while
245 // QueuePayouts still records the full obligation and the miners
246 // are then paid out of coin that block never contributed.
247 // BitcoinMiner refuses to mine in this state; refuse to hand the
248 // pool's miners work in it too. printf and not LogPrint for the
249 // reason given above the deaf-node refusal, and throttled the
250 // same way -- the no-job watchdog retries every few seconds for
251 // as long as the condition lasts.
252 static int64 nLastSaidNoKey = 0;
253 if (GetTime() - nLastSaidNoKey > 60) {
254 nLastSaidNoKey = GetTime();
255 printf("RebuildJob: no wallet key available for the coinbase "
256 "(wallet locked, or key generation failed -- the "
257 "GetKeyFromPool line above says which) -- not issuing "
258 "jobs\n");
259 }
260 return false;
261 }
226 static std::atomic<uint32_t> sExtra{0}; 262 static std::atomic<uint32_t> sExtra{0};
227 uint32_t extraNonce = ++sExtra; 263 uint32_t extraNonce = ++sExtra;
228 264
@@ -1832,7 +1868,9 @@ static void FlushMaturePayouts()
1832 } 1868 }
1833 int64 total = 0; 1869 int64 total = 0;
1834 for (auto& kv : it->amounts) total += kv.second; 1870 for (auto& kv : it->amounts) total += kv.second;
1835 LogPrint("payout", "[payout] block %d (%s) was orphaned -- voiding %zu" 1871 // Always: one line per voided entry, never a collapsed summary.
1872 // A reorg voids these in a burst from this one source line.
1873 LogPrintAlways("payout", "[payout] block %d (%s) was orphaned -- voiding %zu"
1836 " payment(s) totalling %s\n", 1874 " payment(s) totalling %s\n",
1837 it->blockHeight, it->blockHash.ToString().substr(0, 14).c_str(), 1875 it->blockHeight, it->blockHash.ToString().substr(0, 14).c_str(),
1838 it->amounts.size(), FormatMoney(total).c_str()); 1876 it->amounts.size(), FormatMoney(total).c_str());
@@ -2031,7 +2069,7 @@ static void RecordPayoutTxid(const PayingRecord& r, const std::string& txid)
2031// disagreeing. 2069// disagreeing.
2032static void ForfeitPayoutRecipient(const PayingRecord& r, const std::string& reason) 2070static void ForfeitPayoutRecipient(const PayingRecord& r, const std::string& reason)
2033{ 2071{
2034 LogPrint("payout", "[payout] writing off %s owed to %s for block %d: %s\n", 2072 LogPrintAlways("payout", "[payout] writing off %s owed to %s for block %d: %s\n",
2035 FormatMoney(r.amount).c_str(), r.address.c_str(), r.blockHeight, 2073 FormatMoney(r.amount).c_str(), r.address.c_str(), r.blockHeight,
2036 reason.c_str()); 2074 reason.c_str());
2037 VersionedBlob blob; 2075 VersionedBlob blob;
@@ -2136,7 +2174,7 @@ static void PayoutThreadFn(void*)
2136 // funding block can land at any point in that window. Upstream has 2174 // funding block can land at any point in that window. Upstream has
2137 // no equivalent -- it decides once, when the entry matures. 2175 // no equivalent -- it decides once, when the entry matures.
2138 if (!PayoutBlockStillOnChain(r.blockHash)) { 2176 if (!PayoutBlockStillOnChain(r.blockHash)) {
2139 LogPrint("payout", "[payout] block %d (%s) orphaned while queued" 2177 LogPrintAlways("payout", "[payout] block %d (%s) orphaned while queued"
2140 " -- dropping %s to %s\n", 2178 " -- dropping %s to %s\n",
2141 r.blockHeight, r.blockHash.ToString().substr(0, 14).c_str(), 2179 r.blockHeight, r.blockHash.ToString().substr(0, 14).c_str(),
2142 FormatMoney(r.amount).c_str(), r.address.c_str()); 2180 FormatMoney(r.amount).c_str(), r.address.c_str());
@@ -2180,7 +2218,7 @@ static void PayoutThreadFn(void*)
2180 const std::string reason = 2218 const std::string reason =
2181 strprintf("'%s' is not a valid address, so no transaction" 2219 strprintf("'%s' is not a valid address, so no transaction"
2182 " can pay it", r.address.c_str()); 2220 " can pay it", r.address.c_str());
2183 LogPrint("payout", "[payout] SKIPPED bad address '%s' --" 2221 LogPrintAlways("payout", "[payout] SKIPPED bad address '%s' --"
2184 " %s owed for block %d cannot be paid\n", 2222 " %s owed for block %d cannot be paid\n",
2185 r.address.c_str(), FormatMoney(r.amount).c_str(), 2223 r.address.c_str(), FormatMoney(r.amount).c_str(),
2186 r.blockHeight); 2224 r.blockHeight);
@@ -2316,7 +2354,7 @@ static void PayoutThreadFn(void*)
2316 // described by at least one of them at every instant. 2354 // described by at least one of them at every instant.
2317 RecordPayoutTxid(r, wtx.GetHash().GetHex()); 2355 RecordPayoutTxid(r, wtx.GetHash().GetHex());
2318 ForgetPayment(r); 2356 ForgetPayment(r);
2319 LogPrint("payout", "[payout] paid %s to %s (tx %s)\n", 2357 LogPrintAlways("payout", "[payout] paid %s to %s (tx %s)\n",
2320 FormatMoney(r.amount).c_str(), r.address.c_str(), 2358 FormatMoney(r.amount).c_str(), r.address.c_str(),
2321 wtx.GetHash().ToString().substr(0, 12).c_str()); 2359 wtx.GetHash().ToString().substr(0, 12).c_str());
2322 } else { 2360 } else {
@@ -2374,7 +2412,7 @@ static void PayoutThreadFn(void*)
2374 // going away must not turn the log into one line a minute 2412 // going away must not turn the log into one line a minute
2375 // forever, and must not go quiet either. 2413 // forever, and must not go quiet either.
2376 if (r.retries <= 5 || r.retries % 60 == 0) 2414 if (r.retries <= 5 || r.retries % 60 == 0)
2377 LogPrint("payout", "[payout] FAILED to pay %s to %s" 2415 LogPrintAlways("payout", "[payout] FAILED to pay %s to %s"
2378 " (%s spendable, wallet unlocked, block %d on" 2416 " (%s spendable, wallet unlocked, block %d on"
2379 " the main chain) -- attempt %d, retrying in" 2417 " the main chain) -- attempt %d, retrying in"
2380 " 60s; this debt stands until it is paid\n", 2418 " 60s; this debt stands until it is paid\n",
@@ -2582,6 +2620,31 @@ static const double VARDIFF_MAX = 1e12;
2582static const int64 VARDIFF_STALL_SECS = 45; // 3x share target -- reacts faster without false-triggering on normal variance 2620static const int64 VARDIFF_STALL_SECS = 45; // 3x share target -- reacts faster without false-triggering on normal variance
2583static const double VARDIFF_STALL_CUT = 4.0; // divide difficulty by this much 2621static const double VARDIFF_STALL_CUT = 4.0; // divide difficulty by this much
2584 2622
2623// #7: m->hashRate is an EWMA sampled only when a share arrives, so a miner
2624// that stops hashing keeps its last estimate forever and RefreshStats sums
2625// it into the announced pool total for as long as the connection sits open
2626// -- the published pool hashrate ran several times over ground truth
2627// because of exactly this. MinerReportedHashRate() below applies the
2628// policy: a miner gets a grace of HASHRATE_IDLE_MISSES expected share
2629// intervals (expected interval = expected hashes per share at its
2630// difficulty, divided by the estimate itself) with no share, after which
2631// the figure we report falls off with a half-life of one more such
2632// interval. The interval is clamped to [HASHRATE_MIN_INTERVAL,
2633// HASHRATE_MAX_INTERVAL] so a fast miner at the vardiff floor (expected
2634// interval of milliseconds) is not punished for ordinary share-delivery
2635// jitter, and a very slow miner's grace does not stretch past the point
2636// where its estimate means anything. At the vardiff target of one share
2637// per 15s that is a minute of grace, half the rate reported 75s in, and
2638// nothing reported after about seventeen minutes of silence.
2639static const double HASHRATE_IDLE_MISSES = 4.0; // grace, in expected share intervals
2640static const double HASHRATE_MIN_INTERVAL = 1.0; // seconds; floor for the expected interval
2641static const double HASHRATE_MAX_INTERVAL = 3600.0; // seconds; ceiling for the expected interval
2642// Half-lives past the grace beyond which we report a flat zero. 2^-64 of the
2643// original estimate is not a number anyone needs, and stopping here keeps
2644// pow() from walking down into the denormals for a miner that has been quiet
2645// for hours.
2646static const double HASHRATE_DECAY_CUTOFF = 64.0;
2647
2585struct Miner { 2648struct Miner {
2586 btf_socket_t fd; 2649 btf_socket_t fd;
2587 bool authorised = false; 2650 bool authorised = false;
@@ -2609,11 +2672,80 @@ struct Miner {
2609 int64 lastShareTime = 0; // GetTime() of the previous accepted share 2672 int64 lastShareTime = 0; // GetTime() of the previous accepted share
2610 double hashRate = 0.0; // smoothed H/s estimate 2673 double hashRate = 0.0; // smoothed H/s estimate
2611 2674
2675 // Replay guard for mining.submit (#8): nonces already credited on this
2676 // connection for the job it is currently working. Keyed to the job id in
2677 // seenNoncesJob and cleared by SendJob whenever that id changes, so a
2678 // resubmission under a NEW job is never turned away, while a replayed
2679 // (job_id, nonce) pair under the same job is refused before it can be
2680 // credited twice into roundShareCount -- the figure the payout split
2681 // divides by.
2682 std::set<uint32_t> seenNonces;
2683 std::string seenNoncesJob;
2684
2612 explicit Miner(btf_socket_t f) 2685 explicit Miner(btf_socket_t f)
2613 : fd(f), connectTime(GetTime()), 2686 : fd(f), connectTime(GetTime()),
2614 extranonce2(gNextExtranonce2.fetch_add(1)) {} 2687 extranonce2(gNextExtranonce2.fetch_add(1)) {}
2615}; 2688};
2616 2689
2690// What we publish as a miner's H/s: the last EWMA sample, faded out if shares
2691// have stopped arriving (#7, policy at HASHRATE_IDLE_MISSES).
2692//
2693// This reads m->hashRate and never writes it. That is the whole design. The
2694// first attempt decayed the stored estimate in place from the event loop's
2695// sweep, which put a running accumulator behind a figure that is only ever
2696// displayed, and the accumulator misbehaved in two ways:
2697//
2698// - `expected` was recomputed from the already-decayed estimate on every
2699// pass, so each decay raised `expected`, which raised `grace`, which is
2700// the very thing gating the next decay. `grace` simply chased `silent`
2701// upward and the reported rate settled into a 1/t crawl instead of the
2702// half-life curve the comment above promises -- 291x too high at ten
2703// half-lives past the grace. Issue #7 is about the pool over-reporting;
2704// that under-corrected it for hours.
2705// - Once `expected` reached HASHRATE_MAX_INTERVAL it could not rise any
2706// further, the feedback that had been gating each pass was gone, and the
2707// decay began compounding once a second against the total elapsed
2708// silence -- taking a miner from 0.4% of its baseline to 1e-11 of it in
2709// the next hundred seconds, four hours in, for no reason a reader of
2710// either the code or the announced number could see.
2711//
2712// Computing the value instead of accumulating it removes the failure mode
2713// rather than tuning it: with no stored decay state there is nothing for a
2714// tick rate, a missed pass or a duplicated pass to perturb, and the answer
2715// depends only on how long the miner has actually been quiet. It also keeps
2716// the fade out of the estimator -- the EWMA on the share path still blends
2717// against the value it last computed, not against a faded copy of it, so a
2718// miner that resumes recovers on exactly the curve it would have without any
2719// of this.
2720//
2721// `now` is a parameter rather than a GetTime() call so that one refresh fades
2722// every miner to the same instant, and so the policy is directly testable.
2723static double MinerReportedHashRate(const Miner* m, int64 now)
2724{
2725 // Nothing sampled yet: a fresh connection, or one that has found a single
2726 // share and so has no interval to have been timed over. Nothing to fade,
2727 // and nothing to divide by below.
2728 if (m->hashRate <= 0.0 || m->lastShareTime <= 0) return m->hashRate;
2729
2730 double expected = ExpectedHashesForDifficulty(m->difficulty) / m->hashRate;
2731 // Written so that a NaN would land on the floor rather than sail through:
2732 // the clamp is what guarantees `expected` is finite and strictly positive
2733 // below, whatever the division produced.
2734 if (!(expected > HASHRATE_MIN_INTERVAL)) expected = HASHRATE_MIN_INTERVAL;
2735 if (expected > HASHRATE_MAX_INTERVAL) expected = HASHRATE_MAX_INTERVAL;
2736
2737 double silent = (double)(now - m->lastShareTime);
2738 double grace = HASHRATE_IDLE_MISSES * expected;
2739 // grace is at least HASHRATE_IDLE_MISSES seconds, so a clock that has
2740 // stepped backwards gives a negative `silent`, takes this branch, and
2741 // reports the sample unchanged. Nothing here can scale an estimate up.
2742 if (!(silent > grace)) return m->hashRate;
2743
2744 double halflives = (silent - grace) / expected;
2745 if (halflives >= HASHRATE_DECAY_CUTOFF) return 0.0;
2746 return m->hashRate * pow(0.5, halflives);
2747}
2748
2617static std::vector<Miner*> gMiners; 2749static std::vector<Miner*> gMiners;
2618 2750
2619struct FoundBlock { int height; int64 ts; std::string addr; }; 2751struct FoundBlock { int height; int64 ts; std::string addr; };
@@ -2664,6 +2796,18 @@ static void LocalAcceptFn(void*)
2664 break; 2796 break;
2665 continue; 2797 continue;
2666 } 2798 }
2799 // #6: let the OS probe a peer that has gone silent, so a half-open
2800 // session eventually errors out of recv and lands in the event
2801 // loop's existing reap path instead of sitting in gMiners forever.
2802 // This is a backstop, not the mechanism: the default cadence before
2803 // the first probe is hours on most stacks, so the idle timeout in
2804 // PoolEventLoop fires long before keepalive does. Miners arriving
2805 // via a relay ride a loopback socket pair whose remote transport is
2806 // the rendezvous socket owned by the tunnel pump threads; keepalive
2807 // cannot reach across that, which is part of why the idle timeout
2808 // exists.
2809 int keepalive = 1;
2810 setsockopt(c, SOL_SOCKET, SO_KEEPALIVE, (char*)&keepalive, sizeof(keepalive));
2667 LogPrint("pool", "[pool] miner arrived via loopback -- pushing to event loop\n"); 2811 LogPrint("pool", "[pool] miner arrived via loopback -- pushing to event loop\n");
2668 PushReady((btf_socket_t)c); 2812 PushReady((btf_socket_t)c);
2669 } 2813 }
@@ -2707,6 +2851,16 @@ static const int64 POOL_ACTIVE_WINDOW = 300; // a miner is "active" if it
2707static const int64 POOL_UNAUTH_GRACE_SECS = 60; // a connection still not 2851static const int64 POOL_UNAUTH_GRACE_SECS = 60; // a connection still not
2708 // authorized after this long is 2852 // authorized after this long is
2709 // idle, not merely starting up 2853 // idle, not merely starting up
2854// #6: a Miner used to leave gMiners only when RecvLine reported a clean
2855// disconnect. A half-open session (miner host died, NAT state expired,
2856// cable pulled) sends no FIN and reports no error, so it sat in the table
2857// forever -- authorize outpaced disconnect 2:1 on the live pool, and the
2858// table grew toward MAX_POOL_MINERS, past which real miners are refused.
2859// lastSeen is stamped on every complete line received; a miner that has
2860// said nothing for this long is gone in every way that matters. Ten
2861// minutes is far beyond the vardiff target (a share every 15s) and the
2862// stall watchdog (45s), so no miner that is actually hashing comes close.
2863static const int64 POOL_IDLE_TIMEOUT_SECS = 600;
2710 2864
2711// Non-blocking recv: pull whatever bytes are available now into buf, then 2865// Non-blocking recv: pull whatever bytes are available now into buf, then
2712// return one complete line if one is ready. Three outcomes: 2866// return one complete line if one is ready. Three outcomes:
@@ -2791,6 +2945,17 @@ static json MakeNotifyParams(const StratumJob& job, const CBlock& b,
2791static void SendJob(Miner* m, bool clean) 2945static void SendJob(Miner* m, bool clean)
2792{ 2946{
2793 if (!gHaveJob) return; 2947 if (!gHaveJob) return;
2948 // Every path that hands a miner a new job funnels through here, so this
2949 // is the one place the replay guard needs to follow the job id: nonces
2950 // credited under the previous job mean nothing under the new one. Keying
2951 // the clear to the id (rather than clearing unconditionally) keeps a
2952 // same-job re-notify -- the vardiff retarget and stall watchdog both
2953 // re-send the CURRENT job -- from reopening the duplicate window it
2954 // exists to close.
2955 if (m->seenNoncesJob != gCurrentJob.jobId) {
2956 m->seenNonces.clear();
2957 m->seenNoncesJob = gCurrentJob.jobId;
2958 }
2794 CBlock mb = BuildMinerBlock(gCurrentJob, m->extranonce2); 2959 CBlock mb = BuildMinerBlock(gCurrentJob, m->extranonce2);
2795 // Use this miner's own shareTarget (set by vardiff) in the notify params. 2960 // Use this miner's own shareTarget (set by vardiff) in the notify params.
2796 // The participant miner reads p[3] as its share target, and HandleLine 2961 // The participant miner reads p[3] as its share target, and HandleLine
@@ -3049,6 +3214,22 @@ static bool HandleLine(Miner* m, const std::string& rawLine,
3049 } 3214 }
3050 unsigned int nNonce; memcpy(&nNonce, nb.data(), 4); 3215 unsigned int nNonce; memcpy(&nNonce, nb.data(), 4);
3051 3216
3217 // Reject a replayed (job, nonce) before it costs a rebuild and a
3218 // RandomX hash: nothing about the work below distinguishes a second
3219 // submission of a valid share from the first, so without this check
3220 // it passes every test and is credited again -- and roundShareCount
3221 // is what the payout split divides by, so each replay multiplies the
3222 // address's cut of the round. The set is per-connection and cleared
3223 // by SendJob on every job change, so only a same-job repeat is
3224 // refused.
3225 if (m->seenNonces.count(nNonce)) {
3226 LogPrint("worker", "[worker->pool] duplicate share from %s"
3227 " nonce=%u job=%s -- already credited, not counting again\n",
3228 m->address.c_str(), nNonce, submitJobId.c_str());
3229 reply(false, "Duplicate share");
3230 return true;
3231 }
3232
3052 // Rebuild this miner's exact block (unique merkle via extranonce2) 3233 // Rebuild this miner's exact block (unique merkle via extranonce2)
3053 CBlock b = BuildMinerBlock(gCurrentJob, m->extranonce2); 3234 CBlock b = BuildMinerBlock(gCurrentJob, m->extranonce2);
3054 b.nNonce = nNonce; 3235 b.nNonce = nNonce;
@@ -3076,6 +3257,7 @@ static bool HandleLine(Miner* m, const std::string& rawLine,
3076 m->roundShares++; 3257 m->roundShares++;
3077 m->totalShares++; 3258 m->totalShares++;
3078 m->vardiffShares++; 3259 m->vardiffShares++;
3260 m->seenNonces.insert(nNonce); // replay guard: credit each nonce once per job
3079 int64 shareTime = GetTime(); 3261 int64 shareTime = GetTime();
3080 m->lastSeen = shareTime; 3262 m->lastSeen = shareTime;
3081 roundShareCount[m->address]++; 3263 roundShareCount[m->address]++;
@@ -4938,6 +5120,82 @@ int RunPoolStratumSelfTest()
4938 strPoolRoundsFile = savedRoundsFile; 5120 strPoolRoundsFile = savedRoundsFile;
4939 gPoolRounds = savedRounds; 5121 gPoolRounds = savedRounds;
4940 5122
5123 // -- hashrate decay (#7) --------------------------------------------------
5124 // The first version of this decayed m->hashRate in place from the event
5125 // loop's sweep, which made the reported figure a function of how the loop
5126 // happened to run rather than of how long the miner had been quiet. These
5127 // pin the properties that fixes: sampling changes nothing, and the answer
5128 // depends only on elapsed silence.
5129 {
5130 // A miner exactly on the vardiff target: 4096 hashes per share at
5131 // difficulty 1.0, one share per 15s, so 4096/15 H/s. Its expected
5132 // interval is 15s and its grace is 60s.
5133 const double base = 4096.0 / 15.0;
5134 const int64 t0 = 1766000000; // any plausible non-zero wall clock
5135 Miner decayed(INVALID_SOCKET);
5136 decayed.difficulty = 1.0;
5137 decayed.hashRate = base;
5138 decayed.lastShareTime = t0;
5139
5140 check(MinerReportedHashRate(&decayed, t0 + 60) == base,
5141 "hashrate decay: a miner inside its grace period reports its full estimate");
5142
5143 // Sampling must not consume the estimate. Twenty passes is one second
5144 // of the event loop's old sweep; a thousand is nearly a minute of it.
5145 double once = MinerReportedHashRate(&decayed, t0 + 61);
5146 bool idempotent = (decayed.hashRate == base);
5147 for (int i = 0; i < 1000 && idempotent; i++)
5148 idempotent = (MinerReportedHashRate(&decayed, t0 + 61) == once) &&
5149 (decayed.hashRate == base);
5150 check(idempotent,
5151 "hashrate decay: repeated sampling returns one value and leaves the estimate alone");
5152
5153 // One second past a 60s grace is 1/15th of a half-life: ~4.5% off, not
5154 // the estimate gone. A miner at the vardiff target overshoots its grace
5155 // roughly 1.8% of the time (e^-4) purely by share-timing variance, and
5156 // must not be zeroed for it.
5157 check(once > 0.94 * base && once < 0.96 * base,
5158 "hashrate decay: one second past grace costs a few percent, not the estimate");
5159 double three = MinerReportedHashRate(&decayed, t0 + 63);
5160 check(three > 0.86 * base && three < 0.88 * base,
5161 "hashrate decay: three seconds past grace costs ~13%");
5162
5163 // One half-life past the grace is exactly half.
5164 double half = MinerReportedHashRate(&decayed, t0 + 75);
5165 check(half > 0.499 * base && half < 0.501 * base,
5166 "hashrate decay: one expected interval past grace halves the estimate");
5167
5168 // A miner that has genuinely stopped ends up reported as nothing --
5169 // the whole point of #7. The old in-place version could not get here:
5170 // its decay fed back into its own grace and settled into a 1/t crawl.
5171 check(MinerReportedHashRate(&decayed, t0 + 3600) == 0.0,
5172 "hashrate decay: a miner silent for an hour is reported as zero");
5173
5174 // A clock that steps backwards must never inflate what we announce.
5175 check(MinerReportedHashRate(&decayed, t0 - 3600) == base,
5176 "hashrate decay: a backwards clock reports the estimate unchanged, never higher");
5177
5178 // Fresh connection, and a connection with one share and so no interval
5179 // to have timed: both must report nothing rather than divide by zero.
5180 Miner fresh(INVALID_SOCKET);
5181 check(MinerReportedHashRate(&fresh, t0) == 0.0,
5182 "hashrate decay: a miner that never submitted a share reports zero");
5183 Miner single(INVALID_SOCKET);
5184 single.lastShareTime = t0;
5185 check(MinerReportedHashRate(&single, t0 + 86400) == 0.0,
5186 "hashrate decay: a miner with no rate sample yet reports zero");
5187
5188 // Nothing in the swept range may produce a NaN, an infinity, a negative
5189 // rate, or a rate above the estimate it started from.
5190 bool finite = true;
5191 for (int64 s = -100; s < 200000 && finite; s += 37) {
5192 double v = MinerReportedHashRate(&decayed, t0 + s);
5193 finite = !std::isnan(v) && !std::isinf(v) && v >= 0.0 && v <= base;
5194 }
5195 check(finite,
5196 "hashrate decay: stays finite, non-negative and non-amplifying across a long silence");
5197 }
5198
4941 gCurrentJob = savedJob; 5199 gCurrentJob = savedJob;
4942 gHaveJob = savedHaveJob; 5200 gHaveJob = savedHaveJob;
4943 5201
@@ -4965,6 +5223,10 @@ static void RefreshStats(int blocksFoundThisSession, uint64 roundShareTotal)
4965 if (m->authorised) gStats.authorizedMiners++; 5223 if (m->authorised) gStats.authorizedMiners++;
4966 5224
4967 gWorkerStats.clear(); 5225 gWorkerStats.clear();
5226 // One timestamp for the whole sweep (#7): every miner is faded to the
5227 // same instant, so the per-worker rows and the total they are summed
5228 // into describe one moment rather than a smear across the loop.
5229 int64 nowStats = GetTime();
4968 for (Miner* m : gMiners) { 5230 for (Miner* m : gMiners) {
4969 if (!m->authorised || m->lastSeen <= 0) continue; 5231 if (!m->authorised || m->lastSeen <= 0) continue;
4970 PoolWorkerStatView v; 5232 PoolWorkerStatView v;
@@ -4973,9 +5235,11 @@ static void RefreshStats(int blocksFoundThisSession, uint64 roundShareTotal)
4973 v.roundShares = m->roundShares; 5235 v.roundShares = m->roundShares;
4974 v.totalShares = m->totalShares; 5236 v.totalShares = m->totalShares;
4975 v.lastSeen = m->lastSeen; 5237 v.lastSeen = m->lastSeen;
4976 v.hashRate = m->hashRate; 5238 // Not m->hashRate: a miner that has stopped submitting shares must
5239 // not keep contributing its last sample to the announced total.
5240 v.hashRate = MinerReportedHashRate(m, nowStats);
4977 gWorkerStats.push_back(v); 5241 gWorkerStats.push_back(v);
4978 gStats.totalHashRate += m->hashRate; 5242 gStats.totalHashRate += v.hashRate;
4979 } 5243 }
4980 std::sort(gWorkerStats.begin(), gWorkerStats.end(), 5244 std::sort(gWorkerStats.begin(), gWorkerStats.end(),
4981 [](const PoolWorkerStatView& a, const PoolWorkerStatView& b) { 5245 [](const PoolWorkerStatView& a, const PoolWorkerStatView& b) {
@@ -5208,6 +5472,35 @@ static void PoolEventLoop()
5208 } 5472 }
5209 } 5473 }
5210 5474
5475 // 3.6. Idle reap (#6). Mirror the clean-disconnect path exactly --
5476 // log, close, erase from gMiners via std::find, delete -- just with
5477 // a different reason. Shares the miner already earned stay in
5478 // roundShareCount, exactly as they do when a miner cleanly
5479 // disconnects mid-round. connectTime stands in for lastSeen on a
5480 // connection that never completed a line. Erasing inside the loop
5481 // above would invalidate the iteration, so collect then reap.
5482 {
5483 int64 now = GetTime();
5484 std::vector<Miner*> idle;
5485 for (Miner* m : gMiners) {
5486 int64 last = (m->lastSeen > 0) ? m->lastSeen : m->connectTime;
5487 if (now - last > POOL_IDLE_TIMEOUT_SECS)
5488 idle.push_back(m);
5489 }
5490 for (Miner* m : idle) {
5491 LogPrint("worker", "[pool] dropping idle miner %s -- nothing"
5492 " received in over %llds (session shares: %llu,"
5493 " round shares: %llu)\n",
5494 m->worker.empty() ? "(never authorized)" : m->worker.c_str(),
5495 (long long)POOL_IDLE_TIMEOUT_SECS,
5496 (unsigned long long)m->sessionShares,
5497 (unsigned long long)m->roundShares);
5498 sock_close(m->fd);
5499 gMiners.erase(std::find(gMiners.begin(), gMiners.end(), m));
5500 delete m;
5501 }
5502 }
5503
5211 // 4. Select over miner sockets 5504 // 4. Select over miner sockets
5212 if (!gMiners.empty()) { 5505 if (!gMiners.empty()) {
5213 fd_set fds; FD_ZERO(&fds); 5506 fd_set fds; FD_ZERO(&fds);
@@ -5230,6 +5523,11 @@ static void PoolEventLoop()
5230 // terminate the whole node -- not just the pool. Every 5523 // terminate the whole node -- not just the pool. Every
5231 // line arrives from an unauthenticated socket. 5524 // line arrives from an unauthenticated socket.
5232 while (RecvLine(m->fd, m->readBuf, line, disc)) { 5525 while (RecvLine(m->fd, m->readBuf, line, disc)) {
5526 // Any complete line is proof of life (#6): authorize
5527 // and valid shares already stamp lastSeen themselves,
5528 // but a miner that only ever subscribes (or sends
5529 // unrecognised methods) must count as alive too.
5530 m->lastSeen = GetTime();
5233 try { 5531 try {
5234 HandleLine(m, line, roundShareCount, 5532 HandleLine(m, line, roundShareCount,
5235 roundShareTotal, blocksFoundThisSession); 5533 roundShareTotal, blocksFoundThisSession);
@@ -5306,13 +5604,19 @@ static void AcceptOneFn(void* arg)
5306 std::string host = relay.substr(0, colon); 5604 std::string host = relay.substr(0, colon);
5307 int port = atoi(relay.substr(colon + 1).c_str()); 5605 int port = atoi(relay.substr(colon + 1).c_str());
5308 5606
5309 LogPrint("pool", "[pool] accept thread started for relay %s\n", relay.c_str()); 5607 LogPrint("pool", "[pool] accept thread started for relay %s%s\n", relay.c_str(),
5608 fBtfRelayPinned ? " (/rvrelay pin)" : "");
5609
5610 // Registration health for this relay. A pin has no fallback, so a pin that
5611 // never registers means the pool is simply unreachable -- and that has to
5612 // be loud. The 2026-07-30 incident went unnoticed because this loop logged
5613 // failures at one flat line and success not at all, so "which relay is this
5614 // pool actually registered at" could not be answered from the log.
5615 int nConsecFail = 0;
5616 int64 nFirstFail = 0;
5617 bool fEverRegistered = false;
5310 5618
5311 while (!fShutdown && gPoolRunning) { 5619 while (!fShutdown && gPoolRunning) {
5312 // Advertise this relay as the pool's meeting node BEFORE registering,
5313 // so that miners which resolve our descriptor find a relay where the
5314 // pool (not the node's peer-accept) holds the registration.
5315 BtfSetActiveRelay(relay);
5316 // Returns as soon as the relay lists us -- registered, not yet paired. 5620 // Returns as soon as the relay lists us -- registered, not yet paired.
5317 btf::RvSocket rv = btf::RvServiceRegister(host.c_str(), (unsigned short)port, pk); 5621 btf::RvSocket rv = btf::RvServiceRegister(host.c_str(), (unsigned short)port, pk);
5318 5622
@@ -5321,12 +5625,36 @@ static void AcceptOneFn(void* arg)
5321 break; 5625 break;
5322 } 5626 }
5323 if (rv == btf::RV_INVALID) { 5627 if (rv == btf::RV_INVALID) {
5324 LogPrint("pool", "[pool] relay %s: RvServiceRegister failed" 5628 nConsecFail++;
5325 " -- backing off 30s before retry\n", relay.c_str()); 5629 if (nFirstFail == 0) nFirstFail = GetTime();
5630 LogPrint("pool", "[pool] relay %s: registration failed (attempt %d,"
5631 " failing for %llds) -- backing off 30s before retry\n",
5632 relay.c_str(), nConsecFail, (long long)(GetTime() - nFirstFail));
5633 if (fBtfRelayPinned && (nConsecFail == 3 || nConsecFail % 10 == 0))
5634 LogPrint("pool", "[pool] WARNING: pinned relay %s refused registration"
5635 " %d times running (%llds); /rvrelay leaves no fallback, so"
5636 " miners cannot reach this pool%s\n",
5637 relay.c_str(), nConsecFail, (long long)(GetTime() - nFirstFail),
5638 fEverRegistered ? "" : " -- it has never registered once");
5326 for (int i = 0; i < 30 && !fShutdown && gPoolRunning; i++) Sleep(1000); 5639 for (int i = 0; i < 30 && !fShutdown && gPoolRunning; i++) Sleep(1000);
5327 continue; 5640 continue;
5328 } 5641 }
5329 5642
5643 // Advertise THIS relay only now. Setting it before the call published a
5644 // meeting node we were not yet listed at, so a miner resolving the
5645 // descriptor inside that window burned its dial on a relay holding no
5646 // registration for us. net.cpp's peer-accept has always ordered it this
5647 // way round; the pool had not.
5648 BtfSetActiveRelay(relay);
5649 if (!fEverRegistered || nConsecFail > 0)
5650 LogPrint("pool", "[pool] registered at relay %s%s%s -- advertising it as"
5651 " the pool's meeting node\n", relay.c_str(),
5652 fBtfRelayPinned ? " (/rvrelay pin)" : "",
5653 nConsecFail > 0 ? ", recovered" : "");
5654 fEverRegistered = true;
5655 nConsecFail = 0;
5656 nFirstFail = 0;
5657
5330 // Block for a miner to actually arrive. RvServiceRegister used to do 5658 // Block for a miner to actually arrive. RvServiceRegister used to do
5331 // this itself and returned with the relay's 0x01 pairing byte already 5659 // this itself and returned with the relay's 0x01 pairing byte already
5332 // consumed; it no longer does. Without waiting here, BtfServiceWrap 5660 // consumed; it no longer does. Without waiting here, BtfServiceWrap
@@ -5381,9 +5709,21 @@ static void AcceptLoopFn(void*)
5381 LogPrint("pool", "[pool] .btf identity ready after %ds\n", waitSecs * 2); 5709 LogPrint("pool", "[pool] .btf identity ready after %ds\n", waitSecs * 2);
5382 5710
5383 std::set<std::string> spawned; // relays we've already started a thread for 5711 std::set<std::string> spawned; // relays we've already started a thread for
5712 std::set<std::string> skipped; // discovered relays the pin excluded, logged once each
5384 5713
5385 while (!fShutdown && gPoolRunning) { 5714 while (!fShutdown && gPoolRunning) {
5715 // BtfAllRelays() already honours the pin: with /rvrelay set it returns
5716 // vBtfMeetingRelays alone, so no thread is ever spawned for a
5717 // discovered relay. Name the ones it drops -- a pool registering at a
5718 // stranger's relay is exactly the thing that should not be silent.
5386 vector<string> relays = BtfAllRelays(); 5719 vector<string> relays = BtfAllRelays();
5720 if (fBtfRelayPinned) {
5721 for (const string& r : BtfDiscoveredRelays())
5722 if (std::find(relays.begin(), relays.end(), r) == relays.end() &&
5723 skipped.insert(r).second)
5724 LogPrint("pool", "[pool] not registering at discovered relay %s"
5725 " -- /rvrelay pins the relay list\n", r.c_str());
5726 }
5387 if (relays.empty()) { 5727 if (relays.empty()) {
5388 LogPrint("pool", "[pool] no relays available -- miners cannot connect yet\n"); 5728 LogPrint("pool", "[pool] no relays available -- miners cannot connect yet\n");
5389 } else { 5729 } else {
@@ -5399,8 +5739,9 @@ static void AcceptLoopFn(void*)
5399 relay.c_str()); 5739 relay.c_str());
5400 } else { 5740 } else {
5401 spawned.insert(relay); 5741 spawned.insert(relay);
5402 LogPrint("pool", "[pool] accept thread spawned for relay %s" 5742 LogPrint("pool", "[pool] accept thread spawned for relay %s%s"
5403 " (%zu total)\n", relay.c_str(), spawned.size()); 5743 " (%zu total)\n", relay.c_str(),
5744 fBtfRelayPinned ? " (/rvrelay pin)" : "", spawned.size());
5404 } 5745 }
5405 } 5746 }
5406 } 5747 }
@@ -5436,10 +5777,17 @@ void ThreadRPCServer(void*)
5436 // armed for its one wallet probe before it is allowed to send. 5777 // armed for its one wallet probe before it is allowed to send.
5437 ReconcilePayouts(); 5778 ReconcilePayouts();
5438 5779
5439 _beginthread(AcceptLoopFn, 0, NULL); 5780 // _beginthread cannot throw (it reports -1), but an unchecked failure
5440 _beginthread(LocalAcceptFn, 0, NULL); 5781 // leaves the pool running deaf: nobody accepts, announces, or pays, and
5441 _beginthread(ThreadBtfPoolAnnouncer, 0, NULL); 5782 // nothing in the log says why.
5442 _beginthread(PayoutThreadFn, 0, NULL); 5783 if (_beginthread(AcceptLoopFn, 0, NULL) == (uintptr_t)-1)
5784 LogPrint("pool", "[pool] FATAL: accept loop thread failed to spawn -- miners cannot connect\n");
5785 if (_beginthread(LocalAcceptFn, 0, NULL) == (uintptr_t)-1)
5786 LogPrint("pool", "[pool] local accept thread failed to spawn\n");
5787 if (_beginthread(ThreadBtfPoolAnnouncer, 0, NULL) == (uintptr_t)-1)
5788 LogPrint("pool", "[pool] announcer thread failed to spawn -- pool will not be advertised\n");
5789 if (_beginthread(PayoutThreadFn, 0, NULL) == (uintptr_t)-1)
5790 LogPrint("pool", "[pool] FATAL: payout thread failed to spawn -- no one gets paid\n");
5443 5791
5444 PoolEventLoop(); // blocks until gPoolRunning = false or fShutdown 5792 PoolEventLoop(); // blocks until gPoolRunning = false or fShutdown
5445 5793
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
9bool fDebug = false; 9bool fDebug = false;
10bool 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.
15int64 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.
39static bool LogCategoryVerboseOnly(const char* category)
40{
41 return strcmp(category, "relay") == 0 ||
42 strcmp(category, "nostrdiscovery") == 0;
43}
44
29bool LogAcceptsCategory(const char* category) 45bool 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 {
47static std::map<std::string, LogDedupState> g_logDedup; 65static std::map<std::string, LogDedupState> g_logDedup;
48static CCriticalSection cs_logDedup; 66static 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.
70struct 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
77static int64 g_logDedupLastSweep = 0;
78
79static 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.
100static 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
50void LogPrintDedup(const char* category, const char* file, int line, const std::string& msgIn) 123void 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.
194void 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
400int 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).
503static_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.
513int64 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
diff --git a/src/util.h b/src/util.h
index d72518b..dfe7511 100644
--- a/src/util.h
+++ b/src/util.h
@@ -87,6 +87,15 @@ inline T& REF(const T& val)
87 87
88extern bool fDebug; 88extern bool fDebug;
89 89
90// /debugrelay: the per-message firehose ("relay" and "nostrdiscovery"
91// categories) that even -debug keeps off. See LogAcceptsCategory().
92extern 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.
97extern 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// ---------------------------------------------------------------------------
114bool LogAcceptsCategory(const char* category); 134bool LogAcceptsCategory(const char* category);
115void LogPrintDedup(const char* category, const char* file, int line, const std::string& msg); 135void LogPrintDedup(const char* category, const char* file, int line, const std::string& msg);
136void 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);
145string FormatMoney(int64 n, bool fPlus=false); 168string FormatMoney(int64 n, bool fPlus=false);
146bool ParseMoney(const char* pszIn, int64& nRet); 169bool ParseMoney(const char* pszIn, int64& nRet);
147bool FileExists(const char* psz); 170bool FileExists(const char* psz);
148int GetFilesize(FILE* file); 171int64 GetFilesize(FILE* file);
149uint64 GetRand(uint64 nMax); 172uint64 GetRand(uint64 nMax);
150int64 GetTime(); 173int64 GetTime();
151int64 GetAdjustedTime(); 174int64 GetAdjustedTime();
@@ -199,7 +222,7 @@ protected:
199public: 222public:
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;