diff --git a/src/init.cpp b/src/init.cpp index 4addc663c..ecf05d95b 100644 --- a/src/init.cpp +++ b/src/init.cpp @@ -668,6 +668,9 @@ bool AppInit2(boost::thread_group& threadGroup, CScheduler& scheduler) fLogTimestamps = GetBoolArg("-logtimestamps", true); fLogIPs = GetBoolArg("-logips", false); + LogPrintf("\n\n\n\n\n\n\n\n\n\n\n\n\n\n\n\n\n\n\n\n"); + LogPrintf("Bitcoin version %s (%s)\n", FormatFullVersion(), CLIENT_DATE); + // when specifying an explicit binding address, you want to listen on it // even when -connect or -proxy is specified if (mapArgs.count("-bind")) { @@ -941,8 +944,10 @@ bool AppInit2(boost::thread_group& threadGroup, CScheduler& scheduler) #endif if (GetBoolArg("-shrinkdebugfile", !fDebug)) ShrinkDebugFile(); - LogPrintf("\n\n\n\n\n\n\n\n\n\n\n\n\n\n\n\n\n\n\n\n"); - LogPrintf("Bitcoin version %s (%s)\n", FormatFullVersion(), CLIENT_DATE); + + if (fPrintToDebugLog) + OpenDebugLog(); + LogPrintf("Using OpenSSL version %s\n", SSLeay_version(SSLEAY_VERSION)); #ifdef ENABLE_WALLET LogPrintf("Using BerkeleyDB version %s\n", DbEnv::version(0, 0, 0)); diff --git a/src/util.cpp b/src/util.cpp index 00d0f3a00..97fecc6c8 100644 --- a/src/util.cpp +++ b/src/util.cpp @@ -175,23 +175,51 @@ instance_of_cinit; */ static boost::once_flag debugPrintInitFlag = BOOST_ONCE_INIT; + /** - * We use boost::call_once() to make sure these are initialized - * in a thread-safe manner the first time called: + * 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 *vMsgsBeforeOpenLog; + +static int FileWriteStr(const std::string &str, FILE *fp) +{ + return fwrite(str.data(), 1, str.size(), fp); +} static void DebugPrintInit() { - assert(fileout == NULL); assert(mutexDebugLog == NULL); + mutexDebugLog = new boost::mutex(); + vMsgsBeforeOpenLog = new list; +} + +void OpenDebugLog() +{ + boost::call_once(&DebugPrintInit, debugPrintInitFlag); + boost::mutex::scoped_lock scoped_lock(*mutexDebugLog); + assert(fileout == NULL); + assert(vMsgsBeforeOpenLog); boost::filesystem::path pathDebug = GetDataDir() / "debug.log"; fileout = fopen(pathDebug.string().c_str(), "a"); if (fileout) setbuf(fileout, NULL); // unbuffered - mutexDebugLog = new boost::mutex(); + // dump buffered messages from before we opened the log + while (!vMsgsBeforeOpenLog->empty()) { + FileWriteStr(vMsgsBeforeOpenLog->front(), fileout); + vMsgsBeforeOpenLog->pop_front(); + } + + delete vMsgsBeforeOpenLog; + vMsgsBeforeOpenLog = NULL; } bool LogAcceptCategory(const char* category) @@ -223,44 +251,67 @@ bool LogAcceptCategory(const char* category) return true; } +/** + * 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) +{ + 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; +} + 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 && AreBaseParamsConfigured()) + else if (fPrintToDebugLog) { - static bool fStartedNewLine = true; boost::call_once(&DebugPrintInit, debugPrintInitFlag); - - if (fileout == NULL) - return ret; - boost::mutex::scoped_lock scoped_lock(*mutexDebugLog); - // reopen the log file, if requested - if (fReopenDebugLog) { - fReopenDebugLog = false; - boost::filesystem::path pathDebug = GetDataDir() / "debug.log"; - if (freopen(pathDebug.string().c_str(),"a",fileout) != NULL) - setbuf(fileout, NULL); // unbuffered - } + string strTimestamped = LogTimestampStr(str, &fStartedNewLine); - // Debug print useful for profiling - if (fLogTimestamps && fStartedNewLine) - ret += fprintf(fileout, "%s ", DateTimeStrFormat("%Y-%m-%d %H:%M:%S", GetTime()).c_str()); - if (!str.empty() && str[str.size()-1] == '\n') - fStartedNewLine = true; + // buffer if we haven't opened the log yet + if (fileout == NULL) { + assert(vMsgsBeforeOpenLog); + ret = strTimestamped.length(); + vMsgsBeforeOpenLog->push_back(strTimestamped); + } else - fStartedNewLine = false; - - ret = fwrite(str.data(), 1, str.size(), fileout); + { + // reopen the log file, if requested + if (fReopenDebugLog) { + fReopenDebugLog = false; + boost::filesystem::path pathDebug = GetDataDir() / "debug.log"; + if (freopen(pathDebug.string().c_str(),"a",fileout) != NULL) + setbuf(fileout, NULL); // unbuffered + } + + ret = FileWriteStr(strTimestamped, fileout); + } } - return ret; } diff --git a/src/util.h b/src/util.h index 6019e2501..afc9a378b 100644 --- a/src/util.h +++ b/src/util.h @@ -125,6 +125,7 @@ void ReadConfigFile(std::map& mapSettingsRet, std::map boost::filesystem::path GetSpecialFolderPath(int nFolder, bool fCreate = true); #endif boost::filesystem::path GetTempPath(); +void OpenDebugLog(); void ShrinkDebugFile(); void runCommand(const std::string& strCommand);