Merge bitcoin/bitcoin#25614: Severity-based logging, step 2

9580480570 Update debug logging section in the developer notes (Jon Atack)
1abaa31aa3 Update -debug and -debugexclude help docs for severity level logging (Jon Atack)
45f9282162 Create BCLog::Level::Trace log severity level (Jon Atack)
2a8712db4f Unit test coverage for -loglevel configuration option (klementtan)
eb7bee5f84 Create -loglevel configuration option (klementtan)
98a1f9c687 Unit test coverage for log severity levels (klementtan)
9c7507bf76 Create BCLog::Logger::LogLevelsString() helper function (klementtan)
8fe3457dbb Update LogAcceptCategory() and unit tests with log severity levels (klementtan)
c2797cfc60 Add BCLog::Logger::SetLogLevel()/SetCategoryLogLevel() for string inputs (klementtan)
f6c0cc0350 Add BCLog::Logger::m_category_log_levels data member and getter/setter (Jon Atack)
2978b387bf Add BCLog::Logger::m_log_level data member and getter/setter (Jon Atack)
f1379aeca9 Simplify BCLog::Level enum class and LogLevelToStr() function (Jon Atack)

Pull request description:

  This is an updated version of https://github.com/bitcoin/bitcoin/pull/25287 and the next steps in parent PR #25203 implementing, with Klement Tan, user-configurable, per-category severity log levels based on an idea by John Newbery and refined in GitHub discussions by Wladimir Van der Laan and Marco Falke.

  - simplify the `BCLog::Level` enum class and the `LogLevelToStr()` function and add documentation
  - update the logging logic to filter logs by log level both globally and per-category
  - add a hidden `-loglevel` help-debug config option to allow testing setting the global or per-category severity level on startup for logging categories enabled with the `-debug` configuration option or the logging RPC (Klement Tan)
  - add a `trace` log severity level selectable by the user; the plan is for the current debug messages to become trace, LogPrint ones to become debug, and LogPrintf ones to become info, warning, or error

  ```
  $ ./src/bitcoind -help-debug | grep -A10 loglevel
    -loglevel=<level>|<category>:<level>
         Set the global or per-category severity level for logging categories
         enabled with the -debug configuration option or the logging RPC:
         info, debug, trace (default=info); warning and error levels are
         always logged. If <category>:<level> is supplied, the setting
         will override the global one and may be specified multiple times
         to set multiple category-specific levels. <category> can be:
         addrman, bench, blockstorage, cmpctblock, coindb, estimatefee,
         http, i2p, ipc, leveldb, libevent, lock, mempool, mempoolrej,
         net, proxy, prune, qt, rand, reindex, rpc, selectcoins, tor,
         util, validation, walletdb, zmq.
  ```

  See the individual commit messages for details.

ACKs for top commit:
  jonatack:
    One final push per `git range-diff a5d5569 ce3c4c9 9580480` (should be trivial to re-ACK) to ensure this pull changes no default behavior in any way for users or the tests/CI in order to be completely v24 compatible, to update the unit test setup in general, and to update the debug logging section in the developer notes.
  klementtan:
    reACK 9580480570
  1440000bytes:
    reACK 9580480570
  vasild:
    ACK 9580480570
  dunxen:
    reACK 9580480
  brunoerg:
    reACK 9580480570

Tree-SHA512: 476a638e0581f40b5d058a9992691722e8b546471ec85e07cbc990798d1197fbffbd02e1b3d081b4978404e07a428378cdc8e159c0004b81f58be7fb01b7cba0
This commit is contained in:
Andrew Chow
2022-09-01 15:44:02 -04:00
10 changed files with 270 additions and 36 deletions

View File

@@ -5,15 +5,17 @@
#include <fs.h>
#include <logging.h>
#include <util/threadnames.h>
#include <util/string.h>
#include <util/threadnames.h>
#include <util/time.h>
#include <algorithm>
#include <array>
#include <mutex>
#include <optional>
const char * const DEFAULT_DEBUGLOGFILE = "debug.log";
constexpr auto MAX_USER_SETABLE_SEVERITY_LEVEL{BCLog::Level::Info};
BCLog::Logger& LogInstance()
{
@@ -122,6 +124,19 @@ bool BCLog::Logger::WillLogCategory(BCLog::LogFlags category) const
return (m_categories.load(std::memory_order_relaxed) & category) != 0;
}
bool BCLog::Logger::WillLogCategoryLevel(BCLog::LogFlags category, BCLog::Level level) const
{
// Log messages at Warning and Error level unconditionally, so that
// important troubleshooting information doesn't get lost.
if (level >= BCLog::Level::Warning) 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);
}
bool BCLog::Logger::DefaultShrinkDebugFile() const
{
return m_categories == BCLog::NONE;
@@ -135,7 +150,7 @@ struct CLogCategoryDesc {
const CLogCategoryDesc LogCategories[] =
{
{BCLog::NONE, "0"},
{BCLog::NONE, "none"},
{BCLog::NONE, ""},
{BCLog::NET, "net"},
{BCLog::TOR, "tor"},
{BCLog::MEMPOOL, "mempool"},
@@ -184,11 +199,11 @@ bool GetLogCategory(BCLog::LogFlags& flag, const std::string& str)
return false;
}
std::string LogLevelToStr(BCLog::Level level)
std::string BCLog::Logger::LogLevelToStr(BCLog::Level level) const
{
switch (level) {
case BCLog::Level::None:
return "none";
case BCLog::Level::Trace:
return "trace";
case BCLog::Level::Debug:
return "debug";
case BCLog::Level::Info:
@@ -197,6 +212,8 @@ std::string LogLevelToStr(BCLog::Level level)
return "warning";
case BCLog::Level::Error:
return "error";
case BCLog::Level::None:
return "";
}
assert(false);
}
@@ -206,7 +223,7 @@ std::string LogCategoryToStr(BCLog::LogFlags category)
// Each log category string representation should sync with LogCategories
switch (category) {
case BCLog::LogFlags::NONE:
return "none";
return "";
case BCLog::LogFlags::NET:
return "net";
case BCLog::LogFlags::TOR:
@@ -269,6 +286,25 @@ std::string LogCategoryToStr(BCLog::LogFlags category)
assert(false);
}
static std::optional<BCLog::Level> GetLogLevel(const std::string& level_str)
{
if (level_str == "trace") {
return BCLog::Level::Trace;
} else if (level_str == "debug") {
return BCLog::Level::Debug;
} else if (level_str == "info") {
return BCLog::Level::Info;
} else if (level_str == "warning") {
return BCLog::Level::Warning;
} else if (level_str == "error") {
return BCLog::Level::Error;
} else if (level_str == "none") {
return BCLog::Level::None;
} else {
return std::nullopt;
}
}
std::vector<LogCategory> BCLog::Logger::LogCategoriesList() const
{
// Sort log categories by alphabetical order.
@@ -287,6 +323,18 @@ std::vector<LogCategory> BCLog::Logger::LogCategoriesList() const
return ret;
}
/** Log severity levels that can be selected by the user. */
static constexpr std::array<BCLog::Level, 3> LogLevelsList()
{
return {BCLog::Level::Info, BCLog::Level::Debug, BCLog::Level::Trace};
}
std::string BCLog::Logger::LogLevelsString() const
{
const auto& levels = LogLevelsList();
return Join(std::vector<BCLog::Level>{levels.begin(), levels.end()}, ", ", [this](BCLog::Level level) { return LogLevelToStr(level); });
}
std::string BCLog::Logger::LogTimestampStr(const std::string& str)
{
std::string strStamped;
@@ -334,7 +382,7 @@ namespace BCLog {
}
} // namespace BCLog
void BCLog::Logger::LogPrintStr(const std::string& str, const std::string& logging_function, const std::string& source_file, const int source_line, const BCLog::LogFlags category, const BCLog::Level level)
void BCLog::Logger::LogPrintStr(const std::string& str, const std::string& logging_function, const std::string& source_file, int source_line, BCLog::LogFlags category, BCLog::Level level)
{
StdLockGuard scoped_lock(m_cs);
std::string str_prefixed = LogEscapeMessage(str);
@@ -443,3 +491,24 @@ void BCLog::Logger::ShrinkDebugFile()
else if (file != nullptr)
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;
}
bool BCLog::Logger::SetCategoryLogLevel(const std::string& category_str, const std::string& level_str)
{
BCLog::LogFlags flag;
if (!GetLogCategory(flag, category_str)) return false;
const auto level = GetLogLevel(level_str);
if (!level.has_value() || level.value() > MAX_USER_SETABLE_SEVERITY_LEVEL) return false;
StdLockGuard scoped_lock(m_cs);
m_category_log_levels[flag] = level.value();
return true;
}