log: Remove brittle and confusing LogPrintLevel #34051

maflcko commented at 7:08 PM on December 11, 2025: member

LogPrintLevel has many issues:

It encourages to log several levels in one source location. This is problematic, because all levels (even warnings and errors) will be rate limited equally for the same location.
Its warning and error logs are specially formatted compared to all other warning and error logs in the codebase, making them harder to spot (both in the debug log and in the code).
It is verbose to type and read.
It is confusing, because the majority of code uses the Log$LEVEL(...) macros. Having less ways to achieve the same makes the code more consistent and easier to review.

Fix all issues by removing it

DrahtBot renamed this:
~~log: Remove brittle and confusing LogPrintLevel~~
log: Remove brittle and confusing LogPrintLevel
on Dec 11, 2025

DrahtBot added the label Utils/log/libs on Dec 11, 2025

DrahtBot commented at 7:08 PM on December 11, 2025: 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/34051.

Reviews

See the guideline for information on the review process.

Type	Reviewers
ACK	stickies-v, pablomartin4btc, ajtowns
Stale ACK	w0xlt, rkrux

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:

#34038 (logging: API improvements by ajtowns)

LLM Linter (✨ experimental)

Possible places where named args for integral literals may be used (e.g. func(x, /*named_arg=*/0) in C++, and func(x, named_arg=0) in Python):

[LogTrace(BCLog::HTTP, "trace_%s. This log level is lower than the global one.", 2)] in src/test/logging_tests.cpp
[LogDebug(BCLog::HTTP, "debug_%s", 3)] in src/test/logging_tests.cpp
[LogDebug(BCLog::NET, "debug_%s. This log level is the same as the global one but lower than the category-specific one, which takes precedence.", 6)] in src/test/logging_tests.cpp

2025-12-13

maflcko force-pushed on Dec 11, 2025

DrahtBot added the label CI failed on Dec 11, 2025

DrahtBot commented at 7:15 PM on December 11, 2025: contributor

🚧 At least one of the CI tasks failed. Task Windows-cross to x86_64, msvcrt: https://github.com/bitcoin/bitcoin/actions/runs/20144403035/job/57820697416 LLM reason (✨ experimental): C++ syntax error in wallet/coinselection.cpp due to mismatched braces (missing/extra brace) causing end-of-input and cascading “qualified-id … before '('” errors.

<details><summary>Hints</summary>

Try to run the tests locally, according to the documentation. However, a CI failure may still happen due to a number of reasons, for example:

Possibly due to a silent merge conflict (the changes in this pull request being incompatible with the current code in the target branch). If so, make sure to rebase on the latest commit of the target branch.
A sanitizer issue, which can only be found by compiling with the sanitizer and running the affected test.
An intermittent issue.

Leave a comment here, if you need help tracking down a confusing failure.

</details>

DrahtBot removed the label CI failed on Dec 11, 2025

in src/test/logging_tests.cpp:194 in fa35682637 outdated

 188 | @@ -207,22 +189,20 @@ BOOST_FIXTURE_TEST_CASE(logging_SeverityLevels, LogSetup)
 189 |      LogInstance().SetCategoryLogLevel(/*category_str=*/"net", /*level_str=*/"info");
 190 |  
 191 |      // Global log level
 192 | -    LogPrintLevel(BCLog::HTTP, BCLog::Level::Info, "foo1: %s\n", "bar1");
 193 | -    LogPrintLevel(BCLog::MEMPOOL, BCLog::Level::Trace, "foo2: %s. This log level is lower than the global one.\n", "bar2");
 194 | -    LogPrintLevel(BCLog::VALIDATION, BCLog::Level::Warning, "foo3: %s\n", "bar3");
 195 | -    LogPrintLevel(BCLog::RPC, BCLog::Level::Error, "foo4: %s\n", "bar4");
 196 | +    LogInfo("info_%s", 1);
 197 | +    LogTrace(BCLog::HTTP, "trace_%s. This log level is lower than the global one.", 2);

stickies-v commented at 11:52 PM on December 11, 2025:

nit: for people unfamiliar with these tests, it's not obvious that the relevant debug/category settings are set in LogSetup. would be a nice improvement to make the test more self contained by explicitly setting them at the beginning of the test (even if it's duplication)

maflcko commented at 7:40 AM on December 12, 2025:

I've added a new LogDebug(BCLog::HTTP, in the line below, to clarify this in the test itself. If that is not sufficient, I am happy to push any diff or commit here, if someone writes one. Also, I am happy to review a separate pull, or a follow-up.

stickies-v commented at 10:17 AM on December 12, 2025:

I've added a new LogDebug(BCLog::HTTP, in the line below, to clarify this in the test itself.

That just made me wonder "wait why does this pass" rather than make it obvious that this was enabled in LogSetup. It's confusing because in normal operation Info is the default level. I think the below diff is all that's needed to make this test self-documenting.

diff --git a/src/test/logging_tests.cpp b/src/test/logging_tests.cpp
index 3d95c97426..2a34aefae1 100644
--- a/src/test/logging_tests.cpp
+++ b/src/test/logging_tests.cpp
@@ -185,6 +185,7 @@ BOOST_FIXTURE_TEST_CASE(logging_LogPrintMacros_CategoryName, LogSetup)
 
 BOOST_FIXTURE_TEST_CASE(logging_SeverityLevels, LogSetup)
 {
+    LogInstance().SetLogLevel(BCLog::Level::Debug);
     LogInstance().EnableCategory(BCLog::LogFlags::ALL);
     LogInstance().SetCategoryLogLevel(/*category_str=*/"net", /*level_str=*/"info");

</details>

maflcko commented at 10:33 AM on December 12, 2025:

Thanks for providing a diff. I've pushed a commit with that:

$ git diff fa35682637 fa33a9f5be -U0
diff --git a/src/test/logging_tests.cpp b/src/test/logging_tests.cpp
index 3d95c97426..2a34aefae1 100644
--- a/src/test/logging_tests.cpp
+++ b/src/test/logging_tests.cpp
@@ -187,0 +188 @@ BOOST_FIXTURE_TEST_CASE(logging_SeverityLevels, LogSetup)
+    LogInstance().SetLogLevel(BCLog::Level::Debug);

stickies-v approved

stickies-v commented at 11:54 PM on December 11, 2025: contributor

ACK fa35682637e7848106189e314a963d8f6c45b2bc

w0xlt commented at 1:32 AM on December 12, 2025: contributor

ACK https://github.com/bitcoin/bitcoin/pull/34051/commits/fa35682637e7848106189e314a963d8f6c45b2bc

in src/logging.h:379 in fa35682637 outdated

 380 | -// vulnerability if level >= Info is used. Additionally, users specifying -debug are assumed to be
 381 | +// Log by prefixing the output with the passed category name and severity level. This logs conditionally if
 382 | +// the category is allowed. No rate limiting is applied, because users specifying -debug are assumed to be
 383 |  // developers or power users who are aware that -debug may cause excessive disk usage due to logging.
 384 | -#define LogPrintLevel(category, level, ...)                           \
 385 | +#define detail_LogIfCategoryAndLevelEnabled(category, level, ...)     \

Ataraxia009 commented at 5:32 AM on December 12, 2025:

Why not write it this like?

#define detail_LogIfCategoryAndLevelEnabled(category, level, ...)  
    do {                
        Assume(level < BCLog::Level::Info);                                             
        if (LogAcceptCategory((category), (level))) {
            LogPrintLevel_(category, level, false, __VA_ARGS__);
        }                                                            
    } while (0)

maflcko commented at 7:34 AM on December 12, 2025:

Why not write it this like?

#define detail_LogIfCategoryAndLevelEnabled(category, level, ...)  
    do {                
        Assume(level < BCLog::Level::Info);                                             
        if (LogAcceptCategory((category), (level))) {
            LogPrintLevel_(category, level, false, __VA_ARGS__);
        }                                                            
    } while (0)

That'd conceptually re-introduce the CVE from https://bitcoincore.org/en/2025/10/24/disclose-cve-2025-54605/:

The Assume is not hit in release builds, because it is compiled out. Only Assert are compiled into the release builds.
If some developer (accidentally or intentionally) re-introduces a call to detail_LogIfCategoryAndLevelEnabled with the Info level, the Assume would pass and the rate limiting would be disabled.

I understand the CVE was low severity and the scenario to re-introduce it by accident is close to impossible, but I think it can't hurt to leave in the belt-and-suspenders check for now. After all, it is just a single and trivial line of code.

I'll leave as-is for now, also to not invalidate the two existing reviews.

Ataraxia009 commented at 9:55 AM on December 12, 2025:

sounds good

Ataraxia009 commented at 11:22 AM on December 12, 2025:

I still don't see the point of leaving the Assume in there since it seems to make no difference other than constricting somebody that would want to create a new macro for LogInfo w category. But i wont hold the PR back because of it.

maflcko commented at 11:49 AM on December 12, 2025:

I still don't see the point of leaving the Assume in there since it seems to make no difference

The point of the Assume is to document internal assumptions for developers. The docs say No rate limiting is applied, . So writing an Assume(!rate_limit) ensures this to some extent for developers and documents it further.

The assume is just a trivial single line, I don't see the risk to keep it. It is also more trivial to remove, than to update the doc string itself.

I'll leave as-is for now, also to not invalidate the two existing reviews.

pablomartin4btc commented at 7:32 PM on December 12, 2025:

nit (if you have to retouch and agree):

#define detail_LogIfCategoryAcceptsLevel(category, level, ...)     \

or detail_LogIfCategoryIsAcceptedAtLevel... perhaps it's clearer and more consistent with existing internal call API LogAcceptCategory().

Ataraxia009 commented at 5:24 AM on December 13, 2025:

doc string can be changed. No risk to keep it but also no point to add it imo. Can just be a normal function that only rate limits >= Info Level and only used within this file.

But just move forward its fine

Ataraxia009 commented at 5:33 AM on December 12, 2025: none

Concept Ack

Ataraxia009 commented at 5:34 AM on December 12, 2025: none

This is good LogPrintLevel just leads to more confusion, standardise the macros!

maflcko force-pushed on Dec 12, 2025

stickies-v commented at 10:55 AM on December 12, 2025: contributor

re-ACK fa33a9f5be1beabfee6c217d133cc51dea3b9a63

No changes except improved self-documentation of test, ty!

DrahtBot requested review from w0xlt on Dec 12, 2025

rkrux approved

rkrux commented at 10:57 AM on December 12, 2025: contributor

ACK fa33a9f5be1beabfee6c217d133cc51dea3b9a63

This is helpful. Having gone through the logging code recently, I found myself confused a bit upon seeing different ways to log. Removal of LogPrintLevel helps in decreasing the confusion by just using LOG<$LEVEL>() macros.

pablomartin4btc commented at 7:32 PM on December 12, 2025: member

ACK fa33a9f5be1beabfee6c217d133cc51dea3b9a63

I agree with the benefits mentioned in the PR description.

libevent: separate log statements per level

Avoids ratelimiting unconditional log statements when debug logging
is enabled. Introduces slight behaviour change by removing
the category from unconditional logs, making them more uniform
with the other unconditional logs in the codebase.

Also, in a slight behavior change, prefix the info-level (and higher)
messages with "libevent:".

94c51ae540

ipc: separate log statements per level

Avoids ratelimiting unconditional log statements when debug logging
is enabled. Introduces slight behaviour change by removing
the category from unconditional logs, making them more uniform
with the other unconditional logs in the codebase.

Also, in a slight behavior change, prefix the info-level (and higher)
messages with "ipc:".

f273167661

test: Clarify logging_SeverityLevels test

The test was a bit confusing, because it just referred to the "global
log level" without explicitly specifying what it is. The level is set
though the LogSetup constructor. However, it is easier to follow unit
tests, if they are self-contained. So just set the level to Debug
explicitly here.

Also, add a new debug_3 log, to further document the intended behavior
of the unit test.

Also, replace the LogPrintLevel with the shorter and exact replacements
LogTrace and LogDebug.

fac24bbec8

in src/i2p.cpp:455 in fa33a9f5be

 451 | @@ -452,7 +452,7 @@ void Session::CreateIfNotCreatedAlready()
 452 |      m_session_id = session_id;
 453 |      m_control_sock = std::move(sock);
 454 |  
 455 | -    LogPrintLevel(BCLog::I2P, BCLog::Level::Info, "%s SAM session %s created, my address=%s\n",
 456 | +    LogInfo("%s SAM session %s created, my address=%s",

ajtowns commented at 2:52 AM on December 13, 2025:

Should these log messages include "I2P" somewhere? Otherwise figuring out what SAM relates to may be confusing. The help text for -i2psam describes it as an "I2P SAM proxy".

maflcko commented at 1:53 PM on December 13, 2025:

thx, done in all commits

maflcko force-pushed on Dec 13, 2025

DrahtBot added the label CI failed on Dec 13, 2025

DrahtBot commented at 12:12 PM on December 13, 2025: contributor

🚧 At least one of the CI tasks failed. Task ASan + LSan + UBSan + integer: https://github.com/bitcoin/bitcoin/actions/runs/20191670716/job/57969925072 LLM reason (✨ experimental): i2p_tests failed due to an aborted subprocess caused by a SAM session error (Session was closed) during test execution.

<details><summary>Hints</summary>

Try to run the tests locally, according to the documentation. However, a CI failure may still happen due to a number of reasons, for example:

Possibly due to a silent merge conflict (the changes in this pull request being incompatible with the current code in the target branch). If so, make sure to rebase on the latest commit of the target branch.
A sanitizer issue, which can only be found by compiling with the sanitizer and running the affected test.
An intermittent issue.

Leave a comment here, if you need help tracking down a confusing failure.

</details>

log: Remove brittle and confusing LogPrintLevel fa8a5d215c

maflcko force-pushed on Dec 13, 2025

stickies-v commented at 1:39 PM on December 13, 2025: contributor

re-ACK fa8a5d215c5a81a7282fd5dd1098f9d3fa40e5db

DrahtBot requested review from rkrux on Dec 13, 2025

DrahtBot requested review from pablomartin4btc on Dec 13, 2025

pablomartin4btc approved

pablomartin4btc commented at 1:54 PM on December 13, 2025: member

re-ACK fa8a5d215c5a81a7282fd5dd1098f9d3fa40e5db

DrahtBot removed the label CI failed on Dec 13, 2025

ajtowns commented at 8:14 PM on December 13, 2025: contributor

ACK fa8a5d215c5a81a7282fd5dd1098f9d3fa40e5db

fanquake merged this on Dec 14, 2025

fanquake closed this on Dec 14, 2025

maflcko deleted the branch on Dec 15, 2025

in src/mapport.cpp:50 in fa8a5d215c

  46 | @@ -47,7 +47,7 @@ static void ProcessPCP()
  47 |      // Local functor to handle result from PCP/NATPMP mapping.
  48 |      auto handle_mapping = [&](std::variant<MappingResult, MappingError> &res) -> void {
  49 |          if (MappingResult* mapping = std::get_if<MappingResult>(&res)) {
  50 | -            LogPrintLevel(BCLog::NET, BCLog::Level::Info, "portmap: Added mapping %s\n", mapping->ToString());
  51 | +            LogInfo("portmap: Added mapping %s", mapping->ToString());

vasild commented at 8:03 AM on December 16, 2025:

Here and elsewhere these messages had a category before and now they are category-less. When a message has a category its log is prefixed by e.g. [net:info] which makes it easier to filter/grep all "net" messages and to know which module a message comes from.

Would be nice to have the ability to log info/warning/error messages with category.

maflcko commented at 8:20 AM on December 16, 2025:

I'd imagine this is trivial to implement by modifying LogInfo to take an optional category, but my recollection is that this was controversial, because it makes it less clear which logs lead to unconditional logging and which logs lead to conditional logging.

I understand that the CVE around this is of low severity and fixed by now (https://bitcoincore.org/en/2025/10/24/disclose-cve-2025-54605/). However, I still think it is ideal to avoid hitting rate-limiting in practise.

makes it easier to filter/grep all "net" messages and to know which module a message comes from.

Also, if this was the goal, then all logging should be moved there. Otherwise, it is just inconsistent and brittle.

Currently, before and after this pull request, most info logs in net do not have a category: git grep 'LogInfo(' ./src/net.cpp

I am also not sure if this is a worthwhile goal, because with logsourcelocations, the module (file) is logged and can be grepped, no?

No strong opinion, and I probably won't be working on this, but I think it should be trivial to implement. The goal of this pull request here was to merely fix all issues listed in the pull description.

Would be nice to have the ability to log info/warning/error messages with category.

No strong opinion on info, but I actually disagree about warnings and errors having a category. Those are all alerts that should go to the user, so being able to grep for all of them in a single and consistent way should be a goal (as explained in the pull description). Instead of supplying alerts with a category, the alert message should be unique and fully descriptive, so that the user can act on it, without having to know or look up which module it came from.