fix uncaught exception on handler flush(). Improve flush logic (#404)

fix uncaught exception on handler flush(). Improve flush logic

CHANGELOG.md

@@ -63,6 +63,14 @@
 - Fixed windows clang-cl build error. ([#400](https://github.com/odygrd/quill/pull/400))
 - Fixed compilation errors encountered on FreeBSD and extended ``get_thread_id()`` support to various other BSD
   operating systems. ([#401](https://github.com/odygrd/quill/pull/401))
+- Fix open_file in the FileHandler to also create the parent path before opening the
+  file. ([#395](https://github.com/odygrd/quill/issues/395))
+- Enhance logic for backend thread's flush() invocation; it now triggers only if the handler has previously written
+  data. ([#395](https://github.com/odygrd/quill/issues/395))
+- Address an uncaught exception in the backend thread that could occur when a user manually removes the log file from
+  the terminal while the logger is running. ([#395](https://github.com/odygrd/quill/issues/395))
+- Ensure that after a logger is removed, there are no subsequent calls to the Handler's flush() or run_loop(), provided
+  the Handler is not shared. ([#395](https://github.com/odygrd/quill/issues/395))
 - Update bundled `libfmt` to `v10.2.1`
 
 ## v3.6.0

quill/include/quill/detail/LoggerCollection.h

@@ -142,6 +142,24 @@ class LoggerCollection
    */
   QUILL_NODISCARD bool remove_invalidated_loggers(std::function<bool(void)> const& check_queues_empty);
 
+  /**
+   * Checks if any invalidated loggers exist
+   * @return
+   */
+  QUILL_NODISCARD bool has_invalidated_loggers() const noexcept
+  {
+    return _has_invalidated_loggers.load(std::memory_order_acquire);
+  }
+
+  /**
+   * Get a list of all the active subscribed handlers filtering out the handlers of any invalidated logger
+   * The list contains each handler only once regardless the amount of Logger instances using it
+   * This is not used for logging by the backend but only in special cases when
+   * e.g. it needs to iterate through all handlers for e.g. to flush
+   * @param active_handlers_collection active handlers collection
+   */
+  void active_handlers(std::vector<std::weak_ptr<Handler>>& active_handlers_collection) const;
+
 private:
   Config const& _config;
   ThreadContextCollection& _thread_context_collection; /**< We need to pass this to each logger */

quill/include/quill/detail/backend/BackendWorker.h

@@ -153,11 +153,6 @@ class BackendWorker
   QUILL_ATTRIBUTE_HOT inline bool _process_and_write_single_message(
     ThreadContextCollection::backend_thread_contexts_cache_t const& cached_thread_contexts);
 
-  /**
-   * Force flush all active Handlers
-   */
-  QUILL_ATTRIBUTE_HOT void _force_flush();
-
   /**
    * Check for dropped messages - only when bounded queue is used
    * @param cached_thread_contexts loaded thread contexts
@@ -192,6 +187,46 @@ class BackendWorker
    */
   QUILL_ATTRIBUTE_HOT void _resync_rdtsc_clock();
 
+  /**
+   * Updates the active handlers cache
+   */
+  void _flush_and_run_active_handlers_loop(bool run_loop)
+  {
+    if (_logger_collection.has_invalidated_loggers())
+    {
+      // If there are invalidated loggers we take a slower path and exclude the handlers of
+      // the invalidated loggers
+      _logger_collection.active_handlers(_active_handlers_cache);
+    }
+    else
+    {
+      _handler_collection.active_handlers(_active_handlers_cache);
+    }
+
+    for (auto const& handler : _active_handlers_cache)
+    {
+      std::shared_ptr<Handler> h = handler.lock();
+      if (h)
+      {
+        QUILL_TRY
+        {
+          // If an exception is thrown, catch it here to prevent it from propagating
+          // to the outer function. This prevents potential infinite loops caused by failing flush operations.
+          h->flush();
+        }
+#if !defined(QUILL_NO_EXCEPTIONS)
+        QUILL_CATCH(std::exception const& e) { _notification_handler(e.what()); }
+        QUILL_CATCH_ALL() { _notification_handler(std::string{"Caught unhandled exception."}); }
+#endif
+
+        if (run_loop)
+        {
+          h->run_loop();
+        }
+      }
+    }
+  }
+
 private:
   Config const& _config;
   ThreadContextCollection& _thread_context_collection;
@@ -223,7 +258,6 @@ class BackendWorker
   backend_worker_notification_handler_t _notification_handler; /** error handler for the backend thread */
 
   bool _backend_thread_yield; /** backend_thread_yield from config **/
-  bool _has_unflushed_messages{false}; /** There are messages that are buffered by the OS, but not yet flushed */
   bool _strict_log_timestamp_order{true};
   bool _empty_all_queues_before_exit{true};
   bool _use_transit_buffer{true};
@@ -689,18 +723,8 @@ void BackendWorker::_main_loop()
   {
     // None of the thread local queues had any events to process, this means we have processed
     // all messages in all queues We force flush all remaining messages
-    _handler_collection.active_handlers(_active_handlers_cache);
-    _force_flush();
 
-    // invoke the Handler's periodic loop
-    for (auto const& handler : _active_handlers_cache)
-    {
-      std::shared_ptr<Handler> h = handler.lock();
-      if (h)
-      {
-        h->run_loop();
-      }
-    }
+    _flush_and_run_active_handlers_loop(true);
 
     // check for any dropped messages / blocked threads
     _check_message_failures(cached_thread_contexts, _notification_handler);
@@ -815,8 +839,7 @@ void BackendWorker::_exit()
       {
         // we are done, all queues are now empty
         _check_message_failures(cached_thread_contexts, _notification_handler);
-        _handler_collection.active_handlers(_active_handlers_cache);
-        _force_flush();
+        _flush_and_run_active_handlers_loop(false);
         break;
       }
     }

quill/include/quill/handlers/FileHandler.h

@@ -113,7 +113,7 @@ class FileHandler : public StreamHandler
   /**
    * Flushes the stream and optionally fsyncs it
    */
-  QUILL_ATTRIBUTE_HOT void flush() noexcept override;
+  QUILL_ATTRIBUTE_HOT void flush() override;
 
 protected:
   void open_file(fs::path const& filename, std::string const& mode);

quill/include/quill/handlers/Handler.h

@@ -75,7 +75,7 @@ class Handler
   /**
    * Flush the handler synchronising the associated handler with its controlled output sequence.
    */
-  QUILL_ATTRIBUTE_HOT virtual void flush() noexcept = 0;
+  QUILL_ATTRIBUTE_HOT virtual void flush() = 0;
 
   /**
    * Executes periodically by the backend thread, providing an opportunity for the user

quill/include/quill/handlers/NullHandler.h

@@ -19,6 +19,6 @@ class NullHandler : public Handler
   QUILL_ATTRIBUTE_HOT void write(fmt_buffer_t const& formatted_log_message, TransitEvent const& log_event) override
   {
   }
-  QUILL_ATTRIBUTE_HOT void flush() noexcept override {}
+  QUILL_ATTRIBUTE_HOT void flush() override {}
 };
 } // namespace quill

quill/include/quill/handlers/StreamHandler.h

@@ -63,7 +63,7 @@ class StreamHandler : public Handler
   /**
    * Flushes the stream
    */
-  QUILL_ATTRIBUTE_HOT void flush() noexcept override;
+  QUILL_ATTRIBUTE_HOT void flush() override;
 
   /**
    * @return return the name of the file
@@ -82,5 +82,6 @@ class StreamHandler : public Handler
   FILE* _file{nullptr};
   FileEventNotifier _file_event_notifier;
   bool _is_null{false};
+  bool _write_occurred{false};
 };
 } // namespace quill

quill/src/detail/LoggerCollection.cpp

@@ -303,5 +303,40 @@ bool LoggerCollection::remove_invalidated_loggers(std::function<bool(void)> cons
 
   return loggers_removed;
 }
+
+/***/
+void LoggerCollection::active_handlers(std::vector<std::weak_ptr<Handler>>& active_handlers_collection) const
+{
+  active_handlers_collection.clear();
+
+  std::lock_guard<std::recursive_mutex> const lock{_rmutex};
+  for (auto const& [logger_name, logger_ptr] : _logger_name_map)
+  {
+    if (logger_ptr->is_invalidated())
+    {
+      // Skip handlers of invalidated loggers
+      continue;
+    }
+
+    std::vector<std::shared_ptr<Handler>> const& logger_handlers = logger_ptr->_logger_details.handlers();
+    for (std::shared_ptr<Handler> const& handler : logger_handlers)
+    {
+      auto search_it = std::find_if(std::begin(active_handlers_collection), std::end(active_handlers_collection),
+                                    [handler_ptr = handler.get()](std::weak_ptr<Handler> const& elem)
+                                    {
+                                      // no one else can remove the shared pointer as this is only
+                                      // running on backend thread, lock() will always succeed
+                                      return elem.lock().get() == handler_ptr;
+                                    });
+
+      if (search_it == std::end(active_handlers_collection))
+      {
+        // Add handler
+        active_handlers_collection.push_back(handler);
+      }
+    }
+  }
+}
+
 } // namespace detail
 } // namespace quill

quill/src/detail/backend/BackendWorker.cpp

@@ -425,38 +425,14 @@ void BackendWorker::_process_transit_event(TransitEvent& transit_event)
   }
   else if (macro_metadata.event() == MacroMetadata::Event::Flush)
   {
-    _handler_collection.active_handlers(_active_handlers_cache);
-    _force_flush();
+    _flush_and_run_active_handlers_loop(false);
 
     // this is a flush event, so we need to notify the caller to continue now
     transit_event.flush_flag->store(true);
 
     // we also need to reset the flush_flag as the TransitEvents are re-used
     transit_event.flush_flag = nullptr;
   }
-
-  // Since after processing an event we never force flush but leave it up to the OS instead,
-  // set this to true to keep track of unflushed messages we have
-  _has_unflushed_messages = true;
-}
-
-/***/
-void BackendWorker::_force_flush()
-{
-  if (_has_unflushed_messages)
-  {
-    // If we have buffered any messages then flush all active handlers
-    for (auto const& handler : _active_handlers_cache)
-    {
-      std::shared_ptr<Handler> h = handler.lock();
-      if (h)
-      {
-        h->flush();
-      }
-    }
-
-    _has_unflushed_messages = false;
-  }
 }
 
 /***/
@@ -497,4 +473,5 @@ void BackendWorker::_resync_rdtsc_clock()
     }
   }
 }
+
 } // namespace quill::detail

quill/src/detail/misc/FileUtilities.cpp

@@ -28,6 +28,18 @@ void fwrite_fully(void const* ptr, size_t size, size_t count, FILE* stream)
 /***/
 FILE* open_file(fs::path const& filename, std::string const& mode)
 {
+  if (!filename.parent_path().empty())
+  {
+    std::error_code ec;
+    fs::create_directories(filename.parent_path(), ec);
+    if (ec)
+    {
+      // use .string() to also support experimental fs
+      QUILL_THROW(QuillError{fmtquill::format("cannot create directories for {}, error: {}",
+                                              filename.parent_path().string(), ec.message())});
+    }
+  }
+
   FILE* fp = fopen(filename.string().data(), mode.data());
 
   if (!fp)

quill/src/handlers/FileHandler.cpp

@@ -83,7 +83,7 @@ void FileHandler::open_file(fs::path const& filename, std::string const& mode)
   // _file is the base file*
   _file = detail::open_file(filename, mode);
 
-  assert(_file && "open_file always returns a valid pointer");
+  assert(_file && "open_file always returns a valid pointer or throws");
 
   if (_file_event_notifier.after_open)
   {
@@ -94,29 +94,37 @@ void FileHandler::open_file(fs::path const& filename, std::string const& mode)
 /***/
 void FileHandler::close_file()
 {
-  if (_file)
+  if (!_file)
   {
-    if (_file_event_notifier.before_close)
-    {
-      _file_event_notifier.before_close(_filename, _file);
-    }
-
-    fclose(_file);
-    _file = nullptr;
-
-    if (_file_event_notifier.after_close)
-    {
-      _file_event_notifier.after_close(_filename);
-    }
+    return;
+  }
+
+  if (_file_event_notifier.before_close)
+  {
+    _file_event_notifier.before_close(_filename, _file);
+  }
+
+  fclose(_file);
+  _file = nullptr;
+
+  if (_file_event_notifier.after_close)
+  {
+    _file_event_notifier.after_close(_filename);
   }
 }
 
 /***/
 FileHandler::~FileHandler() { close_file(); }
 
 /***/
-void FileHandler::flush() noexcept
+void FileHandler::flush()
 {
+  if (!_write_occurred || !_file)
+  {
+    // Check here because StreamHandler::flush() will set _write_occurred to false
+    return;
+  }
+
   StreamHandler::flush();
 
   if (_config.do_fsync())