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