From 6a3b0d3d1aee1ab924f30b9910bc517c764917cd Mon Sep 17 00:00:00 2001 From: Evan Klitzke Date: Mon, 26 Mar 2018 21:35:35 -0700 Subject: [PATCH] Print to console by default when not run with -daemon Printing to the debug log file can be disabled with -nodebulogfile --- src/init.cpp | 26 ++++++++++++++------- src/util.cpp | 15 ++++++++---- test/functional/feature_logging.py | 21 ++++++++++++++--- test/functional/test_framework/test_node.py | 12 +++++++++- 4 files changed, 57 insertions(+), 17 deletions(-) diff --git a/src/init.cpp b/src/init.cpp index abff5ec79d..9174413610 100644 --- a/src/init.cpp +++ b/src/init.cpp @@ -815,14 +815,25 @@ static std::string ResolveErrMsg(const char * const optname, const std::string& return strprintf(_("Cannot resolve -%s address: '%s'"), optname, strBind); } +/** + * Initialize global loggers. + * + * Note that this is called very early in the process lifetime, so you should be + * careful about what global state you rely on here. + */ void InitLogging() { - fPrintToConsole = gArgs.GetBoolArg("-printtoconsole", false); + // 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"); + + fPrintToConsole = gArgs.GetBoolArg("-printtoconsole", !gArgs.GetBoolArg("-daemon", false)); + fPrintToDebugLog = !gArgs.IsArgNegated("-debuglogfile"); fLogTimestamps = gArgs.GetBoolArg("-logtimestamps", DEFAULT_LOGTIMESTAMPS); fLogTimeMicros = gArgs.GetBoolArg("-logtimemicros", DEFAULT_LOGTIMEMICROS); fLogIPs = gArgs.GetBoolArg("-logips", DEFAULT_LOGIPS); - LogPrintf("\n\n\n\n\n\n\n\n\n\n\n\n\n\n\n\n\n\n\n\n"); std::string version_string = FormatFullVersion(); #ifdef DEBUG version_string += " (debug build)"; @@ -1216,13 +1227,12 @@ bool AppInitMain() #ifndef WIN32 CreatePidFile(GetPidFile(), getpid()); #endif - if (gArgs.GetBoolArg("-shrinkdebugfile", logCategories == BCLog::NONE)) { - // Do this first since it both loads a bunch of debug.log into memory, - // and because this needs to happen before any other debug.log printing - ShrinkDebugFile(); - } - if (fPrintToDebugLog) { + if (gArgs.GetBoolArg("-shrinkdebugfile", logCategories == BCLog::NONE)) { + // Do this first since it both loads a bunch of debug.log into memory, + // and because this needs to happen before any other debug.log printing + ShrinkDebugFile(); + } if (!OpenDebugLog()) { return InitError(strprintf("Could not open debug log file %s", GetDebugLogPath().string())); } diff --git a/src/util.cpp b/src/util.cpp index 1fb40ae7a1..6b0bffa35a 100644 --- a/src/util.cpp +++ b/src/util.cpp @@ -341,14 +341,12 @@ int LogPrintStr(const std::string &str) std::string strTimestamped = LogTimestampStr(str, &fStartedNewLine); - if (fPrintToConsole) - { + if (fPrintToConsole) { // print to console ret = fwrite(strTimestamped.data(), 1, strTimestamped.size(), stdout); fflush(stdout); } - else if (fPrintToDebugLog) - { + if (fPrintToDebugLog) { std::call_once(debugPrintInitFlag, &DebugPrintInit); std::lock_guard scoped_lock(*mutexDebugLog); @@ -1126,9 +1124,16 @@ void ShrinkDebugFile() // Scroll debug.log if it's getting too big fs::path pathLog = GetDebugLogPath(); FILE* file = fsbridge::fopen(pathLog, "r"); + + // Special files (e.g. device nodes) may not have a size. + size_t log_size = 0; + try { + log_size = fs::file_size(pathLog); + } catch (boost::filesystem::filesystem_error &) {} + // If debug.log file is more than 10% bigger the RECENT_DEBUG_HISTORY_SIZE // trim it down by saving only the last RECENT_DEBUG_HISTORY_SIZE bytes - if (file && fs::file_size(pathLog) > 11 * (RECENT_DEBUG_HISTORY_SIZE / 10)) + if (file && log_size > 11 * (RECENT_DEBUG_HISTORY_SIZE / 10)) { // Restart the file with some of the end std::vector vch(RECENT_DEBUG_HISTORY_SIZE, 0); diff --git a/test/functional/feature_logging.py b/test/functional/feature_logging.py index 3c7aecf10a..166f8f8694 100755 --- a/test/functional/feature_logging.py +++ b/test/functional/feature_logging.py @@ -15,13 +15,17 @@ class LoggingTest(BitcoinTestFramework): self.num_nodes = 1 self.setup_clean_chain = True + def relative_log_path(self, name): + return os.path.join(self.nodes[0].datadir, "regtest", name) + def run_test(self): # test default log file name - assert os.path.isfile(os.path.join(self.nodes[0].datadir, "regtest", "debug.log")) + default_log_path = self.relative_log_path("debug.log") + assert os.path.isfile(default_log_path) # test alternative log file name in datadir self.restart_node(0, ["-debuglogfile=foo.log"]) - assert os.path.isfile(os.path.join(self.nodes[0].datadir, "regtest", "foo.log")) + assert os.path.isfile(self.relative_log_path("foo.log")) # test alternative log file name outside datadir tempname = os.path.join(self.options.tmpdir, "foo.log") @@ -29,7 +33,7 @@ class LoggingTest(BitcoinTestFramework): assert os.path.isfile(tempname) # check that invalid log (relative) will cause error - invdir = os.path.join(self.nodes[0].datadir, "regtest", "foo") + invdir = self.relative_log_path("foo") invalidname = os.path.join("foo", "foo.log") self.stop_node(0) exp_stderr = "Error: Could not open debug log file \S+$" @@ -55,6 +59,17 @@ class LoggingTest(BitcoinTestFramework): self.start_node(0, ["-debuglogfile=%s" % (invalidname)]) assert os.path.isfile(os.path.join(invdir, "foo.log")) + # check that -nodebuglogfile disables logging + self.stop_node(0) + os.unlink(default_log_path) + assert not os.path.isfile(default_log_path) + self.start_node(0, ["-nodebuglogfile"]) + assert not os.path.isfile(default_log_path) + + # just sanity check no crash here + self.stop_node(0) + self.start_node(0, ["-debuglogfile=%s" % os.devnull]) + if __name__ == '__main__': LoggingTest().main() diff --git a/test/functional/test_framework/test_node.py b/test/functional/test_framework/test_node.py index 0f0d031f35..04d1de8d91 100755 --- a/test/functional/test_framework/test_node.py +++ b/test/functional/test_framework/test_node.py @@ -78,7 +78,17 @@ class TestNode(): # For those callers that need more flexibility, they can just set the args property directly. # Note that common args are set in the config file (see initialize_datadir) self.extra_args = extra_args - self.args = [self.binary, "-datadir=" + self.datadir, "-logtimemicros", "-debug", "-debugexclude=libevent", "-debugexclude=leveldb", "-mocktime=" + str(mocktime), "-uacomment=testnode%d" % i] + self.args = [ + self.binary, + "-datadir=" + self.datadir, + "-logtimemicros", + "-debug", + "-debugexclude=libevent", + "-debugexclude=leveldb", + "-mocktime=" + str(mocktime), + "-uacomment=testnode%d" % i, + "-noprinttoconsole" + ] self.cli = TestNodeCLI(os.getenv("BITCOINCLI", "bitcoin-cli"), self.datadir) self.use_cli = use_cli