Merge #13004: Print to console by default when not run with -daemon

6a3b0d3 Print to console by default when not run with -daemon (Evan Klitzke)

Pull request description:

  Cherry-picked ef6fa1c38e1bd115d1cce155907023d79da379d8 from the "up for grabs" PR: "Smarter default behavior for -printtoconsole" (#12689).

  See previous review in #12689.

Tree-SHA512: 8923a89b9c8973286d53e960d3c464b1cd026cd5a5911ba62f9f972c83684417dc4004101815dfe987fc1e1baaec1fdd90748a0866bb5548e974d77b3135d43b

Author: laanwj

src/init.cpp

@@ -814,14 +814,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)";
@@ -1215,13 +1226,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()));
         }

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<std::mutex> 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<char> vch(RECENT_DEBUG_HISTORY_SIZE, 0);

test/functional/feature_logging.py

@@ -15,21 +15,25 @@ def set_test_params(self):
         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")
         self.restart_node(0, ["-debuglogfile=%s" % tempname])
         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 @@ def run_test(self):
         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()

test/functional/test_framework/test_node.py

@@ -78,7 +78,17 @@ def __init__(self, i, datadir, rpchost, timewait, binary, stderr, mocktime, cove
         # 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