Permalink
Browse files

Merge pull request #6149

27d7605 Buffer log messages and explicitly open logs (Adam Weiss)
  • Loading branch information...
laanwj committed Jul 22, 2015
2 parents 45d1f59 + 27d7605 commit 633fe10869abe89d32d657c2ae8944daa97e4f22
Showing with 85 additions and 28 deletions.
  1. +7 −2 src/init.cpp
  2. +77 −26 src/util.cpp
  3. +1 −0 src/util.h
View
@@ -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));
View
@@ -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<string> *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<string>;
+}
+
+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;
}
View
@@ -125,6 +125,7 @@ void ReadConfigFile(std::map<std::string, std::string>& 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);

0 comments on commit 633fe10

Please sign in to comment.