add option add_metadata_to_multi_line_logs

CHANGELOG.md

@@ -75,9 +75,12 @@
 
 ## v7.0.0 - TBD
 
-- Simplified the log tags API. The `Tags` class has been removed. You now pass a `char const*` directly to the macros. Additionally, macros previously named `WITH_TAGS` have been renamed to `_TAGS`. For example, `LOG_INFO_WITH_TAGS` is now `LOG_INFO_TAGS`.
+- Simplified the log tags API. The `Tags` class has been removed. You now pass a `char const*` directly to the macros.
+  Additionally, macros previously named `WITH_TAGS` have been renamed to `_TAGS`. For example, `LOG_INFO_WITH_TAGS` is
+  now `LOG_INFO_TAGS`.
 - Renamed `backend_cpu_affinity` to `cpu_affinity` in `BackendOptions` to improve consistency.
-- Simplified project structure by removing the extra quill directory and made minor CMake improvements; `include/quill` is now directly in the root.
+- Simplified project structure by removing the extra quill directory and made minor CMake improvements; `include/quill`
+  is now directly in the root.
 - Added support for `std::string` with custom allocator. ([#524](https://github.com/odygrd/quill/issues/524))
 - Added a new log level `NOTICE`, for capturing significant events that aren't errors or warnings. It fits
   between `INFO` and `WARNING` for logging important runtime events that require
@@ -90,6 +93,15 @@
 - Minor performance enhancement in the frontend by replacing `std::vector<size_t>` with an `InlinedVector<uint32_t, 12>`
   for caching sizes (e.g. string arguments).
 - Fixed order of evaluation for `Codec::pair<T1,T2>::compute_encoded_size()` to prevent side effects observed on MSVC
+- Introduced the `add_metadata_to_multi_line_logs` option in `PatternFormatter`. This option, now enabled by default,
+  appends metadata such as timestamps and log levels to every line of multiline log entries, ensuring consistent log
+  output. To restore the previous behavior, set this option to false when creating a `Logger`
+  using `Frontend::create_or_get_logger(...)`. Note that this option is ignored when logging JSON using named arguments
+  in the format message. ([#534](https://github.com/odygrd/quill/pull/534))
+- The functions `Frontend::create_or_get_logger(...)` now takes an additional
+  parameter, `add_metadata_to_multi_line_logs`.
+- `JSON` sinks now automatically remove any `\n` characters from format messages, ensuring the emission of valid `JSON`
+  messages even when `\n` is present in the format.
 
 ## v6.1.2
 

benchmarks/backend_throughput/quill_backend_throughput.cpp

@@ -37,7 +37,8 @@ int main()
 
   quill::Logger* logger = quill::Frontend::create_or_get_logger(
     "bench_logger", std::move(file_sink),
-    "%(time) [%(thread_id)] %(short_source_location) %(log_level) %(message)");
+    "%(time) [%(thread_id)] %(short_source_location) %(log_level) %(message)", "%H:%M:%S.%Qns",
+    quill::Timezone::LocalTime, false);
 
   quill::Frontend::preallocate();
 

benchmarks/backend_throughput/quill_backend_throughput_no_buffering.cpp

@@ -38,7 +38,9 @@ int main()
 
   quill::Logger* logger = quill::Frontend::create_or_get_logger(
     "bench_logger", std::move(file_sink),
-    "%(time) [%(thread_id)] %(short_source_location) %(log_level) %(message)");
+    "%(time) [%(thread_id)] %(short_source_location) %(log_level) %(message)", "%H:%M:%S.%Qns",
+    quill::Timezone::LocalTime, false);
+  ;
 
   quill::Frontend::preallocate();
 

benchmarks/hot_path_latency/quill_hot_path_rdtsc_clock.cpp

@@ -56,7 +56,8 @@ void quill_benchmark(std::vector<uint16_t> const& thread_count_array,
 
   Logger* logger = Frontend::create_or_get_logger(
     "bench_logger", std::move(file_sink),
-    "%(time) [%(thread_id)] %(short_source_location) %(log_level) %(message)");
+    "%(time) [%(thread_id)] %(short_source_location) %(log_level) %(message)", "%H:%M:%S.%Qns",
+    quill::Timezone::LocalTime, false);
 
   /** LOGGING THREAD FUNCTIONS - on_start, on_exit, log_func must be implemented **/
   /** those run on a several thread(s). It can be one or multiple threads based on THREAD_LIST_COUNT config */

benchmarks/hot_path_latency/quill_hot_path_system_clock.cpp

@@ -57,7 +57,7 @@ void quill_benchmark(std::vector<uint16_t> const& thread_count_array,
   Logger* logger = Frontend::create_or_get_logger(
     "bench_logger", std::move(file_sink),
     "%(time) [%(thread_id)] %(short_source_location) %(log_level) %(message)", "%H:%M:%S.%Qns",
-    quill::Timezone::LocalTime, quill::ClockSourceType::System);
+    quill::Timezone::LocalTime, false, quill::ClockSourceType::System);
 
   /** LOGGING THREAD FUNCTIONS - on_start, on_exit, log_func must be implemented **/
   /** those run on a several thread(s). It can be one or multiple threads based on THREAD_LIST_COUNT config */

examples/system_clock_logging.cpp

@@ -23,7 +23,7 @@ int main()
 
   quill::Logger* logger = quill::Frontend::create_or_get_logger(
     "root", std::move(console_sink), "%(time) [%(process_id)] [%(thread_id)] %(logger) - %(message)",
-    "%D %H:%M:%S.%Qms %z", quill::Timezone::GmtTime, quill::ClockSourceType::System);
+    "%D %H:%M:%S.%Qms %z", quill::Timezone::GmtTime, false, quill::ClockSourceType::System);
 
   // Change the LogLevel to print everything
   logger->set_log_level(quill::LogLevel::TraceL3);

examples/user_clock_source.cpp

@@ -64,7 +64,7 @@ int main()
   quill::Logger* logger = quill::Frontend::create_or_get_logger(
     "root", std::move(console_sink),
     "%(time) %(short_source_location:<28) LOG_%(log_level:<9) %(logger:<12) %(message)",
-    "%D %H:%M:%S.%Qns", quill::Timezone::LocalTime, quill::ClockSourceType::User, &simulated_clock);
+    "%D %H:%M:%S.%Qns", quill::Timezone::LocalTime, false, quill::ClockSourceType::User, &simulated_clock);
 
   // Change the LogLevel to print everything
   logger->set_log_level(quill::LogLevel::TraceL3);

include/quill/Frontend.h

@@ -42,8 +42,8 @@ class FrontendImpl
   QUILL_ATTRIBUTE_COLD static void preallocate()
   {
     uint32_t const volatile spsc_queue_capacity = detail::get_local_thread_context<TFrontendOptions>()
-        ->template get_spsc_queue<TFrontendOptions::queue_type>()
-        .capacity();
+                                                    ->template get_spsc_queue<TFrontendOptions::queue_type>()
+                                                    .capacity();
 
     // On windows and c++17, QUILL_MAYBE_UNUSED won't work
     (void)spsc_queue_capacity;
@@ -81,24 +81,29 @@ class FrontendImpl
    * @param format_pattern The format pattern for log messages.
    * @param time_pattern The time pattern for log timestamps.
    * @param timestamp_timezone The timezone for log timestamps.
+   * @param add_metadata_to_multi_line_logs If true, ensures that metadata (such as timestamps and log levels) is appended to every line in multi-line log entries, maintaining consistency in log outputs.
+   *        Note: This option is ignored when logging `JSON` with named arguments in the format message.
+   *        Note: This option only applies to multi-line log entries. It can be disabled if you prefer not to append metadata or if your logs are exclusively single-line entries.
    * @param clock_source The clock source for log timestamps.
    * @param user_clock A pointer to a custom user clock.
+   *
    * @return Logger* A pointer to the created or retrieved logger.
    */
   static logger_t* create_or_get_logger(
     std::string const& logger_name, std::shared_ptr<Sink> sink,
     std::string const& format_pattern =
       "%(time) [%(thread_id)] %(short_source_location:<28) LOG_%(log_level:<9) %(logger:<12) "
       "%(message)",
-    std::string const& time_pattern = "%H:%M:%S.%Qns", Timezone timestamp_timezone = Timezone::LocalTime,
+    std::string const& time_pattern = "%H:%M:%S.%Qns",
+    Timezone timestamp_timezone = Timezone::LocalTime, bool add_metadata_to_multi_line_logs = true,
     ClockSourceType clock_source = ClockSourceType::Tsc, UserClockSource* user_clock = nullptr)
   {
     std::vector<std::shared_ptr<Sink>> sinks;
     sinks.push_back(static_cast<std::shared_ptr<Sink>&&>(sink));
 
     return _cast_to_logger(detail::LoggerManager::instance().create_or_get_logger<logger_t>(
       logger_name, static_cast<std::vector<std::shared_ptr<Sink>>&&>(sinks), format_pattern,
-      time_pattern, timestamp_timezone, clock_source, user_clock));
+      time_pattern, timestamp_timezone, add_metadata_to_multi_line_logs, clock_source, user_clock));
   }
 
   /**
@@ -109,6 +114,9 @@ class FrontendImpl
    * @param format_pattern The format pattern for log messages.
    * @param time_pattern The time pattern for log timestamps.
    * @param timestamp_timezone The timezone for log timestamps.
+   * @param add_metadata_to_multi_line_logs If true, ensures that metadata (such as timestamps and log levels) is appended to every line in multi-line log entries, maintaining consistency in log outputs.
+   *        Note: This option is ignored when logging `JSON` with named arguments in the format message.
+   *        Note: This option only applies to multi-line log entries. It can be disabled if you prefer not to append metadata or if your logs are exclusively single-line entries.
    * @param clock_source The clock source for log timestamps.
    * @param user_clock A pointer to a custom user clock.
    * @return Logger* A pointer to the created or retrieved logger.
@@ -118,12 +126,13 @@ class FrontendImpl
     std::string const& format_pattern =
       "%(time) [%(thread_id)] %(short_source_location:<28) LOG_%(log_level:<9) %(logger:<12) "
       "%(message)",
-    std::string const& time_pattern = "%H:%M:%S.%Qns", Timezone timestamp_timezone = Timezone::LocalTime,
+    std::string const& time_pattern = "%H:%M:%S.%Qns",
+    Timezone timestamp_timezone = Timezone::LocalTime, bool add_metadata_to_multi_line_logs = true,
     ClockSourceType clock_source = ClockSourceType::Tsc, UserClockSource* user_clock = nullptr)
   {
     return _cast_to_logger(detail::LoggerManager::instance().create_or_get_logger<logger_t>(
       logger_name, std::vector<std::shared_ptr<Sink>>{sinks}, format_pattern, time_pattern,
-      timestamp_timezone, clock_source, user_clock));
+      timestamp_timezone, add_metadata_to_multi_line_logs, clock_source, user_clock));
   }
 
   /**
@@ -212,4 +221,4 @@ class FrontendImpl
 
 using Frontend = FrontendImpl<FrontendOptions>;
 
-QUILL_END_NAMESPACE
+QUILL_END_NAMESPACE

include/quill/Logger.h

@@ -313,11 +313,11 @@ class LoggerImpl : public detail::LoggerBase
   /***/
   LoggerImpl(std::string logger_name, std::vector<std::shared_ptr<Sink>> sinks,
              std::string format_pattern, std::string time_pattern, Timezone timestamp_timezone,
-             ClockSourceType clock_source, UserClockSource* user_clock)
+             bool add_metadata_to_multi_line_logs, ClockSourceType clock_source, UserClockSource* user_clock)
     : detail::LoggerBase(static_cast<std::string&&>(logger_name),
                          static_cast<std::vector<std::shared_ptr<Sink>>&&>(sinks),
-                         static_cast<std::string&&>(format_pattern),
-                         static_cast<std::string&&>(time_pattern), timestamp_timezone, clock_source, user_clock)
+                         static_cast<std::string&&>(format_pattern), static_cast<std::string&&>(time_pattern),
+        timestamp_timezone, add_metadata_to_multi_line_logs, clock_source, user_clock)
 
   {
     if (this->user_clock)

include/quill/backend/BackendWorker.h

@@ -494,6 +494,8 @@ class BackendWorker
         {
           if (logger->pattern_formatter &&
               (logger->pattern_formatter->format_pattern() == transit_event->logger_base->format_pattern) &&
+              (logger->pattern_formatter->get_add_metadata_to_multi_line_logs() ==
+               transit_event->logger_base->add_metadata_to_multi_line_logs) &&
               (logger->pattern_formatter->timestamp_formatter().time_format() ==
                transit_event->logger_base->time_pattern) &&
               (logger->pattern_formatter->timestamp_formatter().timestamp_timezone() ==
@@ -512,7 +514,7 @@ class BackendWorker
         // Didn't find an existing formatter  need to create a new pattern formatter
         transit_event->logger_base->pattern_formatter = std::make_shared<PatternFormatter>(
           transit_event->logger_base->format_pattern, transit_event->logger_base->time_pattern,
-          transit_event->logger_base->timezone);
+          transit_event->logger_base->timezone, transit_event->logger_base->add_metadata_to_multi_line_logs);
       }
     }
 
@@ -737,7 +739,7 @@ class BackendWorker
     {
       if (transit_event.log_level() != LogLevel::Backtrace)
       {
-        _write_transit_event_to_sinks(transit_event);
+        _dispatch_transit_event_to_sinks(transit_event);
 
         // We also need to check the severity of the log message here against the backtrace
         // Check if we should also flush the backtrace messages:
@@ -750,7 +752,7 @@ class BackendWorker
           if (transit_event.logger_base->backtrace_storage)
           {
             transit_event.logger_base->backtrace_storage->process(
-              [this](TransitEvent const& te) { _write_transit_event_to_sinks(te); });
+              [this](TransitEvent const& te) { _dispatch_transit_event_to_sinks(te); });
           }
         }
       }
@@ -786,8 +788,8 @@ class BackendWorker
       if (transit_event.logger_base->backtrace_storage)
       {
         // process all records in backtrace for this logger and log them
-        transit_event.logger_base->backtrace_storage->process([this](TransitEvent const& te)
-                                                              { _write_transit_event_to_sinks(te); });
+        transit_event.logger_base->backtrace_storage->process(
+          [this](TransitEvent const& te) { _dispatch_transit_event_to_sinks(te); });
       }
     }
     else if (transit_event.macro_metadata->event() == MacroMetadata::Event::Flush)
@@ -803,13 +805,10 @@ class BackendWorker
   }
 
   /**
-   * Write a transit event
+   * Dispatches a transit event
    */
-  QUILL_ATTRIBUTE_HOT void _write_transit_event_to_sinks(TransitEvent const& transit_event) const
+  QUILL_ATTRIBUTE_HOT void _dispatch_transit_event_to_sinks(TransitEvent const& transit_event) const
   {
-    std::string_view const log_message =
-      std::string_view{transit_event.formatted_msg.data(), transit_event.formatted_msg.size()};
-
     std::string_view const log_level_description =
       detail::log_level_to_string(transit_event.log_level(), _options.log_level_descriptions.data(),
                                   _options.log_level_descriptions.size());
@@ -818,14 +817,71 @@ class BackendWorker
       detail::log_level_to_string(transit_event.log_level(), _options.log_level_short_codes.data(),
                                   _options.log_level_short_codes.size());
 
+    if (transit_event.logger_base->pattern_formatter->get_add_metadata_to_multi_line_logs() &&
+        (!transit_event.named_args || transit_event.named_args->empty()))
+    {
+      // This is only supported when named_args are not used
+      _process_multi_line_message(transit_event, log_level_description, log_level_short_code);
+    }
+    else
+    {
+      // if the log_message ends with \n we should exclude it
+      size_t const log_message_size =
+        transit_event.formatted_msg.data()[transit_event.formatted_msg.size() - 1] == '\n'
+        ? transit_event.formatted_msg.size() - 2
+        : transit_event.formatted_msg.size();
+
+      // process the whole message without adding metadata to each line
+      _write_log_statement(transit_event, log_level_description, log_level_short_code,
+                           std::string_view{transit_event.formatted_msg.data(), log_message_size});
+    }
+  }
+
+  /**
+   * Splits and writes a transit event that has multiple lines
+   */
+  QUILL_ATTRIBUTE_HOT void _process_multi_line_message(TransitEvent const& transit_event,
+                                                       std::string_view const& log_level_description,
+                                                       std::string_view const& log_level_short_code) const
+  {
+    auto const msg =
+      std::string_view{transit_event.formatted_msg.data(), transit_event.formatted_msg.size()};
+
+    size_t start = 0;
+    while (start < msg.size())
+    {
+      size_t const end = msg.find_first_of('\n', start);
+
+      if (end == std::string_view::npos)
+      {
+        // Handle the last line or a single line without a newline
+        _write_log_statement(transit_event, log_level_description, log_level_short_code,
+                             std::string_view(msg.data() + start, msg.size() - start));
+        break;
+      }
+
+      // Write the current line
+      _write_log_statement(transit_event, log_level_description, log_level_short_code,
+                           std::string_view(msg.data() + start, end - start));
+      start = end + 1;
+    }
+  }
+
+  /**
+   * Formats and writes the log statement to each sink
+   */
+  QUILL_ATTRIBUTE_HOT void _write_log_statement(TransitEvent const& transit_event,
+                                                std::string_view const& log_level_description,
+                                                std::string_view const& log_level_short_code,
+                                                std::string_view const& log_message) const
+  {
     std::string_view const log_statement = transit_event.logger_base->pattern_formatter->format(
       transit_event.timestamp, transit_event.thread_id, transit_event.thread_name, _process_id,
       transit_event.logger_base->logger_name, log_level_description, log_level_short_code,
       *transit_event.macro_metadata, transit_event.named_args.get(), log_message);
 
     for (auto& sink : transit_event.logger_base->sinks)
     {
-      // If all filters are okay we write this message to the file
       if (sink->apply_all_filters(transit_event.macro_metadata, transit_event.timestamp,
                                   transit_event.thread_id, transit_event.thread_name,
                                   transit_event.logger_base->logger_name, transit_event.log_level(),