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
This commit is contained in:
Guilherme Lawless 2020-08-24 18:54:32 +01:00 committed by GitHub
commit 0007250678
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
2 changed files with 56 additions and 1 deletions

View file

@ -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);
}

View file

@ -6,6 +6,7 @@
#include <boost/date_time/posix_time/posix_time.hpp>
#include <boost/log/expressions.hpp>
#include <boost/log/utility/exception_handler.hpp>
#include <boost/log/utility/setup/common_attributes.hpp>
#include <boost/log/utility/setup/console.hpp>
#include <boost/log/utility/setup/file.hpp>
@ -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_<pattern> instead of log_<pattern>.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<std::exception> (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 ();
}
}