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

ryanofsky commented at 3:28 pm on March 9, 2026: contributor

Rewrite log macros to fix a number of issues: lack of control over rate limiting, unnecessary strprintf calls during fuzzing, and confusing error messages when macros are called with the wrong arguments.

This PR is a refactoring and shouldn’t change externally visible behavior. Changes are described in detail in commit messages. There are also some internal improvements making previously implicit behaviors (evaluating unused format arguments, not outputting categories at certain log levels) explicit and better enforced.

Some changes here were originally part of #29256, but they should make sense on their own and simplify both PRs.

log test: verify log argument evaluation semantics

Test that LogInfo/LogWarning/LogError always evaluate their arguments
even when logging is disabled.

ajtowns pointed out this behavior was important and could affect non-logging
code if changed in
https://github.com/bitcoin/bitcoin/pull/34374#discussion_r2734793117

Co-authored-by: l0rinc <pap.lorinc@gmail.com>

449fc7ce3b

log test: Add test for all accepted logging arguments

Add new logging test to call macros with all allowed combinations of macro
arguments.

The new test replaces a less comprehensive test that doesn't cover log
statements without format arguments. It's also moved to the top of the test
suite because it's a good illustration of what typical log prints look like,
what logging calls are allowed and disallowed, and what the resulting log
output looks like.

1ee5ae0c17

log refactor: Ensure categories are not logged at info and higher levels

Previously this used to be possible through the LogPrintLevel call but now that
call is removed, this change is just an internal refactoring and has no visible
effect except in tests.

8f3e279bb9

log refactor: log macro rewrite

Rewrite log macros to fix a number of issues: lack of control over rate
limiting, unnecessary strprintf calls during fuzzing, confusing error messages
when macros are called with the wrong arguments.

More specifically, benefits are:

- Control over rate limiting: `LogPrintLevel_` hack used to bypass rate limiting
  is dropped. A `LogPrint` macro is added that can control rate limiting (as
  well as other options if they are added in the future).

- Unnecessary `strprintf` calls are now skipped in bitcoind when
  `-noprinttoconsole -nodebuglogfile` options are used, and skipped in tests and
  kernel applications when logging is disabled. This change should not affect
  bitcoind noticeably, but it could speed up fuzz tests calling functions that
  log.

- Clearer error messages: Differences between macros accepting and not accepting
  category arguments has been a source of confusion. Now if you pass a category
  to a macro which does not accept it, or forget to pass a category to a macro
  which requires it, you will see a clear error message telling you to add or
  remove the category instead of more confusing macro errors.

- Previously you could call `LogPrintLevel_` to bypass restrictions on passing
  category arguments. Now `LogPrint` enforces all requirements.

- Previously "always evaluate arguments" behavior at Info and higher levels
  looked accidental and was undocumented
  (https://github.com/bitcoin/bitcoin/pull/34374#discussion_r2734793117). Now
  the behavior is documented and explicit.

- There is now a single macro, `LogPrint` implementing all logging functionality
  and enforcing all restrictions, instead of different sets of macros with
  branching code paths and unexplained differences.

Co-Authored-By: Hodlinator <172445034+hodlinator@users.noreply.github.com>
Co-Authored-By: stickies-v <stickies-v@protonmail.com>

e983d97a91

DrahtBot commented at 3:29 pm on March 9, 2026: contributor

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
Concept NACK	ajtowns

If your review is incorrectly listed, please copy-paste <!–meta-tag:bot-skip–> into the comment that the bot should ignore.

Conflicts

Reviewers, this pull request conflicts with the following ones:

#34806 (refactor: logging: Various API improvements by ajtowns)
#34730 (util/log: Combine the warning/error log levels into a single alert level by ajtowns)
#34729 (Reduce log noise by ajtowns)
#34639 (iwyu: Document or remove some pragma: export and other improvements by hebasto)
#34514 (refactor: remove unnecessary std::move for trivially copyable types by l0rinc)
#34448 (ci, iwyu: Fix warnings in src/util and treat them as errors by hebasto)
#33727 (zmq: Log bind error at Error level, abort startup on init error by isrod)

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.

LLM Linter (✨ experimental)

Possible typos and grammar issues:

testring -> testing [typo in “Include commented out calls … for easy manual testring…”]
readble -> readable [typo in “these calls produce readble compile errors.”]

2026-03-09 15:29:05

ajtowns commented at 10:46 am on March 10, 2026: contributor

Concept NACK to reintroducing a generic LogPrint. The NO_RATE_LIMIT commit from #34038 has been available for review for three months now, and has had a concept ack for that long.

ryanofsky commented at 1:43 pm on March 10, 2026: contributor

The NO_RATE_LIMIT commit from #34038 has been available for review for three months now, and has had a concept ack for that long.

That’s interesting. #34038 is mostly a logging backend change, changing the RPC interface and command line options. It seems like the no-ratelimit change part of that PR might not be related to the other changes there? (I don’t see the connection at least.)

To compare the two approaches, #34038 syntax looks like:

0LogInfo(util::log::NO_RATE_LIMIT, "message");

while syntax here is:

0LogPrint((.level = util::log::Level::Info, .ratelimit = false), "message"),

There is not much difference between the approaches externally, and they are compatible (this PR could easily support a NO_RATE_LIMIT flag if reviewers would prefer that.)

This bigger goal of this PR is to replace current implementation of the logging macros which is messy and inconsistent with a clean implementation. All preprocessor functionality is implemented in a single macro called LogPrint, getting rid of the branching code paths at different priority levels [1] [2] that have unexplained differences. The differences are all kept, they are just explicit rather than implicit, with better documentation and tests and stricter enforcement of restrictions.

The .ratelimit = true option is exposed as a side-effect of this refactoring, and the refactoring also allows other options to be implemented cleanly in the future. Examples could be .log_once=true .log_every=24h .log_every=60m .stack_trace=true .dedup = true etc. I was also thinking of an .impossible = true option that could be used to document preconditions & provide better bug reports and output from fuzz & unit test failures. The point is that I think we should make it easy to add logging options and try to implement most options with constexpr code instead of macros. And get rid of complication of different macros at different log levels having different implementations.

Anyway I’d be happy to review #34038 and I think the runtime changes there look nice. The NO_RATE_LIMIT flag idea there could be nice. If reviewers like it maybe I could support it here and #34038 could be simpler and only implement the logging backend improvements without making a unrelated change (it would seem) to the logging macros?

in src/validation.cpp:2867 in e983d97a91

2862@@ -2863,8 +2863,9 @@ static void UpdateTipLog(
2863 
2864     AssertLockHeld(::cs_main);
2865 
2866-    // Disable rate limiting in LogPrintLevel_ so this source location may log during IBD.
2867-    LogPrintLevel_(BCLog::LogFlags::ALL, util::log::Level::Info, /*should_ratelimit=*/false, "%s%s: new best=%s height=%d version=0x%08x log2_work=%f tx=%lu date='%s' progress=%f cache=%.1fMiB(%utxo)%s\n",
2868+    // Disable rate limiting so this source location may log during IBD.
2869+    LogPrint((.level = util::log::Level::Info, .ratelimit = false),

maflcko commented at 2:30 pm on March 10, 2026:

not sure about using the internal/hidden macro here, after the changes. If someone wants to log at info level, it seems clearer to just call LogInfo, instead of using some internal macro with a bunch of options.

Also, supporting .ratelimit = false for other levels doesn’t really make sense, and certainly isn’t needed by current code at all, so supporting it seems odd.

edit: I see it is needed for one warning log as well. So I guess my main concern is that this will open the gates for the “wild west” that we were trying to fix: For example, this new macro may encourage to re-introduce helpers of the form: [](auto level, auto msg) { LogPrint((.level=level),"%s", msg); }, which will then work incorrectly with regard to rate-limiting (silently dropping warnings/errors, when info logs overflow)

ryanofsky commented at 2:46 pm on March 10, 2026:

re: #34778 (review)

so supporting it seems odd.

When you say odd do you mean the code is doing something it should not do? Or not doing something it should do? For example, It would be easy to add a static assert to prevent ratelimiting being requested at certain levels if you feel that is important. Though I’m not sure why ratelimiting should not be available at different levels (I haven’t looked into the rate limiting implementation).

Overall, the idea here is to accept options and pass them along the backend to implement. I imagine the bitcoinkernel backend probably won’t support rate limiting at all for example (or at least it doesn’t in #34374)

maflcko commented at 2:55 pm on March 10, 2026:

(I haven’t looked into the rate limiting implementation).

I’ve edited my comment to explain one case that will make code more brittle.

I mostly think this should remain internal/hidden, maybe LogPrintInternalDetail(...). Otherwise, devs may think this is fine to use without thinking much about the implicit edges.

ryanofsky commented at 3:12 pm on March 10, 2026:

re: #34778 (review)

For example, this new macro may encourage to re-introduce helpers of the form: [](auto level, auto msg) { LogPrint((.level=level),"%s", msg); }, which will then work incorrectly with regard to rate-limiting (silently dropping warnings/errors, when info logs overflow)

Hmm, I’m confused why someone would do what you are suggesting, but if they did it should be safe and work correctly. The ratelimit default value should be the same as before.

The point of adding LogPrint is to be a safe, single implementation of logging code that other macros can just forward to without their own bespoke logic and special cases.

Please let me know if I am missing something here. Like I said I haven’t actually looked at the ratelimiting implementation. This PR is just forwarding the option. If any unsafe option values are currently accepted, we should definitely prohibit them with a static assert, but I’m not seeing where that could be happening.

maflcko commented at 3:29 pm on March 10, 2026:

Hmm, I’m confused why someone would do what you are suggesting,

Well, you can go back in the git history to find this exact pattern. See 2210feb4466eff1455468f0a25045fce4b89c55d.

but if they did it should be safe and work correctly.

No, see 2210feb4466eff1455468f0a25045fce4b89c55d, which fixed this. (You can refer to the commit messages for more details)

ryanofsky commented at 3:48 pm on March 10, 2026:

re: #34778 (review)

Hmm, I’m confused why someone would do what you are suggesting,

Well, you can go back in the git history to find this exact pattern. See 2210feb.

Thanks for clarifying. For others who may be following, the pattern is shown specifically in f2731676619d14fa4527aa9086fb73078d20f26f and 94c51ae540723f5f648477789c11f6395730ae05 and it is not allowed by this PR. This PR enforces the same restrictions as current code.

E.g. if you try to revert f2731676619d14fa4527aa9086fb73078d20f26f and call LogPrint((.level = ConvertIPCLogLevel(message.level)) , "%s\n", message.message); you will see an error because the level is not a compile time constant.

(EDIT: I’d add that I don’t see anything inherently wrong with the pattern used in those commits, and no reason it couldn’t work well. The previous LogPrintLevel implemention just had a bug and was good candidate for removal for other reasons.)

maflcko commented at 4:49 pm on March 10, 2026:

and it is not allowed by this PR. This PR enforces the same restrictions as current code.

I don’t think this is true. I am sure one can write a similar pattern deriving the level constexpr/consteval.

(EDIT: I’d add that I don’t see anything inherently wrong with the pattern used in those commits, and no reason it couldn’t work well.

logging takes the source location, which is then used for other stuff (such as rate limiting or -logsourcelocations). Using the same source location for different logs is brittle in itself. Though, using it for different log levels is doubly brittle. I don’t see the need to regress here

ryanofsky commented at 5:41 pm on March 10, 2026:

re: #34778 (review)

and it is not allowed by this PR. This PR enforces the same restrictions as current code.

I don’t think this is true. I am sure one can write a similar pattern deriving the level constexpr/consteval.

Can we slow down and try to work through an example here? I would like to understand the problem you are concerned about and either confirm that it is not an issue here, or make some fix to solve it.

As far as I can tell, you did a little pattern matching like “this new function looks similar to that previously removed function” and assuming “therefore it has the same bugs and limitations of the previous function.” This is a reasonable assumption, but it happens not to be true in this case!

(EDIT: I’d add that I don’t see anything inherently wrong with the pattern used in those commits, and no reason it couldn’t work well.

logging takes the source location, which is then used for other stuff (such as rate limiting or -logsourcelocations). Using the same source location for different logs is brittle in itself.

Sorry yes I should have clarified I only think the pattern is good for external code that does not include source locations. Internal logs should definitely have source locations! I don’t think you will find any regressions on that front either implemented in this PR or enabled by it.

To the contrary, followup PR #30343 adds source locations to wallet code which is currently missing them.

maflcko commented at 6:18 pm on March 10, 2026:

example

Of course, this synthetic example is not found in the codebase as-is, but I don’t see why it wouldn’t compile with the changes in this pull

0struct Module {
1std::string m_name;
2template<Level level>
3void ModuleLog(std::string m) { LogPrint((.level=level), "[%s] %s", m_name, m); }
4...
5};

ryanofsky commented at 7:03 pm on March 10, 2026:

re: #34778 (review)

Thanks for the concrete example. I am assuming based on your earlier comments that problem with this example is that it hides source locations, and I agree hiding source locations would be bad. I guess I just disagree with the realism of the example. You seem to be saying is that this PR could make developers more tempted to write bad per-module logging interfaces and add calls like:

0my_module.ModuleLog<Level::Info>("message")

to the code, hiding source locations that would otherwise be available. Even though developers could implement literally the same bad interface today by calling the LogInfo/LogWarning/LogError macros with an if or switch statement? And even though we already have an existing WalletLogPrintf function today which has no problem hiding source locations with the current logging macros?

I just don’t see this PR by itself having any real impact on support for source locations. But if that is the concern and I did not misunderstand something, thanks for clarifying.

maflcko commented at 2:53 pm on March 16, 2026:

I guess I just disagree with the realism of the example.

You give a real place yourself (WalletLogPrintf), where a dev (or an LLM) could apply the example today (or use it as an excuse to introduce the pattern in another module) in any of the 300 open pulls. So I don’t see why the example should not be real.

an if or switch statement?

Fair enough, but at least this won’t apply rate-limiting across levels, when it shouldn’t.

And to re-iterate an earlier point: Just as the logging was fixed to be consistent, so that one can call git grep LogInfo to find all info logs, this will introduce a new alias to grep for. I am sure over time devs will then use (inside the same file), stuff like:

0LogPrint((.level = util::log::Level::Info), "a");
1LogInfo("b):

I don’t see the point in allowing all of this, if there is no reason for it. Why not just indicate in the name of the macro or function that this is only meant for internal use, like it was before this pull request?

DrahtBot commented at 3:27 am on March 23, 2026: contributor

🐙 This pull request conflicts with the target branch and needs rebase.

DrahtBot added the label Needs rebase on Mar 23, 2026

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

Reviews

Conflicts

LLM Linter (✨ experimental)