log: Mitigate disk filling attacks by rate limiting LogPrintf, LogInfo, LogWarning, LogError #32604

Crypt-iQ · 2025-05-23T20:48:49Z

This revives the work done by dergoegge in #21603. The approach is largely the same except that std::source_location is used under-the-hood now that we can use c++20 features. The logging functions have also changed slightly since that PR was opened, so work has been done to preserve the intent of the original rate limiting change. I have tried to give commit attribution where possible (unfortunately I was not able to figure out how to type ö in vim).

Approach:
Each source code location is given an hourly logging quota of 1MiB of logging per hour. Logging is only dropped from source locations that exceed the quota.

Only logging to disk is rate limited. Logging to console is not rate limited.
Printing with the category argument is not rate limited.
UpdateTip: new best=[…] is logged with the new UNCONDITIONAL_ALWAYS category to avoid rate limiting. High log volume is expected for that source location during IBD.
When logging is restarted a tally of how many messages/bytes were dropped is printed.
Log rate limiting can be disabled with the -ratelimitlogging config option.
All logs will be prefixed with [*] if there is at least one source location that is currently being suppressed.

I've repurposed the old logging rpc mentioned in #21603 in another branch for testing here. This can be used to log from source locations and test out the new changes in logging behavior. Note that the setmocktime RPC needs to be used to set the mock time past the current clock time to reset the logging messages.

Example usage:

bitcoin-cli -regtest excessivelog 1 1048500 # log just under 1MiB
bitcoin-cli -regtest excessivelog 1 100 # this should get the total amount logged above 1MiB
                                        # and the rate limiting logic should kick in
bitcoin-cli -regtest excessivelog 2 1048500
bitcoin-cli -regtest excessivelog 2 100 # trigger rate limiting from another location
bitcoin-cli -regtest setmocktime <N> # set this past the current clock time because of how `LogRateLimiter` is initialized
bitcoin-cli -regtest excessivelog 1 100 # this should trigger logging to resume and will log the source locations that were reset

Example output:

[*] Excessive logging detected from rpc/node.cpp:139 (RPCHelpMan excessivelog()): >1 MiB logged during the last hour.Suppressing logging to disk from this source location for up to one hour. Console logging unaffected. Last log entry.2025-06-11T16:32:41Z aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa
[*] Excessive logging detected from rpc/node.cpp:142 (RPCHelpMan excessivelog()): >1 MiB logged during the last hour.Suppressing logging to disk from this source location for up to one hour. Console logging unaffected. Last log entry.2025-06-11T16:33:04Z aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa
Restarting logging from rpc/node.cpp:139 (RPCHelpMan excessivelog()): (1 MiB) were dropped during the last hour.
Restarting logging from rpc/node.cpp:142 (RPCHelpMan excessivelog()): (0 MiB) were dropped during the last hour.

DrahtBot · 2025-05-23T20:48:51Z

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

Reviews

See the guideline for information on the review process.

Type	Reviewers
Concept ACK	davidgumberg, dergoegge, brunoerg, l0rinc
Approach ACK	stickies-v
Stale ACK	janb84

If your review is incorrectly listed, please react with 👎 to this comment and the bot will ignore it on the next update.

Conflicts

Reviewers, this pull request conflicts with the following ones:

#29641 (scripted-diff: Use LogInfo over LogPrintf [WIP, NOMERGE, DRAFT] by maflcko)
#29256 (log, refactor: Allow log macros to accept context arguments by ryanofsky)
#26812 (test: add end-to-end tests for CConnman and PeerManager by vasild)

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.

davidgumberg · 2025-05-23T21:00:08Z

Concept ACK

gmaxwell · 2025-05-23T21:34:45Z

Any thoughts about adding some kind of dying gasp so that if a node crashes or hits some fatal error the most recent unfiltered log can be saved?

DrahtBot · 2025-05-23T21:47:18Z

🚧 At least one of the CI tasks failed.
_{Task lint: https://github.com/bitcoin/bitcoin/runs/42810774045}
_{LLM reason (✨ experimental): The CI failure is due to linting errors related to std::filesystem and locale dependence.}

Hints

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.

Crypt-iQ · 2025-05-24T20:49:35Z

if a node crashes or hits some fatal error the most recent unfiltered log can be saved?

Does unfiltered here mean a log line that was rate limited or does it mean something else in this context? I think that we would need to know ahead of time if we were going to crash to save the most recent unfiltered log unless we somehow always cache it?

dergoegge · 2025-05-26T12:07:55Z

Concept ACK

Thanks for picking this up!

janb84

ACK 0bc6ed6

Ratelimits loging to disk if loggin exceeds 1 MiB in 1 hour (WINDOW_MAX_BYTES const & WINDOW_SIZE const)

code review
build & tested

src/logging.h

brunoerg · 2025-05-26T19:47:41Z

Concept ACK

Crypt-iQ · 2025-05-29T16:22:13Z

The tidy job is failing because it doesn't like the logging macros being used in lambda functions. It seems like this is pre-existing so I'm not sure why it's failing now. The windows cross-built job is failing on the rate_limiting test at every file-size comparison. I don't have a windows machine to debug this, but I think maybe fs::file_size is failing or some other quirk is showing up?

stickies-v

Concept ACK on locking down this attack vector, and the code changes required seem acceptable. Also nice to start using std::source_location here.

src/logging.h

src/init/common.cpp

src/logging.h

fanquake · 2025-05-30T10:57:04Z

The windows cross-built job is failing on the rate_limiting test at every file-size comparison. I don't have a windows machine to debug this, but I think maybe fs::file_size is failing or some other quirk is showing up?

@hebasto can you take a look here? I ran test_bitcoin.exe from this branch (rebased) under wine and didn't see any failures.

hebasto · 2025-05-30T12:20:01Z

The windows cross-built job is failing on the rate_limiting test at every file-size comparison. I don't have a windows machine to debug this, but I think maybe fs::file_size is failing or some other quirk is showing up?

@hebasto can you take a look here? I ran test_bitcoin.exe from this branch (rebased) under wine and didn't see any failures.

It seems to be related to MSVCRT behaviour, as binaries linked to UCRT pass all unit tests.

src/logging.cpp

src/logging.h

stickies-v · 2025-05-30T12:49:40Z

src/logging.cpp

+                                    "(%d MiB) were dropped during the last hour.\n",
+                                    source_loc.file_name(), source_loc.line(), logging_function,
+                                    dropped_bytes / (1024 * 1024)));
+        } else if (is_ratelimited && !was_ratelimited) {


nit: It would be nice if we could catch this in debug builds (ideally even at a fraction, say 20% of the limit), to help inform if our default limit needs to change. Assume() is an option, but that would probably break unit tests in debug builds.

nit, because 1MB is small enough that it should prevent issues even on devices with little disk size (unless an attacker finds multiple log vulnerabilities), and large enough that no single unconditional logging statement should ever hit that in the foreseeable future, so I think "driving blind" is acceptable here.

I want to address this because I think it would be useful to catch in debug builds via Assume but also don't want to break tests. Do you think this should be addressed?

dergoegge · 2025-06-03T08:47:37Z

I vaguely remember having trouble with the unit tests on windows too. Iirc it had something to do with windows line endings being different (i.e. \r\n on windows vs \n on linux), which throws off the size accounting.

maflcko · 2025-06-03T10:03:15Z

The tidy job is failing because it doesn't like the logging macros being used in lambda functions. It seems like this is pre-existing so I'm not sure why it's failing now.

It happens after commit dfbc3e4 and looks unrelated. Maybe just use the workaround from ./src/util/check.h?

l0rinc · 2025-06-03T10:09:15Z

Concept ACK, but I'm not yet sure about the approach. Let me know if I misunderstood something important here.

Edit:

All logs will be prefixed with [*] if there is at least one source location that is currently being suppressed

Will that appear on the console as well, which didn't have any messages dropped?

src/init/common.cpp

src/logging.h

Crypt-iQ

The latest change uses a single BCLog::LogRateLimiter instance and uses a slimmer way of tracking the amount of logging bytes left per std::source_location. I like the approach better as m_categories is no longer being used. I would like to point out that the rate-limiting logic can be bypassed if LogPrintLevel is used. I think LogPrintLevel callers need to be cautious and I kind of think this macro shouldn't be used if level >= BCLog::Level::Info.

Will that appear on the console as well, which didn't have any messages dropped?

Yes this appears in the console as well. I actually was unsure if console-logging should be rate-limited or not. Hopefully users have sensible limits on their terminal history?

I will work on fixing the CI, I think review can still happen in the meantime while I debug the windows failure and fix the tidy job.

Crypt-iQ · 2025-06-04T17:39:39Z

src/logging.cpp

+                                    "(%d MiB) were dropped during the last hour.\n",
+                                    source_loc.file_name(), source_loc.line(), logging_function,
+                                    dropped_bytes / (1024 * 1024)));
+        } else if (is_ratelimited && !was_ratelimited) {


I want to address this because I think it would be useful to catch in debug builds via Assume but also don't want to break tests. Do you think this should be addressed?

src/logging.h

src/logging.cpp

src/logging.h

src/logging.cpp

src/logging.h

src/init/common.cpp

src/logging.h

src/logging.cpp

DrahtBot · 2025-06-05T18:57:26Z

🚧 At least one of the CI tasks failed.
_{Task previous releases, depends DEBUG: https://github.com/bitcoin/bitcoin/runs/43565644662}
_{LLM reason (✨ experimental): The build failed due to a compilation error caused by incomplete type declaration of BCLog::SourceLocationCounter.}

Hints

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.

Crypt-iQ · 2025-06-05T20:12:21Z

The latest push encapsulates things a bit more. I think there's still room for improvement and am open to suggestions -- I don't like how WINDOW_MAX_BYTES is not a LogRateLimiter member and I also dislike the friend class Logger usage.

I think the windows cross-built job is failing because a static BCLog::Logger* is shared across tests and is triggering the rate-limiting logic before the logging tests are run. The CI logs have an asterisk:
Mismatch at position 0: [*] foo5: bar5 != foo5: bar5

stickies-v

Approach ACK. I think this PR needs release notes because of the behaviour change.

src/logging.h

src/logging.cpp

stickies-v · 2025-06-06T09:28:33Z

src/logging.cpp

+        str.insert(0, strprintf("Restarting logging from %s:%d (%s): "
+                                "(%d MiB) were dropped during the last hour.\n",
+                                source_loc.file_name(), source_loc.line(), source_loc.function_name(),
+                                dropped_bytes / (1024 * 1024)));


This will now only be shown for a single source location per time window. I think this should be moved to MaybeResetWindow(), where we iterate over m_suppressed_locations before clearing it?

I've made this change, lmk what you think. MaybeResetWindow() now uses str.insert(0, ...) per m_suppressed_locations.

stickies-v · 2025-06-06T09:43:26Z

src/logging.cpp

 {
    if (!str.ends_with('\n')) str.push_back('\n');

    str.insert(0, GetLogPrefix(category, level));

    if (m_log_sourcelocations) {
-        str.insert(0, strprintf("[%s:%d] [%s] ", RemovePrefixView(source_file, "./"), source_line, logging_function));
+        str.insert(0, strprintf("[%s:%d] [%s] ", RemovePrefixView(source_loc.file_name(), "./"), source_loc.line(), source_loc.function_name()));


As you pointed out, this changes the logging output by now including the full function signature instead of just the function name. I think that's generally an improvement, but should probably be mentioned in the release notes (which would be good to have for the new rate limiting behaviour in general anyway) because it might break downstream log parsing. Would suggest adding commit at the top with release notes?

stickies-v · 2025-06-06T09:46:36Z

src/logging.cpp

                .threadname=util::ThreadGetInternalName(),
-                .source_line=source_line,
+                .source_loc=source_loc,


Since source_loc is fairly large and this function is frequently called, I think it might make sense to optimize this a bit further and have LogPrintStr_ (and its callsites) take a std::source_location&& so we can move it here and avoid the copy?

git diff on 911ee52

diff --git a/src/logging.cpp b/src/logging.cpp index e31e346549..006bac6a98 100644 --- a/src/logging.cpp +++ b/src/logging.cpp @@ -74,8 +74,7 @@ bool BCLog::Logger::StartLogging() // dump buffered messages from before we opened the log m_buffering = false; if (m_buffer_lines_discarded > 0) { - const auto source_loc{std::source_location::current()}; - LogPrintStr_(strprintf("Early logging buffer overflowed, %d log lines discarded.\n", m_buffer_lines_discarded), source_loc, BCLog::ALL, Level::Info, /*should_ratelimit=*/false); + LogPrintStr_(strprintf("Early logging buffer overflowed, %d log lines discarded.\n", m_buffer_lines_discarded), std::source_location::current(), BCLog::ALL, Level::Info, /*should_ratelimit=*/false); } while (!m_msgs_before_open.empty()) { const auto& buflog = m_msgs_before_open.front(); @@ -434,13 +433,13 @@ void BCLog::Logger::FormatLogStrInPlace(std::string& str, BCLog::LogFlags catego str.insert(0, LogTimestampStr(now, mocktime)); } -void BCLog::Logger::LogPrintStr(std::string_view str, const std::source_location& source_loc, BCLog::LogFlags category, BCLog::Level level, bool should_ratelimit) +void BCLog::Logger::LogPrintStr(std::string_view str, std::source_location&& source_loc, BCLog::LogFlags category, BCLog::Level level, bool should_ratelimit) { StdLockGuard scoped_lock(m_cs); - return LogPrintStr_(str, source_loc, category, level, should_ratelimit); + return LogPrintStr_(str, std::move(source_loc), category, level, should_ratelimit); } -void BCLog::Logger::LogPrintStr_(std::string_view str, const std::source_location& source_loc, BCLog::LogFlags category, BCLog::Level level, bool should_ratelimit) +void BCLog::Logger::LogPrintStr_(std::string_view str, std::source_location&& source_loc, BCLog::LogFlags category, BCLog::Level level, bool should_ratelimit) { std::string str_prefixed = LogEscapeMessage(str); @@ -451,7 +450,7 @@ void BCLog::Logger::LogPrintStr_(std::string_view str, const std::source_locatio .mocktime=GetMockTime(), .str=str_prefixed, .threadname=util::ThreadGetInternalName(), - .source_loc=source_loc, + .source_loc=std::move(source_loc), .category=category, .level=level, }; diff --git a/src/logging.h b/src/logging.h index d588ef86dc..edef5c074f 100644 --- a/src/logging.h +++ b/src/logging.h @@ -201,7 +201,7 @@ namespace BCLog { std::list<std::function<void(const std::string&)>> m_print_callbacks GUARDED_BY(m_cs) {}; /** Send a string to the log output (internal) */ - void LogPrintStr_(std::string_view str, const std::source_location& source_loc, BCLog::LogFlags category, BCLog::Level level, bool should_ratelimit) + void LogPrintStr_(std::string_view str, std::source_location&& source_loc, BCLog::LogFlags category, BCLog::Level level, bool should_ratelimit) EXCLUSIVE_LOCKS_REQUIRED(m_cs); std::string GetLogPrefix(LogFlags category, Level level) const; @@ -220,7 +220,7 @@ namespace BCLog { std::atomic<bool> m_reopen_file{false}; /** Send a string to the log output */ - void LogPrintStr(std::string_view str, const std::source_location& source_loc, BCLog::LogFlags category, BCLog::Level level, bool should_ratelimit) + void LogPrintStr(std::string_view str, std::source_location&& source_loc, BCLog::LogFlags category, BCLog::Level level, bool should_ratelimit) EXCLUSIVE_LOCKS_REQUIRED(!m_cs); /** Returns whether logs will be written to any output */ @@ -320,7 +320,7 @@ static inline bool LogAcceptCategory(BCLog::LogFlags category, BCLog::Level leve bool GetLogCategory(BCLog::LogFlags& flag, std::string_view str); template <typename... Args> -inline void LogPrintFormatInternal(const std::source_location& source_loc, const BCLog::LogFlags flag, const BCLog::Level level, const bool should_ratelimit, util::ConstevalFormatString<sizeof...(Args)> fmt, const Args&... args) +inline void LogPrintFormatInternal(std::source_location&& source_loc, const BCLog::LogFlags flag, const BCLog::Level level, const bool should_ratelimit, util::ConstevalFormatString<sizeof...(Args)> fmt, const Args&... args) { if (LogInstance().Enabled()) { std::string log_msg; @@ -329,7 +329,7 @@ inline void LogPrintFormatInternal(const std::source_location& source_loc, const } catch (tinyformat::format_error& fmterr) { log_msg = "Error \"" + std::string{fmterr.what()} + "\" while formatting log message: " + fmt.fmt; } - LogInstance().LogPrintStr(log_msg, source_loc, flag, level, should_ratelimit); + LogInstance().LogPrintStr(log_msg, std::move(source_loc), flag, level, should_ratelimit); } } diff --git a/src/test/logging_tests.cpp b/src/test/logging_tests.cpp index 0043df182e..f5ce17aa23 100644 --- a/src/test/logging_tests.cpp +++ b/src/test/logging_tests.cpp @@ -97,12 +97,12 @@ BOOST_FIXTURE_TEST_CASE(logging_LogPrintStr, LogSetup) std::source_location::current(), std::source_location::current(), }; - LogInstance().LogPrintStr("foo1: bar1", source_locs[0], BCLog::LogFlags::NET, BCLog::Level::Debug, /*should_ratelimit=*/false); - LogInstance().LogPrintStr("foo2: bar2", source_locs[1], BCLog::LogFlags::NET, BCLog::Level::Info, /*should_ratelimit=*/false); - LogInstance().LogPrintStr("foo3: bar3", source_locs[2], BCLog::LogFlags::ALL, BCLog::Level::Debug, /*should_ratelimit=*/false); - LogInstance().LogPrintStr("foo4: bar4", source_locs[3], BCLog::LogFlags::ALL, BCLog::Level::Info, /*should_ratelimit=*/false); - LogInstance().LogPrintStr("foo5: bar5", source_locs[4], BCLog::LogFlags::NONE, BCLog::Level::Debug, /*should_ratelimit=*/false); - LogInstance().LogPrintStr("foo6: bar6", source_locs[5], BCLog::LogFlags::NONE, BCLog::Level::Info, /*should_ratelimit=*/false); + LogInstance().LogPrintStr("foo1: bar1", std::move(source_locs[0]), BCLog::LogFlags::NET, BCLog::Level::Debug, /*should_ratelimit=*/false); + LogInstance().LogPrintStr("foo2: bar2", std::move(source_locs[1]), BCLog::LogFlags::NET, BCLog::Level::Info, /*should_ratelimit=*/false); + LogInstance().LogPrintStr("foo3: bar3", std::move(source_locs[2]), BCLog::LogFlags::ALL, BCLog::Level::Debug, /*should_ratelimit=*/false); + LogInstance().LogPrintStr("foo4: bar4", std::move(source_locs[3]), BCLog::LogFlags::ALL, BCLog::Level::Info, /*should_ratelimit=*/false); + LogInstance().LogPrintStr("foo5: bar5", std::move(source_locs[4]), BCLog::LogFlags::NONE, BCLog::Level::Debug, /*should_ratelimit=*/false); + LogInstance().LogPrintStr("foo6: bar6", std::move(source_locs[5]), BCLog::LogFlags::NONE, BCLog::Level::Info, /*should_ratelimit=*/false); std::ifstream file{tmp_log_path}; std::vector<std::string> log_lines; for (std::string log; std::getline(file, log);) {

I've sort of implemented this. I wasn't able to use std::source_location&& in LogPrintStr_ because it's passed to two functions (FormatLogStrInPlace and NeedsRateLimiting) and implicit invalidation might occur. Instead, I pass std::source_location& and call std::move only when needed to invoke the move constructor.

src/logging.h

LogRateLimiter will be used to keep track of source locations and our current time-based logging window. It contains an unordered_map and unordered_set to track source locations. This will be used in a later commit by BCLog::Logger to manage all of the rate limiting logic. SourceLocationCounter counts the available bytes left for logging per source location for the current logging window. It does not track actual source locations; it is used as a value in m_source_locations. Co-Authored-By: Niklas Gogge <n.goeggi@gmail.com>

The std::source_location conveniently stores the file name, line number, and function name of a source code location. We switch to using it instead of the __func__ identifier and the __FILE__ and __LINE__ macros. Co-Authored-By: Niklas Gogge <n.goeggi@gmail.com>

To mitigate disk-filling attacks caused by unsafe usages of LogPrintf and friends, we rate-limit them by passing a should_ratelimit bool that eventually makes its way to LogPrintStr which may call LogRateLimiter::NeedsRateLimiting. The rate limiting is accomplished by adding a LogRateLimiter member to BCLog::Logger which tracks source code locations for the given logging window. Every hour, a source location can log up to 1MiB of data. Source locations that exceed the limit will have their logs suppressed for the rest of the window determined by m_limiter. Note that this rate limiting change does not affect callers that directly use LogPrintLevel with BCLog::Level >= BCLog::Level::Info. Co-Authored-By: Niklas Gogge <n.goeggi@gmail.com>

…te limiting Since UpdateTipLog logs heavily during IBD, we need to exempt it from rate limiting. This is done by using the LogPrintLevel_ macro so that we can explicitly set should_ratelimit to false. The public LogPrintLevel macro is intentionally un-used so as not to encourage potentially unsafe log macro usage. Co-Authored-By: Niklas Gogge <n.goeggi@gmail.com>

We mark ~DebugLogHelper as noexcept(false) to be able to catch the exception it throws. This lets us use it in test in combination with BOOST_CHECK_THROW and BOOST_CHECK_NO_THROW to check that certain log messages are (not) logged. Co-Authored-By: Niklas Gogge <n.goeggi@gmail.com>

…Counter Co-Authored-By: Niklas Gogge <n.goeggi@gmail.com>

The rate_limiting test checks that: - rate limiting is disabled for exempt source locations - the debug.log file size changes as expected when rate limiting - the expected rate limiting-specific log messages are written Co-Authored-By: Niklas Gogge <n.goeggi@gmail.com>

DrahtBot · 2025-06-11T15:46:43Z

🚧 At least one of the CI tasks failed.
_{Task ARM, unit tests, no functional tests: https://github.com/bitcoin/bitcoin/runs/43903011789}
_{LLM reason (✨ experimental): The CI failure is caused by a compilation error in logging_tests.cpp due to a narrowing type conversion resulting in the build stopping.}

Hints

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.

Crypt-iQ · 2025-06-11T16:56:16Z

The latest push a7bd7c9 includes:

rate limiting for callers of LogPrintLevel with level >= BCLog::Level::Info.
fix for the windows cross-built CI by using GetFileSize instead of fs::file_size in logging_tests/rate_limiting

I've repurposed the old logging rpc from #21603 in another branch for testing here. This can be used to log from source locations and test out the new changes in logging behavior. Note that the setmocktime RPC needs to be used to set the mock time past the current clock time to reset the logging messages.

Example usage:

bitcoin-cli -regtest excessivelog 1 1048500 # log just under 1MiB
bitcoin-cli -regtest excessivelog 1 100 # this should get the total amount logged above 1MiB
                                        # and the rate limiting logic should kick in
bitcoin-cli -regtest excessivelog 2 1048500
bitcoin-cli -regtest excessivelog 2 100 # trigger rate limiting from another location
bitcoin-cli -regtest setmocktime <N> # set this past the current clock time because of how `LogRateLimiter` is initialized
bitcoin-cli -regtest excessivelog 1 100 # this should trigger logging to resume and will log the source locations that were reset

Example output:

[*] Excessive logging detected from rpc/node.cpp:139 (RPCHelpMan excessivelog()): >1 MiB logged during the last hour.Suppressing logging to disk from this source location for up to one hour. Console logging unaffected. Last log entry.2025-06-11T16:32:41Z aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa
[*] Excessive logging detected from rpc/node.cpp:142 (RPCHelpMan excessivelog()): >1 MiB logged during the last hour.Suppressing logging to disk from this source location for up to one hour. Console logging unaffected. Last log entry.2025-06-11T16:33:04Z aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa
Restarting logging from rpc/node.cpp:139 (RPCHelpMan excessivelog()): (1 MiB) were dropped during the last hour.
Restarting logging from rpc/node.cpp:142 (RPCHelpMan excessivelog()): (0 MiB) were dropped during the last hour.

DrahtBot added the Utils/log/libs label May 23, 2025

DrahtBot added the CI failed label May 23, 2025

janb84 reviewed May 26, 2025

View reviewed changes

src/logging.h Outdated Show resolved Hide resolved

DrahtBot requested review from davidgumberg and dergoegge May 26, 2025 13:41

Crypt-iQ force-pushed the log_ratelimiting_05192025 branch from 0bc6ed6 to 6dece05 Compare May 28, 2025 14:38

stickies-v reviewed May 30, 2025

View reviewed changes

src/logging.h Outdated Show resolved Hide resolved

src/init/common.cpp Outdated Show resolved Hide resolved

src/logging.h Outdated Show resolved Hide resolved

stickies-v reviewed May 30, 2025

View reviewed changes

l0rinc suggested changes Jun 3, 2025

View reviewed changes

src/init/common.cpp Outdated Show resolved Hide resolved

src/logging.h Outdated Show resolved Hide resolved

src/logging.h Outdated Show resolved Hide resolved

Crypt-iQ force-pushed the log_ratelimiting_05192025 branch from 6dece05 to b275b24 Compare June 4, 2025 17:37

Crypt-iQ commented Jun 4, 2025

View reviewed changes

Crypt-iQ force-pushed the log_ratelimiting_05192025 branch from b275b24 to 5535df6 Compare June 4, 2025 20:52

DrahtBot removed the CI failed label Jun 4, 2025

stickies-v reviewed Jun 5, 2025

View reviewed changes

src/logging.cpp Outdated Show resolved Hide resolved

Crypt-iQ force-pushed the log_ratelimiting_05192025 branch 2 times, most recently from 4643260 to 7304113 Compare June 5, 2025 18:57

DrahtBot added the CI failed label Jun 5, 2025

Crypt-iQ force-pushed the log_ratelimiting_05192025 branch from 7304113 to 3c6cb37 Compare June 5, 2025 19:23

Crypt-iQ force-pushed the log_ratelimiting_05192025 branch 2 times, most recently from 21a3a50 to 911ee52 Compare June 5, 2025 21:59

DrahtBot removed the CI failed label Jun 5, 2025

stickies-v reviewed Jun 6, 2025

View reviewed changes

Crypt-iQ force-pushed the log_ratelimiting_05192025 branch from 911ee52 to 387ccd9 Compare June 11, 2025 15:26

Crypt-iQ and others added 7 commits June 11, 2025 11:46

test: introduce logging_sourcelocation_counter to test SourceLocation…

eb510cc

…Counter Co-Authored-By: Niklas Gogge <n.goeggi@gmail.com>

Crypt-iQ force-pushed the log_ratelimiting_05192025 branch from 387ccd9 to a7bd7c9 Compare June 11, 2025 15:46

DrahtBot added the CI failed label Jun 11, 2025

DrahtBot removed the CI failed label Jun 11, 2025

log: Mitigate disk filling attacks by rate limiting LogPrintf, LogInfo, LogWarning, LogError #32604

Are you sure you want to change the base?

log: Mitigate disk filling attacks by rate limiting LogPrintf, LogInfo, LogWarning, LogError #32604

Uh oh!

Conversation

Uh oh!

Uh oh!

Uh oh!

Code Coverage & Benchmarks

Reviews

Conflicts

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Uh oh!

Uh oh!

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!

Uh oh!