Infrastructure for timer insertion, logging, and testing.

BUILD

@@ -186,6 +186,7 @@ cc_library(
         "src/core/statistics/census_rpc_stats.h",
         "src/core/statistics/census_tracing.h",
         "src/core/statistics/hash_table.h",
+        "src/core/statistics/timers.h",
         "src/core/statistics/window_stats.h",
         "src/core/surface/byte_buffer_queue.h",
         "src/core/surface/call.h",
@@ -297,6 +298,7 @@ cc_library(
         "src/core/statistics/census_rpc_stats.c",
         "src/core/statistics/census_tracing.c",
         "src/core/statistics/hash_table.c",
+        "src/core/statistics/timers.c",
         "src/core/statistics/window_stats.c",
         "src/core/surface/byte_buffer.c",
         "src/core/surface/byte_buffer_queue.c",
@@ -414,6 +416,7 @@ cc_library(
         "src/core/statistics/census_rpc_stats.h",
         "src/core/statistics/census_tracing.h",
         "src/core/statistics/hash_table.h",
+        "src/core/statistics/timers.h",
         "src/core/statistics/window_stats.h",
         "src/core/surface/byte_buffer_queue.h",
         "src/core/surface/call.h",
@@ -505,6 +508,7 @@ cc_library(
         "src/core/statistics/census_rpc_stats.c",
         "src/core/statistics/census_tracing.c",
         "src/core/statistics/hash_table.c",
+        "src/core/statistics/timers.c",
         "src/core/statistics/window_stats.c",
         "src/core/surface/byte_buffer.c",
         "src/core/surface/byte_buffer_queue.c",

build.json

@@ -136,6 +136,7 @@
         "src/core/statistics/census_rpc_stats.h",
         "src/core/statistics/census_tracing.h",
         "src/core/statistics/hash_table.h",
+        "src/core/statistics/timers.h",
         "src/core/statistics/window_stats.h",
         "src/core/surface/byte_buffer_queue.h",
         "src/core/surface/call.h",
@@ -228,6 +229,7 @@
         "src/core/statistics/census_rpc_stats.c",
         "src/core/statistics/census_tracing.c",
         "src/core/statistics/hash_table.c",
+        "src/core/statistics/timers.c",
         "src/core/statistics/window_stats.c",
         "src/core/surface/byte_buffer.c",
         "src/core/surface/byte_buffer_queue.c",
@@ -1658,6 +1660,20 @@
         "gpr"
       ]
     },
+    {
+      "name": "timers_test",
+      "build": "test",
+      "language": "c",
+      "src": [
+        "test/core/statistics/timers_test.c"
+      ],
+      "deps": [
+        "grpc_test_util",
+        "grpc",
+        "gpr_test_util",
+        "gpr"
+      ]
+    },
     {
       "name": "transport_metadata_test",
       "build": "test",

src/core/statistics/timers.c

@@ -0,0 +1,162 @@
+/*
+ *
+ * Copyright 2015, Google Inc.
+ * All rights reserved.
+ *
+ * Redistribution and use in source and binary forms, with or without
+ * modification, are permitted provided that the following conditions are
+ * met:
+ *
+ *     * Redistributions of source code must retain the above copyright
+ * notice, this list of conditions and the following disclaimer.
+ *     * Redistributions in binary form must reproduce the above
+ * copyright notice, this list of conditions and the following disclaimer
+ * in the documentation and/or other materials provided with the
+ * distribution.
+ *     * Neither the name of Google Inc. nor the names of its
+ * contributors may be used to endorse or promote products derived from
+ * this software without specific prior written permission.
+ *
+ * THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS
+ * "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT
+ * LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR
+ * A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT
+ * OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
+ * SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT
+ * LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE,
+ * DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY
+ * THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
+ * (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
+ * OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
+ *
+ */
+
+#include "timers.h"
+
+#include <grpc/support/alloc.h>
+#include <grpc/support/log.h>
+#include <grpc/support/time.h>
+#include <grpc/support/sync.h>
+#include <stdio.h>
+
+typedef struct grpc_timer_entry {
+#ifdef GRPC_TIMERS_RDTSC
+#error Rdtsc timers not supported yet
+  /* TODO(vpai): Fill in rdtsc support if desired */
+#else
+  gpr_timespec timer_;
+#endif
+  const char* tag_;
+  int seq_;
+  const char* file_;
+  int line_;
+} grpc_timer_entry;
+
+struct grpc_timers_log {
+  gpr_mu mu_;
+  grpc_timer_entry* log_;
+  int num_entries_;
+  int capacity_;
+  int capacity_limit_;
+  FILE *fp_;
+  const char *fmt_;
+};
+
+grpc_timers_log* grpc_timers_log_global = NULL;
+
+static int timer_now(grpc_timer_entry *tm) {
+#ifdef GRPC_TIMERS_RDTSC
+#error Rdtsc not supported yet
+#else
+  tm->timer_ = gpr_now();
+  return(1);
+#endif
+}
+
+grpc_timers_log* grpc_timers_log_create(int capacity_limit, FILE *dump,
+                                        const char *fmt) {
+  grpc_timers_log* log = gpr_malloc(sizeof(*log));
+  GPR_ASSERT(log);
+
+  /* TODO (vpai): Allow allocation below limit */
+  log->log_ = gpr_malloc(capacity_limit*sizeof(*log->log_));
+  GPR_ASSERT(log->log_);
+
+  /* TODO (vpai): Improve concurrency, do per-thread logging? */
+  gpr_mu_init(&log->mu_);
+
+  log->num_entries_ = 0;
+  log->capacity_ = log->capacity_limit_ = capacity_limit;
+
+  log->fp_ = dump;
+  log->fmt_ = fmt;
+
+  return log;
+}
+
+static void log_report_locked(grpc_timers_log *log) {
+  FILE *fp = log->fp_;
+  const char *fmt = log->fmt_;
+  int i;
+  for (i=0;i<log->num_entries_;i++) {
+    grpc_timer_entry* entry = &(log->log_[i]);
+    fprintf(fp, fmt,
+#ifdef GRPC_TIMERS_RDTSC
+#error Rdtsc not supported
+#else
+            entry->timer_.tv_sec, entry->timer_.tv_nsec,
+#endif
+            entry->tag_, entry->seq_, entry->file_, entry->line_);
+  }
+
+  /* Now clear out the log */
+  log->num_entries_=0;
+}
+
+void grpc_timers_log_destroy(grpc_timers_log *log) {
+  gpr_mu_lock(&log->mu_);
+  log_report_locked(log);
+  gpr_mu_unlock(&log->mu_);
+
+  gpr_free(log->log_);
+  gpr_mu_destroy(&log->mu_);
+
+  gpr_free(log);
+}
+
+void grpc_timers_log_add(grpc_timers_log *log, const char *tag, int seq,
+                         const char *file, int line) {
+  grpc_timer_entry* entry;
+
+  /* TODO (vpai) : Improve concurrency */
+  gpr_mu_lock(&log->mu_);
+  if (log->num_entries_ == log->capacity_limit_) {
+    log_report_locked(log);
+  }
+
+  entry = &log->log_[log->num_entries_++];
+
+  timer_now(entry);
+  entry->tag_ = tag;
+  entry->seq_ = seq;
+  entry->file_ = file;
+  entry->line_ = line;
+
+  gpr_mu_unlock(&log->mu_);
+}
+
+void grpc_timers_log_global_init(void) {
+  grpc_timers_log_global =
+      grpc_timers_log_create(100000, stdout,
+#ifdef GRPC_TIMERS_RDTSC
+#error Rdtsc not supported
+#else
+                            "TIMER %1$ld.%2$09d %3$s seq %4$d @ %5$s:%6$d\n"
+#endif
+                            );
+  /* Use positional arguments as an example for others to change fmt */
+}
+
+void grpc_timers_log_global_destroy(void) {
+  grpc_timers_log_destroy(grpc_timers_log_global);
+}

src/core/statistics/timers.h

@@ -0,0 +1,63 @@
+/*
+ *
+ * Copyright 2015, Google Inc.
+ * All rights reserved.
+ *
+ * Redistribution and use in source and binary forms, with or without
+ * modification, are permitted provided that the following conditions are
+ * met:
+ *
+ *     * Redistributions of source code must retain the above copyright
+ * notice, this list of conditions and the following disclaimer.
+ *     * Redistributions in binary form must reproduce the above
+ * copyright notice, this list of conditions and the following disclaimer
+ * in the documentation and/or other materials provided with the
+ * distribution.
+ *     * Neither the name of Google Inc. nor the names of its
+ * contributors may be used to endorse or promote products derived from
+ * this software without specific prior written permission.
+ *
+ * THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS
+ * "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT
+ * LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR
+ * A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT
+ * OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
+ * SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT
+ * LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE,
+ * DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY
+ * THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
+ * (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
+ * OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
+ *
+ */
+
+#ifndef GRPC_TIMERS_H
+#define GRPC_TIMERS_H
+
+#include <stdio.h>
+
+#ifdef __cplusplus
+extern "C" {
+#endif
+
+typedef struct grpc_timers_log grpc_timers_log;
+
+void grpc_timers_log_global_init(void);
+void grpc_timers_log_global_destroy(void);
+grpc_timers_log* grpc_timers_log_create(int capacity_limit, FILE *dump,
+                                        const char *fmt);
+void grpc_timers_log_add(grpc_timers_log *, const char *tag, int seq,
+                        const char *file, int line);
+void grpc_timers_log_destroy(grpc_timers_log *);
+
+extern grpc_timers_log *grpc_timers_log_global;
+
+#define GRPC_TIMER_MARK(x, s) grpc_timers_log_add(grpc_timers_log_global, #x, \
+    s, __FILE__, __LINE__);
+
+
+#ifdef __cplusplus
+}
+#endif
+
+#endif /* GRPC_TIMERS_H */

src/core/surface/init.c

@@ -32,10 +32,11 @@
  */
 
 #include <grpc/grpc.h>
-#include "src/core/iomgr/iomgr.h"
+#include "src/core/channel/channel_stack.h"
 #include "src/core/debug/trace.h"
+#include "src/core/iomgr/iomgr.h"
 #include "src/core/statistics/census_interface.h"
-#include "src/core/channel/channel_stack.h"
+#include "src/core/statistics/timers.h"
 #include "src/core/surface/call.h"
 #include "src/core/surface/init.h"
 #include "src/core/surface/surface_trace.h"
@@ -63,6 +64,7 @@ void grpc_init(void) {
     grpc_tracer_init("GRPC_TRACE");
     grpc_iomgr_init();
     census_init();
+    grpc_timers_log_global_init();
   }
   gpr_mu_unlock(&g_init_mu);
 }
@@ -72,6 +74,7 @@ void grpc_shutdown(void) {
   if (--g_initializations == 0) {
     grpc_iomgr_shutdown();
     census_shutdown();
+    grpc_timers_log_global_destroy();
   }
   gpr_mu_unlock(&g_init_mu);
 }

test/core/statistics/timers_test.c

@@ -0,0 +1,83 @@
+/*
+ *
+ * Copyright 2015, Google Inc.
+ * All rights reserved.
+ *
+ * Redistribution and use in source and binary forms, with or without
+ * modification, are permitted provided that the following conditions are
+ * met:
+ *
+ *     * Redistributions of source code must retain the above copyright
+ * notice, this list of conditions and the following disclaimer.
+ *     * Redistributions in binary form must reproduce the above
+ * copyright notice, this list of conditions and the following disclaimer
+ * in the documentation and/or other materials provided with the
+ * distribution.
+ *     * Neither the name of Google Inc. nor the names of its
+ * contributors may be used to endorse or promote products derived from
+ * this software without specific prior written permission.
+ *
+ * THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS
+ * "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT
+ * LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR
+ * A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT
+ * OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
+ * SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT
+ * LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE,
+ * DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY
+ * THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
+ * (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
+ * OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
+ *
+ */
+
+#include "src/core/statistics/timers.h"
+#include <stdlib.h>
+#include "test/core/util/test_config.h"
+
+void test_log_events(int num_seqs) {
+  int start = 0;
+  int *state;
+  state = calloc(num_seqs,sizeof(state[0]));
+  while (start < num_seqs) {
+    int i;
+    int row;
+    if (state[start] == 3) { /* Already done with this posn */
+      start++;
+      continue;
+    }
+
+    row = rand() % 10; /* how many in a row */
+    for (i = start; (i < start+row) && (i < num_seqs); i++) {
+      int j;
+      int advance = 1 + rand() % 3; /* how many to advance by */
+      for (j=0; j<advance; j++) {
+        switch (state[i]) {
+          case 0:
+            GRPC_TIMER_MARK(STATE_0, i);
+            state[i]++;
+            break;
+          case 1:
+            GRPC_TIMER_MARK(STATE_1, i);
+            state[i]++;
+            break;
+          case 2:
+            GRPC_TIMER_MARK(STATE_2, i);
+            state[i]++;
+            break;
+          case 3:
+            break;
+        }
+      }
+    }
+  }
+  free(state);
+}
+
+int main(int argc, char **argv) {
+  grpc_test_init(argc, argv);
+  grpc_timers_log_global_init();
+  test_log_events(1000000);
+  grpc_timers_log_global_destroy();
+  return 0;
+}