Add support for nested JSON format in json logging mode (#12602)

Add support for nested JSON format in JSON logging mode.

Risk Level: low, feature only used if nested objects are configured, thus opt-in.
Testing: unit tests
Docs Changes: yes
Release Notes: added
Fixes: #12582

Signed-off-by: Petr Pchelko <ppchelko@wikimedia.org>

docs/root/configuration/observability/access_log/usage.rst

@@ -93,7 +93,7 @@ would be rendered as the number ``123``.
 Format dictionaries have the following restrictions:
 
 * The dictionary must map strings to strings (specifically, strings to command operators). Nesting
-  is not currently supported.
+  is supported.
 * When using the ``typed_json_format`` command operators will only produce typed output if the
   command operator is the only string that appears in the dictionary value. For example,
   ``"%DURATION%"`` will log a numeric duration value, but ``"%DURATION%.0"`` will log a string

docs/root/version_history/current.rst

@@ -55,6 +55,7 @@ New Features
 ------------
 * access log: added a :ref:`dynamic metadata filter<envoy_v3_api_msg_config.accesslog.v3.MetadataFilter>` for access logs, which filters whether to log based on matching dynamic metadata.
 * access log: added support for :ref:`%DOWNSTREAM_PEER_FINGERPRINT_1% <config_access_log_format_response_flags>` as a response flag.
+* access log: added support for nested objects in :ref:`JSON logging mode <config_access_log_format_dictionaries>`.
 * build: enable building envoy :ref:`arm64 images <arm_binaries>` by buildx tool in x86 CI platform.
 * dns_filter: added support for answering :ref:`service record<envoy_v3_api_msg_data.dns.v3.DnsTable.DnsService>` queries.
 * dynamic_forward_proxy: added :ref:`use_tcp_for_dns_lookups<envoy_v3_api_field_extensions.common.dynamic_forward_proxy.v3.DnsCacheConfig.use_tcp_for_dns_lookups>` option to use TCP for DNS lookups in order to match the DNS options for :ref:`Clusters<envoy_v3_api_msg_config.cluster.v3.Cluster>`.

source/common/formatter/substitution_format_string.cc

@@ -4,27 +4,11 @@
 
 namespace Envoy {
 namespace Formatter {
-namespace {
-
-absl::flat_hash_map<std::string, std::string>
-convertJsonFormatToMap(const ProtobufWkt::Struct& json_format) {
-  absl::flat_hash_map<std::string, std::string> output;
-  for (const auto& pair : json_format.fields()) {
-    if (pair.second.kind_case() != ProtobufWkt::Value::kStringValue) {
-      throw EnvoyException("Only string values are supported in the JSON access log format.");
-    }
-    output.emplace(pair.first, pair.second.string_value());
-  }
-  return output;
-}
-
-} // namespace
 
 FormatterPtr
 SubstitutionFormatStringUtils::createJsonFormatter(const ProtobufWkt::Struct& struct_format,
                                                    bool preserve_types) {
-  auto json_format_map = convertJsonFormatToMap(struct_format);
-  return std::make_unique<JsonFormatterImpl>(json_format_map, preserve_types);
+  return std::make_unique<JsonFormatterImpl>(struct_format, preserve_types);
 }
 
 FormatterPtr SubstitutionFormatStringUtils::fromProtoConfig(

source/common/formatter/substitution_formatter.cc

@@ -49,6 +49,9 @@ const std::regex& getStartTimeNewlinePattern() {
 }
 const std::regex& getNewlinePattern() { CONSTRUCT_ON_FIRST_USE(std::regex, "\n"); }
 
+template <class... Ts> struct JsonFormatMapVisitor : Ts... { using Ts::operator()...; };
+template <class... Ts> JsonFormatMapVisitor(Ts...) -> JsonFormatMapVisitor<Ts...>;
+
 } // namespace
 
 const std::string SubstitutionFormatUtils::DEFAULT_FORMAT =
@@ -109,14 +112,6 @@ std::string FormatterImpl::format(const Http::RequestHeaderMap& request_headers,
   return log_line;
 }
 
-JsonFormatterImpl::JsonFormatterImpl(
-    const absl::flat_hash_map<std::string, std::string>& format_mapping, bool preserve_types)
-    : preserve_types_(preserve_types) {
-  for (const auto& pair : format_mapping) {
-    json_output_format_.emplace(pair.first, SubstitutionFormatParser::parse(pair.second));
-  }
-}
-
 std::string JsonFormatterImpl::format(const Http::RequestHeaderMap& request_headers,
                                       const Http::ResponseHeaderMap& response_headers,
                                       const Http::ResponseTrailerMap& response_trailers,
@@ -129,37 +124,61 @@ std::string JsonFormatterImpl::format(const Http::RequestHeaderMap& request_head
   return absl::StrCat(log_line, "\n");
 }
 
+JsonFormatterImpl::JsonFormatMapWrapper
+JsonFormatterImpl::toFormatMap(const ProtobufWkt::Struct& json_format) const {
+  auto output = std::make_unique<JsonFormatMap>();
+  for (const auto& pair : json_format.fields()) {
+    switch (pair.second.kind_case()) {
+    case ProtobufWkt::Value::kStringValue:
+      output->emplace(pair.first, SubstitutionFormatParser::parse(pair.second.string_value()));
+      break;
+    case ProtobufWkt::Value::kStructValue:
+      output->emplace(pair.first, toFormatMap(pair.second.struct_value()));
+      break;
+    default:
+      throw EnvoyException(
+          "Only string values or nested structs are supported in the JSON access log format.");
+    }
+  }
+  return {std::move(output)};
+};
+
 ProtobufWkt::Struct JsonFormatterImpl::toStruct(const Http::RequestHeaderMap& request_headers,
                                                 const Http::ResponseHeaderMap& response_headers,
                                                 const Http::ResponseTrailerMap& response_trailers,
                                                 const StreamInfo::StreamInfo& stream_info,
                                                 absl::string_view local_reply_body) const {
-  ProtobufWkt::Struct output;
-  auto* fields = output.mutable_fields();
-  for (const auto& pair : json_output_format_) {
-    const auto& providers = pair.second;
-    ASSERT(!providers.empty());
-
-    if (providers.size() == 1) {
-      const auto& provider = providers.front();
-      const auto val =
-          preserve_types_ ? provider->formatValue(request_headers, response_headers,
-                                                  response_trailers, stream_info, local_reply_body)
-                          : ValueUtil::stringValue(
-                                provider->format(request_headers, response_headers,
-                                                 response_trailers, stream_info, local_reply_body));
-      (*fields)[pair.first] = val;
-    } else {
-      // Multiple providers forces string output.
-      std::string str;
-      for (const auto& provider : providers) {
-        str += provider->format(request_headers, response_headers, response_trailers, stream_info,
-                                local_reply_body);
-      }
-      (*fields)[pair.first] = ValueUtil::stringValue(str);
-    }
-  }
-  return output;
+  const std::function<ProtobufWkt::Value(const std::vector<FormatterProviderPtr>&)>
+      providers_callback = [&](const std::vector<FormatterProviderPtr>& providers) {
+        ASSERT(!providers.empty());
+        if (providers.size() == 1) {
+          const auto& provider = providers.front();
+          if (preserve_types_) {
+            return provider->formatValue(request_headers, response_headers, response_trailers,
+                                         stream_info, local_reply_body);
+          }
+          return ValueUtil::stringValue(provider->format(
+              request_headers, response_headers, response_trailers, stream_info, local_reply_body));
+        }
+        // Multiple providers forces string output.
+        std::string str;
+        for (const auto& provider : providers) {
+          str += provider->format(request_headers, response_headers, response_trailers, stream_info,
+                                  local_reply_body);
+        }
+        return ValueUtil::stringValue(str);
+      };
+  const std::function<ProtobufWkt::Value(const JsonFormatterImpl::JsonFormatMapWrapper&)>
+      json_format_map_callback = [&](const JsonFormatterImpl::JsonFormatMapWrapper& format) {
+        ProtobufWkt::Struct output;
+        auto* fields = output.mutable_fields();
+        JsonFormatMapVisitor visitor{json_format_map_callback, providers_callback};
+        for (const auto& pair : *format.value_) {
+          (*fields)[pair.first] = std::visit(visitor, pair.second);
+        }
+        return ValueUtil::structValue(output);
+      };
+  return json_format_map_callback(json_output_format_).struct_value();
 }
 
 void SubstitutionFormatParser::parseCommandHeader(const std::string& token, const size_t start,

source/common/formatter/substitution_formatter.h

@@ -102,8 +102,8 @@ class FormatterImpl : public Formatter {
 
 class JsonFormatterImpl : public Formatter {
 public:
-  JsonFormatterImpl(const absl::flat_hash_map<std::string, std::string>& format_mapping,
-                    bool preserve_types);
+  JsonFormatterImpl(const ProtobufWkt::Struct& format_mapping, bool preserve_types)
+      : preserve_types_(preserve_types), json_output_format_(toFormatMap(format_mapping)) {}
 
   // Formatter::format
   std::string format(const Http::RequestHeaderMap& request_headers,
@@ -113,14 +113,26 @@ class JsonFormatterImpl : public Formatter {
                      absl::string_view local_reply_body) const override;
 
 private:
+  struct JsonFormatMapWrapper;
+  using JsonFormatMapValue =
+      absl::variant<const std::vector<FormatterProviderPtr>, const JsonFormatMapWrapper>;
+  // Although not required for JSON, it is nice to have the order of properties
+  // preserved between the format and the log entry, thus std::map.
+  using JsonFormatMap = std::map<std::string, JsonFormatMapValue>;
+  using JsonFormatMapPtr = std::unique_ptr<JsonFormatMap>;
+  struct JsonFormatMapWrapper {
+    JsonFormatMapPtr value_;
+  };
+
   const bool preserve_types_;
-  std::map<const std::string, const std::vector<FormatterProviderPtr>> json_output_format_;
+  const JsonFormatMapWrapper json_output_format_;
 
   ProtobufWkt::Struct toStruct(const Http::RequestHeaderMap& request_headers,
                                const Http::ResponseHeaderMap& response_headers,
                                const Http::ResponseTrailerMap& response_trailers,
                                const StreamInfo::StreamInfo& stream_info,
                                absl::string_view local_reply_body) const;
+  JsonFormatMapWrapper toFormatMap(const ProtobufWkt::Struct& json_format) const;
 };
 
 /**

test/common/formatter/substitution_format_string_test.cc

@@ -21,7 +21,8 @@ class SubstitutionFormatStringUtilsTest : public ::testing::Test {
     EXPECT_CALL(stream_info_, responseCode()).WillRepeatedly(Return(response_code));
   }
 
-  Http::TestRequestHeaderMapImpl request_headers_{{":method", "GET"}, {":path", "/bar/foo"}};
+  Http::TestRequestHeaderMapImpl request_headers_{
+      {":method", "GET"}, {":path", "/bar/foo"}, {"content-type", "application/json"}};
   Http::TestResponseHeaderMapImpl response_headers_;
   Http::TestResponseTrailerMapImpl response_trailers_;
   StreamInfo::MockStreamInfo stream_info_;
@@ -54,6 +55,8 @@ TEST_F(SubstitutionFormatStringUtilsTest, TestFromProtoConfigJson) {
     text: "plain text"
     path: "%REQ(:path)%"
     code: "%RESPONSE_CODE%"
+    headers:
+      content-type: "%REQ(CONTENT-TYPE)%"
 )EOF";
   TestUtility::loadFromYaml(yaml, config_);
 
@@ -64,7 +67,10 @@ TEST_F(SubstitutionFormatStringUtilsTest, TestFromProtoConfigJson) {
   const std::string expected = R"EOF({
     "text": "plain text",
     "path": "/bar/foo",
-    "code": 200
+    "code": 200,
+    "headers": {
+      "content-type": "application/json"
+    }
 })EOF";
   EXPECT_TRUE(TestUtility::jsonStringEqual(out_json, expected));
 }
@@ -78,18 +84,13 @@ TEST_F(SubstitutionFormatStringUtilsTest, TestInvalidConfigs) {
       R"(
   json_format:
     field: 200
-)",
-      R"(
-  json_format:
-    field:
-      nest_field: "value"
 )",
   };
   for (const auto& yaml : invalid_configs) {
     TestUtility::loadFromYaml(yaml, config_);
-    EXPECT_THROW_WITH_MESSAGE(SubstitutionFormatStringUtils::fromProtoConfig(config_),
-                              EnvoyException,
-                              "Only string values are supported in the JSON access log format.");
+    EXPECT_THROW_WITH_MESSAGE(
+        SubstitutionFormatStringUtils::fromProtoConfig(config_), EnvoyException,
+        "Only string values or nested structs are supported in the JSON access log format.");
   }
 }
 

test/common/formatter/substitution_formatter_speed_test.cc

@@ -11,18 +11,20 @@ namespace Envoy {
 namespace {
 
 std::unique_ptr<Envoy::Formatter::JsonFormatterImpl> makeJsonFormatter(bool typed) {
-  absl::flat_hash_map<std::string, std::string> JsonLogFormat = {
-      {"remote_address", "%DOWNSTREAM_REMOTE_ADDRESS_WITHOUT_PORT%"},
-      {"start_time", "%START_TIME(%Y/%m/%dT%H:%M:%S%z %s)%"},
-      {"method", "%REQ(:METHOD)%"},
-      {"url", "%REQ(X-FORWARDED-PROTO)%://%REQ(:AUTHORITY)%%REQ(X-ENVOY-ORIGINAL-PATH?:PATH)%"},
-      {"protocol", "%PROTOCOL%"},
-      {"respoinse_code", "%RESPONSE_CODE%"},
-      {"bytes_sent", "%BYTES_SENT%"},
-      {"duration", "%DURATION%"},
-      {"referer", "%REQ(REFERER)%"},
-      {"user-agent", "%REQ(USER-AGENT)%"}};
-
+  ProtobufWkt::Struct JsonLogFormat;
+  const std::string format_yaml = R"EOF(
+    remote_address: '%DOWNSTREAM_REMOTE_ADDRESS_WITHOUT_PORT%'
+    start_time: '%START_TIME(%Y/%m/%dT%H:%M:%S%z %s)%'
+    method: '%REQ(:METHOD)%'
+    url: '%REQ(X-FORWARDED-PROTO)%://%REQ(:AUTHORITY)%%REQ(X-ENVOY-ORIGINAL-PATH?:PATH)%'
+    protocol: '%PROTOCOL%'
+    respoinse_code: '%RESPONSE_CODE%'
+    bytes_sent: '%BYTES_SENT%'
+    duration: '%DURATION%'
+    referer: '%REQ(REFERER)%'
+    user-agent: '%REQ(USER-AGENT)%'
+  )EOF";
+  TestUtility::loadFromYaml(format_yaml, JsonLogFormat);
   return std::make_unique<Envoy::Formatter::JsonFormatterImpl>(JsonLogFormat, typed);
 }