Skip to content

Commit

Permalink
logging: replace global and category log levels with atomic int
Browse files Browse the repository at this point in the history 
Since we have reduced how much log levels can be configured (error,
warning and info are always logged; and only debug and trace levels can
be disabled), we only need two bits per category to store the information.
We can do this with two atomic ints, one for whether -debug is enabled,
and the other for whether -trace is enabled.

This allows `WillLogCategoryLevel` to avoid taking a mutex, potentially
allowing for better performance in the event that multiple threads are
running many LogDebug(..) statements over categories that do not have
-debug enabled (or LogTrace/-trace).
  • Loading branch information
@ajtowns
ajtowns committed Aug 31, 2023
1 parent cb58059 commit 451f2e7
Show file tree
Hide file tree
Showing 4 changed files with 53 additions and 97 deletions.
66 changes: 26 additions & 40 deletions src/logging.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -93,12 +93,6 @@ void BCLog::Logger::DisconnectTestLogger()
m_print_callbacks.clear();
}

void BCLog::Logger::EnableCategory(BCLog::LogFlags flag)
{
m_categories |= flag;
SetCategoryLogLevel(flag, Level::Debug);
}

bool BCLog::Logger::EnableCategory(const std::string& str)
{
BCLog::LogFlags flag;
Expand All @@ -107,12 +101,6 @@ bool BCLog::Logger::EnableCategory(const std::string& str)
return true;
}

void BCLog::Logger::TraceCategory(BCLog::LogFlags flag)
{
m_categories |= flag;
SetCategoryLogLevel(flag, Level::Trace);
}

bool BCLog::Logger::TraceCategory(const std::string& str)
{
BCLog::LogFlags flag;
Expand All @@ -121,11 +109,6 @@ bool BCLog::Logger::TraceCategory(const std::string& str)
return true;
}

void BCLog::Logger::DisableCategory(BCLog::LogFlags flag)
{
m_categories &= ~flag;
}

bool BCLog::Logger::DisableCategory(const std::string& str)
{
BCLog::LogFlags flag;
Expand All @@ -141,15 +124,17 @@ bool BCLog::Logger::WillLogCategory(BCLog::LogFlags category) const

bool BCLog::Logger::WillLogCategoryLevel(BCLog::LogFlags category, BCLog::Level level) const
{
// Log messages at Info, Warning and Error level unconditionally, so that
// important troubleshooting information doesn't get lost.
if (level >= BCLog::Level::Info) return true;

if (!WillLogCategory(category)) return false;

StdLockGuard scoped_lock(m_cs);
const auto it{m_category_log_levels.find(category)};
return level >= (it == m_category_log_levels.end() ? LogLevel() : it->second);
switch (level) {
case BCLog::Level::Error:
case BCLog::Level::Warning:
case BCLog::Level::Info:
break;
case BCLog::Level::Debug:
return WillLogCategory(category);
case BCLog::Level::Trace:
return (m_trace_categories.load(std::memory_order_relaxed) & category) != 0;
}
return true;
}

bool BCLog::Logger::DefaultShrinkDebugFile() const
Expand Down Expand Up @@ -519,22 +504,23 @@ void BCLog::Logger::ShrinkDebugFile()
fclose(file);
}

bool BCLog::Logger::SetLogLevel(const std::string& level_str)
{
const auto level = GetLogLevel(level_str);
if (!level.has_value() || level.value() > MAX_USER_SETABLE_SEVERITY_LEVEL) return false;
m_log_level = level.value();
return true;
}

void BCLog::Logger::SetCategoryLogLevel(BCLog::LogFlags flag, BCLog::Level level)
{
StdLockGuard scoped_lock(m_cs);
if (flag == LogFlags::ALL) {
SetLogLevel(level);
m_category_log_levels.clear();
} else {
m_category_log_levels[flag] = level;
switch (level) {
case BCLog::Level::Error:
case BCLog::Level::Warning:
case BCLog::Level::Info:
m_categories &= ~flag;
m_trace_categories &= ~flag;
break;
case BCLog::Level::Debug:
m_categories |= flag;
m_trace_categories &= ~flag;
break;
case BCLog::Level::Trace:
m_categories |= flag;
m_trace_categories |= flag;
break;
}
}

Expand Down
35 changes: 10 additions & 25 deletions src/logging.h
View file
Original file line number Diff line number Diff line change
Expand Up @@ -17,7 +17,6 @@
#include <list>
#include <mutex>
#include <string>
#include <unordered_map>
#include <vector>

static const bool DEFAULT_LOGTIMEMICROS = false;
Expand Down Expand Up @@ -94,15 +93,10 @@ namespace BCLog {
*/
std::atomic_bool m_started_new_line{true};

//! Category-specific log level. Overrides `m_log_level`.
std::unordered_map<LogFlags, Level> m_category_log_levels GUARDED_BY(m_cs);

//! If there is no category-specific log level, all logs with a severity
//! level lower than `m_log_level` will be ignored.
std::atomic<Level> m_log_level{Level::Debug};

/** Log categories bitfield. */
std::atomic<uint32_t> m_categories{0};
/** Tracing-enabled categories bitfield. */
std::atomic<uint32_t> m_trace_categories{0};

std::string LogTimestampStr(const std::string& str);

Expand Down Expand Up @@ -153,30 +147,21 @@ namespace BCLog {

void ShrinkDebugFile();

std::unordered_map<LogFlags, Level> CategoryLevels() const
{
StdLockGuard scoped_lock(m_cs);
return m_category_log_levels;
}
void SetCategoryLogLevel(const std::unordered_map<LogFlags, Level>& levels)
{
StdLockGuard scoped_lock(m_cs);
m_category_log_levels = levels;
}
void SetCategoryLogLevel(LogFlags flag, Level level);
bool SetCategoryLogLevel(const std::string& category_str, const std::string& level_str);

Level LogLevel() const { return m_log_level.load(); }
void SetLogLevel(Level level) { m_log_level = level; }
bool SetLogLevel(const std::string& level);

uint32_t GetCategoryMask() const { return m_categories.load(); }
uint32_t GetCategoryTraceMask() const { return m_trace_categories.load(); }
void ResetLogLevels(uint32_t catmask, uint32_t tracemask) {
m_categories = catmask;
m_trace_categories = (catmask | tracemask);
}

void EnableCategory(LogFlags flag);
void EnableCategory(LogFlags flag) { SetCategoryLogLevel(flag, Level::Debug); }
bool EnableCategory(const std::string& str);
void TraceCategory(LogFlags flag);
void TraceCategory(LogFlags flag) { SetCategoryLogLevel(flag, Level::Trace); }
bool TraceCategory(const std::string& str);
void DisableCategory(LogFlags flag);
void DisableCategory(LogFlags flag) { SetCategoryLogLevel(flag, Level::Info); }
bool DisableCategory(const std::string& str);

bool WillLogCategory(LogFlags category) const;
Expand Down
7 changes: 4 additions & 3 deletions src/test/i2p_tests.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -20,8 +20,9 @@ BOOST_FIXTURE_TEST_SUITE(i2p_tests, BasicTestingSetup)

BOOST_AUTO_TEST_CASE(unlimited_recv)
{
const auto prev_log_level{LogInstance().LogLevel()};
LogInstance().SetLogLevel(BCLog::Level::Trace);
const auto prev_log_mask{LogInstance().GetCategoryMask()};
const auto prev_log_trace_mask{LogInstance().GetCategoryTraceMask()};
LogInstance().TraceCategory(BCLog::LogFlags::ALL);
auto CreateSockOrig = CreateSock;

// Mock CreateSock() to create MockSock.
Expand All @@ -42,7 +43,7 @@ BOOST_AUTO_TEST_CASE(unlimited_recv)
}

CreateSock = CreateSockOrig;
LogInstance().SetLogLevel(prev_log_level);
LogInstance().ResetLogLevels(prev_log_mask, prev_log_trace_mask);
}

BOOST_AUTO_TEST_SUITE_END()
42 changes: 13 additions & 29 deletions src/test/logging_tests.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -21,8 +21,7 @@ BOOST_FIXTURE_TEST_SUITE(logging_tests, BasicTestingSetup)

static void ResetLogger()
{
LogInstance().SetLogLevel(BCLog::Level::Debug);
LogInstance().SetCategoryLogLevel({});
LogInstance().ResetLogLevels(0,0);
}

struct LogSetup : public BasicTestingSetup {
Expand All @@ -33,8 +32,8 @@ struct LogSetup : public BasicTestingSetup {
bool prev_log_timestamps;
bool prev_log_threadnames;
bool prev_log_sourcelocations;
std::unordered_map<BCLog::LogFlags, BCLog::Level> prev_category_levels;
BCLog::Level prev_log_level;
uint32_t prev_category_mask;
uint32_t prev_category_trace_mask;

LogSetup() : prev_log_path{LogInstance().m_file_path},
tmp_log_path{m_args.GetDataDirBase() / "tmp_debug.log"},
Expand All @@ -43,8 +42,8 @@ struct LogSetup : public BasicTestingSetup {
prev_log_timestamps{LogInstance().m_log_timestamps},
prev_log_threadnames{LogInstance().m_log_threadnames},
prev_log_sourcelocations{LogInstance().m_log_sourcelocations},
prev_category_levels{LogInstance().CategoryLevels()},
prev_log_level{LogInstance().LogLevel()}
prev_category_mask{LogInstance().GetCategoryMask()},
prev_category_trace_mask{LogInstance().GetCategoryTraceMask()}
{
LogInstance().m_file_path = tmp_log_path;
LogInstance().m_reopen_file = true;
Expand All @@ -67,8 +66,7 @@ struct LogSetup : public BasicTestingSetup {
LogInstance().m_log_timestamps = prev_log_timestamps;
LogInstance().m_log_threadnames = prev_log_threadnames;
LogInstance().m_log_sourcelocations = prev_log_sourcelocations;
LogInstance().SetLogLevel(prev_log_level);
LogInstance().SetCategoryLogLevel(prev_category_levels);
LogInstance().ResetLogLevels(prev_category_mask, prev_category_trace_mask);
}
};

Expand Down Expand Up @@ -186,7 +184,6 @@ BOOST_FIXTURE_TEST_CASE(logging_SeverityLevels, LogSetup)
{
LogInstance().EnableCategory(BCLog::LogFlags::ALL);

LogInstance().SetLogLevel(BCLog::Level::Debug);
LogInstance().SetCategoryLogLevel(/*category_str=*/"net", /*level_str=*/"info");

// Global log level
Expand Down Expand Up @@ -228,7 +225,9 @@ BOOST_FIXTURE_TEST_CASE(logging_Conf, LogSetup)

auto result = init::SetLoggingCategories(args);
BOOST_REQUIRE(result);
BOOST_CHECK_EQUAL(LogInstance().LogLevel(), BCLog::Level::Debug);

BOOST_CHECK_EQUAL(LogInstance().GetCategoryMask(), BCLog::LogFlags::NONE);
BOOST_CHECK_EQUAL(LogInstance().GetCategoryTraceMask(), BCLog::LogFlags::NONE);
}

// All traced categories
Expand All @@ -243,10 +242,8 @@ BOOST_FIXTURE_TEST_CASE(logging_Conf, LogSetup)
auto result = init::SetLoggingCategories(args);
BOOST_REQUIRE(result);

BOOST_CHECK_EQUAL(LogInstance().LogLevel(), BCLog::Level::Trace);

const auto& category_levels{LogInstance().CategoryLevels()};
BOOST_CHECK_EQUAL(category_levels.size(), 0);
BOOST_CHECK_EQUAL(LogInstance().GetCategoryMask(), BCLog::LogFlags::ALL);
BOOST_CHECK_EQUAL(LogInstance().GetCategoryTraceMask(), BCLog::LogFlags::ALL);
}

// Specific traced categories
Expand All @@ -261,22 +258,9 @@ BOOST_FIXTURE_TEST_CASE(logging_Conf, LogSetup)

auto result = init::SetLoggingCategories(args);
BOOST_REQUIRE(result);
BOOST_CHECK_EQUAL(LogInstance().LogLevel(), BCLog::Level::Debug);

const auto& category_levels{LogInstance().CategoryLevels()};
BOOST_CHECK_EQUAL(category_levels.size(), 3);

const auto net_it{category_levels.find(BCLog::LogFlags::NET)};
BOOST_CHECK(net_it != category_levels.end());
BOOST_CHECK_EQUAL(net_it->second, BCLog::Level::Trace);

const auto http_it{category_levels.find(BCLog::LogFlags::HTTP)};
BOOST_CHECK(http_it != category_levels.end());
BOOST_CHECK_EQUAL(http_it->second, BCLog::Level::Trace);

const auto mempool_it{category_levels.find(BCLog::LogFlags::MEMPOOL)};
BOOST_CHECK(mempool_it != category_levels.end());
BOOST_CHECK_EQUAL(mempool_it->second, BCLog::Level::Debug);
BOOST_CHECK_EQUAL(LogInstance().GetCategoryMask(), BCLog::LogFlags::NET | BCLog::LogFlags::HTTP | BCLog::LogFlags::MEMPOOL);
BOOST_CHECK_EQUAL(LogInstance().GetCategoryTraceMask(), BCLog::LogFlags::NET | BCLog::LogFlags::HTTP);
}
}

Expand Down

0 comments on commit 451f2e7

Please sign in to comment.