application_logs: add bootstrap option to write logs in JSON format

api/envoy/config/bootstrap/v3/bootstrap.proto

@@ -41,7 +41,7 @@ option (udpa.annotations.file_status).package_version_status = ACTIVE;
 // <config_overview_bootstrap>` for more detail.
 
 // Bootstrap :ref:`configuration overview <config_overview_bootstrap>`.
-// [#next-free-field: 38]
+// [#next-free-field: 39]
 message Bootstrap {
   option (udpa.annotations.versioning).previous_message_type =
       "envoy.config.bootstrap.v2.Bootstrap";
@@ -101,6 +101,17 @@ message Bootstrap {
     core.v3.ApiConfigSource ads_config = 3;
   }
 
+  message ApplicationLogFormat {
+    oneof log_format {
+      option (validate.required) = true;
+
+      // Flush application logs in JSON format. The configured JSON struct can
+      // support all the format tags specified in the in :option:`--log-format`
+      // command line option section, except for the ``%v`` and ``%_`` flags.
+      google.protobuf.Struct json_format = 1;
+    }
+  }
+
   reserved 10, 11;
 
   reserved "runtime";
@@ -360,6 +371,11 @@ message Bootstrap {
   // Envoy only supports ListenerManager for this field and Envoy Mobile
   // supports ApiListenerManager.
   core.v3.TypedExtensionConfig listener_manager = 37;
+
+  // Optional field to set the application logs format. If this field is set, it will override
+  // the default log format. In case the :option:`--log-format` command line option is used,
+  // it will override ``application_log_format`` configurations.
+  ApplicationLogFormat application_log_format = 38;
 }
 
 // Administration interface :ref:`operations documentation

changelogs/current.yaml

@@ -284,6 +284,10 @@ new_features:
   change: |
     added new field ``envoy.extensions.filters.http.fault.v3.HTTPFault.filter_metadata`` to aid in logging.
     Metadata will be stored in StreamInfo dynamic metadata under a namespace corresponding to the name of the fault filter.
+- area: application_logs
+  change: |
+    Added bootstrap option :ref:`application_log_format <envoy_v3_api_field_config.bootstrap.v3.Bootstrap.ApplicationLogFormat.json_format>`
+    to enable setting application log format as JSON structure.
 - area: ext_proc
   change: |
     added new field ``filter_metadata <envoy_v3_api_field_extensions.filters.http.ext_proc.v3.ExtProc.filter_metadata`` to aid in logging.

docs/root/configuration/observability/application_logging.rst

@@ -23,3 +23,24 @@ with the following :ref:`command line options <operations_cli>`:
 * The ``--log-level`` flag can be set to control the log severity logged to Stackdriver.
 
 `Reference documentation <https://cloud.google.com/run/docs/logging#container-logs>`_ for Stackdriver on GKE.
+
+Printing logs in JSON format
+----------------------------
+
+It is possible to use the bootstrap config :ref:`json_format <envoy_v3_api_field_config.bootstrap.v3.Bootstrap.ApplicationLogFormat.json_format>`
+to print the logs in custom JSON format. The json format struct can support all the format flags that are specified in :ref:`command line options <operations_cli>`,
+except for the ``%v`` and ``%_`` flags, as they may break the JSON structure log. Instead, use the ``%j`` flag. Example:
+
+.. code-block:: yaml
+
+  application_log_format:
+    json_format:
+      Timestamp: "%Y-%m-%dT%T.%F"
+      ThreadId: "%t"
+      SourceLine: "%s:%#"
+      Level: "%l"
+      Message: "%j"
+      FixedValue: "SomeFixedValue"
+
+.. note::
+  Setting both ``application_log_format`` and CLI option ``--log-format`` is not allowed, and will cause a bootstrap error.

envoy/server/options.h

@@ -169,6 +169,11 @@ class Options {
    */
   virtual const std::string& logFormat() const PURE;
 
+  /**
+   * @return whether or not a log format was set by CLI option.
+   */
+  virtual bool logFormatSet() const PURE;
+
   /**
    * @return const bool indicating whether to escape c-style escape sequences in logs.
    */

source/common/common/BUILD

@@ -211,6 +211,7 @@ envoy_cc_library(
         ":lock_guard_lib",
         ":macros",
         ":non_copyable",
+        "//source/common/protobuf:protobuf",
     ] + select({
         "//bazel:android_logger": ["logger_impl_lib_android"],
         "//conditions:default": ["logger_impl_lib_standard"],

source/common/common/logger.cc

@@ -254,6 +254,31 @@ void Registry::setLogFormat(const std::string& log_format) {
   }
 }
 
+absl::Status Registry::setJsonLogFormat(const Protobuf::Message& log_format_struct) {
+  Protobuf::util::JsonPrintOptions json_options;
+  json_options.preserve_proto_field_names = true;
+  json_options.always_print_primitive_fields = true;
+
+  std::string format_as_json;
+  const auto status =
+      Protobuf::util::MessageToJsonString(log_format_struct, &format_as_json, json_options);
+
+  if (!status.ok()) {
+    return absl::InvalidArgumentError("Provided struct cannot be serialized as JSON string");
+  }
+
+  if (format_as_json.find("%v") != std::string::npos) {
+    return absl::InvalidArgumentError("Usage of %v is unavailable for JSON log formats");
+  }
+
+  if (format_as_json.find("%_") != std::string::npos) {
+    return absl::InvalidArgumentError("Usage of %_ is unavailable for JSON log formats");
+  }
+
+  setLogFormat(format_as_json);
+  return absl::OkStatus();
+}
+
 Logger* Registry::logger(const std::string& log_name) {
   Logger* logger_to_return = nullptr;
   for (Logger& logger : loggers()) {

source/common/common/logger.h

@@ -15,6 +15,7 @@
 #include "source/common/common/logger_impl.h"
 #include "source/common/common/macros.h"
 #include "source/common/common/non_copyable.h"
+#include "source/common/protobuf/protobuf.h"
 
 #include "absl/container/flat_hash_map.h"
 #include "absl/strings/string_view.h"
@@ -353,6 +354,11 @@ class Registry {
    */
   static void setLogFormat(const std::string& log_format);
 
+  /**
+   * Sets the log format from a struct as a JSON string.
+   */
+  static absl::Status setJsonLogFormat(const Protobuf::Message& log_format_struct);
+
   /**
    * @return std::vector<Logger>& the installed loggers.
    */

source/server/config_validation/server.cc

@@ -85,6 +85,21 @@ void ValidationInstance::initialize(const Options& options,
   InstanceUtil::loadBootstrapConfig(bootstrap_, options,
                                     messageValidationContext().staticValidationVisitor(), *api_);
 
+  if (options_.logFormatSet() && bootstrap_.has_application_log_format()) {
+    throw EnvoyException(
+        "Only one of application_log_format or CLI option --log-format can be specified.");
+  }
+
+  if (bootstrap_.has_application_log_format() &&
+      bootstrap_.application_log_format().has_json_format()) {
+    const auto status =
+        Logger::Registry::setJsonLogFormat(bootstrap_.application_log_format().json_format());
+
+    if (!status.ok()) {
+      throw EnvoyException(fmt::format("setJsonLogFormat error: {}", status.ToString()));
+    }
+  }
+
   // Inject regex engine to singleton.
   Regex::EnginePtr regex_engine = createRegexEngine(
       bootstrap_, messageValidationContext().staticValidationVisitor(), serverFactoryContext());

source/server/options_impl.cc

@@ -194,6 +194,7 @@ OptionsImpl::OptionsImpl(std::vector<std::string> args,
   }
 
   log_format_ = log_format.getValue();
+  log_format_set_ = log_format.isSet();
   log_format_escaped_ = log_format_escaped.getValue();
   enable_fine_grain_logging_ = enable_fine_grain_logging.getValue();
 

source/server/options_impl.h

@@ -78,7 +78,10 @@ class OptionsImpl : public Server::Options, protected Logger::Loggable<Logger::I
   }
   void setDrainStrategy(Server::DrainStrategy drain_strategy) { drain_strategy_ = drain_strategy; }
   void setLogLevel(spdlog::level::level_enum log_level) { log_level_ = log_level; }
-  void setLogFormat(const std::string& log_format) { log_format_ = log_format; }
+  void setLogFormat(const std::string& log_format) {
+    log_format_ = log_format;
+    log_format_set_ = true;
+  }
   void setLogPath(const std::string& log_path) { log_path_ = log_path; }
   void setRestartEpoch(uint64_t restart_epoch) { restart_epoch_ = restart_epoch; }
   void setMode(Server::Mode mode) { mode_ = mode; }
@@ -140,6 +143,7 @@ class OptionsImpl : public Server::Options, protected Logger::Loggable<Logger::I
     return component_log_levels_;
   }
   const std::string& logFormat() const override { return log_format_; }
+  bool logFormatSet() const override { return log_format_set_; }
   bool logFormatEscaped() const override { return log_format_escaped_; }
   bool enableFineGrainLogging() const override { return enable_fine_grain_logging_; }
   const std::string& logPath() const override { return log_path_; }
@@ -201,6 +205,7 @@ class OptionsImpl : public Server::Options, protected Logger::Loggable<Logger::I
   std::vector<std::pair<std::string, spdlog::level::level_enum>> component_log_levels_;
   std::string component_log_level_str_;
   std::string log_format_{Logger::Logger::DEFAULT_LOG_FORMAT};
+  bool log_format_set_{false};
   bool log_format_escaped_{false};
   std::string log_path_;
   uint64_t restart_epoch_{0};

source/server/server.cc

@@ -422,6 +422,21 @@ void InstanceImpl::initialize(Network::Address::InstanceConstSharedPtr local_add
                                     messageValidationContext().staticValidationVisitor(), *api_);
   bootstrap_config_update_time_ = time_source_.systemTime();
 
+  if (options_.logFormatSet() && bootstrap_.has_application_log_format()) {
+    throw EnvoyException(
+        "Only one of application_log_format or CLI option --log-format can be specified.");
+  }
+
+  if (bootstrap_.has_application_log_format() &&
+      bootstrap_.application_log_format().has_json_format()) {
+    const auto status =
+        Logger::Registry::setJsonLogFormat(bootstrap_.application_log_format().json_format());
+
+    if (!status.ok()) {
+      throw EnvoyException(fmt::format("setJsonLogFormat error: {}", status.ToString()));
+    }
+  }
+
 #ifdef ENVOY_PERFETTO
   perfetto::TracingInitArgs args;
   // Include in-process events only.

test/common/common/logger_test.cc

@@ -4,6 +4,7 @@
 #include "source/common/common/json_escape_string.h"
 #include "source/common/common/logger.h"
 
+#include "test/mocks/common.h"
 #include "test/test_common/environment.h"
 
 #include "gmock/gmock.h"
@@ -176,17 +177,6 @@ TEST_P(LoggerCustomFlagsTest, LogMessageAsJsonStringEscaped) {
       "StreamAggregatedResources gRPC config stream closed: 14, connection error: desc = "
       "\\\"transport: Error while dialing dial tcp [::1]:15012: connect: connection refused\\\"");
 }
-
-struct MockLogSink : SinkDelegate {
-  MockLogSink(DelegatingLogSinkSharedPtr log_sink) : SinkDelegate(log_sink) { setDelegate(); }
-  ~MockLogSink() override { restoreDelegate(); }
-
-  MOCK_METHOD(void, log, (absl::string_view, const spdlog::details::log_msg&));
-  MOCK_METHOD(void, logWithStableName,
-              (absl::string_view, absl::string_view, absl::string_view, absl::string_view));
-  void flush() override {}
-};
-
 class NamedLogTest : public Loggable<Id::assert>, public testing::Test {};
 
 TEST_F(NamedLogTest, NamedLogsAreSentToSink) {
@@ -270,6 +260,130 @@ TEST(LoggerTest, LogWithLogDetails) {
   ENVOY_LOG_MISC(info, "hello");
 }
 
+TEST(LoggerTest, TestJsonFormatError) {
+  ProtobufWkt::Any log_struct;
+  log_struct.set_type_url("type.googleapis.com/bad.type.url");
+  log_struct.set_value("asdf");
+
+  // This scenario shouldn't happen in production, the test is added mainly for coverage.
+  auto status = Envoy::Logger::Registry::setJsonLogFormat(log_struct);
+  EXPECT_FALSE(status.ok());
+  EXPECT_EQ("INVALID_ARGUMENT: Provided struct cannot be serialized as JSON string",
+            status.ToString());
+}
+
+TEST(LoggerTest, TestJsonFormatNonEscapedThrows) {
+  Envoy::Logger::Registry::setLogLevel(spdlog::level::info);
+
+  {
+    ProtobufWkt::Struct log_struct;
+    (*log_struct.mutable_fields())["Message"].set_string_value("%v");
+    (*log_struct.mutable_fields())["NullField"].set_null_value(ProtobufWkt::NULL_VALUE);
+
+    auto status = Envoy::Logger::Registry::setJsonLogFormat(log_struct);
+    EXPECT_FALSE(status.ok());
+    EXPECT_EQ("INVALID_ARGUMENT: Usage of %v is unavailable for JSON log formats",
+              status.ToString());
+  }
+
+  {
+    ProtobufWkt::Struct log_struct;
+    (*log_struct.mutable_fields())["Message"].set_string_value("%_");
+    (*log_struct.mutable_fields())["NullField"].set_null_value(ProtobufWkt::NULL_VALUE);
+
+    auto status = Envoy::Logger::Registry::setJsonLogFormat(log_struct);
+    EXPECT_FALSE(status.ok());
+    EXPECT_EQ("INVALID_ARGUMENT: Usage of %_ is unavailable for JSON log formats",
+              status.ToString());
+  }
+}
+
+TEST(LoggerTest, TestJsonFormatEmptyStruct) {
+  ProtobufWkt::Struct log_struct;
+  Envoy::Logger::Registry::setLogLevel(spdlog::level::info);
+  EXPECT_TRUE(Envoy::Logger::Registry::setJsonLogFormat(log_struct).ok());
+
+  MockLogSink sink(Envoy::Logger::Registry::getSink());
+  EXPECT_CALL(sink, log(_, _)).WillOnce(Invoke([](auto msg, auto& log) {
+    EXPECT_THAT(msg, HasSubstr("{}"));
+    EXPECT_EQ(log.logger_name, "misc");
+  }));
+
+  ENVOY_LOG_MISC(info, "hello");
+}
+
+TEST(LoggerTest, TestJsonFormatNullAndFixedField) {
+  ProtobufWkt::Struct log_struct;
+  (*log_struct.mutable_fields())["Message"].set_string_value("%j");
+  (*log_struct.mutable_fields())["FixedValue"].set_string_value("Fixed");
+  (*log_struct.mutable_fields())["NullField"].set_null_value(ProtobufWkt::NULL_VALUE);
+  Envoy::Logger::Registry::setLogLevel(spdlog::level::info);
+  EXPECT_TRUE(Envoy::Logger::Registry::setJsonLogFormat(log_struct).ok());
+
+  MockLogSink sink(Envoy::Logger::Registry::getSink());
+  EXPECT_CALL(sink, log(_, _)).WillOnce(Invoke([](auto msg, auto&) {
+    EXPECT_NO_THROW(Json::Factory::loadFromString(std::string(msg)));
+    EXPECT_THAT(msg, HasSubstr("\"Message\":\"hello\""));
+    EXPECT_THAT(msg, HasSubstr("\"FixedValue\":\"Fixed\""));
+    EXPECT_THAT(msg, HasSubstr("\"NullField\":null"));
+  }));
+
+  ENVOY_LOG_MISC(info, "hello");
+}
+
+TEST(LoggerTest, TestJsonFormat) {
+  ProtobufWkt::Struct log_struct;
+  (*log_struct.mutable_fields())["Level"].set_string_value("%l");
+  (*log_struct.mutable_fields())["Message"].set_string_value("%j");
+  Envoy::Logger::Registry::setLogLevel(spdlog::level::info);
+  EXPECT_TRUE(Envoy::Logger::Registry::setJsonLogFormat(log_struct).ok());
+
+  MockLogSink sink(Envoy::Logger::Registry::getSink());
+  EXPECT_CALL(sink, log(_, _))
+      .WillOnce(Invoke([](auto msg, auto& log) {
+        EXPECT_NO_THROW(Json::Factory::loadFromString(std::string(msg)));
+        EXPECT_THAT(msg, HasSubstr("\"Level\":\"info\""));
+        EXPECT_THAT(msg, HasSubstr("\"Message\":\"hello\""));
+        EXPECT_EQ(log.logger_name, "misc");
+      }))
+      .WillOnce(Invoke([](auto msg, auto& log) {
+        EXPECT_NO_THROW(Json::Factory::loadFromString(std::string(msg)));
+        EXPECT_THAT(msg, HasSubstr("\"Level\":\"info\""));
+        EXPECT_THAT(msg, HasSubstr("\"Message\":\"hel\\nlo\""));
+        EXPECT_EQ(log.logger_name, "misc");
+      }))
+      .WillOnce(Invoke([](auto msg, auto& log) {
+        EXPECT_NO_THROW(Json::Factory::loadFromString(std::string(msg)));
+        EXPECT_THAT(msg, HasSubstr("\"Level\":\"info\""));
+        EXPECT_THAT(msg, HasSubstr("\"Message\":\"hel\\\"lo\""));
+        EXPECT_EQ(log.logger_name, "misc");
+      }));
+
+  ENVOY_LOG_MISC(info, "hello");
+  ENVOY_LOG_MISC(info, "hel\nlo");
+  ENVOY_LOG_MISC(info, "hel\"lo");
+}
+
+TEST(LoggerTest, TestJsonFormatWithNestedJsonMessage) {
+  ProtobufWkt::Struct log_struct;
+  (*log_struct.mutable_fields())["Level"].set_string_value("%l");
+  (*log_struct.mutable_fields())["Message"].set_string_value("%j");
+  (*log_struct.mutable_fields())["FixedValue"].set_string_value("Fixed");
+  Envoy::Logger::Registry::setLogLevel(spdlog::level::info);
+  EXPECT_TRUE(Envoy::Logger::Registry::setJsonLogFormat(log_struct).ok());
+
+  MockLogSink sink(Envoy::Logger::Registry::getSink());
+  EXPECT_CALL(sink, log(_, _)).WillOnce(Invoke([](auto msg, auto& log) {
+    EXPECT_NO_THROW(Json::Factory::loadFromString(std::string(msg)));
+    EXPECT_THAT(msg, HasSubstr("\"Level\":\"info\""));
+    EXPECT_THAT(msg, HasSubstr("\"Message\":\"{\\\"nested_message\\\":\\\"hello\\\"}\""));
+    EXPECT_THAT(msg, HasSubstr("\"FixedValue\":\"Fixed\""));
+    EXPECT_EQ(log.logger_name, "misc");
+  }));
+
+  ENVOY_LOG_MISC(info, "{\"nested_message\":\"hello\"}");
+}
+
 } // namespace
 } // namespace Logger
 } // namespace Envoy