util/log: Provide util::log::NO_RATE_LIMIT to avoid rate limits

This commit is contained in:
Anthony Towns
2025-12-08 22:29:39 +10:00
parent 72e92d67df
commit f69d1ae56d
6 changed files with 47 additions and 26 deletions

View File

@@ -736,13 +736,12 @@ logging messages. They should be used as follows:
most of the time, and it should be used for log messages that are
useful for debugging and can reasonably be enabled on a production
system (that has sufficient free storage space). They will be logged
if the program is started with `-debug=category` or `-debug=1`.
if the program is started with `-debug=category` or `-debug=1`, or
the category is enabled through the `logging` RPC.
- `LogInfo(fmt, params...)` should only be used rarely, e.g. for startup
messages or for infrequent and important events such as a new block tip
being found or a new outbound connection being made. These log messages
are unconditional, so care must be taken that they can't be used by an
attacker to fill up storage.
being found or a new outbound connection being made.
- `LogError(fmt, params...)` should be used in place of `LogInfo` for
severe problems that require the node (or a subsystem) to shut down
@@ -764,6 +763,13 @@ Note that the format strings and parameters of `LogDebug` and `LogTrace`
are only evaluated if the logging category is enabled, so you must be
careful to avoid side-effects in those expressions.
While `LogInfo`, `LogWarning` and `LogError` messages should be rare,
in case there are circumstances where they are not, those messages
are automatically rate-limited to prevent potential disk-filling
attacks. For the cases where this protection is undesirable,
rate-limiting can be avoided with the `util::log::NO_RATE_LIMIT` tag, eg
`LogInfo(util::log::NO_RATE_LIMIT, "UpdateTip: new best=%s ...",...)`.
## General C++
For general C++ guidelines, you may refer to the [C++ Core

View File

@@ -572,8 +572,7 @@ void BCLog::LogRateLimiter::Reset()
}
for (const auto& [source_loc, stats] : source_locations) {
if (stats.m_dropped_bytes == 0) continue;
LogPrintLevel_(
LogFlags::ALL, Level::Warning, /*should_ratelimit=*/false,
LogWarning(util::log::NO_RATE_LIMIT,
"Restarting logging from %s:%d (%s): %d bytes were dropped during the last %ss.",
source_loc.file_name(), source_loc.line(), source_loc.function_name_short(),
stats.m_dropped_bytes, Ticks<std::chrono::seconds>(m_reset_window));

View File

@@ -276,7 +276,6 @@ namespace BCLog {
bool DefaultShrinkDebugFile() const;
};
} // namespace BCLog
BCLog::Logger& LogInstance();

View File

@@ -382,7 +382,7 @@ void LogFromLocation(Location location, const std::string& message) {
LogDebug(BCLog::LogFlags::HTTP, "%s\n", message);
return;
case Location::INFO_NOLIMIT:
LogPrintLevel_(BCLog::LogFlags::ALL, BCLog::Level::Info, /*should_ratelimit=*/false, "%s\n", message);
LogInfo(util::log::NO_RATE_LIMIT, "%s\n", message);
return;
} // no default case, so the compiler can warn about missing cases
assert(false);

View File

@@ -43,6 +43,12 @@ namespace util::log {
/** Opaque to util::log; interpreted by consumers (e.g., BCLog::LogFlags). */
using Category = uint64_t;
//! Structure and constant for tagging not to rate limit.
struct NoRateLimitTag {
explicit NoRateLimitTag() = default;
};
inline constexpr NoRateLimitTag NO_RATE_LIMIT{};
enum class Level {
Trace = 0, // High-volume or detailed logging for development/debugging
Debug, // Reasonably noisy logging, but still usable in production
@@ -68,15 +74,9 @@ bool ShouldLog(Category category, Level level);
/** Send message to be logged. Applications using the logging library need to provide this. */
void Log(Entry entry);
} // namespace util::log
namespace BCLog {
//! Alias for compatibility. Prefer util::log::Level over BCLog::Level in new code.
using Level = util::log::Level;
} // namespace BCLog
template <typename... Args>
inline void LogPrintFormatInternal(SourceLocation&& source_loc, BCLog::LogFlags flag, BCLog::Level level, bool should_ratelimit, util::ConstevalFormatString<sizeof...(Args)> fmt, const Args&... args)
inline void LogPrintFormatInternal_(SourceLocation&& source_loc, BCLog::LogFlags flag, util::log::Level level, bool should_ratelimit, util::ConstevalFormatString<sizeof...(Args)> fmt, const Args&... args)
{
std::string log_msg;
try {
@@ -92,17 +92,35 @@ inline void LogPrintFormatInternal(SourceLocation&& source_loc, BCLog::LogFlags
.message = std::move(log_msg)});
}
template <typename... Args>
inline void LogPrintFormatInternal(SourceLocation&& source_loc, BCLog::LogFlags flag, util::log::Level level, util::ConstevalFormatString<sizeof...(Args)> fmt, const Args&... args)
{
return LogPrintFormatInternal_(std::move(source_loc), flag, level, /*should_ratelimit=*/true, fmt, args...);
}
template <typename... Args>
inline void LogPrintFormatInternal(SourceLocation&& source_loc, BCLog::LogFlags flag, util::log::Level level, util::log::NoRateLimitTag, util::ConstevalFormatString<sizeof...(Args)> fmt, const Args&... args)
{
return LogPrintFormatInternal_(std::move(source_loc), flag, level, /*should_ratelimit=*/false, fmt, args...);
}
} // namespace util::log
namespace BCLog {
//! Alias for compatibility. Prefer util::log::Level over BCLog::Level in new code.
using Level = util::log::Level;
} // namespace BCLog
// Allow __func__ to be used in any context without warnings:
// NOLINTNEXTLINE(bugprone-lambda-function-name)
#define LogPrintLevel_(category, level, should_ratelimit, ...) LogPrintFormatInternal(SourceLocation{__func__}, category, level, should_ratelimit, __VA_ARGS__)
#define LogPrintLevel_(category, level, ...) util::log::LogPrintFormatInternal(SourceLocation{__func__}, category, level, __VA_ARGS__)
// Log unconditionally. Uses basic rate limiting to mitigate disk filling attacks.
// Be conservative when using functions that unconditionally log to debug.log!
// It should not be the case that an inbound peer can fill up a user's storage
// with debug.log entries.
#define LogInfo(...) LogPrintLevel_(BCLog::LogFlags::ALL, BCLog::Level::Info, /*should_ratelimit=*/true, __VA_ARGS__)
#define LogWarning(...) LogPrintLevel_(BCLog::LogFlags::ALL, BCLog::Level::Warning, /*should_ratelimit=*/true, __VA_ARGS__)
#define LogError(...) LogPrintLevel_(BCLog::LogFlags::ALL, BCLog::Level::Error, /*should_ratelimit=*/true, __VA_ARGS__)
#define LogInfo(...) LogPrintLevel_(BCLog::LogFlags::ALL, util::log::Level::Info, __VA_ARGS__)
#define LogWarning(...) LogPrintLevel_(BCLog::LogFlags::ALL, util::log::Level::Warning, __VA_ARGS__)
#define LogError(...) LogPrintLevel_(BCLog::LogFlags::ALL, util::log::Level::Error, __VA_ARGS__)
// Use a macro instead of a function for conditional logging to prevent
// evaluating arguments when logging for the category is not enabled.
@@ -113,14 +131,13 @@ inline void LogPrintFormatInternal(SourceLocation&& source_loc, BCLog::LogFlags
#define detail_LogIfCategoryAndLevelEnabled(category, level, ...) \
do { \
if (util::log::ShouldLog((category), (level))) { \
bool rate_limit{level >= BCLog::Level::Info}; \
Assume(!rate_limit); /*Only called with the levels below*/ \
LogPrintLevel_(category, level, rate_limit, __VA_ARGS__); \
Assume((level) < util::log::Level::Info); /*Only called with the levels below*/ \
LogPrintLevel_((category), (level), util::log::NO_RATE_LIMIT, __VA_ARGS__); \
} \
} while (0)
// Log conditionally, prefixing the output with the passed category name.
#define LogDebug(category, ...) detail_LogIfCategoryAndLevelEnabled(category, BCLog::Level::Debug, __VA_ARGS__)
#define LogTrace(category, ...) detail_LogIfCategoryAndLevelEnabled(category, BCLog::Level::Trace, __VA_ARGS__)
#define LogDebug(category, ...) detail_LogIfCategoryAndLevelEnabled(category, util::log::Level::Debug, __VA_ARGS__)
#define LogTrace(category, ...) detail_LogIfCategoryAndLevelEnabled(category, util::log::Level::Trace, __VA_ARGS__)
#endif // BITCOIN_UTIL_LOG_H

View File

@@ -2864,8 +2864,8 @@ static void UpdateTipLog(
AssertLockHeld(::cs_main);
// Disable rate limiting in LogPrintLevel_ so this source location may log during IBD.
LogPrintLevel_(BCLog::LogFlags::ALL, util::log::Level::Info, /*should_ratelimit=*/false, "%s%s: new best=%s height=%d version=0x%08x log2_work=%f tx=%lu date='%s' progress=%f cache=%.1fMiB(%utxo)%s\n",
// Disable rate limiting as this may log frequently during IBD.
LogInfo(util::log::NO_RATE_LIMIT, "%s%s: new best=%s height=%d version=0x%08x log2_work=%f tx=%lu date='%s' progress=%f cache=%.1fMiB(%utxo)%s\n",
prefix, func_name,
tip->GetBlockHash().ToString(), tip->nHeight, tip->nVersion,
log(tip->nChainWork.getdouble()) / log(2.0), tip->m_chain_tx_count,