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

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

This PR is an internal cleanup for util/log.h that fixes several problems with the logging macros defined there.

The main change is replacing the internal LogPrintLevel_ macro with a LOG_EMIT macro. It makes all the external logging macros (LogDebug, LogInfo, etc.) call LOG_EMIT, eliminating inconsistencies, improving efficiency, and producing clearer compiler errors when called incorrectly.

Specific problems this PR fixes:

LogPrintLevel_ is easy to call incorrectly because it takes level and ratelimit as independent options, when ratelimit should almost always depend on level, and currently requires hacks like a runtime assert to ensure consistency. By contrast, LOG_EMIT sets options correctly by default while allowing explicit overrides (e.g. .ratelimit = false) for special cases.
Unlike other logging macros, LogPrintLevel_ allows categories to be specified at Info, Warning, and Error levels. By contrast, LOG_EMIT makes it a compile-time error to specify categories at these levels, or to omit them at lower levels.
Current logging macros produce hard to decipher syntax errors when category arguments are specified but not allowed, or required but not provided. Now all logging macros produce clear static_assert errors indicating whether to add or remove category arguments.
Current logging macros duplicate logic and have undocumented, untested differences. For example, some macros evaluate their arguments when logging is disabled and others do not. By constrast, the LOG_EMIT macro implements logging logic in one place, preventing hidden inconsistencies.
Having multiple implementations of logging macros makes it difficult to add new logging features (see below), because it requires changing many macros and adding separate macro arguments for each feature. Having a single core LOG_EMIT macro taking a single compile-time options argument makes it possible to add new features cleanly.
Current LogInfo, LogWarning, and LogError macros generate log entries and call util::log::Log(Entry) even when logging is disabled. LOG_EMIT avoids this overhead, which is probably minor but could improve performance in some kernel applications and fuzzing.

Possible followups

This PR does not add any new logging features. It is purely an internal cleanup that fixes the problems listed above. However, it is worth noting that this PR could make it easier to add logging features in the future. For example:

New logging options could be added. Examples: .stacktrace = true to log the current stack trace, .exception = true to log the current exception, .impossible = true to indicate an impossible condition and halt fuzzing or request a bug report, .log_once = true to log at most once from this source location, .log_every = 60m to log at most once per hour, .dedup = true to drop duplicste messages, etc.
External macros like LogInfo and LogDebug could accept these options. Example: f5ca95b1e610ebad7063143ddef98fc318251bc4
Context information could be added to log messages, e.g., wallet names, chainstate names, or request IDs to distinguish logs from paralell requests. Example: #30343
Non-global logging streams could also be supported. For example, kernel functions could accept optional logger arguments instead of always writing to the global logger. Example: #30342

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:

#34865 (logging: better use of log::Entry internally by stickies-v)
#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)
#34514 (refactor: remove unnecessary std::move for trivially copyable types by l0rinc)
#33727 (zmq: Log bind error at Error level, abort startup on init error by isrod)
#30343 (wallet, logging: Replace WalletLogPrintf() with LogInfo() by ryanofsky)
#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 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 added the label Needs rebase on Mar 23, 2026

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>

3ea39b9f21

logging: declare LogAcceptCategory in util

Move LogAcceptCategory from logging.h to util/log.h without changing
behavior. Also call LogAcceptCategory instead of ShouldLog in
validationinterface.cpp.

LogAcceptCategory is the stable API for determining if log messages
should be emitted by application code. ShouldLog is a lower-level hook
implemented by the log handling backend which takes an opaque category
argument instead of an enum.

Also add some test coverage on LogAcceptCategory.

Co-authored-by: Ryan Ofsky <ryan@ofsky.org>

4ad8e0e206

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.

8a3d10759b

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.

c53ded9860

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.

Since this is a rewrite, reading the new code in log.h first should be clearer
than starting from the diff.

Specific benefits of the new implementation are:

- Functionality is implemented once in a single `LOG_EMIT` macro instead of
  multiple times in different macros with diverging code paths and unexplained
  differences.

- `LogPrintLevel_` hack used to bypass rate limiting is dropped. The `LOG_EMIT`
  macro can control rate limiting (and other options if they are added in the
  future) while still using the same rate-limiting defaults as other macros.

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

- Clearer error messages: 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 direct message telling you to add or remove the category instead
  of expanded macro syntax errors.

- Previously you could call `LogPrintLevel_` to bypass restrictions on passing
  category arguments. New `LOG_EMIT` macro has the same requirements as the
  other macros and shows the same compile-time errors.

- 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.

- Previously `detail_LogIfCategoryAndLevelEnabled` would assert at runtime
  if it was called at a disallowed level. Now all checking is done at
  compile time.

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

31612a7f5f

ryanofsky force-pushed on Apr 1, 2026

DrahtBot removed the label Needs rebase on Apr 1, 2026

ryanofsky force-pushed on Apr 3, 2026

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

Possible followups

Reviews

Conflicts