From 000725067896c1e090f99aec13378049c07da5ff Mon Sep 17 00:00:00 2001 From: Guilherme Lawless Date: Mon, 24 Aug 2020 18:54:32 +0100 Subject: [PATCH] Logging exception handler and fix for stable_log_filename on windows (#2880) * Logging exception handler and fix for stable_log_filename on windows Although our logger has never thrown in normal conditions, it has been reported to when stressing the RPC in a RAM node, especially with a low rotation file size. This adds an exception handler that handles by simply prints to stderr. Also fixes an issue with the `stable_log_filename` config on Windows. The `node.log` file was being created with read-only permissions, so writing to the file after restarting the node would throw an exception. However, this can't be unit tested because the file gets the full permissions by default. The change to `nano::logging::release_file_sink ()` enables the added test. * Set permissions for pre-existing log file as well, as Boost re-creates with read-only on rotation --- nano/core_test/logger.cpp | 32 ++++++++++++++++++++++++++++++++ nano/node/logging.cpp | 25 ++++++++++++++++++++++++- 2 files changed, 56 insertions(+), 1 deletion(-) diff --git a/nano/core_test/logger.cpp b/nano/core_test/logger.cpp index 8a769e04..18c6272b 100644 --- a/nano/core_test/logger.cpp +++ b/nano/core_test/logger.cpp @@ -121,3 +121,35 @@ TEST (logger, always_log) std::getline (ss, str, '\n'); ASSERT_STREQ (str.c_str (), output2); } + +TEST (logger, stable_filename) +{ + auto path (nano::unique_path ()); + nano::logging logging; + + // Releasing allows setting up logging again + logging.release_file_sink (); + + logging.stable_log_filename = true; + logging.init (path); + + nano::logger_mt logger (logging.min_time_between_log_output); + logger.always_log ("stable1"); + + auto log_file = path / "log" / "node.log"; + +#if BOOST_VERSION >= 107000 + EXPECT_TRUE (boost::filesystem::exists (log_file)); + // Try opening it again + logging.release_file_sink (); + logging.init (path); + logger.always_log ("stable2"); +#else + // When using Boost < 1.70 , behavior is reverted to not using the stable filename + EXPECT_FALSE (boost::filesystem::exists (log_file)); +#endif + + // Reset the logger + logging.release_file_sink (); + nano::logging ().init (path); +} \ No newline at end of file diff --git a/nano/node/logging.cpp b/nano/node/logging.cpp index 2fb2d284..6115d0b2 100644 --- a/nano/node/logging.cpp +++ b/nano/node/logging.cpp @@ -6,6 +6,7 @@ #include #include +#include #include #include #include @@ -81,11 +82,12 @@ void nano::logging::init (boost::filesystem::path const & application_path_a) if (stable_log_filename) { #if BOOST_VERSION >= 107000 + auto const file_name = path / "node.log"; // Logging to node.log and node_ instead of log_.log is deliberate. This way, // existing log monitoring scripts expecting the old logfile structure will fail immediately instead // of reading only rotated files with old entries. file_sink = boost::log::add_file_log (boost::log::keywords::target = path, - boost::log::keywords::file_name = path / "node.log", + boost::log::keywords::file_name = file_name, boost::log::keywords::target_file_name = path / "node_%Y-%m-%d_%H-%M-%S.%N.log", boost::log::keywords::open_mode = std::ios_base::out | std::ios_base::app, // append to node.log if it exists boost::log::keywords::enable_final_rotation = false, // for stable log filenames, don't rotate on destruction @@ -94,6 +96,16 @@ void nano::logging::init (boost::filesystem::path const & application_path_a) boost::log::keywords::scan_method = boost::log::sinks::file::scan_method::scan_matching, boost::log::keywords::max_size = max_size, // max total size in bytes of all log files boost::log::keywords::format = format_with_timestamp); + + if (!boost::filesystem::exists (file_name)) + { + // Create temp stream to first create the file + std::ofstream stream (file_name.string ()); + } + + // Set permissions before opening otherwise Windows only has read permissions + nano::set_secure_perm_file (file_name); + #else debug_assert (false); #endif @@ -108,6 +120,16 @@ void nano::logging::init (boost::filesystem::path const & application_path_a) boost::log::keywords::max_size = max_size, boost::log::keywords::format = format_with_timestamp); } + + struct exception_handler + { + void operator() (std::exception const & e) const + { + std::cerr << "Logging exception: " << e.what () << std::endl; + } + }; + + boost::log::core::get ()->set_exception_handler (boost::log::make_exception_handler (exception_handler ())); } //clang-format on } @@ -118,6 +140,7 @@ void nano::logging::release_file_sink () { boost::log::core::get ()->remove_sink (nano::logging::file_sink); nano::logging::file_sink.reset (); + logging_already_added.clear (); } }