diff --git a/src/logging.cpp b/src/logging.cpp index f0b00f8cc..32186e53a 100644 --- a/src/logging.cpp +++ b/src/logging.cpp @@ -1,360 +1,360 @@ // Copyright (c) 2009-2010 Satoshi Nakamoto // Copyright (c) 2009-2016 The Bitcoin Core developers // Copyright (c) 2017-2019 The Bitcoin developers // Distributed under the MIT software license, see the accompanying // file COPYING or http://www.opensource.org/licenses/mit-license.php. #include #include #include bool fLogIPs = DEFAULT_LOGIPS; const char *const DEFAULT_DEBUGLOGFILE = "debug.log"; BCLog::Logger &LogInstance() { /** * NOTE: the logger instance 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; } static int FileWriteStr(const std::string &str, FILE *fp) { return fwrite(str.data(), 1, str.size(), fp); } bool BCLog::Logger::StartLogging() { - LockGuard scoped_lock(m_cs); + 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; } // Unbuffered. setbuf(m_fileout, nullptr); // 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; while (!m_msgs_before_open.empty()) { const std::string &s = m_msgs_before_open.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_msgs_before_open.pop_front(); } if (m_print_to_console) { fflush(stdout); } return true; } void BCLog::Logger::DisconnectTestLogger() { - LockGuard scoped_lock(m_cs); + StdLockGuard scoped_lock(m_cs); m_buffering = true; if (m_fileout != nullptr) { fclose(m_fileout); } m_fileout = nullptr; m_print_callbacks.clear(); } struct CLogCategoryDesc { BCLog::LogFlags flag; std::string category; }; const CLogCategoryDesc LogCategories[] = { {BCLog::NONE, "0"}, {BCLog::NONE, "none"}, {BCLog::NET, "net"}, {BCLog::TOR, "tor"}, {BCLog::MEMPOOL, "mempool"}, {BCLog::HTTP, "http"}, {BCLog::BENCH, "bench"}, {BCLog::ZMQ, "zmq"}, {BCLog::WALLETDB, "walletdb"}, {BCLog::RPC, "rpc"}, {BCLog::ESTIMATEFEE, "estimatefee"}, {BCLog::ADDRMAN, "addrman"}, {BCLog::SELECTCOINS, "selectcoins"}, {BCLog::REINDEX, "reindex"}, {BCLog::CMPCTBLOCK, "cmpctblock"}, {BCLog::RAND, "rand"}, {BCLog::PRUNE, "prune"}, {BCLog::PROXY, "proxy"}, {BCLog::MEMPOOLREJ, "mempoolrej"}, {BCLog::LIBEVENT, "libevent"}, {BCLog::COINDB, "coindb"}, {BCLog::QT, "qt"}, {BCLog::LEVELDB, "leveldb"}, {BCLog::VALIDATION, "validation"}, {BCLog::ALL, "1"}, {BCLog::ALL, "all"}, }; bool GetLogCategory(BCLog::LogFlags &flag, const std::string &str) { if (str == "") { flag = BCLog::ALL; return true; } for (const CLogCategoryDesc &category_desc : LogCategories) { if (category_desc.category == str) { flag = category_desc.flag; return true; } } return false; } std::string ListLogCategories() { std::string ret; int outcount = 0; for (const CLogCategoryDesc &category_desc : LogCategories) { // Omit the special cases. if (category_desc.flag != BCLog::NONE && category_desc.flag != BCLog::ALL) { if (outcount != 0) { ret += ", "; } ret += category_desc.category; outcount++; } } return ret; } std::vector ListActiveLogCategories() { std::vector ret; for (const CLogCategoryDesc &category_desc : LogCategories) { // Omit the special cases. if (category_desc.flag != BCLog::NONE && category_desc.flag != BCLog::ALL) { CLogCategoryActive catActive; catActive.category = category_desc.category; catActive.active = LogAcceptCategory(category_desc.flag); ret.push_back(catActive); } } return ret; } BCLog::Logger::~Logger() { if (m_fileout) { fclose(m_fileout); } } std::string BCLog::Logger::LogTimestampStr(const std::string &str) { std::string strStamped; if (!m_log_timestamps) { return str; } if (m_started_new_line) { int64_t nTimeMicros = GetTimeMicros(); strStamped = FormatISO8601DateTime(nTimeMicros / 1000000); if (m_log_time_micros) { strStamped.pop_back(); strStamped += strprintf(".%06dZ", nTimeMicros % 1000000); } int64_t mocktime = GetMockTime(); if (mocktime) { strStamped += " (mocktime: " + FormatISO8601DateTime(mocktime) + ")"; } strStamped += ' ' + str; } else { strStamped = str; } 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(const std::string &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 void BCLog::Logger::LogPrintStr(const std::string &str) { - LockGuard scoped_lock(m_cs); + StdLockGuard scoped_lock(m_cs); std::string str_prefixed = LogEscapeMessage(str); if (m_log_threadnames && m_started_new_line) { str_prefixed.insert(0, "[" + util::ThreadGetInternalName() + "] "); } str_prefixed = LogTimestampStr(str_prefixed); m_started_new_line = !str.empty() && str[str.size() - 1] == '\n'; if (m_buffering) { // buffer if we haven't started logging yet m_msgs_before_open.push_back(str_prefixed); return; } 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) { // unbuffered. setbuf(m_fileout, nullptr); 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 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); } } void BCLog::Logger::EnableCategory(LogFlags category) { m_categories |= category; } bool BCLog::Logger::EnableCategory(const std::string &str) { BCLog::LogFlags flag; if (!GetLogCategory(flag, str)) { if (str == "db") { // DEPRECATION: Added in 0.22.4, should start returning an error in // a future release LogPrintf("Warning: logging category 'db' is deprecated, use " "'walletdb' instead\n"); EnableCategory(BCLog::WALLETDB); return true; } return false; } EnableCategory(flag); return true; } void BCLog::Logger::DisableCategory(LogFlags category) { m_categories &= ~category; } bool BCLog::Logger::DisableCategory(const std::string &str) { BCLog::LogFlags flag; if (!GetLogCategory(flag, str)) { return false; } DisableCategory(flag); return true; } bool BCLog::Logger::WillLogCategory(LogFlags category) const { // ALL is not meant to be used as a logging category, but only as a mask // representing all categories. if (category == BCLog::NONE || category == BCLog::ALL) { LogPrintf("Error trying to log using a category mask instead of an " "explicit category.\n"); return true; } return (m_categories.load(std::memory_order_relaxed) & category) != 0; } bool BCLog::Logger::DefaultShrinkDebugFile() const { return m_categories != BCLog::NONE; } diff --git a/src/logging.h b/src/logging.h index 240aa422e..e812d08d3 100644 --- a/src/logging.h +++ b/src/logging.h @@ -1,204 +1,204 @@ // Copyright (c) 2009-2010 Satoshi Nakamoto // Copyright (c) 2009-2016 The Bitcoin Core developers // Copyright (c) 2017-2019 The Bitcoin developers // Distributed under the MIT software license, see the accompanying // file COPYING or http://www.opensource.org/licenses/mit-license.php. #ifndef BITCOIN_LOGGING_H #define BITCOIN_LOGGING_H #include #include #include #include #include #include #include #include static const bool DEFAULT_LOGTIMEMICROS = false; static const bool DEFAULT_LOGIPS = false; static const bool DEFAULT_LOGTIMESTAMPS = true; static const bool DEFAULT_LOGTHREADNAMES = false; extern bool fLogIPs; extern const char *const DEFAULT_DEBUGLOGFILE; struct CLogCategoryActive { std::string category; bool active; }; namespace BCLog { enum LogFlags : uint32_t { NONE = 0, NET = (1 << 0), TOR = (1 << 1), MEMPOOL = (1 << 2), HTTP = (1 << 3), BENCH = (1 << 4), ZMQ = (1 << 5), WALLETDB = (1 << 6), RPC = (1 << 7), ESTIMATEFEE = (1 << 8), ADDRMAN = (1 << 9), SELECTCOINS = (1 << 10), REINDEX = (1 << 11), CMPCTBLOCK = (1 << 12), RAND = (1 << 13), PRUNE = (1 << 14), PROXY = (1 << 15), MEMPOOLREJ = (1 << 16), LIBEVENT = (1 << 17), COINDB = (1 << 18), QT = (1 << 19), LEVELDB = (1 << 20), VALIDATION = (1 << 21), ALL = ~uint32_t(0), }; class Logger { private: // Can not use Mutex from sync.h because in debug mode it would cause a // deadlock when a potential deadlock was detected mutable StdMutex m_cs; FILE *m_fileout GUARDED_BY(m_cs) = nullptr; std::list m_msgs_before_open GUARDED_BY(m_cs); //! Buffer messages before logging can be started. bool m_buffering GUARDED_BY(m_cs) = true; /** * m_started_new_line is a state variable that will suppress printing of the * timestamp when multiple calls are made that don't end in a newline. */ std::atomic_bool m_started_new_line{true}; /** * Log categories bitfield. */ std::atomic m_categories{0}; std::string LogTimestampStr(const std::string &str); /** Slots that connect to the print signal */ std::list> m_print_callbacks GUARDED_BY(m_cs){}; public: bool m_print_to_console = false; bool m_print_to_file = false; bool m_log_timestamps = DEFAULT_LOGTIMESTAMPS; bool m_log_time_micros = DEFAULT_LOGTIMEMICROS; bool m_log_threadnames = DEFAULT_LOGTHREADNAMES; fs::path m_file_path; std::atomic m_reopen_file{false}; ~Logger(); /** Send a string to the log output */ void LogPrintStr(const std::string &str); /** Returns whether logs will be written to any output */ bool Enabled() const { - LockGuard scoped_lock(m_cs); + StdLockGuard scoped_lock(m_cs); return m_buffering || m_print_to_console || m_print_to_file || !m_print_callbacks.empty(); } /** Connect a slot to the print signal and return the connection */ std::list>::iterator PushBackCallback(std::function fun) { - LockGuard scoped_lock(m_cs); + StdLockGuard scoped_lock(m_cs); m_print_callbacks.push_back(std::move(fun)); return --m_print_callbacks.end(); } /** Delete a connection */ void DeleteCallback( std::list>::iterator it) { - LockGuard scoped_lock(m_cs); + StdLockGuard scoped_lock(m_cs); m_print_callbacks.erase(it); } /** Start logging (and flush all buffered messages) */ bool StartLogging(); /** Only for testing */ void DisconnectTestLogger(); void ShrinkDebugFile(); uint32_t GetCategoryMask() const { return m_categories.load(); } void EnableCategory(LogFlags category); bool EnableCategory(const std::string &str); void DisableCategory(LogFlags category); bool DisableCategory(const std::string &str); /** Return true if log accepts specified category */ bool WillLogCategory(LogFlags category) const; /** Default for whether ShrinkDebugFile should be run */ bool DefaultShrinkDebugFile() const; }; } // namespace BCLog BCLog::Logger &LogInstance(); /** Return true if log accepts specified category */ static inline bool LogAcceptCategory(BCLog::LogFlags category) { return LogInstance().WillLogCategory(category); } /** Returns a string with the log categories. */ std::string ListLogCategories(); /** Returns a vector of the active log categories. */ std::vector ListActiveLogCategories(); /** Return true if str parses as a log category and set the flag */ bool GetLogCategory(BCLog::LogFlags &flag, const std::string &str); // Be conservative when using LogPrintf/error or other things which // unconditionally log to debug.log! It should not be the case that an inbound // peer can fill up a user's disk with debug.log entries. template static inline void LogPrintf(const char *fmt, const Args &... args) { if (LogInstance().Enabled()) { std::string log_msg; try { log_msg = tfm::format(fmt, args...); } catch (tinyformat::format_error &fmterr) { /** * Original format string will have newline so don't add one here */ log_msg = "Error \"" + std::string(fmterr.what()) + "\" while formatting log message: " + fmt; } LogInstance().LogPrintStr(log_msg); } } // Use a macro instead of a function for conditional logging to prevent // evaluating arguments when logging for the category is not enabled. #define LogPrint(category, ...) \ do { \ if (LogAcceptCategory((category))) { \ LogPrintf(__VA_ARGS__); \ } \ } while (0) /** * These are aliases used to explicitly state that the message should not end * with a newline character. It allows for detecting the missing newlines that * could make the logs hard to read. */ #define LogPrintfToBeContinued LogPrintf #define LogPrintToBeContinued LogPrint #endif // BITCOIN_LOGGING_H diff --git a/src/threadsafety.h b/src/threadsafety.h index d8d77ca88..4cc4afb00 100644 --- a/src/threadsafety.h +++ b/src/threadsafety.h @@ -1,75 +1,75 @@ // Copyright (c) 2009-2010 Satoshi Nakamoto // Copyright (c) 2009-2014 The Bitcoin Core developers // Distributed under the MIT software license, see the accompanying // file COPYING or http://www.opensource.org/licenses/mit-license.php. #ifndef BITCOIN_THREADSAFETY_H #define BITCOIN_THREADSAFETY_H #include #ifdef __clang__ // TL;DR Add GUARDED_BY(mutex) to member variables. The others are rarely // necessary. Ex: int nFoo GUARDED_BY(cs_foo); // // See https://clang.llvm.org/docs/ThreadSafetyAnalysis.html for documentation. // The clang compiler can do advanced static analysis of locking when given the // -Wthread-safety option. #define LOCKABLE __attribute__((lockable)) #define SCOPED_LOCKABLE __attribute__((scoped_lockable)) #define GUARDED_BY(x) __attribute__((guarded_by(x))) #define PT_GUARDED_BY(x) __attribute__((pt_guarded_by(x))) #define ACQUIRED_AFTER(...) __attribute__((acquired_after(__VA_ARGS__))) #define ACQUIRED_BEFORE(...) __attribute__((acquired_before(__VA_ARGS__))) #define EXCLUSIVE_LOCK_FUNCTION(...) \ __attribute__((exclusive_lock_function(__VA_ARGS__))) #define SHARED_LOCK_FUNCTION(...) \ __attribute__((shared_lock_function(__VA_ARGS__))) #define EXCLUSIVE_TRYLOCK_FUNCTION(...) \ __attribute__((exclusive_trylock_function(__VA_ARGS__))) #define SHARED_TRYLOCK_FUNCTION(...) \ __attribute__((shared_trylock_function(__VA_ARGS__))) #define UNLOCK_FUNCTION(...) __attribute__((unlock_function(__VA_ARGS__))) #define LOCK_RETURNED(x) __attribute__((lock_returned(x))) #define LOCKS_EXCLUDED(...) __attribute__((locks_excluded(__VA_ARGS__))) #define EXCLUSIVE_LOCKS_REQUIRED(...) \ __attribute__((exclusive_locks_required(__VA_ARGS__))) #define SHARED_LOCKS_REQUIRED(...) \ __attribute__((shared_locks_required(__VA_ARGS__))) #define NO_THREAD_SAFETY_ANALYSIS __attribute__((no_thread_safety_analysis)) #define ASSERT_EXCLUSIVE_LOCK(...) \ __attribute__((assert_exclusive_lock(__VA_ARGS__))) #else #define LOCKABLE #define SCOPED_LOCKABLE #define GUARDED_BY(x) #define PT_GUARDED_BY(x) #define ACQUIRED_AFTER(...) #define ACQUIRED_BEFORE(...) #define EXCLUSIVE_LOCK_FUNCTION(...) #define SHARED_LOCK_FUNCTION(...) #define EXCLUSIVE_TRYLOCK_FUNCTION(...) #define SHARED_TRYLOCK_FUNCTION(...) #define UNLOCK_FUNCTION(...) #define LOCK_RETURNED(x) #define LOCKS_EXCLUDED(...) #define EXCLUSIVE_LOCKS_REQUIRED(...) #define SHARED_LOCKS_REQUIRED(...) #define NO_THREAD_SAFETY_ANALYSIS #define ASSERT_EXCLUSIVE_LOCK(...) #endif // __GNUC__ // StdMutex provides an annotated version of std::mutex for us, // and should only be used when sync.h Mutex/LOCK/etc are not usable. class LOCKABLE StdMutex : public std::mutex {}; -// LockGuard provides an annotated version of lock_guard for us -// should only be used when sync.h Mutex/LOCK/etc aren't usable -class SCOPED_LOCKABLE LockGuard : public std::lock_guard { +// StdLockGuard provides an annotated version of std::lock_guard for us, +// and should only be used when sync.h Mutex/LOCK/etc are not usable. +class SCOPED_LOCKABLE StdLockGuard : public std::lock_guard { public: - explicit LockGuard(StdMutex &cs) EXCLUSIVE_LOCK_FUNCTION(cs) + explicit StdLockGuard(StdMutex &cs) EXCLUSIVE_LOCK_FUNCTION(cs) : std::lock_guard(cs) {} - ~LockGuard() UNLOCK_FUNCTION(){}; + ~StdLockGuard() UNLOCK_FUNCTION() {} }; #endif // BITCOIN_THREADSAFETY_H