Merge pull request #10163 from ctiller/count_now

Track calls to gpr_now()

src/core/lib/support/time_posix.c

@@ -42,6 +42,7 @@
 #ifdef __linux__
 #include <sys/syscall.h>
 #endif
+#include <grpc/support/atm.h>
 #include <grpc/support/log.h>
 #include <grpc/support/time.h>
 #include "src/core/lib/support/block_annotate.h"
@@ -144,7 +145,14 @@ static gpr_timespec now_impl(gpr_clock_type clock) {
 
 gpr_timespec (*gpr_now_impl)(gpr_clock_type clock_type) = now_impl;
 
+#ifdef GPR_LOW_LEVEL_COUNTERS
+gpr_atm gpr_now_call_count;
+#endif
+
 gpr_timespec gpr_now(gpr_clock_type clock_type) {
+#ifdef GPR_LOW_LEVEL_COUNTERS
+  __atomic_fetch_add(&gpr_now_call_count, 1, __ATOMIC_RELAXED);
+#endif
   return gpr_now_impl(clock_type);
 }
 

test/cpp/microbenchmarks/bm_call_create.cc

@@ -68,10 +68,12 @@ auto &force_library_initialization = Library::get();
 void BM_Zalloc(benchmark::State &state) {
   // speed of light for call creation is zalloc, so benchmark a few interesting
   // sizes
+  TrackCounters track_counters;
   size_t sz = state.range(0);
   while (state.KeepRunning()) {
     gpr_free(gpr_zalloc(sz));
   }
+  track_counters.Finish(state);
 }
 BENCHMARK(BM_Zalloc)
     ->Arg(64)

test/cpp/microbenchmarks/helpers.cc

@@ -57,6 +57,10 @@ void TrackCounters::AddToLabel(std::ostream &out, benchmark::State &state) {
       << ((double)(gpr_atm_no_barrier_load(&gpr_counter_atm_add) -
                    atm_add_at_start_) /
           (double)state.iterations())
+      << " nows/iter:"
+      << ((double)(gpr_atm_no_barrier_load(&gpr_now_call_count) -
+                   now_calls_at_start_) /
+          (double)state.iterations())
       << " allocs/iter:"
       << ((double)(counters_at_end.total_allocs_absolute -
                    counters_at_start_.total_allocs_absolute) /

test/cpp/microbenchmarks/helpers.h

@@ -72,6 +72,7 @@ class Library {
 extern "C" gpr_atm gpr_mu_locks;
 extern "C" gpr_atm gpr_counter_atm_cas;
 extern "C" gpr_atm gpr_counter_atm_add;
+extern "C" gpr_atm gpr_now_call_count;
 #endif
 
 class TrackCounters {
@@ -86,6 +87,8 @@ class TrackCounters {
       gpr_atm_no_barrier_load(&gpr_counter_atm_cas);
   const size_t atm_add_at_start_ =
       gpr_atm_no_barrier_load(&gpr_counter_atm_add);
+  const size_t now_calls_at_start_ =
+      gpr_atm_no_barrier_load(&gpr_now_call_count);
   grpc_memory_counters counters_at_start_ = grpc_memory_counters_snapshot();
 #endif
 };

tools/profiling/microbenchmarks/bm2bq.py

@@ -71,6 +71,7 @@ columns = [
   ('end_of_stream', 'boolean'),
   ('header_bytes_per_iteration', 'float'),
   ('framing_bytes_per_iteration', 'float'),
+  ('nows_per_iteration', 'float'),
 ]
 
 SANITIZE = {
@@ -103,4 +104,3 @@ for row in bm_json.expand_json(js, js2):
       if row[name] == '': continue
       sane_row[name] = SANITIZE[sql_type](row[name])
   writer.writerow(sane_row)
-

tools/profiling/microbenchmarks/bm_diff.py

@@ -56,6 +56,7 @@ _INTERESTING = (
   'writes_per_iteration',
   'atm_cas_per_iteration',
   'atm_add_per_iteration',
+  'nows_per_iteration',
 )
 
 def changed_ratio(n, o):