Merge bitcoin/bitcoin#30889: log: Use ConstevalFormatString

facbcd4 log: Use ConstevalFormatString (MarcoFalke)
fae9b60 test: Use LogPrintStr to test m_log_sourcelocations (MarcoFalke)
fa39b1c doc: move-only logging warning (MarcoFalke)

Pull request description:

  This changes all logging (including the wallet logging) to produce a
  `ConstevalFormatString` at compile time, so that the format string can be
  validated at compile-time.

  I tested with `clang` and found that the compiler will use less than 1% more of time and memory.

  When an error is found, the compile-time error depends on the compiler, but it may look similar to:

  ```
  src/util/string.h: In function ‘int main(int, char**)’:
  src/bitcoind.cpp:265:5:   in ‘constexpr’ expansion of ‘util::ConstevalFormatString<1>(((const char*)"Hi %s %s"))’
  src/util/string.h:38:98:   in ‘constexpr’ expansion of ‘util::ConstevalFormatString<1>::Detail_CheckNumFormatSpecifiers(std::basic_string_view<char>(((const char*)((util::ConstevalFormatString<1>*)this)->util::ConstevalFormatString<1>::fmt)))’
  src/util/string.h:78:34: error: expression ‘<throw-expression>’ is not a constant expression
     78 |         if (num_params != count) throw "Format specifier count must match the argument count!";
        |                                  ^~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
  ```

  This refactor does not change behavior of the compiled executables.

ACKs for top commit:
  hodlinator:
    re-ACK facbcd4
  l0rinc:
    ACK facbcd4
  ryanofsky:
    Code review ACK facbcd4
  pablomartin4btc:
    re-ACK facbcd4
  stickies-v:
    Approach ACK and code LGTM facbcd4 modulo a `tinyformat::format_error` concern.

Tree-SHA512: 852f74d360897020f0d0f6e5064edc5e7f7dacc2bec1d5feff22c634a2fcd2eb535aa75be0b7191d9053728be6108484c737154b02d68ad3186a2e5544ba0db8

Author: fanquake

src/logging.cpp

@@ -1,5 +1,5 @@
 // Copyright (c) 2009-2010 Satoshi Nakamoto
-// Copyright (c) 2009-2022 The Bitcoin Core developers
+// Copyright (c) 2009-present The Bitcoin Core developers
 // Distributed under the MIT software license, see the accompanying
 // file COPYING or http://www.opensource.org/licenses/mit-license.php.
 
@@ -103,7 +103,6 @@ void BCLog::Logger::DisconnectTestLogger()
     m_cur_buffer_memusage = 0;
     m_buffer_lines_discarded = 0;
     m_msgs_before_open.clear();
-
 }
 
 void BCLog::Logger::DisableLogging()

src/logging.h

@@ -1,5 +1,5 @@
 // Copyright (c) 2009-2010 Satoshi Nakamoto
-// Copyright (c) 2009-2022 The Bitcoin Core developers
+// Copyright (c) 2009-present The Bitcoin Core developers
 // Distributed under the MIT software license, see the accompanying
 // file COPYING or http://www.opensource.org/licenses/mit-license.php.
 
@@ -245,28 +245,27 @@ static inline bool LogAcceptCategory(BCLog::LogFlags category, BCLog::Level leve
 /** Return true if str parses as a log category and set the flag */
 bool GetLogCategory(BCLog::LogFlags& flag, std::string_view str);
 
-// Be conservative when using functions that
-// unconditionally log to debug.log! It should not be the case that an inbound
-// peer can fill up a user's disk with debug.log entries.
-
 template <typename... Args>
-static inline void LogPrintf_(std::string_view logging_function, std::string_view source_file, const int source_line, const BCLog::LogFlags flag, const BCLog::Level level, const char* fmt, const Args&... args)
+inline void LogPrintFormatInternal(std::string_view logging_function, std::string_view source_file, const int source_line, const BCLog::LogFlags flag, const BCLog::Level level, util::ConstevalFormatString<sizeof...(Args)> fmt, const Args&... args)
 {
     if (LogInstance().Enabled()) {
         std::string log_msg;
         try {
             log_msg = tfm::format(fmt, args...);
         } catch (tinyformat::format_error& fmterr) {
             /* 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.fmt;
         }
         LogInstance().LogPrintStr(log_msg, logging_function, source_file, source_line, flag, level);
     }
 }
 
-#define LogPrintLevel_(category, level, ...) LogPrintf_(__func__, __FILE__, __LINE__, category, level, __VA_ARGS__)
+#define LogPrintLevel_(category, level, ...) LogPrintFormatInternal(__func__, __FILE__, __LINE__, category, level, __VA_ARGS__)
 
 // Log unconditionally.
+// Be conservative when using functions that unconditionally log to debug.log!
+// It should not be the case that an inbound peer can fill up a user's storage
+// with debug.log entries.
 #define LogInfo(...) LogPrintLevel_(BCLog::LogFlags::ALL, BCLog::Level::Info, __VA_ARGS__)
 #define LogWarning(...) LogPrintLevel_(BCLog::LogFlags::ALL, BCLog::Level::Warning, __VA_ARGS__)
 #define LogError(...) LogPrintLevel_(BCLog::LogFlags::ALL, BCLog::Level::Error, __VA_ARGS__)

src/test/logging_tests.cpp

@@ -83,15 +83,15 @@ 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_LogPrintf_, LogSetup)
+BOOST_FIXTURE_TEST_CASE(logging_LogPrintStr, LogSetup)
 {
     LogInstance().m_log_sourcelocations = true;
-    LogPrintf_("fn1", "src1", 1, BCLog::LogFlags::NET, BCLog::Level::Debug, "foo1: %s\n", "bar1");
-    LogPrintf_("fn2", "src2", 2, BCLog::LogFlags::NET, BCLog::Level::Info, "foo2: %s\n", "bar2");
-    LogPrintf_("fn3", "src3", 3, BCLog::LogFlags::ALL, BCLog::Level::Debug, "foo3: %s\n", "bar3");
-    LogPrintf_("fn4", "src4", 4, BCLog::LogFlags::ALL, BCLog::Level::Info, "foo4: %s\n", "bar4");
-    LogPrintf_("fn5", "src5", 5, BCLog::LogFlags::NONE, BCLog::Level::Debug, "foo5: %s\n", "bar5");
-    LogPrintf_("fn6", "src6", 6, BCLog::LogFlags::NONE, BCLog::Level::Info, "foo6: %s\n", "bar6");
+    LogInstance().LogPrintStr("foo1: bar1\n", "fn1", "src1", 1, BCLog::LogFlags::NET, BCLog::Level::Debug);
+    LogInstance().LogPrintStr("foo2: bar2\n", "fn2", "src2", 2, BCLog::LogFlags::NET, BCLog::Level::Info);
+    LogInstance().LogPrintStr("foo3: bar3\n", "fn3", "src3", 3, BCLog::LogFlags::ALL, BCLog::Level::Debug);
+    LogInstance().LogPrintStr("foo4: bar4\n", "fn4", "src4", 4, BCLog::LogFlags::ALL, BCLog::Level::Info);
+    LogInstance().LogPrintStr("foo5: bar5\n", "fn5", "src5", 5, BCLog::LogFlags::NONE, BCLog::Level::Debug);
+    LogInstance().LogPrintStr("foo6: bar6\n", "fn6", "src6", 6, BCLog::LogFlags::NONE, BCLog::Level::Info);
     std::ifstream file{tmp_log_path};
     std::vector<std::string> log_lines;
     for (std::string log; std::getline(file, log);) {

src/wallet/scriptpubkeyman.h

@@ -254,9 +254,9 @@ class ScriptPubKeyMan
 
     /** Prepends the wallet name in logging output to ease debugging in multi-wallet use cases */
     template <typename... Params>
-    void WalletLogPrintf(const char* fmt, Params... parameters) const
+    void WalletLogPrintf(util::ConstevalFormatString<sizeof...(Params)> wallet_fmt, const Params&... params) const
     {
-        LogPrintf(("%s " + std::string{fmt}).c_str(), m_storage.GetDisplayName(), parameters...);
+        LogInfo("%s %s", m_storage.GetDisplayName(), tfm::format(wallet_fmt, params...));
     };
 
     /** Watch-only address added */

src/wallet/wallet.h

@@ -927,9 +927,9 @@ class CWallet final : public WalletStorage, public interfaces::Chain::Notificati
 
     /** Prepends the wallet name in logging output to ease debugging in multi-wallet use cases */
     template <typename... Params>
-    void WalletLogPrintf(const char* fmt, Params... parameters) const
+    void WalletLogPrintf(util::ConstevalFormatString<sizeof...(Params)> wallet_fmt, const Params&... params) const
     {
-        LogPrintf(("%s " + std::string{fmt}).c_str(), GetDisplayName(), parameters...);
+        LogInfo("%s %s", GetDisplayName(), tfm::format(wallet_fmt, params...));
     };
 
     /** Upgrade the wallet */

test/lint/lint-format-strings.py

@@ -17,15 +17,7 @@
 
 FUNCTION_NAMES_AND_NUMBER_OF_LEADING_ARGUMENTS = [
     'tfm::format,1',  # Assuming tfm::::format(std::ostream&, ...
-    'LogError,0',
-    'LogWarning,0',
-    'LogInfo,0',
-    'LogDebug,1',
-    'LogTrace,1',
-    'LogPrintf,0',
-    'LogPrintLevel,2',
     'strprintf,0',
-    'WalletLogPrintf,0',
 ]
 RUN_LINT_FILE = 'test/lint/run-lint-format-strings.py'
 

test/lint/run-lint-format-strings.py

@@ -15,11 +15,6 @@
 FALSE_POSITIVES = [
     ("src/clientversion.cpp", "strprintf(_(COPYRIGHT_HOLDERS).translated, COPYRIGHT_HOLDERS_SUBSTITUTION)"),
     ("src/test/translation_tests.cpp", "strprintf(format, arg)"),
-    ("src/validationinterface.cpp", "LogDebug(BCLog::VALIDATION, fmt \"\\n\", __VA_ARGS__)"),
-    ("src/wallet/wallet.h", "WalletLogPrintf(const char* fmt, Params... parameters)"),
-    ("src/wallet/wallet.h", "LogPrintf((\"%s \" + std::string{fmt}).c_str(), GetDisplayName(), parameters...)"),
-    ("src/wallet/scriptpubkeyman.h", "WalletLogPrintf(const char* fmt, Params... parameters)"),
-    ("src/wallet/scriptpubkeyman.h", "LogPrintf((\"%s \" + std::string{fmt}).c_str(), m_storage.GetDisplayName(), parameters...)"),
 ]