bitcoin · LarryRuane · Jan 20, 2020
diff --git a/src/init/common.cpp b/src/init/common.cpp
@@ -124,6 +124,10 @@ void LogPackageVersion()
 #else
     version_string += " (release build)";
 #endif
-    LogPrintf(PACKAGE_NAME " version %s\n", version_string);
+    std::string str{strprintf("%s version %s", PACKAGE_NAME, version_string)};
+    LogPrintf("%s\n", str);
+
+    // Useful to always have in the debug.log file (even after log rotation).
+    LogInstance().AddRelogMessage(str);
 }
 } // namespace init
diff --git a/src/logging.cpp b/src/logging.cpp
@@ -287,7 +287,7 @@ std::vector<LogCategory> BCLog::Logger::LogCategoriesList() const
     return ret;
 }
 
-std::string BCLog::Logger::LogTimestampStr(const std::string& str)
+std::string BCLog::Logger::LogTimestampStr(const std::string& str) const
 {
     std::string strStamped;
 
@@ -368,9 +368,35 @@ void BCLog::Logger::LogPrintStr(const std::string& str, const std::string& loggi
         str_prefixed.insert(0, "[" + (threadname.empty() ? "unknown" : threadname) + "] ");
     }
 
+    std::string str_console;
+    if (m_print_to_console) {
+        str_console = LogTimestampStr(str_prefixed);
+    }
+
+    if (!m_buffering && m_print_to_file) {
+        assert(m_fileout != nullptr);
+
+        // reopen the log file, if requested
+        if (m_reopen_file) {
+            m_reopen_file = false;
+            FILE* new_fileout = fsbridge::fopen(m_file_path, "a");
+            if (new_fileout) {
+                setbuf(new_fileout, nullptr); // unbuffered
+                fclose(m_fileout);
+                m_fileout = new_fileout;
+
+                // Re-log important messages to the new file so they're not lost.
+                m_started_new_line = true; // prepend timestamp to these messages
+                FileWriteStr(LogTimestampStr("*** reopen log file ***\n"), m_fileout);
+                for (const std::string& msg : m_msgs_relog) {
+                    FileWriteStr(LogTimestampStr(msg) + '\n', m_fileout);
+                }
+            }
+        }
+    }
     str_prefixed = LogTimestampStr(str_prefixed);
 
-    m_started_new_line = !str.empty() && str[str.size()-1] == '\n';
+    m_started_new_line = !str.empty() && str[str.size() - 1] == '\n';
 
     if (m_buffering) {
         // buffer if we haven't started logging yet
@@ -380,25 +406,14 @@ void BCLog::Logger::LogPrintStr(const std::string& str, const std::string& loggi
 
     if (m_print_to_console) {
         // print to console
-        fwrite(str_prefixed.data(), 1, str_prefixed.size(), stdout);
+        fwrite(str_console.data(), 1, str_console.size(), stdout);
         fflush(stdout);
     }
     for (const auto& cb : m_print_callbacks) {
         cb(str_prefixed);
     }
     if (m_print_to_file) {
         assert(m_fileout != nullptr);
-
-        // reopen the log file, if requested
-        if (m_reopen_file) {
-            m_reopen_file = false;
-            FILE* new_fileout = fsbridge::fopen(m_file_path, "a");
-            if (new_fileout) {
-                setbuf(new_fileout, nullptr); // unbuffered
-                fclose(m_fileout);
-                m_fileout = new_fileout;
-            }
-        }
         FileWriteStr(str_prefixed, m_fileout);
     }
 }

diff --git a/src/logging.h b/src/logging.h
@@ -84,6 +84,13 @@ namespace BCLog {
         std::list<std::string> m_msgs_before_open GUARDED_BY(m_cs);
         bool m_buffering GUARDED_BY(m_cs) = true; //!< Buffer messages before logging can be started.
 
+        /**
+         * Some logged messages are important enough that they should be
+         * re-logged to the new debug.log file when it rotates, so that they
+         * are always visible near the start of the current debug.log file.
+         */
+        std::list<std::string> m_msgs_relog;
+
         /**
          * m_started_new_line is a state variable that will suppress printing of
          * the timestamp when multiple calls are made that don't end in a
@@ -94,7 +101,7 @@ namespace BCLog {
         /** Log categories bitfield. */
         std::atomic<uint32_t> m_categories{0};
 
-        std::string LogTimestampStr(const std::string& str);
+        std::string LogTimestampStr(const std::string& str) const;
 
         /** Slots that connect to the print signal */
         std::list<std::function<void(const std::string&)>> m_print_callbacks GUARDED_BY(m_cs) {};
@@ -160,6 +167,20 @@ namespace BCLog {
         };
 
         bool DefaultShrinkDebugFile() const;
+
+        /** (Re)log important string to debug.log later, each time it rotates */
+        void AddRelogMessage(const std::string& str)
+        {
+            if (m_print_to_file) {
+                m_msgs_relog.push_back(str);
+            }
+        }
+
+        /** Only for testing */
+        void DeleteRelogMessages()
+        {
+            m_msgs_relog.clear();
+        }
     };
 
 } // namespace BCLog

diff --git a/src/test/getarg_tests.cpp b/src/test/getarg_tests.cpp
@@ -442,6 +442,7 @@ BOOST_AUTO_TEST_CASE(logargs)
     local_args.LogArgs();
 
     LogInstance().DeleteCallback(print_connection);
+    LogInstance().DeleteRelogMessages();
     // Check that what should appear does, and what shouldn't doesn't.
     BOOST_CHECK(str.find("Command-line arg: okaylog-bool=\"\"") != std::string::npos);
     BOOST_CHECK(str.find("Command-line arg: okaylog-negbool=false") != std::string::npos);
@@ -450,4 +451,71 @@ BOOST_AUTO_TEST_CASE(logargs)
     BOOST_CHECK(str.find("private") == std::string::npos);
 }
 
+static void relogargscheck()
+{
+    // Open and read debug.log. This test can't use PushBackCallback() like the
+    // logargs test above because, by design, log file rotation doesn't cause
+    // the relogged messages to be sent to that interface, only to the file.
+    FILE* file = fsbridge::fopen(LogInstance().m_file_path, "rb");
+    fseek(file, 0, SEEK_END);
+    std::vector<char> vch(ftell(file), 0);
+    fseek(file, 0, SEEK_SET);
+    size_t nbytes = fread(vch.data(), 1, vch.size(), file);
+    fclose(file);
+
+    assert(nbytes == vch.size());
+
+    // Check that what should appear does, and what shouldn't doesn't.
+    std::string str(vch.begin(), vch.end());
+    BOOST_CHECK(str.find("test relogargs") != std::string::npos);
+    BOOST_CHECK(str.find("Bitcoin Core version") != std::string::npos);
+    BOOST_CHECK(str.find("Command-line arg: okaylog-bool=\"\"") != std::string::npos);
+    BOOST_CHECK(str.find("Command-line arg: okaylog-negbool=false") != std::string::npos);
+    BOOST_CHECK(str.find("Command-line arg: okaylog=\"public\"") != std::string::npos);
+    BOOST_CHECK(str.find("dontlog=****") != std::string::npos);
+    BOOST_CHECK(str.find("private") == std::string::npos);
+}
+
+BOOST_AUTO_TEST_CASE(relogargs)
+{
+    ArgsManager local_args;
+
+    const auto okaylog_bool = std::make_pair("-okaylog-bool", ArgsManager::ALLOW_ANY);
+    const auto okaylog_negbool = std::make_pair("-okaylog-negbool", ArgsManager::ALLOW_ANY);
+    const auto okaylog = std::make_pair("-okaylog", ArgsManager::ALLOW_ANY);
+    const auto dontlog = std::make_pair("-dontlog", ArgsManager::ALLOW_ANY | ArgsManager::SENSITIVE);
+    SetupArgs(local_args, {okaylog_bool, okaylog_negbool, okaylog, dontlog});
+    ResetArgs(local_args, "-okaylog-bool -nookaylog-negbool -okaylog=public -dontlog=private");
+
+    // Log the arguments to debug.log.
+    local_args.LogArgs();
+
+    // This should also appear in the log.
+    LogPrintf("test relogargs\n");
+
+    // Verify that the arguments were logged.
+    relogargscheck();
+
+    // Simulate log rotation.
+#ifdef WIN32
+    // Windows doesn't allow an open file to be renamed, so close and reopen (below).
+    LogInstance().DisconnectTestLogger();
+#endif
+    fs::path newname = LogInstance().m_file_path + ".rename";
+    fs::rename(LogInstance().m_file_path, newname);
+#ifdef WIN32
+    LogInstance().StartLogging();
+#endif
+
+    // Simulate SIGHUP (on a real system, signal causes HandleSIGHUP() to run).
+    LogInstance().m_reopen_file = true;
+
+    // The first log message after signal causes the arguments to be relogged.
+    LogPrintf("test relogargs\n");
+
+    // Verify that the arguments were (re)logged.
+    relogargscheck();
+    LogInstance().DeleteRelogMessages();
+}
+
 BOOST_AUTO_TEST_SUITE_END()
diff --git a/src/test/logging_tests.cpp b/src/test/logging_tests.cpp
@@ -52,6 +52,19 @@ struct LogSetup : public BasicTestingSetup {
         LogInstance().m_log_threadnames = prev_log_threadnames;
         LogInstance().m_log_sourcelocations = prev_log_sourcelocations;
     }
+
+    std::vector<std::string> GetLogLines() const
+    {
+      
9E12
  std::ifstream file{tmp_log_path};
+        std::vector<std::string> log_lines;
+        for (std::string log; std::getline(file, log);) {
+            // The log file get "reopened", so ignore some extra lines.
+            if (log.find("reopen log file") != std::string::npos) continue;
+            if (log.find("version") != std::string::npos) continue;
+            log_lines.push_back(log);
+        }
+        return log_lines;
+    }
 };
 
 BOOST_AUTO_TEST_CASE(logging_timer)
@@ -78,11 +91,7 @@ BOOST_FIXTURE_TEST_CASE(logging_LogPrintf_, LogSetup)
     LogPrintf_("fn2", "src2", 2, BCLog::LogFlags::NET, BCLog::Level::None, "foo2: %s", "bar2\n");
     LogPrintf_("fn3", "src3", 3, BCLog::LogFlags::NONE, BCLog::Level::Debug, "foo3: %s", "bar3\n");
     LogPrintf_("fn4", "src4", 4, BCLog::LogFlags::NONE, BCLog::Level::None, "foo4: %s", "bar4\n");
-    std::ifstream file{tmp_log_path};
-    std::vector<std::string> log_lines;
-    for (std::string log; std::getline(file, log);) {
-        log_lines.push_back(log);
-    }
+    std::vector<std::string> log_lines{GetLogLines()};
     std::vector<std::string> expected = {
         "[src1:1] [fn1] [net:debug] foo1: bar1",
         "[src2:2] [fn2] [net] foo2: bar2",
@@ -104,11 +113,7 @@ BOOST_FIXTURE_TEST_CASE(logging_LogPrintMacros, LogSetup)
     LogPrintLevel(BCLog::NET, BCLog::Level::Warning, "foo9: %s\n", "bar9");
     LogPrintLevel(BCLog::NET, BCLog::Level::Error, "foo10: %s\n", "bar10");
     LogPrintfCategory(BCLog::VALIDATION, "foo11: %s\n", "bar11");
-    std::ifstream file{tmp_log_path};
-    std::vector<std::string> log_lines;
-    for (std::string log; std::getline(file, log);) {
-        log_lines.push_back(log);
-    }
+    std::vector<std::string> log_lines{GetLogLines()};
     std::vector<std::string> expected = {
         "foo5: bar5",
         "[net] foo6: bar6",
@@ -145,11 +150,7 @@ BOOST_FIXTURE_TEST_CASE(logging_LogPrintMacros_CategoryName, LogSetup)
         expected.push_back(expected_log);
     }
 
-    std::ifstream file{tmp_log_path};
-    std::vector<std::string> log_lines;
-    for (std::string log; std::getline(file, log);) {
-        log_lines.push_back(log);
-    }
+    std::vector<std::string> log_lines{GetLogLines()};
     BOOST_CHECK_EQUAL_COLLECTIONS(log_lines.begin(), log_lines.end(), expected.begin(), expected.end());
 }
 

diff --git a/src/util/system.cpp b/src/util/system.cpp
@@ -1115,7 +1115,10 @@ void ArgsManager::logArgsPrefix(
             std::optional<unsigned int> flags = GetArgFlags('-' + arg.first);
             if (flags) {
                 std::string value_str = (*flags & SENSITIVE) ? "****" : value.write();
-                LogPrintf("%s %s%s=%s\n", prefix, section_str, arg.first, value_str);
+                std::string str{strprintf("%s %s%s=%s", prefix, section_str, arg.first, value_str)};
+                LogPrintf("%s\n", str);
+                // Useful to always have in the current debug.log file.
+                LogInstance().AddRelogMessage(str);
             }
         }
     }