From a9eb302abaccdd3609d81ba75434cccaed49f4fd Mon Sep 17 00:00:00 2001
From: David Garcia Quintas <dgq@google.com>
Date: Mon, 27 Apr 2015 19:17:20 -0700
Subject: [PATCH] STAP annotation working.

Test annotations made to client_channel.c (start_rpc) and channel_create.c
(grpc_channel_create).
---
 Makefile                             | 25 +++++++++++++++++
 src/core/channel/client_channel.c    |  4 +++
 src/core/surface/channel_create.c    |  8 ++++--
 test/build/systemtap.c               | 42 ++++++++++++++++++++++++++++
 test/core/profiling/mark_timings.stp | 32 +++++++++++++++++++++
 5 files changed, 109 insertions(+), 2 deletions(-)
 create mode 100644 test/build/systemtap.c
 create mode 100644 test/core/profiling/mark_timings.stp

diff --git a/Makefile b/Makefile
index 2def6e2413..1955e2fa48 100644
--- a/Makefile
+++ b/Makefile
@@ -183,6 +183,7 @@ DEFINES_gcov = NDEBUG
 prefix ?= /usr/local
 
 PROTOC = protoc
+DTRACE = dtrace
 CONFIG ?= opt
 CC = $(CC_$(CONFIG))
 CXX = $(CXX_$(CONFIG))
@@ -350,6 +351,8 @@ PERFTOOLS_CHECK_CMD = $(CC) $(CFLAGS) $(CPPFLAGS) -o $(TMPOUT) test/build/perfto
 PROTOBUF_CHECK_CMD = $(CXX) $(CXXFLAGS) $(CPPFLAGS) -o $(TMPOUT) test/build/protobuf.cc -lprotobuf $(LDFLAGS)
 PROTOC_CHECK_CMD = which protoc > /dev/null
 PROTOC_CHECK_VERSION_CMD = protoc --version | grep -q libprotoc.3
+DTRACE_CHECK_CMD = which dtrace > /dev/null
+SYSTEMTAP_HEADERS_CHECK_CMD = $(CC) $(CFLAGS) $(CPPFLAGS) -o $(TMPOUT) test/build/systemtap.c $(LDFLAGS)
 
 ifeq ($(OPENSSL_REQUIRES_DL),true)
 OPENSSL_ALPN_CHECK_CMD += -ldl
@@ -382,6 +385,19 @@ else
 HAS_VALID_PROTOC = false
 endif
 
+# Check for Systemtap (https://sourceware.org/systemtap/), first by making sure <sys/sdt.h> is present
+# in the system and secondly by checking for the "dtrace" binary (on Linux, this is part of the Systemtap
+# distribution. It's part of the base system on BSD/Solaris machines).
+HAS_SYSTEMTAP_HEADERS = $(shell $(SYSTEMTAP_HEADERS_CHECK_CMD) 2> /dev/null && echo true || echo false)
+HAS_DTRACE = $(shell $(DTRACE_CHECK_CMD) 2> /dev/null && echo true || echo false)
+HAS_SYSTEMTAP = false
+ifeq ($(HAS_SYSTEMTAP_HEADERS),true)
+ifeq ($(HAS_DTRACE),true)
+HAS_SYSTEMTAP = true
+DEFINES += GRPC_STAP_PROFILER
+endif
+endif
+
 ifeq ($(wildcard third_party/openssl/ssl/ssl.h),)
 HAS_EMBEDDED_OPENSSL_ALPN = false
 else
@@ -2779,6 +2795,15 @@ $(GENDIR)/test/proto/test.grpc.pb.cc: test/proto/test.proto $(PROTOBUF_DEP) $(PR
 endif
 
 
+ifeq ($(HAS_SYSTEMTAP),true)
+$(GENDIR)/src/core/profiling/stap_probes.h: src/core/profiling/stap_probes.d
+	$(E) "[DTRACE]  Compiling $<"
+	$(Q) mkdir -p `dirname $@`
+	$(Q) $(DTRACE) -C -h -s $< -o $@
+
+src/core/profiling/timers.h: $(GENDIR)/src/core/profiling/stap_probes.h
+endif
+
 $(OBJDIR)/$(CONFIG)/%.o : %.c
 	$(E) "[C]       Compiling $<"
 	$(Q) mkdir -p `dirname $@`
diff --git a/src/core/channel/client_channel.c b/src/core/channel/client_channel.c
index bc481e59ca..0c241240e2 100644
--- a/src/core/channel/client_channel.c
+++ b/src/core/channel/client_channel.c
@@ -39,7 +39,9 @@
 #include "src/core/channel/child_channel.h"
 #include "src/core/channel/connected_channel.h"
 #include "src/core/iomgr/iomgr.h"
+#include "src/core/profiling/timers.h"
 #include "src/core/support/string.h"
+
 #include <grpc/support/alloc.h>
 #include <grpc/support/log.h>
 #include <grpc/support/sync.h>
@@ -127,6 +129,7 @@ static void complete_activate(grpc_call_element *elem, grpc_call_op *op) {
 static void start_rpc(grpc_call_element *elem, grpc_call_op *op) {
   call_data *calld = elem->call_data;
   channel_data *chand = elem->channel_data;
+  GRPC_STAP_TIMING_NS_BEGIN(2);
   gpr_mu_lock(&chand->mu);
   if (calld->state == CALL_CANCELLED) {
     gpr_mu_unlock(&chand->mu);
@@ -172,6 +175,7 @@ static void start_rpc(grpc_call_element *elem, grpc_call_op *op) {
       grpc_transport_setup_initiate(chand->transport_setup);
     }
   }
+  GRPC_STAP_TIMING_NS_END(2);
 }
 
 static void remove_waiting_child(channel_data *chand, call_data *calld) {
diff --git a/src/core/surface/channel_create.c b/src/core/surface/channel_create.c
index 3104b1d00d..73b3670ccc 100644
--- a/src/core/surface/channel_create.c
+++ b/src/core/surface/channel_create.c
@@ -31,6 +31,7 @@
  *
  */
 
+
 #include "src/core/iomgr/sockaddr.h"
 
 #include <grpc/grpc.h>
@@ -48,10 +49,12 @@
 #include "src/core/iomgr/endpoint.h"
 #include "src/core/iomgr/resolve_address.h"
 #include "src/core/iomgr/tcp_client.h"
+#include "src/core/profiling/timers.h"
+#include "src/core/support/string.h"
 #include "src/core/surface/channel.h"
 #include "src/core/surface/client.h"
-#include "src/core/support/string.h"
 #include "src/core/transport/chttp2_transport.h"
+
 #include <grpc/support/alloc.h>
 #include <grpc/support/log.h>
 #include <grpc/support/sync.h>
@@ -195,6 +198,7 @@ grpc_channel *grpc_channel_create(const char *target,
 #define MAX_FILTERS 3
   const grpc_channel_filter *filters[MAX_FILTERS];
   int n = 0;
+  GRPC_STAP_TIMING_NS_BEGIN(1);
   filters[n++] = &grpc_client_surface_filter;
   if (grpc_channel_args_is_census_enabled(args)) {
     filters[n++] = &grpc_client_census_filter;
@@ -210,6 +214,6 @@ grpc_channel *grpc_channel_create(const char *target,
   grpc_client_setup_create_and_attach(grpc_channel_get_channel_stack(channel),
                                       args, mdctx, initiate_setup, done_setup,
                                       s);
-
+  GRPC_STAP_TIMING_NS_END(1);
   return channel;
 }
diff --git a/test/build/systemtap.c b/test/build/systemtap.c
new file mode 100644
index 0000000000..66ff38ebd6
--- /dev/null
+++ b/test/build/systemtap.c
@@ -0,0 +1,42 @@
+/*
+ *
+ * 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 <sys/sdt.h>
+
+#ifndef _SYS_SDT_H
+#error "_SYS_SDT_H not defined, despite <sys/sdt.h> being present."
+#endif
+
+int main() {
+  return 0;
+}
diff --git a/test/core/profiling/mark_timings.stp b/test/core/profiling/mark_timings.stp
new file mode 100644
index 0000000000..a7ccc83c61
--- /dev/null
+++ b/test/core/profiling/mark_timings.stp
@@ -0,0 +1,32 @@
+global starts, times, times_per_tag
+
+probe process.mark("timing_ns_begin") {
+  starts[$arg1, tid()] = gettimeofday_ns();
+}
+
+probe process.mark("timing_ns_end") {
+  tag = $arg1
+  t = gettimeofday_ns();
+  if (s = starts[tag, tid()]) {
+     times[tag, tid()] <<< t-s;
+     delete starts[tag, tid()];
+  }
+}
+
+probe end {
+  printf("%15s %9s %10s %10s %10s %10s\n", "tag", "tid", "count",
+    "min(ns)", "avg(ns)", "max(ns)");
+  foreach ([tag+, tid] in times) {
+    printf("%15X %9d %10d %10d %10d %10d\n", tag, tid, @count(times[tag, tid]),
+          @min(times[tag, tid]), @avg(times[tag, tid]), @max(times[tag, tid]));
+  }
+
+  printf("Per tag average of averages\n");
+  foreach ([tag+, tid] in times) {
+    times_per_tag[tag] <<< @avg(times[tag, tid]);
+  }
+  printf("%15s %10s %10s\n", "tag", "count", "avg(ns)");
+  foreach ([tag+] in times_per_tag) {
+    printf("%15X %10d %10d\n", tag, @count(times_per_tag[tag]), @avg(times_per_tag[tag]));
+  }
+}
-- 
GitLab