From fea25712ca54c4715f874cf3d871e84bbfd83352 Mon Sep 17 00:00:00 2001 From: Michael Hendricks Date: Fri, 2 Mar 2012 12:24:38 -0700 Subject: [PATCH 1/2] Serialize access to debug.log stream Acquire an exclusive, advisory lock before sending output to debug.log and release it when we're done. This should avoid output from multiple threads being interspersed in the log file. We can't use CRITICAL_SECTION machinery for this because the debug log is written during startup and shutdown when that machinery is not available. (Thanks to Gavin for pointing out the CRITICAL_SECTION problems based on his earlier work in this area) --- src/util.cpp | 3 +++ 1 file changed, 3 insertions(+) diff --git a/src/util.cpp b/src/util.cpp index b0c80f6d..d143306a 100644 --- a/src/util.cpp +++ b/src/util.cpp @@ -25,6 +25,7 @@ namespace boost { #include #include #include +#include #include #include #include @@ -209,6 +210,8 @@ inline int OutputDebugStringF(const char* pszFormat, ...) if (fileout) { static bool fStartedNewLine = true; + static boost::mutex mutexDebugLog; + boost::mutex::scoped_lock scoped_lock(mutexDebugLog); // Debug print useful for profiling if (fLogTimestamps && fStartedNewLine) From 9af080c351c40a4f56d37174253d33a9f4ffdb69 Mon Sep 17 00:00:00 2001 From: Michael Hendricks Date: Fri, 2 Mar 2012 12:31:16 -0700 Subject: [PATCH 2/2] Reopen debug.log on SIGHUP The best log rotation method formerly available was to configure logrotate with the copytruncate option. As described in the logrotate documentation, "there is a very small time slice between copying the file and truncating it, so some logging data might be lost". By sending SIGHUP to the server process, one can now reopen the debug log file without losing any data. --- src/init.cpp | 12 +++++++++++- src/util.cpp | 9 +++++++++ src/util.h | 1 + 3 files changed, 21 insertions(+), 1 deletion(-) diff --git a/src/init.cpp b/src/init.cpp index b027a53d..726950bd 100644 --- a/src/init.cpp +++ b/src/init.cpp @@ -80,6 +80,10 @@ void HandleSIGTERM(int) fRequestShutdown = true; } +void HandleSIGHUP(int) +{ + fReopenDebugLog = true; +} @@ -285,7 +289,13 @@ bool AppInit2() sa.sa_flags = 0; sigaction(SIGTERM, &sa, NULL); sigaction(SIGINT, &sa, NULL); - sigaction(SIGHUP, &sa, NULL); + + // Reopen debug.log on SIGHUP + struct sigaction sa_hup; + sa_hup.sa_handler = HandleSIGHUP; + sigemptyset(&sa_hup.sa_mask); + sa_hup.sa_flags = 0; + sigaction(SIGHUP, &sa_hup, NULL); #endif fTestNet = GetBoolArg("-testnet"); diff --git a/src/util.cpp b/src/util.cpp index d143306a..e3a49dcb 100644 --- a/src/util.cpp +++ b/src/util.cpp @@ -70,6 +70,7 @@ bool fTestNet = false; bool fNoListen = false; bool fLogTimestamps = false; CMedianFilter vTimeOffsets(200,0); +bool fReopenDebugLog = false; // Init openssl library multithreading support static CCriticalSection** ppmutexOpenSSL; @@ -213,6 +214,14 @@ inline int OutputDebugStringF(const char* pszFormat, ...) static boost::mutex mutexDebugLog; 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 + } + // Debug print useful for profiling if (fLogTimestamps && fStartedNewLine) fprintf(fileout, "%s ", DateTimeStrFormat("%x %H:%M:%S", GetTime()).c_str()); diff --git a/src/util.h b/src/util.h index f7bdaf53..edef3544 100644 --- a/src/util.h +++ b/src/util.h @@ -121,6 +121,7 @@ extern std::string strMiscWarning; extern bool fTestNet; extern bool fNoListen; extern bool fLogTimestamps; +extern bool fReopenDebugLog; void RandAddSeed(); void RandAddSeedPerfmon();