logger: support log control in admin interface and command line optio…

…n for Fancy Logger (envoyproxy#12369)

Add log control (list and modify log level) in admin interface for Fancy Logger, a new fine-grained logger for Envoy, and provide command line option --enable-fine-grain-logging for developers. 

Additional Description: A doc of overview is provided here: source/docs/fancy_logger.md.
Risk Level: Medium
Testing: Unit tests.
Docs Changes: Added a new option --enable-fine-grain-logging and doc it.
Release Notes: Added to current.rst.

Signed-off-by: Jinhui Song <jinhuisong@google.com>

api/envoy/admin/v3/server_info.proto

@@ -54,7 +54,7 @@ message ServerInfo {
   CommandLineOptions command_line_options = 6;
 }
 
-// [#next-free-field: 34]
+// [#next-free-field: 35]
 message CommandLineOptions {
   option (udpa.annotations.versioning).previous_message_type =
       "envoy.admin.v2alpha.CommandLineOptions";
@@ -176,4 +176,7 @@ message CommandLineOptions {
 
   // See :option:`--bootstrap-version` for details.
   uint32 bootstrap_version = 29;
+
+  // See :option:`--enable-fine-grain-logging` for details.
+  bool enable_fine_grain_logging = 34;
 }

docs/root/operations/admin.rst

@@ -237,7 +237,9 @@ modify different aspects of the server:
 
   .. note::
 
-    Generally only used during development.
+    Generally only used during development. With `--enable-fine-grain-logging` being set, the logger is represented
+    by the path of the file it belongs to (to be specific, the path determined by `__FILE__`), so the logger list
+    will show a list of file paths, and the specific path should be used as <logger_name> to change the log level. 
 
 .. http:get:: /memory
 

docs/root/operations/cli.rst

@@ -184,6 +184,13 @@ following are the command line options that Envoy supports.
   The :ref:`hot restart wrapper <operations_hot_restarter>` sets the *RESTART_EPOCH* environment
   variable which should be passed to this option in most cases.
 
+.. option:: --enable-fine-grain-logging
+  *(optional)* Enables fine-grain logger with file level log control and runtime update at administration
+  interface. If enabled, main log macros including `ENVOY_LOG`, `ENVOY_CONN_LOG`, `ENVOY_STREAM_LOG` and
+  `ENVOY_FLUSH_LOG` will use a per-file logger, and the usage doesn't need `Envoy::Logger::Loggable` any 
+  more. The administration interface usage is similar. Please see `Administration interface 
+  <https://www.envoyproxy.io/docs/envoy/latest/operations/admin>`_ for more detail.
+
 .. option:: --hot-restart-version
 
   *(optional)* Outputs an opaque hot restart compatibility version for the binary. This can be

docs/root/version_history/current.rst

@@ -21,6 +21,7 @@ Minor Behavior Changes
 * http: fixed the 100-continue response path to properly handle upstream failure by sending 5xx responses. This behavior can be temporarily reverted by setting `envoy.reloadable_features.allow_500_after_100` to false.
 * http: the per-stream FilterState maintained by the HTTP connection manager will now provide read/write access to the downstream connection FilterState. As such, code that relies on interacting with this might
   see a change in behavior.
+* logging: add fine-grain logging for file level log control with logger management at administration interface. It can be enabled by option `--enable-fine-grain-logging`.
 * logging: change default log format to `"[%Y-%m-%d %T.%e][%t][%l][%n] [%g:%#] %v"` and default value of :option:`--log-format-prefix-with-location` to `0`.
 * logging: nghttp2 log messages no longer appear at trace level unless `ENVOY_NGHTTP2_TRACE` is set
   in the environment.

include/envoy/server/options.h

@@ -178,6 +178,11 @@ class Options {
    */
   virtual bool logFormatEscaped() const PURE;
 
+  /**
+   * @return const bool logger mode: whether to use Fancy Logger.
+   */
+  virtual bool enableFineGrainLogging() const PURE;
+
   /**
    * @return const std::string& the log file path.
    */

source/common/common/BUILD

@@ -137,30 +137,19 @@ envoy_cc_library(
 # Contains minimal code for logging to stderr.
 envoy_cc_library(
     name = "minimal_logger_lib",
-    srcs = ["logger.cc"],
-    hdrs = ["logger.h"],
-    external_deps = ["abseil_synchronization"],
-    deps = [
-        ":base_logger_lib",
-        ":lock_guard_lib",
-        ":macros",
-        ":non_copyable",
-    ] + select({
-        "//bazel:android_logger": ["logger_impl_lib_android"],
-        "//conditions:default": ["logger_impl_lib_standard"],
-    }),
-)
-
-envoy_cc_library(
-    name = "fancy_logger_lib",
-    srcs = ["fancy_logger.cc"],
-    hdrs = ["fancy_logger.h"],
+    srcs = [
+        "fancy_logger.cc",
+        "logger.cc",
+    ],
+    hdrs = [
+        "fancy_logger.h",
+        "logger.h",
+    ],
     external_deps = ["abseil_synchronization"],
     deps = [
         ":base_logger_lib",
         ":lock_guard_lib",
         ":macros",
-        ":minimal_logger_lib",
         ":non_copyable",
     ] + select({
         "//bazel:android_logger": ["logger_impl_lib_android"],

source/common/common/fancy_logger.cc

@@ -26,7 +26,11 @@ class FancyBasicLockable : public Thread::BasicLockable {
 SpdLoggerSharedPtr FancyContext::getFancyLogEntry(std::string key)
     ABSL_LOCKS_EXCLUDED(fancy_log_lock_) {
   absl::ReaderMutexLock l(&fancy_log_lock_);
-  return fancy_log_map_->find(key)->second;
+  auto it = fancy_log_map_->find(key);
+  if (it != fancy_log_map_->end()) {
+    return it->second;
+  }
+  return nullptr;
 }
 
 void FancyContext::initFancyLogger(std::string key, std::atomic<spdlog::logger*>& logger)
@@ -69,6 +73,23 @@ void FancyContext::setDefaultFancyLevelFormat(spdlog::level::level_enum level, s
   }
 }
 
+std::string FancyContext::listFancyLoggers() ABSL_LOCKS_EXCLUDED(fancy_log_lock_) {
+  std::string info = "";
+  absl::ReaderMutexLock l(&fancy_log_lock_);
+  for (const auto& it : *fancy_log_map_) {
+    info += fmt::format("   {}: {}\n", it.first, static_cast<int>(it.second->level()));
+  }
+  return info;
+}
+
+void FancyContext::setAllFancyLoggers(spdlog::level::level_enum level)
+    ABSL_LOCKS_EXCLUDED(fancy_log_lock_) {
+  absl::ReaderMutexLock l(&fancy_log_lock_);
+  for (const auto& it : *fancy_log_map_) {
+    it.second->set_level(level);
+  }
+}
+
 void FancyContext::initSink() {
   spdlog::sink_ptr sink = Logger::Registry::getSink();
   Logger::DelegatingLogSinkSharedPtr sp = std::static_pointer_cast<Logger::DelegatingLogSink>(sink);

source/common/common/fancy_logger.h

@@ -38,11 +38,23 @@ class FancyContext {
       ABSL_LOCKS_EXCLUDED(fancy_log_lock_);
 
   /**
-   * Sets the default logger level and format when updating context.
+   * Sets the default logger level and format when updating context. It should only be used in
+   * Context, otherwise the fancy_default_level will possibly be inconsistent with the actual
+   * logger level.
    */
   void setDefaultFancyLevelFormat(spdlog::level::level_enum level, std::string format)
       ABSL_LOCKS_EXCLUDED(fancy_log_lock_);
 
+  /**
+   * Lists keys and levels of all loggers in a string for admin page usage.
+   */
+  std::string listFancyLoggers() ABSL_LOCKS_EXCLUDED(fancy_log_lock_);
+
+  /**
+   * Sets the levels of all loggers.
+   */
+  void setAllFancyLoggers(spdlog::level::level_enum level) ABSL_LOCKS_EXCLUDED(fancy_log_lock_);
+
 private:
   /**
    * Initializes sink for the initialization of loggers, needed only in benchmark test.

source/common/common/logger.cc

@@ -10,6 +10,7 @@
 
 #include "absl/strings/ascii.h"
 #include "absl/strings/escaping.h"
+#include "absl/strings/str_replace.h"
 #include "absl/strings/strip.h"
 #include "spdlog/spdlog.h"
 
@@ -110,9 +111,9 @@ DelegatingLogSinkSharedPtr DelegatingLogSink::init() {
 static Context* current_context = nullptr;
 
 Context::Context(spdlog::level::level_enum log_level, const std::string& log_format,
-                 Thread::BasicLockable& lock, bool should_escape)
+                 Thread::BasicLockable& lock, bool should_escape, bool enable_fine_grain_logging)
     : log_level_(log_level), log_format_(log_format), lock_(lock), should_escape_(should_escape),
-      save_context_(current_context) {
+      enable_fine_grain_logging_(enable_fine_grain_logging), save_context_(current_context) {
   current_context = this;
   activate();
 }
@@ -126,21 +127,54 @@ Context::~Context() {
   }
 }
 
-void Context::activate(LoggerMode mode) {
+void Context::activate() {
   Registry::getSink()->setLock(lock_);
   Registry::getSink()->setShouldEscape(should_escape_);
   Registry::setLogLevel(log_level_);
   Registry::setLogFormat(log_format_);
 
-  if (mode == LoggerMode::Fancy) {
-    fancy_default_level_ = log_level_;
-    fancy_log_format_ = log_format_;
+  // sets level and format for Fancy Logger
+  fancy_default_level_ = log_level_;
+  fancy_log_format_ = log_format_;
+  if (enable_fine_grain_logging_) {
+    // loggers with default level before are set to log_level_ as new default
+    getFancyContext().setDefaultFancyLevelFormat(log_level_, log_format_);
+    if (log_format_ == Logger::Logger::DEFAULT_LOG_FORMAT) {
+      fancy_log_format_ = absl::StrReplaceAll(log_format_, {{"[%n]", ""}});
+    }
+  }
+}
+
+bool Context::useFancyLogger() {
+  if (current_context) {
+    return current_context->enable_fine_grain_logging_;
+  }
+  return false;
+}
+
+void Context::enableFancyLogger() {
+  current_context->enable_fine_grain_logging_ = true;
+  if (current_context) {
+    getFancyContext().setDefaultFancyLevelFormat(current_context->log_level_,
+                                                 current_context->log_format_);
+    current_context->fancy_default_level_ = current_context->log_level_;
+    current_context->fancy_log_format_ = current_context->log_format_;
+    if (current_context->log_format_ == Logger::Logger::DEFAULT_LOG_FORMAT) {
+      current_context->fancy_log_format_ =
+          absl::StrReplaceAll(current_context->log_format_, {{"[%n]", ""}});
+    }
+  }
+}
+
+void Context::disableFancyLogger() {
+  if (current_context) {
+    current_context->enable_fine_grain_logging_ = false;
   }
 }
 
 std::string Context::getFancyLogFormat() {
   if (!current_context) { // Context is not instantiated in benchmark test
-    return "[%Y-%m-%d %T.%e][%t][%l][%n] %v";
+    return "[%Y-%m-%d %T.%e][%t][%l] %v";
   }
   return current_context->fancy_log_format_;
 }