Skip to content

Commit

Permalink
exclude CSV loggers from logging error logs in signal handler when us…
Browse files Browse the repository at this point in the history
…ing CsvWriter (#589)

* exclude CSV loggers from logging error logs in signal handler when using CsvWriter

* remove redundant namespace prefix
  • Loading branch information
odygrd authored Sep 25, 2024
1 parent 443a962 commit cd2eb4c
Show file tree
Hide file tree
Showing 13 changed files with 100 additions and 58 deletions.
6 changes: 6 additions & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
@@ -1,3 +1,4 @@
- [v7.3.0](#v730)
- [v7.2.2](#v722)
- [v7.2.1](#v721)
- [v7.2.0](#v720)
Expand Down Expand Up @@ -77,6 +78,11 @@
- [v1.1.0](#v110)
- [v1.0.0](#v100)

## v7.3.0

- Prevented error logs from the `SignalHandler` from being output to CSV files when a `CsvWriter` is in
use. ([#588](https://github.com/odygrd/quill/issues/588))

## v7.2.2

- Fixed race condition during DLL unload by ensuring safe cleanup of `ThreadContext` when
Expand Down
5 changes: 3 additions & 2 deletions include/quill/Backend.h
Original file line number Diff line number Diff line change
@@ -1,5 +1,5 @@
/**
* @page copyright
* @page copyright
* Copyright(c) 2020-present, Odysseas Georgoudis & quill contributors.* @page copyright
* Distributed under the MIT License (http://opensource.org/licenses/MIT)
*/
Expand Down Expand Up @@ -220,7 +220,8 @@ class Backend

if (!manual_backend_worker)
{
QUILL_THROW(QuillError{"acquire_manual_backend_worker() can only be called once per process. "
QUILL_THROW(
QuillError{"acquire_manual_backend_worker() can only be called once per process. "
"Additionally, it should "
"not be called when start() or start_with_signal_handler() has been invoked"});
}
Expand Down
29 changes: 15 additions & 14 deletions include/quill/CsvWriter.h
Original file line number Diff line number Diff line change
Expand Up @@ -52,7 +52,7 @@ class CsvWriter
FilenameAppendOption filename_append = FilenameAppendOption::None)
{
_logger = Frontend::create_or_get_logger(
filename + "_csv",
_logger_name_prefix + filename,
Frontend::create_or_get_sink<FileSink>(filename,
[open_mode, filename_append]()
{
Expand All @@ -61,9 +61,9 @@ class CsvWriter
cfg.set_filename_append_option(filename_append);
return cfg;
}()),
quill::PatternFormatterOptions{"%(message)", "", Timezone::GmtTime});
PatternFormatterOptions{"%(message)", "", Timezone::GmtTime});

_logger->template log_statement<false, false>(quill::LogLevel::None, &header_metadata, TCsvSchema::header);
_logger->template log_statement<false, false>(LogLevel::None, &_header_metadata, TCsvSchema::header);
}

/**
Expand All @@ -74,11 +74,10 @@ class CsvWriter
*/
CsvWriter(std::string const& unique_name, std::shared_ptr<Sink> sink)
{
_logger =
Frontend::create_or_get_logger(unique_name + "_csv", std::move(sink),
quill::PatternFormatterOptions{"%(message)", "", Timezone::GmtTime});
_logger = Frontend::create_or_get_logger(_logger_name_prefix + unique_name, std::move(sink),
PatternFormatterOptions{"%(message)", "", Timezone::GmtTime});

_logger->template log_statement<false, false>(quill::LogLevel::None, &header_metadata, TCsvSchema::header);
_logger->template log_statement<false, false>(LogLevel::None, &_header_metadata, TCsvSchema::header);
}

/**
Expand All @@ -90,9 +89,9 @@ class CsvWriter
CsvWriter(std::string const& unique_name, std::initializer_list<std::shared_ptr<Sink>> sinks)
{
_logger = Frontend::create_or_get_logger(
unique_name + "_csv", sinks, quill::PatternFormatterOptions{"%(message)", "", Timezone::GmtTime});
_logger_name_prefix + unique_name, sinks, PatternFormatterOptions{"%(message)", "", Timezone::GmtTime});

_logger->template log_statement<false, false>(quill::LogLevel::None, &header_metadata, TCsvSchema::header);
_logger->template log_statement<false, false>(LogLevel::None, &_header_metadata, TCsvSchema::header);
}

/**
Expand All @@ -112,7 +111,7 @@ class CsvWriter
template <typename... Args>
void append_row(Args&&... fields)
{
_logger->template log_statement<false, false>(quill::LogLevel::None, &line_metadata, fields...);
_logger->template log_statement<false, false>(LogLevel::None, &_line_metadata, fields...);
}

/**
Expand All @@ -122,11 +121,13 @@ class CsvWriter
void flush() { _logger->flush_log(); }

private:
static constexpr quill::MacroMetadata header_metadata{
"", "", "{}", nullptr, LogLevel::Info, quill::MacroMetadata::Event::Log};
static constexpr MacroMetadata _header_metadata{
"", "", "{}", nullptr, LogLevel::Info, MacroMetadata::Event::Log};

static constexpr quill::MacroMetadata line_metadata{
"", "", TCsvSchema::format, nullptr, LogLevel::Info, quill::MacroMetadata::Event::Log};
static constexpr MacroMetadata _line_metadata{
"", "", TCsvSchema::format, nullptr, LogLevel::Info, MacroMetadata::Event::Log};

static inline std::string _logger_name_prefix {"__csv__"};

LoggerImpl<TFrontendOptions>* _logger{nullptr};
};
Expand Down
14 changes: 7 additions & 7 deletions include/quill/Logger.h
Original file line number Diff line number Diff line change
Expand Up @@ -74,22 +74,22 @@ class LoggerImpl : public detail::LoggerBase
#ifndef NDEBUG
if (has_dynamic_log_level)
{
assert((dynamic_log_level != quill::LogLevel::None) &&
assert((dynamic_log_level != LogLevel::None) &&
"When has_dynamic_log_level is set to true then dynamic_log_level should not be None");
}

if (dynamic_log_level != quill::LogLevel::None)
if (dynamic_log_level != LogLevel::None)
{
assert((macro_metadata->log_level() == quill::LogLevel::Dynamic) &&
assert((macro_metadata->log_level() == LogLevel::Dynamic) &&
"MacroMetadata LogLevel must be Dynamic when using a dynamic_log_level");

assert(has_dynamic_log_level &&
"When dynamic_log_level is used then has_dynamic_log_level must also be true");
}

if (macro_metadata->log_level() != quill::LogLevel::Dynamic)
if (macro_metadata->log_level() != LogLevel::Dynamic)
{
assert((dynamic_log_level == quill::LogLevel::None) &&
assert((dynamic_log_level == LogLevel::None) &&
"No dynamic_log_level should be set when MacroMetadata LogLevel is not Dynamic");
}

Expand Down Expand Up @@ -224,7 +224,7 @@ class LoggerImpl : public detail::LoggerBase
*/
void init_backtrace(uint32_t max_capacity, LogLevel flush_level = LogLevel::None)
{
// we do not care about the other fields, except quill::MacroMetadata::Event::InitBacktrace
// we do not care about the other fields, except MacroMetadata::Event::InitBacktrace
static constexpr MacroMetadata macro_metadata{
"", "", "{}", nullptr, LogLevel::Critical, MacroMetadata::Event::InitBacktrace};

Expand All @@ -244,7 +244,7 @@ class LoggerImpl : public detail::LoggerBase
*/
void flush_backtrace()
{
// we do not care about the other fields, except quill::MacroMetadata::Event::Flush
// we do not care about the other fields, except MacroMetadata::Event::Flush
static constexpr MacroMetadata macro_metadata{
"", "", "", nullptr, LogLevel::Critical, MacroMetadata::Event::FlushBacktrace};

Expand Down
6 changes: 3 additions & 3 deletions include/quill/StringRef.h
Original file line number Diff line number Diff line change
Expand Up @@ -46,15 +46,15 @@ class StringRef

/***/
template <>
struct Codec<quill::utility::StringRef>
struct Codec<utility::StringRef>
{
static size_t compute_encoded_size(detail::SizeCacheVector&, quill::utility::StringRef const&) noexcept
static size_t compute_encoded_size(detail::SizeCacheVector&, utility::StringRef const&) noexcept
{
return sizeof(size_t) + sizeof(uintptr_t);
}

static void encode(std::byte*& buffer, detail::SizeCacheVector const&, uint32_t&,
quill::utility::StringRef const& no_copy) noexcept
utility::StringRef const& no_copy) noexcept
{
char const* data = no_copy.get_string_view().data();
std::memcpy(buffer, &data, sizeof(uintptr_t));
Expand Down
2 changes: 1 addition & 1 deletion include/quill/backend/BackendManager.h
Original file line number Diff line number Diff line change
Expand Up @@ -22,7 +22,6 @@ class BackendTscClock;

namespace detail
{

/**
* Provides access to common collection class that are used by both the frontend and the backend
* components of the logging system
Expand Down Expand Up @@ -90,6 +89,7 @@ class BackendManager
{
return &_manual_backend_worker;
}

private:
BackendWorker _backend_worker;
ManualBackendWorker _manual_backend_worker{&_backend_worker};
Expand Down
2 changes: 1 addition & 1 deletion include/quill/backend/BackendWorker.h
Original file line number Diff line number Diff line change
Expand Up @@ -710,7 +710,7 @@ class BackendWorker
{
transit_event->named_args->clear();
}

thread_context->_transit_event_buffer->pop_front();

if (flush_flag)
Expand Down
41 changes: 24 additions & 17 deletions include/quill/backend/SignalHandler.h
Original file line number Diff line number Diff line change
Expand Up @@ -58,6 +58,8 @@ class SignalHandlerContext
return instance;
}

static constexpr std::string_view excluded_logger_name_substr = {"__csv__"};

std::atomic<int32_t> signal_number{0};
std::atomic<uint32_t> lock{0};
std::atomic<uint32_t> backend_thread_id{0};
Expand All @@ -69,16 +71,16 @@ class SignalHandlerContext
~SignalHandlerContext() = default;
};

#define QUILL_SIGNAL_HANDLER_LOG(logger, log_level, fmt, ...) \
do \
{ \
if (logger->template should_log_statement<log_level>()) \
{ \
static constexpr quill::MacroMetadata macro_metadata{ \
#define QUILL_SIGNAL_HANDLER_LOG(logger, log_level, fmt, ...) \
do \
{ \
if (logger->template should_log_statement<log_level>()) \
{ \
static constexpr quill::MacroMetadata macro_metadata{ \
"SignalHandler:~", "", fmt, nullptr, log_level, quill::MacroMetadata::Event::Log}; \
\
logger->template log_statement<false, false>(quill::LogLevel::None, &macro_metadata, ##__VA_ARGS__); \
} \
} \
} while (0)

/***/
Expand Down Expand Up @@ -125,7 +127,8 @@ void on_signal(int32_t signal_number)
{
std::exit(EXIT_SUCCESS);
}
else if (should_reraise_signal)

if (should_reraise_signal)
{
// for other signals expect SIGINT and SIGTERM we re-raise
std::signal(signal_number, SIG_DFL);
Expand All @@ -135,7 +138,8 @@ void on_signal(int32_t signal_number)
else
{
// This means signal handler is running on a frontend thread, we can log and flush
LoggerBase* logger_base = detail::LoggerManager::instance().get_valid_logger();
LoggerBase* logger_base =
detail::LoggerManager::instance().get_valid_logger(SignalHandlerContext::excluded_logger_name_substr);

if (logger_base)
{
Expand All @@ -146,7 +150,7 @@ void on_signal(int32_t signal_number)
#endif

auto logger = reinterpret_cast<LoggerImpl<TFrontendOptions>*>(logger_base);
QUILL_SIGNAL_HANDLER_LOG(logger, quill::LogLevel::Info, "Received signal: {} (signum: {})",
QUILL_SIGNAL_HANDLER_LOG(logger, LogLevel::Info, "Received signal: {} (signum: {})",
signal_desc, signal_number);

if (signal_number == SIGINT || signal_number == SIGTERM)
Expand All @@ -156,9 +160,10 @@ void on_signal(int32_t signal_number)
logger->flush_log(0);
std::exit(EXIT_SUCCESS);
}
else if (should_reraise_signal)

if (should_reraise_signal)
{
QUILL_SIGNAL_HANDLER_LOG(logger, quill::LogLevel::Critical,
QUILL_SIGNAL_HANDLER_LOG(logger, LogLevel::Critical,
"Program terminated unexpectedly due to signal: {} (signum: {})",
signal_desc, signal_number);

Expand Down Expand Up @@ -246,11 +251,12 @@ BOOL WINAPI on_console_signal(DWORD signal)
(signal == CTRL_C_EVENT || signal == CTRL_BREAK_EVENT))
{
// Log the interruption and flush log messages
LoggerBase* logger_base = detail::LoggerManager::instance().get_valid_logger();
LoggerBase* logger_base =
detail::LoggerManager::instance().get_valid_logger(SignalHandlerContext::excluded_logger_name_substr);
if (logger_base)
{
auto logger = reinterpret_cast<LoggerImpl<TFrontendOptions>*>(logger_base);
QUILL_SIGNAL_HANDLER_LOG(logger, quill::LogLevel::Info,
QUILL_SIGNAL_HANDLER_LOG(logger, LogLevel::Info,
"Program interrupted by Ctrl+C or Ctrl+Break signal");

// Pass `0` to avoid calling std::this_thread::sleep_for()
Expand All @@ -273,16 +279,17 @@ LONG WINAPI on_exception(EXCEPTION_POINTERS* exception_p)
if ((backend_thread_id != 0) && (current_thread_id != backend_thread_id))
{
// Log the interruption and flush log messages
LoggerBase* logger_base = detail::LoggerManager::instance().get_valid_logger();
LoggerBase* logger_base =
detail::LoggerManager::instance().get_valid_logger(SignalHandlerContext::excluded_logger_name_substr);
if (logger_base)
{
auto logger = reinterpret_cast<LoggerImpl<TFrontendOptions>*>(logger_base);

QUILL_SIGNAL_HANDLER_LOG(logger, quill::LogLevel::Info, "Received exception: {} (Code: {})",
QUILL_SIGNAL_HANDLER_LOG(logger, LogLevel::Info, "Received exception: {} (Code: {})",
get_error_message(exception_p->ExceptionRecord->ExceptionCode),
exception_p->ExceptionRecord->ExceptionCode);

QUILL_SIGNAL_HANDLER_LOG(logger, quill::LogLevel::Critical,
QUILL_SIGNAL_HANDLER_LOG(logger, LogLevel::Critical,
"Program terminated unexpectedly due to exception: {} (Code: {})",
get_error_message(exception_p->ExceptionRecord->ExceptionCode),
exception_p->ExceptionRecord->ExceptionCode);
Expand Down
2 changes: 1 addition & 1 deletion include/quill/core/FrontendOptions.h
Original file line number Diff line number Diff line change
Expand Up @@ -25,7 +25,7 @@ struct FrontendOptions
*
* By default, the library uses an UnboundedBlocking queue, which starts with initial_queue_capacity.
*/
static constexpr quill::QueueType queue_type = quill::QueueType::UnboundedBlocking;
static constexpr QueueType queue_type = QueueType::UnboundedBlocking;

/**
* Initial capacity of the queue. Used for UnboundedBlocking, UnboundedDropping, and
Expand Down
11 changes: 9 additions & 2 deletions include/quill/core/LoggerManager.h
Original file line number Diff line number Diff line change
Expand Up @@ -18,6 +18,7 @@
#include <initializer_list>
#include <memory>
#include <string>
#include <string_view>
#include <vector>

QUILL_BEGIN_NAMESPACE
Expand Down Expand Up @@ -69,7 +70,7 @@ class LoggerManager
}

/***/
QUILL_NODISCARD LoggerBase* get_valid_logger() const
QUILL_NODISCARD LoggerBase* get_valid_logger(std::string_view exclude_logger_substr = {}) const
{
// Retrieves any valid logger without the need for constructing a vector
LockGuard const lock{_spinlock};
Expand All @@ -79,7 +80,13 @@ class LoggerManager
// we can not add invalidated loggers as they can be removed at any time
if (elem->is_valid_logger())
{
return elem.get();
// Return the logger only if it does not match the exclude_logger_substr
if (exclude_logger_substr.empty() ||
elem->get_logger_name().find(exclude_logger_substr) == std::string::npos)
{
// Return this logger if it's valid and not excluded
return elem.get();
}
}
}

Expand Down
4 changes: 2 additions & 2 deletions include/quill/core/UnboundedSPSCQueue.h
Original file line number Diff line number Diff line change
Expand Up @@ -106,7 +106,7 @@ class UnboundedSPSCQueue
* making it visible to the consumer.
* @return a valid point to the buffer
*/
template <quill::QueueType queue_type>
template <QueueType queue_type>
QUILL_NODISCARD QUILL_ATTRIBUTE_HOT std::byte* prepare_write(size_t nbytes)
{
// Try to reserve the bounded queue
Expand Down Expand Up @@ -200,7 +200,7 @@ class UnboundedSPSCQueue

private:
/***/
template <quill::QueueType queue_type>
template <QueueType queue_type>
QUILL_NODISCARD std::byte* _handle_full_queue(size_t nbytes)
{
// Then it means the queue doesn't have enough size
Expand Down
Loading

0 comments on commit cd2eb4c

Please sign in to comment.