From ae1c6a7b49d9b4f8cf7218c0baec84f348eb5ef6 Mon Sep 17 00:00:00 2001 From: bitflash-maintainer Date: Wed, 2 Sep 2026 05:26:51 +0000 Subject: log: cap debug.log in-process, and ship a logrotate policy debug.log grew without bound (production: 1.95 GiB, 51-129 MB/day). Nothing shrank it once the process was up -- there is no ShrinkDebugFile in this tree, and upstream's only ran at startup. OutputDebugStringF now rolls the file to debug.log.old when it passes -maxdebugfilesize (MB, default 1024, 0 disables). The write path already opens and closes the file per line under one lock, so the rename-and-reopen is a few lines inside that lock and no fd can be stranded mid-roll. contrib/logrotate/bitflash-debug.logrotate is the longer-term policy (size 1G, rotate 4, compress, missingok, notifempty, copytruncate); copytruncate keeps the writer's append handle valid across rotation. Closes #34 --- src/main_gui.cpp | 15 +++++++++++++++ 1 file changed, 15 insertions(+) (limited to 'src/main_gui.cpp') diff --git a/src/main_gui.cpp b/src/main_gui.cpp index 211e1e2..05f5ecf 100644 --- a/src/main_gui.cpp +++ b/src/main_gui.cpp @@ -111,6 +111,7 @@ static void PrintUsage() printf(" /help, -help, --help, /?\n"); printf(" /datadir=PATH\n"); printf(" /debug\n"); + printf(" /maxdebugfilesize=N (roll debug.log at N MB, default 1024; 0 = never)\n"); printf(" /gen\n"); printf(" /nogui or /daemon\n"); printf(" /selftest=wallet-keypool, wallet-hd, wallet-format, wallet-crypto, wallet-encrypt,\n"); @@ -191,6 +192,20 @@ static void ParseStartupArguments(int argc, char* argv[]) if (arg(argc,argv,"/debug") || arg(argc,argv,"-debug")) fDebug = true; + // /maxdebugfilesize=N -- roll debug.log to debug.log.old once it passes + // N MB, checked on each write. Default is 1024 (see util.cpp); 0 turns + // the check off and leaves rotation entirely to logrotate. + string strMaxDebugSize = argval2(argc, argv, "/maxdebugfilesize", "-maxdebugfilesize"); + if (!strMaxDebugSize.empty()) + { + int64 nMB = atoi64(strMaxDebugSize.c_str()); + if (nMB < 0) + fprintf(stderr, "Ignoring /maxdebugfilesize=%s: not a size in MB\n", + strMaxDebugSize.c_str()); + else + nMaxDebugFileSize = nMB * 1024 * 1024; + } + if (arg(argc,argv,"/gen") || arg(argc,argv,"-gen")) { fGenerateBitcoins = 1; -- cgit v1.2.3 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/main.cpp | 6 +++--- src/main_gui.cpp | 12 ++++++++++++ src/net.h | 22 ++++++++++++++++++---- src/nostr.cpp | 2 +- src/util.cpp | 13 +++++++++++++ src/util.h | 4 ++++ 6 files changed, 51 insertions(+), 8 deletions(-) (limited to 'src/main_gui.cpp') diff --git a/src/main.cpp b/src/main.cpp index 7b3e555..80f5f31 100644 --- a/src/main.cpp +++ b/src/main.cpp @@ -1712,7 +1712,7 @@ void CWalletTx::RelayWalletTransaction(CTxDB& txdb) uint256 hash = GetHash(); if (!txdb.ContainsTx(hash)) { - if (LogAcceptsCategory("net")) printf("Relaying wtx %s\n", hash.ToString().substr(0,6).c_str()); + if (LogAcceptsCategory("relay")) printf("Relaying wtx %s\n", hash.ToString().substr(0,6).c_str()); RelayMessage(CInv(MSG_TX, hash), (CTransaction)*this); } } @@ -3263,7 +3263,7 @@ bool ProcessMessage(CNode* pfrom, string strCommand, CDataStream& vRecv) vRecv >> *pblock; //// debug print - if (LogAcceptsCategory("net")) { printf("received block:\n"); pblock->print(); } + if (LogAcceptsCategory("relay")) { printf("received block:\n"); pblock->print(); } CInv inv(MSG_BLOCK, pblock->GetHash()); pfrom->AddInventoryKnown(inv); @@ -4555,7 +4555,7 @@ bool BitcoinMiner(int nThreadId) //// debug print if (LogAcceptsCategory("net")) printf("BitcoinMiner:\n"); if (LogAcceptsCategory("net")) printf("RandomX proof-of-work found \n powhash: %s \ntarget: %s\n", hash.GetHex().c_str(), hashTarget.GetHex().c_str()); - if (LogAcceptsCategory("net")) pblock->print(); + if (LogAcceptsCategory("relay")) pblock->print(); SetThreadPriority(GetCurrentThread(), THREAD_PRIORITY_NORMAL); CRITICAL_BLOCK(cs_main) diff --git a/src/main_gui.cpp b/src/main_gui.cpp index 05f5ecf..163d78e 100644 --- a/src/main_gui.cpp +++ b/src/main_gui.cpp @@ -111,6 +111,7 @@ static void PrintUsage() printf(" /help, -help, --help, /?\n"); printf(" /datadir=PATH\n"); printf(" /debug\n"); + printf(" /debugrelay (/debug plus per-message relay chatter and block dumps)\n"); printf(" /maxdebugfilesize=N (roll debug.log at N MB, default 1024; 0 = never)\n"); printf(" /gen\n"); printf(" /nogui or /daemon\n"); @@ -192,6 +193,17 @@ static void ParseStartupArguments(int argc, char* argv[]) if (arg(argc,argv,"/debug") || arg(argc,argv,"-debug")) fDebug = true; + // /debugrelay -- everything /debug shows, plus the per-message firehose + // ("relay" and "nostrdiscovery" categories: sending: tx, Relaying wtx, + // raw CBlock dumps, per-peer discovery lines). That traffic was ~90% of + // a 13-hour production debug.log (issue #35), so plain /debug leaves it + // off; the message text itself is unchanged for anyone grepping it. + if (arg(argc,argv,"/debugrelay") || arg(argc,argv,"-debugrelay")) + { + fDebug = true; + fDebugRelay = true; + } + // /maxdebugfilesize=N -- roll debug.log to debug.log.old once it passes // N MB, checked on each write. Default is 1024 (see util.cpp); 0 turns // the check off and leaves rotation entirely to logrotate. diff --git a/src/net.h b/src/net.h index 9f3c7e4..1aee973 100644 --- a/src/net.h +++ b/src/net.h @@ -802,6 +802,18 @@ public: + // "sending: tx (N bytes)" alone was ~71% of a 13-hour production + // debug.log (issue #35), so tx sends are demoted to the /debugrelay-gated + // "relay" category; every other command's send trace stays on "net". + // The line is emitted in pieces across BeginMessage/EndMessage/ + // AbortMessage, so all three must agree on the category or orphaned + // "(N bytes)" fragments would leak into a plain -debug log. + // Valid only mid-message (nPushPos != -1). + const char* SendLogCategory() const + { + return strcmp(GetMessageCommand(), "tx") == 0 ? "relay" : "net"; + } + void BeginMessage(const char* pszCommand) { EnterCriticalSection(&cs_vSend); @@ -809,17 +821,19 @@ public: AbortMessage(); nPushPos = vSend.size(); vSend << CMessageHeader(pszCommand, 0); - if (LogAcceptsCategory("net")) printf("sending: %-12s ", pszCommand); + if (LogAcceptsCategory(SendLogCategory())) printf("sending: %-12s ", pszCommand); } void AbortMessage() { if (nPushPos == -1) return; + // Capture before nPushPos is cleared; GetMessageCommand() needs it. + const char* pszCategory = SendLogCategory(); vSend.resize(nPushPos); nPushPos = -1; LeaveCriticalSection(&cs_vSend); - if (LogAcceptsCategory("net")) printf("(aborted)\n"); + if (LogAcceptsCategory(pszCategory)) printf("(aborted)\n"); } void EndMessage() @@ -839,10 +853,10 @@ public: unsigned int nSize = vSend.size() - nPushPos - sizeof(CMessageHeader); memcpy((char*)&vSend[nPushPos] + offsetof(CMessageHeader, nMessageSize), &nSize, sizeof(nSize)); - if (LogAcceptsCategory("net")) printf("(%d bytes) ", nSize); + if (LogAcceptsCategory(SendLogCategory())) printf("(%d bytes) ", nSize); //for (int i = nPushPos+sizeof(CMessageHeader); i < min(vSend.size(), nPushPos+sizeof(CMessageHeader)+20U); i++) // printf("%02x ", vSend[i] & 0xff); - if (LogAcceptsCategory("net")) printf("\n"); + if (LogAcceptsCategory(SendLogCategory())) printf("\n"); nPushPos = -1; LeaveCriticalSection(&cs_vSend); 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") diff --git a/src/util.cpp b/src/util.cpp index 52cda84..a5a4e80 100644 --- a/src/util.cpp +++ b/src/util.cpp @@ -7,6 +7,7 @@ bool fDebug = false; +bool fDebugRelay = false; // In-process cap for debug.log, in bytes. Default matches the 1G trigger of // the shipped logrotate policy so a long-running node stays bounded even @@ -31,10 +32,22 @@ static bool LogCategoryDefaultOn(const char* category) strcmp(category, "payout") == 0; } +// Categories so noisy they drown out everything else even under -debug: +// per-message send traces, wallet relay rebroadcasts, raw CBlock dumps and +// per-address discovery lines made up ~90% of a 13-hour production capture +// (issue #35). They need /debugrelay, not merely /debug. +static bool LogCategoryVerboseOnly(const char* category) +{ + return strcmp(category, "relay") == 0 || + strcmp(category, "nostrdiscovery") == 0; +} + bool LogAcceptsCategory(const char* category) { if (LogCategoryDefaultOn(category)) return true; + if (LogCategoryVerboseOnly(category)) + return fDebugRelay; return fDebug; } diff --git a/src/util.h b/src/util.h index f2ea23f..c47b8a7 100644 --- a/src/util.h +++ b/src/util.h @@ -87,6 +87,10 @@ inline T& REF(const T& val) extern bool fDebug; +// /debugrelay: the per-message firehose ("relay" and "nostrdiscovery" +// categories) that even -debug keeps off. See LogAcceptsCategory(). +extern bool fDebugRelay; + // debug.log is rolled to debug.log.old once it grows past this many bytes // (set from -maxdebugfilesize, in MB; 0 disables the check). See the roll // site in OutputDebugStringF() below. -- cgit v1.2.3 From e3cc976ae3f211727e3fae702776aacca46efb0c Mon Sep 17 00:00:00 2001 From: bitflash-maintainer Date: Wed, 2 Sep 2026 16:42:39 +0000 Subject: log: reject a -maxdebugfilesize that is not a plain count of MB atoi64() is strtoll() with the endptr discarded, so it yields 0 for anything it cannot read. -maxdebugfilesize=1G and -maxdebugfilesize=1024MB both parsed as 0, which the roll reads as "never roll" -- indistinguishable from requesting that deliberately, and silent. An operator who wrote a unit suffix got no rotation and no warning. Only a negative value said anything. The multiplication was unchecked as well: a large enough N made nMB * 1024 * 1024 overflow to a negative cap, which disables the roll too. Parse with strtoll() and its endptr, and reject trailing characters, ERANGE, negatives, and any value that would overflow the byte cap -- each reported with the reason and the cap being kept. 0 still means never roll and is still accepted without comment. --- src/main_gui.cpp | 31 +++++++++++++++++++++++++++---- 1 file changed, 27 insertions(+), 4 deletions(-) (limited to 'src/main_gui.cpp') diff --git a/src/main_gui.cpp b/src/main_gui.cpp index 163d78e..0e64985 100644 --- a/src/main_gui.cpp +++ b/src/main_gui.cpp @@ -210,10 +210,33 @@ static void ParseStartupArguments(int argc, char* argv[]) string strMaxDebugSize = argval2(argc, argv, "/maxdebugfilesize", "-maxdebugfilesize"); if (!strMaxDebugSize.empty()) { - int64 nMB = atoi64(strMaxDebugSize.c_str()); - if (nMB < 0) - fprintf(stderr, "Ignoring /maxdebugfilesize=%s: not a size in MB\n", - strMaxDebugSize.c_str()); + // Parsed with atoi64() before, which is strtoll() with the endptr + // thrown away: it returns 0 for anything it cannot read, so + // /maxdebugfilesize=1G and =1024MB both came out as 0 -- "never + // roll", identical to asking for that on purpose, with nothing said + // to the operator. The old code also multiplied without a range + // check, so a big enough N wrapped to a negative cap, which the roll + // reads as "off" too. Every rejection is now reported and leaves the + // default in place; the value is a plain count of MB, no suffix. + const char* psz = strMaxDebugSize.c_str(); + char* pszEnd = NULL; + errno = 0; + int64 nMB = strtoll(psz, &pszEnd, 10); + // INT64_MAX, without depending on which limits header this tree pulls in. + const int64 nMaxMB = (int64)((~(uint64)0) >> 1) / (1024 * 1024); + const char* pszWhy = NULL; + if (pszEnd == psz) + pszWhy = "not a number"; + else if (*pszEnd != '\0') + pszWhy = "trailing characters -- the value is a count of MB, with no unit suffix"; + else if (errno == ERANGE || nMB < 0) + pszWhy = "not a size in MB"; + else if (nMB > nMaxMB) + pszWhy = "larger than a file size can be"; + if (pszWhy) + fprintf(stderr, "Ignoring /maxdebugfilesize=%s: %s (keeping %lld MB)\n", + strMaxDebugSize.c_str(), pszWhy, + (long long)(nMaxDebugFileSize / 1024 / 1024)); else nMaxDebugFileSize = nMB * 1024 * 1024; } -- cgit v1.2.3