Inside Bitcoin

251        return "info";
252    case BCLog::Level::Warning:
253        return "warning";
254    case BCLog::Level::Error:
255        return "error";
256    }
257    assert(false);
258}
259
260static std::string LogCategoryToStr(BCLog::LogFlags category)
261{
262    if (category == BCLog::ALL) {
263        return "all";
264    }
265    auto it = LOG_CATEGORIES_BY_FLAG.find(category);
266    assert(it != LOG_CATEGORIES_BY_FLAG.end());
267    return it->second;
268}
269
270static std::optional<BCLog::Level> GetLogLevel(std::string_view level_str)
271{
272    if (level_str == "trace") {
273        return BCLog::Level::Trace;
274    } else if (level_str == "debug") {
275        return BCLog::Level::Debug;
276    } else if (level_str == "info") {
277        return BCLog::Level::Info;
278    } else if (level_str == "warning") {
279        return BCLog::Level::Warning;
280    } else if (level_str == "error") {
281        return BCLog::Level::Error;
282    } else {
283        return std::nullopt;
284    }
285}
286
287std::vector<LogCategory> BCLog::Logger::LogCategoriesList() const
288{
289    std::vector<LogCategory> ret;
290    ret.reserve(LOG_CATEGORIES_BY_STR.size());
291    for (const auto& [category, flag] : LOG_CATEGORIES_BY_STR) {
292        ret.push_back(LogCategory{.category = category, .active = WillLogCategory(flag)});
293    }
294    return ret;
295}
296
297/** Log severity levels that can be selected by the user. */
298static constexpr std::array<BCLog::Level, 3> LogLevelsList()
299{
300    return {BCLog::Level::Info, BCLog::Level::Debug, BCLog::Level::Trace};
301}
302
303std::string BCLog::Logger::LogLevelsString() const
304{
305    const auto& levels = LogLevelsList();
306    return Join(std::vector<BCLog::Level>{levels.begin(), levels.end()}, ", ", [](BCLog::Level level) { return LogLevelToStr(level); });
307}
308
309std::string BCLog::Logger::LogTimestampStr(SystemClock::time_point now, std::chrono::seconds mocktime) const
310{
311    std::string strStamped;
312
313    if (!m_log_timestamps)
314        return strStamped;
315
316    const auto now_seconds{std::chrono::time_point_cast<std::chrono::seconds>(now)};
317    strStamped = FormatISO8601DateTime(TicksSinceEpoch<std::chrono::seconds>(now_seconds));
318    if (m_log_time_micros && !strStamped.empty()) {
319        strStamped.pop_back();
320        strStamped += strprintf(".%06dZ", Ticks<std::chrono::microseconds>(now - now_seconds));
321    }
322    if (mocktime > 0s) {
323        strStamped += " (mocktime: " + FormatISO8601DateTime(count_seconds(mocktime)) + ")";
324    }
325    strStamped += ' ';
326
327    return strStamped;
328}
329
330namespace BCLog {
331    /** Belts and suspenders: make sure outgoing log messages don't contain
332     * potentially suspicious characters, such as terminal control codes.
333     *
334     * This escapes control characters except newline ('\n') in C syntax.
335     * It escapes instead of removes them to still allow for troubleshooting
336     * issues where they accidentally end up in strings.
337     */
338    std::string LogEscapeMessage(std::string_view str) {
339        std::string ret;
340        for (char ch_in : str) {
341            uint8_t ch = (uint8_t)ch_in;
342            if ((ch >= 32 || ch == '\n') && ch != '\x7f') {
343                ret += ch_in;
344            } else {
345                ret += strprintf("\\x%02x", ch);
346            }
347        }
348        return ret;
349    }
350} // namespace BCLog
351
352std::string BCLog::Logger::GetLogPrefix(BCLog::LogFlags category, BCLog::Level level) const
353{
354    if (category == LogFlags::NONE) category = LogFlags::ALL;
355
356    const bool has_category{m_always_print_category_level || category != LogFlags::ALL};
357
358    // If there is no category, Info is implied
359    if (!has_category && level == Level::Info) return {};
360
361    std::string s{"["};
362    if (has_category) {
363        s += LogCategoryToStr(category);
364    }
365
366    if (m_always_print_category_level || !has_category || level != Level::Debug) {
367        // If there is a category, Debug is implied, so don't add the level
368
369        // Only add separator if we have a category
370        if (has_category) s += ":";
371        s += Logger::LogLevelToStr(level);
372    }
373
374    s += "] ";
375    return s;
376}
377
378static size_t MemUsage(const util::log::Entry& log)
379{
380    return memusage::DynamicUsage(log.message) +
381           memusage::DynamicUsage(log.thread_name) +
382           memusage::MallocUsage(sizeof(memusage::list_node<util::log::Entry>));
383}
384
385BCLog::LogRateLimiter::LogRateLimiter(uint64_t max_bytes, std::chrono::seconds reset_window)
386    : m_max_bytes{max_bytes}, m_reset_window{reset_window} {}
387
388std::shared_ptr<BCLog::LogRateLimiter> BCLog::LogRateLimiter::Create(
389    SchedulerFunction&& scheduler_func, uint64_t max_bytes, std::chrono::seconds reset_window)
390{
391    auto limiter{std::shared_ptr<LogRateLimiter>(new LogRateLimiter(max_bytes, reset_window))};
392    std::weak_ptr<LogRateLimiter> weak_limiter{limiter};
393    auto reset = [weak_limiter] {
394        if (auto shared_limiter{weak_limiter.lock()}) shared_limiter->Reset();
395    };
396    scheduler_func(reset, limiter->m_reset_window);
397    return limiter;
398}
399
400BCLog::LogRateLimiter::Status BCLog::LogRateLimiter::Consume(
401    const SourceLocation& source_loc,
402    const std::string& str)
403{
404    STDLOCK(m_mutex);
405    auto& stats{m_source_locations.try_emplace(source_loc, m_max_bytes).first->second};
406    Status status{stats.m_dropped_bytes > 0 ? Status::STILL_SUPPRESSED : Status::UNSUPPRESSED};
407
408    if (!stats.Consume(str.size()) && status == Status::UNSUPPRESSED) {
409        status = Status::NEWLY_SUPPRESSED;
410        m_suppression_active = true;
411    }
412
413    return status;
414}
415
416std::string BCLog::Logger::Format(const util::log::Entry& entry) const
417{
418    std::string result{LogTimestampStr(entry.timestamp, entry.mocktime)};
419
420    if (m_log_threadnames) {
421        result += strprintf("[%s] ", (entry.thread_name.empty() ? "unknown" : entry.thread_name));
422    }
423
424    if (m_log_sourcelocations) {
425        result += strprintf("[%s:%d] [%s] ", RemovePrefixView(entry.source_loc.file_name(), "./"), entry.source_loc.line(), entry.source_loc.function_name_short());
426    }
427
428    result += GetLogPrefix(static_cast<LogFlags>(entry.category), entry.level);
429    result += LogEscapeMessage(entry.message);
430
431    if (!result.ends_with('\n')) result += '\n';
432    return result;
433}
434
435void BCLog::Logger::LogPrint(util::log::Entry entry)
436{
437    STDLOCK(m_cs);
438    return LogPrint_(std::move(entry));
439}
440
441// NOLINTNEXTLINE(misc-no-recursion)
442void BCLog::Logger::LogPrint_(util::log::Entry entry)
443{
444    if (m_buffering) {
445        {
446            m_cur_buffer_memusage += MemUsage(entry);
447            m_msgs_before_open.push_back(std::move(entry));
448        }
449
450        while (m_cur_buffer_memusage > m_max_buffer_memusage) {
451            if (m_msgs_before_open.empty()) {
452                m_cur_buffer_memusage = 0;
453                break;
454            }
455            m_cur_buffer_memusage -= MemUsage(m_msgs_before_open.front());
456            m_msgs_before_open.pop_front();
457            ++m_buffer_lines_discarded;
458        }
459
460        return;
461    }
462
463    std::string str_prefixed{Format(entry)};
464    bool ratelimit{false};
465    if (entry.should_ratelimit && m_limiter) {
466        auto status{m_limiter->Consume(entry.source_loc, str_prefixed)};
467        if (status == LogRateLimiter::Status::NEWLY_SUPPRESSED) {
468            // NOLINTNEXTLINE(misc-no-recursion)
469            LogPrint_({
470                .category = LogFlags::ALL,
471                .level = Level::Warning,
472                .should_ratelimit = false, // with should_ratelimit=false, this cannot lead to infinite recursion
473                .source_loc = SourceLocation{__func__},
474                .message = strprintf(
475                    "Excessive logging detected from %s:%d (%s): >%d bytes logged during "
476                    "the last time window of %is. Suppressing logging to disk from this "
477                    "source location until time window resets. Console logging "
478                    "unaffected. Last log entry.",
479                    entry.source_loc.file_name(), entry.source_loc.line(), entry.source_loc.function_name_short(),
480                    m_limiter->m_max_bytes,
481                    Ticks<std::chrono::seconds>(m_limiter->m_reset_window)),
482            });
483        } else if (status == LogRateLimiter::Status::STILL_SUPPRESSED) {
484            ratelimit = true;
485        }
486    }
487
488    // To avoid confusion caused by dropped log messages when debugging an issue,
489    // we prefix log lines with "[*]" when there are any suppressed source locations.
490    if (m_limiter && m_limiter->SuppressionsActive()) {
491        str_prefixed.insert(0, "[*] ");
492    }
493
494    if (m_print_to_console) {
495        // print to console
496        fwrite(str_prefixed.data(), 1, str_prefixed.size(), stdout);
497        fflush(stdout);
498    }
499    for (const auto& cb : m_print_callbacks) {
500        cb(str_prefixed);