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