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