Get basic profiler working again

2 files changed, 25 insertions, 16 deletions

diff --git a/src/core/profiling/basic_timers.c b/src/core/profiling/basic_timers.c
index 2f6c88daac..b7614375b3 100644
--- a/src/core/profiling/basic_timers.c
+++ b/src/core/profiling/basic_timers.c
@@ -53,31 +53,42 @@ typedef enum {
 
 typedef struct grpc_timer_entry {
   gpr_timespec tm;
-  int tag;
   const char *tagstr;
   marker_type type;
-  void *id;
   const char *file;
   int line;
 } grpc_timer_entry;
 
 #define MAX_COUNT (1024 * 1024 / sizeof(grpc_timer_entry))
 
-static __thread grpc_timer_entry log[MAX_COUNT];
-static __thread int count;
+static __thread grpc_timer_entry g_log[MAX_COUNT];
+static __thread int g_count;
+static gpr_once g_once_init = GPR_ONCE_INIT;
+static FILE *output_file;
+
+static void close_output() { fclose(output_file); }
+
+static void init_output() {
+  output_file = fopen("latency_trace.txt", "w");
+  GPR_ASSERT(output_file);
+  atexit(close_output);
+}
 
 static void log_report() {
   int i;
-  for (i = 0; i < count; i++) {
-    grpc_timer_entry *entry = &(log[i]);
-    printf("GRPC_LAT_PROF %ld.%09d  %p %c %d(%s) %p %s %d\n", entry->tm.tv_sec,
-           entry->tm.tv_nsec, (void *)(gpr_intptr)gpr_thd_currentid(),
-           entry->type, entry->tag, entry->tagstr, entry->id, entry->file,
-           entry->line);
+  gpr_once_init(&g_once_init, init_output);
+  for (i = 0; i < g_count; i++) {
+    grpc_timer_entry *entry = &(g_log[i]);
+    fprintf(output_file,
+            "{\"t\": %ld.%09d, \"thd\": \"%p\", \"type\": \"%c\", \"tag\": "
+            "\"%s\", \"file\": \"%s\", \"line\": %d}\n",
+            entry->tm.tv_sec, entry->tm.tv_nsec,
+            (void *)(gpr_intptr)gpr_thd_currentid(), entry->type, entry->tagstr,
+            entry->file, entry->line);
   }
 
   /* Now clear out the log */
-  count = 0;
+  g_count = 0;
 }
 
 static void grpc_timers_log_add(int tag, const char *tagstr, marker_type type,
@@ -85,17 +96,15 @@ static void grpc_timers_log_add(int tag, const char *tagstr, marker_type type,
   grpc_timer_entry *entry;
 
   /* TODO (vpai) : Improve concurrency */
-  if (count == MAX_COUNT) {
+  if (g_count == MAX_COUNT) {
     log_report();
   }
 
-  entry = &log[count++];
+  entry = &g_log[g_count++];
 
   entry->tm = gpr_now(GPR_CLOCK_PRECISE);
-  entry->tag = tag;
   entry->tagstr = tagstr;
   entry->type = type;
-  entry->id = id;
   entry->file = file;
   entry->line = line;
 }
diff --git a/src/core/profiling/timers.h b/src/core/profiling/timers.h
index a70520408c..c7cbf2bc2e 100644
--- a/src/core/profiling/timers.h
+++ b/src/core/profiling/timers.h
@@ -65,7 +65,7 @@ enum grpc_profiling_tags {
   GRPC_PTAG_POLL_FINISHED = 203 + GRPC_PTAG_IGNORE_THRESHOLD,
   GRPC_PTAG_TCP_CB_WRITE = 204 + GRPC_PTAG_IGNORE_THRESHOLD,
   GRPC_PTAG_TCP_WRITE = 205 + GRPC_PTAG_IGNORE_THRESHOLD,
-  GRPC_PTAG_CALL_ON_DONE_RECV = 206 + GRPC_PTAG_IGNORE_THRESHOLD,
+  GRPC_PTAG_CALL_ON_DONE_RECV = 206,
 
   /* C++ */
   GRPC_PTAG_CPP_CALL_CREATED = 300 + GRPC_PTAG_IGNORE_THRESHOLD,