From 2661de141e46dadfb2903bb12e72dc87c5a64375 Mon Sep 17 00:00:00 2001 From: bitflash-maintainer Date: Wed, 2 Sep 2026 05:31:22 +0000 Subject: log: demote the four lines that were 90% of debug.log behind /debugrelay A 13-hour production capture was ~71% "sending: tx", ~16% "Nostr: discovered .btf peer", ~5% "Relaying wtx", and ~43% of raw lines were CBlock/CTransaction dumps -- all already under -debug, which operators run permanently, so -debug was useless as a filter. The category mechanism gains a verbose tier: "relay" and "nostrdiscovery" are accepted only with the new /debugrelay flag (which implies /debug); everything else keeps its current gate. Demoted, with message text unchanged for anyone grepping it: net.h "sending: tx (N bytes)" (BeginMessage/EndMessage/ AbortMessage all pick the category from the command, so no orphaned "(N bytes)" fragments leak into a plain -debug log) main.cpp "Relaying wtx", "received block:" + CBlock::print, and the BitcoinMiner block dump nostr.cpp "Nostr: discovered .btf peer" -> "nostrdiscovery" Pool/worker/payout, [payout], BLOCK ORPHANED/ACCEPTED and share flow lines are untouched. Because LogPrint dedup keys on category, demoted lines also keep their burst collapse under /debugrelay. Closes #35 --- src/nostr.cpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) (limited to 'src/nostr.cpp') diff --git a/src/nostr.cpp b/src/nostr.cpp index e2d839c..9bbf74e 100644 --- a/src/nostr.cpp +++ b/src/nostr.cpp @@ -1440,7 +1440,7 @@ static bool SeedFromRelay(CNostrKey& key, const string& relay) else if (createdAt > it->second) it->second = createdAt; // refresh } if (fNew && fDebug) - LogPrint("nostr", "Nostr: discovered .btf peer %s\n", peerAddr.c_str()); + LogPrint("nostrdiscovery", "Nostr: discovered .btf peer %s\n", peerAddr.c_str()); if (++nPeers > 500) break; } else if (type == "EOSE") -- cgit v1.2.3 From 9a409d8ba97251f29ba80913a4014b8a369c52c0 Mon Sep 17 00:00:00 2001 From: bitflash-maintainer Date: Wed, 2 Sep 2026 14:46:38 +0000 Subject: pool: advertise a rendezvous only once registered, and log the pin Issue #2 reported that /rvrelay does not govern registration. It does: BtfAllRelays() returns vBtfMeetingRelays alone when fBtfRelayPinned, and every relay-choosing site -- the pool's AcceptLoopFn, the node's ThreadBtfAccept, and the dial path -- draws from it. vBtfMeetingRelays has exactly one writer, the pin itself. A pinned pool therefore spawns one accept thread, at the pin, and no discovered relay is registered at. The registration the incident actually caught was not the pool's. The "registered at" line it quotes exists only in ThreadBtfAccept, and 90.156.222.107:8434 is not a stranger's relay -- it is the third hardcoded seed, one of the three ThreadBtfAccept picks between at random when no pin is in force. That relay is only reachable with the pin absent, so the binary that logged it did not have one; both the pin and the operator-mode skip that keeps a pool out of that thread landed two days before the observation. What was genuinely wrong is that none of this could be read off a log. The pool announced no successful registration at all, and retried failures at one flat line, so "is this pool registered where its descriptor says" had no answer. So: - Advertise the relay after registering at it, not before. The optimistic order published a meeting node we were not yet listed at, and a miner resolving the descriptor inside that window spent its dial on a relay holding no registration for us. ThreadBtfAccept has always ordered it this way; the pool had not. - Log the relay registration succeeds at, name the pin when one is in force, and name each discovered relay the pin excludes. - Escalate when a pinned relay keeps refusing: a pin has no fallback, so an unregistered pin means the pool is unreachable, and that now says so instead of scrolling past. - Refuse to advertise a non-pinned relay in BtfSetActiveRelay. No caller can reach it today, but the descriptor is the one thing a miner obeys, so the invariant is enforced at the sink rather than retrusted to every future caller. Does not touch the registration-consumption race: the pool still gives up its registration on each pairing and re-registers after wrap-and-push. Moving the advertise call inside that loop does not widen the window, it only stops the descriptor naming a relay we never reached. --- src/nostr.cpp | 25 ++++++++++++++++++++++++ src/nostr.h | 3 +++ src/rpc.cpp | 61 ++++++++++++++++++++++++++++++++++++++++++++++++++--------- 3 files changed, 80 insertions(+), 9 deletions(-) (limited to 'src/nostr.cpp') diff --git a/src/nostr.cpp b/src/nostr.cpp index e2d839c..0717e12 100644 --- a/src/nostr.cpp +++ b/src/nostr.cpp @@ -151,6 +151,19 @@ string BtfActiveRelay() void BtfSetActiveRelay(const string& relay) { + // With /rvrelay set, the descriptor must never name anything but the pin. + // No caller can reach here with another relay today -- both registration + // paths draw their list from BtfAllRelays(), which returns the pin alone -- + // but the descriptor is the one thing a miner obeys, so the invariant is + // enforced at the sink instead of being retrusted to every future caller. + if (fBtfRelayPinned && + find(vBtfMeetingRelays.begin(), vBtfMeetingRelays.end(), relay) == vBtfMeetingRelays.end()) + { + LogPrint("pool", "refusing to advertise meeting relay %s: /rvrelay pins %s\n", + relay.c_str(), + vBtfMeetingRelays.empty() ? "an empty list" : vBtfMeetingRelays[0].c_str()); + return; + } CRITICAL_BLOCK(cs_activeRelay) strBtfActiveRelay = relay; } @@ -223,6 +236,18 @@ vector BtfAllRelays() return all; } +// Relays learned from Nostr, whether or not a pin is in force. Reporting only: +// it exists so the pool can name what /rvrelay is excluding. Anything choosing +// a relay to register or dial at must keep using BtfAllRelays(). +vector BtfDiscoveredRelays() +{ + vector out; + CRITICAL_BLOCK(cs_discoveredRelays) + foreach(const string& r, g_discoveredRelays) + out.push_back(r); + return out; +} + // // Utilities 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; bool LooksLikeRelay(const std::string& r); // Every relay to try: curated seeds + relays discovered from Nostr announcements. std::vector BtfAllRelays(); +// Relays discovered from Nostr, ignoring the pin. For reporting what a pin +// excludes -- never for choosing a relay to register or dial at. +std::vector BtfDiscoveredRelays(); struct BtfPoolAnnouncement { diff --git a/src/rpc.cpp b/src/rpc.cpp index a4b53ca..a3560ff 100644 --- a/src/rpc.cpp +++ b/src/rpc.cpp @@ -4947,13 +4947,19 @@ static void AcceptOneFn(void* arg) std::string host = relay.substr(0, colon); int port = atoi(relay.substr(colon + 1).c_str()); - LogPrint("pool", "[pool] accept thread started for relay %s\n", relay.c_str()); + LogPrint("pool", "[pool] accept thread started for relay %s%s\n", relay.c_str(), + fBtfRelayPinned ? " (/rvrelay pin)" : ""); + + // Registration health for this relay. A pin has no fallback, so a pin that + // never registers means the pool is simply unreachable -- and that has to + // be loud. The 2026-07-30 incident went unnoticed because this loop logged + // failures at one flat line and success not at all, so "which relay is this + // pool actually registered at" could not be answered from the log. + int nConsecFail = 0; + int64 nFirstFail = 0; + bool fEverRegistered = false; while (!fShutdown && gPoolRunning) { - // Advertise this relay as the pool's meeting node BEFORE registering, - // so that miners which resolve our descriptor find a relay where the - // pool (not the node's peer-accept) holds the registration. - BtfSetActiveRelay(relay); // Returns as soon as the relay lists us -- registered, not yet paired. btf::RvSocket rv = btf::RvServiceRegister(host.c_str(), (unsigned short)port, pk); @@ -4962,12 +4968,36 @@ static void AcceptOneFn(void* arg) break; } if (rv == btf::RV_INVALID) { - LogPrint("pool", "[pool] relay %s: RvServiceRegister failed" - " -- backing off 30s before retry\n", relay.c_str()); + nConsecFail++; + if (nFirstFail == 0) nFirstFail = GetTime(); + LogPrint("pool", "[pool] relay %s: registration failed (attempt %d," + " failing for %llds) -- backing off 30s before retry\n", + relay.c_str(), nConsecFail, (long long)(GetTime() - nFirstFail)); + if (fBtfRelayPinned && (nConsecFail == 3 || nConsecFail % 10 == 0)) + LogPrint("pool", "[pool] WARNING: pinned relay %s refused registration" + " %d times running (%llds); /rvrelay leaves no fallback, so" + " miners cannot reach this pool%s\n", + relay.c_str(), nConsecFail, (long long)(GetTime() - nFirstFail), + fEverRegistered ? "" : " -- it has never registered once"); for (int i = 0; i < 30 && !fShutdown && gPoolRunning; i++) Sleep(1000); continue; } + // Advertise THIS relay only now. Setting it before the call published a + // meeting node we were not yet listed at, so a miner resolving the + // descriptor inside that window burned its dial on a relay holding no + // registration for us. net.cpp's peer-accept has always ordered it this + // way round; the pool had not. + BtfSetActiveRelay(relay); + if (!fEverRegistered || nConsecFail > 0) + LogPrint("pool", "[pool] registered at relay %s%s%s -- advertising it as" + " the pool's meeting node\n", relay.c_str(), + fBtfRelayPinned ? " (/rvrelay pin)" : "", + nConsecFail > 0 ? ", recovered" : ""); + fEverRegistered = true; + nConsecFail = 0; + nFirstFail = 0; + // Block for a miner to actually arrive. RvServiceRegister used to do // this itself and returned with the relay's 0x01 pairing byte already // consumed; it no longer does. Without waiting here, BtfServiceWrap @@ -5022,9 +5052,21 @@ static void AcceptLoopFn(void*) LogPrint("pool", "[pool] .btf identity ready after %ds\n", waitSecs * 2); std::set spawned; // relays we've already started a thread for + std::set skipped; // discovered relays the pin excluded, logged once each while (!fShutdown && gPoolRunning) { + // BtfAllRelays() already honours the pin: with /rvrelay set it returns + // vBtfMeetingRelays alone, so no thread is ever spawned for a + // discovered relay. Name the ones it drops -- a pool registering at a + // stranger's relay is exactly the thing that should not be silent. vector relays = BtfAllRelays(); + if (fBtfRelayPinned) { + for (const string& r : BtfDiscoveredRelays()) + if (std::find(relays.begin(), relays.end(), r) == relays.end() && + skipped.insert(r).second) + LogPrint("pool", "[pool] not registering at discovered relay %s" + " -- /rvrelay pins the relay list\n", r.c_str()); + } if (relays.empty()) { LogPrint("pool", "[pool] no relays available -- miners cannot connect yet\n"); } else { @@ -5040,8 +5082,9 @@ static void AcceptLoopFn(void*) relay.c_str()); } else { spawned.insert(relay); - LogPrint("pool", "[pool] accept thread spawned for relay %s" - " (%zu total)\n", relay.c_str(), spawned.size()); + LogPrint("pool", "[pool] accept thread spawned for relay %s%s" + " (%zu total)\n", relay.c_str(), + fBtfRelayPinned ? " (/rvrelay pin)" : "", spawned.size()); } } } -- cgit v1.2.3