highperfocused/bitcoin
1
0
Fork 0
mirror of https://github.com/bitcoin/bitcoin.git synced 2026-05-29 23:33:33 +02:00
Code Issues Packages Projects Releases Wiki Activity

logging: pass log::Entry through to logging functions

Browse Source 
Use the entry's timestamp and thread_name, captured at the call
site, instead of re-capturing them in the logger.
This commit is contained in:
stickies-v
2026-03-10 14:34:22 +08:00
parent b414913c73
commit 8115001cd4
3 changed files with 43 additions and 33 deletions
Download Patch File Download Diff File Expand all files Collapse all files

60
src/logging.cpp
View File

@@ -75,7 +75,13 @@ 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), SourceLocation{__func__}, BCLog::ALL, Level::Info, /*should_ratelimit=*/false);
LogPrint_({
.category = BCLog::ALL,
.level = Level::Info,
.should_ratelimit = false,
.source_loc = SourceLocation{__func__},
.message = strprintf("Early logging buffer overflowed, %d log lines discarded.", m_buffer_lines_discarded),
});
}
while (!m_msgs_before_open.empty()) {
const auto& buflog = m_msgs_before_open.front();
@@ -421,28 +427,29 @@ void BCLog::Logger::FormatLogStrInPlace(std::string& str, BCLog::LogFlags catego
str.insert(0, LogTimestampStr(now, mocktime));
}
void BCLog::Logger::LogPrintStr(std::string_view str, SourceLocation&& source_loc, BCLog::LogFlags category, BCLog::Level level, bool should_ratelimit)
void BCLog::Logger::LogPrint(util::log::Entry entry)
{
STDLOCK(m_cs);
return LogPrintStr_(str, std::move(source_loc), category, level, should_ratelimit);
return LogPrint_(std::move(entry));
}
// NOLINTNEXTLINE(misc-no-recursion)
void BCLog::Logger::LogPrintStr_(std::string_view str, SourceLocation&& source_loc, BCLog::LogFlags category, BCLog::Level level, bool should_ratelimit)
void BCLog::Logger::LogPrint_(util::log::Entry entry)
{
std::string str_prefixed = LogEscapeMessage(str);
std::string str_prefixed = LogEscapeMessage(entry.message);
if (m_buffering) {
{
BufferedLog buf{
.now = SystemClock::now(),
.now = entry.timestamp,
.mocktime = GetMockTime(),
.str = str_prefixed,
.threadname = util::ThreadGetInternalName(),
.source_loc = std::move(source_loc),
.category = category,
.level = level,
.str = std::move(str_prefixed),
.threadname = std::move(entry.thread_name),
.source_loc = entry.source_loc,
.category = static_cast<LogFlags>(entry.category),
.level = entry.level,
};
(void)std::move(entry);
m_cur_buffer_memusage += MemUsage(buf);
m_msgs_before_open.push_back(std::move(buf));
}
@@ -460,21 +467,26 @@ void BCLog::Logger::LogPrintStr_(std::string_view str, SourceLocation&& source_l
return;
}
FormatLogStrInPlace(str_prefixed, category, level, source_loc, util::ThreadGetInternalName(), SystemClock::now(), GetMockTime());
FormatLogStrInPlace(str_prefixed, static_cast<LogFlags>(entry.category), entry.level, entry.source_loc, entry.thread_name, entry.timestamp, GetMockTime());
bool ratelimit{false};
if (should_ratelimit && m_limiter) {
auto status{m_limiter->Consume(source_loc, str_prefixed)};
if (entry.should_ratelimit && m_limiter) {
auto status{m_limiter->Consume(entry.source_loc, str_prefixed)};
if (status == 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 "
"source location until time window resets. Console logging "
"unaffected. Last log entry.",
source_loc.file_name(), source_loc.line(), source_loc.function_name_short(),
m_limiter->m_max_bytes,
Ticks<std::chrono::seconds>(m_limiter->m_reset_window)),
SourceLocation{__func__}, LogFlags::ALL, Level::Warning, /*should_ratelimit=*/false); // with should_ratelimit=false, this cannot lead to infinite recursion
LogPrint_({
.category = LogFlags::ALL,
.level = Level::Warning,
.should_ratelimit = false, // with should_ratelimit=false, this cannot lead to infinite recursion
.source_loc = SourceLocation{__func__},
.message = strprintf(
"Excessive logging detected from %s:%d (%s): >%d bytes logged during "
"the last time window of %is. Suppressing logging to disk from this "
"source location until time window resets. Console logging "
"unaffected. Last log entry.",
entry.source_loc.file_name(), entry.source_loc.line(), entry.source_loc.function_name_short(),
m_limiter->m_max_bytes,
Ticks<std::chrono::seconds>(m_limiter->m_reset_window)),
});
} else if (status == LogRateLimiter::Status::STILL_SUPPRESSED) {
ratelimit = true;
}
@@ -612,6 +624,6 @@ void util::log::Log(util::log::Entry entry)
{
BCLog::Logger& logger{LogInstance()};
if (logger.Enabled()) {
logger.LogPrintStr(std::move(entry.message), std::move(entry.source_loc), static_cast<BCLog::LogFlags>(entry.category), entry.level, entry.should_ratelimit);
logger.LogPrint(std::move(entry));
}
}

12
src/logging.h
View File

@@ -164,11 +164,10 @@ namespace BCLog {
std::string LogTimestampStr(SystemClock::time_point now, std::chrono::seconds mocktime) const;
/** Slots that connect to the print signal */
std::list<std::function<void(const std::string&)>> m_print_callbacks GUARDED_BY(m_cs) {};
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, SourceLocation&& source_loc, BCLog::LogFlags category, BCLog::Level level, bool should_ratelimit)
EXCLUSIVE_LOCKS_REQUIRED(m_cs);
/** Send an entry to the log output (internal) */
void LogPrint_(util::log::Entry log_entry) EXCLUSIVE_LOCKS_REQUIRED(m_cs);
std::string GetLogPrefix(LogFlags category, Level level) const;
@@ -185,9 +184,8 @@ namespace BCLog {
fs::path m_file_path;
std::atomic<bool> m_reopen_file{false};
/** Send a string to the log output */
void LogPrintStr(std::string_view str, SourceLocation&& source_loc, BCLog::LogFlags category, BCLog::Level level, bool should_ratelimit)
EXCLUSIVE_LOCKS_REQUIRED(!m_cs);
/** Send an entry to the log output */
void LogPrint(util::log::Entry log_entry) EXCLUSIVE_LOCKS_REQUIRED(!m_cs);
/** Returns whether logs will be written to any output */
bool Enabled() const EXCLUSIVE_LOCKS_REQUIRED(!m_cs)

4
src/test/logging_tests.cpp
View File

@@ -110,7 +110,7 @@ BOOST_AUTO_TEST_CASE(logging_timer)
BOOST_CHECK_EQUAL(micro_timer.LogMsg("msg").substr(0, result_prefix.size()), result_prefix);
}
BOOST_FIXTURE_TEST_CASE(logging_LogPrintStr, LogSetup)
BOOST_FIXTURE_TEST_CASE(logging_LogPrint, LogSetup)
{
LogInstance().m_log_sourcelocations = true;
@@ -134,7 +134,7 @@ BOOST_FIXTURE_TEST_CASE(logging_LogPrintStr, LogSetup)
std::vector<std::string> 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_short(), prefix, msg));
LogInstance().LogPrintStr(msg, std::move(loc), category, level, /*should_ratelimit=*/false);
LogInstance().LogPrint({.category = category, .level = level, .should_ratelimit = false, .source_loc = std::move(loc), .message = msg});
}
std::vector<std::string> log_lines{ReadDebugLogLines()};
BOOST_CHECK_EQUAL_COLLECTIONS(log_lines.begin(), log_lines.end(), expected.begin(), expected.end());