/bitcoin/src/logging.cpp

Source
// Copyright (c) 2009-2010 Satoshi Nakamoto
// Copyright (c) 2009-present The Bitcoin Core developers
// Distributed under the MIT software license, see the accompanying
// file COPYING or http://www.opensource.org/licenses/mit-license.php.

#include <logging.h>
#include <memusage.h>
#include <util/check.h>
#include <util/fs.h>
#include <util/string.h>
#include <util/threadnames.h>
#include <util/time.h>

#include <array>
#include <map>
#include <optional>

using util::Join;
using util::RemovePrefixView;

const char * const DEFAULT_DEBUGLOGFILE = "debug.log";
constexpr auto MAX_USER_SETABLE_SEVERITY_LEVEL{BCLog::Level::Info};

BCLog::Logger& LogInstance()
{
/**
 * NOTE: the logger instances is leaked on exit. This is ugly, but will be
 * cleaned up by the OS/libc. Defining a logger as a global object doesn't work
 * since the order of destruction of static/global objects is undefined.
 * Consider if the logger gets destroyed, and then some later destructor calls
 * LogPrintf, maybe indirectly, and you get a core dump at shutdown trying to
 * access the logger. When the shutdown sequence is fully audited and tested,
 * explicit destruction of these objects can be implemented by changing this
 * from a raw pointer to a std::unique_ptr.
 * Since the ~Logger() destructor is never called, the Logger class and all
 * its subclasses must have implicitly-defined destructors.
 *
 * This method of initialization was originally introduced in
 * ee3374234c60aba2cc4c5cd5cac1c0aefc2d817c.
 */
    static BCLog::Logger* g_logger{new BCLog::Logger()};
    return *g_logger;
}

bool fLogIPs = DEFAULT_LOGIPS;

static int FileWriteStr(std::string_view str, FILE *fp)
{
    return fwrite(str.data(), 1, str.size(), fp);
}

bool BCLog::Logger::StartLogging()
{
    StdLockGuard scoped_lock(m_cs);

    assert(m_buffering);
    assert(m_fileout == nullptr);

    if (m_print_to_file) {
        assert(!m_file_path.empty());
        m_fileout = fsbridge::fopen(m_file_path, "a");
        if (!m_fileout) {
            return false;
        }

        setbuf(m_fileout, nullptr); // unbuffered

        // Add newlines to the logfile to distinguish this execution from the
        // last one.
        FileWriteStr("\n\n\n\n\n", m_fileout);
    }

    // dump buffered messages from before we opened the log
    m_buffering = false;
    if (m_buffer_lines_discarded > 0) {
        LogPrintStr_(strprintf("Early logging buffer overflowed, %d log lines discarded.\n", m_buffer_lines_discarded), __func__, __FILE__, __LINE__, BCLog::ALL, Level::Info);
    }
    while (!m_msgs_before_open.empty()) {
        const auto& buflog = m_msgs_before_open.front();
        std::string s{buflog.str};
        FormatLogStrInPlace(s, buflog.category, buflog.level, buflog.source_file, buflog.source_line, buflog.logging_function, buflog.threadname, buflog.now, buflog.mocktime);
        m_msgs_before_open.pop_front();

        if (m_print_to_file) FileWriteStr(s, m_fileout);
        if (m_print_to_console) fwrite(s.data(), 1, s.size(), stdout);
        for (const auto& cb : m_print_callbacks) {
            cb(s);
        }
    }
    m_cur_buffer_memusage = 0;
    if (m_print_to_console) fflush(stdout);

    return true;
}

void BCLog::Logger::DisconnectTestLogger()
{
    StdLockGuard scoped_lock(m_cs);
    m_buffering = true;
    if (m_fileout != nullptr) fclose(m_fileout);
    m_fileout = nullptr;
    m_print_callbacks.clear();
    m_max_buffer_memusage = DEFAULT_MAX_LOG_BUFFER;
    m_cur_buffer_memusage = 0;
    m_buffer_lines_discarded = 0;
    m_msgs_before_open.clear();
}

void BCLog::Logger::DisableLogging()
{
    {
        StdLockGuard scoped_lock(m_cs);
        assert(m_buffering);
        assert(m_print_callbacks.empty());
    }
    m_print_to_file = false;
    m_print_to_console = false;
    StartLogging();
}

void BCLog::Logger::EnableCategory(BCLog::LogFlags flag)
{
    m_categories |= flag;
}

bool BCLog::Logger::EnableCategory(std::string_view str)
{
    BCLog::LogFlags flag;
    if (!GetLogCategory(flag, str)) return false;
    EnableCategory(flag);
    return true;
}

void BCLog::Logger::DisableCategory(BCLog::LogFlags flag)
{
    m_categories &= ~flag;
}

bool BCLog::Logger::DisableCategory(std::string_view str)
{
    BCLog::LogFlags flag;
    if (!GetLogCategory(flag, str)) return false;
    DisableCategory(flag);
    return true;
}

bool BCLog::Logger::WillLogCategory(BCLog::LogFlags category) const
{
    return (m_categories.load(std::memory_order_relaxed) & category) != 0;
}

bool BCLog::Logger::WillLogCategoryLevel(BCLog::LogFlags category, BCLog::Level level) const
{
    // Log messages at Info, Warning and Error level unconditionally, so that
    // important troubleshooting information doesn't get lost.
    if (level >= BCLog::Level::Info) return true;

    if (!WillLogCategory(category)) return false;

    StdLockGuard scoped_lock(m_cs);
    const auto it{m_category_log_levels.find(category)};
    return level >= (it == m_category_log_levels.end() ? LogLevel() : it->second);
}

bool BCLog::Logger::DefaultShrinkDebugFile() const
{
    return m_categories == BCLog::NONE;
}

static const std::map<std::string, BCLog::LogFlags, std::less<>> LOG_CATEGORIES_BY_STR{
    {"net", BCLog::NET},
    {"tor", BCLog::TOR},
    {"mempool", BCLog::MEMPOOL},
    {"http", BCLog::HTTP},
    {"bench", BCLog::BENCH},
    {"zmq", BCLog::ZMQ},
    {"walletdb", BCLog::WALLETDB},
    {"rpc", BCLog::RPC},
    {"estimatefee", BCLog::ESTIMATEFEE},
    {"addrman", BCLog::ADDRMAN},
    {"selectcoins", BCLog::SELECTCOINS},
    {"reindex", BCLog::REINDEX},
    {"cmpctblock", BCLog::CMPCTBLOCK},
    {"rand", BCLog::RAND},
    {"prune", BCLog::PRUNE},
    {"proxy", BCLog::PROXY},
    {"mempoolrej", BCLog::MEMPOOLREJ},
    {"libevent", BCLog::LIBEVENT},
    {"coindb", BCLog::COINDB},
    {"qt", BCLog::QT},
    {"leveldb", BCLog::LEVELDB},
    {"validation", BCLog::VALIDATION},
    {"i2p", BCLog::I2P},
    {"ipc", BCLog::IPC},
#ifdef DEBUG_LOCKCONTENTION
    {"lock", BCLog::LOCK},
#endif
    {"blockstorage", BCLog::BLOCKSTORAGE},
    {"txreconciliation", BCLog::TXRECONCILIATION},
    {"scan", BCLog::SCAN},
    {"txpackages", BCLog::TXPACKAGES},
};

static const std::unordered_map<BCLog::LogFlags, std::string> LOG_CATEGORIES_BY_FLAG{
    // Swap keys and values from LOG_CATEGORIES_BY_STR.
    [](const auto& in) {
        std::unordered_map<BCLog::LogFlags, std::string> out;
        for (const auto& [k, v] : in) {
            const bool inserted{out.emplace(v, k).second};
            assert(inserted);
        }
        return out;
    }(LOG_CATEGORIES_BY_STR)
};

bool GetLogCategory(BCLog::LogFlags& flag, std::string_view str)
{
    if (str.empty() || str == "1" || str == "all") {
        flag = BCLog::ALL;
        return true;
    }
    auto it = LOG_CATEGORIES_BY_STR.find(str);
    if (it != LOG_CATEGORIES_BY_STR.end()) {
        flag = it->second;
        return true;
    }
    return false;
}

std::string BCLog::Logger::LogLevelToStr(BCLog::Level level)
{
    switch (level) {
    case BCLog::Level::Trace:
        return "trace";
    case BCLog::Level::Debug:
        return "debug";
    case BCLog::Level::Info:
        return "info";
    case BCLog::Level::Warning:
        return "warning";
    case BCLog::Level::Error:
        return "error";
    }
    assert(false);
}

static std::string LogCategoryToStr(BCLog::LogFlags category)
{
    if (category == BCLog::ALL) {
        return "all";
    }
    auto it = LOG_CATEGORIES_BY_FLAG.find(category);
    assert(it != LOG_CATEGORIES_BY_FLAG.end());
    return it->second;
}

static std::optional<BCLog::Level> GetLogLevel(std::string_view level_str)
{
    if (level_str == "trace") {
        return BCLog::Level::Trace;
    } else if (level_str == "debug") {
        return BCLog::Level::Debug;
    } else if (level_str == "info") {
        return BCLog::Level::Info;
    } else if (level_str == "warning") {
        return BCLog::Level::Warning;
    } else if (level_str == "error") {
        return BCLog::Level::Error;
    } else {
        return std::nullopt;
    }
}

std::vector<LogCategory> BCLog::Logger::LogCategoriesList() const
{
    std::vector<LogCategory> ret;
    ret.reserve(LOG_CATEGORIES_BY_STR.size());
    for (const auto& [category, flag] : LOG_CATEGORIES_BY_STR) {
        ret.push_back(LogCategory{.category = category, .active = WillLogCategory(flag)});
    }
    return ret;
}

/** Log severity levels that can be selected by the user. */
static constexpr std::array<BCLog::Level, 3> LogLevelsList()
{
    return {BCLog::Level::Info, BCLog::Level::Debug, BCLog::Level::Trace};
}

std::string BCLog::Logger::LogLevelsString() const
{
    const auto& levels = LogLevelsList();
    return Join(std::vector<BCLog::Level>{levels.begin(), levels.end()}, ", ", [](BCLog::Level level) { return LogLevelToStr(level); });
}

std::string BCLog::Logger::LogTimestampStr(SystemClock::time_point now, std::chrono::seconds mocktime) const
{
    std::string strStamped;

    if (!m_log_timestamps)
        return strStamped;

    const auto now_seconds{std::chrono::time_point_cast<std::chrono::seconds>(now)};
    strStamped = FormatISO8601DateTime(TicksSinceEpoch<std::chrono::seconds>(now_seconds));
    if (m_log_time_micros && !strStamped.empty()) {
        strStamped.pop_back();
        strStamped += strprintf(".%06dZ", Ticks<std::chrono::microseconds>(now - now_seconds));
    }
    if (mocktime > 0s) {
        strStamped += " (mocktime: " + FormatISO8601DateTime(count_seconds(mocktime)) + ")";
    }
    strStamped += ' ';

    return strStamped;
}

namespace BCLog {
    /** Belts and suspenders: make sure outgoing log messages don't contain
     * potentially suspicious characters, such as terminal control codes.
     *
     * This escapes control characters except newline ('\n') in C syntax.
     * It escapes instead of removes them to still allow for troubleshooting
     * issues where they accidentally end up in strings.
     */
    std::string LogEscapeMessage(std::string_view str) {
        std::string ret;
        for (char ch_in : str) {
            uint8_t ch = (uint8_t)ch_in;
            if ((ch >= 32 || ch == '\n') && ch != '\x7f') {
                ret += ch_in;
            } else {
                ret += strprintf("\\x%02x", ch);
            }
        }
        return ret;
    }
} // namespace BCLog

std::string BCLog::Logger::GetLogPrefix(BCLog::LogFlags category, BCLog::Level level) const
{
    if (category == LogFlags::NONE) category = LogFlags::ALL;

    const bool has_category{m_always_print_category_level || category != LogFlags::ALL};

    // If there is no category, Info is implied
    if (!has_category && level == Level::Info) return {};

    std::string s{"["};
    if (has_category) {
        s += LogCategoryToStr(category);
    }

    if (m_always_print_category_level || !has_category || level != Level::Debug) {
        // If there is a category, Debug is implied, so don't add the level

        // Only add separator if we have a category
        if (has_category) s += ":";
        s += Logger::LogLevelToStr(level);
    }

    s += "] ";
    return s;
}

static size_t MemUsage(const BCLog::Logger::BufferedLog& buflog)
{
    return buflog.str.size() + buflog.logging_function.size() + buflog.source_file.size() + buflog.threadname.size() + memusage::MallocUsage(sizeof(memusage::list_node<BCLog::Logger::BufferedLog>));
}

void BCLog::Logger::FormatLogStrInPlace(std::string& str, BCLog::LogFlags category, BCLog::Level level, std::string_view source_file, int source_line, std::string_view logging_function, std::string_view threadname, SystemClock::time_point now, std::chrono::seconds mocktime) const
{
    if (!str.ends_with('\n')) str.push_back('\n');

    str.insert(0, GetLogPrefix(category, level));

    if (m_log_sourcelocations) {
        str.insert(0, strprintf("[%s:%d] [%s] ", RemovePrefixView(source_file, "./"), source_line, logging_function));
    }

    if (m_log_threadnames) {
        str.insert(0, strprintf("[%s] ", (threadname.empty() ? "unknown" : threadname)));
    }

    str.insert(0, LogTimestampStr(now, mocktime));
}

void BCLog::Logger::LogPrintStr(std::string_view str, std::string_view logging_function, std::string_view source_file, int source_line, BCLog::LogFlags category, BCLog::Level level)
{
    StdLockGuard scoped_lock(m_cs);
    return LogPrintStr_(str, logging_function, source_file, source_line, category, level);
}

void BCLog::Logger::LogPrintStr_(std::string_view str, std::string_view logging_function, std::string_view source_file, int source_line, BCLog::LogFlags category, BCLog::Level level)
{
    std::string str_prefixed = LogEscapeMessage(str);

    if (m_buffering) {
        {
            BufferedLog buf{
                .now=SystemClock::now(),
                .mocktime=GetMockTime(),
                .str=str_prefixed,
                .logging_function=std::string(logging_function),
                .source_file=std::string(source_file),
                .threadname=util::ThreadGetInternalName(),
                .source_line=source_line,
                .category=category,
                .level=level,
            };
            m_cur_buffer_memusage += MemUsage(buf);
            m_msgs_before_open.push_back(std::move(buf));
        }

        while (m_cur_buffer_memusage > m_max_buffer_memusage) {
            if (m_msgs_before_open.empty()) {
                m_cur_buffer_memusage = 0;
                break;
            }
            m_cur_buffer_memusage -= MemUsage(m_msgs_before_open.front());
            m_msgs_before_open.pop_front();
            ++m_buffer_lines_discarded;
        }

        return;
    }

    FormatLogStrInPlace(str_prefixed, category, level, source_file, source_line, logging_function, util::ThreadGetInternalName(), SystemClock::now(), GetMockTime());

    if (m_print_to_console) {
        // print to console
        fwrite(str_prefixed.data(), 1, str_prefixed.size(), stdout);
        fflush(stdout);
    }
    for (const auto& cb : m_print_callbacks) {
        cb(str_prefixed);
    }
    if (m_print_to_file) {
        assert(m_fileout != nullptr);

        // reopen the log file, if requested
        if (m_reopen_file) {
            m_reopen_file = false;
            FILE* new_fileout = fsbridge::fopen(m_file_path, "a");
            if (new_fileout) {
                setbuf(new_fileout, nullptr); // unbuffered
                fclose(m_fileout);
                m_fileout = new_fileout;
            }
        }
        FileWriteStr(str_prefixed, m_fileout);
    }
}

void BCLog::Logger::ShrinkDebugFile()
{
    // Amount of debug.log to save at end when shrinking (must fit in memory)
    constexpr size_t RECENT_DEBUG_HISTORY_SIZE = 10 * 1000000;

    assert(!m_file_path.empty());

    // Scroll debug.log if it's getting too big
    FILE* file = fsbridge::fopen(m_file_path, "r");

    // Special files (e.g. device nodes) may not have a size.
    size_t log_size = 0;
    try {
        log_size = fs::file_size(m_file_path);
    } catch (const fs::filesystem_error&) {}

    // If debug.log file is more than 10% bigger the RECENT_DEBUG_HISTORY_SIZE
    // trim it down by saving only the last RECENT_DEBUG_HISTORY_SIZE bytes
    if (file && log_size > 11 * (RECENT_DEBUG_HISTORY_SIZE / 10))
    {
        // Restart the file with some of the end
        std::vector<char> vch(RECENT_DEBUG_HISTORY_SIZE, 0);
        if (fseek(file, -((long)vch.size()), SEEK_END)) {
            LogPrintf("Failed to shrink debug log file: fseek(...) failed\n");
            fclose(file);
            return;
        }
        int nBytes = fread(vch.data(), 1, vch.size(), file);
        fclose(file);

        file = fsbridge::fopen(m_file_path, "w");
        if (file)
        {
            fwrite(vch.data(), 1, nBytes, file);
            fclose(file);
        }
    }
    else if (file != nullptr)
        fclose(file);
}

bool BCLog::Logger::SetLogLevel(std::string_view level_str)
{
    const auto level = GetLogLevel(level_str);
    if (!level.has_value() || level.value() > MAX_USER_SETABLE_SEVERITY_LEVEL) return false;
    m_log_level = level.value();
    return true;
}

bool BCLog::Logger::SetCategoryLogLevel(std::string_view category_str, std::string_view level_str)
{
    BCLog::LogFlags flag;
    if (!GetLogCategory(flag, category_str)) return false;

    const auto level = GetLogLevel(level_str);
    if (!level.has_value() || level.value() > MAX_USER_SETABLE_SEVERITY_LEVEL) return false;

    StdLockGuard scoped_lock(m_cs);
    m_category_log_levels[flag] = level.value();
    return true;
}

Coverage Report

Created: 2025-06-10 13:21

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 <map>
16		#include <optional>
17
18		using util::Join;
19		using util::RemovePrefixView;
20
21		const char * const DEFAULT_DEBUGLOGFILE = "debug.log";
22		constexpr auto MAX_USER_SETABLE_SEVERITY_LEVEL{BCLog::Level::Info};
23
24		BCLog::Logger& LogInstance()
25	290M	{
26		/**
27		* NOTE: the logger instances is leaked on exit. This is ugly, but will be
28		* cleaned up by the OS/libc. Defining a logger as a global object doesn't work
29		* since the order of destruction of static/global objects is undefined.
30		* Consider if the logger gets destroyed, and then some later destructor calls
31		* LogPrintf, maybe indirectly, and you get a core dump at shutdown trying to
32		* access the logger. When the shutdown sequence is fully audited and tested,
33		* explicit destruction of these objects can be implemented by changing this
34		* from a raw pointer to a std::unique_ptr.
35		* Since the ~Logger() destructor is never called, the Logger class and all
36		* its subclasses must have implicitly-defined destructors.
37		*
38		* This method of initialization was originally introduced in
39		* ee3374234c60aba2cc4c5cd5cac1c0aefc2d817c.
40		*/
41	290M	static BCLog::Logger* g_logger{new BCLog::Logger()};
42	290M	return *g_logger;
43	290M	}
44
45		bool fLogIPs = DEFAULT_LOGIPS;
46
47		static int FileWriteStr(std::string_view str, FILE *fp)
48	97.1M	{
49	97.1M	return fwrite(str.data(), 1, str.size(), fp);
50	97.1M	}
51
52		bool BCLog::Logger::StartLogging()
53	11.0k	{
54	11.0k	StdLockGuard scoped_lock(m_cs);
55
56	11.0k	assert(m_buffering); Branch (56:5): [True: 11.0k, False: 0]
57	11.0k	assert(m_fileout == nullptr); Branch (57:5): [True: 11.0k, False: 0]
58
59	11.0k	if (m_print_to_file) { Branch (59:9): [True: 11.0k, False: 0]
60	11.0k	assert(!m_file_path.empty()); Branch (60:9): [True: 11.0k, False: 0]
61	11.0k	m_fileout = fsbridge::fopen(m_file_path, "a");
62	11.0k	if (!m_fileout) { Branch (62:13): [True: 0, False: 11.0k]
63	0	return false;
64	0	}
65
66	11.0k	setbuf(m_fileout, nullptr); // unbuffered
67
68		// Add newlines to the logfile to distinguish this execution from the
69		// last one.
70	11.0k	FileWriteStr("\n\n\n\n\n", m_fileout);
71	11.0k	}
72
73		// dump buffered messages from before we opened the log
74	11.0k	m_buffering = false;
75	11.0k	if (m_buffer_lines_discarded > 0) { Branch (75:9): [True: 0, False: 11.0k]
76	0	LogPrintStr_(strprintf("Early logging buffer overflowed, %d log lines discarded.\n", m_buffer_lines_discarded), __func__, __FILE__, __LINE__, BCLog::ALL, Level::Info);
77	0	}
78	66.5k	while (!m_msgs_before_open.empty()) { Branch (78:12): [True: 55.4k, False: 11.0k]
79	55.4k	const auto& buflog = m_msgs_before_open.front();
80	55.4k	std::string s{buflog.str};
81	55.4k	FormatLogStrInPlace(s, buflog.category, buflog.level, buflog.source_file, buflog.source_line, buflog.logging_function, buflog.threadname, buflog.now, buflog.mocktime);
82	55.4k	m_msgs_before_open.pop_front();
83
84	55.4k	if (m_print_to_file) FileWriteStr(s, m_fileout); Branch (84:13): [True: 55.4k, False: 0]
85	55.4k	if (m_print_to_console) fwrite(s.data(), 1, s.size(), stdout); Branch (85:13): [True: 55.4k, False: 0]
86	55.4k	for (const auto& cb : m_print_callbacks) { Branch (86:29): [True: 0, False: 55.4k]
87	0	cb(s);
88	0	}
89	55.4k	}
90	11.0k	m_cur_buffer_memusage = 0;
91	11.0k	if (m_print_to_console) fflush(stdout); Branch (91:9): [True: 11.0k, False: 0]
92
93	11.0k	return true;
94	11.0k	}
95
96		void BCLog::Logger::DisconnectTestLogger()
97	0	{
98	0	StdLockGuard scoped_lock(m_cs);
99	0	m_buffering = true;
100	0	if (m_fileout != nullptr) fclose(m_fileout); Branch (100:9): [True: 0, False: 0]
101	0	m_fileout = nullptr;
102	0	m_print_callbacks.clear();
103	0	m_max_buffer_memusage = DEFAULT_MAX_LOG_BUFFER;
104	0	m_cur_buffer_memusage = 0;
105	0	m_buffer_lines_discarded = 0;
106	0	m_msgs_before_open.clear();
107	0	}
108
109		void BCLog::Logger::DisableLogging()
110	0	{
111	0	{
112	0	StdLockGuard scoped_lock(m_cs);
113	0	assert(m_buffering); Branch (113:9): [True: 0, False: 0]
114	0	assert(m_print_callbacks.empty()); Branch (114:9): [True: 0, False: 0]
115	0	}
116	0	m_print_to_file = false;
117	0	m_print_to_console = false;
118	0	StartLogging();
119	0	}
120
121		void BCLog::Logger::EnableCategory(BCLog::LogFlags flag)
122	11.0k	{
123	11.0k	m_categories \|= flag;
124	11.0k	}
125
126		bool BCLog::Logger::EnableCategory(std::string_view str)
127	11.0k	{
128	11.0k	BCLog::LogFlags flag;
129	11.0k	if (!GetLogCategory(flag, str)) return false; Branch (129:9): [True: 0, False: 11.0k]
130	11.0k	EnableCategory(flag);
131	11.0k	return true;
132	11.0k	}
133
134		void BCLog::Logger::DisableCategory(BCLog::LogFlags flag)
135	22.1k	{
136	22.1k	m_categories &= ~flag;
137	22.1k	}
138
139		bool BCLog::Logger::DisableCategory(std::string_view str)
140	22.1k	{
141	22.1k	BCLog::LogFlags flag;
142	22.1k	if (!GetLogCategory(flag, str)) return false; Branch (142:9): [True: 0, False: 22.1k]
143	22.1k	DisableCategory(flag);
144	22.1k	return true;
145	22.1k	}
146
147		bool BCLog::Logger::WillLogCategory(BCLog::LogFlags category) const
148	96.9M	{
149	96.9M	return (m_categories.load(std::memory_order_relaxed) & category) != 0;
150	96.9M	}
151
152		bool BCLog::Logger::WillLogCategoryLevel(BCLog::LogFlags category, BCLog::Level level) const
153	95.7M	{
154		// Log messages at Info, Warning and Error level unconditionally, so that
155		// important troubleshooting information doesn't get lost.
156	95.7M	if (level >= BCLog::Level::Info) return true; Branch (156:9): [True: 11.0k, False: 95.7M]
157
158	95.7M	if (!WillLogCategory(category)) return false; Branch (158:9): [True: 2.39M, False: 93.3M]
159
160	93.3M	StdLockGuard scoped_lock(m_cs);
161	93.3M	const auto it{m_category_log_levels.find(category)};
162	18.4E	return level >= (it == m_category_log_levels.end() ? LogLevel() : it->second); Branch (162:22): [True: 93.3M, False: 18.4E]
163	95.7M	}
164
165		bool BCLog::Logger::DefaultShrinkDebugFile() const
166	11.0k	{
167	11.0k	return m_categories == BCLog::NONE;
168	11.0k	}
169
170		static const std::map<std::string, BCLog::LogFlags, std::less<>> LOG_CATEGORIES_BY_STR{
171		{"net", BCLog::NET},
172		{"tor", BCLog::TOR},
173		{"mempool", BCLog::MEMPOOL},
174		{"http", BCLog::HTTP},
175		{"bench", BCLog::BENCH},
176		{"zmq", BCLog::ZMQ},
177		{"walletdb", BCLog::WALLETDB},
178		{"rpc", BCLog::RPC},
179		{"estimatefee", BCLog::ESTIMATEFEE},
180		{"addrman", BCLog::ADDRMAN},
181		{"selectcoins", BCLog::SELECTCOINS},
182		{"reindex", BCLog::REINDEX},
183		{"cmpctblock", BCLog::CMPCTBLOCK},
184		{"rand", BCLog::RAND},
185		{"prune", BCLog::PRUNE},
186		{"proxy", BCLog::PROXY},
187		{"mempoolrej", BCLog::MEMPOOLREJ},
188		{"libevent", BCLog::LIBEVENT},
189		{"coindb", BCLog::COINDB},
190		{"qt", BCLog::QT},
191		{"leveldb", BCLog::LEVELDB},
192		{"validation", BCLog::VALIDATION},
193		{"i2p", BCLog::I2P},
194		{"ipc", BCLog::IPC},
195		#ifdef DEBUG_LOCKCONTENTION
196		{"lock", BCLog::LOCK},
197		#endif
198		{"blockstorage", BCLog::BLOCKSTORAGE},
199		{"txreconciliation", BCLog::TXRECONCILIATION},
200		{"scan", BCLog::SCAN},
201		{"txpackages", BCLog::TXPACKAGES},
202		};
203
204		static const std::unordered_map<BCLog::LogFlags, std::string> LOG_CATEGORIES_BY_FLAG{
205		// Swap keys and values from LOG_CATEGORIES_BY_STR.
206	11.0k	[](const auto& in) {
207	11.0k	std::unordered_map<BCLog::LogFlags, std::string> out;
208	310k	for (const auto& [k, v] : in) { Branch (208:33): [True: 310k, False: 11.0k]
209	310k	const bool inserted{out.emplace(v, k).second};
210	310k	assert(inserted); Branch (210:13): [True: 310k, False: 0]
211	310k	}
212	11.0k	return out;
213	11.0k	}(LOG_CATEGORIES_BY_STR)
214		};
215
216		bool GetLogCategory(BCLog::LogFlags& flag, std::string_view str)
217	33.2k	{
218	33.2k	if (str.empty() \|\| str == "1" \|\| str == "all") { Branch (218:9): [True: 11.0k, False: 22.1k] Branch (218:24): [True: 0, False: 22.1k] Branch (218:38): [True: 0, False: 22.1k]
219	11.0k	flag = BCLog::ALL;
220	11.0k	return true;
221	11.0k	}
222	22.1k	auto it = LOG_CATEGORIES_BY_STR.find(str);
223	22.1k	if (it != LOG_CATEGORIES_BY_STR.end()) { Branch (223:9): [True: 22.1k, False: 0]
224	22.1k	flag = it->second;
225	22.1k	return true;
226	22.1k	}
227	0	return false;
228	22.1k	}
229
230		std::string BCLog::Logger::LogLevelToStr(BCLog::Level level)
231	60.5k	{
232	60.5k	switch (level) { Branch (232:13): [True: 0, False: 60.5k]
233	11.0k	case BCLog::Level::Trace: Branch (233:5): [True: 11.0k, False: 49.4k]
234	11.0k	return "trace";
235	22.1k	case BCLog::Level::Debug: Branch (235:5): [True: 22.1k, False: 38.3k]
236	22.1k	return "debug";
237	11.0k	case BCLog::Level::Info: Branch (237:5): [True: 11.0k, False: 49.4k]
238	11.0k	return "info";
239	11.0k	case BCLog::Level::Warning: Branch (239:5): [True: 11.0k, False: 49.4k]
240	11.0k	return "warning";
241	5.06k	case BCLog::Level::Error: Branch (241:5): [True: 5.06k, False: 55.4k]
242	5.06k	return "error";
243	60.5k	}
244	60.5k	assert(false); Branch (244:5): [Folded - Ignored]
245	0	}
246
247		static std::string LogCategoryToStr(BCLog::LogFlags category)
248	93.2M	{
249	93.2M	if (category == BCLog::ALL) { Branch (249:9): [True: 0, False: 93.2M]
250	0	return "all";
251	0	}
252	93.2M	auto it = LOG_CATEGORIES_BY_FLAG.find(category);
253	93.2M	assert(it != LOG_CATEGORIES_BY_FLAG.end()); Branch (253:5): [True: 93.2M, False: 0]
254	93.2M	return it->second;
255	93.2M	}
256
257		static std::optional<BCLog::Level> GetLogLevel(std::string_view level_str)
258	0	{
259	0	if (level_str == "trace") { Branch (259:9): [True: 0, False: 0]
260	0	return BCLog::Level::Trace;
261	0	} else if (level_str == "debug") { Branch (261:16): [True: 0, False: 0]
262	0	return BCLog::Level::Debug;
263	0	} else if (level_str == "info") { Branch (263:16): [True: 0, False: 0]
264	0	return BCLog::Level::Info;
265	0	} else if (level_str == "warning") { Branch (265:16): [True: 0, False: 0]
266	0	return BCLog::Level::Warning;
267	0	} else if (level_str == "error") { Branch (267:16): [True: 0, False: 0]
268	0	return BCLog::Level::Error;
269	0	} else {
270	0	return std::nullopt;
271	0	}
272	0	}
273
274		std::vector<LogCategory> BCLog::Logger::LogCategoriesList() const
275	44.3k	{
276	44.3k	std::vector<LogCategory> ret;
277	44.3k	ret.reserve(LOG_CATEGORIES_BY_STR.size());
278	1.24M	for (const auto& [category, flag] : LOG_CATEGORIES_BY_STR) { Branch (278:39): [True: 1.24M, False: 44.3k]
279	1.24M	ret.push_back(LogCategory{.category = category, .active = WillLogCategory(flag)});
280	1.24M	}
281	44.3k	return ret;
282	44.3k	}
283
284		/** Log severity levels that can be selected by the user. */
285		static constexpr std::array<BCLog::Level, 3> LogLevelsList()
286	11.0k	{
287	11.0k	return {BCLog::Level::Info, BCLog::Level::Debug, BCLog::Level::Trace};
288	11.0k	}
289
290		std::string BCLog::Logger::LogLevelsString() const
291	11.0k	{
292	11.0k	const auto& levels = LogLevelsList();
293	33.2k	return Join(std::vector<BCLog::Level>{levels.begin(), levels.end()}, ", ", [](BCLog::Level level) { return LogLevelToStr(level); });
294	11.0k	}
295
296		std::string BCLog::Logger::LogTimestampStr(SystemClock::time_point now, std::chrono::seconds mocktime) const
297	97.1M	{
298	97.1M	std::string strStamped;
299
300	97.1M	if (!m_log_timestamps) Branch (300:9): [True: 0, False: 97.1M]
301	0	return strStamped;
302
303	97.1M	const auto now_seconds{std::chrono::time_point_cast<std::chrono::seconds>(now)};
304	97.1M	strStamped = FormatISO8601DateTime(TicksSinceEpoch<std::chrono::seconds>(now_seconds));
305	97.1M	if (m_log_time_micros && !strStamped.empty()) { Branch (305:9): [True: 0, False: 97.1M] Branch (305:30): [True: 0, False: 0]
306	0	strStamped.pop_back();
307	0	strStamped += strprintf(".%06dZ", Ticks<std::chrono::microseconds>(now - now_seconds));
308	0	}
309	97.1M	if (mocktime > 0s) { Branch (309:9): [True: 95.3M, False: 1.70M]
310	95.3M	strStamped += " (mocktime: " + FormatISO8601DateTime(count_seconds(mocktime)) + ")";
311	95.3M	}
312	97.1M	strStamped += ' ';
313
314	97.1M	return strStamped;
315	97.1M	}
316
317		namespace BCLog {
318		/** Belts and suspenders: make sure outgoing log messages don't contain
319		* potentially suspicious characters, such as terminal control codes.
320		*
321		* This escapes control characters except newline ('\n') in C syntax.
322		* It escapes instead of removes them to still allow for troubleshooting
323		* issues where they accidentally end up in strings.
324		*/
325	97.1M	std::string LogEscapeMessage(std::string_view str) {
326	97.1M	std::string ret;
327	7.27G	for (char ch_in : str) { Branch (327:25): [True: 7.27G, False: 97.1M]
328	7.27G	uint8_t ch = (uint8_t)ch_in;
329	7.27G	if ((ch >= 32 \|\| ch == '\n') && ch != '\x7f') { Branch (329:18): [True: 7.17G, False: 96.8M] Branch (329:30): [True: 96.8M, False: 0] Branch (329:45): [True: 7.27G, False: 0]
330	7.27G	ret += ch_in;
331	7.27G	} else {
332	0	ret += strprintf("\\x%02x", ch);
333	0	}
334	7.27G	}
335	97.1M	return ret;
336	97.1M	}
337		} // namespace BCLog
338
339		std::string BCLog::Logger::GetLogPrefix(BCLog::LogFlags category, BCLog::Level level) const
340	97.1M	{
341	97.1M	if (category == LogFlags::NONE) category = LogFlags::ALL; Branch (341:9): [True: 0, False: 97.1M]
342
343	97.1M	const bool has_category{m_always_print_category_level \|\| category != LogFlags::ALL}; Branch (343:29): [True: 0, False: 97.1M] Branch (343:62): [True: 93.2M, False: 3.82M]
344
345		// If there is no category, Info is implied
346	97.1M	if (!has_category && level == Level::Info) return {}; Branch (346:9): [True: 3.82M, False: 93.2M] Branch (346:26): [True: 3.82M, False: 5.06k]
347
348	93.2M	std::string s{"["};
349	93.2M	if (has_category) { Branch (349:9): [True: 93.2M, False: 5.06k]
350	93.2M	s += LogCategoryToStr(category);
351	93.2M	}
352
353	93.2M	if (m_always_print_category_level \|\| !has_category \|\| level != Level::Debug) { Branch (353:9): [True: 0, False: 93.2M] Branch (353:42): [True: 5.06k, False: 93.2M] Branch (353:59): [True: 11.0k, False: 93.2M]
354		// If there is a category, Debug is implied, so don't add the level
355
356		// Only add separator if we have a category
357	16.1k	if (has_category) s += ":"; Branch (357:13): [True: 11.0k, False: 5.06k]
358	16.1k	s += Logger::LogLevelToStr(level);
359	16.1k	}
360
361	93.2M	s += "] ";
362	93.2M	return s;
363	97.1M	}
364
365		static size_t MemUsage(const BCLog::Logger::BufferedLog& buflog)
366	55.4k	{
367	55.4k	return buflog.str.size() + buflog.logging_function.size() + buflog.source_file.size() + buflog.threadname.size() + memusage::MallocUsage(sizeof(memusage::list_node<BCLog::Logger::BufferedLog>));
368	55.4k	}
369
370		void BCLog::Logger::FormatLogStrInPlace(std::string& str, BCLog::LogFlags category, BCLog::Level level, std::string_view source_file, int source_line, std::string_view logging_function, std::string_view threadname, SystemClock::time_point now, std::chrono::seconds mocktime) const
371	97.1M	{
372	97.1M	if (!str.ends_with('\n')) str.push_back('\n'); Branch (372:9): [True: 265k, False: 96.8M]
373
374	97.1M	str.insert(0, GetLogPrefix(category, level));
375
376	97.1M	if (m_log_sourcelocations) { Branch (376:9): [True: 0, False: 97.1M]
377	0	str.insert(0, strprintf("[%s:%d] [%s] ", RemovePrefixView(source_file, "./"), source_line, logging_function));
378	0	}
379
380	97.1M	if (m_log_threadnames) { Branch (380:9): [True: 0, False: 97.1M]
381	0	str.insert(0, strprintf("[%s] ", (threadname.empty() ? "unknown" : threadname))); Branch (381:43): [True: 0, False: 0]
382	0	}
383
384	97.1M	str.insert(0, LogTimestampStr(now, mocktime));
385	97.1M	}
386
387		void BCLog::Logger::LogPrintStr(std::string_view str, std::string_view logging_function, std::string_view source_file, int source_line, BCLog::LogFlags category, BCLog::Level level)
388	97.0M	{
389	97.0M	StdLockGuard scoped_lock(m_cs);
390	97.0M	return LogPrintStr_(str, logging_function, source_file, source_line, category, level);
391	97.0M	}
392
393		void BCLog::Logger::LogPrintStr_(std::string_view str, std::string_view logging_function, std::string_view source_file, int source_line, BCLog::LogFlags category, BCLog::Level level)
394	97.1M	{
395	97.1M	std::string str_prefixed = LogEscapeMessage(str);
396
397	97.1M	if (m_buffering) { Branch (397:9): [True: 55.4k, False: 97.0M]
398	55.4k	{
399	55.4k	BufferedLog buf{
400	55.4k	.now=SystemClock::now(),
401	55.4k	.mocktime=GetMockTime(),
402	55.4k	.str=str_prefixed,
403	55.4k	.logging_function=std::string(logging_function),
404	55.4k	.source_file=std::string(source_file),
405	55.4k	.threadname=util::ThreadGetInternalName(),
406	55.4k	.source_line=source_line,
407	55.4k	.category=category,
408	55.4k	.level=level,
409	55.4k	};
410	55.4k	m_cur_buffer_memusage += MemUsage(buf);
411	55.4k	m_msgs_before_open.push_back(std::move(buf));
412	55.4k	}
413
414	55.4k	while (m_cur_buffer_memusage > m_max_buffer_memusage) { Branch (414:16): [True: 0, False: 55.4k]
415	0	if (m_msgs_before_open.empty()) { Branch (415:17): [True: 0, False: 0]
416	0	m_cur_buffer_memusage = 0;
417	0	break;
418	0	}
419	0	m_cur_buffer_memusage -= MemUsage(m_msgs_before_open.front());
420	0	m_msgs_before_open.pop_front();
421	0	++m_buffer_lines_discarded;
422	0	}
423
424	55.4k	return;
425	55.4k	}
426
427	97.0M	FormatLogStrInPlace(str_prefixed, category, level, source_file, source_line, logging_function, util::ThreadGetInternalName(), SystemClock::now(), GetMockTime());
428
429	97.0M	if (m_print_to_console) { Branch (429:9): [True: 97.0M, False: 0]
430		// print to console
431	97.0M	fwrite(str_prefixed.data(), 1, str_prefixed.size(), stdout);
432	97.0M	fflush(stdout);
433	97.0M	}
434	97.0M	for (const auto& cb : m_print_callbacks) { Branch (434:25): [True: 0, False: 97.0M]
435	0	cb(str_prefixed);
436	0	}
437	97.0M	if (m_print_to_file) { Branch (437:9): [True: 97.0M, False: 0]
438	97.0M	assert(m_fileout != nullptr); Branch (438:9): [True: 97.0M, False: 0]
439
440		// reopen the log file, if requested
441	97.0M	if (m_reopen_file) { Branch (441:13): [True: 0, False: 97.0M]
442	0	m_reopen_file = false;
443	0	FILE* new_fileout = fsbridge::fopen(m_file_path, "a");
444	0	if (new_fileout) { Branch (444:17): [True: 0, False: 0]
445	0	setbuf(new_fileout, nullptr); // unbuffered
446	0	fclose(m_fileout);
447	0	m_fileout = new_fileout;
448	0	}
449	0	}
450	97.0M	FileWriteStr(str_prefixed, m_fileout);
451	97.0M	}
452	97.0M	}
453
454		void BCLog::Logger::ShrinkDebugFile()
455	0	{
456		// Amount of debug.log to save at end when shrinking (must fit in memory)
457	0	constexpr size_t RECENT_DEBUG_HISTORY_SIZE = 10 * 1000000;
458
459	0	assert(!m_file_path.empty()); Branch (459:5): [True: 0, False: 0]
460
461		// Scroll debug.log if it's getting too big
462	0	FILE* file = fsbridge::fopen(m_file_path, "r");
463
464		// Special files (e.g. device nodes) may not have a size.
465	0	size_t log_size = 0;
466	0	try {
467	0	log_size = fs::file_size(m_file_path);
468	0	} catch (const fs::filesystem_error&) {}
469
470		// If debug.log file is more than 10% bigger the RECENT_DEBUG_HISTORY_SIZE
471		// trim it down by saving only the last RECENT_DEBUG_HISTORY_SIZE bytes
472	0	if (file && log_size > 11 * (RECENT_DEBUG_HISTORY_SIZE / 10)) Branch (472:9): [True: 0, False: 0] Branch (472:17): [True: 0, False: 0]
473	0	{
474		// Restart the file with some of the end
475	0	std::vector<char> vch(RECENT_DEBUG_HISTORY_SIZE, 0);
476	0	if (fseek(file, -((long)vch.size()), SEEK_END)) { Branch (476:13): [True: 0, False: 0]
477	0	LogPrintf("Failed to shrink debug log file: fseek(...) failed\n");
478	0	fclose(file);
479	0	return;
480	0	}
481	0	int nBytes = fread(vch.data(), 1, vch.size(), file);
482	0	fclose(file);
483
484	0	file = fsbridge::fopen(m_file_path, "w");
485	0	if (file) Branch (485:13): [True: 0, False: 0]
486	0	{
487	0	fwrite(vch.data(), 1, nBytes, file);
488	0	fclose(file);
489	0	}
490	0	}
491	0	else if (file != nullptr) Branch (491:14): [True: 0, False: 0]
492	0	fclose(file);
493	0	}
494
495		bool BCLog::Logger::SetLogLevel(std::string_view level_str)
496	0	{
497	0	const auto level = GetLogLevel(level_str);
498	0	if (!level.has_value() \|\| level.value() > MAX_USER_SETABLE_SEVERITY_LEVEL) return false; Branch (498:9): [True: 0, False: 0] Branch (498:31): [True: 0, False: 0]
499	0	m_log_level = level.value();
500	0	return true;
501	0	}
502
503		bool BCLog::Logger::SetCategoryLogLevel(std::string_view category_str, std::string_view level_str)
504	0	{
505	0	BCLog::LogFlags flag;
506	0	if (!GetLogCategory(flag, category_str)) return false; Branch (506:9): [True: 0, False: 0]
507
508	0	const auto level = GetLogLevel(level_str);
509	0	if (!level.has_value() \|\| level.value() > MAX_USER_SETABLE_SEVERITY_LEVEL) return false; Branch (509:9): [True: 0, False: 0] Branch (509:31): [True: 0, False: 0]
510
511	0	StdLockGuard scoped_lock(m_cs);
512	0	m_category_log_levels[flag] = level.value();
513	0	return true;
514	0	}