Track GRPC config update durations with a histogram

Signed-off-by: Adam Schaub <adamsjob@google.com>
envoyproxy · Dec 9, 2020 · 64ee95c · 64ee95c
1 parent 214010b
commit 64ee95c
Show file tree

Hide file tree

Showing 3 changed files with 20 additions and 12 deletions.
diff --git a/include/envoy/config/subscription.h b/include/envoy/config/subscription.h
@@ -204,22 +204,23 @@ using SubscriptionPtr = std::unique_ptr<Subscription>;
 /**
  * Per subscription stats. @see stats_macros.h
  */
-#define ALL_SUBSCRIPTION_STATS(COUNTER, GAUGE, TEXT_READOUT)                                       \
+#define ALL_SUBSCRIPTION_STATS(COUNTER, GAUGE, TEXT_READOUT, HISTOGRAM)                            \
   COUNTER(init_fetch_timeout)                                                                      \
   COUNTER(update_attempt)                                                                          \
   COUNTER(update_failure)                                                                          \
   COUNTER(update_rejected)                                                                         \
   COUNTER(update_success)                                                                          \
   GAUGE(update_time, NeverImport)                                                                  \
   GAUGE(version, NeverImport)                                                                      \
+  HISTOGRAM(update_duration, Milliseconds)                                                         \
   TEXT_READOUT(version_text)
 
 /**
  * Struct definition for per subscription stats. @see stats_macros.h
  */
 struct SubscriptionStats {
   ALL_SUBSCRIPTION_STATS(GENERATE_COUNTER_STRUCT, GENERATE_GAUGE_STRUCT,
-                         GENERATE_TEXT_READOUT_STRUCT)
+                         GENERATE_TEXT_READOUT_STRUCT, GENERATE_HISTOGRAM_STRUCT)
 };
 
 } // namespace Config

diff --git a/source/common/config/grpc_subscription_impl.cc b/source/common/config/grpc_subscription_impl.cc
@@ -1,5 +1,7 @@
 #include "common/config/grpc_subscription_impl.h"
 
+#include <chrono>
+
 #include "common/common/assert.h"
 #include "common/common/logger.h"
 #include "common/common/utility.h"
@@ -63,21 +65,23 @@ void GrpcSubscriptionImpl::onConfigUpdate(const std::vector<Config::DecodedResou
   // supply those versions to onConfigUpdate() along with the xDS response ("system")
   // version_info. This way, both types of versions can be tracked and exposed for debugging by
   // the configuration update targets.
-  uint64_t start_time = DateUtil::nowToMilliseconds(dispatcher_.timeSource());
+  auto start = dispatcher_.timeSource().monotonicTime();
   callbacks_.onConfigUpdate(resources, version_info);
-  uint64_t update_duration_ms = DateUtil::nowToMilliseconds(dispatcher_.timeSource()) - start_time;
+  std::chrono::milliseconds update_duration = std::chrono::duration_cast<std::chrono::milliseconds>(
+      dispatcher_.timeSource().monotonicTime() - start);
   stats_.update_success_.inc();
   stats_.update_attempt_.inc();
   stats_.update_time_.set(DateUtil::nowToMilliseconds(dispatcher_.timeSource()));
   stats_.version_.set(HashUtil::xxHash64(version_info));
   stats_.version_text_.set(version_info);
+  stats_.update_duration_.recordValue(update_duration.count());
   ENVOY_LOG(debug, "gRPC config for {} accepted with {} resources with version {}", type_url_,
             resources.size(), version_info);
 
   // TODO(adamsjob): make the threshold configurable, either through runtime or bootstrap
-  if (update_duration_ms > 50) {
+  if (update_duration.count() > 50) {
     ENVOY_LOG(debug, "Config update for gRPC config for {} with {} resources took {} ms", type_url_,
-              resources.size(), update_duration_ms);
+              resources.size(), update_duration.count());
   }
 }
 
@@ -87,18 +91,20 @@ void GrpcSubscriptionImpl::onConfigUpdate(
     const std::string& system_version_info) {
   disableInitFetchTimeoutTimer();
   stats_.update_attempt_.inc();
-  uint64_t start_time = DateUtil::nowToMilliseconds(dispatcher_.timeSource());
+  auto start = dispatcher_.timeSource().monotonicTime();
   callbacks_.onConfigUpdate(added_resources, removed_resources, system_version_info);
-  uint64_t update_duration_ms = DateUtil::nowToMilliseconds(dispatcher_.timeSource()) - start_time;
+  std::chrono::milliseconds update_duration = std::chrono::duration_cast<std::chrono::milliseconds>(
+      dispatcher_.timeSource().monotonicTime() - start);
   stats_.update_success_.inc();
   stats_.update_time_.set(DateUtil::nowToMilliseconds(dispatcher_.timeSource()));
   stats_.version_.set(HashUtil::xxHash64(system_version_info));
   stats_.version_text_.set(system_version_info);
+  stats_.update_duration_.recordValue(update_duration.count());
 
   // TODO(adamsjob): make the threshold configurable, either through runtime or bootstrap
-  if (update_duration_ms > 50) {
+  if (update_duration.count() > 50) {
     ENVOY_LOG(debug, "Config update for gRPC config for {} with {} resources took {} ms", type_url_,
-              added_resources.size(), update_duration_ms);
+              added_resources.size(), update_duration.count());
   }
 }
 

diff --git a/source/common/config/utility.h b/source/common/config/utility.h
@@ -14,6 +14,7 @@
 #include "envoy/server/filter_config.h"
 #include "envoy/stats/histogram.h"
 #include "envoy/stats/scope.h"
+#include "envoy/stats/stats_macros.h"
 #include "envoy/stats/stats_matcher.h"
 #include "envoy/stats/tag_producer.h"
 #include "envoy/upstream/cluster_manager.h"
@@ -205,8 +206,8 @@ class Utility {
    * @return SubscriptionStats for scope.
    */
   static SubscriptionStats generateStats(Stats::Scope& scope) {
-    return {
-        ALL_SUBSCRIPTION_STATS(POOL_COUNTER(scope), POOL_GAUGE(scope), POOL_TEXT_READOUT(scope))};
+    return {ALL_SUBSCRIPTION_STATS(POOL_COUNTER(scope), POOL_GAUGE(scope), POOL_TEXT_READOUT(scope),
+                                   POOL_HISTOGRAM(scope))};
   }
 
   /**