sikkienl/dash
1
0
Fork 0
mirror of https://github.com/dashpay/dash.git synced 2024-12-25 03:52:49 +01:00
Code Issues Actions 8 Packages Projects Releases Wiki Activity

merge bitcoin#24464: Add severity level to logs

Browse Source
This commit is contained in:
Kittywhiskers Van Gogh 2024-11-17 17:14:18 +00:00
parent d3e837ad22
commit 88592f30a3
No known key found for this signature in database
GPG Key ID: 30CD0C065E5C4AAD
4 changed files with 300 additions and 26 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

141
src/logging.cpp
View File

@ -188,7 +188,7 @@ const CLogCategoryDesc LogCategories[] =
bool GetLogCategory(BCLog::LogFlags& flag, const std::string& str) bool GetLogCategory(BCLog::LogFlags& flag, const std::string& str)
{ {
if (str == "") { if (str.empty()) {
flag = BCLog::ALL; flag = BCLog::ALL;
return true; return true;
} }
@ -201,6 +201,123 @@ bool GetLogCategory(BCLog::LogFlags& flag, const std::string& str)
return false; return false;
} }
std::string LogLevelToStr(BCLog::Level level)
{
switch (level) {
case BCLog::Level::None:
return "none";
case BCLog::Level::Debug:
return "debug";
case BCLog::Level::Info:
return "info";
case BCLog::Level::Warning:
return "warning";
case BCLog::Level::Error:
return "error";
}
assert(false);
}
std::string LogCategoryToStr(BCLog::LogFlags category)
{
// Each log category string representation should sync with LogCategories
switch (category) {
case BCLog::LogFlags::NONE:
return "none";
case BCLog::LogFlags::NET:
return "net";
case BCLog::LogFlags::TOR:
return "tor";
case BCLog::LogFlags::MEMPOOL:
return "mempool";
case BCLog::LogFlags::HTTP:
return "http";
case BCLog::LogFlags::BENCHMARK:
return "bench";
case BCLog::LogFlags::ZMQ:
return "zmq";
case BCLog::LogFlags::WALLETDB:
return "walletdb";
case BCLog::LogFlags::RPC:
return "rpc";
case BCLog::LogFlags::ESTIMATEFEE:
return "estimatefee";
case BCLog::LogFlags::ADDRMAN:
return "addrman";
case BCLog::LogFlags::SELECTCOINS:
return "selectcoins";
case BCLog::LogFlags::REINDEX:
return "reindex";
case BCLog::LogFlags::CMPCTBLOCK:
return "cmpctblock";
case BCLog::LogFlags::RANDOM:
return "rand";
case BCLog::LogFlags::PRUNE:
return "prune";
case BCLog::LogFlags::PROXY:
return "proxy";
case BCLog::LogFlags::MEMPOOLREJ:
return "mempoolrej";
case BCLog::LogFlags::LIBEVENT:
return "libevent";
case BCLog::LogFlags::COINDB:
return "coindb";
case BCLog::LogFlags::QT:
return "qt";
case BCLog::LogFlags::LEVELDB:
return "leveldb";
case BCLog::LogFlags::VALIDATION:
return "validation";
case BCLog::LogFlags::I2P:
return "i2p";
case BCLog::LogFlags::IPC:
return "ipc";
#ifdef DEBUG_LOCKCONTENTION
case BCLog::LogFlags::LOCK:
return "lock";
#endif
case BCLog::LogFlags::BLOCKSTORE:
return "blockstorage";
case BCLog::LogFlags::TXRECONCILIATION:
return "txreconciliation";
/* Start Dash */
case BCLog::LogFlags::CHAINLOCKS:
return "chainlocks";
case BCLog::LogFlags::GOBJECT:
return "gobject";
case BCLog::LogFlags::INSTANTSEND:
return "instantsend";
case BCLog::LogFlags::LLMQ:
return "llmq";
case BCLog::LogFlags::LLMQ_DKG:
return "llmq-dkg";
case BCLog::LogFlags::LLMQ_SIGS:
return "llmq-sigs";
case BCLog::LogFlags::MNPAYMENTS:
return "mnpayments";
case BCLog::LogFlags::MNSYNC:
return "mnsync";
case BCLog::LogFlags::COINJOIN:
return "coinjoin";
case BCLog::LogFlags::SPORK:
return "spork";
case BCLog::LogFlags::NETCONN:
return "netconn";
case BCLog::LogFlags::CREDITPOOL:
return "creditpool";
case BCLog::LogFlags::EHF:
return "ehf";
case BCLog::LogFlags::DASH:
return "dash";
case BCLog::LogFlags::NET_NETCONN:
return "net|netconn";
/* End Dash */
case BCLog::LogFlags::ALL:
return "all";
}
assert(false);
}
std::vector<LogCategory> BCLog::Logger::LogCategoriesList(bool enabled_only) const std::vector<LogCategory> BCLog::Logger::LogCategoriesList(bool enabled_only) const
{ {
// Sort log categories by alphabetical order. // Sort log categories by alphabetical order.
@ -268,11 +385,31 @@ namespace BCLog {
} }
} // 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) 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)
{ {
StdLockGuard scoped_lock(m_cs); StdLockGuard scoped_lock(m_cs);
std::string str_prefixed = LogEscapeMessage(str); std::string str_prefixed = LogEscapeMessage(str);
if ((category != LogFlags::NONE || level != Level::None) && m_started_new_line) {
std::string s{"["};
if (category != LogFlags::NONE) {
s += LogCategoryToStr(category);
}
if (category != LogFlags::NONE && level != Level::None) {
// Only add separator if both flag and level are not NONE
s += ":";
}
if (level != Level::None) {
s += LogLevelToStr(level);
}
s += "] ";
str_prefixed.insert(0, s);
}
if (m_log_sourcelocations && m_started_new_line) { if (m_log_sourcelocations && m_started_new_line) {
str_prefixed.insert(0, "[" + RemovePrefix(source_file, "./") + ":" + ToString(source_line) + "] [" + logging_function + "] "); str_prefixed.insert(0, "[" + RemovePrefix(source_file, "./") + ":" + ToString(source_line) + "] [" + logging_function + "] ");
} }

35
src/logging.h
View File

@ -91,6 +91,13 @@ namespace BCLog {
ALL = ~(uint64_t)0, ALL = ~(uint64_t)0,
}; };
enum class Level {
Debug = 0,
None = 1,
Info = 2,
Warning = 3,
Error = 4,
};
class Logger class Logger
{ {
@ -130,7 +137,7 @@ namespace BCLog {
std::atomic<bool> m_reopen_file{false}; std::atomic<bool> m_reopen_file{false};
/** Send a string to the log output */ /** Send a string to the log output */
void LogPrintStr(const std::string& str, const std::string& logging_function, const std::string& source_file, const int source_line); void 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);
/** Returns whether logs will be written to any output */ /** Returns whether logs will be written to any output */
bool Enabled() const bool Enabled() const
@ -211,7 +218,7 @@ std::string SafeStringFormat(const std::string& fmt, const Args&... args)
// peer can fill up a user's disk with debug.log entries. // peer can fill up a user's disk with debug.log entries.
template <typename... Args> template <typename... Args>
static inline void LogPrintf_(const std::string& logging_function, const std::string& source_file, const int source_line, const char* fmt, const Args&... args) static inline void LogPrintf_(const std::string& logging_function, const std::string& source_file, const int source_line, const BCLog::LogFlags flag, const BCLog::Level level, const char* fmt, const Args&... args)
{ {
if (LogInstance().Enabled()) { if (LogInstance().Enabled()) {
std::string log_msg; std::string log_msg;
@ -221,19 +228,29 @@ static inline void LogPrintf_(const std::string& logging_function, const std::st
/* Original format string will have newline so don't add one here */ /* Original format string will have newline so don't add one here */
log_msg = "Error \"" + std::string(fmterr.what()) + "\" while formatting log message: " + fmt; log_msg = "Error \"" + std::string(fmterr.what()) + "\" while formatting log message: " + fmt;
} }
LogInstance().LogPrintStr(log_msg, logging_function, source_file, source_line); LogInstance().LogPrintStr(log_msg, logging_function, source_file, source_line, flag, level);
} }
} }
#define LogPrintf(...) LogPrintf_(__func__, __FILE__, __LINE__, __VA_ARGS__)
#define LogPrintLevel_(category, level, ...) LogPrintf_(__func__, __FILE__, __LINE__, category, level, __VA_ARGS__)
#define LogPrintf(...) LogPrintLevel_(BCLog::LogFlags::NONE, BCLog::Level::None, __VA_ARGS__)
// Use a macro instead of a function for conditional logging to prevent // Use a macro instead of a function for conditional logging to prevent
// evaluating arguments when logging for the category is not enabled. // evaluating arguments when logging for the category is not enabled.
#define LogPrint(category, ...) \ #define LogPrint(category, ...) \
do { \ do { \
if (LogAcceptCategory((category))) { \ if (LogAcceptCategory((category))) { \
LogPrintf(__VA_ARGS__); \ LogPrintLevel_(category, BCLog::Level::None, __VA_ARGS__); \
} \ } \
} while (0)
#define LogPrintLevel(level, category, ...) \
do { \
if (LogAcceptCategory((category))) { \
LogPrintLevel_(category, level, __VA_ARGS__); \
} \
} while (0) } while (0)
#endif // BITCOIN_LOGGING_H #endif // BITCOIN_LOGGING_H

30
src/net.cpp
View File

@ -481,7 +481,7 @@ static CAddress GetBindAddress(const Sock& sock)
if (!sock.GetSockName((struct sockaddr*)&sockaddr_bind, &sockaddr_bind_len)) { if (!sock.GetSockName((struct sockaddr*)&sockaddr_bind, &sockaddr_bind_len)) {
addr_bind.SetSockAddr((const struct sockaddr*)&sockaddr_bind); addr_bind.SetSockAddr((const struct sockaddr*)&sockaddr_bind);
} else { } else {
LogPrint(BCLog::NET, "Warning: getsockname failed\n"); LogPrintLevel(BCLog::Level::Warning, BCLog::NET, "getsockname failed\n");
} }
} }
return addr_bind; return addr_bind;
@ -509,14 +509,14 @@ CNode* CConnman::ConnectNode(CAddress addrConnect, const char *pszDest, bool fCo
/// debug print /// debug print
if (fLogIPs) { if (fLogIPs) {
LogPrint(BCLog::NET, "trying %s connection %s lastseen=%.1fhrs\n", LogPrintLevel(BCLog::Level::Debug, BCLog::NET, "trying %s connection %s lastseen=%.1fhrs\n",
use_v2transport ? "v2" : "v1", use_v2transport ? "v2" : "v1",
pszDest ? pszDest : addrConnect.ToStringAddrPort(), pszDest ? pszDest : addrConnect.ToStringAddrPort(),
pszDest ? 0.0 : (double)(GetAdjustedTime() - addrConnect.nTime)/3600.0); pszDest ? 0.0 : (double)(GetAdjustedTime() - addrConnect.nTime)/3600.0);
} else { } else {
LogPrint(BCLog::NET, "trying %s connection lastseen=%.1fhrs\n", LogPrintLevel(BCLog::Level::Debug, BCLog::NET, "trying %s connection lastseen=%.1fhrs\n",
use_v2transport ? "v2" : "v1", use_v2transport ? "v2" : "v1",
pszDest ? 0.0 : (double)(GetAdjustedTime() - addrConnect.nTime)/3600.0); pszDest ? 0.0 : (double)(GetAdjustedTime() - addrConnect.nTime)/3600.0);
} }
// Resolve // Resolve
@ -1963,7 +1963,7 @@ void CConnman::AcceptConnection(const ListenSocket& hListenSocket, CMasternodeSy
} }
if (!addr.SetSockAddr((const struct sockaddr*)&sockaddr)) { if (!addr.SetSockAddr((const struct sockaddr*)&sockaddr)) {
LogPrintf("Warning: Unknown socket family\n"); LogPrintLevel(BCLog::Level::Warning, BCLog::NET, "Unknown socket family\n");
} else { } else {
addr = CAddress{MaybeFlipIPv6toCJDNS(addr), NODE_NONE}; addr = CAddress{MaybeFlipIPv6toCJDNS(addr), NODE_NONE};
} }
@ -4068,14 +4068,14 @@ bool CConnman::BindListenPort(const CService& addrBind, bilingual_str& strError,
if (!addrBind.GetSockAddr((struct sockaddr*)&sockaddr, &len)) if (!addrBind.GetSockAddr((struct sockaddr*)&sockaddr, &len))
{ {
strError = strprintf(Untranslated("Error: Bind address family for %s not supported"), addrBind.ToStringAddrPort()); strError = strprintf(Untranslated("Error: Bind address family for %s not supported"), addrBind.ToStringAddrPort());
LogPrintf("%s\n", strError.original); LogPrintLevel(BCLog::Level::Error, BCLog::NET, "%s\n", strError.original);
return false; return false;
} }
std::unique_ptr<Sock> sock = CreateSock(addrBind); std::unique_ptr<Sock> sock = CreateSock(addrBind);
if (!sock) { if (!sock) {
strError = strprintf(Untranslated("Error: Couldn't open socket for incoming connections (socket returned error %s)"), NetworkErrorString(WSAGetLastError())); strError = strprintf(Untranslated("Couldn't open socket for incoming connections (socket returned error %s)"), NetworkErrorString(WSAGetLastError()));
LogPrintf("%s\n", strError.original); LogPrintLevel(BCLog::Level::Error, BCLog::NET, "%s\n", strError.original);
return false; return false;
} }
@ -4110,7 +4110,7 @@ bool CConnman::BindListenPort(const CService& addrBind, bilingual_str& strError,
strError = strprintf(_("Unable to bind to %s on this computer. %s is probably already running."), addrBind.ToStringAddrPort(), PACKAGE_NAME); strError = strprintf(_("Unable to bind to %s on this computer. %s is probably already running."), addrBind.ToStringAddrPort(), PACKAGE_NAME);
else else
strError = strprintf(_("Unable to bind to %s on this computer (bind returned error %s)"), addrBind.ToStringAddrPort(), NetworkErrorString(nErr)); strError = strprintf(_("Unable to bind to %s on this computer (bind returned error %s)"), addrBind.ToStringAddrPort(), NetworkErrorString(nErr));
LogPrintf("%s\n", strError.original); LogPrintLevel(BCLog::Level::Error, BCLog::NET, "%s\n", strError.original);
return false; return false;
} }
LogPrintf("Bound to %s\n", addrBind.ToStringAddrPort()); LogPrintf("Bound to %s\n", addrBind.ToStringAddrPort());
@ -4118,8 +4118,8 @@ bool CConnman::BindListenPort(const CService& addrBind, bilingual_str& strError,
// Listen for incoming connections // Listen for incoming connections
if (sock->Listen(SOMAXCONN) == SOCKET_ERROR) if (sock->Listen(SOMAXCONN) == SOCKET_ERROR)
{ {
strError = strprintf(_("Error: Listening for incoming connections failed (listen returned error %s)"), NetworkErrorString(WSAGetLastError())); strError = strprintf(_("Listening for incoming connections failed (listen returned error %s)"), NetworkErrorString(WSAGetLastError()));
LogPrintf("%s\n", strError.original); LogPrintLevel(BCLog::Level::Error, BCLog::NET, "%s\n", strError.original);
return false; return false;
} }

120
src/test/logging_tests.cpp
View File

@ -5,13 +5,55 @@
#include <logging.h> #include <logging.h>
#include <logging/timer.h> #include <logging/timer.h>
#include <test/util/setup_common.h> #include <test/util/setup_common.h>
#include <util/string.h>
#include <chrono> #include <chrono>
#include <fstream>
#include <iostream>
#include <utility>
#include <vector>
#include <boost/test/unit_test.hpp> #include <boost/test/unit_test.hpp>
BOOST_FIXTURE_TEST_SUITE(logging_tests, BasicTestingSetup) BOOST_FIXTURE_TEST_SUITE(logging_tests, BasicTestingSetup)
struct LogSetup : public BasicTestingSetup {
fs::path prev_log_path;
fs::path tmp_log_path;
bool prev_reopen_file;
bool prev_print_to_file;
bool prev_log_timestamps;
bool prev_log_threadnames;
bool prev_log_sourcelocations;
LogSetup() : prev_log_path{LogInstance().m_file_path},
tmp_log_path{m_args.GetDataDirBase() / "tmp_debug.log"},
prev_reopen_file{LogInstance().m_reopen_file},
prev_print_to_file{LogInstance().m_print_to_file},
prev_log_timestamps{LogInstance().m_log_timestamps},
prev_log_threadnames{LogInstance().m_log_threadnames},
prev_log_sourcelocations{LogInstance().m_log_sourcelocations}
{
LogInstance().m_file_path = tmp_log_path;
LogInstance().m_reopen_file = true;
LogInstance().m_print_to_file = true;
LogInstance().m_log_timestamps = false;
LogInstance().m_log_threadnames = false;
LogInstance().m_log_sourcelocations = true;
}
~LogSetup()
{
LogInstance().m_file_path = prev_log_path;
LogPrintf("Sentinel log to reopen log file\n");
LogInstance().m_print_to_file = prev_print_to_file;
LogInstance().m_reopen_file = prev_reopen_file;
LogInstance().m_log_timestamps = prev_log_timestamps;
LogInstance().m_log_threadnames = prev_log_threadnames;
LogInstance().m_log_sourcelocations = prev_log_sourcelocations;
}
};
BOOST_AUTO_TEST_CASE(logging_timer) BOOST_AUTO_TEST_CASE(logging_timer)
{ {
SetMockTime(1); SetMockTime(1);
@ -30,4 +72,82 @@ BOOST_AUTO_TEST_CASE(logging_timer)
BOOST_CHECK_EQUAL(sec_timer.LogMsg("test secs"), "tests: test secs (1.00s)"); BOOST_CHECK_EQUAL(sec_timer.LogMsg("test secs"), "tests: test secs (1.00s)");
} }
BOOST_FIXTURE_TEST_CASE(logging_LogPrintf_, LogSetup)
{
LogPrintf_("fn1", "src1", 1, BCLog::LogFlags::NET, BCLog::Level::Debug, "foo1: %s", "bar1\n");
LogPrintf_("fn2", "src2", 2, BCLog::LogFlags::NET, BCLog::Level::None, "foo2: %s", "bar2\n");
LogPrintf_("fn3", "src3", 3, BCLog::LogFlags::NONE, BCLog::Level::Debug, "foo3: %s", "bar3\n");
LogPrintf_("fn4", "src4", 4, BCLog::LogFlags::NONE, BCLog::Level::None, "foo4: %s", "bar4\n");
std::ifstream file{tmp_log_path};
std::vector<std::string> log_lines;
for (std::string log; std::getline(file, log);) {
log_lines.push_back(log);
}
std::vector<std::string> expected = {
"[src1:1] [fn1] [net:debug] foo1: bar1",
"[src2:2] [fn2] [net] foo2: bar2",
"[src3:3] [fn3] [debug] foo3: bar3",
"[src4:4] [fn4] foo4: bar4",
};
BOOST_CHECK_EQUAL_COLLECTIONS(log_lines.begin(), log_lines.end(), expected.begin(), expected.end());
}
BOOST_FIXTURE_TEST_CASE(logging_LogPrintMacros, LogSetup)
{
// Prevent tests from failing when the line number of the following log calls changes.
LogInstance().m_log_sourcelocations = false;
LogPrintf("foo5: %s\n", "bar5");
LogPrint(BCLog::NET, "foo6: %s\n", "bar6");
LogPrintLevel(BCLog::Level::Debug, BCLog::NET, "foo7: %s\n", "bar7");
LogPrintLevel(BCLog::Level::Info, BCLog::NET, "foo8: %s\n", "bar8");
LogPrintLevel(BCLog::Level::Warning, BCLog::NET, "foo9: %s\n", "bar9");
LogPrintLevel(BCLog::Level::Error, BCLog::NET, "foo10: %s\n", "bar10");
std::ifstream file{tmp_log_path};
std::vector<std::string> log_lines;
for (std::string log; std::getline(file, log);) {
log_lines.push_back(log);
}
std::vector<std::string> expected = {
"foo5: bar5",
"[net] foo6: bar6",
"[net:debug] foo7: bar7",
"[net:info] foo8: bar8",
"[net:warning] foo9: bar9",
"[net:error] foo10: bar10"};
BOOST_CHECK_EQUAL_COLLECTIONS(log_lines.begin(), log_lines.end(), expected.begin(), expected.end());
}
BOOST_FIXTURE_TEST_CASE(logging_LogPrintMacros_CategoryName, LogSetup)
{
// Prevent tests from failing when the line number of the following log calls changes.
LogInstance().m_log_sourcelocations = false;
LogInstance().EnableCategory(BCLog::LogFlags::ALL);
const auto concated_categery_names = LogInstance().LogCategoriesString();
std::vector<std::pair<BCLog::LogFlags, std::string>> expected_category_names;
const auto category_names = SplitString(concated_categery_names, ',');
for (const auto& category_name : category_names) {
BCLog::LogFlags category = BCLog::NONE;
const auto trimmed_category_name = TrimString(category_name);
BOOST_TEST(GetLogCategory(category, trimmed_category_name));
expected_category_names.emplace_back(category, trimmed_category_name);
}
std::vector<std::string> expected;
for (const auto& [category, name] : expected_category_names) {
LogPrint(category, "foo: %s\n", "bar");
std::string expected_log = "[";
expected_log += name;
expected_log += "] foo: bar";
expected.push_back(expected_log);
}
std::ifstream file{tmp_log_path};
std::vector<std::string> log_lines;
for (std::string log; std::getline(file, log);) {
log_lines.push_back(log);
}
BOOST_CHECK_EQUAL_COLLECTIONS(log_lines.begin(), log_lines.end(), expected.begin(), expected.end());
}
BOOST_AUTO_TEST_SUITE_END() BOOST_AUTO_TEST_SUITE_END()