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

nit: would be nice to align the other initializations to the new C++ 11 {} style in a follow up PR, to keep the code base consistent.

I can do that in a follow-up

I have opted not to do this in the follow-up PR.

nit: I think a brief docstring on their suggested usage here would be helpful here

I'm not sure introducing two extra category flags is a good abstraction here - feels noisy. Wouldn’t it be cleaner to decide based on exposure to the attack surface instead? For example, during IBD (or any state with zero peer connections) we could leave all logs unrestricted, and always enable rate-limiting when node is reachable by peers.

See #32604 (review), will change. Imo, having to determine whether we are in IBD or have zero peer connections is heading into too much complexity. This PR shouldn't cause IBD debug logs to be rate-limited, but if it does we should fix that.

Resolving as I've removed categories.

Is there a good use case for disabling rate limiting? I can't think of one. Letting the user define the amount of rate limiting is an alternative, but even then, I'm not sure. If an attacker or bug is able to reach the sane default maximum, then is the user really going to get any benefit from being to inspect the additional volume of un-ratelimited logs? I'm not sure. If so, I think it would make sense to not have this as a configurable option.

That's a good point, I can't think of any concrete use case to disable rate limiting here.

@dergoegge might remember why this was added?

fwiw: I can't find any discussion about it in #21603, and the option was present from the first version of the PR (https://github.com/bitcoin/bitcoin/commit/4648b6d207139ec0ab2994f56c0a47f81cdf516a#diff-b1e19192258d83199d8adaa5ac31f067af98f63554bfdd679bd8e8073815e69d)

When I’m benchmarking IBD, I don’t want any artificial size or rate limits. Since the attack only matters when peers can influence us, could we simply disable rate-limiting for all logs during IBD/reindexes/assumeutxo?

Should the docs explicitly state the 1 MiB-per-hour cap, or could we replace the boolean flag with a numeric "MiB per hour" parameter (retaining 0 and 1 as the current meanings)?

Since the attack only matters when peers can influence us, could we simply disable rate-limiting for all logs during IBD

?

Can you be more specific :)?

What do you mean by "peers not being able to influence us during IBD"?

I meant that during IBD we’re mostly replaying validated history, and my understanding is that rate-limiting is meant to protect logs caused by peer-supplied invalid data, not the deterministic IBD progress logs (e.g. -debug=bench or -debug=leveldb, which are very verbose (way over the 1MiB/h), but isn't related to a user-sent serialization error or similar cheap attack). "Attacking" a node that is still in the original IBD seems less severe to me than skipped logs. I also understand if you disagree with this and I would appreciate an explanation, I want to understand.

We can still get invalid data (thanks for triggering a clarification), but maybe the guard should added per LogFlags and we may want to blacklist instead of whitelisting. Or is this meant as a final catch-all for all the unknowns, e.g. maybe there's a trick to enable LevelDB logs externally and this should still guard against that?

I believe that if somebody is using -debug=bench or -debug=leveldb, the fact that they are using a category should bypass the rate limit if LogDebug is used. I think the mitigation should be in place whether or not we're in IBD -- if we have any peers (inbound or outbound), we need to be cautious. This patch is meant to be the "final catch-all" like you said to fully eliminate this class of attack.

Thanks for clarifying

It seems like this startup option is still in the latest force-push (5914a2ee6c915585b7213217047ad1644b873376), but from this discussion it doesn't seem like there are good arguments to keep it? I'm not sure if @l0rinc still needs it for IBD bench reasons, but imo that's way too much of a niche to keep it as a startup option?

I'm doing a reindex benchmark to check if the current implementation has any performance burden

Edit: reindexing until 900k indicates there's no slowdown caused by this change

<details> <summary>Details</summary>

COMMITS="e95bfc1d537e06d223dfcaec510181aa3d3f8386 f29b081b9277332523b7025394cad15b02cc53d2"; \
STOP=900000; DBCACHE=2500; \
CC=gcc; CXX=g++; \
BASE_DIR="/mnt/my_storage"; DATA_DIR="$BASE_DIR/BitcoinData"; LOG_DIR="$BASE_DIR/logs"; \
(echo ""; for c in $COMMITS; do git fetch -q origin $c && git log -1 --pretty='%h %s' $c || exit 1; done; echo "") && \
hyperfine \
  --sort command \
  --runs 1 \
  --export-json "$BASE_DIR/rdx-$(sed -E 's/(\w{8})\w+ ?/\1-/g;s/-$//'<<<"$COMMITS")-$STOP-$DBCACHE-$CC.json" \
  --parameter-list COMMIT ${COMMITS// /,} \
  --prepare "killall bitcoind; rm -f $DATA_DIR/debug.log; git checkout {COMMIT}; git clean -fxd; git reset --hard && \
    cmake -B build -G Ninja -DCMAKE_BUILD_TYPE=Release && ninja -C build bitcoind && \
    ./build/bin/bitcoind -datadir=$DATA_DIR -stopatheight=$STOP -dbcache=1000 -printtoconsole=0; sleep 10" \
  --cleanup "cp $DATA_DIR/debug.log $LOG_DIR/debug-{COMMIT}-$(date +%s).log" \
  "COMPILER=$CC ./build/bin/bitcoind -datadir=$DATA_DIR -stopatheight=$STOP -dbcache=$DBCACHE -reindex -blocksonly -connect=0 -printtoconsole=0"

e95bfc1d53 Merge bitcoin/bitcoin#32797: doc: archive 28.2 release notes f29b081b92 doc: add release notes for new rate limiting logging behavior

Benchmark 1: COMPILER=gcc ./build/bin/bitcoind -datadir=/mnt/my_storage/BitcoinData -stopatheight=900000 -dbcache=2500 -reindex -blocksonly -connect=0 -printtoconsole=0 (COMMIT = e95bfc1d537e06d223dfcaec510181aa3d3f8386)
  Time (abs ≡):        29033.291 s               [User: 43597.672 s, System: 1644.619 s]
 
Benchmark 2: COMPILER=gcc ./build/bin/bitcoind -datadir=/mnt/my_storage/BitcoinData -stopatheight=900000 -dbcache=2500 -reindex -blocksonly -connect=0 -printtoconsole=0 (COMMIT = f29b081b9277332523b7025394cad15b02cc53d2)
  Time (abs ≡):        28875.472 s               [User: 43552.019 s, System: 1541.380 s]

Relative speed comparison
        1.01          COMPILER=gcc ./build/bin/bitcoind -datadir=/mnt/my_storage/BitcoinData -stopatheight=900000 -dbcache=2500 -reindex -blocksonly -connect=0 -printtoconsole=0 (COMMIT = e95bfc1d537e06d223dfcaec510181aa3d3f8386)
        1.00          COMPILER=gcc ./build/bin/bitcoind -datadir=/mnt/my_storage/BitcoinData -stopatheight=900000 -dbcache=2500 -reindex -blocksonly -connect=0 -printtoconsole=0 (COMMIT = f29b081b9277332523b7025394cad15b02cc53d2)

</details>

Sweet, thanks for doing this! I was curious about any performance hits.

Hmm, I'm feeling uneasy about using m_categories, when rate limiting flags fundamentally don't represent a category. I can see how it reduces the diff, but I'm not sure that's worth it. I'll think about an alternative approach - have you considered any already?

Since the user doesn't have to be able to configure any of this, and we only have a single UNCONDITIONAL_ALWAYS use case (and likely won't have (many) more in the future), I think adding an is_conditional=True arg to LogPrintLevel and a LogInfoAlways macro might be an alternative?

I haven't considered alternative approaches, but I think adding a boolean is better than adding special-cased categories.

Or perhaps even better than a boolean is a uint64_t rate_limit=DEFAULT_RATE_LIMIT so we can do away with the distinction between ratelimited and non-ratelimited logging entirely? We could use rate_limit=0 as a synonym for non-ratelimited logging, but I think even UpdateTipLog() doesn't have to be exempt from rate limiting, we could still set a sane value that allows doing entire IBD in one hour, for example.

Then UpdateTipLog() could just use:

    LogInfo(/*rate_limit=*/100, "%s%s: new best=%s height=%d version=0x%08x log2_work=%f tx=%lu date='%s' progress=%f cache=%.1fMiB(%utxo)%s\n",

I think callers just need to be aware that they cannot set the rate limit very high in certain cases. Maybe this change and a comment will suffice?

While implementing this, I came to the conclusion that because macros don't have default arguments, skipping the rate limiting for UpdateTipLog means that we need to: 1) introduce a new macro for IBD specifically for UpdateTipLog, or 2) modify all call-sites of whichever macro UpdateTipLog uses to accept a rate_limit argument.

I am partial to introducing a new macro for UpdateTipLog since it gets rid of the noise in the categories logic. I think that option 2) to modify all call-sites to pass in a rate-limiting argument is cumbersome when most callers don't need to be aware of rate limiting and it should instead be done under-the-hood (i.e. UpdateTipLog is the exception to the rule). I think using a boolean for rate-limiting vs no-rate-limiting is better than a uint64_t because then the proposed SourceLocationCounter needs to also keep track of this window-scaling value (i.e. multiple of WINDOW_MAX_BYTES).

I might be wrong here, curious to hear thoughts.

2. to modify all call-sites to pass in a rate-limiting argument is cumbersome

Absolutely agree that would not be an improvement.

I think using a boolean for rate-limiting vs no-rate-limiting is better than a uint64_t

I think either will work fine, the uint64_t generalizes a bit nicer but we probably won't be needing the generalization in the future, so whichever ends up being the most elegant implementation now is what I think we should go for.

I am partial to introducing a new macro for UpdateTipLog

That seems sensible to me, yes.

I've changed this so that the logging macros eventually pass a should_ratelimit bool to LogPrintStr. Instead of introducing a new macro for UpdateTipLog, it now uses LogPrintLevel which can bypass the rate-limiting. I'm not sure how I feel about using LogPrintLevel as I don't want to encourage more usage of it in the codebase as it could be a potential footgun.

I think it's unintuitive that this function returns true when the operation failed. It seems like the rate limiting can be carved out pretty much as-is into a separate bool NeedsRateLimiting() function? There are only 2 callsites of FormatLogStrAndRateLimit, and the first one (StartLogging) doesn't look like it needs rate limiting because we already have a max buffer size?

edit: this would pair fairly well with my suggestion here

Yup, this makes sense as well. Can change.

I've carved this out into a NeedsRateLimiting function and have kept the logic of FormatLogStrInPlace mostly unchanged. The reason I had the original change is because FormatLogStrInPlace inserts a timestamp at the beginning of str and I wanted the prepended rate-limiting logs to occur after the timestamp. With the new change, the rate-limiting logs are first in str followed by the time-stamp. I think now the logs look a little wonky, but I like the code change better. I could also extract the time-stamp prepend logic so it's called after NeedsRateLimiting.

Not a big issue, but since we have quite a few log source locations, this class will be instantiated a fair amount of (N) times. An alternative approach would be to have a single LogRateLimiter instance that encapsulates most of the logic in 6b54362c19ca9baf9dfa9be9281f6faeda169420, and has a single m_last_reset member, spawning a minimal SourceLocationCounter struct for each source location, containing just the m_available_bytes and m_dropped_bytes members.

This:

• reduces N std::chrono::time_point<NodeClock> instances to just 1
• allows LogRateLimiter to completely clean up memory for log locations that haven't been triggered in the last hour
• improves code encapsulation

Overall, this shouldn't be a big change from what you have now, mostly just moving code around into a new class?

Yup I had thought about this and wasn't sure how to evaluate the overhead. I'll change it.

Implemented this change, lmk what you think. I think this encapsulates code a bit better, but it probably could still be improved.

I've left some comments for further encapsulation, but yeah I think this a step in the right direction, thanks!

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?

Not sure we would catch that with our test suite. But if it's meant to draw the users' attention early for false positives, maybe we could log a warning at least. (theoretically the tests could also fail for unregistered extra log warnings)

Just checking in to say it would be possible to add (and test) after #32588 by using test_only_CheckFailuresAreExceptionsNotAborts in the unit tests.

Do we ever clear m_ratelimiters, or does that map only grow over the lifetime of the process?

This never gets cleared. I haven't calculated the overhead of the map, but it could make sense to clear it periodically. Do you think it should just be on a timer or something?

note: this is part of my suggestion in #32604 (review)

@stickies-v, my mistake, I quickly wanted to make sure this doesn't affect my IBD benchmarks, didn't have time to review it in detail yet

Both the map and set are now cleared if LogRateLimiter determines that the logging window should be reset.

in bec74626867abefbfc55da5aaaf8a0c030663f3a:

nit: comparing ints is more performant than comparing strings, and is more differentiating than the filename, so would do the line comparison first

        return lhs.line() == rhs.line() && strcmp(lhs.file_name(), rhs.file_name()) == 0 ;

NeedsRateLimiting as well as the underlying maps imo belong to LogRateLimiter rather than Logger. I also don't think should_ratelimit is a meaningful parameter, the function should just not be called if that's false. I also don't understand why logging_function is a separate parameter - can't we just get that from source_loc?

Suggested diff that incorporates all of those suggestions:

<details> <summary>git diff on 5535df69a2</summary>

diff --git a/src/logging.cpp b/src/logging.cpp
index 1e20c10368..c4ae881ffd 100644
--- a/src/logging.cpp
+++ b/src/logging.cpp
@@ -5,6 +5,7 @@
 
 #include <logging.h>
 #include <memusage.h>
+#include <sync.h>
 #include <util/check.h>
 #include <util/fs.h>
 #include <util/string.h>
@@ -376,41 +377,40 @@ static size_t MemUsage(const BCLog::Logger::BufferedLog& buflog)
     return buflog.str.size() + buflog.logging_function.size() + strlen(buflog.source_loc.file_name()) + buflog.threadname.size() + memusage::MallocUsage(sizeof(memusage::list_node<BCLog::Logger::BufferedLog>));
 }
 
-bool BCLog::Logger::NeedsRateLimiting(bool should_ratelimit, const std::source_location& source_loc, std::string& str, std::string_view logging_function)
+bool BCLog::LogRateLimiter::NeedsRateLimiting(const std::source_location& source_loc, std::string& str)
 {
+    StdLockGuard scoped_lock(m_cs);
     // Whether or not logging to disk was/is ratelimited for this source location.
     bool was_ratelimited{false};
     bool is_ratelimited{false};
 
-    if (m_ratelimit && should_ratelimit) {
-        // Check to see if we were rate limited before calling ResetWindow.
-        was_ratelimited = m_suppressed_locations.find(source_loc) != m_suppressed_locations.end();
+    // Check to see if we were rate limited before calling ResetWindow.
+    was_ratelimited = m_suppressed_locations.find(source_loc) != m_suppressed_locations.end();
 
-        // If the m_limiter window has elapsed, then we need to clear the unordered map and set.
-        if (m_limiter.ResetWindow()) {
-            m_source_locations.clear();
-            m_suppressed_locations.clear();
-        }
+    // If the m_limiter window has elapsed, then we need to clear the unordered map and set.
+    if (ResetWindow()) {
+        m_source_locations.clear();
+        m_suppressed_locations.clear();
+    }
 
-        is_ratelimited = !m_source_locations[source_loc].Consume(str.size());
+    is_ratelimited = !m_source_locations[source_loc].Consume(str.size());
 
-        if (!is_ratelimited && was_ratelimited) {
-            uint64_t dropped_bytes = m_source_locations[source_loc].GetDroppedBytes();
+    if (!is_ratelimited && was_ratelimited) {
+        uint64_t dropped_bytes{m_source_locations[source_loc].GetDroppedBytes()};
 
-            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(), logging_function,
-                                    dropped_bytes / (1024 * 1024)));
-        } else if (is_ratelimited && !was_ratelimited) {
-            // Logging from this source location will be suppressed until the current window resets.
-            m_suppressed_locations.insert(source_loc);
+        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)));
+    } else if (is_ratelimited && !was_ratelimited) {
+        // Logging from this source location will be suppressed until the current window resets.
+        m_suppressed_locations.insert(source_loc);
 
-            str.insert(0, strprintf("Excessive logging detected from %s:%d (%s): >%d 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.",
-                                    source_loc.file_name(), source_loc.line(), logging_function,
-                                    LogRateLimiter::WINDOW_MAX_BYTES / (1024 * 1024)));
-        }
+        str.insert(0, strprintf("Excessive logging detected from %s:%d (%s): >%d 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.",
+                                source_loc.file_name(), source_loc.line(), source_loc.function_name(),
+                                LogRateLimiter::WINDOW_MAX_BYTES / (1024 * 1024)));
     }
 
     // To avoid confusion caused by dropped log messages when debugging an issue,
@@ -479,7 +479,7 @@ void BCLog::Logger::LogPrintStr_(std::string_view str, std::string_view logging_
     }
 
     FormatLogStrInPlace(str_prefixed, category, level, source_loc, logging_function, util::ThreadGetInternalName(), SystemClock::now(), GetMockTime());
-    bool ratelimit = NeedsRateLimiting(should_ratelimit, source_loc, str_prefixed, logging_function);
+    bool ratelimit = m_ratelimit && should_ratelimit && m_limiter.NeedsRateLimiting(source_loc, str_prefixed);
 
     if (m_print_to_console) {
         // print to console
diff --git a/src/logging.h b/src/logging.h
index b94b9cb495..f9441f6913 100644
--- a/src/logging.h
+++ b/src/logging.h
@@ -48,7 +48,7 @@ struct SourceLocationHasher {
     {
         // Use CSipHasher(0, 0) as a simple way to get uniform distribution.
         return static_cast<size_t>(CSipHasher(0, 0)
-                                       .Write(std::hash<std::string>{}(s.file_name()))
+                                       .Write(std::hash<std::string_view>{}(s.file_name()))
                                        .Write(std::hash<int>{}(s.line()))
                                        .Finalize());
     }
@@ -106,13 +106,18 @@ namespace BCLog {
     constexpr auto DEFAULT_LOG_LEVEL{Level::Debug};
     constexpr size_t DEFAULT_MAX_LOG_BUFFER{1'000'000}; // buffer up to 1MB of log data prior to StartLogging
 
+    class SourceLocationCounter;
     //! Fixed window rate limiter for logging.
     class LogRateLimiter
     {
     private:
         //! Timestamp of the last window reset.
         std::chrono::time_point<NodeClock> m_last_reset;
-
+        //! Counters for each source location that has attempted to log something.
+        std::unordered_map<std::source_location, SourceLocationCounter, SourceLocationHasher, SourceLocationEqual> m_source_locations GUARDED_BY(m_cs);
+        //! Set of source file locations that were dropped on the last log attempt.
+        std::unordered_set<std::source_location, SourceLocationHasher, SourceLocationEqual> m_suppressed_locations GUARDED_BY(m_cs);
+        mutable StdMutex m_cs; // TODO: does LogRateLimiter need to use Logger:m_cs instead? Didn't investigate.
     public:
         //! Interval after which the window is reset.
         static constexpr std::chrono::hours WINDOW_SIZE{1};
@@ -120,6 +125,8 @@ namespace BCLog {
         static constexpr uint64_t WINDOW_MAX_BYTES{1024 * 1024};
         //! Attempts to reset the window if the window interval has passed. Returns true if the window was reset.
         bool ResetWindow();
+        //! Check if we need to rate limit a source_location.
+        bool NeedsRateLimiting(const std::source_location& source_loc, std::string& str) EXCLUSIVE_LOCKS_REQUIRED(!m_cs);
 
         LogRateLimiter() : m_last_reset{NodeClock::now()} {}
 
@@ -176,10 +183,6 @@ namespace BCLog {
 
         //! Keeps track of the last time we've reset the logging window.
         LogRateLimiter m_limiter GUARDED_BY(m_cs);
-        //! Counters for each source location that has attempted to log something.
-        std::unordered_map<std::source_location, SourceLocationCounter, SourceLocationHasher, SourceLocationEqual> m_source_locations GUARDED_BY(m_cs);
-        //! Set of source file locations that were dropped on the last log attempt.
-        std::unordered_set<std::source_location, SourceLocationHasher, SourceLocationEqual> m_suppressed_locations GUARDED_BY(m_cs);
 
         //! Category-specific log level. Overrides `m_log_level`.
         std::unordered_map<LogFlags, Level> m_category_log_levels GUARDED_BY(m_cs);
@@ -193,9 +196,6 @@ namespace BCLog {
 
         void FormatLogStrInPlace(std::string& str, LogFlags category, Level level, const std::source_location& source_loc, std::string_view logging_function, std::string_view threadname, SystemClock::time_point now, std::chrono::seconds mocktime) const;
 
-        /** Check if we need to rate limit a source_location. */
-        bool NeedsRateLimiting(bool should_ratelimit, const std::source_location& source_loc, std::string& str, std::string_view logging_function) EXCLUSIVE_LOCKS_REQUIRED(m_cs);
-
         std::string LogTimestampStr(SystemClock::time_point now, std::chrono::seconds mocktime) const;
 
         /** Slots that connect to the print signal */

</details>

Note: I didn't think about thread safety much yet, so I just threw in another m_cs to make it compile and pass tests, might be wrong/unsafe as-is.

I've removed logging_function and __func__ usage. I think it makes the function names a little longer in the map, but I'm ok with it. I think m_cs is unnecessary if m_ratelimiter is guarded by m_cs?

I think it makes the function names a little longer in the map, but I'm ok with it.

Oh interesting, I didn't realize that. On my machine, __func__ contains just the function name, whereas function_name() returns the entire signature, e.g.:

__func__: AppInitParameterInteraction
source_location: bool AppInitParameterInteraction(const ArgsManager &)

I don't see how this affects any maps, though? I think it just affects the messages when we stop and restart logging?

I think m_cs is unnecessary if m_ratelimiter is guarded by m_cs?

Yeah nice, that seems correct. Probably good to add "This class is not thread-safe." to the LogRateLimiter docstring, given that it is likely to be used in a multithreaded context.

I don't see how this affects any maps, though? I think it just affects the messages when we stop and restart logging?

Oh, I think I mistakenly thought that function_name was included in the map somehow or used when hashing std::source_location, but I see that's not actually the case.

nit: string_view to avoid unnecessary string construction

                                       .Write(std::hash<std::string_view>{}(s.file_name()))

The previous docstring is misleading, LogPrintLevel() can also be used for unconditional logging when a Level::Info is passed as level, as is e.g. done in mapport.cpp and in a few other places. I don't think this is a robust way of deciding on rate limiting.

I think I would prefer either:

1. using LogPrintLevel_ directly in UpdateTipLog(), with a comment on why we're using a private function and not enabling rate limiting here. A LogInfoAlways macro could be an alternative.
2. refactoring logging.h replace a lot of the current macros to become regular functions using std::source_location, allowing easier overloads for ratelimiting. This probably makes more sense in a separate pull, so imo going with 1. in this PR and then improving with 2. separately would be nice?

I've changed the misleading docstring and I've implemented suggestion 1. and I will pick up suggestion 2. as well. I think this might conflict a bit with the work in #29256.

Nice. Since af86b55f996cf06e8e9179d5c1fe7ce3d94fa3c6 now uses LogPrintLevel_ directly, I think the changes to LogPrintLevel in ed3c0a592b60a565ec5dade7c3af62e7f4cf75a1 can now be reverted and rate limiting applied consistently to all "public" macros? (would also require an update to the UpdateTipLog docstring)

I'm a little unsure about adding rate-limiting to LogPrintLevel as then if a user runs with -debug, they could potentially hit the rate-limit via LogDebug or by some of the existing LogPrintLevel calls. I think it is in the user's best interest to have rate-limiting applied to all public macros like you suggested, but I also don't want to potentially confuse users as to why their debug.log is incomplete due to rate-limiting when they are just running with -debug.

Oh no I agree, debug logs should be exempt from ratelimiting. My point is just that I think it's bad to have different logging behaviour depending on whether LogInfo() or LogPrintLevel(..., BCLog::Info) is used, so I think something like the below would work well?

<details> <summary>git diff on 911ee520c8</summary>

diff --git a/src/logging.h b/src/logging.h
index d588ef86dc..5f298405e7 100644
--- a/src/logging.h
+++ b/src/logging.h
@@ -349,17 +349,13 @@ inline void LogPrintFormatInternal(const std::source_location& source_loc, const
 // Use a macro instead of a function for conditional logging to prevent
 // evaluating arguments when logging for the category is not enabled.
 
-// Log by prefixing the output with the passed category name and severity level. This can either
-// log conditionally if the category is allowed or unconditionally if level >= BCLog::Level::Info
-// is passed. Note that this function bypasses rate limiting. Callers need to take care to ensure
-// that an attacker cannot trigger a disk-fill vulnerability if level >= Info is used. Additionally,
-// users specifying -debug are assumed to be developers or power users who are aware that -debug
-// may cause excessive disk usage due to logging.
-#define LogPrintLevel(category, level, ...)                                           \
-    do {                                                                              \
-        if (LogAcceptCategory((category), (level))) {                                 \
-            LogPrintLevel_(category, level, /*should_ratelimit=*/false, __VA_ARGS__); \
-        }                                                                             \
+// Log conditionally, prefixing the output with the passed category name and severity level.
+#define LogPrintLevel(category, level, ...)                             \
+    do {                                                                \
+        if (LogAcceptCategory((category), (level))) {                   \
+            bool rate_limit{level >= BCLog::Info};                      \
+            LogPrintLevel_(category, level, rate_limit, __VA_ARGS__);   \
+        }                                                               \
     } while (0)
 
 // Log conditionally, prefixing the output with the passed category name.

</details>

Oh I completely misunderstood! I like this suggestion a lot and I think it plugs the hole. I am not sure the future plans for LogPrintLevel but I wonder if eventually all instances of LogPrintLevel with level >= BCLog::Info could instead be converted to LogInfo or the equivalent?

In a general sense, having a generalized logging function is helpful when the loglevel isn't known in advance, as is e.g. the case here: https://github.com/bitcoin/bitcoin/blob/f3bbc746647d1fd23bf5cfe357e32f38c5f6319c/src/httpserver.cpp#L440

It seems like we currently don't really need it in our codebase, but I would keep that discussion for a separate PR because it would lead us astray a bit much here?

Resolving as it's now addressed.

This logic should be encapsulated in ResetWindow imo, so probably this statement could just be:

        m_limiter.MaybeResetWindow();

nit: moving it into the BCLog namespace seems fine, but BCLog::WINDOW_MAX_BYTES is not a very helpful name. RATELIMIT_MAX_BYTES probably better?

nit: line length

        //! Attempts to reset the logging window if the window interval has passed. This will clear
        //! m_source_locations and m_suppressed_locations if a reset occurs.

Docstring could be beefed up a bit to highlight that this is not a pure check but has side effects. E.g.:

        //! Consumes `source_loc`'s available bytes corresponding to the size of the (formatted)
        //! `str` and returns true if it exceeds the allowance in the current time window.

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.

Yeah, that looks good, thanks. It's unfortunate that these message are counted in is_ratelimited = !m_source_locations[source_loc].Consume(str.size());, but suppressions should be extremely rare, so triggering enough of them to cause a meaningful difference here seems impractical. A solution with not too much change could be to change to MaybeResetWindow(const std::string& str, std::string& resume_msg), so we can keep separate accounting, but yeah not sure that's worth it/important.

Deciding to keep as-is

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?

Done

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?

<details> <summary>git diff on 911ee520c8</summary>

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);) {

</details>

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.

I am not sure how I feel about my approach here because the caller of LogPrintStr_ now needs to be aware that std::source_location& can be moved-from?

I misunderstood the original suggestion and have now implemented it in ca0c1a7a9ce9198c950e123d36c9e4bb13db13da

In the two-part string literal in NeedsRateLimiting: “…during the last hour.”"Suppressing logging…” -> “…during the last hour. Suppressing logging…” [missing space between sentences due to C++ literal concatenation]

nit: I don't think hashing the line is necessary?

                                       .Write(s.line())

Yup good catch

nit: I think this can be simplified a bit:

<details> <summary>git diff on b7d9c669ca</summary>

diff --git a/src/logging.cpp b/src/logging.cpp
index 827d1bad10..fec8e5ec58 100644
--- a/src/logging.cpp
+++ b/src/logging.cpp
@@ -379,17 +379,13 @@ static size_t MemUsage(const BCLog::Logger::BufferedLog& buflog)
 
 bool BCLog::LogRateLimiter::NeedsRateLimiting(const std::source_location& source_loc, std::string& str)
 {
-    // Whether or not logging to disk was/is ratelimited for this source location.
-    bool was_ratelimited{false};
-    bool is_ratelimited{false};
-
     // Check to see if we were rate limited before calling MaybeResetWindow.
-    was_ratelimited = m_suppressed_locations.find(source_loc) != m_suppressed_locations.end();
+    bool was_ratelimited{m_suppressed_locations.contains(source_loc)};
 
     // If the window has elapsed, then we need to clear the unordered map and set.
     MaybeResetWindow(str);
 
-    is_ratelimited = !m_source_locations[source_loc].Consume(str.size());
+    bool is_ratelimited{!m_source_locations[source_loc].Consume(str.size())};
 
     if (is_ratelimited && !was_ratelimited) {
         // Logging from this source location will be suppressed until the current window resets.

</details>

nit: updating the ca0c1a7a9ce9198c950e123d36c9e4bb13db13da commit message with a brief mention of the behaviour change for -logsourcelocations would be helpful for both review and historical documentation purposes.

nit: I don't think it's crucial to be super precise here, since it's only used briefly during startup, but I think this underestimating the std::source_location size a bit. It's not accounting the 2*4 bytes for line and column, nor the pointers (3 on gcc) used to implement std::source_location. If people think it's crucial to get this (more) right, probably adding a separate MemUsage(const std::source_location&) could make sense.

I also noticed this and wasn't sure if it was worth bringing up.

I was long overdue for my biannual confusion about (dynamic) memory usage, but luckily here it is. It seems like I got it entirely backwards in my previous comment. The memory pointed to by std::source_location is static, so I don't think we need to account for any of it beyond what the memusage::MallocUsage(sizeof(memusage::list_node<BCLog::Logger::BufferedLog>)) statement is already doing.

Orthogonal, but since we're touching the line anyway: dynamic memory usage of std::string should be measured with .capacity() instead of .size(). Or even better, use the DynamicUsage(const std::string&) function we already have to also account for small string optimization, which, of course, is totally a thing.

So the function could become:

static size_t MemUsage(const BCLog::Logger::BufferedLog& buflog)
{
    return memusage::DynamicUsage(buflog.str) +
           memusage::DynamicUsage(buflog.threadname) +
           memusage::MallocUsage(sizeof(memusage::list_node<BCLog::Logger::BufferedLog>));
}

All in all, this should mean that thanks to ca0c1a7a9ce9198c950e123d36c9e4bb13db13da we can now buffer quite a bit more messages within our 1MB limit. Obviously not going to change anything meaningful, but wouldn't hurt to add a line to commit msg to highlight that.

Nice catch, I missed that std::source_location was part of BufferedLog and therefore included in the MallocUsage call.

👍

nit: requires #include <utility>

nit: can be cleaned up a bit:

<details> <summary>git diff on b7d9c669ca</summary>

diff --git a/src/test/logging_tests.cpp b/src/test/logging_tests.cpp
index c9b7913ee4..d673792ab6 100644
--- a/src/test/logging_tests.cpp
+++ b/src/test/logging_tests.cpp
@@ -114,15 +114,16 @@ BOOST_FIXTURE_TEST_CASE(logging_LogPrintStr, LogSetup)
     for (std::string log; std::getline(file, log);) {
         log_lines.push_back(log);
     }
-    std::string file_name = util::RemovePrefix(source_locs[0].file_name(), "./");
-    std::string function_name{source_locs[0].function_name()};
+    auto format_source_location = [](const std::source_location& loc) {
+        return tfm::format("[%s:%s] [%s]", util::RemovePrefixView(loc.file_name(), "./"), loc.line(), loc.function_name());
+    };
     std::vector<std::string> expected = {
-        "[" + file_name + ":" + util::ToString(source_locs[0].line()) + "] [" + function_name + "] [net] foo1: bar1",
-        "[" + file_name + ":" + util::ToString(source_locs[1].line()) + "] [" + function_name + "] [net:info] foo2: bar2",
-        "[" + file_name + ":" + util::ToString(source_locs[2].line()) + "] [" + function_name + "] [debug] foo3: bar3",
-        "[" + file_name + ":" + util::ToString(source_locs[3].line()) + "] [" + function_name + "] foo4: bar4",
-        "[" + file_name + ":" + util::ToString(source_locs[4].line()) + "] [" + function_name + "] [debug] foo5: bar5",
-        "[" + file_name + ":" + util::ToString(source_locs[5].line()) + "] [" + function_name + "] foo6: bar6",
+        format_source_location(source_locs[0]) + " [net] foo1: bar1",
+        format_source_location(source_locs[1]) + " [net:info] foo2: bar2",
+        format_source_location(source_locs[2]) + " [debug] foo3: bar3",
+        format_source_location(source_locs[3]) + " foo4: bar4",
+        format_source_location(source_locs[4]) + " [debug] foo5: bar5",
+        format_source_location(source_locs[5]) + " foo6: bar6",
     };
     BOOST_CHECK_EQUAL_COLLECTIONS(log_lines.begin(), log_lines.end(), expected.begin(), expected.end());
 }

</details>

done

This code could use LogPrintLevel with the Info level to bypass rate-limiting

I don't think that's correct? I'm not sure a long docstring is required here anyway, we already have decent documentation for the macros and functions involved. A brief "don't rate limit because this can be hit frequently during IBD" seems sufficient to me without overloading the reader with information.

I think this is an old comment, will change.

nit: (a brief version of) the commit message in 32615bffa6424625078e5bd9f6d79c7e99c9a322 would probably be helpful here as a docstring too?

The resulting comment just repeats what the code already does:

//! Mark as noexcept(false) to catch any thrown exceptions.

We don't comment every noexcept(false) since it's self-explanatory. What else could noexcept(false) mean?

is just repeating what the doc states:

expression is specified to be non-throwing(since C++17), and false otherwise.

Should probably terminate with \n?

nit: I find mixing C++20 code with C API a bit clunky, if you touch again, consider either comparing their std::string_view wrappers or maybe even adding such a helper to string.h for const char* values.

edit: also note that equality check may be easier to optimize internally than a comparison

I understand when the time is split off from the measured code to make sure it's accurate - but I don't see how that's the case here, consider inlining it:

    m_limiter.m_last_reset = NodeClock::now();

Seems to me the first two sentences contradict each other now: "log unconditionally, unless it doesn't fulfill the rate limiting condition"

Semantically, I agree. But practically, I think it's fine as is. Conditional vs unconditional are at this point fairly established concepts in our logging code in that they indicate whether or not logging categories need to be enabled or not. Rate limiting should in practice never occur, so for all intents and purposes, it is indeed unconditional.

How would you suggest to improve this? I can't think of an improvement.

I don't consider "established" a relevant argument in this case - it just prevents new contributors from understanding the codebase. But if you think this isn't confusing, I don't mind resolving the comment, I did eventually understand it, just got sidetracked by the contradiction and wanted to simplify it to the next person. If we do correct it, we could be more specific instead of overly generalizing it (ie specify the restrictions instead of claiming there are none).

I don't think this is confusing because of prior context. I can understand the point about newer contributors. I've come across other places in the codebase where I've had to learn the context by combing through IRC, PRs, commit messages, blogs, etc. I think it's similar to adding the information in the commit message rather than including a comment since a user must search for the commit message info.

EDIT: That said, I'm open to suggestions, but I thought the context was pretty clear for me because I went through the code and the original PR.

That's a reasonable assumption - if a bug could trigger debug logging, we'd likely have bigger problems I guess

Does this "prevent" rate limiting or just allows one more megabyte?

The latter. "Ensure tests don't use each other's rate limiting budget" could be an alternative?

this seems a bit hacky to me - this is basically a parameterized test where we implicitly verify the inputs produce the desired outputs, line-by-line. It could make sense to store it in a way that indicates more clearly which outputs we're expecting for which inputs.

We do need separate ::current() calls to capture that the lines are assigned properly, we could add those to the parameterized test values as well.

I also find it a bit awkward that we're concatenating the result of a tfm::format with strings instead of having a final formatter.

Lastly, do we really need the RemovePrefix here, given that we know the exact file structiure?

Please consider something like this for clarity:

BOOST_FIXTURE_TEST_CASE(logging_LogPrintStr, LogSetup)
{
    LogInstance().m_log_sourcelocations = true;

    struct Case {
        std::string msg;
        BCLog::LogFlags cat;
        BCLog::Level level;
        std::string prefix;
        std::source_location loc;
    };

    std::vector<Case> cases = {
        {"foo1: bar1", BCLog::NET,  BCLog::Level::Debug, "[net] ",      std::source_location::current()},
        {"foo2: bar2", BCLog::NET,  BCLog::Level::Info,  "[net:info] ", std::source_location::current()},
        {"foo3: bar3", BCLog::ALL,  BCLog::Level::Debug, "[debug] ",    std::source_location::current()},
        {"foo4: bar4", BCLog::ALL,  BCLog::Level::Info,  "",            std::source_location::current()},
        {"foo5: bar5", BCLog::NONE, BCLog::Level::Debug, "[debug] ",    std::source_location::current()},
        {"foo6: bar6", BCLog::NONE, BCLog::Level::Info,  "",            std::source_location::current()},
    };

    std::vector<std::string> expected;
    for (auto& [msg, cat, level, prefix, loc] : cases) {
        expected.push_back(tfm::format("[%s:%s] [%s] %s%s", loc.file_name(), loc.line(), loc.function_name(), prefix, msg));
        LogInstance().LogPrintStr(msg, std::move(loc), cat, level, /*should_ratelimit=*/false);
    }
    std::ifstream file{tmp_log_path};
    std::string line;
    for (const auto& exp : expected) {
        BOOST_REQUIRE(std::getline(file, line));
        BOOST_CHECK_EQUAL(line, exp);
    }
    BOOST_CHECK(!std::getline(file, line));
}

Lastly, do we really need the RemovePrefix here, given that we know the exact file structiure?

Yup, the file name may differ across platforms and the test will fail on some platforms otherwise. Necessary because it's done here: https://github.com/bitcoin/bitcoin/blob/68ca13e1f96a9dae997558a1d7a873b10056091b/src/logging.cpp#L377

I have implemented your suggestion other than that.

👍 nice and clear test

I'm not a fan of dead comments, could we rather extract it to a named variable, something like CSipHasher uniform(0, 0) instead of explaining code with text?

nit: Maybe my formatter is off, but do we really need to push the formatted lines so far out?

I don't think this is a dead comment, the choice for using siphash over e.g. std::hash is not obvious (to me), and just naming the variable uniform would not have been clear to me. Would prefer keeping this as is.

Can we name the variable such that the choice is obvious instead of adding extra comments?

By "dead" I meant that it doesn't bite back (like code does), it can state absolutely anything and the compiler won't help us. Comments usually seem to me like we've given up on trying to express our design within the boundaries of the language. In a few cases here I think the code can be slightly improved to eliminate the need for extra comments.

The choice of a hashing algorithm has many dimensions (distribution, performance, collision resistance, ...). Capturing that rationale in a variable name seems an unrealistic expectation. I'm all for removing dead comments but this seems not the place to me.

It's possible that this isn't the place, but it doesn't currently explain performance or collision resistance either - but if those are importance, maybe we could explain them in the commit message instead.

I have kept the comment -- I made a note in the commit message about the change.

I find this confusing (either the name or the value), by default debug logs aren't displayed...

This variable is not used or changed in this PR.

~This argument may not be, but the test is validating the changed code, dead parameter names don't increase my confidence in the correctness of the PR. It may have an obvious explanation, but it seemed related to me, given that we're touching surrounding code~

What do you mean with "dead parameter names"? This variable defines the default log level, which indeed is debug level. If you run bitcoind -debug=net, you'll start seeing net debug logs, you don't have to set -loglevel=debug.

I replied to the wrong thread here, thanks for the explanation, please resolve it.

naming nit again: we're not counting the source locations, rather assigning the statistics we collect here to a std::source_location later - we're mixing abstraction levels this way, we're naming something based on how we're planning on using it later (instead of what it is or what it does), such as LogLimitStats or something similar.

These two cases are basically the same and they depend on a magic int that I will have to tie to some other integers somewhere else to understand what it means. Could we make this a parameterized test as well, maybe with a std::function and more type safety instead of an int with only 4 allowed values

I haven't implemented this, could this be left for a follow-up?

I doubt anyone will review it if we push it separately - but I think we could make these tests less awkward. Not a blocker from my side, just a preference

I agree with you that the tests are awkward, but I do want to limit churn as this PR has been through a few iterations. I would definitely review a follow-up if you wanted to make the PR. This could also be a good candidate for https://www.bitcoin-followups.info/

I share the eagerness to get this merged, but I don't think this PR is ready yet. It still feels like a draft, not polished yet, contains multiple styles because we don't want to touch a previous author's work. As far as I can tell there's no rush, let's do it properly and minimize having to touch the same code in multiple PRs.

Anf if you insist on keeping this logic here, at least merge the two identical cases:

    case 0:
    case 1:
        LogInfo("%s\n", message);
        break;

contains multiple styles

I don't think that's a good reason to hold up a useful and important PR that already has gone several iterations (in this and a previous PR) when nitting about documentation styles can block progress entirely as eventually reviewers lose interest and dilligence in re-reviewing. Follow-ups are entirely appropriate places for this to happen.

can we make this value parameterizable instead of referencing a value in a comment? It's not trivial that the 1024 (or 512 + 512 in other places) has to coincide with the 1_MiB in another place.

Now uses a parameter, but I have kept the comment. I think it is clear as is? I think a follow-up could address this?

the code already states /*should_ratelimit=*/false, there's no point in repeating that a few more times in a comment

The point of the docstring is to explain why we don't ratelimit, which is because we don't want IBD tip logs to be suppressed. Documenting that absolutely seems helpful to me.

Yes, that part does seem helpful and we can't express it with code, we should keep that part!

I've modified the comment so it doesn't repeat the phrase "rate limit" twice.

It's still a bit noisy, but adding IBD as context could be helpful for some.

        //! Returns whether enough bytes were available.

The comment duplicates the code, this is already clear from the method name and from what follows.

do we need to mix the two system here, base 1000 with base 1024?

Both are frequently used throughout the codebase. RATELIMIT_MAX_BYTES and DEFAULT_MAX_LOG_BUFFER are not related to eachother beyond both being used in logging. I don't see any footgun potential between using one or the other, so this seems like an either-is-fine option that can be left to the author to decide, and very quickly becomes bikeshedding otherwise.

I think this memory usage change needs a commit message explanation in d41a39e43c219eb0b06b8df2c2c5d24baaf015c4 (it explains why logging_function counting was removed, but not why source_file was as far as I can tell)

Did you validate in any way that this is indeed representative of the memory consumption? Or it's just a guess anyway, so it's not important?

I didn't validate it, but I can. I think it is important that the new and old versions of MemUsage are roughly the same.

Modified the commit message and have checked that MemUsage returns an accurate accounting of the memory used. Thanks for this comment, it encouraged me to verify this.

Can you show us the raw measurements?

IIRC, logging a 1024-byte line in my test had a memory overhead of ~1140 bytes. Prior to the change it was ~1200 bytes or so.

isn't it expensive to insert so often in front of the string?

I have not run benchmarks, though this insert is pre-existing so will resolve. It would be nicer if there was a better way to format the string other than the insert-at-beginning logic in FormatLogStrInPlace.

Can you please explain in the commit message which change caused the removal of [InitConfig] here?

Modified the commit message 👍

Commit message claims a source location can log up to 1MiB of data, but code states constexpr size_t DEFAULT_MAX_LOG_BUFFER{1'000'000}; // buffer up to 1MB of log data prior to StartLogging - I'm confused why we have this discrepancy

They could be the same value, but they're unrelated things, and I don't think it's relevant in this PR. DEFAULT_MAX_LOG_BUFFER represents the max size of the buffer that holds log messages (across all locations) that are produced before we start writing them to file.

Misunderstood that part, thanks. The different base part still applies (though I know this isn't uncommon in the code base)

I agree this is confusing and threw me. The different base part is pre-existing so will resolve. I think another PR could eliminate the different bases unless there's a compelling "historical" reason to keep both?

can we move this closer to its usage?

That would mean the rate limiting warnings are no longer logged to console and callbacks (NeedsRateLimiting has side effects), so I think keeping this as-is is better.

Ah, so there's a side-effect here that wasn't obvious to me, thanks for clarifying.

Edit: this seems like a code smell, doesn't this indicate that NeedsRateLimiting does too many things and should be split out to smaller, more focused methods? If we can't give it a proper name that reflects what it does, that's usually a good sign that it's not as simple as it could be

I agree NeedsRateLimiting has too many responsibilities. I think it's okay as-is, but your comment nerdsniped me into revisiting this. I'm working on a branch that removes the side effects from NeedsRateLimiting and a couple of other improvements. I'm not sure yet if it'll be too much of a detour for this PR, but at least it'll be interesting to be able to compare. Should have it ready tomorrow.

Sorry for the wait, branch is ready: https://github.com/stickies-v/bitcoin/commits/2025-06/schedule-ratelimit-reset/ . I added the "fixup" comments as commits that should be squashable into the current branch as-is (requiring rebase for the commits above, though). Hopefully the isolation of the changes makes this easier to review and potentially adopt into this PR.

The main change is that I've carved out scheduling from LogRateLimiter (leaving that to CScheduler), which allows quite a bit of subsequent improvements. Specifically for this thread, I've refactored NeedsRateLimiting into Consume that does not have any side-effects (except update internal accounting, as expected by the Consume name).

The other changes (see diff) I've implemented in this branch include:

• change Logger::m_limiter to a pointer so it can more easily be (re)set, allowing for easier testing.
• add unit tests specifically for the LogRateLimiter interface that I find quite a bit easier to understand than the existing rate_limit tests, but there may be merit in keeping both (I've updated the latter so they don't break, but they should probably be deduplicated at least somewhat)
• made LogRateLimiter thread-safe since it is now used in multiple threads
• various cleanups, including removing the unnecessary m_suppressed_locations (now a m_suppression_active boolean), parameterizing the max_bytes and reset_window, ...
• removes the need for the test-only BCLog::Logger::ResetLimiter() function

I think the PR is in a good enough shape as it is, and I don't want to block progress. I like the new interface of my suggestion quite a bit better than the old one, and I think it is worth the time and effort to overhaul this (I spent a lot of time carving everything out in separate commits to make rebasing easy), but I understand this PR has had a lot of back-and-forth already. I'll leave it up to the author if he wants to change the approach here, of if I'll do it in a follow-up (which unfortunately would be a lot of churn). In either case, I'll shortly do a full re-review.

Leaving a note that I am going to implement these changes and plan to push up either later today or tomorrow.

Sweet, I'm planning on reviewing it this week!

Latest change addresses this.

nit:

log strings currently look like:

Restarting logging from ../../src/rpc/request.cpp:140 (GenerateAuthCookieResult GenerateAuthCookie(const std::optionalfs::perms &, std::string &, std::string &)): (0 MiB) were dropped during the last hour.

Would suggest printing this as bytes and removing the parentheses.

                                    "%d bytes were dropped during the last hour.\n",
                                    source_loc.file_name(), source_loc.line(), source_loc.function_name(),
                                    dropped_bytes));

Changed, I think tracking bytes is better.

nit

            std::string str threadname;

Did not implement as this gave me a compilation error?

Sorry, please disregard. I think I misread this as std::string, threadname and probably didn't even try compiling the suggestion.

nit: the -logsourcelocation behaviour change is unrelated to the rate limiting, so I think this phrasing is a bit confusing. Would put it in a separate paragraph:

Unconditional logging to disk via LogPrintf, LogInfo, LogWarning, LogError, and
LogPrintLevel is now rate limited by giving each source location a logging quota of
1MiB per hour. (#32604)

When `-logsourcelocation` is enabled, the log output now contains the entire function signature
instead of just the function name. (#32604)

Agree phrasing was confusing, have changed.

This is causing a TSan issue:

<details> <summary> logs </summary>

[18:53:46.472] WARNING: ThreadSanitizer: data race (pid=9715)
[18:53:46.472]   Read of size 8 at 0x723c00000068 by thread T1 (mutexes: write M0):
[18:53:46.472]     [#0](/bitcoin-bitcoin/0/) std::__1::unique_ptr<BCLog::LogRateLimiter, std::__1::default_delete<BCLog::LogRateLimiter>>::operator bool[abi:ne200100]() const /usr/lib/llvm-20/bin/../include/c++/v1/__memory/unique_ptr.h:287:12 (bitcoind+0xc87f7a) (BuildId: 2b13e1fe2bba2fe47e258c908d3d80d2947d2486)
[18:53:46.472]     [#1](/bitcoin-bitcoin/1/) BCLog::Logger::LogPrintStr_(std::__1::basic_string_view<char, std::__1::char_traits<char>>, std::__1::source_location&&, BCLog::LogFlags, BCLog::Level, bool) /ci_container_base/ci/scratch/build-x86_64-pc-linux-gnu/src/util/./logging.cpp:455:29 (bitcoind+0xc87f7a)
[18:53:46.472]     [#2](/bitcoin-bitcoin/2/) BCLog::Logger::LogPrintStr(std::__1::basic_string_view<char, std::__1::char_traits<char>>, std::__1::source_location&&, BCLog::LogFlags, BCLog::Level, bool) /ci_container_base/ci/scratch/build-x86_64-pc-linux-gnu/src/util/./logging.cpp:418:12 (bitcoind+0xc8bc32) (BuildId: 2b13e1fe2bba2fe47e258c908d3d80d2947d2486)
[18:53:46.472]     [#3](/bitcoin-bitcoin/3/) void LogPrintFormatInternal<std::__1::basic_string_view<char, std::__1::char_traits<char>>>(std::__1::source_location&&, BCLog::LogFlags, BCLog::Level, bool, util::ConstevalFormatString<sizeof...(std::__1::basic_string_view<char, std::__1::char_traits<char>>)>, std::__1::basic_string_view<char, std::__1::char_traits<char>> const&) /ci_container_base/ci/scratch/build-x86_64-pc-linux-gnu/src/./logging.h:354:23 (bitcoind+0x6e776d) (BuildId: 2b13e1fe2bba2fe47e258c908d3d80d2947d2486)
[18:53:46.472]     [#4](/bitcoin-bitcoin/4/) util::TraceThread(std::__1::basic_string_view<char, std::__1::char_traits<char>>, std::__1::function<void ()>) /ci_container_base/ci/scratch/build-x86_64-pc-linux-gnu/src/util/./util/thread.cpp:20:9 (bitcoind+0xc84c3b) (BuildId: 2b13e1fe2bba2fe47e258c908d3d80d2947d2486)
[18:53:46.472]     [#5](/bitcoin-bitcoin/5/) decltype(std::declval<void (*)(std::__1::basic_string_view<char, std::__1::char_traits<char>>, std::__1::function<void ()>)>()(std::declval<char const*>(), std::declval<AppInitMain(node::NodeContext&, interfaces::BlockAndHeaderTipInfo*)::$_7>())) std::__1::__invoke[abi:ne200100]<void (*)(std::__1::basic_string_view<char, std::__1::char_traits<char>>, std::__1::function<void ()>), char const*, AppInitMain(node::NodeContext&, interfaces::BlockAndHeaderTipInfo*)::$_7>(void (*&&)(std::__1::basic_string_view<char, std::__1::char_traits<char>>, std::__1::function<void ()>), char const*&&, AppInitMain(node::NodeContext&, interfaces::BlockAndHeaderTipInfo*)::$_7&&) /usr/lib/llvm-20/bin/../include/c++/v1/__type_traits/invoke.h:179:25 (bitcoind+0x1c6a5c) (BuildId: 2b13e1fe2bba2fe47e258c908d3d80d2947d2486)
[18:53:46.472]     [#6](/bitcoin-bitcoin/6/) void std::__1::__thread_execute[abi:ne200100]<std::__1::unique_ptr<std::__1::__thread_struct, std::__1::default_delete<std::__1::__thread_struct>>, void (*)(std::__1::basic_string_view<char, std::__1::char_traits<char>>, std::__1::function<void ()>), char const*, AppInitMain(node::NodeContext&, interfaces::BlockAndHeaderTipInfo*)::$_7, 2ul, 3ul>(std::__1::tuple<std::__1::unique_ptr<std::__1::__thread_struct, std::__1::default_delete<std::__1::__thread_struct>>, void (*)(std::__1::basic_string_view<char, std::__1::char_traits<char>>, std::__1::function<void ()>), char const*, AppInitMain(node::NodeContext&, interfaces::BlockAndHeaderTipInfo*)::$_7>&, std::__1::__tuple_indices<2ul, 3ul>) /usr/lib/llvm-20/bin/../include/c++/v1/__thread/thread.h:199:3 (bitcoind+0x1c6a5c)
[18:53:46.472]     [#7](/bitcoin-bitcoin/7/) void* std::__1::__thread_proxy[abi:ne200100]<std::__1::tuple<std::__1::unique_ptr<std::__1::__thread_struct, std::__1::default_delete<std::__1::__thread_struct>>, void (*)(std::__1::basic_string_view<char, std::__1::char_traits<char>>, std::__1::function<void ()>), char const*, AppInitMain(node::NodeContext&, interfaces::BlockAndHeaderTipInfo*)::$_7>>(void*) /usr/lib/llvm-20/bin/../include/c++/v1/__thread/thread.h:208:3 (bitcoind+0x1c6a5c)
[18:53:46.472] 
[18:53:46.472]   Previous write of size 8 at 0x723c00000068 by main thread:
[18:53:46.472]     [#0](/bitcoin-bitcoin/0/) std::__1::unique_ptr<BCLog::LogRateLimiter, std::__1::default_delete<BCLog::LogRateLimiter>>::reset[abi:ne200100](BCLog::LogRateLimiter*) /usr/lib/llvm-20/bin/../include/c++/v1/__memory/unique_ptr.h:298:19 (bitcoind+0x1b779a) (BuildId: 2b13e1fe2bba2fe47e258c908d3d80d2947d2486)
[18:53:46.472]     [#1](/bitcoin-bitcoin/1/) std::__1::unique_ptr<BCLog::LogRateLimiter, std::__1::default_delete<BCLog::LogRateLimiter>>::operator=[abi:ne200100](std::__1::unique_ptr<BCLog::LogRateLimiter, std::__1::default_delete<BCLog::LogRateLimiter>>&&) /usr/lib/llvm-20/bin/../include/c++/v1/__memory/unique_ptr.h:240:5 (bitcoind+0x1b779a)
[18:53:46.472]     [#2](/bitcoin-bitcoin/2/) BCLog::Logger::SetRateLimiting(std::__1::unique_ptr<BCLog::LogRateLimiter, std::__1::default_delete<BCLog::LogRateLimiter>>&&) /ci_container_base/ci/scratch/build-x86_64-pc-linux-gnu/src/./logging.h:275:23 (bitcoind+0x1b779a)
[18:53:46.472]     [#3](/bitcoin-bitcoin/3/) AppInitMain(node::NodeContext&, interfaces::BlockAndHeaderTipInfo*) /ci_container_base/ci/scratch/build-x86_64-pc-linux-gnu/src/./init.cpp:1381:19 (bitcoind+0x1b779a)
[18:53:46.472]     [#4](/bitcoin-bitcoin/4/) AppInit(node::NodeContext&) /ci_container_base/ci/scratch/build-x86_64-pc-linux-gnu/src/./bitcoind.cpp:237:43 (bitcoind+0x199892) (BuildId: 2b13e1fe2bba2fe47e258c908d3d80d2947d2486)
[18:53:46.472]     [#5](/bitcoin-bitcoin/5/) main /ci_container_base/ci/scratch/build-x86_64-pc-linux-gnu/src/./bitcoind.cpp:283:10 (bitcoind+0x199892)
[18:53:46.472] 
[18:53:46.472]   Location is heap block of size 232 at 0x723c00000000 allocated by main thread:
[18:53:46.472]     [#0](/bitcoin-bitcoin/0/) operator new(unsigned long) <null> (bitcoind+0x1977f6) (BuildId: 2b13e1fe2bba2fe47e258c908d3d80d2947d2486)
[18:53:46.472]     [#1](/bitcoin-bitcoin/1/) LogInstance() /ci_container_base/ci/scratch/build-x86_64-pc-linux-gnu/src/util/./logging.cpp:43:36 (bitcoind+0xc8756b) (BuildId: 2b13e1fe2bba2fe47e258c908d3d80d2947d2486)
[18:53:46.472]     [#2](/bitcoin-bitcoin/2/) init::AddLoggingArgs(ArgsManager&) /ci_container_base/ci/scratch/build-x86_64-pc-linux-gnu/src/./init/common.cpp:31:209 (bitcoind+0xb0a2c7) (BuildId: 2b13e1fe2bba2fe47e258c908d3d80d2947d2486)
[18:53:46.472]     [#3](/bitcoin-bitcoin/3/) SetupServerArgs(ArgsManager&, bool) /ci_container_base/ci/scratch/build-x86_64-pc-linux-gnu/src/./init.cpp:446:5 (bitcoind+0x1a0e07) (BuildId: 2b13e1fe2bba2fe47e258c908d3d80d2947d2486)
[18:53:46.472]     [#4](/bitcoin-bitcoin/4/) ParseArgs(node::NodeContext&, int, char**) /ci_container_base/ci/scratch/build-x86_64-pc-linux-gnu/src/./bitcoind.cpp:116:5 (bitcoind+0x198e34) (BuildId: 2b13e1fe2bba2fe47e258c908d3d80d2947d2486)
[18:53:46.472]     [#5](/bitcoin-bitcoin/5/) main /ci_container_base/ci/scratch/build-x86_64-pc-linux-gnu/src/./bitcoind.cpp:278:10 (bitcoind+0x198e34)
[18:53:46.472] 
[18:53:46.472]   Mutex M0 (0x723c00000000) created at:
[18:53:46.472]     [#0](/bitcoin-bitcoin/0/) pthread_mutex_lock <null> (bitcoind+0x11559b) (BuildId: 2b13e1fe2bba2fe47e258c908d3d80d2947d2486)
[18:53:46.472]     [#1](/bitcoin-bitcoin/1/) std::__1::mutex::lock() <null> (libc++.so.1.0.20+0x713cc) (BuildId: 30ef7da36db6fb0c014ee96603f7649f755cb793)
[18:53:46.472]     [#2](/bitcoin-bitcoin/2/) init::LogPackageVersion() /ci_container_base/ci/scratch/build-x86_64-pc-linux-gnu/src/./init/common.cpp:151:5 (bitcoind+0xb0dc4e) (BuildId: 2b13e1fe2bba2fe47e258c908d3d80d2947d2486)
[18:53:46.472]     [#3](/bitcoin-bitcoin/3/) InitLogging(ArgsManager const&) /ci_container_base/ci/scratch/build-x86_64-pc-linux-gnu/src/./init.cpp:818:5 (bitcoind+0x1b0390) (BuildId: 2b13e1fe2bba2fe47e258c908d3d80d2947d2486)
[18:53:46.475]     [#4](/bitcoin-bitcoin/4/) AppInit(node::NodeContext&) /ci_container_base/ci/scratch/build-x86_64-pc-linux-gnu/src/./bitcoind.cpp:181:9 (bitcoind+0x199572) (BuildId: 2b13e1fe2bba2fe47e258c908d3d80d2947d2486)
[18:53:46.475]     [#5](/bitcoin-bitcoin/5/) main /ci_container_base/ci/scratch/build-x86_64-pc-linux-gnu/src/./bitcoind.cpp:283:10 (bitcoind+0x199572)
[18:53:46.475] 
[18:53:46.475]   Thread T1 'b-scheduler' (tid=9717, running) created by main thread at:
[18:53:46.475]     [#0](/bitcoin-bitcoin/0/) pthread_create <null> (bitcoind+0x11388e) (BuildId: 2b13e1fe2bba2fe47e258c908d3d80d2947d2486)
[18:53:46.475]     [#1](/bitcoin-bitcoin/1/) std::__1::__libcpp_thread_create[abi:ne200100](unsigned long*, void* (*)(void*), void*) /usr/lib/llvm-20/bin/../include/c++/v1/__thread/support/pthread.h:182:10 (bitcoind+0x1b75c1) (BuildId: 2b13e1fe2bba2fe47e258c908d3d80d2947d2486)
[18:53:46.475]     [#2](/bitcoin-bitcoin/2/) std::__1::thread::thread<void (&)(std::__1::basic_string_view<char, std::__1::char_traits<char>>, std::__1::function<void ()>), char const (&) [10], AppInitMain(node::NodeContext&, interfaces::BlockAndHeaderTipInfo*)::$_7, 0>(void (&)(std::__1::basic_string_view<char, std::__1::char_traits<char>>, std::__1::function<void ()>), char const (&) [10], AppInitMain(node::NodeContext&, interfaces::BlockAndHeaderTipInfo*)::$_7&&) /usr/lib/llvm-20/bin/../include/c++/v1/__thread/thread.h:218:14 (bitcoind+0x1b75c1)
[18:53:46.475]     [#3](/bitcoin-bitcoin/3/) AppInitMain(node::NodeContext&, interfaces::BlockAndHeaderTipInfo*) /ci_container_base/ci/scratch/build-x86_64-pc-linux-gnu/src/./init.cpp:1363:34 (bitcoind+0x1b75c1)
[18:53:46.475]     [#4](/bitcoin-bitcoin/4/) AppInit(node::NodeContext&) /ci_container_base/ci/scratch/build-x86_64-pc-linux-gnu/src/./bitcoind.cpp:237:43 (bitcoind+0x199892) (BuildId: 2b13e1fe2bba2fe47e258c908d3d80d2947d2486)
[18:53:46.475]     [#5](/bitcoin-bitcoin/5/) main /ci_container_base/ci/scratch/build-x86_64-pc-linux-gnu/src/./bitcoind.cpp:283:10 (bitcoind+0x199892)
[18:53:46.475] 
[18:53:46.475] SUMMARY: ThreadSanitizer: data race /ci_container_base/ci/scratch/build-x86_64-pc-linux-gnu/src/util/./logging.cpp:455:29 in BCLog::Logger::LogPrintStr_(std::__1::basic_string_view<char, std::__1::char_traits<char>>, std::__1::source_location&&, BCLog::LogFlags, BCLog::Level, bool)
[18:53:46.475] ==================

</details>

In my suggestion, I removed the mutex guard for m_limiter because the class is now thread-safe, but of course that doesn't prevent race conditions on the setting of m_limiter, e.g. when one thread calls SetRateLimiting() and another inspects if m_limiter is set, which is what TSan caught here.

Can be fixed by re-introducing the m_cs guard:

<details> <summary>git diff on 34fc54d547</summary>

diff --git a/src/logging.h b/src/logging.h
index f81f4947af..c801e94e28 100644
--- a/src/logging.h
+++ b/src/logging.h
@@ -201,7 +201,7 @@ namespace BCLog {
         size_t m_buffer_lines_discarded GUARDED_BY(m_cs){0};
 
         //! Manages the rate limiting of each log location.
-        std::unique_ptr<LogRateLimiter> m_limiter;
+        std::unique_ptr<LogRateLimiter> m_limiter GUARDED_BY(m_cs);
 
         //! Category-specific log level. Overrides `m_log_level`.
         std::unordered_map<LogFlags, Level> m_category_log_levels GUARDED_BY(m_cs);
@@ -270,8 +270,9 @@ namespace BCLog {
         /** Only for testing */
         void DisconnectTestLogger() EXCLUSIVE_LOCKS_REQUIRED(!m_cs);
 
-        void SetRateLimiting(std::unique_ptr<LogRateLimiter>&& limiter)
+        void SetRateLimiting(std::unique_ptr<LogRateLimiter>&& limiter) EXCLUSIVE_LOCKS_REQUIRED(!m_cs)
         {
+            StdLockGuard scoped_lock(m_cs);
             m_limiter = std::move(limiter);
         }
 

</details>

Sorry about the oversight.

Will implement. I should have caught this as well -- I am glad we have TSAN in CI. I will test the branch locally under TSAN.

I added this recursive LogPrintStr_ because I think it's better to have separate log statements than inserting into the existing string, and added the should_ratelimit=false which makes it safe for infinite recursion. I forgot to add the clang-tidy suppression though, causing this CI failure. It seems like we can only suppress this by marking all of LogPrintStr_ as NOLINT, instead of just this single source, which is not ideal.

<details> <summary>git diff on 34fc54d547</summary>

diff --git a/src/logging.cpp b/src/logging.cpp
index 5c7d7fc57d..1fdbceff5f 100644
--- a/src/logging.cpp
+++ b/src/logging.cpp
@@ -418,6 +418,7 @@ void BCLog::Logger::LogPrintStr(std::string_view str, std::source_location&& sou
     return LogPrintStr_(str, std::move(source_loc), category, level, should_ratelimit);
 }
 
+// NOLINTNEXTLINE(misc-no-recursion)
 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);
@@ -455,6 +456,7 @@ void BCLog::Logger::LogPrintStr_(std::string_view str, std::source_location&& so
     if (should_ratelimit && m_limiter) {
         auto status{m_limiter->Consume(source_loc, str_prefixed)};
         if (status == BCLog::LogRateLimiter::Status::NEWLY_SUPPRESSED) {
+            // NOLINTNEXTLINE(misc-no-recursion)
             LogPrintStr_(strprintf(
                              "Excessive logging detected from %s:%d (%s): >%d bytes logged during "
                              "the last time window of %is. Suppressing logging to disk from this "
@@ -463,7 +465,7 @@ void BCLog::Logger::LogPrintStr_(std::string_view str, std::source_location&& so
                              source_loc.file_name(), source_loc.line(), source_loc.function_name(),
                              m_limiter->m_max_bytes,
                              Ticks<std::chrono::seconds>(m_limiter->m_reset_window)),
-                         std::source_location::current(), LogFlags::ALL, Level::Warning, /*should_ratelimit=*/false);
+                         std::source_location::current(), LogFlags::ALL, Level::Warning, /*should_ratelimit=*/false);  // with should_ratelimit=false, this cannot lead to infinite recursion
         }
         ratelimit = status == BCLog::LogRateLimiter::Status::STILL_SUPPRESSED;
         // To avoid confusion caused by dropped log messages when debugging an issue,

</details>

Unfortunate that it can only be resolved by marking the function as NOLINT. Addressed.

As mentioned before, I'm not comfortable with this, can we find a safer way?

I think this is safe. I understand the concern, but the NOLINT and the comment next to the recursion should be a bright red flag to anybody modifying the code in the future.

nit: making this a simple struct LogRateLimiter::Stats would clean things up a bit more.

Diff that does that + updates naming to reflect the phasing out of LogLocationCounter naming and updates documentation to not mention concepts it's not aware of (e.g. Stats does not know anything about time windows).

<details> <summary>git diff on 6a7147358c</summary>

diff --git a/src/logging.cpp b/src/logging.cpp
index a090803652..7dc81928f2 100644
--- a/src/logging.cpp
+++ b/src/logging.cpp
@@ -384,10 +384,10 @@ BCLog::LogRateLimiter::Status BCLog::LogRateLimiter::Consume(
     const std::string& str)
 {
     StdLockGuard scoped_lock(m_mutex);
-    auto& counter{m_source_locations.try_emplace(source_loc, m_max_bytes).first->second};
-    Status status{counter.GetDroppedBytes() > 0 ? Status::STILL_SUPPRESSED : Status::UNSUPPRESSED};
+    auto& stats{m_source_locations.try_emplace(source_loc, m_max_bytes).first->second};
+    Status status{stats.dropped_bytes > 0 ? Status::STILL_SUPPRESSED : Status::UNSUPPRESSED};
 
-    if (!counter.Consume(str.size()) && status == Status::UNSUPPRESSED) {
+    if (!stats.Consume(str.size()) && status == Status::UNSUPPRESSED) {
         status = Status::NEWLY_SUPPRESSED;
         m_suppression_active = true;
     }
@@ -549,8 +549,8 @@ void BCLog::LogRateLimiter::Reset()
         source_locations.swap(m_source_locations);
         m_suppression_active = false;
     }
-    for (const auto& [source_loc, counter] : source_locations) {
-        uint64_t dropped_bytes{counter.GetDroppedBytes()};
+    for (const auto& [source_loc, stats] : source_locations) {
+        uint64_t dropped_bytes{stats.dropped_bytes};
         if (dropped_bytes == 0) continue;
         LogPrintLevel_(
             LogFlags::ALL, Level::Info, /*should_ratelimit=*/false,
@@ -560,15 +560,15 @@ void BCLog::LogRateLimiter::Reset()
     }
 }
 
-bool BCLog::LogLimitStats::Consume(uint64_t bytes)
+bool BCLog::LogRateLimiter::Stats::Consume(uint64_t bytes)
 {
-    if (bytes > m_available_bytes) {
-        m_dropped_bytes += bytes;
-        m_available_bytes = 0;
+    if (bytes > available_bytes) {
+        dropped_bytes += bytes;
+        available_bytes = 0;
         return false;
     }
 
-    m_available_bytes -= bytes;
+    available_bytes -= bytes;
     return true;
 }
 
diff --git a/src/logging.h b/src/logging.h
index c801e94e28..3253bdf910 100644
--- a/src/logging.h
+++ b/src/logging.h
@@ -106,43 +106,18 @@ namespace BCLog {
     constexpr size_t DEFAULT_MAX_LOG_BUFFER{1'000'000}; // buffer up to 1MB of log data prior to StartLogging
     constexpr uint64_t RATELIMIT_MAX_BYTES{1024 * 1024}; // maximum number of bytes that can be logged within one window
 
-    //! Keeps track of an individual source location and how many available bytes are left for logging from it.
-    class LogLimitStats
-    {
-    private:
-        //! Remaining bytes in the current window interval.
-        uint64_t m_available_bytes;
-        //! Number of bytes that were not consumed within the current window.
-        uint64_t m_dropped_bytes{0};
-
-    public:
-        LogLimitStats(uint64_t max_bytes) : m_available_bytes{max_bytes} {}
-        //! Consume bytes from the window if enough bytes are available.
-        //!
-        //! Returns whether enough bytes were available.
-        bool Consume(uint64_t bytes);
-
-        uint64_t GetAvailableBytes() const
-        {
-            return m_available_bytes;
-        }
-
-        uint64_t GetDroppedBytes() const
-        {
-            return m_dropped_bytes;
-        }
-    };
-
     /**
      * Fixed window rate limiter for logging.
      */
     class LogRateLimiter
     {
+    public:
+        struct Stats;
     private:
         mutable StdMutex m_mutex;
 
-        //! Counters for each source location that has attempted to log something.
-        std::unordered_map<std::source_location, LogLimitStats, SourceLocationHasher, SourceLocationEqual> m_source_locations GUARDED_BY(m_mutex);
+        //! Stats for each source location that has attempted to log something.
+        std::unordered_map<std::source_location, Stats, SourceLocationHasher, SourceLocationEqual> m_source_locations GUARDED_BY(m_mutex);
         //! True if at least one log location is suppressed. Cached view on m_source_locations for performance reasons.
         std::atomic<bool> m_suppression_active{false};
 
@@ -154,7 +129,7 @@ namespace BCLog {
          *                          reset_window interval.
          * [@param](/bitcoin-bitcoin/contributor/param/) max_bytes         Maximum number of bytes that can be logged for each source
          *                          location.
-         * [@param](/bitcoin-bitcoin/contributor/param/) reset_window      Time window after which the byte counters are reset.
+         * [@param](/bitcoin-bitcoin/contributor/param/) reset_window      Time window after which the stats are reset.
          */
         LogRateLimiter(SchedulerFunction scheduler_func, uint64_t max_bytes, std::chrono::seconds reset_window);
         //! Maximum number of bytes logged per location per window.
@@ -178,6 +153,19 @@ namespace BCLog {
         bool SuppressionsActive() const { return m_suppression_active; }
     };
 
+    //! Keeps track of an individual source location and how many available bytes are left for logging from it.
+    struct LogRateLimiter::Stats
+    {
+        //! Remaining bytes
+        uint64_t available_bytes;
+        //! Number of bytes that were consumed but didn't fit in the available bytes
+        uint64_t dropped_bytes{0};
+
+            Stats(uint64_t max_bytes) : available_bytes{max_bytes} {}
+            //! Updates internal accounting and returns true if enough available_bytes were remaining
+            bool Consume(uint64_t bytes);
+        };
+
     class Logger
     {
     public:
diff --git a/src/test/logging_tests.cpp b/src/test/logging_tests.cpp
index 00fb44eaa3..0b21aed588 100644
--- a/src/test/logging_tests.cpp
+++ b/src/test/logging_tests.cpp
@@ -348,25 +348,25 @@ BOOST_AUTO_TEST_CASE(logging_log_rate_limiter)
 
 BOOST_AUTO_TEST_CASE(logging_log_limit_stats)
 {
-    BCLog::LogLimitStats counter{BCLog::RATELIMIT_MAX_BYTES};
+    BCLog::LogRateLimiter::Stats stats{BCLog::RATELIMIT_MAX_BYTES};
 
-    // Check that counter gets initialized correctly.
-    BOOST_CHECK_EQUAL(counter.GetAvailableBytes(), BCLog::RATELIMIT_MAX_BYTES);
-    BOOST_CHECK_EQUAL(counter.GetDroppedBytes(), 0ull);
+    // Check that stats gets initialized correctly.
+    BOOST_CHECK_EQUAL(stats.available_bytes, BCLog::RATELIMIT_MAX_BYTES);
+    BOOST_CHECK_EQUAL(stats.dropped_bytes, 0ull);
 
     const uint64_t MESSAGE_SIZE{512 * 1024};
-    BOOST_CHECK(counter.Consume(MESSAGE_SIZE));
-    BOOST_CHECK_EQUAL(counter.GetAvailableBytes(), BCLog::RATELIMIT_MAX_BYTES - MESSAGE_SIZE);
-    BOOST_CHECK_EQUAL(counter.GetDroppedBytes(), 0ull);
+    BOOST_CHECK(stats.Consume(MESSAGE_SIZE));
+    BOOST_CHECK_EQUAL(stats.available_bytes, BCLog::RATELIMIT_MAX_BYTES - MESSAGE_SIZE);
+    BOOST_CHECK_EQUAL(stats.dropped_bytes, 0ull);
 
-    BOOST_CHECK(counter.Consume(MESSAGE_SIZE));
-    BOOST_CHECK_EQUAL(counter.GetAvailableBytes(), BCLog::RATELIMIT_MAX_BYTES - MESSAGE_SIZE * 2);
-    BOOST_CHECK_EQUAL(counter.GetDroppedBytes(), 0ull);
+    BOOST_CHECK(stats.Consume(MESSAGE_SIZE));
+    BOOST_CHECK_EQUAL(stats.available_bytes, BCLog::RATELIMIT_MAX_BYTES - MESSAGE_SIZE * 2);
+    BOOST_CHECK_EQUAL(stats.dropped_bytes, 0ull);
 
     // Consuming more bytes after already having consumed 1MB should fail.
-    BOOST_CHECK(!counter.Consume(500));
-    BOOST_CHECK_EQUAL(counter.GetAvailableBytes(), 0ull);
-    BOOST_CHECK_EQUAL(counter.GetDroppedBytes(), 500ull);
+    BOOST_CHECK(!stats.Consume(500));
+    BOOST_CHECK_EQUAL(stats.available_bytes, 0ull);
+    BOOST_CHECK_EQUAL(stats.dropped_bytes, 500ull);
 }
 
 void LogFromLocation(int location, std::string message)

</details>

Stats is a better name, LogRateLimiter::LogLimitStats is a bit verbose / stutter-y. Will address in a follow-up, I am not so good with naming.

I don't think we're at the "follow-up" stage yet, let's fix whatever we can in this PR, we're not in any hurry as far as I can tell. The nits left by @stickies-v are reasonable, he's willing to re-review, same for me, let's spend a bit more time wit this, it's not ready just yet...

review note: if a single line contains two log statements, they will be sharing the same stats. I can't find any current such instances in the code, and the only realistic scenario in which I could see something like that happen is:

warn ? LogWarning(msg) : LogInfo(msg)

which would logically be equivalent to the same log location (e.g. using LogPrintLevel) anyway.

This behaviour can be verified with:

<details> <summary>git diff on 6a7147358c</summary>

diff --git a/src/test/logging_tests.cpp b/src/test/logging_tests.cpp
index 00fb44eaa3..0632dcd438 100644
--- a/src/test/logging_tests.cpp
+++ b/src/test/logging_tests.cpp
@@ -369,7 +369,7 @@ BOOST_AUTO_TEST_CASE(logging_log_limit_stats)
     BOOST_CHECK_EQUAL(counter.GetDroppedBytes(), 500ull);
 }
 
-void LogFromLocation(int location, std::string message)
+void LogFromLocation(int location, std::string message, bool warn = true)
 {
     switch (location) {
     case 0:
@@ -384,13 +384,16 @@ void LogFromLocation(int location, std::string message)
     case 3:
         LogPrintLevel(BCLog::LogFlags::ALL, BCLog::Level::Info, "%s\n", message);
         break;
+    case 4:
+        warn ? LogInfo("%s\n", message) : LogInfo("%s\n", message);
+        break;
     }
 }
 
-void LogFromLocationAndExpect(int location, std::string message, std::string expect)
+void LogFromLocationAndExpect(int location, std::string message, std::string expect, bool warn = true)
 {
     ASSERT_DEBUG_LOG(expect);
-    LogFromLocation(location, message);
+    LogFromLocation(location, message, warn);
 }
 
 BOOST_FIXTURE_TEST_CASE(logging_filesize_rate_limit, LogSetup)
@@ -465,6 +468,13 @@ BOOST_FIXTURE_TEST_CASE(logging_filesize_rate_limit, LogSetup)
 
     BOOST_CHECK_MESSAGE(log_file_size < GetFileSize(log_path), "location 3 should be exempt from rate limiting");
 
+    // log from warn "sublocation" until limit is reached
+    for (int i = 0; i < 1024; ++i) {
+        BOOST_CHECK_THROW(LogFromLocationAndExpect(4, log_message, "Excessive logging detected", /*warn=*/true), std::runtime_error);
+    }
+    // we haven't yet logged from the non-warn "sublocation", yet it is ratelimited right away
+    LogFromLocationAndExpect(4, log_message, "Excessive logging detected", /*warn=*/false);
+
     LogInstance().m_log_timestamps = prev_log_timestamps;
     LogInstance().m_log_sourcelocations = prev_log_sourcelocations;
     LogInstance().m_log_threadnames = prev_log_threadnames;

</details>

I had thought about that as well. I looked for patterns like this, but I did not look very hard. Do you think this deserves a comment in a follow-up to warn against behavior like this?

I was also worried about that, especially when the logging is called via some dedicated method which hijacks the location, even though the call sites should probably not be bundled together. Or if macros are messing up the lines in any way.

On the other hand, is it really necessary to do the accounting per line, aren't we over-complicating a hypothetical scenario?

The original PR stated:

The main point against global rate limiting is that it opens another attack vector where an attacker could trigger rate limiting and then execute a 2. attack which would then not be document in the logs at all

Maybe, but this could apply currently as well, you just have to make sure you exhaust the target logger before the second attack. And as far as I can tell currently any hack which would enable all logs to be written would allow log-locations * 1MiB additional lines to be added. That kinda' seems worse to me, maybe we should investigate a simpler solution first.

But if we stay with the per-line logging-quota, I think this should at least be explained in the PR description.

when the logging is called via some dedicated method which hijacks the location

I don't think we can reasonably protect against malicious modifications to the binary?

Or if macros are messing up the lines in any way.

That seems both unlikely and just something that should be, and is, tested.

you just have to make sure you exhaust the target logger

"just" seems inappropriate, unconditional logging should always take care that it can never be used to exhaust resources, but with this PR we add another layer of defence in case of an oversight.

On the other hand, is it really necessary to do the accounting per line, aren't we over-complicating a hypothetical scenario?

I don't think this is hypothetical -- security vulnerabilities these days are increasingly multi-layered and complex and it is not unheard of for attackers to chain together exploits. I have personally had to use logs to piece together what happened after-the-fact when somebody's machine was compromised. The concern brought up in the earlier PRs was about an attacker finding two vulnerabilities if there is a global limit:

• a logging vulnerability that triggers the global rate limit
• a separate vulnerability which goes undetected because all logs to disk are now suppressed

Maybe, but this could apply currently as well, you just have to make sure you exhaust the target logger before the second attack.

I don't think this applies currently -- because the rate limiting is done per source-code location, an attacker will leave a trail of evidence.

And as far as I can tell currently any hack which would enable all logs to be written would allow log-locations * 1MiB additional lines to be added.

I can't find a bug in the current version of the code that allows this to happen. If there is some way to bypass the rate limiting logic, that would be severe. However, the same issue would also exist in the global rate limiting case.

But if we stay with the per-line logging-quota, I think this should at least be explained in the PR description.

This is explained in the PR description under the "Approach" section -- it mentions source code locations.

The PR description still states:

Both the quota and time window are configurable

As far as I can tell that's not the case anymore.

When logging is restarted a tally of how many messages/bytes were dropped is printed

Do we also print the message count?

But if we stay with the per-line logging-quota, I think this should at least be explained in the PR description

I meant the reason for choosing to restrict based on source lines and not globally. I'm still not fully convinced that it's more dangerous to restrict all logging, but I can accept if others think it is - I'm probably just not up-to-date with these attacks.

As far as I can tell that's not the case anymore.

Ah, this was confusing. I meant to say that LogRateLimiter is parameterized, but it reads like a node operator is able to configure the quote and time window without modifying the source code. I've removed this line since it's confusing.

Do we also print the message count?

Removed mention of "messages".

I think there are a number of issues with this part of the test:

• the docstring states locations 2 and 3 are exempt, but I don't see why they would be
• it tests that the location can log up to the ratelimit amount, which is true in any case
• it tests that the filesize increases, which would also happen if ratelimiting were to have happened, so it doesn't really catch anything

I think the logging_filesize_rate_limit test can be improved and cleaned up in a follow-up (to e.g. address the very confusing BOOST_CHECK_THROW(LogFromLocationAndExpect()) pattern), so perhaps this can all be done together, but with a minimal diff I would suggest to change this to:

<details> <summary>git diff on 6a7147358c</summary>

diff --git a/src/test/logging_tests.cpp b/src/test/logging_tests.cpp
index 00fb44eaa3..847279ad4d 100644
--- a/src/test/logging_tests.cpp
+++ b/src/test/logging_tests.cpp
@@ -379,10 +379,10 @@ void LogFromLocation(int location, std::string message)
         LogInfo("%s\n", message);
         break;
     case 2:
-        LogPrintLevel(BCLog::LogFlags::NONE, BCLog::Level::Info, "%s\n", message);
+        LogDebug(BCLog::LogFlags::HTTP, "%s\n", message);
         break;
     case 3:
-        LogPrintLevel(BCLog::LogFlags::ALL, BCLog::Level::Info, "%s\n", message);
+        LogPrintLevel_(BCLog::LogFlags::ALL, BCLog::Level::Info, /*should_ratelimit=*/false, "%s\n", message);
         break;
     }
 }
@@ -449,20 +449,21 @@ BOOST_FIXTURE_TEST_CASE(logging_filesize_rate_limit, LogSetup)
 
     BOOST_CHECK_THROW(LogFromLocationAndExpect(1, log_message, "Restarting logging"), std::runtime_error);
 
-    // Attempt to log 1MiB from location 2 and 1MiB from location 3. These exempt locations should be allowed to log
-    // without limit.
-    log_file_size = GetFileSize(log_path);
-    for (int i = 0; i < 1024; ++i) {
-        BOOST_CHECK_THROW(LogFromLocationAndExpect(2, log_message, "Excessive logging detected"), std::runtime_error);
+    // Fill up locations 2 and 3 to the ratelimit amount
+    for (size_t loc : {2, 3}) {
+        for (int i = 0; i < 1024; ++i) {
+            LogFromLocation(loc, log_message);
+        }
     }
 
+    // Ensure location 2 (debug logging) can go beyond the ratelimiting, it is exempt.
+    log_file_size = GetFileSize(log_path);
+    BOOST_CHECK_THROW(LogFromLocationAndExpect(2, log_message, "Excessive logging detected"), std::runtime_error);
     BOOST_CHECK_MESSAGE(log_file_size < GetFileSize(log_path), "location 2 should be exempt from rate limiting");
 
+    // Ensure location 3 (with explicit should_ratelimit=false) can go beyond the ratelimiting, it is exempt.
     log_file_size = GetFileSize(log_path);
-    for (int i = 0; i < 1024; ++i) {
-        BOOST_CHECK_THROW(LogFromLocationAndExpect(3, log_message, "Excessive logging detected"), std::runtime_error);
-    }
-
+    BOOST_CHECK_THROW(LogFromLocationAndExpect(3, log_message, "Excessive logging detected"), std::runtime_error);
     BOOST_CHECK_MESSAGE(log_file_size < GetFileSize(log_path), "location 3 should be exempt from rate limiting");
 
     LogInstance().m_log_timestamps = prev_log_timestamps;

</details>

Will address in a follow-up, I think this is from an older version of the PR where the functions used in location 2/3 were not caught by the rate limit.

Let's do these here, I don't think we're in a rush.

We're trying to get this in for 30.0. We shouldn't rush it in if we have concerns about the stability or effectiveness of this code, but blocking it for stylistic or test improvement purposes seems counter-productive when they can be done in a follow-up, ensuring progress on the important bits.

Ok, if you're fine with that, I'm fine with that, let's do the remaining ones in follow-ups.

I think there are a number of issues with this part of the test:

I also noticed those in my review, but also noticed you mentioned it already.

nit: so many comment styles used here, most in new code. Now that this is a one-liner, we can unify it with the rest of the comments here:

    //! Fixed window rate limiter for logging.

If you apply this, please see other similar ones as well.

The problem with these inconsistencies is not just cosmetic, these differences are distracting us from being able to treat inconsistencies as code smells.

we seem to have a lot of (comment) styles here, now that it's this short, let's simplify and unify this:

    //! Fixed window rate limiter for logging.

nit:

        //! Whether any log locations are suppressed. Cached view on m_source_locations for performance reasons.

Cached view on m_source_locations for performance reasons

Can you explain these performance reasons? Is it to avoid iterating the values of the map to find a 0? But shouldn't we only prefix the dropped lines by * anyway (why prefix the lines that aren't dropped in the first place?), so why do we care about a global suppression state, i.e.

// To avoid confusion caused by dropped log messages when debugging an issue,
// we prefix log lines with "[*]" when there are any suppressed source locations.
if (m_limiter->SuppressionsActive()) {
    str_prefixed.insert(0, "[*] ");
}

I think this is more confusing than only prefixing the dropped lines, i.e. something like:

if (m_print_to_console && ratelimit) {
    str_prefixed.insert(0, "[*] ");
}

Which would eliminate the need for m_suppression_active as far as I can tell.

Can you explain these performance reasons?

Not having to acquire a lock and iterate over an entire map.

But shouldn't we only prefix the dropped lines by * anyway

No, the point is to continue making it visible to users that log lines are being suppressed, because they might have missed the initial announcement.

But shouldn't we only prefix the dropped lines by * anyway (why prefix the lines that aren't dropped in the first place?), so why do we care about a global suppression state, i.e.

To build on @stickies-v comment, terminals may have a history limit and so if the prefix was only for dropped lines, an attack (which should now be thwarted!) could go undetected.

Fair points, maybe we could hint at that in the first message which announces that some logs are being suppressed (explaining what the new * prefix indicates).

what's the reason for commented out code? Is this PR still in draft mode or is it ready for review?

This line should have been removed indeed, as it was replaced by ASSERT_DEBUG_LOG("Restarting logging");.

My mistake, addressed. This might have been a rebase artifact, I was pretty sure that I removed it.

this way we're not seeing the unequal values, just the message. Why not BOOST_CHECK_EQUAL?

Given that we had problems with Windows so far, it might not be immediately obvious if this newline is a single char on Windows as well - can we generalize the test so that it doesn't matter?

Is there a reason to copy the large message on each invocation?

void LogFromLocation(int location, const std::string& message)

I haven't spent time trying to come up with an alternative yet, so I might be completely wrong, but I'm not sure I fully understand yet why we need these states. If the role of the extra NEWLY_SUPPRESSED state is just to signal that we need to log a warning message now, maybe we can simplify a bit since it seems to me some work might be duplicated here (i.e. that we should be able to get rid of this enum completely). Let me know if you need me to create a prototype to (dis)prove my hunch.

Also, this change is meant to avoid an attack, we don't have to be that precise with the calculations, just a rough accounting should suffice as far as I can tell - especially if it makes the code simpler.

It's what we're doing in https://github.com/bitcoin/bitcoin/blob/e419b0e17f8acfe577c35c62a8a71a19aad249f3/src/txdb.cpp#L132 as well - we just call it an approximate size and keep adding values to it until the limit is exceeded. Would that not suffice here?

I'm not sure I fully understand yet why we need these states

It's because the callsites behave differently whether a log line is un, newly or still suppressed. Previously, we encapsulated all that logic inside the Consume() function (then called NeedsRateLimiting(), but that gave the function too many responsibilities (as I believe you also pointed out), so this cleans that up. It think perhaps working out the code you'd prefer would be helpful.

Also, this change is meant to avoid an attack, we don't have to be that precise with the calculations, just a rough accounting should suffice as far as I can tell - especially if it makes the code simpler.

The accounting could be less precise, I had not considered that. I like that this PR is precise and I can account for the bytes.

I passionately dislike these huge comments, they're usually distracting from the actual code (the ultimate source of truth) and over-explain something that - if indeed hard to understand - should be refactored instead.

• why is the outer function called a Callable object, but the internal one a function to be executed
• why are we even explaining SchedulerFunction here - the code already clearly states the same, the comment just duplicates exactly the same information in a place that should explain LogRateLimiter. IfSchedulerFunction is complicated, we could extract it to a dedicated type and explain it there if it's hard to understand.

This is a public class, explaining the parameters and interface seems very desirable to me. scheduler_func could mean many things, when I review code I like to be able to quickly see what something's intent is. This seems like a pretty obvious best practice?

I like comments because it gives you an overview of the code to come. I can understand the aversion to comments, but I personally find them pretty helpful especially here. Sure, the code is the real source of truth, but comments have their use and I think usage here is reasonable.

Can we document somewhere the expected behavior for when the node is restarted?

Have documented this in the commit message of 6e47dad25c5a167cd171e5c11d51a7bee7c8d3c6

Should be plural:

When `-logsourcelocations` is enabled, the log output now contains the entire

Ah, my bad. Fixed.

LogPrintLevel can be debug as well which won't be rate limited - so this generalization seems inaccurate to me. And the important part of our message (i.e. that we're hiding some logs now) is mentioned too late:

Unconditional logging to disk is now rate limited via `LogPrintf`, `LogInfo`, `LogWarning`, `LogError`,
and the corresponding `LogPrintLevel` calls by giving each source location a quota of
1MiB per hour. (#32604)

This is better -- I've implemented this to make it clear. I was attempting to walk a line between being verbose and being succinct.

👍 for removing the config option, this is simpler

but console logging is affected, we'll prefix them with * (which we're not explaining anywhere as far as I can tell)

This is mentioned in the PR description and also in the commit message of b5d0cc29ac378f360424472f637f6d6af74660a5.

I find this concerning, it's very unintuitive that logging announcement would even pose such a threat

Can you elaborate? Recursion is not inherently bad. It can lead to bugs, which is why we need to mindful about when we use it, but to me this looks like the best alternative. What do you suggest?

Recursion is not inherently bad

When the stopping condition isn't rock solit, it kinda' is. Maybe it is solid in this case - but given that we had to add a comment to reassure the readers, it may not be. I'd sleep better knowing that we haven't just introduced a new attack vector...

What do you suggest?

In other cases we've switched recursive methods to iterative ones, e.g. #32351. I haven't investigated what that would imply here, got already tired at the end of reviewing the rest of the code.