Skip to content

Commit

Permalink
Logging exception handler and fix for stable_log_filename on windows (#…
Browse files Browse the repository at this point in the history
…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
  • Loading branch information
guilhermelawless authored Aug 24, 2020
1 parent 9102122 commit 0007250
Show file tree
Hide file tree
Showing 2 changed files with 56 additions and 1 deletion.
32 changes: 32 additions & 0 deletions nano/core_test/logger.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -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);
}
25 changes: 24 additions & 1 deletion nano/node/logging.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -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>
Expand Down Expand Up @@ -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
Expand All @@ -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
Expand All @@ -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
}
Expand All @@ -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 ();
}
}

Expand Down

0 comments on commit 0007250

Please sign in to comment.