access log: add response flag filter

api/bazel/repositories.bzl

@@ -3,7 +3,7 @@ GOGOPROTO_SHA = "1adfc126b41513cc696b209667c8656ea7aac67c" # v1.0.0
 PROMETHEUS_SHA = "99fa1f4be8e564e8a6b613da7fa6f46c9edafc6c" # Nov 17, 2017
 OPENCENSUS_SHA = "ab82e5fdec8267dc2a726544b10af97675970847" # May 23, 2018
 
-PGV_GIT_SHA = "345b6b478ef955ad31382955d21fb504e95f38c7"
+PGV_GIT_SHA = "f9d2b11e44149635b23a002693b76512b01ae515"
 
 load("@bazel_tools//tools/build_defs/repo:git.bzl", "git_repository")
 

api/envoy/config/filter/accesslog/v2/accesslog.proto

@@ -61,6 +61,9 @@ message AccessLogFilter {
 
     // Header filter.
     HeaderFilter header_filter = 8;
+
+    // Response flag filter.
+    ResponseFlagFilter response_flag_filter = 9;
   }
 }
 
@@ -150,3 +153,15 @@ message HeaderFilter {
   // check.
   envoy.api.v2.route.HeaderMatcher header = 1 [(validate.rules).message.required = true];
 }
+
+// Filters requests that received responses with an Envoy response flag set.
+// A list of the response flags can be found
+// in the access log formatter :ref:`documentation<config_access_log_format_response_flags>`.
+message ResponseFlagFilter {
+  // Only responses with the any of the flags listed in this field will be logged.
+  // This field is optional. If it is not specified, then any response flag will pass
+  // the filter check.
+  repeated string flags = 1 [(validate.rules).repeated .items.string = {
+    in: ["LH", "UH", "UT", "LR", "UR", "UF", "UC", "UO", "NR", "DI", "FI", "RL", "UAEX"]
+  }];
+}

docs/root/configuration/access_log.rst

@@ -102,6 +102,8 @@ The following command operators are supported:
   TCP
     Total duration in milliseconds of the downstream connection.
 
+.. _config_access_log_format_response_flags:
+
 %RESPONSE_FLAGS%
   Additional details about the response or connection, if any. For TCP connections, the response codes mentioned in
   the descriptions do not apply. Possible values are:

docs/root/intro/version_history.rst

@@ -3,6 +3,8 @@ Version history
 
 1.8.0 (Pending)
 ===============
+* access log: added :ref:`response flag filter <envoy_api_msg_config.filter.accesslog.v2.ResponseFlagFilter>` 
+  to filter based on the presence of Envoy response flags. 
 * admin: added :http:get:`/hystrix_event_stream` as an endpoint for monitoring envoy's statistics 
   through `Hystrix dashboard <https://github.com/Netflix-Skunkworks/hystrix-dashboard/wiki>`_.
 * http: response filters not applied to early error paths such as http_parser generated 400s.

include/envoy/request_info/request_info.h

@@ -64,6 +64,13 @@ class RequestInfo {
    */
   virtual void setResponseFlag(ResponseFlag response_flag) PURE;
 
+  /**
+   * @param response_flags the response_flags to intersect with.
+   * @return true if the intersection of the response_flags argument and the currently set response
+   * flags is non-empty.
+   */
+  virtual bool intersectResponseFlags(uint64_t response_flags) const PURE;
+
   /**
    * @param host the selected upstream host for the request.
    */
@@ -216,7 +223,12 @@ class RequestInfo {
   /**
    * @return whether response flag is set or not.
    */
-  virtual bool getResponseFlag(ResponseFlag response_flag) const PURE;
+  virtual bool hasResponseFlag(ResponseFlag response_flag) const PURE;
+
+  /**
+   * @return whether any response flag is set or not.
+   */
+  virtual bool hasAnyResponseFlag() const PURE;
 
   /**
    * @return upstream host description.

source/common/access_log/BUILD

@@ -51,7 +51,10 @@ envoy_cc_library(
         "//source/common/http:header_utility_lib",
         "//source/common/http:headers_lib",
         "//source/common/http:utility_lib",
+        "//source/common/protobuf:utility_lib",
+        "//source/common/request_info:request_info_lib",
         "//source/common/runtime:uuid_util_lib",
         "//source/common/tracing:http_tracer_lib",
+        "@envoy_api//envoy/config/filter/accesslog/v2:accesslog_cc",
     ],
 )

source/common/access_log/access_log_impl.cc

@@ -4,6 +4,7 @@
 #include <string>
 
 #include "envoy/common/time.h"
+#include "envoy/config/filter/accesslog/v2/accesslog.pb.validate.h"
 #include "envoy/filesystem/filesystem.h"
 #include "envoy/http/header_map.h"
 #include "envoy/runtime/runtime.h"
@@ -17,6 +18,8 @@
 #include "common/http/header_utility.h"
 #include "common/http/headers.h"
 #include "common/http/utility.h"
+#include "common/protobuf/utility.h"
+#include "common/request_info/utility.h"
 #include "common/runtime/uuid_util.h"
 #include "common/tracing/http_tracer_impl.h"
 
@@ -68,6 +71,9 @@ FilterFactory::fromProto(const envoy::config::filter::accesslog::v2::AccessLogFi
     return FilterPtr{new OrFilter(config.or_filter(), runtime, random)};
   case envoy::config::filter::accesslog::v2::AccessLogFilter::kHeaderFilter:
     return FilterPtr{new HeaderFilter(config.header_filter())};
+  case envoy::config::filter::accesslog::v2::AccessLogFilter::kResponseFlagFilter:
+    MessageUtil::validate(config);
+    return FilterPtr{new ResponseFlagFilter(config.response_flag_filter())};
   default:
     NOT_REACHED;
   }
@@ -174,6 +180,24 @@ bool HeaderFilter::evaluate(const RequestInfo::RequestInfo&,
   return Http::HeaderUtility::matchHeaders(request_headers, header_data_);
 }
 
+ResponseFlagFilter::ResponseFlagFilter(
+    const envoy::config::filter::accesslog::v2::ResponseFlagFilter& config) {
+  for (int i = 0; i < config.flags_size(); i++) {
+    absl::optional<RequestInfo::ResponseFlag> response_flag =
+        RequestInfo::ResponseFlagUtils::toResponseFlag(config.flags(i));
+    // The config has been validated. Therefore, every flag in the config will have a mapping.
+    ASSERT(response_flag.has_value());
+    configured_flags_ |= response_flag.value();
+  }
+}
+
+bool ResponseFlagFilter::evaluate(const RequestInfo::RequestInfo& info, const Http::HeaderMap&) {
+  if (configured_flags_ != 0) {
+    return info.intersectResponseFlags(configured_flags_);
+  }
+  return info.hasAnyResponseFlag();
+}
+
 InstanceSharedPtr
 AccessLogFactory::fromProto(const envoy::config::filter::accesslog::v2::AccessLog& config,
                             Server::Configuration::FactoryContext& context) {

source/common/access_log/access_log_impl.h

@@ -6,7 +6,6 @@
 
 #include "envoy/access_log/access_log.h"
 #include "envoy/config/filter/accesslog/v2/accesslog.pb.h"
-#include "envoy/request_info/request_info.h"
 #include "envoy/runtime/runtime.h"
 #include "envoy/server/access_log_config.h"
 
@@ -166,6 +165,21 @@ class HeaderFilter : public Filter {
   std::vector<Http::HeaderUtility::HeaderData> header_data_;
 };
 
+/**
+ * Filter requests that had a response with an Envoy response flag set.
+ */
+class ResponseFlagFilter : public Filter {
+public:
+  ResponseFlagFilter(const envoy::config::filter::accesslog::v2::ResponseFlagFilter& config);
+
+  // AccessLog::Filter
+  bool evaluate(const RequestInfo::RequestInfo& info,
+                const Http::HeaderMap& request_headers) override;
+
+private:
+  uint64_t configured_flags_{};
+};
+
 /**
  * Access log factory that reads the configuration from proto.
  */

source/common/request_info/request_info_impl.h

@@ -125,7 +125,13 @@ struct RequestInfoImpl : public RequestInfo {
 
   void setResponseFlag(ResponseFlag response_flag) override { response_flags_ |= response_flag; }
 
-  bool getResponseFlag(ResponseFlag flag) const override { return response_flags_ & flag; }
+  bool intersectResponseFlags(uint64_t response_flags) const override {
+    return (response_flags_ & response_flags) != 0;
+  }
+
+  bool hasResponseFlag(ResponseFlag flag) const override { return response_flags_ & flag; }
+
+  bool hasAnyResponseFlag() const override { return response_flags_ != 0; }
 
   void onUpstreamHostSelected(Upstream::HostDescriptionConstSharedPtr host) override {
     upstream_host_ = host;

source/common/request_info/utility.cc

@@ -33,61 +33,85 @@ const std::string ResponseFlagUtils::toShortString(const RequestInfo& request_in
 
   static_assert(ResponseFlag::LastFlag == 0x1000, "A flag has been added. Fix this code.");
 
-  if (request_info.getResponseFlag(ResponseFlag::FailedLocalHealthCheck)) {
+  if (request_info.hasResponseFlag(ResponseFlag::FailedLocalHealthCheck)) {
     appendString(result, FAILED_LOCAL_HEALTH_CHECK);
   }
 
-  if (request_info.getResponseFlag(ResponseFlag::NoHealthyUpstream)) {
+  if (request_info.hasResponseFlag(ResponseFlag::NoHealthyUpstream)) {
     appendString(result, NO_HEALTHY_UPSTREAM);
   }
 
-  if (request_info.getResponseFlag(ResponseFlag::UpstreamRequestTimeout)) {
+  if (request_info.hasResponseFlag(ResponseFlag::UpstreamRequestTimeout)) {
     appendString(result, UPSTREAM_REQUEST_TIMEOUT);
   }
 
-  if (request_info.getResponseFlag(ResponseFlag::LocalReset)) {
+  if (request_info.hasResponseFlag(ResponseFlag::LocalReset)) {
     appendString(result, LOCAL_RESET);
   }
 
-  if (request_info.getResponseFlag(ResponseFlag::UpstreamRemoteReset)) {
+  if (request_info.hasResponseFlag(ResponseFlag::UpstreamRemoteReset)) {
     appendString(result, UPSTREAM_REMOTE_RESET);
   }
 
-  if (request_info.getResponseFlag(ResponseFlag::UpstreamConnectionFailure)) {
+  if (request_info.hasResponseFlag(ResponseFlag::UpstreamConnectionFailure)) {
     appendString(result, UPSTREAM_CONNECTION_FAILURE);
   }
 
-  if (request_info.getResponseFlag(ResponseFlag::UpstreamConnectionTermination)) {
+  if (request_info.hasResponseFlag(ResponseFlag::UpstreamConnectionTermination)) {
     appendString(result, UPSTREAM_CONNECTION_TERMINATION);
   }
 
-  if (request_info.getResponseFlag(ResponseFlag::UpstreamOverflow)) {
+  if (request_info.hasResponseFlag(ResponseFlag::UpstreamOverflow)) {
     appendString(result, UPSTREAM_OVERFLOW);
   }
 
-  if (request_info.getResponseFlag(ResponseFlag::NoRouteFound)) {
+  if (request_info.hasResponseFlag(ResponseFlag::NoRouteFound)) {
     appendString(result, NO_ROUTE_FOUND);
   }
 
-  if (request_info.getResponseFlag(ResponseFlag::DelayInjected)) {
+  if (request_info.hasResponseFlag(ResponseFlag::DelayInjected)) {
     appendString(result, DELAY_INJECTED);
   }
 
-  if (request_info.getResponseFlag(ResponseFlag::FaultInjected)) {
+  if (request_info.hasResponseFlag(ResponseFlag::FaultInjected)) {
     appendString(result, FAULT_INJECTED);
   }
 
-  if (request_info.getResponseFlag(ResponseFlag::RateLimited)) {
+  if (request_info.hasResponseFlag(ResponseFlag::RateLimited)) {
     appendString(result, RATE_LIMITED);
   }
 
-  if (request_info.getResponseFlag(ResponseFlag::UnauthorizedExternalService)) {
+  if (request_info.hasResponseFlag(ResponseFlag::UnauthorizedExternalService)) {
     appendString(result, UNAUTHORIZED_EXTERNAL_SERVICE);
   }
 
   return result.empty() ? NONE : result;
 }
 
+absl::optional<ResponseFlag> ResponseFlagUtils::toResponseFlag(const std::string& flag) {
+  static const std::map<std::string, ResponseFlag> map = {
+      {ResponseFlagUtils::FAILED_LOCAL_HEALTH_CHECK, ResponseFlag::FailedLocalHealthCheck},
+      {ResponseFlagUtils::NO_HEALTHY_UPSTREAM, ResponseFlag::NoHealthyUpstream},
+      {ResponseFlagUtils::UPSTREAM_REQUEST_TIMEOUT, ResponseFlag::UpstreamRequestTimeout},
+      {ResponseFlagUtils::LOCAL_RESET, ResponseFlag::LocalReset},
+      {ResponseFlagUtils::UPSTREAM_REMOTE_RESET, ResponseFlag::UpstreamRemoteReset},
+      {ResponseFlagUtils::UPSTREAM_CONNECTION_FAILURE, ResponseFlag::UpstreamConnectionFailure},
+      {ResponseFlagUtils::UPSTREAM_CONNECTION_TERMINATION,
+       ResponseFlag::UpstreamConnectionTermination},
+      {ResponseFlagUtils::UPSTREAM_OVERFLOW, ResponseFlag::UpstreamOverflow},
+      {ResponseFlagUtils::NO_ROUTE_FOUND, ResponseFlag::NoRouteFound},
+      {ResponseFlagUtils::DELAY_INJECTED, ResponseFlag::DelayInjected},
+      {ResponseFlagUtils::FAULT_INJECTED, ResponseFlag::FaultInjected},
+      {ResponseFlagUtils::RATE_LIMITED, ResponseFlag::RateLimited},
+      {ResponseFlagUtils::UNAUTHORIZED_EXTERNAL_SERVICE, ResponseFlag::UnauthorizedExternalService},
+  };
+  const auto& it = map.find(flag);
+  if (it != map.end()) {
+    return absl::make_optional<ResponseFlag>(it->second);
+  }
+  return absl::nullopt;
+}
+
 const std::string&
 Utility::formatDownstreamAddressNoPort(const Network::Address::Instance& address) {
   if (address.type() == Network::Address::Type::Ip) {

source/common/request_info/utility.h

@@ -14,6 +14,7 @@ namespace RequestInfo {
 class ResponseFlagUtils {
 public:
   static const std::string toShortString(const RequestInfo& request_info);
+  static absl::optional<ResponseFlag> toResponseFlag(const std::string& response_flag);
 
 private:
   ResponseFlagUtils();

source/extensions/access_loggers/http_grpc/grpc_access_log_impl.cc

@@ -88,55 +88,55 @@ void HttpGrpcAccessLog::responseFlagsToAccessLogResponseFlags(
   static_assert(RequestInfo::ResponseFlag::LastFlag == 0x1000,
                 "A flag has been added. Fix this code.");
 
-  if (request_info.getResponseFlag(RequestInfo::ResponseFlag::FailedLocalHealthCheck)) {
+  if (request_info.hasResponseFlag(RequestInfo::ResponseFlag::FailedLocalHealthCheck)) {
     common_access_log.mutable_response_flags()->set_failed_local_healthcheck(true);
   }
 
-  if (request_info.getResponseFlag(RequestInfo::ResponseFlag::NoHealthyUpstream)) {
+  if (request_info.hasResponseFlag(RequestInfo::ResponseFlag::NoHealthyUpstream)) {
     common_access_log.mutable_response_flags()->set_no_healthy_upstream(true);
   }
 
-  if (request_info.getResponseFlag(RequestInfo::ResponseFlag::UpstreamRequestTimeout)) {
+  if (request_info.hasResponseFlag(RequestInfo::ResponseFlag::UpstreamRequestTimeout)) {
     common_access_log.mutable_response_flags()->set_upstream_request_timeout(true);
   }
 
-  if (request_info.getResponseFlag(RequestInfo::ResponseFlag::LocalReset)) {
+  if (request_info.hasResponseFlag(RequestInfo::ResponseFlag::LocalReset)) {
     common_access_log.mutable_response_flags()->set_local_reset(true);
   }
 
-  if (request_info.getResponseFlag(RequestInfo::ResponseFlag::UpstreamRemoteReset)) {
+  if (request_info.hasResponseFlag(RequestInfo::ResponseFlag::UpstreamRemoteReset)) {
     common_access_log.mutable_response_flags()->set_upstream_remote_reset(true);
   }
 
-  if (request_info.getResponseFlag(RequestInfo::ResponseFlag::UpstreamConnectionFailure)) {
+  if (request_info.hasResponseFlag(RequestInfo::ResponseFlag::UpstreamConnectionFailure)) {
     common_access_log.mutable_response_flags()->set_upstream_connection_failure(true);
   }
 
-  if (request_info.getResponseFlag(RequestInfo::ResponseFlag::UpstreamConnectionTermination)) {
+  if (request_info.hasResponseFlag(RequestInfo::ResponseFlag::UpstreamConnectionTermination)) {
     common_access_log.mutable_response_flags()->set_upstream_connection_termination(true);
   }
 
-  if (request_info.getResponseFlag(RequestInfo::ResponseFlag::UpstreamOverflow)) {
+  if (request_info.hasResponseFlag(RequestInfo::ResponseFlag::UpstreamOverflow)) {
     common_access_log.mutable_response_flags()->set_upstream_overflow(true);
   }
 
-  if (request_info.getResponseFlag(RequestInfo::ResponseFlag::NoRouteFound)) {
+  if (request_info.hasResponseFlag(RequestInfo::ResponseFlag::NoRouteFound)) {
     common_access_log.mutable_response_flags()->set_no_route_found(true);
   }
 
-  if (request_info.getResponseFlag(RequestInfo::ResponseFlag::DelayInjected)) {
+  if (request_info.hasResponseFlag(RequestInfo::ResponseFlag::DelayInjected)) {
     common_access_log.mutable_response_flags()->set_delay_injected(true);
   }
 
-  if (request_info.getResponseFlag(RequestInfo::ResponseFlag::FaultInjected)) {
+  if (request_info.hasResponseFlag(RequestInfo::ResponseFlag::FaultInjected)) {
     common_access_log.mutable_response_flags()->set_fault_injected(true);
   }
 
-  if (request_info.getResponseFlag(RequestInfo::ResponseFlag::RateLimited)) {
+  if (request_info.hasResponseFlag(RequestInfo::ResponseFlag::RateLimited)) {
     common_access_log.mutable_response_flags()->set_rate_limited(true);
   }
 
-  if (request_info.getResponseFlag(RequestInfo::ResponseFlag::UnauthorizedExternalService)) {
+  if (request_info.hasResponseFlag(RequestInfo::ResponseFlag::UnauthorizedExternalService)) {
     common_access_log.mutable_response_flags()->mutable_unauthorized_details()->set_reason(
         envoy::data::accesslog::v2::ResponseFlags_Unauthorized_Reason::
             ResponseFlags_Unauthorized_Reason_EXTERNAL_SERVICE);

test/common/access_log/access_log_formatter_test.cc

@@ -115,7 +115,7 @@ TEST(AccessLogFormatterTest, requestInfoFormatter) {
 
   {
     RequestInfoFormatter response_flags_format("RESPONSE_FLAGS");
-    ON_CALL(request_info, getResponseFlag(RequestInfo::ResponseFlag::LocalReset))
+    ON_CALL(request_info, hasResponseFlag(RequestInfo::ResponseFlag::LocalReset))
         .WillByDefault(Return(true));
     EXPECT_EQ("LR", response_flags_format.format(header, header, header, request_info));
   }