diff options
| -rw-r--r-- | src/init.cpp | 10 | ||||
| -rw-r--r-- | src/logging.cpp | 68 | ||||
| -rw-r--r-- | src/logging.h | 19 | ||||
| -rwxr-xr-x | test/functional/feature_config_args.py | 7 |
4 files changed, 63 insertions, 41 deletions
diff --git a/src/init.cpp b/src/init.cpp index 2a10f28a84..6625080c6e 100644 --- a/src/init.cpp +++ b/src/init.cpp @@ -852,12 +852,6 @@ void InitLogging() { LogInstance().m_print_to_file = !gArgs.IsArgNegated("-debuglogfile"); LogInstance().m_file_path = AbsPathForConfigVal(gArgs.GetArg("-debuglogfile", DEFAULT_DEBUGLOGFILE)); - - // 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"); - LogInstance().m_print_to_console = gArgs.GetBoolArg("-printtoconsole", !gArgs.GetBoolArg("-daemon", false)); LogInstance().m_log_timestamps = gArgs.GetBoolArg("-logtimestamps", DEFAULT_LOGTIMESTAMPS); LogInstance().m_log_time_micros = gArgs.GetBoolArg("-logtimemicros", DEFAULT_LOGTIMEMICROS); @@ -1237,10 +1231,10 @@ bool AppInitMain(InitInterfaces& interfaces) // and because this needs to happen before any other debug.log printing LogInstance().ShrinkDebugFile(); } - if (!LogInstance().OpenDebugLog()) { + } + if (!LogInstance().StartLogging()) { return InitError(strprintf("Could not open debug log file %s", LogInstance().m_file_path.string())); - } } if (!LogInstance().m_log_timestamps) diff --git a/src/logging.cpp b/src/logging.cpp index 3eda4995db..418a701179 100644 --- a/src/logging.cpp +++ b/src/logging.cpp @@ -39,24 +39,38 @@ static int FileWriteStr(const std::string &str, FILE *fp) return fwrite(str.data(), 1, str.size(), fp); } -bool BCLog::Logger::OpenDebugLog() +bool BCLog::Logger::StartLogging() { - std::lock_guard<std::mutex> scoped_lock(m_file_mutex); + std::lock_guard<std::mutex> scoped_lock(m_cs); + assert(m_buffering); assert(m_fileout == nullptr); - assert(!m_file_path.empty()); - m_fileout = fsbridge::fopen(m_file_path, "a"); - if (!m_fileout) { - return false; + if (m_print_to_file) { + assert(!m_file_path.empty()); + m_fileout = fsbridge::fopen(m_file_path, "a"); + if (!m_fileout) { + return false; + } + + setbuf(m_fileout, nullptr); // unbuffered + + // Add newlines to the logfile to distinguish this execution from the + // last one. + FileWriteStr("\n\n\n\n\n", m_fileout); } - setbuf(m_fileout, nullptr); // unbuffered // dump buffered messages from before we opened the log + m_buffering = false; while (!m_msgs_before_open.empty()) { - FileWriteStr(m_msgs_before_open.front(), m_fileout); + const std::string& s = m_msgs_before_open.front(); + + if (m_print_to_file) FileWriteStr(s, m_fileout); + if (m_print_to_console) fwrite(s.data(), 1, s.size(), stdout); + m_msgs_before_open.pop_front(); } + if (m_print_to_console) fflush(stdout); return true; } @@ -202,8 +216,9 @@ std::string BCLog::Logger::LogTimestampStr(const std::string& str) return strStamped; } -void BCLog::Logger::LogPrintStr(const std::string &str) +void BCLog::Logger::LogPrintStr(const std::string& str) { + std::lock_guard<std::mutex> scoped_lock(m_cs); std::string str_prefixed = str; if (m_log_threadnames && m_started_new_line) { @@ -214,32 +229,31 @@ void BCLog::Logger::LogPrintStr(const std::string &str) m_started_new_line = !str.empty() && str[str.size()-1] == '\n'; + if (m_buffering) { + // buffer if we haven't started logging yet + m_msgs_before_open.push_back(str_prefixed); + return; + } + if (m_print_to_console) { // print to console fwrite(str_prefixed.data(), 1, str_prefixed.size(), stdout); fflush(stdout); } if (m_print_to_file) { - std::lock_guard<std::mutex> scoped_lock(m_file_mutex); - - // buffer if we haven't opened the log yet - if (m_fileout == nullptr) { - m_msgs_before_open.push_back(str_prefixed); - } - else - { - // 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; - } + 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); } + FileWriteStr(str_prefixed, m_fileout); } } diff --git a/src/logging.h b/src/logging.h index e399d4c307..36b1a4045d 100644 --- a/src/logging.h +++ b/src/logging.h @@ -60,9 +60,10 @@ namespace BCLog { class Logger { private: - FILE* m_fileout = nullptr; - std::mutex m_file_mutex; - std::list<std::string> m_msgs_before_open; + mutable std::mutex m_cs; // Can not use Mutex from sync.h because in debug mode it would cause a deadlock when a potential deadlock was detected + FILE* m_fileout = nullptr; // GUARDED_BY(m_cs) + std::list<std::string> m_msgs_before_open; // GUARDED_BY(m_cs) + bool m_buffering{true}; //!< Buffer messages before logging can be started. GUARDED_BY(m_cs) /** * m_started_new_line is a state variable that will suppress printing of @@ -88,12 +89,18 @@ namespace BCLog { std::atomic<bool> m_reopen_file{false}; /** Send a string to the log output */ - void LogPrintStr(const std::string &str); + void LogPrintStr(const std::string& str); /** Returns whether logs will be written to any output */ - bool Enabled() const { return m_print_to_console || m_print_to_file; } + bool Enabled() const + { + std::lock_guard<std::mutex> scoped_lock(m_cs); + return m_buffering || m_print_to_console || m_print_to_file; + } + + /** Start logging (and flush all buffered messages) */ + bool StartLogging(); - bool OpenDebugLog(); void ShrinkDebugFile(); uint32_t GetCategoryMask() const { return m_categories.load(); } diff --git a/test/functional/feature_config_args.py b/test/functional/feature_config_args.py index 2b93e3c24d..074a832594 100755 --- a/test/functional/feature_config_args.py +++ b/test/functional/feature_config_args.py @@ -61,9 +61,16 @@ class ConfArgsTest(BitcoinTestFramework): with open(inc_conf_file2_path, 'w', encoding='utf-8') as conf: conf.write('') # clear + def test_log_buffer(self): + with self.nodes[0].assert_debug_log(expected_msgs=['Warning: parsed potentially confusing double-negative -connect=0']): + self.start_node(0, extra_args=['-noconnect=0']) + self.stop_node(0) + def run_test(self): self.stop_node(0) + self.test_log_buffer() + self.test_config_file_parser() # Remove the -datadir argument so it doesn't override the config file |