fix(common/log_v2): When apply() called, the log file is reopened (#1610

)

* fix(common/log_v2): the otel logger becomes the otl logger
* fix(tests/engine): new test on Engine reload and log reopened
* cleanup(common/log_v2): new comment to explain the new file

This reopen is needed because of the log rotate that moves the log file into the archives directory and then reloads centengine. But since centengine did not reopen the file, it still wrote in it instead of opening a new one.

REFS: MON-146682

common/log_v2/centreon_file_sink.hh

@@ -0,0 +1,102 @@
+/**
+ * Copyright(c) 2015-present, Gabi Melman & spdlog contributors.
+ * Distributed under the MIT License (http://opensource.org/licenses/MIT)
+ *
+ * This file is copied from basic_file_sink{-inl.h,.h}
+ * The goal here is just to add a method `reopen()` using the file_helper mutex.
+ */
+#pragma once
+
+#include <spdlog/common.h>
+#include <spdlog/details/file_helper.h>
+#include <spdlog/details/null_mutex.h>
+#include <spdlog/details/os.h>
+#include <spdlog/details/synchronous_factory.h>
+#include <spdlog/sinks/base_sink.h>
+
+#include <mutex>
+#include <string>
+
+namespace spdlog {
+namespace sinks {
+/*
+ * Trivial file sink with single file as target
+ */
+template <typename Mutex>
+class centreon_file_sink final : public base_sink<Mutex> {
+ public:
+  explicit centreon_file_sink(const filename_t& filename,
+                              bool truncate = false,
+                              const file_event_handlers& event_handlers = {});
+  const filename_t& filename() const;
+  void reopen();
+
+ protected:
+  void sink_it_(const details::log_msg& msg) override;
+  void flush_() override;
+
+ private:
+  details::file_helper file_helper_;
+};
+
+using centreon_file_sink_mt = centreon_file_sink<std::mutex>;
+using centreon_file_sink_st = centreon_file_sink<details::null_mutex>;
+
+template <typename Mutex>
+SPDLOG_INLINE centreon_file_sink<Mutex>::centreon_file_sink(
+    const filename_t& filename,
+    bool truncate,
+    const file_event_handlers& event_handlers)
+    : file_helper_{event_handlers} {
+  file_helper_.open(filename, truncate);
+}
+
+template <typename Mutex>
+SPDLOG_INLINE const filename_t& centreon_file_sink<Mutex>::filename() const {
+  return file_helper_.filename();
+}
+
+template <typename Mutex>
+SPDLOG_INLINE void centreon_file_sink<Mutex>::reopen() {
+  std::lock_guard<Mutex> lock(base_sink<Mutex>::mutex_);
+  file_helper_.reopen(false);
+}
+
+template <typename Mutex>
+SPDLOG_INLINE void centreon_file_sink<Mutex>::sink_it_(
+    const details::log_msg& msg) {
+  memory_buf_t formatted;
+  base_sink<Mutex>::formatter_->format(msg, formatted);
+  file_helper_.write(formatted);
+}
+
+template <typename Mutex>
+SPDLOG_INLINE void centreon_file_sink<Mutex>::flush_() {
+  file_helper_.flush();
+}
+}  // namespace sinks
+
+//
+// factory functions
+//
+template <typename Factory = spdlog::synchronous_factory>
+inline std::shared_ptr<logger> basic_logger_mt(
+    const std::string& logger_name,
+    const filename_t& filename,
+    bool truncate = false,
+    const file_event_handlers& event_handlers = {}) {
+  return Factory::template create<sinks::centreon_file_sink_mt>(
+      logger_name, filename, truncate, event_handlers);
+}
+
+template <typename Factory = spdlog::synchronous_factory>
+inline std::shared_ptr<logger> basic_logger_st(
+    const std::string& logger_name,
+    const filename_t& filename,
+    bool truncate = false,
+    const file_event_handlers& event_handlers = {}) {
+  return Factory::template create<sinks::centreon_file_sink_st>(
+      logger_name, filename, truncate, event_handlers);
+}
+
+}  // namespace spdlog

common/log_v2/log_v2.cc

@@ -21,12 +21,12 @@
 #include <absl/container/flat_hash_set.h>
 #include <grpc/impl/codegen/log.h>
 #include <spdlog/common.h>
-#include <spdlog/sinks/basic_file_sink.h>
 #include <spdlog/sinks/null_sink.h>
 #include <spdlog/sinks/rotating_file_sink.h>
 #include <spdlog/sinks/stdout_color_sinks.h>
 #include <spdlog/sinks/stdout_sinks.h>
 #include <spdlog/sinks/syslog_sink.h>
+#include "centreon_file_sink.hh"
 
 #include <atomic>
 #include <initializer_list>
@@ -67,7 +67,7 @@ const std::array<std::string, log_v2::LOGGER_SIZE> log_v2::_logger_name = {
     "comments",
     "macros",
     "runtime",
-    "otel"};
+    "otl"};
 
 /**
  * @brief this function is passed to grpc in order to log grpc layer's events to
@@ -228,7 +228,7 @@ void log_v2::create_loggers(config::logger_type typ, size_t length) {
         my_sink = std::make_shared<sinks::rotating_file_sink_mt>(
             _file_path, _current_max_size, 99);
       else
-        my_sink = std::make_shared<sinks::basic_file_sink_mt>(_file_path);
+        my_sink = std::make_shared<sinks::centreon_file_sink_mt>(_file_path);
     } break;
     case config::logger_type::LOGGER_SYSLOG:
       my_sink = std::make_shared<sinks::syslog_sink_mt>(_log_name, 0, 0, true);
@@ -303,7 +303,7 @@ void log_v2::apply(const config& log_conf) {
           my_sink = std::make_shared<sinks::rotating_file_sink_mt>(
               _file_path, log_conf.max_size(), 99);
         else
-          my_sink = std::make_shared<sinks::basic_file_sink_mt>(_file_path);
+          my_sink = std::make_shared<sinks::centreon_file_sink_mt>(_file_path);
       } break;
       case config::logger_type::LOGGER_SYSLOG:
         my_sink =
@@ -374,6 +374,13 @@ void log_v2::apply(const config& log_conf) {
         logger->flush_on(lvl);
     }
   }
+
+  for (auto& s : _loggers[0]->sinks()) {
+    spdlog::sinks::centreon_file_sink_mt* file_sink =
+        dynamic_cast<spdlog::sinks::centreon_file_sink_mt*>(s.get());
+    if (file_sink)
+      file_sink->reopen();
+  }
 }
 
 /**

common/log_v2/log_v2.hh

@@ -82,7 +82,7 @@ class log_v2 {
     COMMENTS = 26,
     MACROS = 27,
     RUNTIME = 28,
-    OTEL = 29,
+    OTL = 29,
     LOGGER_SIZE
   };
 
@@ -93,7 +93,6 @@ class log_v2 {
   std::string _file_path;
   const static std::array<std::string, LOGGER_SIZE> _logger_name;
   std::array<std::shared_ptr<spdlog::logger>, LOGGER_SIZE> _loggers;
-  std::atomic<config::logger_type> _current_log_type;
   size_t _current_max_size = 0U;
   bool _log_pid = false;
   bool _log_source = false;

common/tests/log_v2/log_v2.cc

@@ -61,10 +61,12 @@ TEST_F(TestLogV2, LoggerUpdated) {
   const auto& core_logger = log_v2::instance().get(log_v2::CORE);
   ASSERT_EQ(core_logger->level(), spdlog::level::info);
   testing::internal::CaptureStdout();
-  core_logger->info("First log");
-  core_logger->debug("First debug log");
   config cfg("/tmp/test.log", config::logger_type::LOGGER_STDOUT, 0, false,
              false);
+  cfg.set_level("core", "info");
+  log_v2::instance().apply(cfg);
+  core_logger->info("First log");
+  core_logger->debug("First debug log");
   cfg.set_level("core", "debug");
   log_v2::instance().apply(cfg);
   ASSERT_EQ(core_logger->level(), spdlog::level::debug);

engine/modules/opentelemetry/src/main.cc

@@ -56,7 +56,7 @@ extern std::shared_ptr<asio::io_context> g_io_context;
  *  @return 0 on success, any other value on failure.
  */
 extern "C" int nebmodule_deinit(int /*flags*/, int /*reason*/) {
-  open_telemetry::unload(log_v2::instance().get(log_v2::OTEL));
+  open_telemetry::unload(log_v2::instance().get(log_v2::OTL));
   return 0;
 }
 
@@ -107,7 +107,7 @@ extern "C" int nebmodule_init(int flags, char const* args, void* handle) {
     throw msg_fmt("main: no configuration file provided");
 
   open_telemetry::load(conf_file_path, g_io_context,
-                       log_v2::instance().get(log_v2::OTEL));
+                       log_v2::instance().get(log_v2::OTL));
   commands::otel_connector::init_all();
 
   return 0;
@@ -118,6 +118,6 @@ extern "C" int nebmodule_init(int flags, char const* args, void* handle) {
  *
  */
 extern "C" int nebmodule_reload() {
-  open_telemetry::reload(log_v2::instance().get(log_v2::OTEL));
+  open_telemetry::reload(log_v2::instance().get(log_v2::OTL));
   return 0;
 }

engine/src/commands/otel_connector.cc

@@ -122,7 +122,7 @@ otel_connector::otel_connector(const std::string& connector_name,
                                commands::command_listener* listener)
     : command(connector_name, cmd_line, listener, e_type::otel),
       _host_serv_list(std::make_shared<otel::host_serv_list>()),
-      _logger(log_v2::instance().get(log_v2::OTEL)) {
+      _logger(log_v2::instance().get(log_v2::OTL)) {
   init();
 }
 

engine/src/configuration/applier/state.cc

@@ -1185,7 +1185,7 @@ void applier::state::apply_log_config(configuration::state& new_cfg) {
     log_cfg.set_level("macros", new_cfg.log_level_macros());
     log_cfg.set_level("process", new_cfg.log_level_process());
     log_cfg.set_level("runtime", new_cfg.log_level_runtime());
-    log_cfg.set_level("otel", new_cfg.log_level_otl());
+    log_cfg.set_level("otl", new_cfg.log_level_otl());
     if (has_already_been_loaded)
       log_cfg.allow_only_atomic_changes(true);
     log_v2::instance().apply(log_cfg);

tests/broker/log.robot

@@ -126,7 +126,7 @@ BLBD
 ...    ${SPACE}${SPACE}value: "error"
 ...    }
 ...    level {
-...    ${SPACE}${SPACE}key: "otel"
+...    ${SPACE}${SPACE}key: "otl"
 ...    ${SPACE}${SPACE}value: "error"
 ...    }
 ...    level {

tests/engine/reload-and-logs.robot

@@ -0,0 +1,39 @@
+*** Settings ***
+Documentation       Centreon Engine forced checks tests
+
+Resource            ../resources/import.resource
+
+Suite Setup         Ctn Clean Before Suite
+Suite Teardown      Ctn Clean After Suite
+Test Setup          Ctn Stop Processes
+
+
+*** Test Cases ***
+ERL
+    [Documentation]    Engine is started and writes logs in centengine.log.
+    ...    Then we remove the log file. The file disappears but Engine is still writing into it.
+    ...    Engine is reloaded and the centengine.log should appear again.
+    [Tags]    engine    log-v2    MON-146682
+    Ctn Config Engine    ${1}
+    Ctn Engine Config Set Value    ${0}    log_legacy_enabled    ${0}
+    Ctn Engine Config Set Value    ${0}    log_v2_enabled    ${1}
+    Ctn Engine Config Set Value    ${0}    log_level_events    info
+    Ctn Engine Config Set Value    ${0}    log_flush_period    0
+
+    Ctn Clear Retention
+    Ctn Clear Db    hosts
+    ${start}    Ctn Get Round Current Date
+    Ctn Start Engine
+    Ctn Wait For Engine To Be Ready    ${start}    ${1}
+
+    File Should Exist    ${VarRoot}/log/centreon-engine/config0/centengine.log
+
+    Remove File    ${VarRoot}/log/centreon-engine/config0/centengine.log
+
+    Sleep    5s
+
+    File Should Not Exist    ${VarRoot}/log/centreon-engine/config0/centengine.log
+    Ctn Reload Engine
+
+    Wait Until Created    ${VarRoot}/log/centreon-engine/config0/centengine.log    timeout=30s
+    Ctn Stop Engine