Merge bitcoin/bitcoin#25202: log: Use severity-based logging for leveldb/libevent messages, reverse LogPrintLevel order

c4e77177276ea2b79c4675cb2678ee2cc757b743 refactor: Change LogPrintLevel order to category, severity (laanwj)
ce920713bf0810614c2c0c994511b50d4f660bce leveldb: Log messages from leveldb with category and debug level (laanwj)
18ec120bb9e1fc9d27d2419da4c580bd3cde7e86 http: Use severity-based logging for messages from libevent (laanwj)
bd971bffb02c7b06aac9a479f7e5ed8f71de2bec logging: Unconditionally log levels >= WARN (laanwj)

Pull request description:

  Log messages from leveldb and libevent libraries in the severity+level based log format introduced in bitcoin/bitcoin#24464.

  Example of messages before:
  ```
  2022-05-24T18:11:57Z [libevent] libevent: event_add: event: 0x55da963fcc10 (fd 10), EV_READ    call 0x7f1c7a254620
  2022-05-24T18:11:57Z [libevent] libevent: Epoll ADD(1) on fd 10 okay. Old events were 0; read change was 1 (add); write change was 0 (none); close change was 0 (none)
  2022-05-24T18:12:08Z leveldb: Generated table #609127@1: 6445 keys, 312916 bytes
  2022-05-24T18:12:08Z leveldb: Generated table #609128@1: 5607 keys, 268548 bytes
  2022-05-24T18:12:08Z leveldb: Generated table #609129@1: 189 keys, 9384 bytes
  2022-05-24T18:12:08Z leveldb: Generated table #609130@1: 293 keys, 13818 bytes
  ```

  Example of messages after:
  ```
  2022-05-24T17:59:52Z [libevent:debug] event_add: event: 0x5652f44dac10 (fd 10), EV_READ    call 0x7f210f2e6620
  2022-05-24T17:59:52Z [libevent:debug] Epoll ADD(1) on fd 10 okay. Old events were 0; read change was 1 (add); write change was 0 (none); close change was 0 (none)
  2022-05-24T17:59:53Z [leveldb:debug] Recovering log #1072
  2022-05-24T17:59:53Z [leveldb:debug] Level-0 table #1082: started
  2022-05-24T17:59:53Z [leveldb:debug] Level-0 table #1082: 193 bytes OK
  2022-05-24T17:59:53Z [leveldb:debug] Delete type=3 #1070
  2022-05-24T17:59:53Z [leveldb:debug] Delete type=0 #1072
  ```

  The first commit changes it so that messages with level Warning and Error are always logged independent of the `-debug` setting. I think this is useful to make sure warnings and errors, which tend to be important, are not lost. In the future this should be made more configurable.

  Last commit changes LogPrintLevel argument order to category, severity: This is more consistent with the other functions, as well as with the logging output itself. If we want to make this change, we should do it before it's all over the place.

ACKs for top commit:
  jonatack:
    Tested ACK c4e77177276ea2b79c4675cb2678ee2cc757b743

Tree-SHA512: ea48a1517f8c1b23760e59933bbd64ebf09c32eb947e31b8c2696b4630ac1f4303b126720183e2de052bcede3a17e475bbf3fbb6378a12b0fa8f3582d610930d

7 files changed, 42 insertions, 25 deletions

diff --git a/src/dbwrapper.cpp b/src/dbwrapper.cpp
index 50a601c684..a2f1f32780 100644
--- a/src/dbwrapper.cpp
+++ b/src/dbwrapper.cpp
@@ -19,7 +19,7 @@ public:
     // This code is adapted from posix_logger.h, which is why it is using vsprintf.
     // Please do not do this in normal code
     void Logv(const char * format, va_list ap) override {
-            if (!LogAcceptCategory(BCLog::LEVELDB)) {
+            if (!LogAcceptCategory(BCLog::LEVELDB, BCLog::Level::Debug)) {
                 return;
             }
             char buffer[500];
@@ -63,7 +63,7 @@ public:
 
                 assert(p <= limit);
                 base[std::min(bufsize - 1, (int)(p - base))] = '\0';
-                LogPrintf("leveldb: %s", base);  /* Continued */
+                LogPrintLevel(BCLog::LEVELDB, BCLog::Level::Debug, "%s", base);  /* Continued */
                 if (base != buffer) {
                     delete[] base;
                 }
@@ -186,7 +186,7 @@ CDBWrapper::~CDBWrapper()
 
 bool CDBWrapper::WriteBatch(CDBBatch& batch, bool fSync)
 {
-    const bool log_memory = LogAcceptCategory(BCLog::LEVELDB);
+    const bool log_memory = LogAcceptCategory(BCLog::LEVELDB, BCLog::Level::Debug);
     double mem_before = 0;
     if (log_memory) {
         mem_before = DynamicMemoryUsage() / 1024.0 / 1024;
diff --git a/src/httpserver.cpp b/src/httpserver.cpp
index b9a1fc672a..44937dc523 100644
--- a/src/httpserver.cpp
+++ b/src/httpserver.cpp
@@ -344,10 +344,22 @@ static void HTTPWorkQueueRun(WorkQueue<HTTPClosure>* queue, int worker_num)
 /** libevent event log callback */
 static void libevent_log_cb(int severity, const char *msg)
 {
-    if (severity >= EVENT_LOG_WARN) // Log warn messages and higher without debug category
-        LogPrintf("libevent: %s\n", msg);
-    else
-        LogPrint(BCLog::LIBEVENT, "libevent: %s\n", msg);
+    BCLog::Level level;
+    switch (severity) {
+    case EVENT_LOG_DEBUG:
+        level = BCLog::Level::Debug;
+        break;
+    case EVENT_LOG_MSG:
+        level = BCLog::Level::Info;
+        break;
+    case EVENT_LOG_WARN:
+        level = BCLog::Level::Warning;
+        break;
+    default: // EVENT_LOG_ERR and others are mapped to error
+        level = BCLog::Level::Error;
+        break;
+    }
+    LogPrintLevel(BCLog::LIBEVENT, level, "%s\n", msg);
 }
 
 bool InitHTTPServer()
diff --git a/src/logging.h b/src/logging.h
index 421c3395c2..8a896b6b33 100644
--- a/src/logging.h
+++ b/src/logging.h
@@ -166,9 +166,14 @@ namespace BCLog {
 
 BCLog::Logger& LogInstance();
 
-/** Return true if log accepts specified category */
-static inline bool LogAcceptCategory(BCLog::LogFlags category)
+/** Return true if log accepts specified category, at the specified level. */
+static inline bool LogAcceptCategory(BCLog::LogFlags category, BCLog::Level level)
 {
+    // Log messages at Warning and Error level unconditionally, so that
+    // important troubleshooting information doesn't get lost.
+    if (level >= BCLog::Level::Warning) {
+        return true;
+    }
     return LogInstance().WillLogCategory(category);
 }
 
@@ -203,14 +208,14 @@ static inline void LogPrintf_(const std::string& logging_function, const std::st
 // evaluating arguments when logging for the category is not enabled.
 #define LogPrint(category, ...)                                        \
     do {                                                               \
-        if (LogAcceptCategory((category))) {                           \
+        if (LogAcceptCategory((category), BCLog::Level::Debug)) {      \
             LogPrintLevel_(category, BCLog::Level::None, __VA_ARGS__); \
         }                                                              \
     } while (0)
 
-#define LogPrintLevel(level, category, ...)               \
+#define LogPrintLevel(category, level, ...)               \
     do {                                                  \
-        if (LogAcceptCategory((category))) {              \
+        if (LogAcceptCategory((category), (level))) {     \
             LogPrintLevel_(category, level, __VA_ARGS__); \
         }                                                 \
     } while (0)
diff --git a/src/net.cpp b/src/net.cpp
index 918249c813..a28937f561 100644
--- a/src/net.cpp
+++ b/src/net.cpp
@@ -430,7 +430,7 @@ static CAddress GetBindAddress(SOCKET sock)
         if (!getsockname(sock, (struct sockaddr*)&sockaddr_bind, &sockaddr_bind_len)) {
             addr_bind.SetSockAddr((const struct sockaddr*)&sockaddr_bind);
         } else {
-            LogPrintLevel(BCLog::Level::Warning, BCLog::NET, "getsockname failed\n");
+            LogPrintLevel(BCLog::NET, BCLog::Level::Warning, "getsockname failed\n");
         }
     }
     return addr_bind;
@@ -454,7 +454,7 @@ CNode* CConnman::ConnectNode(CAddress addrConnect, const char *pszDest, bool fCo
     }
 
     /// debug print
-    LogPrintLevel(BCLog::Level::Debug, BCLog::NET, "trying connection %s lastseen=%.1fhrs\n",
+    LogPrintLevel(BCLog::NET, BCLog::Level::Debug, "trying connection %s lastseen=%.1fhrs\n",
                   pszDest ? pszDest : addrConnect.ToString(),
                   pszDest ? 0.0 : (double)(GetAdjustedTime() - addrConnect.nTime) / 3600.0);
 
@@ -1140,7 +1140,7 @@ void CConnman::AcceptConnection(const ListenSocket& hListenSocket) {
     }
 
     if (!addr.SetSockAddr((const struct sockaddr*)&sockaddr)) {
-        LogPrintLevel(BCLog::Level::Warning, BCLog::NET, "Unknown socket family\n");
+        LogPrintLevel(BCLog::NET, BCLog::Level::Warning, "Unknown socket family\n");
     } else {
         addr = CAddress{MaybeFlipIPv6toCJDNS(addr), NODE_NONE};
     }
@@ -2398,14 +2398,14 @@ bool CConnman::BindListenPort(const CService& addrBind, bilingual_str& strError,
     if (!addrBind.GetSockAddr((struct sockaddr*)&sockaddr, &len))
     {
         strError = strprintf(Untranslated("Bind address family for %s not supported"), addrBind.ToString());
-        LogPrintLevel(BCLog::Level::Error, BCLog::NET, "%s\n", strError.original);
+        LogPrintLevel(BCLog::NET, BCLog::Level::Error, "%s\n", strError.original);
         return false;
     }
 
     std::unique_ptr<Sock> sock = CreateSock(addrBind);
     if (!sock) {
         strError = strprintf(Untranslated("Couldn't open socket for incoming connections (socket returned error %s)"), NetworkErrorString(WSAGetLastError()));
-        LogPrintLevel(BCLog::Level::Error, BCLog::NET, "%s\n", strError.original);
+        LogPrintLevel(BCLog::NET, BCLog::Level::Error, "%s\n", strError.original);
         return false;
     }
 
@@ -2441,7 +2441,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.ToString(), PACKAGE_NAME);
         else
             strError = strprintf(_("Unable to bind to %s on this computer (bind returned error %s)"), addrBind.ToString(), NetworkErrorString(nErr));
-        LogPrintLevel(BCLog::Level::Error, BCLog::NET, "%s\n", strError.original);
+        LogPrintLevel(BCLog::NET, BCLog::Level::Error, "%s\n", strError.original);
         return false;
     }
     LogPrintf("Bound to %s\n", addrBind.ToString());
@@ -2450,7 +2450,7 @@ bool CConnman::BindListenPort(const CService& addrBind, bilingual_str& strError,
     if (listen(sock->Get(), SOMAXCONN) == SOCKET_ERROR)
     {
         strError = strprintf(_("Listening for incoming connections failed (listen returned error %s)"), NetworkErrorString(WSAGetLastError()));
-        LogPrintLevel(BCLog::Level::Error, BCLog::NET, "%s\n", strError.original);
+        LogPrintLevel(BCLog::NET, BCLog::Level::Error, "%s\n", strError.original);
         return false;
     }
 
diff --git a/src/test/logging_tests.cpp b/src/test/logging_tests.cpp
index 1f09a07987..3f6a605945 100644
--- a/src/test/logging_tests.cpp
+++ b/src/test/logging_tests.cpp
@@ -99,10 +99,10 @@ BOOST_FIXTURE_TEST_CASE(logging_LogPrintMacros, LogSetup)
 
     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");
+    LogPrintLevel(BCLog::NET, BCLog::Level::Debug, "foo7: %s\n", "bar7");
+    LogPrintLevel(BCLog::NET, BCLog::Level::Info, "foo8: %s\n", "bar8");
+    LogPrintLevel(BCLog::NET, BCLog::Level::Warning, "foo9: %s\n", "bar9");
+    LogPrintLevel(BCLog::NET, BCLog::Level::Error, "foo10: %s\n", "bar10");
     std::ifstream file{tmp_log_path};
     std::vector<std::string> log_lines;
     for (std::string log; std::getline(file, log);) {
diff --git a/src/timedata.cpp b/src/timedata.cpp
index 06659871e5..7faf22aba0 100644
--- a/src/timedata.cpp
+++ b/src/timedata.cpp
@@ -99,7 +99,7 @@ void AddTimeData(const CNetAddr& ip, int64_t nOffsetSample)
             }
         }
 
-        if (LogAcceptCategory(BCLog::NET)) {
+        if (LogAcceptCategory(BCLog::NET, BCLog::Level::Debug)) {
             std::string log_message{"time data samples: "};
             for (const int64_t n : vSorted) {
                 log_message += strprintf("%+d  ", n);
diff --git a/src/wallet/coinselection.cpp b/src/wallet/coinselection.cpp
index e710787a26..07df8d9fc8 100644
--- a/src/wallet/coinselection.cpp
+++ b/src/wallet/coinselection.cpp
@@ -307,7 +307,7 @@ std::optional<SelectionResult> KnapsackSolver(std::vector<OutputGroup>& groups,
             }
         }
 
-        if (LogAcceptCategory(BCLog::SELECTCOINS)) {
+        if (LogAcceptCategory(BCLog::SELECTCOINS, BCLog::Level::Debug)) {
             std::string log_message{"Coin selection best subset: "};
             for (unsigned int i = 0; i < applicable_groups.size(); i++) {
                 if (vfBest[i]) {