Merge 6f049e1230090baa64d1bf1a3d9c2064ee913e39 into 5f4422d68dc3530c353af1f87499de1c864b60ad

src/bench/logging.cpp

@@ -9,6 +9,8 @@
 #include <functional>
 #include <vector>
 
+using namespace std::literals;
+
 // All but 2 of the benchmarks should have roughly similar performance:
 //
 // LogWithoutDebug should be ~3 orders of magnitude faster, as nothing is logged.
@@ -57,8 +59,48 @@ static void LogWithoutWriteToFile(benchmark::Bench& bench)
     });
 }
 
+namespace BCLog {
+    bool IsSuspicious(const char ch) noexcept;
+    std::string LogEscapeMessage(std::string_view str);
+}
+
+static void LogEscapeMessageNormal(benchmark::Bench& bench) {
+    const std::vector<std::string> normal_logs{
+        "UpdateTip: new best=000000000000000000003c4c32d94a9363241a84d42cbbc1ec9f5f12f84f4feb height=875371 version=0x20000004 log2_work=95.334853 tx=1133590694 date='2024-12-19T01:57:26Z' progress=0.993026 cache=8.3MiB(56574txo)"s,
+        "received: headers (162 bytes) peer=15"s,
+        "Config file arg: datadir=/Users/bitcoin/data"s,
+        "Verified block header at height 12345 hash: 你好 🔤"s
+    };
+
+    bench.batch(normal_logs.size()).run([&] {
+        for (const auto& msg : normal_logs) {
+            const auto& res{std::ranges::none_of(msg, BCLog::IsSuspicious) ? msg : BCLog::LogEscapeMessage(msg)};
+            ankerl::nanobench::doNotOptimizeAway(res);
+        }
+    });
+}
+
+static void LogEscapeMessageSuspicious(benchmark::Bench& bench) {
+    // Based on the test cases
+    const std::vector<std::string> suspicious_logs{
+        "Received strange message\0from peer=12"s,
+        "Got malformed packet\x01\x02\x03\x7F from peer=13"s,
+        "Peer=14 sent:\x0D\x0Econtent-length: 100\x0D\x0A"s,
+        "Validation failed on\x1B[31mERROR\x1B[0m block=123456"s
+    };
+
+   bench.batch(suspicious_logs.size()).run([&] {
+        for (const auto& msg : suspicious_logs) {
+            const auto& res{std::ranges::none_of(msg, BCLog::IsSuspicious) ? msg : BCLog::LogEscapeMessage(msg)};
+            ankerl::nanobench::doNotOptimizeAway(res);
+        }
+    });
+}
+
 BENCHMARK(LogWithDebug, benchmark::PriorityLevel::HIGH);
 BENCHMARK(LogWithoutDebug, benchmark::PriorityLevel::HIGH);
 BENCHMARK(LogWithThreadNames, benchmark::PriorityLevel::HIGH);
 BENCHMARK(LogWithoutThreadNames, benchmark::PriorityLevel::HIGH);
 BENCHMARK(LogWithoutWriteToFile, benchmark::PriorityLevel::HIGH);
+BENCHMARK(LogEscapeMessageNormal, benchmark::PriorityLevel::LOW);
+BENCHMARK(LogEscapeMessageSuspicious, benchmark::PriorityLevel::LOW);

src/logging.cpp

@@ -315,6 +315,11 @@ std::string BCLog::Logger::LogTimestampStr(SystemClock::time_point now, std::chr
 }
 
 namespace BCLog {
+    bool IsSuspicious(const char ch) noexcept
+    {
+        const auto uch{static_cast<uint8_t>(ch)};
+        return (uch < ' ' && uch != '\n') || uch == '\x7f';
+    }
     /** Belts and suspenders: make sure outgoing log messages don't contain
      * potentially suspicious characters, such as terminal control codes.
      *
@@ -322,14 +327,15 @@ namespace BCLog {
      * It escapes instead of removes them to still allow for troubleshooting
      * issues where they accidentally end up in strings.
      */
-    std::string LogEscapeMessage(std::string_view str) {
+    std::string LogEscapeMessage(std::string_view str)
+    {
         std::string ret;
-        for (char ch_in : str) {
-            uint8_t ch = (uint8_t)ch_in;
-            if ((ch >= 32 || ch == '\n') && ch != '\x7f') {
-                ret += ch_in;
-            } else {
+        ret.reserve(3 + str.size()); // Assume at least one suspicious character
+        for (auto ch : str) {
+            if (IsSuspicious(ch)) {
                 ret += strprintf("\\x%02x", ch);
+            } else {
+                ret += ch;
             }
         }
         return ret;
@@ -392,7 +398,7 @@ void BCLog::Logger::LogPrintStr(std::string_view str, std::string_view logging_f
 
 void BCLog::Logger::LogPrintStr_(std::string_view str, std::string_view logging_function, std::string_view source_file, int source_line, BCLog::LogFlags category, BCLog::Level level)
 {
-    std::string str_prefixed = LogEscapeMessage(str);
+    std::string str_prefixed{std::ranges::none_of(str, IsSuspicious) ? str : LogEscapeMessage(str)};
 
     if (m_buffering) {
         {