diff options
Diffstat (limited to 'src/logging.cpp')
| -rw-r--r-- | src/logging.cpp | 228 |
1 files changed, 109 insertions, 119 deletions
diff --git a/src/logging.cpp b/src/logging.cpp index e481582321..e8e22cbf97 100644 --- a/src/logging.cpp +++ b/src/logging.cpp @@ -4,97 +4,93 @@ // file COPYING or http://www.opensource.org/licenses/mit-license.php. #include <logging.h> -#include <util.h> -#include <utilstrencodings.h> - -#include <list> -#include <mutex> +#include <utiltime.h> const char * const DEFAULT_DEBUGLOGFILE = "debug.log"; -bool fPrintToConsole = false; -bool fPrintToDebugLog = true; - -bool fLogTimestamps = DEFAULT_LOGTIMESTAMPS; -bool fLogTimeMicros = DEFAULT_LOGTIMEMICROS; -bool fLogIPs = DEFAULT_LOGIPS; -std::atomic<bool> fReopenDebugLog(false); - -/** Log categories bitfield. */ -std::atomic<uint32_t> logCategories(0); -/** - * LogPrintf() has been broken a couple of times now - * by well-meaning people adding mutexes in the most straightforward way. - * It breaks because it may be called by global destructors during shutdown. - * Since the order of destruction of static/global objects is undefined, - * defining a mutex as a global object doesn't work (the mutex gets - * destroyed, and then some later destructor calls OutputDebugStringF, - * maybe indirectly, and you get a core dump at shutdown trying to lock - * the mutex). - */ - -static std::once_flag debugPrintInitFlag; - /** - * We use std::call_once() to make sure mutexDebugLog and - * vMsgsBeforeOpenLog are initialized in a thread-safe manner. + * 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. * - * NOTE: fileout, mutexDebugLog and sometimes vMsgsBeforeOpenLog - * are leaked on exit. This is ugly, but will be cleaned up by - * the OS/libc. When the shutdown sequence is fully audited and - * tested, explicit destruction of these objects can be implemented. + * This method of initialization was originally introduced in + * ee3374234c60aba2cc4c5cd5cac1c0aefc2d817c. */ -static FILE* fileout = nullptr; -static std::mutex* mutexDebugLog = nullptr; -static std::list<std::string>* vMsgsBeforeOpenLog; +BCLog::Logger* const g_logger = new BCLog::Logger(); + +bool fLogIPs = DEFAULT_LOGIPS; static int FileWriteStr(const std::string &str, FILE *fp) { return fwrite(str.data(), 1, str.size(), fp); } -static void DebugPrintInit() +bool BCLog::Logger::OpenDebugLog() { - assert(mutexDebugLog == nullptr); - mutexDebugLog = new std::mutex(); - vMsgsBeforeOpenLog = new std::list<std::string>; + std::lock_guard<std::mutex> scoped_lock(m_file_mutex); + + assert(m_fileout == nullptr); + assert(!m_file_path.empty()); + + m_fileout = fsbridge::fopen(m_file_path, "a"); + if (!m_fileout) { + return false; + } + + setbuf(m_fileout, nullptr); // unbuffered + // dump buffered messages from before we opened the log + while (!m_msgs_before_open.empty()) { + FileWriteStr(m_msgs_before_open.front(), m_fileout); + m_msgs_before_open.pop_front(); + } + + return true; } -fs::path GetDebugLogPath() +void BCLog::Logger::EnableCategory(BCLog::LogFlags flag) { - fs::path logfile(gArgs.GetArg("-debuglogfile", DEFAULT_DEBUGLOGFILE)); - return AbsPathForConfigVal(logfile); + m_categories |= flag; } -bool OpenDebugLog() +bool BCLog::Logger::EnableCategory(const std::string& str) { - std::call_once(debugPrintInitFlag, &DebugPrintInit); - std::lock_guard<std::mutex> scoped_lock(*mutexDebugLog); + BCLog::LogFlags flag; + if (!GetLogCategory(flag, str)) return false; + EnableCategory(flag); + return true; +} - assert(fileout == nullptr); - assert(vMsgsBeforeOpenLog); - fs::path pathDebug = GetDebugLogPath(); +void BCLog::Logger::DisableCategory(BCLog::LogFlags flag) +{ + m_categories &= ~flag; +} - fileout = fsbridge::fopen(pathDebug, "a"); - if (!fileout) { - return false; - } +bool BCLog::Logger::DisableCategory(const std::string& str) +{ + BCLog::LogFlags flag; + if (!GetLogCategory(flag, str)) return false; + DisableCategory(flag); + return true; +} - setbuf(fileout, nullptr); // unbuffered - // dump buffered messages from before we opened the log - while (!vMsgsBeforeOpenLog->empty()) { - FileWriteStr(vMsgsBeforeOpenLog->front(), fileout); - vMsgsBeforeOpenLog->pop_front(); - } +bool BCLog::Logger::WillLogCategory(BCLog::LogFlags category) const +{ + return (m_categories.load(std::memory_order_relaxed) & category) != 0; +} - delete vMsgsBeforeOpenLog; - vMsgsBeforeOpenLog = nullptr; - return true; +bool BCLog::Logger::DefaultShrinkDebugFile() const +{ + return m_categories == BCLog::NONE; } struct CLogCategoryDesc { - uint32_t flag; + BCLog::LogFlags flag; std::string category; }; @@ -127,19 +123,17 @@ const CLogCategoryDesc LogCategories[] = {BCLog::ALL, "all"}, }; -bool GetLogCategory(uint32_t *f, const std::string *str) +bool GetLogCategory(BCLog::LogFlags& flag, const std::string& str) { - if (f && str) { - if (*str == "") { - *f = BCLog::ALL; + if (str == "") { + flag = BCLog::ALL; + return true; + } + for (const CLogCategoryDesc& category_desc : LogCategories) { + if (category_desc.category == str) { + flag = category_desc.flag; return true; } - for (unsigned int i = 0; i < ARRAYLEN(LogCategories); i++) { - if (LogCategories[i].category == *str) { - *f = LogCategories[i].flag; - return true; - } - } } return false; } @@ -148,11 +142,11 @@ std::string ListLogCategories() { std::string ret; int outcount = 0; - for (unsigned int i = 0; i < ARRAYLEN(LogCategories); i++) { + for (const CLogCategoryDesc& category_desc : LogCategories) { // Omit the special cases. - if (LogCategories[i].flag != BCLog::NONE && LogCategories[i].flag != BCLog::ALL) { + if (category_desc.flag != BCLog::NONE && category_desc.flag != BCLog::ALL) { if (outcount != 0) ret += ", "; - ret += LogCategories[i].category; + ret += category_desc.category; outcount++; } } @@ -162,34 +156,29 @@ std::string ListLogCategories() std::vector<CLogCategoryActive> ListActiveLogCategories() { std::vector<CLogCategoryActive> ret; - for (unsigned int i = 0; i < ARRAYLEN(LogCategories); i++) { + for (const CLogCategoryDesc& category_desc : LogCategories) { // Omit the special cases. - if (LogCategories[i].flag != BCLog::NONE && LogCategories[i].flag != BCLog::ALL) { + if (category_desc.flag != BCLog::NONE && category_desc.flag != BCLog::ALL) { CLogCategoryActive catActive; - catActive.category = LogCategories[i].category; - catActive.active = LogAcceptCategory(LogCategories[i].flag); + catActive.category = category_desc.category; + catActive.active = LogAcceptCategory(category_desc.flag); ret.push_back(catActive); } } return ret; } -/** - * fStartedNewLine is a state variable held by the calling context that will - * suppress printing of the timestamp when multiple calls are made that don't - * end in a newline. Initialize it to true, and hold it, in the calling context. - */ -static std::string LogTimestampStr(const std::string &str, std::atomic_bool *fStartedNewLine) +std::string BCLog::Logger::LogTimestampStr(const std::string &str) { std::string strStamped; - if (!fLogTimestamps) + if (!m_log_timestamps) return str; - if (*fStartedNewLine) { + if (m_started_new_line) { int64_t nTimeMicros = GetTimeMicros(); strStamped = FormatISO8601DateTime(nTimeMicros/1000000); - if (fLogTimeMicros) { + if (m_log_time_micros) { strStamped.pop_back(); strStamped += strprintf(".%06dZ", nTimeMicros%1000000); } @@ -202,63 +191,60 @@ static std::string LogTimestampStr(const std::string &str, std::atomic_bool *fSt strStamped = str; if (!str.empty() && str[str.size()-1] == '\n') - *fStartedNewLine = true; + m_started_new_line = true; else - *fStartedNewLine = false; + m_started_new_line = false; return strStamped; } -int LogPrintStr(const std::string &str) +void BCLog::Logger::LogPrintStr(const std::string &str) { - int ret = 0; // Returns total number of characters written - static std::atomic_bool fStartedNewLine(true); - - std::string strTimestamped = LogTimestampStr(str, &fStartedNewLine); + std::string strTimestamped = LogTimestampStr(str); - if (fPrintToConsole) { + if (m_print_to_console) { // print to console - ret = fwrite(strTimestamped.data(), 1, strTimestamped.size(), stdout); + fwrite(strTimestamped.data(), 1, strTimestamped.size(), stdout); fflush(stdout); } - if (fPrintToDebugLog) { - std::call_once(debugPrintInitFlag, &DebugPrintInit); - std::lock_guard<std::mutex> scoped_lock(*mutexDebugLog); + if (m_print_to_file) { + std::lock_guard<std::mutex> scoped_lock(m_file_mutex); // buffer if we haven't opened the log yet - if (fileout == nullptr) { - assert(vMsgsBeforeOpenLog); - ret = strTimestamped.length(); - vMsgsBeforeOpenLog->push_back(strTimestamped); + if (m_fileout == nullptr) { + m_msgs_before_open.push_back(strTimestamped); } else { // reopen the log file, if requested - if (fReopenDebugLog) { - fReopenDebugLog = false; - fs::path pathDebug = GetDebugLogPath(); - if (fsbridge::freopen(pathDebug,"a",fileout) != nullptr) - setbuf(fileout, nullptr); // unbuffered + if (m_reopen_file) { + m_reopen_file = false; + m_fileout = fsbridge::freopen(m_file_path, "a", m_fileout); + if (!m_fileout) { + return; + } + setbuf(m_fileout, nullptr); // unbuffered } - ret = FileWriteStr(strTimestamped, fileout); + FileWriteStr(strTimestamped, m_fileout); } } - return ret; } -void ShrinkDebugFile() +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 - fs::path pathLog = GetDebugLogPath(); - FILE* file = fsbridge::fopen(pathLog, "r"); + 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(pathLog); + log_size = fs::file_size(m_file_path); } catch (boost::filesystem::filesystem_error &) {} // If debug.log file is more than 10% bigger the RECENT_DEBUG_HISTORY_SIZE @@ -267,11 +253,15 @@ void ShrinkDebugFile() { // Restart the file with some of the end std::vector<char> vch(RECENT_DEBUG_HISTORY_SIZE, 0); - fseek(file, -((long)vch.size()), SEEK_END); + 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(pathLog, "w"); + file = fsbridge::fopen(m_file_path, "w"); if (file) { fwrite(vch.data(), 1, nBytes, file); |