Merge pull request #9522 from ctiller/bm_perf

Update latency profiler to use (more appropriate) microbenchmarks

2 files changed, 22 insertions, 4 deletions

diff --git a/src/core/lib/profiling/basic_timers.c b/src/core/lib/profiling/basic_timers.c
index bdf9af2339..1f1987fb8e 100644
--- a/src/core/lib/profiling/basic_timers.c
+++ b/src/core/lib/profiling/basic_timers.c
@@ -43,6 +43,9 @@
 #include <grpc/support/thd.h>
 #include <grpc/support/time.h>
 #include <stdio.h>
+#include <string.h>
+
+#include "src/core/lib/support/env.h"
 
 typedef enum { BEGIN = '{', END = '}', MARK = '.' } marker_type;
 
@@ -74,7 +77,7 @@ typedef struct gpr_timer_log_list {
 static __thread gpr_timer_log *g_thread_log;
 static gpr_once g_once_init = GPR_ONCE_INIT;
 static FILE *output_file;
-static const char *output_filename = "latency_trace.txt";
+static const char *output_filename_or_null = NULL;
 static pthread_mutex_t g_mu;
 static pthread_cond_t g_cv;
 static gpr_timer_log_list g_in_progress_logs;
@@ -85,6 +88,17 @@ static __thread int g_thread_id;
 static int g_next_thread_id;
 static int g_writing_enabled = 1;
 
+static const char *output_filename() {
+  if (output_filename_or_null == NULL) {
+    output_filename_or_null = gpr_getenv("LATENCY_TRACE");
+    if (output_filename_or_null == NULL ||
+        strlen(output_filename_or_null) == 0) {
+      output_filename_or_null = "latency_trace.txt";
+    }
+  }
+  return output_filename_or_null;
+}
+
 static int timer_log_push_back(gpr_timer_log_list *list, gpr_timer_log *log) {
   if (list->head == NULL) {
     list->head = list->tail = log;
@@ -134,7 +148,7 @@ static void timer_log_remove(gpr_timer_log_list *list, gpr_timer_log *log) {
 static void write_log(gpr_timer_log *log) {
   size_t i;
   if (output_file == NULL) {
-    output_file = fopen(output_filename, "w");
+    output_file = fopen(output_filename(), "w");
   }
   for (i = 0; i < log->num_entries; i++) {
     gpr_timer_entry *entry = &(log->log[i]);
@@ -198,7 +212,7 @@ static void finish_writing(void) {
 }
 
 void gpr_timers_set_log_filename(const char *filename) {
-  output_filename = filename;
+  output_filename_or_null = filename;
 }
 
 static void init_output() {
diff --git a/src/core/lib/slice/slice_intern.c b/src/core/lib/slice/slice_intern.c
index 7cbd17bffd..32adc4df97 100644
--- a/src/core/lib/slice/slice_intern.c
+++ b/src/core/lib/slice/slice_intern.c
@@ -215,7 +215,9 @@ bool grpc_slice_is_interned(grpc_slice slice) {
 }
 
 grpc_slice grpc_slice_intern(grpc_slice slice) {
+  GPR_TIMER_BEGIN("grpc_slice_intern", 0);
   if (GRPC_IS_STATIC_METADATA_STRING(slice)) {
+    GPR_TIMER_END("grpc_slice_intern", 0);
     return slice;
   }
 
@@ -225,6 +227,7 @@ grpc_slice grpc_slice_intern(grpc_slice slice) {
         static_metadata_hash[(hash + i) % GPR_ARRAY_SIZE(static_metadata_hash)];
     if (ent.hash == hash && ent.idx < GRPC_STATIC_MDSTR_COUNT &&
         grpc_slice_eq(grpc_static_slice_table[ent.idx], slice)) {
+      GPR_TIMER_END("grpc_slice_intern", 0);
       return grpc_static_slice_table[ent.idx];
     }
   }
@@ -247,7 +250,7 @@ grpc_slice grpc_slice_intern(grpc_slice slice) {
         /* and treat this as if we were never here... sshhh */
       } else {
         gpr_mu_unlock(&shard->mu);
-        GPR_TIMER_END("grpc_mdstr_from_buffer", 0);
+        GPR_TIMER_END("grpc_slice_intern", 0);
         return materialize(s);
       }
     }
@@ -275,6 +278,7 @@ grpc_slice grpc_slice_intern(grpc_slice slice) {
 
   gpr_mu_unlock(&shard->mu);
 
+  GPR_TIMER_END("grpc_slice_intern", 0);
   return materialize(s);
 }