From facd3d56ccbe2414a5f2b75be7132cd8b904f1e9 Mon Sep 17 00:00:00 2001 From: MarcoFalke <*~=`'#}+{/-|&$^_@721217.xyz> Date: Wed, 17 Dec 2025 10:49:27 +0100 Subject: [PATCH] log: Use `__func__` for -logsourcelocations --- doc/release-notes-34088.md | 2 ++ src/logging.cpp | 18 ++++++++-------- src/logging.h | 42 +++++++++++++++++++++++++++++--------- src/test/logging_tests.cpp | 20 +++++++++--------- 4 files changed, 53 insertions(+), 29 deletions(-) create mode 100644 doc/release-notes-34088.md diff --git a/doc/release-notes-34088.md b/doc/release-notes-34088.md new file mode 100644 index 00000000000..5aa8a9d992f --- /dev/null +++ b/doc/release-notes-34088.md @@ -0,0 +1,2 @@ +- When `-logsourcelocations` is enabled, the log output now contains just the + function name instead of the entire function signature. (#34088) diff --git a/src/logging.cpp b/src/logging.cpp index 5fb42bba624..113fc3462fa 100644 --- a/src/logging.cpp +++ b/src/logging.cpp @@ -75,7 +75,7 @@ bool BCLog::Logger::StartLogging() // dump buffered messages from before we opened the log m_buffering = false; if (m_buffer_lines_discarded > 0) { - 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); + LogPrintStr_(strprintf("Early logging buffer overflowed, %d log lines discarded.\n", m_buffer_lines_discarded), SourceLocation{__func__}, BCLog::ALL, Level::Info, /*should_ratelimit=*/false); } while (!m_msgs_before_open.empty()) { const auto& buflog = m_msgs_before_open.front(); @@ -388,7 +388,7 @@ std::shared_ptr BCLog::LogRateLimiter::Create( } BCLog::LogRateLimiter::Status BCLog::LogRateLimiter::Consume( - const std::source_location& source_loc, + const SourceLocation& source_loc, const std::string& str) { StdLockGuard scoped_lock(m_mutex); @@ -403,14 +403,14 @@ BCLog::LogRateLimiter::Status BCLog::LogRateLimiter::Consume( return status; } -void BCLog::Logger::FormatLogStrInPlace(std::string& str, BCLog::LogFlags category, BCLog::Level level, const std::source_location& source_loc, std::string_view threadname, SystemClock::time_point now, std::chrono::seconds mocktime) const +void BCLog::Logger::FormatLogStrInPlace(std::string& str, BCLog::LogFlags category, BCLog::Level level, const SourceLocation& source_loc, std::string_view threadname, SystemClock::time_point now, std::chrono::seconds mocktime) const { if (!str.ends_with('\n')) str.push_back('\n'); str.insert(0, GetLogPrefix(category, level)); if (m_log_sourcelocations) { - str.insert(0, strprintf("[%s:%d] [%s] ", RemovePrefixView(source_loc.file_name(), "./"), source_loc.line(), source_loc.function_name())); + str.insert(0, strprintf("[%s:%d] [%s] ", RemovePrefixView(source_loc.file_name(), "./"), source_loc.line(), source_loc.function_name_short())); } if (m_log_threadnames) { @@ -420,14 +420,14 @@ void BCLog::Logger::FormatLogStrInPlace(std::string& str, BCLog::LogFlags catego str.insert(0, LogTimestampStr(now, mocktime)); } -void BCLog::Logger::LogPrintStr(std::string_view str, std::source_location&& source_loc, BCLog::LogFlags category, BCLog::Level level, bool should_ratelimit) +void BCLog::Logger::LogPrintStr(std::string_view str, SourceLocation&& source_loc, BCLog::LogFlags category, BCLog::Level level, bool should_ratelimit) { StdLockGuard scoped_lock(m_cs); 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) +void BCLog::Logger::LogPrintStr_(std::string_view str, SourceLocation&& source_loc, BCLog::LogFlags category, BCLog::Level level, bool should_ratelimit) { std::string str_prefixed = LogEscapeMessage(str); @@ -470,10 +470,10 @@ void BCLog::Logger::LogPrintStr_(std::string_view str, std::source_location&& so "the last time window of %is. Suppressing logging to disk from this " "source location until time window resets. Console logging " "unaffected. Last log entry.", - source_loc.file_name(), source_loc.line(), source_loc.function_name(), + source_loc.file_name(), source_loc.line(), source_loc.function_name_short(), m_limiter->m_max_bytes, Ticks(m_limiter->m_reset_window)), - std::source_location::current(), LogFlags::ALL, Level::Warning, /*should_ratelimit=*/false); // with should_ratelimit=false, this cannot lead to infinite recursion + SourceLocation{__func__}, LogFlags::ALL, Level::Warning, /*should_ratelimit=*/false); // with should_ratelimit=false, this cannot lead to infinite recursion } else if (status == LogRateLimiter::Status::STILL_SUPPRESSED) { ratelimit = true; } @@ -564,7 +564,7 @@ void BCLog::LogRateLimiter::Reset() LogPrintLevel_( LogFlags::ALL, Level::Warning, /*should_ratelimit=*/false, "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(), + source_loc.file_name(), source_loc.line(), source_loc.function_name_short(), stats.m_dropped_bytes, Ticks(m_reset_window)); } } diff --git a/src/logging.h b/src/logging.h index 29f51085854..2105039f511 100644 --- a/src/logging.h +++ b/src/logging.h @@ -37,15 +37,35 @@ extern const char * const DEFAULT_DEBUGLOGFILE; extern bool fLogIPs; +/// Like std::source_location, but allowing to override the function name. +class SourceLocation +{ +public: + /// The func argument must be constructed from the C++11 __func__ macro. + /// Ref: https://en.cppreference.com/w/cpp/language/function.html#func + /// Non-static string literals are not supported. + SourceLocation(const char* func, + std::source_location loc = std::source_location::current()) + : m_func{func}, m_loc{loc} {} + + std::string_view file_name() const { return m_loc.file_name(); } + std::uint_least32_t line() const { return m_loc.line(); } + std::string_view function_name_short() const { return m_func; } + +private: + std::string_view m_func; + std::source_location m_loc; +}; + struct SourceLocationEqual { - bool operator()(const std::source_location& lhs, const std::source_location& rhs) const noexcept + bool operator()(const SourceLocation& lhs, const SourceLocation& rhs) const noexcept { return lhs.line() == rhs.line() && std::string_view(lhs.file_name()) == std::string_view(rhs.file_name()); } }; struct SourceLocationHasher { - size_t operator()(const std::source_location& s) const noexcept + size_t operator()(const SourceLocation& s) const noexcept { // Use CSipHasher(0, 0) as a simple way to get uniform distribution. return size_t(CSipHasher(0, 0) @@ -131,7 +151,7 @@ namespace BCLog { mutable StdMutex m_mutex; //! Stats for each source location that has attempted to log something. - std::unordered_map m_source_locations GUARDED_BY(m_mutex); + std::unordered_map m_source_locations GUARDED_BY(m_mutex); //! Whether any log locations are suppressed. Cached view on m_source_locations for performance reasons. std::atomic m_suppression_active{false}; LogRateLimiter(uint64_t max_bytes, std::chrono::seconds reset_window); @@ -163,7 +183,7 @@ namespace BCLog { //! Consumes `source_loc`'s available bytes corresponding to the size of the (formatted) //! `str` and returns its status. [[nodiscard]] Status Consume( - const std::source_location& source_loc, + const SourceLocation& source_loc, const std::string& str) EXCLUSIVE_LOCKS_REQUIRED(!m_mutex); //! Resets all usage to zero. Called periodically by the scheduler. void Reset() EXCLUSIVE_LOCKS_REQUIRED(!m_mutex); @@ -178,7 +198,7 @@ namespace BCLog { SystemClock::time_point now; std::chrono::seconds mocktime; std::string str, threadname; - std::source_location source_loc; + SourceLocation source_loc; LogFlags category; Level level; }; @@ -206,7 +226,7 @@ namespace BCLog { /** Log categories bitfield. */ std::atomic m_categories{BCLog::NONE}; - void FormatLogStrInPlace(std::string& str, LogFlags category, Level level, const std::source_location& source_loc, std::string_view threadname, SystemClock::time_point now, std::chrono::seconds mocktime) const; + void FormatLogStrInPlace(std::string& str, LogFlags category, Level level, const SourceLocation& source_loc, std::string_view threadname, SystemClock::time_point now, std::chrono::seconds mocktime) const; std::string LogTimestampStr(SystemClock::time_point now, std::chrono::seconds mocktime) const; @@ -214,7 +234,7 @@ namespace BCLog { std::list> m_print_callbacks GUARDED_BY(m_cs) {}; /** Send a string to the log output (internal) */ - void LogPrintStr_(std::string_view str, std::source_location&& source_loc, BCLog::LogFlags category, BCLog::Level level, bool should_ratelimit) + void LogPrintStr_(std::string_view str, SourceLocation&& source_loc, BCLog::LogFlags category, BCLog::Level level, bool should_ratelimit) EXCLUSIVE_LOCKS_REQUIRED(m_cs); std::string GetLogPrefix(LogFlags category, Level level) const; @@ -233,7 +253,7 @@ namespace BCLog { std::atomic m_reopen_file{false}; /** Send a string to the log output */ - void LogPrintStr(std::string_view str, std::source_location&& source_loc, BCLog::LogFlags category, BCLog::Level level, bool should_ratelimit) + void LogPrintStr(std::string_view str, SourceLocation&& 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 */ @@ -347,7 +367,7 @@ static inline bool LogAcceptCategory(BCLog::LogFlags category, BCLog::Level leve bool GetLogCategory(BCLog::LogFlags& flag, std::string_view str); template -inline void LogPrintFormatInternal(std::source_location&& source_loc, BCLog::LogFlags flag, BCLog::Level level, bool should_ratelimit, util::ConstevalFormatString fmt, const Args&... args) +inline void LogPrintFormatInternal(SourceLocation&& source_loc, BCLog::LogFlags flag, BCLog::Level level, bool should_ratelimit, util::ConstevalFormatString fmt, const Args&... args) { if (LogInstance().Enabled()) { std::string log_msg; @@ -360,7 +380,9 @@ inline void LogPrintFormatInternal(std::source_location&& source_loc, BCLog::Log } } -#define LogPrintLevel_(category, level, should_ratelimit, ...) LogPrintFormatInternal(std::source_location::current(), category, level, should_ratelimit, __VA_ARGS__) +// 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__) // Log unconditionally. Uses basic rate limiting to mitigate disk filling attacks. // Be conservative when using functions that unconditionally log to debug.log! diff --git a/src/test/logging_tests.cpp b/src/test/logging_tests.cpp index 2a34aefae18..12ce40fb00e 100644 --- a/src/test/logging_tests.cpp +++ b/src/test/logging_tests.cpp @@ -118,21 +118,21 @@ BOOST_FIXTURE_TEST_CASE(logging_LogPrintStr, LogSetup) BCLog::LogFlags category; BCLog::Level level; std::string prefix; - std::source_location loc; + SourceLocation loc; }; std::vector 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()}, + {"foo1: bar1", BCLog::NET, BCLog::Level::Debug, "[net] ", SourceLocation{__func__}}, + {"foo2: bar2", BCLog::NET, BCLog::Level::Info, "[net:info] ", SourceLocation{__func__}}, + {"foo3: bar3", BCLog::ALL, BCLog::Level::Debug, "[debug] ", SourceLocation{__func__}}, + {"foo4: bar4", BCLog::ALL, BCLog::Level::Info, "", SourceLocation{__func__}}, + {"foo5: bar5", BCLog::NONE, BCLog::Level::Debug, "[debug] ", SourceLocation{__func__}}, + {"foo6: bar6", BCLog::NONE, BCLog::Level::Info, "", SourceLocation{__func__}}, }; std::vector expected; for (auto& [msg, category, level, prefix, loc] : cases) { - expected.push_back(tfm::format("[%s:%s] [%s] %s%s", util::RemovePrefix(loc.file_name(), "./"), loc.line(), loc.function_name(), prefix, msg)); + expected.push_back(tfm::format("[%s:%s] [%s] %s%s", util::RemovePrefix(loc.file_name(), "./"), loc.line(), loc.function_name_short(), prefix, msg)); LogInstance().LogPrintStr(msg, std::move(loc), category, level, /*should_ratelimit=*/false); } std::vector log_lines{ReadDebugLogLines()}; @@ -306,8 +306,8 @@ BOOST_AUTO_TEST_CASE(logging_log_rate_limiter) auto& limiter{*Assert(limiter_)}; using Status = BCLog::LogRateLimiter::Status; - auto source_loc_1{std::source_location::current()}; - auto source_loc_2{std::source_location::current()}; + auto source_loc_1{SourceLocation{__func__}}; + auto source_loc_2{SourceLocation{__func__}}; // A fresh limiter should not have any suppressions BOOST_CHECK(!limiter.SuppressionsActive());