Reduce log noise by ajtowns · Pull Request #34729 · bitcoin/bitcoin

ajtowns · 2026-03-04T11:56:05Z

This set of changes reduces some of the exaggerated logging that was introduced in #29236 when "error()" logging was upgraded from LogPrintf (aka LogInfo) to LogError. It also introduces LogWarnThenDebug() which duplicates the behaviour of #34549 which issues a warning the first time the log line is hit, but downgrades that to categorized debug messages afterwards. This function is used for failures that are likely caused by system configuration problems (so likely degrade the node's functionality and warrant admin attention) but are triggered by remote activity and thus could occur frequently.

This generalises the functionality introduced for PCP/NAT-PMP logging in bitcoin#34549.

This mostly reduces log noise by using BCLog::NET debug logging where possible (with `LogWarnThenDebug()` used to ensure the first log message still appears for things that may be due to system misconfiguration). Also drops some unnecessary trailing newlines.

…lers

DrahtBot · 2026-03-04T11:56:40Z

The following sections might be updated with supplementary metadata relevant to reviewers and maintainers.

Reviews

See the guideline for information on the review process.

Type	Reviewers
ACK	kevkevinpal, ryanofsky

If your review is incorrectly listed, please copy-paste  into the comment that the bot should ignore.

Conflicts

Reviewers, this pull request conflicts with the following ones:

#34778 (logging: rewrite macros to add ratelimit option, avoid unused strprintf, clarify confusing errors by ryanofsky)
#34520 (refactor: Add [[nodiscard]] to functions returning bool+mutable ref by maflcko)
#29256 (log, refactor: Allow log macros to accept context arguments by ryanofsky)

If you consider this pull request important, please also help to review the conflicting pull requests. Ideally, start with the one that should be merged first.

ajtowns · 2026-03-04T11:59:31Z

See #30348 for further background; I think the changes here should be able to stand on their own merits. I haven't addressed cases where there's ambiguity between LogWarning and LogError here, but if there are other current cases where things are at Warning/Error and should be Info, or at Warning/Error/Info and should be Debug, happy to add them to this PR.

kevkevinpal

ACK c665935

This is a good improvement on the amount of functional code dedicated to logging. Also, the LogWarnThenDebug log will be useful in future cases to help avoid log noise

Added two comments about potentially adding BCLog::VALIDATION to the two validation logs touched

src/validation.cpp

ryanofsky

Code review ACK c665935, Concept -0. Changes here seem logical overall, and I left comments the few places where I had concerns. The LogWarnThenDebug macro also seems cool and potentially useful more places.

The thing I don’t like about this change is that it makes it harder to see if messages are errors or warnings or normal notifications. Being able to see [error] and [warning] tags is a nice feature that is unfortunate to lose. ¹

In an ideal world I would use LogWarning and LogError macros more places rather than fewer. I would also make LogWarning and LogError messages configurable and not always shown, and add a LogCritical level for truly critical messages that should always be shown even when debug logging is off.

That said, this PR seems fine overall: some positives, some negatives, and the code changes look ok.

Note that a message’s error/warning/info status is orthogonal to its priority. A message could describe a normal condition (info), an unexpected condition (warning), or a failure condition (error), and any of these messages could have high or low priority depending how important the information is, whether the condition is temporary or permanent, what side effects it could lead to, and whether it might require manual intervention. ↩

ryanofsky · 2026-03-06T17:17:32Z

src/netbase.cpp

        LogDebug(BCLog::NET, "SOCKS5 connecting %s\n", strDest);
        if (strDest.size() > 255) {
-            LogError("Hostname too long\n");
+            LogDebug(BCLog::PROXY, "Hostname too long for SOCKS5 proxying: %s", strDest);


In commit "netbase: Tidy up logging levels" (436bc94)

Maybe prefix this with Error: to indicate a problem has occurred and distinguish this from informational debug messages

Would suggest the same for other some messages below that aren't clearly labeled as error or failures.

ryanofsky · 2026-03-06T17:30:43Z

src/netbase.cpp

        uint8_t pchRet1[2];
        if (InterruptibleRecv(pchRet1, 2, g_socks5_recv_timeout, sock) != IntrRecvError::OK) {
-            LogInfo("Socks5() connect to %s:%d failed: InterruptibleRecv() timeout or other failure\n", strDest, port);
+            LogDebug(BCLog::PROXY, "Socks5() connect to %s:%d failed: InterruptibleRecv() timeout or other failure", strDest, port);


In commit "netbase: Reduce levels of socks5 error logging" (7567471)

If this is an error communicating with the proxy server (as opposed to an error with the proxy server making a remote connection), it would seem potentially important for the user to know about so they can fix the problem with the server. Hiding this could make problems harder to diagnose, and it might be better to keep the previous level

ryanofsky · 2026-03-06T17:38:03Z

src/netbase.cpp

    // Set the non-blocking option on the socket.
    if (!sock->SetNonBlocking()) {
-        LogInfo("Error setting socket to non-blocking: %s\n", NetworkErrorString(WSAGetLastError()));
+        LogWarnThenDebug(BCLog::NET, "Error setting socket to non-blocking: %s", NetworkErrorString(WSAGetLastError()));


In commit "netbase: Tidy up logging levels" (436bc94)

This change seems ok, but if the goal in the commit message is to use higher levels for errors "that may be due to system misconfiguration" I don't know why this socket error would be more likely to be the result of misconfiguration than SO_NOSIGPIPE above, or if something else account for the difference like this error being considered more severe?

The SO_NOSIGPIPE error is marked as "continuing anyway", rather than immediately failing the connection, which seems fairly straightforwardly less severe.

ryanofsky · 2026-03-06T17:48:59Z

src/bitcoin-tx.cpp

                CScript redeemScript(rsData.begin(), rsData.end());
-                tempKeystore.AddCScript(redeemScript);
+                if (!tempKeystore.AddCScript(redeemScript)) {
+                    throw std::runtime_error(strprintf("Error adding redeemscript=%s", HexStr(redeemScript)));


In commit "script: Lower level of oversized redeemScript log, push errors to callers" (c02d589)

It seems good to throw an error here though text of this message doesn't seem ideal. Redeemscript blob is potentially large and earler logged message seems more helpful (though I'm not sure if logs are shown in bitcoin-tx so it might also be useless). Might want to add another TODO comment here to improve

ryanofsky · 2026-03-06T19:07:01Z

src/netbase.cpp

    auto sock = CreateSock(AF_UNIX, SOCK_STREAM, 0);
    if (!sock) {
-        LogError("Cannot create a socket for connecting to %s\n", m_unix_socket_path);
+        LogWarnThenDebug(BCLog::PROXY, "Cannot create a socket for connecting to %s", m_unix_socket_path);


In commit "netbase: Reduce levels of socks5 error logging" (7567471)

I’m not sure LogWarnThenDebug() is the best fit here. Compared to the earlier uses in this commit and the previous one, this seems less like a persistent configuration problem and more like something that could be intermittent, e.g. due to hitting resource limits.

In that case, warning exactly once and then may hide recurring failures. It would seem better to have a rate limit and show the error once per hour or once per day while it is still occurring, not to just show it once and never again for the lifetime of the process. Absent that, keeping this at info/warning/error level might be safer.

sedited · 2026-03-11T13:21:21Z

src/netbase.cpp

    auto sock = CreateSock(dest.GetSAFamily(), SOCK_STREAM, IPPROTO_TCP);
    if (!sock) {
-        LogError("Cannot create a socket for connecting to %s\n", dest.ToStringAddrPort());
+        LogDebug(BCLog::NET, "Cannot create a socket for connecting to %s", dest.ToStringAddrPort());


In commit 436bc94

I'm a bit confused when you are choosing Debug and when WarnThenDebug in this commit. What is the difference between these cases?

Proxy::Connect failing means you can't connect to the proxy you've configured, which seems likely to be a fairly serious problem for your node, and that error is likely the thing you need to see; ConnectDirectly failing might also be a severe problem, but it might also just be that you're trying to connect over ipv6 because your node says "why not?" but your OS says "no way", which is not really problematic at all. Note that CreateSock is CreateSockOS which mostly has LogWarnThenDebug before it returns nullptr as well.

Not particularly wedded to any particular choices here, these were just my best guesses.

Thanks for elaborating. Makes sense to me.

ajtowns added 7 commits March 4, 2026 15:29

util/log: Add LogWarnThenDebug() helper

0b75dcc

This generalises the functionality introduced for PCP/NAT-PMP logging in bitcoin#34549.

netbase: Reduce levels of socks5 error logging

7567471

script: Lower level of oversized redeemScript log, push errors to cal…

c02d589

…lers

kernel/coinstats: Downgrade ComputeUTXOStates log level

1ba2b65

txindex: Downgrade log messages and include index name

06fea76

validation: Upgrade log levels for possible block corruption warnings

c665935

This was referenced Mar 4, 2026

log, refactor: Allow log macros to accept context arguments #29256

Draft

doc: Drop description of LogError messages as fatal #30361

Open

kevkevinpal reviewed Mar 4, 2026

View reviewed changes

src/validation.cpp Show resolved Hide resolved

src/validation.cpp Show resolved Hide resolved

ryanofsky approved these changes Mar 6, 2026

View reviewed changes

DrahtBot mentioned this pull request Mar 10, 2026

logging: rewrite macros to add ratelimit option, avoid unused strprintf, clarify confusing errors #34778

Open

sedited reviewed Mar 11, 2026

View reviewed changes

Conversation

ajtowns commented Mar 4, 2026

Uh oh!

DrahtBot commented Mar 4, 2026 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Reviews

Conflicts

Uh oh!

ajtowns commented Mar 4, 2026

Uh oh!

kevkevinpal left a comment

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Uh oh!

ryanofsky left a comment

Choose a reason for hiding this comment

Footnotes

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

5 participants

DrahtBot commented Mar 4, 2026 •

edited

Loading