/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 | } |