diff --git a/CMakeLists.txt b/CMakeLists.txt index da16e2efc937..0859d6a83648 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -504,6 +504,7 @@ set(UTIL_SOURCES ./src/compat/glibcxx_sanity.cpp ./src/chainparamsbase.cpp ./src/clientversion.cpp + ./src/logging.cpp ./src/random.cpp ./src/rpc/protocol.cpp ./src/sync.cpp diff --git a/src/Makefile.am b/src/Makefile.am index e9fc98fbd10f..a79501f75f1d 100644 --- a/src/Makefile.am +++ b/src/Makefile.am @@ -130,6 +130,7 @@ BITCOIN_CORE_H = \ keystore.h \ leveldbwrapper.h \ limitedmap.h \ + logging.h \ main.h \ masternode.h \ masternode-payments.h \ @@ -418,6 +419,7 @@ libbitcoin_util_a_SOURCES = \ compat/glibc_sanity.cpp \ compat/glibcxx_sanity.cpp \ compat/strnlen.cpp \ + logging.cpp \ random.cpp \ rpc/protocol.cpp \ support/cleanse.cpp \ diff --git a/src/activemasternode.cpp b/src/activemasternode.cpp index 832817e5cb3e..de36fb04119e 100644 --- a/src/activemasternode.cpp +++ b/src/activemasternode.cpp @@ -21,7 +21,7 @@ void CActiveMasternode::ManageStatus() if (!fMasterNode) return; - if (logCategories != BCLog::NONE) LogPrintf("CActiveMasternode::ManageStatus() - Begin\n"); + LogPrint(BCLog::MASTERNODE, "CActiveMasternode::ManageStatus() - Begin\n"); //need correct blocks to send ping if (!Params().IsRegTestNet() && !masternodeSync.IsBlockchainSynced()) { diff --git a/src/httpserver.cpp b/src/httpserver.cpp index f49c25989dae..91d88709331a 100644 --- a/src/httpserver.cpp +++ b/src/httpserver.cpp @@ -392,8 +392,8 @@ bool InitHTTPServer() // Update libevent's log handling. Returns false if our version of // libevent doesn't support debug logging, in which case we should // clear the BCLog::LIBEVENT flag. - if (!UpdateHTTPServerLogging(logCategories & BCLog::LIBEVENT)) { - logCategories &= ~BCLog::LIBEVENT; + if (!UpdateHTTPServerLogging(g_logger->WillLogCategory(BCLog::LIBEVENT))) { + g_logger->DisableCategory(BCLog::LIBEVENT); } #ifdef WIN32 diff --git a/src/httpserver.h b/src/httpserver.h index cd6f0e173921..ddbe04c14226 100644 --- a/src/httpserver.h +++ b/src/httpserver.h @@ -32,7 +32,7 @@ void InterruptHTTPServer(); /** Stop HTTP server */ void StopHTTPServer(); -/** Change logging level for libevent. Removes BCLog::LIBEVENT from logCategories if +/** Change logging level for libevent. Removes BCLog::LIBEVENT from log categories if * libevent doesn't support debug logging.*/ bool UpdateHTTPServerLogging(bool enable); diff --git a/src/init.cpp b/src/init.cpp index 4aa0ca5adf12..4d982bd6666f 100644 --- a/src/init.cpp +++ b/src/init.cpp @@ -311,7 +311,7 @@ void HandleSIGTERM(int) void HandleSIGHUP(int) { - fReopenDebugLog = true; + g_logger->m_reopen_file = true; } #ifndef WIN32 @@ -507,6 +507,7 @@ std::string HelpMessage(HelpMessageMode mode) strUsage += HelpMessageOpt("-help-debug", _("Show all debugging options (usage: --help -help-debug)")); strUsage += HelpMessageOpt("-logips", strprintf(_("Include IP addresses in debug output (default: %u)"), 0)); strUsage += HelpMessageOpt("-logtimestamps", strprintf(_("Prepend debug output with timestamp (default: %u)"), 1)); + strUsage += HelpMessageOpt("-logtimemicros", strprintf("Add microsecond precision to debug timestamps (default: %u)", DEFAULT_LOGTIMEMICROS)); if (GetBoolArg("-help-debug", false)) { strUsage += HelpMessageOpt("-limitfreerelay=", strprintf(_("Continuously rate-limit free transactions to *1000 bytes per minute (default:%u)"), 15)); strUsage += HelpMessageOpt("-relaypriority", strprintf(_("Require high priority for relaying free or low-fee transactions (default:%u)"), 1)); @@ -901,12 +902,28 @@ static std::string ResolveErrMsg(const char * const optname, const std::string& void InitLogging() { - fPrintToConsole = GetBoolArg("-printtoconsole", false); - fLogTimestamps = GetBoolArg("-logtimestamps", true); - fLogIPs = GetBoolArg("-logips", false); + //g_logger->m_print_to_file = !IsArgNegated("-debuglogfile"); + g_logger->m_print_to_file = true; + g_logger->m_file_path = AbsPathForConfigVal(GetArg("-debuglogfile", DEFAULT_DEBUGLOGFILE)); + // Add newlines to the logfile to distinguish this execution from the last + // one; called before console logging is set up, so this is only sent to + // debug.log. LogPrintf("\n\n\n\n\n\n\n\n\n\n\n\n\n\n\n\n\n\n\n\n"); - LogPrintf("PIVX version %s (%s)\n", FormatFullVersion(), CLIENT_DATE); + + g_logger->m_print_to_console = GetBoolArg("-printtoconsole", !GetBoolArg("-daemon", false)); + g_logger->m_log_timestamps = GetBoolArg("-logtimestamps", DEFAULT_LOGTIMESTAMPS); + g_logger->m_log_time_micros = GetBoolArg("-logtimemicros", DEFAULT_LOGTIMEMICROS); + + fLogIPs = GetBoolArg("-logips", DEFAULT_LOGIPS); + + std::string version_string = FormatFullVersion(); +#ifdef DEBUG + version_string += " (debug build)"; +#else + version_string += " (release build)"; +#endif + LogPrintf("PIVX version %s (%s)\n", version_string, CLIENT_DATE); } /** Initialize pivx. @@ -937,11 +954,9 @@ bool AppInit2() if (!(GetBoolArg("-nodebug", false) || find(categories.begin(), categories.end(), std::string("0")) != categories.end())) { for (const auto& cat : categories) { - uint32_t flag; - if (!GetLogCategory(&flag, &cat)) + if (!g_logger->EnableCategory(cat)) { UIWarning(strprintf(_("Unsupported logging category %s=%s."), "-debug", cat)); - else - logCategories |= flag; + } } } @@ -949,11 +964,9 @@ bool AppInit2() if (mapMultiArgs.count("-debugexclude") > 0) { const std::vector& excludedCategories = mapMultiArgs.at("-debugexclude"); for (const auto& cat : excludedCategories) { - uint32_t flag; - if (!GetLogCategory(&flag, &cat)) + if (!g_logger->DisableCategory(cat)) { UIWarning(strprintf(_("Unsupported logging category %s=%s."), "-debugexclude", cat)); - else - logCategories &= ~flag; + } } } @@ -1062,15 +1075,16 @@ bool AppInit2() #ifndef WIN32 CreatePidFile(GetPidFile(), getpid()); #endif - if (GetBoolArg("-shrinkdebugfile", logCategories != BCLog::NONE)) - ShrinkDebugFile(); - if (fPrintToDebugLog && !OpenDebugLog()) { - return UIError(strprintf("Could not open debug log file %s", GetDebugLogPath().string())); + if (g_logger->m_print_to_file) { + if (GetBoolArg("-shrinkdebugfile", g_logger->DefaultShrinkDebugFile())) + g_logger->ShrinkDebugFile(); + if (!g_logger->OpenDebugLog()) + return UIError(strprintf("Could not open debug log file %s", g_logger->m_file_path.string())); } #ifdef ENABLE_WALLET LogPrintf("Using BerkeleyDB version %s\n", DbEnv::version(0, 0, 0)); #endif - if (!fLogTimestamps) + if (!g_logger->m_log_timestamps) LogPrintf("Startup time: %s\n", DateTimeStrFormat("%Y-%m-%d %H:%M:%S", GetTime())); LogPrintf("Default data directory %s\n", GetDefaultDataDir().string()); LogPrintf("Using data directory %s\n", strDataDir); diff --git a/src/logging.cpp b/src/logging.cpp new file mode 100644 index 000000000000..f5b976d2aa7d --- /dev/null +++ b/src/logging.cpp @@ -0,0 +1,252 @@ +// Copyright (c) 2009-2010 Satoshi Nakamoto +// Copyright (c) 2009-2018 The Bitcoin developers +// Copyright (c) 2015-2020 The PIVX developers +// Distributed under the MIT software license, see the accompanying +// file COPYING or http://www.opensource.org/licenses/mit-license.php. + +#include "chainparamsbase.h" +#include "logging.h" +#include "utiltime.h" + +#include + +const char * const DEFAULT_DEBUGLOGFILE = "debug.log"; +namespace fs = boost::filesystem; + +/** + * 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. + * + * This method of initialization was originally introduced in + * bitcoin@ee3374234c60aba2cc4c5cd5cac1c0aefc2d817c. + */ +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); +} + +bool BCLog::Logger::OpenDebugLog() +{ + std::lock_guard scoped_lock(m_file_mutex); + + assert(m_fileout == nullptr); + assert(!m_file_path.empty()); + + m_fileout = fopen(m_file_path.string().c_str(), "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; +} + +void BCLog::Logger::EnableCategory(BCLog::LogFlags flag) +{ + m_categories |= flag; +} + +bool BCLog::Logger::EnableCategory(const std::string& 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(const std::string& 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::DefaultShrinkDebugFile() const +{ + return m_categories == BCLog::NONE; +} + +struct CLogCategoryDesc +{ + BCLog::LogFlags flag; + std::string category; +}; + +const CLogCategoryDesc LogCategories[] = { + {BCLog::NONE, "0"}, + {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::STAKING, "staking"}, + {BCLog::MASTERNODE, "masternode"}, + {BCLog::MNBUDGET, "mnbudget"}, + {BCLog::LEGACYZC, "zero"}, + {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; +} + +std::string BCLog::Logger::LogTimestampStr(const std::string &str) +{ + std::string strStamped; + + if (!m_log_timestamps) + return str; + + if (m_started_new_line) + strStamped = DateTimeStrFormat("%Y-%m-%d %H:%M:%S", GetTime()) + ' ' + str; + else + strStamped = str; + + if (!str.empty() && str[str.size()-1] == '\n') + m_started_new_line = true; + else + m_started_new_line = false; + + return strStamped; +} + +int BCLog::Logger::LogPrintStr(const std::string &str) +{ + int ret = 0; // Returns total number of characters written + if (m_print_to_console) { + // print to console + ret = fwrite(str.data(), 1, str.size(), stdout); + fflush(stdout); + } else if (m_print_to_file) { + std::lock_guard scoped_lock(m_file_mutex); + + std::string strTimestamped = LogTimestampStr(str); + + // buffer if we haven't opened the log yet + if (m_fileout == NULL) { + ret = strTimestamped.length(); + m_msgs_before_open.push_back(strTimestamped); + + } else { + // reopen the log file, if requested + if (m_reopen_file) { + m_reopen_file = false; + if (freopen(m_file_path.string().c_str(),"a",m_fileout) != NULL) + setbuf(m_fileout, NULL); // unbuffered + } + + ret = FileWriteStr(strTimestamped, m_fileout); + } + } + + return ret; +} + +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 = fopen(m_file_path.string().c_str(), "r"); + if (file && fs::file_size(m_file_path) > RECENT_DEBUG_HISTORY_SIZE) { + // Restart the file with some of the end + std::vector vch(200000, 0); + fseek(file, -((long)vch.size()), SEEK_END); + int nBytes = fread(vch.data(), 1, vch.size(), file); + fclose(file); + + file = fopen(m_file_path.string().c_str(), "w"); + if (file) { + fwrite(vch.data(), 1, nBytes, file); + fclose(file); + } + } else if (file != NULL) + fclose(file); +} diff --git a/src/logging.h b/src/logging.h new file mode 100644 index 000000000000..773636183754 --- /dev/null +++ b/src/logging.h @@ -0,0 +1,165 @@ +// Copyright (c) 2009-2010 Satoshi Nakamoto +// Copyright (c) 2009-2018 The Bitcoin developers +// Copyright (c) 2015-2020 The PIVX developers +// Distributed under the MIT software license, see the accompanying +// file COPYING or http://www.opensource.org/licenses/mit-license.php. + +/** + * Server/client environment: argument handling, config file parsing, + * logging, thread wrappers + */ +#ifndef BITCOIN_LOGGING_H +#define BITCOIN_LOGGING_H + +#include "tinyformat.h" + +#include +#include +#include +#include +#include + +#include + +static const bool DEFAULT_LOGTIMEMICROS = false; +static const bool DEFAULT_LOGIPS = false; +static const bool DEFAULT_LOGTIMESTAMPS = true; +extern const char * const DEFAULT_DEBUGLOGFILE; + +extern bool fLogIPs; + +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), + DB = (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), + STAKING = (1 << 21), + MASTERNODE = (1 << 22), + MNBUDGET = (1 << 23), + LEGACYZC = (1 << 24), + ALL = ~(uint32_t)0, + }; + + class Logger + { + private: + FILE* m_fileout = nullptr; + std::mutex m_file_mutex; + std::list m_msgs_before_open; + + /** + * 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); + + 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; + + boost::filesystem::path m_file_path; + std::atomic m_reopen_file{false}; + + /** Send a string to the log output */ + int LogPrintStr(const std::string &str); + + /** Returns whether logs will be written to any output */ + bool Enabled() const { return m_print_to_console || m_print_to_file; } + + bool OpenDebugLog(); + void ShrinkDebugFile(); + + uint32_t GetCategoryMask() const { return m_categories.load(); } + + void EnableCategory(LogFlags flag); + bool EnableCategory(const std::string& str); + void DisableCategory(LogFlags flag); + bool DisableCategory(const std::string& str); + + bool WillLogCategory(LogFlags category) const; + + bool DefaultShrinkDebugFile() const; + }; + +} // namespace BCLog + +extern BCLog::Logger* const g_logger; + +/** Return true if log accepts specified category */ +static inline bool LogAcceptCategory(BCLog::LogFlags category) +{ + return g_logger->WillLogCategory(category); +} + +/** Returns a string with the supported 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); + +/** Get format string from VA_ARGS for error reporting */ +template std::string FormatStringFromLogArgs(const char *fmt, const Args&... args) { return fmt; } + +// 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. + +#define LogPrintf(...) do { \ + if(g_logger->Enabled()) { \ + std::string _log_msg_; /* Unlikely name to avoid shadowing variables */ \ + try { \ + _log_msg_ = tfm::format(__VA_ARGS__); \ + } catch (tinyformat::format_error &e) { \ + /* Original format string will have newline so don't add one here */ \ + _log_msg_ = "Error \"" + std::string(e.what()) + \ + "\" while formatting log message: " + \ + FormatStringFromLogArgs(__VA_ARGS__); \ + } \ + g_logger->LogPrintStr(_log_msg_); \ + } \ +} while(0) + +#define LogPrint(category, ...) do { \ + if (LogAcceptCategory((category))) { \ + LogPrintf(__VA_ARGS__); \ + } \ +} while(0) + +#endif // BITCOIN_LOGGING_H diff --git a/src/main.cpp b/src/main.cpp index 32f8c2aeab1d..45f42b8ea9a1 100644 --- a/src/main.cpp +++ b/src/main.cpp @@ -3597,8 +3597,7 @@ bool CheckBlock(const CBlock& block, CValidationState& state, bool fCheckPOW, bo REJECT_INVALID, "bad-cb-payee"); } } else { - if (logCategories != BCLog::NONE) - LogPrintf("%s: Masternode/Budget payment checks skipped on sync\n", __func__); + LogPrintf("%s: Masternode/Budget payment checks skipped on sync\n", __func__); } } @@ -5584,8 +5583,7 @@ bool static ProcessMessage(CNode* pfrom, std::string strCommand, CDataStream& vR // we must use CBlocks, as CBlockHeaders won't include the 0x00 nTx count at the end std::vector vHeaders; int nLimit = MAX_HEADERS_RESULTS; - if (logCategories != BCLog::NONE) - LogPrintf("getheaders %d to %s from peer=%d\n", (pindex ? pindex->nHeight : -1), hashStop.ToString(), pfrom->id); + LogPrintf("getheaders %d to %s from peer=%d\n", (pindex ? pindex->nHeight : -1), hashStop.ToString(), pfrom->id); for (; pindex; pindex = chainActive.Next(pindex)) { vHeaders.push_back(pindex->GetBlockHeader()); if (--nLimit <= 0 || pindex->GetBlockHash() == hashStop) diff --git a/src/qt/transactiondesc.cpp b/src/qt/transactiondesc.cpp index 59a89e666076..89264ac780d9 100644 --- a/src/qt/transactiondesc.cpp +++ b/src/qt/transactiondesc.cpp @@ -274,7 +274,7 @@ QString TransactionDesc::toHTML(CWallet* wallet, CWalletTx& wtx, TransactionReco // // Debug view // - if (logCategories != BCLog::NONE) { + if (!GetBoolArg("-shrinkdebugfile", g_logger->DefaultShrinkDebugFile())) { strHTML += "

" + tr("Debug information") + "

"; for (const CTxIn& txin : wtx.vin) if (wallet->IsMine(txin)) diff --git a/src/rpc/misc.cpp b/src/rpc/misc.cpp index accb829dce81..2eff328be709 100644 --- a/src/rpc/misc.cpp +++ b/src/rpc/misc.cpp @@ -587,18 +587,21 @@ UniValue setmocktime(const UniValue& params, bool fHelp) return NullUniValue; } -uint32_t getCategoryMask(UniValue cats) { +void EnableOrDisableLogCategories(UniValue cats, bool enable) { cats = cats.get_array(); - uint32_t mask = 0; for (unsigned int i = 0; i < cats.size(); ++i) { - uint32_t flag = 0; std::string cat = cats[i].get_str(); - if (!GetLogCategory(&flag, &cat)) { - throw JSONRPCError(RPC_INVALID_PARAMETER, "unknown logging category " + cat); + + bool success; + if (enable) { + success = g_logger->EnableCategory(cat); + } else { + success = g_logger->DisableCategory(cat); } - mask |= flag; + + if (!success) + throw JSONRPCError(RPC_INVALID_PARAMETER, "unknown logging category " + cat); } - return mask; } UniValue logging(const UniValue& params, bool fHelp) @@ -621,25 +624,26 @@ UniValue logging(const UniValue& params, bool fHelp) ); } - uint32_t originalLogCategories = logCategories; + uint32_t original_log_categories = g_logger->GetCategoryMask(); if (params.size() > 0 && params[0].isArray()) { - logCategories |= getCategoryMask(params[0]); + EnableOrDisableLogCategories(params[0], true); } if (params.size() > 1 && params[1].isArray()) { - logCategories &= ~getCategoryMask(params[1]); + EnableOrDisableLogCategories(params[1], false); } + uint32_t updated_log_categories = g_logger->GetCategoryMask(); + uint32_t changed_log_categories = original_log_categories ^ updated_log_categories; // Update libevent logging if BCLog::LIBEVENT has changed. // If the library version doesn't allow it, UpdateHTTPServerLogging() returns false, // in which case we should clear the BCLog::LIBEVENT flag. // Throw an error if the user has explicitly asked to change only the libevent // flag and it failed. - uint32_t changedLogCategories = originalLogCategories ^ logCategories; - if (changedLogCategories & BCLog::LIBEVENT) { - if (!UpdateHTTPServerLogging(logCategories & BCLog::LIBEVENT)) { - logCategories &= ~BCLog::LIBEVENT; - if (changedLogCategories == BCLog::LIBEVENT) { + if (changed_log_categories & BCLog::LIBEVENT) { + if (!UpdateHTTPServerLogging(g_logger->WillLogCategory(BCLog::LIBEVENT))) { + g_logger->DisableCategory(BCLog::LIBEVENT); + if (changed_log_categories == BCLog::LIBEVENT) { throw JSONRPCError(RPC_INVALID_PARAMETER, "libevent logging cannot be updated when using libevent before v2.1.1."); } } diff --git a/src/test/test_pivx.cpp b/src/test/test_pivx.cpp index 744f792b1388..df43bf75b404 100644 --- a/src/test/test_pivx.cpp +++ b/src/test/test_pivx.cpp @@ -27,7 +27,6 @@ BasicTestingSetup::BasicTestingSetup() RandomInit(); ECC_Start(); SetupEnvironment(); - fPrintToDebugLog = false; // don't want to write to debug.log file fCheckBlockIndex = true; SelectParams(CBaseChainParams::MAIN); } diff --git a/src/timedata.cpp b/src/timedata.cpp index b16e135d8dcf..5d7a1e55e6ea 100644 --- a/src/timedata.cpp +++ b/src/timedata.cpp @@ -82,7 +82,7 @@ void AddTimeData(const CNetAddr& ip, int64_t nOffsetSample, int nOffsetLimit) LogPrintf("*** %s\n", strMessage); uiInterface.ThreadSafeMessageBox(strMessage, "", CClientUIInterface::MSG_ERROR); } - if (logCategories != BCLog::NONE) { + if (!GetBoolArg("-shrinkdebugfile", g_logger->DefaultShrinkDebugFile())) { for (int64_t n : vSorted) LogPrintf("%+d ", n); LogPrintf("| "); diff --git a/src/util.cpp b/src/util.cpp index 452ef33ca154..afcfa020eb4b 100644 --- a/src/util.cpp +++ b/src/util.cpp @@ -22,6 +22,8 @@ #include +namespace fs = boost::filesystem; + #ifndef WIN32 // for posix_fallocate @@ -102,21 +104,11 @@ bool fSucessfullyLoaded = false; std::vector obfuScationDenominations; std::string strBudgetMode = ""; -const char * const DEFAULT_DEBUGLOGFILE = "debug.log"; -namespace fs = boost::filesystem; - std::map mapArgs; std::map > mapMultiArgs; -bool fPrintToConsole = false; -bool fPrintToDebugLog = true; + bool fDaemon = false; std::string strMiscWarning; -bool fLogTimestamps = false; -bool fLogIPs = false; -volatile bool fReopenDebugLog = false; - -/** Log categories bitfield. */ -std::atomic logCategories(0); /** Init OpenSSL library multithreading support */ static RecursiveMutex** ppmutexOpenSSL; @@ -168,222 +160,6 @@ class CInit } } instance_of_cinit; -/** - * 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 boost::once_flag debugPrintInitFlag = BOOST_ONCE_INIT; -/** - * We use boost::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 boost::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 boost::mutex(); - vMsgsBeforeOpenLog = new std::list; -} - -fs::path GetDebugLogPath() -{ - fs::path logfile(GetArg("-debuglogfile", DEFAULT_DEBUGLOGFILE)); - if (logfile.is_absolute()) { - return logfile; - } else { - return GetDataDir() / logfile; - } -} - -bool OpenDebugLog() -{ - boost::call_once(&DebugPrintInit, debugPrintInitFlag); - boost::mutex::scoped_lock scoped_lock(*mutexDebugLog); - assert(fileout == nullptr); - assert(vMsgsBeforeOpenLog); - - boost::filesystem::path pathDebug = GetDebugLogPath(); - - fileout = fopen(pathDebug.string().c_str(), "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::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::STAKING, "staking"}, - {BCLog::MASTERNODE, "masternode"}, - {BCLog::MNBUDGET, "mnbudget"}, - {BCLog::LEGACYZC, "zero"}, - {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; -} - -/** - * 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, bool *fStartedNewLine) -{ - std::string strStamped; - - if (!fLogTimestamps) - return str; - - if (*fStartedNewLine) - strStamped = DateTimeStrFormat("%Y-%m-%d %H:%M:%S", GetTime()) + ' ' + str; - else - strStamped = str; - - if (!str.empty() && str[str.size()-1] == '\n') - *fStartedNewLine = true; - else - *fStartedNewLine = false; - - return strStamped; -} - -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; -} - -int LogPrintStr(const std::string& str) -{ - int ret = 0; // Returns total number of characters written - static bool fStartedNewLine = true; - if (fPrintToConsole) { - // print to console - ret = fwrite(str.data(), 1, str.size(), stdout); - fflush(stdout); - } else if (fPrintToDebugLog) { - boost::call_once(&DebugPrintInit, debugPrintInitFlag); - boost::mutex::scoped_lock scoped_lock(*mutexDebugLog); - - std::string strTimestamped = LogTimestampStr(str, &fStartedNewLine); - - // buffer if we haven't opened the log yet - if (fileout == NULL) { - assert(vMsgsBeforeOpenLog); - ret = strTimestamped.length(); - vMsgsBeforeOpenLog->push_back(strTimestamped); - - } else { - // reopen the log file, if requested - if (fReopenDebugLog) { - fReopenDebugLog = false; - boost::filesystem::path pathDebug = GetDebugLogPath(); - if (freopen(pathDebug.string().c_str(),"a",fileout) != NULL) - setbuf(fileout, NULL); // unbuffered - } - - ret = FileWriteStr(strTimestamped, fileout); - } - } - - return ret; -} /** Interpret string as boolean, for argument parsing */ static bool InterpretBool(const std::string& strValue) @@ -511,7 +287,7 @@ void PrintExceptionContinue(const std::exception* pex, const char* pszThread) strMiscWarning = message; } -boost::filesystem::path GetDefaultDataDir() +fs::path GetDefaultDataDir() { // Windows < Vista: C:\Documents and Settings\Username\Application Data\PIVX // Windows >= Vista: C:\Users\Username\AppData\Roaming\PIVX @@ -573,22 +349,22 @@ const fs::path& GetDataDir(bool fNetSpecific) void ClearDatadirCache() { - pathCached = boost::filesystem::path(); - pathCachedNetSpecific = boost::filesystem::path(); + pathCached = fs::path(); + pathCachedNetSpecific = fs::path(); } -boost::filesystem::path GetConfigFile() +fs::path GetConfigFile() { - boost::filesystem::path pathConfigFile(GetArg("-conf", "pivx.conf")); + fs::path pathConfigFile(GetArg("-conf", "pivx.conf")); if (!pathConfigFile.is_complete()) pathConfigFile = GetDataDir(false) / pathConfigFile; return pathConfigFile; } -boost::filesystem::path GetMasternodeConfigFile() +fs::path GetMasternodeConfigFile() { - boost::filesystem::path pathConfigFile(GetArg("-mnconf", "masternode.conf")); + fs::path pathConfigFile(GetArg("-mnconf", "masternode.conf")); if (!pathConfigFile.is_complete()) pathConfigFile = GetDataDir() / pathConfigFile; return pathConfigFile; } @@ -596,7 +372,7 @@ boost::filesystem::path GetMasternodeConfigFile() void ReadConfigFile(std::map& mapSettingsRet, std::map >& mapMultiSettingsRet) { - boost::filesystem::ifstream streamConfig(GetConfigFile()); + fs::ifstream streamConfig(GetConfigFile()); if (!streamConfig.good()) { // Create empty pivx.conf if it does not exist FILE* configFile = fopen(GetConfigFile().string().c_str(), "a"); @@ -621,15 +397,23 @@ void ReadConfigFile(std::map& mapSettingsRet, ClearDatadirCache(); } +fs::path AbsPathForConfigVal(const fs::path& path, bool net_specific) +{ + if (path.is_absolute()) { + return path; + } + return fs::absolute(path, GetDataDir(net_specific)); +} + #ifndef WIN32 -boost::filesystem::path GetPidFile() +fs::path GetPidFile() { - boost::filesystem::path pathPidFile(GetArg("-pid", "pivxd.pid")); + fs::path pathPidFile(GetArg("-pid", "pivxd.pid")); if (!pathPidFile.is_complete()) pathPidFile = GetDataDir() / pathPidFile; return pathPidFile; } -void CreatePidFile(const boost::filesystem::path& path, pid_t pid) +void CreatePidFile(const fs::path& path, pid_t pid) { FILE* file = fopen(path.string().c_str(), "w"); if (file) { @@ -639,7 +423,7 @@ void CreatePidFile(const boost::filesystem::path& path, pid_t pid) } #endif -bool RenameOver(boost::filesystem::path src, boost::filesystem::path dest) +bool RenameOver(fs::path src, fs::path dest) { #ifdef WIN32 return MoveFileExA(src.string().c_str(), dest.string().c_str(), @@ -655,12 +439,12 @@ bool RenameOver(boost::filesystem::path src, boost::filesystem::path dest) * Specifically handles case where path p exists, but it wasn't possible for the user to * write to the parent directory. */ -bool TryCreateDirectory(const boost::filesystem::path& p) +bool TryCreateDirectory(const fs::path& p) { try { - return boost::filesystem::create_directory(p); - } catch (const boost::filesystem::filesystem_error&) { - if (!boost::filesystem::exists(p) || !boost::filesystem::is_directory(p)) + return fs::create_directory(p); + } catch (const fs::filesystem_error&) { + if (!fs::exists(p) || !fs::is_directory(p)) throw; } @@ -765,29 +549,8 @@ void AllocateFileRange(FILE* file, unsigned int offset, unsigned int length) #endif } -void ShrinkDebugFile() -{ - // Scroll debug.log if it's getting too big - boost::filesystem::path pathLog = GetDebugLogPath(); - FILE* file = fopen(pathLog.string().c_str(), "r"); - if (file && boost::filesystem::file_size(pathLog) > 10 * 1000000) { - // Restart the file with some of the end - std::vector vch(200000, 0); - fseek(file, -((long)vch.size()), SEEK_END); - int nBytes = fread(vch.data(), 1, vch.size(), file); - fclose(file); - - file = fopen(pathLog.string().c_str(), "w"); - if (file) { - fwrite(vch.data(), 1, nBytes, file); - fclose(file); - } - } else if (file != NULL) - fclose(file); -} - #ifdef WIN32 -boost::filesystem::path GetSpecialFolderPath(int nFolder, bool fCreate) +fs::path GetSpecialFolderPath(int nFolder, bool fCreate) { char pszPath[MAX_PATH] = ""; @@ -800,24 +563,24 @@ boost::filesystem::path GetSpecialFolderPath(int nFolder, bool fCreate) } #endif -boost::filesystem::path GetTempPath() +fs::path GetTempPath() { #if BOOST_FILESYSTEM_VERSION == 3 - return boost::filesystem::temp_directory_path(); + return fs::temp_directory_path(); #else // TODO: remove when we don't support filesystem v2 anymore - boost::filesystem::path path; + fs::path path; #ifdef WIN32 char pszPath[MAX_PATH] = ""; if (GetTempPathA(MAX_PATH, pszPath)) - path = boost::filesystem::path(pszPath); + path = fs::path(pszPath); #else - path = boost::filesystem::path("/tmp"); + path = fs::path("/tmp"); #endif - if (path.empty() || !boost::filesystem::is_directory(path)) { + if (path.empty() || !fs::is_directory(path)) { LogPrintf("GetTempPath(): failed to find temp path\n"); - return boost::filesystem::path(""); + return fs::path(""); } return path; #endif @@ -865,8 +628,8 @@ void SetupEnvironment() // in multithreading environments, it is set explicitly by the main thread. // A dummy locale is used to extract the internal default locale, used by // boost::filesystem::path, which is then used to explicitly imbue the path. - std::locale loc = boost::filesystem::path::imbue(std::locale::classic()); - boost::filesystem::path::imbue(loc); + std::locale loc = fs::path::imbue(std::locale::classic()); + fs::path::imbue(loc); } bool SetupNetworking() diff --git a/src/util.h b/src/util.h index e5bb1d30b5cb..3972a57051af 100644 --- a/src/util.h +++ b/src/util.h @@ -7,7 +7,7 @@ /** * Server/client environment: argument handling, config file parsing, - * logging, thread wrappers + * thread wrappers */ #ifndef BITCOIN_UTIL_H #define BITCOIN_UTIL_H @@ -16,6 +16,7 @@ #include "config/pivx-config.h" #endif +#include "logging.h" #include "compat.h" #include "tinyformat.h" #include "utiltime.h" @@ -46,96 +47,20 @@ extern int keysLoaded; extern bool fSucessfullyLoaded; extern std::vector obfuScationDenominations; extern std::string strBudgetMode; -extern std::atomic logCategories; + extern std::map mapArgs; extern std::map > mapMultiArgs; -extern bool fPrintToConsole; -extern bool fPrintToDebugLog; + extern std::string strMiscWarning; -extern bool fLogTimestamps; -extern bool fLogIPs; -extern volatile bool fReopenDebugLog; + void SetupEnvironment(); bool SetupNetworking(); -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), - DB = (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), - STAKING = (1 << 21), - MASTERNODE = (1 << 22), - MNBUDGET = (1 << 23), - LEGACYZC = (1 << 24), - ALL = ~(uint32_t)0, - }; -} - -/** Return true if log accepts specified category */ -static inline bool LogAcceptCategory(uint32_t category) -{ - return (logCategories.load(std::memory_order_relaxed) & category) != 0; -} - -/** 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 flags in f */ -bool GetLogCategory(uint32_t *f, const std::string *str); -/** Send a string to the log output */ -int LogPrintStr(const std::string& str); - -/** Get format string from VA_ARGS for error reporting */ -template std::string FormatStringFromLogArgs(const char *fmt, const Args&... args) { return fmt; } - -#define LogPrintf(...) do { \ - std::string _log_msg_; /* Unlikely name to avoid shadowing variables */ \ - try { \ - _log_msg_ = tfm::format(__VA_ARGS__); \ - } catch (tinyformat::format_error &e) { \ - /* Original format string will have newline so don't add one here */ \ - _log_msg_ = "Error \"" + std::string(e.what()) + "\" while formatting log message: " + FormatStringFromLogArgs(__VA_ARGS__); \ - } \ - LogPrintStr(_log_msg_); \ -} while(0) - -#define LogPrint(category, ...) do { \ - if (LogAcceptCategory((category))) { \ - LogPrintf(__VA_ARGS__); \ - } \ -} while(0) - template bool error(const char* fmt, const Args&... args) { - LogPrintStr("ERROR: " + tfm::format(fmt, args...) + "\n"); + LogPrintf("ERROR: %s\n", tfm::format(fmt, args...)); return false; } @@ -163,9 +88,7 @@ void ReadConfigFile(std::map& mapSettingsRet, std::map boost::filesystem::path GetSpecialFolderPath(int nFolder, bool fCreate = true); #endif boost::filesystem::path GetTempPath(); -boost::filesystem::path GetDebugLogPath(); -bool OpenDebugLog(); -void ShrinkDebugFile(); + void runCommand(std::string strCommand); inline bool IsSwitchChar(char c) @@ -265,4 +188,6 @@ void TraceThread(const char* name, Callable func) } } +boost::filesystem::path AbsPathForConfigVal(const boost::filesystem::path& path, bool net_specific = true); + #endif // BITCOIN_UTIL_H