feat logging: add an alert for invalid dynamic debug lines

commit_hash:6d8808ae13f15abae6267f7871cdd5b96de06d9d

Author: Anton3

core/functional_tests/metrics/tests/static/metrics_values.txt

@@ -1,5 +1,6 @@
 alerts.cache_update_error:	GAUGE	0
 alerts.config_parse_error:	GAUGE	0
+alerts.dynamic_debug_invalid_location:	GAUGE	0
 alerts.log_reopening_error:	GAUGE	0
 cache.any.documents.parse_failures.v2: cache_name=dynamic-config-client-updater	RATE	0
 cache.any.documents.parse_failures.v2: cache_name=sample-cache	RATE	0

core/include/userver/alerts/source.hpp

@@ -27,6 +27,7 @@ void DumpMetric(utils::statistics::Writer& writer, const SourceData& m);
 class Source final {
 public:
     static constexpr std::chrono::seconds kDefaultDuration{120};
+    static constexpr std::chrono::hours kInfiniteDuration{24 * 365 * 10};  // In 10 years, someone should notice.
 
     explicit Source(const std::string& name);
 

core/include/userver/components/logging_configurator.hpp

@@ -6,8 +6,7 @@
 #include <userver/components/component_fwd.hpp>
 #include <userver/components/raw_component_base.hpp>
 #include <userver/concurrent/async_event_source.hpp>
-#include <userver/dynamic_config/source.hpp>
-#include <userver/rcu/rcu.hpp>
+#include <userver/utils/statistics/fwd.hpp>
 
 #include <dynamic_config/variables/USERVER_LOG_DYNAMIC_DEBUG.hpp>
 
@@ -58,8 +57,9 @@ class LoggingConfigurator final : public RawComponentBase {
 private:
     void OnConfigUpdate(const dynamic_config::Snapshot& config);
 
+    utils::statistics::MetricsStoragePtr metrics_storage_;
+    // config_subscription_ must be the last field!
     concurrent::AsyncEventSubscriberScope config_subscription_;
-    rcu::Variable<logging::DynamicDebugConfig> dynamic_debug_;
 };
 
 /// }@

core/src/components/logging_configurator.cpp

@@ -2,7 +2,9 @@
 
 #include <logging/dynamic_debug.hpp>
 #include <logging/dynamic_debug_config.hpp>
+#include <userver/alerts/source.hpp>
 #include <userver/components/component.hpp>
+#include <userver/components/statistics_storage.hpp>
 #include <userver/dynamic_config/storage/component.hpp>
 #include <userver/dynamic_config/value.hpp>
 #include <userver/tracing/tracer.hpp>
@@ -28,14 +30,17 @@ const dynamic_config::Key<logging::DynamicDebugConfig> kDynamicDebugConfig{
   }
 )"}};
 
+alerts::Source kDynamicDebugInvalidLocation{"dynamic_debug_invalid_location"};
+
 }  // namespace
 
-LoggingConfigurator::LoggingConfigurator(const ComponentConfig& config, const ComponentContext& context) {
+LoggingConfigurator::LoggingConfigurator(const ComponentConfig& config, const ComponentContext& context)
+    : metrics_storage_(context.FindComponent<components::StatisticsStorage>().GetMetricsStorage()) {
     logging::impl::SetLogLimitedEnable(config["limited-logging-enable"].As<bool>());
     logging::impl::SetLogLimitedInterval(config["limited-logging-interval"].As<std::chrono::milliseconds>());
 
     config_subscription_ = context.FindComponent<components::DynamicConfig>().GetSource().UpdateAndListen(
-        this, kName, &LoggingConfigurator::OnConfigUpdate
+        this, kName, &LoggingConfigurator::OnConfigUpdate, ::dynamic_config::USERVER_NO_LOG_SPANS, kDynamicDebugConfig
     );
 }
 
@@ -45,38 +50,45 @@ void LoggingConfigurator::OnConfigUpdate(const dynamic_config::Snapshot& config)
     (void)this;  // silence clang-tidy
     tracing::SetNoLogSpans(tracing::NoLogSpans{config[::dynamic_config::USERVER_NO_LOG_SPANS]});
 
-    try {
-        const auto& dd = config[kDynamicDebugConfig];
-        auto old_dd = dynamic_debug_.Read();
-        if (!(*old_dd == dd)) {
-            auto lock = dynamic_debug_.StartWrite();
-            *lock = dd;
-
-            /* There is a race between multiple AddDynamicDebugLog(), thus some logs
-             * may be logged or not logged by mistake. This is on purpose as logging
-             * locking would be too slow and heavy.
-             */
-
-            // Flush
-            logging::RemoveAllDynamicDebugLog();
-
-            for (const auto& [location, level] : dd.force_disabled) {
-                const auto [path, line] = logging::SplitLocation(location);
-                logging::EntryState state;
-                state.force_disabled_level_plus_one = logging::GetForceDisabledLevelPlusOne(level);
-                AddDynamicDebugLog(path, line, state);
-            }
-            for (const auto& [location, level] : dd.force_enabled) {
-                const auto [path, line] = logging::SplitLocation(location);
-                logging::EntryState state;
-                state.force_enabled_level = level;
-                AddDynamicDebugLog(path, line, state);
-            }
-
-            lock.Commit();
+    const auto& dd = config[kDynamicDebugConfig];
+
+    /* There is a race between multiple AddDynamicDebugLog(), thus some logs
+     * may be logged or not logged by mistake. This is on purpose as logging
+     * locking would be too slow and heavy.
+     */
+
+    // Flush
+    logging::RemoveAllDynamicDebugLog();
+    bool has_error = false;
+
+    for (const auto& [location, level] : dd.force_disabled) {
+        try {
+            const auto [path, line] = logging::SplitLocation(location);
+            logging::EntryState state;
+            state.force_disabled_level_plus_one = logging::GetForceDisabledLevelPlusOne(level);
+            AddDynamicDebugLog(path, line, state);
+        } catch (const std::exception& e) {
+            LOG_ERROR() << "Failed to disable dynamic debug log at '" << location << "': " << e;
+            has_error = true;
+        }
+    }
+
+    for (const auto& [location, level] : dd.force_enabled) {
+        try {
+            const auto [path, line] = logging::SplitLocation(location);
+            logging::EntryState state;
+            state.force_enabled_level = level;
+            AddDynamicDebugLog(path, line, state);
+        } catch (const std::exception& e) {
+            LOG_ERROR() << "Failed to enable dynamic debug log at '" << location << "': " << e;
+            has_error = true;
         }
-    } catch (const std::exception& e) {
-        LOG_ERROR() << "Failed to set dynamic debug logs from config: " << e;
+    }
+
+    if (has_error) {
+        kDynamicDebugInvalidLocation.FireAlert(*metrics_storage_, alerts::Source::kInfiniteDuration);
+    } else {
+        kDynamicDebugInvalidLocation.StopAlertNow(*metrics_storage_);
     }
 }