logging: rewrite macros to enforce restrictions at compile-time, improve efficiency and usability #34778

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 detail_LogWithSrcLoc 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:

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.
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 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.
Current detail_LogWithSrcLoc macro is dangerous to call because because it does not check for inconsistent or invalid arguments. For example, calling it always bypasses ratelimiting without a check to prevent this. (Previously there was a runtime check, but it was removed without justification in 34332dba2f6f6892859ecb62daa9a2add76ae05e). New LOG_EMIT macro is compile-time safe and all the same restrictions as other macros.
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.

Individual commits also implement other improvements: adding missing test coverage and removing misleading Entry::should_ratelimit field which is stored in buffered log messages after rate-limiting has been applied, and has no effect.

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.

Code Coverage & Benchmarks

For details see: https://corecheck.dev/bitcoin/bitcoin/pulls/34778.

Reviews

See the guideline for information on the review process.

Type	Reviewers
Concept NACK	ajtowns

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

Conflicts

Reviewers, this pull request conflicts with the following ones:

#35355 (Use atomics for determining whether trace logging is enabled by ajtowns)
#35322 (logging: streamline Logger state and drop redundant methods 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:

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

while syntax here is:

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

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

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:

my_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:

LogPrint((.level = util::log::Level::Info), "a");
LogInfo("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

ryanofsky force-pushed on Apr 1, 2026

DrahtBot removed the label Needs rebase on Apr 1, 2026

ryanofsky force-pushed on Apr 3, 2026

DrahtBot added the label Needs rebase on Apr 23, 2026

ryanofsky force-pushed on May 6, 2026

ryanofsky commented at 9:17 AM on May 6, 2026: contributor

Rebased 31612a7f5f0d197bdc4a9747ad9e7509bf693d7d -> 0c090593e8bdbdd3f65ea12aa1177ebc3d22d86a (pr/relog.3 -> pr/relog.4, compare) due to conflict with #34865

Rebased 0c090593e8bdbdd3f65ea12aa1177ebc3d22d86a -> f0929e1b781af5012d835f78a8b54054fb5cb21e (pr/relog.4 -> pr/relog.5, compare) due to conflict with #34806

DrahtBot removed the label Needs rebase on May 6, 2026

DrahtBot added the label Needs rebase on May 22, 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>

963ed23bc8

log test: add some test coverage on LogAcceptCategory

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

3ea9b7cb10

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.

9c509ca53c

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.

98f3bd6242

log refactor: log macro rewrite

Rewrite log macros to fix a number of issues: unnecessary strprintf
calls during fuzzing, confusing error messages when macros are called
with the wrong arguments, duplicated code with unexplained differences
and undocumented assumptions.

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.

- 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 it was possible to call `detail_LogWithSrcLoc` with
  inconsistent or invalid arguments, for example bypassing ratelimiting
  without it being explicit. New `LOG_EMIT` macro is compile-time safe
  and enforces the exact same restrictions as other macros.

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

- `NO_RATE_LIMIT` special case 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 ratelimiting
  defaults as other macros.

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

31f9929f3d

log refactor: Drop Entry::should_ratelimit field

Drop Entry::should_ratelimit field in favor of Options::ratelimit field.

Dropping the Entry::should_ratelimit field makes buffered log messages
in m_msgs_before_open smaller, and avoids potential confusion because
the field is stored after rate limiting has been applied, so just gets
ignored. Conceptually it also makes sense to treat the ratelimit option
as an input to the logger rather than as an attribute of the message
being logged.

f0929e1b78

ryanofsky force-pushed on May 26, 2026

ryanofsky renamed this:
~~logging: rewrite macros to add ratelimit option, avoid unused strprintf, clarify confusing errors~~
logging: rewrite macros to enforce restrictions at compile-time, improve efficiency and usability
on May 26, 2026

DrahtBot removed the label Needs rebase on May 26, 2026