Auto merge of #4776 - str4d:logging-files, r=str4d

MOVEONLY: Move logging code from util.{h,cpp} to new files

Based on bitcoin/bitcoin#13021 but implemented from scratch.

This introduces a cyclic dependency between `logging` and `util` that
should be cleaned up in a future PR.
This commit is contained in:
Homu 2020-10-09 16:16:51 +00:00
commit ebc8de390c
5 changed files with 227 additions and 181 deletions

View File

@ -164,6 +164,7 @@ BITCOIN_CORE_H = \
keystore.h \
dbwrapper.h \
limitedmap.h \
logging.h \
main.h \
memusage.h \
merkleblock.h \
@ -413,6 +414,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 \

163
src/logging.cpp Normal file
View File

@ -0,0 +1,163 @@
// Copyright (c) 2009-2010 Satoshi Nakamoto
// Copyright (c) 2009-2018 The Bitcoin Core developers
// Copyright (c) 2018-2020 The Zcash 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 "serialize.h"
#include "util.h"
#include <set>
#include <boost/filesystem/operations.hpp>
#include <boost/thread/mutex.hpp>
#include <boost/thread/once.hpp>
#include <boost/thread/tss.hpp>
using namespace std;
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);
/**
* 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 = NULL;
static boost::mutex* mutexDebugLog = NULL;
static list<string> *vMsgsBeforeOpenLog;
[[noreturn]] void new_handler_terminate()
{
// Rather than throwing std::bad-alloc if allocation fails, terminate
// immediately to (try to) avoid chain corruption.
// Since LogPrintf may itself allocate memory, set the handler directly
// to terminate first.
std::set_new_handler(std::terminate);
fputs("Error: Out of memory. Terminating.\n", stderr);
LogPrintf("Error: Out of memory. Terminating.\n");
// The log was successful, terminate now.
std::terminate();
};
static int FileWriteStr(const std::string &str, FILE *fp)
{
return fwrite(str.data(), 1, str.size(), fp);
}
static void DebugPrintInit()
{
assert(mutexDebugLog == NULL);
mutexDebugLog = new boost::mutex();
vMsgsBeforeOpenLog = new list<string>;
}
boost::filesystem::path GetDebugLogPath()
{
boost::filesystem::path logfile(GetArg("-debuglogfile", DEFAULT_DEBUGLOGFILE));
if (logfile.is_absolute()) {
return logfile;
} else {
return GetDataDir() / logfile;
}
}
std::string LogConfigFilter()
{
// With no -debug flags, show errors and LogPrintf lines.
std::string filter = "error,main=info";
auto& categories = mapMultiArgs["-debug"];
std::set<std::string> setCategories(categories.begin(), categories.end());
if (setCategories.count(string("")) != 0 || setCategories.count(string("1")) != 0) {
// Turn on the firehose!
filter = "debug";
} else {
for (auto category : setCategories) {
filter += "," + category + "=debug";
}
}
return filter;
}
bool LogAcceptCategory(const char* category)
{
if (category != NULL)
{
if (!fDebug)
return false;
// Give each thread quick access to -debug settings.
// This helps prevent issues debugging global destructors,
// where mapMultiArgs might be deleted before another
// global destructor calls LogPrint()
static boost::thread_specific_ptr<set<string> > ptrCategory;
if (ptrCategory.get() == NULL)
{
const vector<string>& categories = mapMultiArgs["-debug"];
ptrCategory.reset(new set<string>(categories.begin(), categories.end()));
// thread_specific_ptr automatically deletes the set when the thread ends.
}
const set<string>& setCategories = *ptrCategory.get();
// if not debugging everything and not debugging specific category, LogPrint does nothing.
if (setCategories.count(string("")) == 0 &&
setCategories.count(string("1")) == 0 &&
setCategories.count(string(category)) == 0)
return false;
}
return true;
}
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 <char> vch(200000,0);
fseek(file, -((long)vch.size()), SEEK_END);
int nBytes = fread(begin_ptr(vch), 1, vch.size(), file);
fclose(file);
file = fopen(pathLog.string().c_str(), "w");
if (file)
{
fwrite(begin_ptr(vch), 1, nBytes, file);
fclose(file);
}
}
else if (file != NULL)
fclose(file);
}

60
src/logging.h Normal file
View File

@ -0,0 +1,60 @@
// Copyright (c) 2009-2010 Satoshi Nakamoto
// Copyright (c) 2009-2018 The Bitcoin Core developers
// Copyright (c) 2018-2020 The Zcash developers
// Distributed under the MIT software license, see the accompanying
// file COPYING or http://www.opensource.org/licenses/mit-license.php.
#ifndef ZCASH_LOGGING_H
#define ZCASH_LOGGING_H
#include "tinyformat.h"
#include <atomic>
#include <string>
#include <boost/filesystem/path.hpp>
#include <tracing.h>
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 fPrintToConsole;
extern bool fPrintToDebugLog;
extern bool fLogTimestamps;
extern bool fLogIPs;
extern std::atomic<bool> fReopenDebugLog;
/** Returns the filtering directive set by the -debug flags. */
std::string LogConfigFilter();
/** Return true if log accepts specified category */
bool LogAcceptCategory(const char* category);
/** Print to debug.log with level INFO and category "main". */
#define LogPrintf(...) LogPrintInner("info", "main", __VA_ARGS__)
/** Print to debug.log with level DEBUG. */
#define LogPrint(category, ...) LogPrintInner("debug", category, __VA_ARGS__)
#define LogPrintInner(level, category, ...) do { \
std::string T_MSG = tfm::format(__VA_ARGS__); \
if (!T_MSG.empty() && T_MSG[T_MSG.size()-1] == '\n') { \
T_MSG.erase(T_MSG.size()-1); \
} \
TracingLog(level, category, T_MSG.c_str()); \
} while(0)
#define LogError(category, ...) ([&]() { \
std::string T_MSG = tfm::format(__VA_ARGS__); \
TracingError(category, T_MSG.c_str()); \
return false; \
}())
boost::filesystem::path GetDebugLogPath();
void ShrinkDebugFile();
#endif // ZCASH_LOGGING_H

View File

@ -100,132 +100,15 @@ using namespace std;
const char * const BITCOIN_CONF_FILENAME = "zcash.conf";
const char * const BITCOIN_PID_FILENAME = "zcashd.pid";
const char * const DEFAULT_DEBUGLOGFILE = "debug.log";
map<string, string> mapArgs;
map<string, vector<string> > mapMultiArgs;
bool fDebug = false;
bool fPrintToConsole = false;
bool fPrintToDebugLog = true;
bool fDaemon = false;
bool fServer = false;
bool fLogTimestamps = DEFAULT_LOGTIMESTAMPS;
bool fLogTimeMicros = DEFAULT_LOGTIMEMICROS;
bool fLogIPs = DEFAULT_LOGIPS;
std::atomic<bool> fReopenDebugLog(false);
CTranslationInterface translationInterface;
/**
* 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 = NULL;
static boost::mutex* mutexDebugLog = NULL;
static list<string> *vMsgsBeforeOpenLog;
[[noreturn]] void new_handler_terminate()
{
// Rather than throwing std::bad-alloc if allocation fails, terminate
// immediately to (try to) avoid chain corruption.
// Since LogPrintf may itself allocate memory, set the handler directly
// to terminate first.
std::set_new_handler(std::terminate);
fputs("Error: Out of memory. Terminating.\n", stderr);
LogPrintf("Error: Out of memory. Terminating.\n");
// The log was successful, terminate now.
std::terminate();
};
static int FileWriteStr(const std::string &str, FILE *fp)
{
return fwrite(str.data(), 1, str.size(), fp);
}
static void DebugPrintInit()
{
assert(mutexDebugLog == NULL);
mutexDebugLog = new boost::mutex();
vMsgsBeforeOpenLog = new list<string>;
}
boost::filesystem::path GetDebugLogPath()
{
boost::filesystem::path logfile(GetArg("-debuglogfile", DEFAULT_DEBUGLOGFILE));
if (logfile.is_absolute()) {
return logfile;
} else {
return GetDataDir() / logfile;
}
}
std::string LogConfigFilter()
{
// With no -debug flags, show errors and LogPrintf lines.
std::string filter = "error,main=info";
auto& categories = mapMultiArgs["-debug"];
std::set<std::string> setCategories(categories.begin(), categories.end());
if (setCategories.count(string("")) != 0 || setCategories.count(string("1")) != 0) {
// Turn on the firehose!
filter = "debug";
} else {
for (auto category : setCategories) {
filter += "," + category + "=debug";
}
}
return filter;
}
bool LogAcceptCategory(const char* category)
{
if (category != NULL)
{
if (!fDebug)
return false;
// Give each thread quick access to -debug settings.
// This helps prevent issues debugging global destructors,
// where mapMultiArgs might be deleted before another
// global destructor calls LogPrint()
static boost::thread_specific_ptr<set<string> > ptrCategory;
if (ptrCategory.get() == NULL)
{
const vector<string>& categories = mapMultiArgs["-debug"];
ptrCategory.reset(new set<string>(categories.begin(), categories.end()));
// thread_specific_ptr automatically deletes the set when the thread ends.
}
const set<string>& setCategories = *ptrCategory.get();
// if not debugging everything and not debugging specific category, LogPrint does nothing.
if (setCategories.count(string("")) == 0 &&
setCategories.count(string("1")) == 0 &&
setCategories.count(string(category)) == 0)
return false;
}
return true;
}
/** Interpret string as boolean, for argument parsing */
static bool InterpretBool(const std::string& strValue)
{
@ -705,30 +588,6 @@ 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 <char> vch(200000,0);
fseek(file, -((long)vch.size()), SEEK_END);
int nBytes = fread(begin_ptr(vch), 1, vch.size(), file);
fclose(file);
file = fopen(pathLog.string().c_str(), "w");
if (file)
{
fwrite(begin_ptr(vch), 1, nBytes, file);
fclose(file);
}
}
else if (file != NULL)
fclose(file);
}
#ifdef WIN32
boost::filesystem::path GetSpecialFolderPath(int nFolder, bool fCreate)
{

View File

@ -5,7 +5,7 @@
/**
* Server/client environment: argument handling, config file parsing,
* logging, thread wrappers
* thread wrappers
*/
#ifndef BITCOIN_UTIL_H
#define BITCOIN_UTIL_H
@ -15,6 +15,7 @@
#endif
#include "compat.h"
#include "logging.h"
#include "tinyformat.h"
#include "utiltime.h"
@ -29,13 +30,6 @@
#include <boost/signals2/signal.hpp>
#include <boost/thread/exceptions.hpp>
#include <tracing.h>
static const bool DEFAULT_LOGTIMEMICROS = false;
static const bool DEFAULT_LOGIPS = false;
static const bool DEFAULT_LOGTIMESTAMPS = true;
extern const char * const DEFAULT_DEBUGLOGFILE;
/** Signals for translation. */
class CTranslationInterface
{
@ -47,13 +41,8 @@ public:
extern std::map<std::string, std::string> mapArgs;
extern std::map<std::string, std::vector<std::string> > mapMultiArgs;
extern bool fDebug;
extern bool fPrintToConsole;
extern bool fPrintToDebugLog;
extern bool fServer;
extern bool fLogTimestamps;
extern bool fLogIPs;
extern std::atomic<bool> fReopenDebugLog;
extern CTranslationInterface translationInterface;
[[noreturn]] extern void new_handler_terminate();
@ -74,31 +63,6 @@ inline std::string _(const char* psz)
void SetupEnvironment();
bool SetupNetworking();
/** Returns the filtering directive set by the -debug flags. */
std::string LogConfigFilter();
/** Return true if log accepts specified category */
bool LogAcceptCategory(const char* category);
/** Print to debug.log with level INFO and category "main". */
#define LogPrintf(...) LogPrintInner("info", "main", __VA_ARGS__)
/** Print to debug.log with level DEBUG. */
#define LogPrint(category, ...) LogPrintInner("debug", category, __VA_ARGS__)
#define LogPrintInner(level, category, ...) do { \
std::string T_MSG = tfm::format(__VA_ARGS__); \
if (!T_MSG.empty() && T_MSG[T_MSG.size()-1] == '\n') { \
T_MSG.erase(T_MSG.size()-1); \
} \
TracingLog(level, category, T_MSG.c_str()); \
} while(0)
#define LogError(category, ...) ([&]() { \
std::string T_MSG = tfm::format(__VA_ARGS__); \
TracingError(category, T_MSG.c_str()); \
return false; \
}())
template<typename... Args>
static inline bool error(const char* format, const Args&... args)
{
@ -132,8 +96,6 @@ void ReadConfigFile(const std::string& confPath, std::map<std::string, std::stri
boost::filesystem::path GetSpecialFolderPath(int nFolder, bool fCreate = true);
#endif
boost::filesystem::path GetTempPath();
boost::filesystem::path GetDebugLogPath();
void ShrinkDebugFile();
void runCommand(const std::string& strCommand);
const boost::filesystem::path GetExportDir();