From b77b6e23457dcbf160a3d586eca9df7a8d0bb351 Mon Sep 17 00:00:00 2001 From: Jim Posen Date: Wed, 18 Apr 2018 10:05:05 -0700 Subject: MOVEONLY: Move logging code from util.{h,cpp} to new files. --- src/logging.cpp | 283 ++++++++++++++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 283 insertions(+) create mode 100644 src/logging.cpp (limited to 'src/logging.cpp') diff --git a/src/logging.cpp b/src/logging.cpp new file mode 100644 index 0000000000..e481582321 --- /dev/null +++ b/src/logging.cpp @@ -0,0 +1,283 @@ +// Copyright (c) 2009-2010 Satoshi Nakamoto +// Copyright (c) 2009-2018 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 +#include +#include + +#include +#include + +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 fReopenDebugLog(false); + +/** Log categories bitfield. */ +std::atomic 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: 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. + */ +static FILE* fileout = nullptr; +static std::mutex* mutexDebugLog = nullptr; +static std::list* vMsgsBeforeOpenLog; + +static int FileWriteStr(const std::string &str, FILE *fp) +{ + return fwrite(str.data(), 1, str.size(), fp); +} + +static void DebugPrintInit() +{ + assert(mutexDebugLog == nullptr); + mutexDebugLog = new std::mutex(); + vMsgsBeforeOpenLog = new std::list; +} + +fs::path GetDebugLogPath() +{ + fs::path logfile(gArgs.GetArg("-debuglogfile", DEFAULT_DEBUGLOGFILE)); + return AbsPathForConfigVal(logfile); +} + +bool OpenDebugLog() +{ + std::call_once(debugPrintInitFlag, &DebugPrintInit); + std::lock_guard scoped_lock(*mutexDebugLog); + + assert(fileout == nullptr); + assert(vMsgsBeforeOpenLog); + fs::path pathDebug = GetDebugLogPath(); + + fileout = fsbridge::fopen(pathDebug, "a"); + if (!fileout) { + return false; + } + + setbuf(fileout, nullptr); // unbuffered + // dump buffered messages from before we opened the log + while (!vMsgsBeforeOpenLog->empty()) { + FileWriteStr(vMsgsBeforeOpenLog->front(), fileout); + vMsgsBeforeOpenLog->pop_front(); + } + + delete vMsgsBeforeOpenLog; + vMsgsBeforeOpenLog = nullptr; + return true; +} + +struct CLogCategoryDesc +{ + uint32_t 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::DB, "db"}, + {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::ALL, "1"}, + {BCLog::ALL, "all"}, +}; + +bool GetLogCategory(uint32_t *f, const std::string *str) +{ + if (f && str) { + if (*str == "") { + *f = BCLog::ALL; + return true; + } + for (unsigned int i = 0; i < ARRAYLEN(LogCategories); i++) { + if (LogCategories[i].category == *str) { + *f = LogCategories[i].flag; + return true; + } + } + } + return false; +} + +std::string ListLogCategories() +{ + std::string ret; + int outcount = 0; + for (unsigned int i = 0; i < ARRAYLEN(LogCategories); i++) { + // Omit the special cases. + if (LogCategories[i].flag != BCLog::NONE && LogCategories[i].flag != BCLog::ALL) { + if (outcount != 0) ret += ", "; + ret += LogCategories[i].category; + outcount++; + } + } + return ret; +} + +std::vector ListActiveLogCategories() +{ + std::vector ret; + for (unsigned int i = 0; i < ARRAYLEN(LogCategories); i++) { + // Omit the special cases. + if (LogCategories[i].flag != BCLog::NONE && LogCategories[i].flag != BCLog::ALL) { + CLogCategoryActive catActive; + catActive.category = LogCategories[i].category; + catActive.active = LogAcceptCategory(LogCategories[i].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 strStamped; + + if (!fLogTimestamps) + return str; + + if (*fStartedNewLine) { + int64_t nTimeMicros = GetTimeMicros(); + strStamped = FormatISO8601DateTime(nTimeMicros/1000000); + if (fLogTimeMicros) { + strStamped.pop_back(); + strStamped += strprintf(".%06dZ", nTimeMicros%1000000); + } + int64_t mocktime = GetMockTime(); + if (mocktime) { + strStamped += " (mocktime: " + FormatISO8601DateTime(mocktime) + ")"; + } + strStamped += ' ' + str; + } else + strStamped = str; + + if (!str.empty() && str[str.size()-1] == '\n') + *fStartedNewLine = true; + else + *fStartedNewLine = false; + + return strStamped; +} + +int 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); + + if (fPrintToConsole) { + // print to console + ret = fwrite(strTimestamped.data(), 1, strTimestamped.size(), stdout); + fflush(stdout); + } + if (fPrintToDebugLog) { + std::call_once(debugPrintInitFlag, &DebugPrintInit); + std::lock_guard scoped_lock(*mutexDebugLog); + + // buffer if we haven't opened the log yet + if (fileout == nullptr) { + assert(vMsgsBeforeOpenLog); + ret = strTimestamped.length(); + vMsgsBeforeOpenLog->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 + } + + ret = FileWriteStr(strTimestamped, fileout); + } + } + return ret; +} + +void ShrinkDebugFile() +{ + // Amount of debug.log to save at end when shrinking (must fit in memory) + constexpr size_t RECENT_DEBUG_HISTORY_SIZE = 10 * 1000000; + // Scroll debug.log if it's getting too big + fs::path pathLog = GetDebugLogPath(); + FILE* file = fsbridge::fopen(pathLog, "r"); + + // Special files (e.g. device nodes) may not have a size. + size_t log_size = 0; + try { + log_size = fs::file_size(pathLog); + } catch (boost::filesystem::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); + fseek(file, -((long)vch.size()), SEEK_END); + int nBytes = fread(vch.data(), 1, vch.size(), file); + fclose(file); + + file = fsbridge::fopen(pathLog, "w"); + if (file) + { + fwrite(vch.data(), 1, nBytes, file); + fclose(file); + } + } + else if (file != nullptr) + fclose(file); +} -- cgit v1.2.3