/root/bitcoin/src/logging.cpp
| Line | Count | Source | 
| 1 |  | // Copyright (c) 2009-2010 Satoshi Nakamoto | 
| 2 |  | // Copyright (c) 2009-present The Bitcoin Core developers | 
| 3 |  | // Distributed under the MIT software license, see the accompanying | 
| 4 |  | // file COPYING or http://www.opensource.org/licenses/mit-license.php. | 
| 5 |  |  | 
| 6 |  | #include <logging.h> | 
| 7 |  | #include <memusage.h> | 
| 8 |  | #include <util/check.h> | 
| 9 |  | #include <util/fs.h> | 
| 10 |  | #include <util/string.h> | 
| 11 |  | #include <util/threadnames.h> | 
| 12 |  | #include <util/time.h> | 
| 13 |  |  | 
| 14 |  | #include <array> | 
| 15 |  | #include <cstring> | 
| 16 |  | #include <map> | 
| 17 |  | #include <optional> | 
| 18 |  | #include <utility> | 
| 19 |  |  | 
| 20 |  | using util::Join; | 
| 21 |  | using util::RemovePrefixView; | 
| 22 |  |  | 
| 23 |  | const char * const DEFAULT_DEBUGLOGFILE = "debug.log"; | 
| 24 |  | constexpr auto MAX_USER_SETABLE_SEVERITY_LEVEL{BCLog::Level::Info}; | 
| 25 |  |  | 
| 26 |  | BCLog::Logger& LogInstance() | 
| 27 | 142k | { | 
| 28 |  | /** | 
| 29 |  |  * NOTE: the logger instances is leaked on exit. This is ugly, but will be | 
| 30 |  |  * cleaned up by the OS/libc. Defining a logger as a global object doesn't work | 
| 31 |  |  * since the order of destruction of static/global objects is undefined. | 
| 32 |  |  * Consider if the logger gets destroyed, and then some later destructor calls | 
| 33 |  |  * LogPrintf, maybe indirectly, and you get a core dump at shutdown trying to | 
| 34 |  |  * access the logger. When the shutdown sequence is fully audited and tested, | 
| 35 |  |  * explicit destruction of these objects can be implemented by changing this | 
| 36 |  |  * from a raw pointer to a std::unique_ptr. | 
| 37 |  |  * Since the ~Logger() destructor is never called, the Logger class and all | 
| 38 |  |  * its subclasses must have implicitly-defined destructors. | 
| 39 |  |  * | 
| 40 |  |  * This method of initialization was originally introduced in | 
| 41 |  |  * ee3374234c60aba2cc4c5cd5cac1c0aefc2d817c. | 
| 42 |  |  */ | 
| 43 | 142k |     static BCLog::Logger* g_logger{new BCLog::Logger()}; | 
| 44 | 142k |     return *g_logger; | 
| 45 | 142k | } | 
| 46 |  |  | 
| 47 |  | bool fLogIPs = DEFAULT_LOGIPS; | 
| 48 |  |  | 
| 49 |  | static int FileWriteStr(std::string_view str, FILE *fp) | 
| 50 | 0 | { | 
| 51 | 0 |     return fwrite(str.data(), 1, str.size(), fp); | 
| 52 | 0 | } | 
| 53 |  |  | 
| 54 |  | bool BCLog::Logger::StartLogging() | 
| 55 | 0 | { | 
| 56 | 0 |     StdLockGuard scoped_lock(m_cs); | 
| 57 |  | 
 | 
| 58 | 0 |     assert(m_buffering); | 
| 59 | 0 |     assert(m_fileout == nullptr); | 
| 60 |  |  | 
| 61 | 0 |     if (m_print_to_file) { | 
| 62 | 0 |         assert(!m_file_path.empty()); | 
| 63 | 0 |         m_fileout = fsbridge::fopen(m_file_path, "a"); | 
| 64 | 0 |         if (!m_fileout) { | 
| 65 | 0 |             return false; | 
| 66 | 0 |         } | 
| 67 |  |  | 
| 68 | 0 |         setbuf(m_fileout, nullptr); // unbuffered | 
| 69 |  |  | 
| 70 |  |         // Add newlines to the logfile to distinguish this execution from the | 
| 71 |  |         // last one. | 
| 72 | 0 |         FileWriteStr("\n\n\n\n\n", m_fileout); | 
| 73 | 0 |     } | 
| 74 |  |  | 
| 75 |  |     // dump buffered messages from before we opened the log | 
| 76 | 0 |     m_buffering = false; | 
| 77 | 0 |     if (m_buffer_lines_discarded > 0) { | 
| 78 | 0 |         LogPrintStr_(strprintf("Early logging buffer overflowed, %d log lines discarded.\n", m_buffer_lines_discarded), std::source_location::current(), BCLog::ALL, Level::Info, /*should_ratelimit=*/false); | 
| 79 | 0 |     } | 
| 80 | 0 |     while (!m_msgs_before_open.empty()) { | 
| 81 | 0 |         const auto& buflog = m_msgs_before_open.front(); | 
| 82 | 0 |         std::string s{buflog.str}; | 
| 83 | 0 |         FormatLogStrInPlace(s, buflog.category, buflog.level, buflog.source_loc, buflog.threadname, buflog.now, buflog.mocktime); | 
| 84 | 0 |         m_msgs_before_open.pop_front(); | 
| 85 |  | 
 | 
| 86 | 0 |         if (m_print_to_file) FileWriteStr(s, m_fileout); | 
| 87 | 0 |         if (m_print_to_console) fwrite(s.data(), 1, s.size(), stdout); | 
| 88 | 0 |         for (const auto& cb : m_print_callbacks) { | 
| 89 | 0 |             cb(s); | 
| 90 | 0 |         } | 
| 91 | 0 |     } | 
| 92 | 0 |     m_cur_buffer_memusage = 0; | 
| 93 | 0 |     if (m_print_to_console) fflush(stdout); | 
| 94 |  | 
 | 
| 95 | 0 |     return true; | 
| 96 | 0 | } | 
| 97 |  |  | 
| 98 |  | void BCLog::Logger::DisconnectTestLogger() | 
| 99 | 1 | { | 
| 100 | 1 |     StdLockGuard scoped_lock(m_cs); | 
| 101 | 1 |     m_buffering = true; | 
| 102 | 1 |     if (m_fileout != nullptr) fclose(m_fileout); | 
| 103 | 1 |     m_fileout = nullptr; | 
| 104 | 1 |     m_print_callbacks.clear(); | 
| 105 | 1 |     m_max_buffer_memusage = DEFAULT_MAX_LOG_BUFFER; | 
| 106 | 1 |     m_cur_buffer_memusage = 0; | 
| 107 | 1 |     m_buffer_lines_discarded = 0; | 
| 108 | 1 |     m_msgs_before_open.clear(); | 
| 109 | 1 | } | 
| 110 |  |  | 
| 111 |  | void BCLog::Logger::DisableLogging() | 
| 112 | 0 | { | 
| 113 | 0 |     { | 
| 114 | 0 |         StdLockGuard scoped_lock(m_cs); | 
| 115 | 0 |         assert(m_buffering); | 
| 116 | 0 |         assert(m_print_callbacks.empty()); | 
| 117 | 0 |     } | 
| 118 | 0 |     m_print_to_file = false; | 
| 119 | 0 |     m_print_to_console = false; | 
| 120 | 0 |     StartLogging(); | 
| 121 | 0 | } | 
| 122 |  |  | 
| 123 |  | void BCLog::Logger::EnableCategory(BCLog::LogFlags flag) | 
| 124 | 0 | { | 
| 125 | 0 |     m_categories |= flag; | 
| 126 | 0 | } | 
| 127 |  |  | 
| 128 |  | bool BCLog::Logger::EnableCategory(std::string_view str) | 
| 129 | 0 | { | 
| 130 | 0 |     BCLog::LogFlags flag; | 
| 131 | 0 |     if (!GetLogCategory(flag, str)) return false; | 
| 132 | 0 |     EnableCategory(flag); | 
| 133 | 0 |     return true; | 
| 134 | 0 | } | 
| 135 |  |  | 
| 136 |  | void BCLog::Logger::DisableCategory(BCLog::LogFlags flag) | 
| 137 | 0 | { | 
| 138 | 0 |     m_categories &= ~flag; | 
| 139 | 0 | } | 
| 140 |  |  | 
| 141 |  | bool BCLog::Logger::DisableCategory(std::string_view str) | 
| 142 | 0 | { | 
| 143 | 0 |     BCLog::LogFlags flag; | 
| 144 | 0 |     if (!GetLogCategory(flag, str)) return false; | 
| 145 | 0 |     DisableCategory(flag); | 
| 146 | 0 |     return true; | 
| 147 | 0 | } | 
| 148 |  |  | 
| 149 |  | bool BCLog::Logger::WillLogCategory(BCLog::LogFlags category) const | 
| 150 | 86.4k | { | 
| 151 | 86.4k |     return (m_categories.load(std::memory_order_relaxed) & category) != 0; | 
| 152 | 86.4k | } | 
| 153 |  |  | 
| 154 |  | bool BCLog::Logger::WillLogCategoryLevel(BCLog::LogFlags category, BCLog::Level level) const | 
| 155 | 86.4k | { | 
| 156 |  |     // Log messages at Info, Warning and Error level unconditionally, so that | 
| 157 |  |     // important troubleshooting information doesn't get lost. | 
| 158 | 86.4k |     if (level >= BCLog::Level::Info) return true; | 
| 159 |  |  | 
| 160 | 86.4k |     if (!WillLogCategory(category)) return false; | 
| 161 |  |  | 
| 162 | 0 |     StdLockGuard scoped_lock(m_cs); | 
| 163 | 0 |     const auto it{m_category_log_levels.find(category)}; | 
| 164 | 0 |     return level >= (it == m_category_log_levels.end() ? LogLevel() : it->second); | 
| 165 | 86.4k | } | 
| 166 |  |  | 
| 167 |  | bool BCLog::Logger::DefaultShrinkDebugFile() const | 
| 168 | 0 | { | 
| 169 | 0 |     return m_categories == BCLog::NONE; | 
| 170 | 0 | } | 
| 171 |  |  | 
| 172 |  | static const std::map<std::string, BCLog::LogFlags, std::less<>> LOG_CATEGORIES_BY_STR{ | 
| 173 |  |     {"net", BCLog::NET}, | 
| 174 |  |     {"tor", BCLog::TOR}, | 
| 175 |  |     {"mempool", BCLog::MEMPOOL}, | 
| 176 |  |     {"http", BCLog::HTTP}, | 
| 177 |  |     {"bench", BCLog::BENCH}, | 
| 178 |  |     {"zmq", BCLog::ZMQ}, | 
| 179 |  |     {"walletdb", BCLog::WALLETDB}, | 
| 180 |  |     {"rpc", BCLog::RPC}, | 
| 181 |  |     {"estimatefee", BCLog::ESTIMATEFEE}, | 
| 182 |  |     {"addrman", BCLog::ADDRMAN}, | 
| 183 |  |     {"selectcoins", BCLog::SELECTCOINS}, | 
| 184 |  |     {"reindex", BCLog::REINDEX}, | 
| 185 |  |     {"cmpctblock", BCLog::CMPCTBLOCK}, | 
| 186 |  |     {"rand", BCLog::RAND}, | 
| 187 |  |     {"prune", BCLog::PRUNE}, | 
| 188 |  |     {"proxy", BCLog::PROXY}, | 
| 189 |  |     {"mempoolrej", BCLog::MEMPOOLREJ}, | 
| 190 |  |     {"libevent", BCLog::LIBEVENT}, | 
| 191 |  |     {"coindb", BCLog::COINDB}, | 
| 192 |  |     {"qt", BCLog::QT}, | 
| 193 |  |     {"leveldb", BCLog::LEVELDB}, | 
| 194 |  |     {"validation", BCLog::VALIDATION}, | 
| 195 |  |     {"i2p", BCLog::I2P}, | 
| 196 |  |     {"ipc", BCLog::IPC}, | 
| 197 |  | #ifdef DEBUG_LOCKCONTENTION | 
| 198 |  |     {"lock", BCLog::LOCK}, | 
| 199 |  | #endif | 
| 200 |  |     {"blockstorage", BCLog::BLOCKSTORAGE}, | 
| 201 |  |     {"txreconciliation", BCLog::TXRECONCILIATION}, | 
| 202 |  |     {"scan", BCLog::SCAN}, | 
| 203 |  |     {"txpackages", BCLog::TXPACKAGES}, | 
| 204 |  | }; | 
| 205 |  |  | 
| 206 |  | static const std::unordered_map<BCLog::LogFlags, std::string> LOG_CATEGORIES_BY_FLAG{ | 
| 207 |  |     // Swap keys and values from LOG_CATEGORIES_BY_STR. | 
| 208 | 0 |     [](const auto& in) { | 
| 209 | 0 |         std::unordered_map<BCLog::LogFlags, std::string> out; | 
| 210 | 0 |         for (const auto& [k, v] : in) { | 
| 211 | 0 |             const bool inserted{out.emplace(v, k).second}; | 
| 212 | 0 |             assert(inserted); | 
| 213 | 0 |         } | 
| 214 | 0 |         return out; | 
| 215 | 0 |     }(LOG_CATEGORIES_BY_STR) | 
| 216 |  | }; | 
| 217 |  |  | 
| 218 |  | bool GetLogCategory(BCLog::LogFlags& flag, std::string_view str) | 
| 219 | 0 | { | 
| 220 | 0 |     if (str.empty() || str == "1" || str == "all") { | 
| 221 | 0 |         flag = BCLog::ALL; | 
| 222 | 0 |         return true; | 
| 223 | 0 |     } | 
| 224 | 0 |     auto it = LOG_CATEGORIES_BY_STR.find(str); | 
| 225 | 0 |     if (it != LOG_CATEGORIES_BY_STR.end()) { | 
| 226 | 0 |         flag = it->second; | 
| 227 | 0 |         return true; | 
| 228 | 0 |     } | 
| 229 | 0 |     return false; | 
| 230 | 0 | } | 
| 231 |  |  | 
| 232 |  | std::string BCLog::Logger::LogLevelToStr(BCLog::Level level) | 
| 233 | 0 | { | 
| 234 | 0 |     switch (level) { | 
| 235 | 0 |     case BCLog::Level::Trace: | 
| 236 | 0 |         return "trace"; | 
| 237 | 0 |     case BCLog::Level::Debug: | 
| 238 | 0 |         return "debug"; | 
| 239 | 0 |     case BCLog::Level::Info: | 
| 240 | 0 |         return "info"; | 
| 241 | 0 |     case BCLog::Level::Warning: | 
| 242 | 0 |         return "warning"; | 
| 243 | 0 |     case BCLog::Level::Error: | 
| 244 | 0 |         return "error"; | 
| 245 | 0 |     } | 
| 246 | 0 |     assert(false); | 
| 247 | 0 | } | 
| 248 |  |  | 
| 249 |  | static std::string LogCategoryToStr(BCLog::LogFlags category) | 
| 250 | 0 | { | 
| 251 | 0 |     if (category == BCLog::ALL) { | 
| 252 | 0 |         return "all"; | 
| 253 | 0 |     } | 
| 254 | 0 |     auto it = LOG_CATEGORIES_BY_FLAG.find(category); | 
| 255 | 0 |     assert(it != LOG_CATEGORIES_BY_FLAG.end()); | 
| 256 | 0 |     return it->second; | 
| 257 | 0 | } | 
| 258 |  |  | 
| 259 |  | static std::optional<BCLog::Level> GetLogLevel(std::string_view level_str) | 
| 260 | 0 | { | 
| 261 | 0 |     if (level_str == "trace") { | 
| 262 | 0 |         return BCLog::Level::Trace; | 
| 263 | 0 |     } else if (level_str == "debug") { | 
| 264 | 0 |         return BCLog::Level::Debug; | 
| 265 | 0 |     } else if (level_str == "info") { | 
| 266 | 0 |         return BCLog::Level::Info; | 
| 267 | 0 |     } else if (level_str == "warning") { | 
| 268 | 0 |         return BCLog::Level::Warning; | 
| 269 | 0 |     } else if (level_str == "error") { | 
| 270 | 0 |         return BCLog::Level::Error; | 
| 271 | 0 |     } else { | 
| 272 | 0 |         return std::nullopt; | 
| 273 | 0 |     } | 
| 274 | 0 | } | 
| 275 |  |  | 
| 276 |  | std::vector<LogCategory> BCLog::Logger::LogCategoriesList() const | 
| 277 | 0 | { | 
| 278 | 0 |     std::vector<LogCategory> ret; | 
| 279 | 0 |     ret.reserve(LOG_CATEGORIES_BY_STR.size()); | 
| 280 | 0 |     for (const auto& [category, flag] : LOG_CATEGORIES_BY_STR) { | 
| 281 | 0 |         ret.push_back(LogCategory{.category = category, .active = WillLogCategory(flag)}); | 
| 282 | 0 |     } | 
| 283 | 0 |     return ret; | 
| 284 | 0 | } | 
| 285 |  |  | 
| 286 |  | /** Log severity levels that can be selected by the user. */ | 
| 287 |  | static constexpr std::array<BCLog::Level, 3> LogLevelsList() | 
| 288 | 0 | { | 
| 289 | 0 |     return {BCLog::Level::Info, BCLog::Level::Debug, BCLog::Level::Trace}; | 
| 290 | 0 | } | 
| 291 |  |  | 
| 292 |  | std::string BCLog::Logger::LogLevelsString() const | 
| 293 | 0 | { | 
| 294 | 0 |     const auto& levels = LogLevelsList(); | 
| 295 | 0 |     return Join(std::vector<BCLog::Level>{levels.begin(), levels.end()}, ", ", [](BCLog::Level level) { return LogLevelToStr(level); }); | 
| 296 | 0 | } | 
| 297 |  |  | 
| 298 |  | std::string BCLog::Logger::LogTimestampStr(SystemClock::time_point now, std::chrono::seconds mocktime) const | 
| 299 | 0 | { | 
| 300 | 0 |     std::string strStamped; | 
| 301 |  | 
 | 
| 302 | 0 |     if (!m_log_timestamps) | 
| 303 | 0 |         return strStamped; | 
| 304 |  |  | 
| 305 | 0 |     const auto now_seconds{std::chrono::time_point_cast<std::chrono::seconds>(now)}; | 
| 306 | 0 |     strStamped = FormatISO8601DateTime(TicksSinceEpoch<std::chrono::seconds>(now_seconds)); | 
| 307 | 0 |     if (m_log_time_micros && !strStamped.empty()) { | 
| 308 | 0 |         strStamped.pop_back(); | 
| 309 | 0 |         strStamped += strprintf(".%06dZ", Ticks<std::chrono::microseconds>(now - now_seconds)); | 
| 310 | 0 |     } | 
| 311 | 0 |     if (mocktime > 0s) { | 
| 312 | 0 |         strStamped += " (mocktime: " + FormatISO8601DateTime(count_seconds(mocktime)) + ")"; | 
| 313 | 0 |     } | 
| 314 | 0 |     strStamped += ' '; | 
| 315 |  | 
 | 
| 316 | 0 |     return strStamped; | 
| 317 | 0 | } | 
| 318 |  |  | 
| 319 |  | namespace BCLog { | 
| 320 |  |     /** Belts and suspenders: make sure outgoing log messages don't contain | 
| 321 |  |      * potentially suspicious characters, such as terminal control codes. | 
| 322 |  |      * | 
| 323 |  |      * This escapes control characters except newline ('\n') in C syntax. | 
| 324 |  |      * It escapes instead of removes them to still allow for troubleshooting | 
| 325 |  |      * issues where they accidentally end up in strings. | 
| 326 |  |      */ | 
| 327 | 0 |     std::string LogEscapeMessage(std::string_view str) { | 
| 328 | 0 |         std::string ret; | 
| 329 | 0 |         for (char ch_in : str) { | 
| 330 | 0 |             uint8_t ch = (uint8_t)ch_in; | 
| 331 | 0 |             if ((ch >= 32 || ch == '\n') && ch != '\x7f') { | 
| 332 | 0 |                 ret += ch_in; | 
| 333 | 0 |             } else { | 
| 334 | 0 |                 ret += strprintf("\\x%02x", ch); | 
| 335 | 0 |             } | 
| 336 | 0 |         } | 
| 337 | 0 |         return ret; | 
| 338 | 0 |     } | 
| 339 |  | } // namespace BCLog | 
| 340 |  |  | 
| 341 |  | std::string BCLog::Logger::GetLogPrefix(BCLog::LogFlags category, BCLog::Level level) const | 
| 342 | 0 | { | 
| 343 | 0 |     if (category == LogFlags::NONE) category = LogFlags::ALL; | 
| 344 |  | 
 | 
| 345 | 0 |     const bool has_category{m_always_print_category_level || category != LogFlags::ALL}; | 
| 346 |  |  | 
| 347 |  |     // If there is no category, Info is implied | 
| 348 | 0 |     if (!has_category && level == Level::Info) return {}; | 
| 349 |  |  | 
| 350 | 0 |     std::string s{"["}; | 
| 351 | 0 |     if (has_category) { | 
| 352 | 0 |         s += LogCategoryToStr(category); | 
| 353 | 0 |     } | 
| 354 |  | 
 | 
| 355 | 0 |     if (m_always_print_category_level || !has_category || level != Level::Debug) { | 
| 356 |  |         // If there is a category, Debug is implied, so don't add the level | 
| 357 |  |  | 
| 358 |  |         // Only add separator if we have a category | 
| 359 | 0 |         if (has_category) s += ":"; | 
| 360 | 0 |         s += Logger::LogLevelToStr(level); | 
| 361 | 0 |     } | 
| 362 |  | 
 | 
| 363 | 0 |     s += "] "; | 
| 364 | 0 |     return s; | 
| 365 | 0 | } | 
| 366 |  |  | 
| 367 |  | static size_t MemUsage(const BCLog::Logger::BufferedLog& buflog) | 
| 368 | 0 | { | 
| 369 | 0 |     return memusage::DynamicUsage(buflog.str) + | 
| 370 | 0 |            memusage::DynamicUsage(buflog.threadname) + | 
| 371 | 0 |            memusage::MallocUsage(sizeof(memusage::list_node<BCLog::Logger::BufferedLog>)); | 
| 372 | 0 | } | 
| 373 |  |  | 
| 374 |  | BCLog::LogRateLimiter::LogRateLimiter(uint64_t max_bytes, std::chrono::seconds reset_window) | 
| 375 | 0 |     : m_max_bytes{max_bytes}, m_reset_window{reset_window} {} | 
| 376 |  |  | 
| 377 |  | std::shared_ptr<BCLog::LogRateLimiter> BCLog::LogRateLimiter::Create( | 
| 378 |  |     SchedulerFunction&& scheduler_func, uint64_t max_bytes, std::chrono::seconds reset_window) | 
| 379 | 0 | { | 
| 380 | 0 |     auto limiter{std::shared_ptr<LogRateLimiter>(new LogRateLimiter(max_bytes, reset_window))}; | 
| 381 | 0 |     std::weak_ptr<LogRateLimiter> weak_limiter{limiter}; | 
| 382 | 0 |     auto reset = [weak_limiter] { | 
| 383 | 0 |         if (auto shared_limiter{weak_limiter.lock()}) shared_limiter->Reset(); | 
| 384 | 0 |     }; | 
| 385 | 0 |     scheduler_func(reset, limiter->m_reset_window); | 
| 386 | 0 |     return limiter; | 
| 387 | 0 | } | 
| 388 |  |  | 
| 389 |  | BCLog::LogRateLimiter::Status BCLog::LogRateLimiter::Consume( | 
| 390 |  |     const std::source_location& source_loc, | 
| 391 |  |     const std::string& str) | 
| 392 | 0 | { | 
| 393 | 0 |     StdLockGuard scoped_lock(m_mutex); | 
| 394 | 0 |     auto& stats{m_source_locations.try_emplace(source_loc, m_max_bytes).first->second}; | 
| 395 | 0 |     Status status{stats.m_dropped_bytes > 0 ? Status::STILL_SUPPRESSED : Status::UNSUPPRESSED}; | 
| 396 |  | 
 | 
| 397 | 0 |     if (!stats.Consume(str.size()) && status == Status::UNSUPPRESSED) { | 
| 398 | 0 |         status = Status::NEWLY_SUPPRESSED; | 
| 399 | 0 |         m_suppression_active = true; | 
| 400 | 0 |     } | 
| 401 |  | 
 | 
| 402 | 0 |     return status; | 
| 403 | 0 | } | 
| 404 |  |  | 
| 405 |  | void BCLog::Logger::FormatLogStrInPlace(std::string& str, BCLog::LogFlags category, BCLog::Level level, const std::source_location& source_loc, std::string_view threadname, SystemClock::time_point now, std::chrono::seconds mocktime) const | 
| 406 | 0 | { | 
| 407 | 0 |     if (!str.ends_with('\n')) str.push_back('\n'); | 
| 408 |  | 
 | 
| 409 | 0 |     str.insert(0, GetLogPrefix(category, level)); | 
| 410 |  | 
 | 
| 411 | 0 |     if (m_log_sourcelocations) { | 
| 412 | 0 |         str.insert(0, strprintf("[%s:%d] [%s] ", RemovePrefixView(source_loc.file_name(), "./"), source_loc.line(), source_loc.function_name())); | 
| 413 | 0 |     } | 
| 414 |  | 
 | 
| 415 | 0 |     if (m_log_threadnames) { | 
| 416 | 0 |         str.insert(0, strprintf("[%s] ", (threadname.empty() ? "unknown" : threadname))); | 
| 417 | 0 |     } | 
| 418 |  | 
 | 
| 419 | 0 |     str.insert(0, LogTimestampStr(now, mocktime)); | 
| 420 | 0 | } | 
| 421 |  |  | 
| 422 |  | void BCLog::Logger::LogPrintStr(std::string_view str, std::source_location&& source_loc, BCLog::LogFlags category, BCLog::Level level, bool should_ratelimit) | 
| 423 | 0 | { | 
| 424 | 0 |     StdLockGuard scoped_lock(m_cs); | 
| 425 | 0 |     return LogPrintStr_(str, std::move(source_loc), category, level, should_ratelimit); | 
| 426 | 0 | } | 
| 427 |  |  | 
| 428 |  | // NOLINTNEXTLINE(misc-no-recursion) | 
| 429 |  | void BCLog::Logger::LogPrintStr_(std::string_view str, std::source_location&& source_loc, BCLog::LogFlags category, BCLog::Level level, bool should_ratelimit) | 
| 430 | 0 | { | 
| 431 | 0 |     std::string str_prefixed = LogEscapeMessage(str); | 
| 432 |  | 
 | 
| 433 | 0 |     if (m_buffering) { | 
| 434 | 0 |         { | 
| 435 | 0 |             BufferedLog buf{ | 
| 436 | 0 |                 .now = SystemClock::now(), | 
| 437 | 0 |                 .mocktime = GetMockTime(), | 
| 438 | 0 |                 .str = str_prefixed, | 
| 439 | 0 |                 .threadname = util::ThreadGetInternalName(), | 
| 440 | 0 |                 .source_loc = std::move(source_loc), | 
| 441 | 0 |                 .category = category, | 
| 442 | 0 |                 .level = level, | 
| 443 | 0 |             }; | 
| 444 | 0 |             m_cur_buffer_memusage += MemUsage(buf); | 
| 445 | 0 |             m_msgs_before_open.push_back(std::move(buf)); | 
| 446 | 0 |         } | 
| 447 |  | 
 | 
| 448 | 0 |         while (m_cur_buffer_memusage > m_max_buffer_memusage) { | 
| 449 | 0 |             if (m_msgs_before_open.empty()) { | 
| 450 | 0 |                 m_cur_buffer_memusage = 0; | 
| 451 | 0 |                 break; | 
| 452 | 0 |             } | 
| 453 | 0 |             m_cur_buffer_memusage -= MemUsage(m_msgs_before_open.front()); | 
| 454 | 0 |             m_msgs_before_open.pop_front(); | 
| 455 | 0 |             ++m_buffer_lines_discarded; | 
| 456 | 0 |         } | 
| 457 |  | 
 | 
| 458 | 0 |         return; | 
| 459 | 0 |     } | 
| 460 |  |  | 
| 461 | 0 |     FormatLogStrInPlace(str_prefixed, category, level, source_loc, util::ThreadGetInternalName(), SystemClock::now(), GetMockTime()); | 
| 462 | 0 |     bool ratelimit{false}; | 
| 463 | 0 |     if (should_ratelimit && m_limiter) { | 
| 464 | 0 |         auto status{m_limiter->Consume(source_loc, str_prefixed)}; | 
| 465 | 0 |         if (status == LogRateLimiter::Status::NEWLY_SUPPRESSED) { | 
| 466 |  |             // NOLINTNEXTLINE(misc-no-recursion) | 
| 467 | 0 |             LogPrintStr_(strprintf( | 
| 468 | 0 |                              "Excessive logging detected from %s:%d (%s): >%d bytes logged during " | 
| 469 | 0 |                              "the last time window of %is. Suppressing logging to disk from this " | 
| 470 | 0 |                              "source location until time window resets. Console logging " | 
| 471 | 0 |                              "unaffected. Last log entry.", | 
| 472 | 0 |                              source_loc.file_name(), source_loc.line(), source_loc.function_name(), | 
| 473 | 0 |                              m_limiter->m_max_bytes, | 
| 474 | 0 |                              Ticks<std::chrono::seconds>(m_limiter->m_reset_window)), | 
| 475 | 0 |                          std::source_location::current(), LogFlags::ALL, Level::Warning, /*should_ratelimit=*/false); // with should_ratelimit=false, this cannot lead to infinite recursion | 
| 476 | 0 |         } else if (status == LogRateLimiter::Status::STILL_SUPPRESSED) { | 
| 477 | 0 |             ratelimit = true; | 
| 478 | 0 |         } | 
| 479 | 0 |     } | 
| 480 |  |  | 
| 481 |  |     // To avoid confusion caused by dropped log messages when debugging an issue, | 
| 482 |  |     // we prefix log lines with "[*]" when there are any suppressed source locations. | 
| 483 | 0 |     if (m_limiter && m_limiter->SuppressionsActive()) { | 
| 484 | 0 |         str_prefixed.insert(0, "[*] "); | 
| 485 | 0 |     } | 
| 486 |  | 
 | 
| 487 | 0 |     if (m_print_to_console) { | 
| 488 |  |         // print to console | 
| 489 | 0 |         fwrite(str_prefixed.data(), 1, str_prefixed.size(), stdout); | 
| 490 | 0 |         fflush(stdout); | 
| 491 | 0 |     } | 
| 492 | 0 |     for (const auto& cb : m_print_callbacks) { | 
| 493 | 0 |         cb(str_prefixed); | 
| 494 | 0 |     } | 
| 495 | 0 |     if (m_print_to_file && !ratelimit) { | 
| 496 | 0 |         assert(m_fileout != nullptr); | 
| 497 |  |  | 
| 498 |  |         // reopen the log file, if requested | 
| 499 | 0 |         if (m_reopen_file) { | 
| 500 | 0 |             m_reopen_file = false; | 
| 501 | 0 |             FILE* new_fileout = fsbridge::fopen(m_file_path, "a"); | 
| 502 | 0 |             if (new_fileout) { | 
| 503 | 0 |                 setbuf(new_fileout, nullptr); // unbuffered | 
| 504 | 0 |                 fclose(m_fileout); | 
| 505 | 0 |                 m_fileout = new_fileout; | 
| 506 | 0 |             } | 
| 507 | 0 |         } | 
| 508 | 0 |         FileWriteStr(str_prefixed, m_fileout); | 
| 509 | 0 |     } | 
| 510 | 0 | } | 
| 511 |  |  | 
| 512 |  | void BCLog::Logger::ShrinkDebugFile() | 
| 513 | 0 | { | 
| 514 |  |     // Amount of debug.log to save at end when shrinking (must fit in memory) | 
| 515 | 0 |     constexpr size_t RECENT_DEBUG_HISTORY_SIZE = 10 * 1000000; | 
| 516 |  | 
 | 
| 517 | 0 |     assert(!m_file_path.empty()); | 
| 518 |  |  | 
| 519 |  |     // Scroll debug.log if it's getting too big | 
| 520 | 0 |     FILE* file = fsbridge::fopen(m_file_path, "r"); | 
| 521 |  |  | 
| 522 |  |     // Special files (e.g. device nodes) may not have a size. | 
| 523 | 0 |     size_t log_size = 0; | 
| 524 | 0 |     try { | 
| 525 | 0 |         log_size = fs::file_size(m_file_path); | 
| 526 | 0 |     } catch (const fs::filesystem_error&) {} | 
| 527 |  |  | 
| 528 |  |     // If debug.log file is more than 10% bigger the RECENT_DEBUG_HISTORY_SIZE | 
| 529 |  |     // trim it down by saving only the last RECENT_DEBUG_HISTORY_SIZE bytes | 
| 530 | 0 |     if (file && log_size > 11 * (RECENT_DEBUG_HISTORY_SIZE / 10)) | 
| 531 | 0 |     { | 
| 532 |  |         // Restart the file with some of the end | 
| 533 | 0 |         std::vector<char> vch(RECENT_DEBUG_HISTORY_SIZE, 0); | 
| 534 | 0 |         if (fseek(file, -((long)vch.size()), SEEK_END)) { | 
| 535 | 0 |             LogPrintf("Failed to shrink debug log file: fseek(...) failed\n"); | 
| 536 | 0 |             fclose(file); | 
| 537 | 0 |             return; | 
| 538 | 0 |         } | 
| 539 | 0 |         int nBytes = fread(vch.data(), 1, vch.size(), file); | 
| 540 | 0 |         fclose(file); | 
| 541 |  | 
 | 
| 542 | 0 |         file = fsbridge::fopen(m_file_path, "w"); | 
| 543 | 0 |         if (file) | 
| 544 | 0 |         { | 
| 545 | 0 |             fwrite(vch.data(), 1, nBytes, file); | 
| 546 | 0 |             fclose(file); | 
| 547 | 0 |         } | 
| 548 | 0 |     } | 
| 549 | 0 |     else if (file != nullptr) | 
| 550 | 0 |         fclose(file); | 
| 551 | 0 | } | 
| 552 |  |  | 
| 553 |  | void BCLog::LogRateLimiter::Reset() | 
| 554 | 0 | { | 
| 555 | 0 |     decltype(m_source_locations) source_locations; | 
| 556 | 0 |     { | 
| 557 | 0 |         StdLockGuard scoped_lock(m_mutex); | 
| 558 | 0 |         source_locations.swap(m_source_locations); | 
| 559 | 0 |         m_suppression_active = false; | 
| 560 | 0 |     } | 
| 561 | 0 |     for (const auto& [source_loc, stats] : source_locations) { | 
| 562 | 0 |         if (stats.m_dropped_bytes == 0) continue; | 
| 563 | 0 |         LogPrintLevel_( | 
| 564 | 0 |             LogFlags::ALL, Level::Warning, /*should_ratelimit=*/false, | 
| 565 | 0 |             "Restarting logging from %s:%d (%s): %d bytes were dropped during the last %ss.", | 
| 566 | 0 |             source_loc.file_name(), source_loc.line(), source_loc.function_name(), | 
| 567 | 0 |             stats.m_dropped_bytes, Ticks<std::chrono::seconds>(m_reset_window)); | 
| 568 | 0 |     } | 
| 569 | 0 | } | 
| 570 |  |  | 
| 571 |  | bool BCLog::LogRateLimiter::Stats::Consume(uint64_t bytes) | 
| 572 | 0 | { | 
| 573 | 0 |     if (bytes > m_available_bytes) { | 
| 574 | 0 |         m_dropped_bytes += bytes; | 
| 575 | 0 |         m_available_bytes = 0; | 
| 576 | 0 |         return false; | 
| 577 | 0 |     } | 
| 578 |  |  | 
| 579 | 0 |     m_available_bytes -= bytes; | 
| 580 | 0 |     return true; | 
| 581 | 0 | } | 
| 582 |  |  | 
| 583 |  | bool BCLog::Logger::SetLogLevel(std::string_view level_str) | 
| 584 | 0 | { | 
| 585 | 0 |     const auto level = GetLogLevel(level_str); | 
| 586 | 0 |     if (!level.has_value() || level.value() > MAX_USER_SETABLE_SEVERITY_LEVEL) return false; | 
| 587 | 0 |     m_log_level = level.value(); | 
| 588 | 0 |     return true; | 
| 589 | 0 | } | 
| 590 |  |  | 
| 591 |  | bool BCLog::Logger::SetCategoryLogLevel(std::string_view category_str, std::string_view level_str) | 
| 592 | 0 | { | 
| 593 | 0 |     BCLog::LogFlags flag; | 
| 594 | 0 |     if (!GetLogCategory(flag, category_str)) return false; | 
| 595 |  |  | 
| 596 | 0 |     const auto level = GetLogLevel(level_str); | 
| 597 | 0 |     if (!level.has_value() || level.value() > MAX_USER_SETABLE_SEVERITY_LEVEL) return false; | 
| 598 |  |  | 
| 599 | 0 |     StdLockGuard scoped_lock(m_cs); | 
| 600 | 0 |     m_category_log_levels[flag] = level.value(); | 
| 601 | 0 |     return true; | 
| 602 | 0 | } |