envoyproxy · zuercher · Feb 3, 2022 · Dec 18, 2021 · Dec 19, 2021 · Dec 19, 2021
diff --git a/docs/root/configuration/http/http_filters/ext_authz_filter.rst b/docs/root/configuration/http/http_filters/ext_authz_filter.rst
@@ -190,6 +190,9 @@ from the authorization server that match the configured
 :ref:`dynamic_metadata_from_headers <envoy_v3_api_field_extensions.filters.http.ext_authz.v3.AuthorizationResponse.dynamic_metadata_from_headers>`,
 if set. For every response header that matches, the filter will emit dynamic metadata whose key is the name of the matched header and whose value is the value of the matched header.
 
+Both the HTTP and gRPC external authorization filters support a dynamic metadata field called ``ext_authz_duration`` which records the time it takes to complete an authorization request in milliseconds.
+This field will not be populated if the request does not complete.
+
 Runtime
 -------
 The fraction of requests for which the filter is enabled can be configured via the :ref:`runtime_key

@@ -1,5 +1,7 @@
 #include "source/extensions/filters/http/ext_authz/ext_authz.h"
 
+#include <chrono>
+
 #include "envoy/config/core/v3/base.pb.h"
 
 #include "source/common/common/assert.h"
@@ -58,6 +60,9 @@ void Filter::initiateCall(const Http::RequestHeaderMap& headers,
       config_->includePeerCertificate(), config_->destinationLabels());
 
   ENVOY_STREAM_LOG(trace, "ext_authz filter calling authorization server", *decoder_callbacks_);
+  // Store start time of ext_authz filter call
+  start_time_ = decoder_callbacks_->dispatcher().timeSource().monotonicTime();
+
   state_ = State::Calling;
   filter_return_ = FilterReturn::StopDecoding; // Don't let the filter chain continue as we are
                                                // going to invoke check call.
@@ -210,6 +215,16 @@ void Filter::onComplete(Filters::Common::ExtAuthz::ResponsePtr&& response) {
   Stats::StatName empty_stat_name;
 
   if (!response->dynamic_metadata.fields().empty()) {
+    // Add duration of call to dynamic metadata if applicable
+    if (start_time_.has_value() && response->status == CheckStatus::OK) {
+      ProtobufWkt::Value ext_authz_duration_value;
+      auto duration =
+          decoder_callbacks_->dispatcher().timeSource().monotonicTime() - start_time_.value();
+      ext_authz_duration_value.set_number_value(
+          std::chrono::duration_cast<std::chrono::milliseconds>(duration).count());
+      (*response->dynamic_metadata.mutable_fields())["ext_authz_duration"] =
+          ext_authz_duration_value;
+    }
     decoder_callbacks_->streamInfo().setDynamicMetadata("envoy.filters.http.ext_authz",
                                                         response->dynamic_metadata);
   }

@@ -269,6 +269,7 @@ class Filter : public Logger::Loggable<Logger::Id::filter>,
   void onComplete(Filters::Common::ExtAuthz::ResponsePtr&&) override;
 
 private:
+  absl::optional<MonotonicTime> start_time_;
   void addResponseHeaders(Http::HeaderMap& header_map, const Http::HeaderVector& headers);
   void initiateCall(const Http::RequestHeaderMap& headers,
                     const Router::RouteConstSharedPtr& route);

@@ -1,5 +1,6 @@
 #include "source/extensions/filters/network/ext_authz/ext_authz.h"
 
+#include <chrono>
 #include <cstdint>
 #include <string>
 
@@ -24,7 +25,8 @@ void Filter::callCheck() {
   Filters::Common::ExtAuthz::CheckRequestUtils::createTcpCheck(filter_callbacks_, check_request_,
                                                                config_->includePeerCertificate(),
                                                                config_->destinationLabels());
-
+  // Store start time of ext_authz filter call
+  start_time_ = filter_callbacks_->connection().dispatcher().timeSource().monotonicTime();
   status_ = Status::Calling;
   config_->stats().active_.inc();
   config_->stats().total_.inc();
@@ -74,6 +76,16 @@ void Filter::onComplete(Filters::Common::ExtAuthz::ResponsePtr&& response) {
   switch (response->status) {
   case Filters::Common::ExtAuthz::CheckStatus::OK:
     config_->stats().ok_.inc();
+    // Add duration of call to dynamic metadata if applicable
+    if (start_time_.has_value()) {
+      ProtobufWkt::Value ext_authz_duration_value;
+      auto duration = filter_callbacks_->connection().dispatcher().timeSource().monotonicTime() -
+                      start_time_.value();
+      ext_authz_duration_value.set_number_value(
+          std::chrono::duration_cast<std::chrono::milliseconds>(duration).count());
+      (*response->dynamic_metadata.mutable_fields())["ext_authz_duration"] =
+          ext_authz_duration_value;
+    }
     break;
   case Filters::Common::ExtAuthz::CheckStatus::Error:
     config_->stats().error_.inc();
@@ -84,6 +96,7 @@ void Filter::onComplete(Filters::Common::ExtAuthz::ResponsePtr&& response) {
   }
 
   if (!response->dynamic_metadata.fields().empty()) {
+
     filter_callbacks_->connection().streamInfo().setDynamicMetadata(
         NetworkFilterNames::get().ExtAuthorization, response->dynamic_metadata);
   }

@@ -134,6 +134,7 @@ class Filter : public Network::ReadFilter,
   bool filterEnabled(const envoy::config::core::v3::Metadata& metadata) {
     return config_->filterEnabledMetadata(metadata);
   }
+  absl::optional<MonotonicTime> start_time_;
 
   ConfigSharedPtr config_;
   Filters::Common::ExtAuthz::ClientPtr client_;