Merge pull request #1408 from dgquintas/stap

Integration of Systemtap as a profiling mechanism.
pull/1434/head
Craig Tiller 10 years ago
commit f2791ab02b
  1. 6
      BUILD
  2. 70
      Makefile
  3. 3
      build.json
  4. 2
      src/core/iomgr/pollset_posix.c
  5. 20
      src/core/iomgr/tcp_posix.c
  6. 41
      src/core/profiling/basic_timers.c
  7. 6
      src/core/profiling/stap_probes.d
  8. 57
      src/core/profiling/stap_timers.c
  9. 90
      src/core/profiling/timers.h
  10. 4
      src/core/surface/init.c
  11. 6
      src/cpp/client/channel.cc
  12. 8
      src/cpp/common/call.cc
  13. 8
      src/cpp/server/server.cc
  14. 64
      templates/Makefile.template
  15. 42
      test/build/systemtap.c
  16. 40
      test/core/profiling/mark_timings.stp
  17. 4
      test/core/profiling/timers_test.c
  18. 4
      vsprojects/grpc/grpc.vcxproj
  19. 5
      vsprojects/grpc/grpc.vcxproj.filters
  20. 4
      vsprojects/grpc_unsecure/grpc_unsecure.vcxproj
  21. 5
      vsprojects/grpc_unsecure/grpc_unsecure.vcxproj.filters

@ -296,7 +296,8 @@ cc_library(
"src/core/json/json_reader.c",
"src/core/json/json_string.c",
"src/core/json/json_writer.c",
"src/core/profiling/timers.c",
"src/core/profiling/basic_timers.c",
"src/core/profiling/stap_timers.c",
"src/core/statistics/census_init.c",
"src/core/statistics/census_log.c",
"src/core/statistics/census_rpc_stats.c",
@ -503,7 +504,8 @@ cc_library(
"src/core/json/json_reader.c",
"src/core/json/json_string.c",
"src/core/json/json_writer.c",
"src/core/profiling/timers.c",
"src/core/profiling/basic_timers.c",
"src/core/profiling/stap_timers.c",
"src/core/statistics/census_init.c",
"src/core/statistics/census_log.c",
"src/core/statistics/census_rpc_stats.c",

@ -87,14 +87,23 @@ CPPFLAGS_opt = -O2
LDFLAGS_opt =
DEFINES_opt = NDEBUG
VALID_CONFIG_latprof = 1
CC_latprof = $(DEFAULT_CC)
CXX_latprof = $(DEFAULT_CXX)
LD_latprof = $(DEFAULT_CC)
LDXX_latprof = $(DEFAULT_CXX)
CPPFLAGS_latprof = -O2 -DGRPC_LATENCY_PROFILER
LDFLAGS_latprof =
DEFINES_latprof = NDEBUG
VALID_CONFIG_basicprof = 1
CC_basicprof = $(DEFAULT_CC)
CXX_basicprof = $(DEFAULT_CXX)
LD_basicprof = $(DEFAULT_CC)
LDXX_basicprof = $(DEFAULT_CXX)
CPPFLAGS_basicprof = -O2 -DGRPC_BASIC_PROFILER
LDFLAGS_basicprof =
DEFINES_basicprof = NDEBUG
VALID_CONFIG_stapprof = 1
CC_stapprof = $(DEFAULT_CC)
CXX_stapprof = $(DEFAULT_CXX)
LD_stapprof = $(DEFAULT_CC)
LDXX_stapprof = $(DEFAULT_CXX)
CPPFLAGS_stapprof = -O2 -DGRPC_STAP_PROFILER
LDFLAGS_stapprof =
DEFINES_stapprof = NDEBUG
VALID_CONFIG_dbg = 1
CC_dbg = $(DEFAULT_CC)
@ -183,6 +192,7 @@ DEFINES_gcov = _DEBUG DEBUG
prefix ?= /usr/local
PROTOC = protoc
DTRACE = dtrace
CONFIG ?= opt
CC = $(CC_$(CONFIG))
CXX = $(CXX_$(CONFIG))
@ -350,6 +360,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 +394,18 @@ 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
endif
endif
ifeq ($(wildcard third_party/openssl/ssl/ssl.h),)
HAS_EMBEDDED_OPENSSL_ALPN = false
else
@ -549,6 +573,17 @@ protoc_dep_message:
@echo " make run_dep_checks"
@echo
systemtap_dep_error:
@echo
@echo "DEPENDENCY ERROR"
@echo
@echo "Under the '$(CONFIG)' configutation, the target you are trying "
@echo "to build requires systemtap 2.7+ (on Linux) or dtrace (on other "
@echo "platforms such as Solaris and *BSD). "
@echo
@echo "Please consult INSTALL to get more information."
@echo
stop:
@false
@ -2779,6 +2814,18 @@ $(GENDIR)/test/proto/test.grpc.pb.cc: test/proto/test.proto $(PROTOBUF_DEP) $(PR
endif
ifeq ($(CONFIG),stapprof)
src/core/profiling/stap_timers.c: $(GENDIR)/src/core/profiling/stap_probes.h
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 $@
else
$(GENDIR)/src/core/profiling/stap_probes.h: systemtap_dep_error stop
endif
endif
$(OBJDIR)/$(CONFIG)/%.o : %.c
$(E) "[C] Compiling $<"
$(Q) mkdir -p `dirname $@`
@ -2799,7 +2846,6 @@ $(OBJDIR)/$(CONFIG)/%.o : %.cc
$(Q) mkdir -p `dirname $@`
$(Q) $(CXX) $(CXXFLAGS) $(CPPFLAGS) -MMD -MF $(addsuffix .dep, $(basename $@)) -c -o $@ $<
install: install_c install_cxx install-plugins install-certs verify-install
install_c: install-headers_c install-static_c install-shared_c
@ -3196,7 +3242,8 @@ LIBGRPC_SRC = \
src/core/json/json_reader.c \
src/core/json/json_string.c \
src/core/json/json_writer.c \
src/core/profiling/timers.c \
src/core/profiling/basic_timers.c \
src/core/profiling/stap_timers.c \
src/core/statistics/census_init.c \
src/core/statistics/census_log.c \
src/core/statistics/census_rpc_stats.c \
@ -3444,7 +3491,8 @@ LIBGRPC_UNSECURE_SRC = \
src/core/json/json_reader.c \
src/core/json/json_string.c \
src/core/json/json_writer.c \
src/core/profiling/timers.c \
src/core/profiling/basic_timers.c \
src/core/profiling/stap_timers.c \
src/core/statistics/census_init.c \
src/core/statistics/census_log.c \
src/core/statistics/census_rpc_stats.c \

@ -231,7 +231,8 @@
"src/core/json/json_reader.c",
"src/core/json/json_string.c",
"src/core/json/json_writer.c",
"src/core/profiling/timers.c",
"src/core/profiling/basic_timers.c",
"src/core/profiling/stap_timers.c",
"src/core/statistics/census_init.c",
"src/core/statistics/census_log.c",
"src/core/statistics/census_rpc_stats.c",

@ -411,7 +411,7 @@ static int unary_poll_pollset_maybe_work(grpc_pollset *pollset,
pfd[1].events = grpc_fd_begin_poll(fd, pollset, POLLIN, POLLOUT, &fd_watcher);
r = poll(pfd, GPR_ARRAY_SIZE(pfd), timeout);
GRPC_TIMER_MARK(POLL_FINISHED, r);
GRPC_TIMER_MARK(GRPC_PTAG_POLL_FINISHED, r);
grpc_fd_end_poll(&fd_watcher);

@ -327,7 +327,7 @@ static void grpc_tcp_handle_read(void *arg /* grpc_tcp */, int success) {
gpr_slice *final_slices;
size_t final_nslices;
GRPC_TIMER_MARK(HANDLE_READ_BEGIN, 0);
GRPC_TIMER_BEGIN(GRPC_PTAG_HANDLE_READ, 0);
slice_state_init(&read_state, static_read_slices, INLINE_SLICE_BUFFER_SIZE,
0);
@ -350,11 +350,11 @@ static void grpc_tcp_handle_read(void *arg /* grpc_tcp */, int success) {
msg.msg_controllen = 0;
msg.msg_flags = 0;
GRPC_TIMER_MARK(RECVMSG_BEGIN, 0);
GRPC_TIMER_BEGIN(GRPC_PTAG_RECVMSG, 0);
do {
read_bytes = recvmsg(tcp->fd, &msg, 0);
} while (read_bytes < 0 && errno == EINTR);
GRPC_TIMER_MARK(RECVMSG_END, 0);
GRPC_TIMER_END(GRPC_PTAG_RECVMSG, 0);
if (read_bytes < allocated_bytes) {
/* TODO(klempner): Consider a second read first, in hopes of getting a
@ -406,7 +406,7 @@ static void grpc_tcp_handle_read(void *arg /* grpc_tcp */, int success) {
++iov_size;
}
}
GRPC_TIMER_MARK(HANDLE_READ_END, 0);
GRPC_TIMER_END(GRPC_PTAG_HANDLE_READ, 0);
}
static void grpc_tcp_notify_on_read(grpc_endpoint *ep, grpc_endpoint_read_cb cb,
@ -438,12 +438,12 @@ static grpc_endpoint_write_status grpc_tcp_flush(grpc_tcp *tcp) {
msg.msg_controllen = 0;
msg.msg_flags = 0;
GRPC_TIMER_MARK(SENDMSG_BEGIN, 0);
GRPC_TIMER_BEGIN(GRPC_PTAG_SENDMSG, 0);
do {
/* TODO(klempner): Cork if this is a partial write */
sent_length = sendmsg(tcp->fd, &msg, 0);
} while (sent_length < 0 && errno == EINTR);
GRPC_TIMER_MARK(SENDMSG_END, 0);
GRPC_TIMER_END(GRPC_PTAG_SENDMSG, 0);
if (sent_length < 0) {
if (errno == EAGAIN) {
@ -479,7 +479,7 @@ static void grpc_tcp_handle_write(void *arg /* grpc_tcp */, int success) {
return;
}
GRPC_TIMER_MARK(CB_WRITE_BEGIN, 0);
GRPC_TIMER_BEGIN(GRPC_PTAG_TCP_CB_WRITE, 0);
write_status = grpc_tcp_flush(tcp);
if (write_status == GRPC_ENDPOINT_WRITE_PENDING) {
grpc_fd_notify_on_write(tcp->em_fd, &tcp->write_closure);
@ -495,7 +495,7 @@ static void grpc_tcp_handle_write(void *arg /* grpc_tcp */, int success) {
cb(tcp->write_user_data, cb_status);
grpc_tcp_unref(tcp);
}
GRPC_TIMER_MARK(CB_WRITE_END, 0);
GRPC_TIMER_END(GRPC_PTAG_TCP_CB_WRITE, 0);
}
static grpc_endpoint_write_status grpc_tcp_write(grpc_endpoint *ep,
@ -518,7 +518,7 @@ static grpc_endpoint_write_status grpc_tcp_write(grpc_endpoint *ep,
}
}
GRPC_TIMER_MARK(WRITE_BEGIN, 0);
GRPC_TIMER_BEGIN(GRPC_PTAG_TCP_WRITE, 0);
GPR_ASSERT(tcp->write_cb == NULL);
slice_state_init(&tcp->write_state, slices, nslices, nslices);
@ -532,7 +532,7 @@ static grpc_endpoint_write_status grpc_tcp_write(grpc_endpoint *ep,
grpc_fd_notify_on_write(tcp->em_fd, &tcp->write_closure);
}
GRPC_TIMER_MARK(WRITE_END, 0);
GRPC_TIMER_END(GRPC_PTAG_TCP_WRITE, 0);
return status;
}

@ -31,7 +31,9 @@
*
*/
#ifdef GRPC_LATENCY_PROFILER
#include <grpc/support/port_platform.h>
#ifdef GRPC_BASIC_PROFILER
#include "src/core/profiling/timers.h"
#include "src/core/profiling/timers_preciseclock.h"
@ -46,7 +48,7 @@
typedef struct grpc_timer_entry {
grpc_precise_clock tm;
gpr_thd_id thd;
const char* tag;
int tag;
void* id;
const char* file;
int line;
@ -63,7 +65,7 @@ struct grpc_timers_log {
grpc_timers_log* grpc_timers_log_global = NULL;
grpc_timers_log* grpc_timers_log_create(int capacity_limit, FILE* dump) {
static grpc_timers_log* grpc_timers_log_create(int capacity_limit, FILE* dump) {
grpc_timers_log* log = gpr_malloc(sizeof(*log));
/* TODO (vpai): Allow allocation below limit */
@ -87,15 +89,15 @@ static void log_report_locked(grpc_timers_log* log) {
grpc_timer_entry* entry = &(log->log[i]);
fprintf(fp, "GRPC_LAT_PROF ");
grpc_precise_clock_print(&entry->tm, fp);
fprintf(fp, " %p %s %p %s %d\n", (void*)(gpr_intptr)entry->thd, entry->tag, entry->id, entry->file,
entry->line);
fprintf(fp, " %p %d %p %s %d\n", (void*)(gpr_intptr)entry->thd, entry->tag,
entry->id, entry->file, entry->line);
}
/* Now clear out the log */
log->num_entries = 0;
}
void grpc_timers_log_destroy(grpc_timers_log* log) {
static void grpc_timers_log_destroy(grpc_timers_log* log) {
gpr_mu_lock(&log->mu);
log_report_locked(log);
gpr_mu_unlock(&log->mu);
@ -106,8 +108,8 @@ void grpc_timers_log_destroy(grpc_timers_log* log) {
gpr_free(log);
}
void grpc_timers_log_add(grpc_timers_log* log, const char* tag, void* id,
const char* file, int line) {
static void grpc_timers_log_add(grpc_timers_log* log, int tag, void* id,
const char* file, int line) {
grpc_timer_entry* entry;
/* TODO (vpai) : Improve concurrency */
@ -128,14 +130,25 @@ void grpc_timers_log_add(grpc_timers_log* log, const char* tag, void* id,
gpr_mu_unlock(&log->mu);
}
void grpc_timers_log_global_init(void) {
/* Latency profiler API implementation. */
void grpc_timer_add_mark(int tag, void* id, const char* file, int line) {
grpc_timers_log_add(grpc_timers_log_global, tag, id, file, line);
}
void grpc_timer_begin(int tag, void* id, const char *file, int line) {}
void grpc_timer_end(int tag, void* id, const char *file, int line) {}
/* Basic profiler specific API functions. */
void grpc_timers_global_init(void) {
grpc_timers_log_global = grpc_timers_log_create(100000, stdout);
}
void grpc_timers_log_global_destroy(void) {
void grpc_timers_global_destroy(void) {
grpc_timers_log_destroy(grpc_timers_log_global);
}
#else /* !GRPC_LATENCY_PROFILER */
void grpc_timers_log_global_init(void) {}
void grpc_timers_log_global_destroy(void) {}
#endif /* GRPC_LATENCY_PROFILER */
#else /* !GRPC_BASIC_PROFILER */
void grpc_timers_global_init(void) {}
void grpc_timers_global_destroy(void) {}
#endif /* GRPC_BASIC_PROFILER */

@ -0,0 +1,6 @@
provider _stap {
probe add_mark(int tag);
probe timing_ns_begin(int tag);
probe timing_ns_end(int tag);
};

@ -0,0 +1,57 @@
/*
*
* 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 <grpc/support/port_platform.h>
#ifdef GRPC_STAP_PROFILER
#include "src/core/profiling/timers.h"
#include <sys/sdt.h>
/* Generated from src/core/profiling/stap_probes.d */
#include "src/core/profiling/stap_probes.h"
/* Latency profiler API implementation. */
void grpc_timer_add_mark(int tag, void* id, const char *file, int line) {
_STAP_ADD_MARK(tag);
}
void grpc_timer_begin(int tag, void* id, const char *file, int line) {
_STAP_TIMING_NS_BEGIN(tag);
}
void grpc_timer_end(int tag, void* id, const char *file, int line) {
_STAP_TIMING_NS_END(tag);
}
#endif /* GRPC_STAP_PROFILER */

@ -34,35 +34,87 @@
#ifndef GRPC_CORE_PROFILING_TIMERS_H
#define GRPC_CORE_PROFILING_TIMERS_H
#include <stdio.h>
#ifdef __cplusplus
extern "C" {
#endif
#ifdef GRPC_LATENCY_PROFILER
void grpc_timers_global_init(void);
void grpc_timers_global_destroy(void);
typedef struct grpc_timers_log grpc_timers_log;
void grpc_timer_add_mark(int tag, void* id, const char *file, int line);
void grpc_timer_begin(int tag, void* id, const char *file, int line);
void grpc_timer_end(int tag, void* id, const char *file, int line);
grpc_timers_log* grpc_timers_log_create(int capacity_limit, FILE* dump);
void grpc_timers_log_add(grpc_timers_log*, const char* tag, void* id,
const char* file, int line);
void grpc_timers_log_destroy(grpc_timers_log *);
enum grpc_profiling_tags {
/* Any GRPC_PTAG_* >= than the threshold won't generate any profiling mark. */
GRPC_PTAG_IGNORE_THRESHOLD = 1000000,
extern grpc_timers_log *grpc_timers_log_global;
/* Re. Protos. */
GRPC_PTAG_PROTO_SERIALIZE = 100 + GRPC_PTAG_IGNORE_THRESHOLD,
GRPC_PTAG_PROTO_DESERIALIZE = 101 + GRPC_PTAG_IGNORE_THRESHOLD,
/* Re. sockets. */
GRPC_PTAG_HANDLE_READ = 200 + GRPC_PTAG_IGNORE_THRESHOLD,
GRPC_PTAG_SENDMSG = 201 + GRPC_PTAG_IGNORE_THRESHOLD,
GRPC_PTAG_RECVMSG = 202 + GRPC_PTAG_IGNORE_THRESHOLD,
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,
/* C++ */
GRPC_PTAG_CPP_CALL_CREATED = 300 + GRPC_PTAG_IGNORE_THRESHOLD,
GRPC_PTAG_CPP_PERFORM_OPS = 301 + GRPC_PTAG_IGNORE_THRESHOLD,
#define GRPC_TIMER_MARK(x, s) \
grpc_timers_log_add(grpc_timers_log_global, #x, ((void *)(gpr_intptr)(s)), \
__FILE__, __LINE__)
/* > 1024 Unassigned reserved. For any miscellaneous use.
* Use addition to generate tags from this base or take advantage of the 10
* zero'd bits for OR-ing. */
GRPC_PTAG_OTHER_BASE = 1024
};
#else /* !GRPC_LATENCY_PROFILER */
#define GRPC_TIMER_MARK(x, s) \
do { \
} while (0)
#endif /* GRPC_LATENCY_PROFILER */
#if !(defined(GRPC_STAP_PROFILER) + defined(GRPC_BASIC_PROFILER))
/* No profiling. No-op all the things. */
#define GRPC_TIMER_MARK(tag, id) \
do {} while(0)
#define GRPC_TIMER_BEGIN(tag, id) \
do {} while(0)
#define GRPC_TIMER_END(tag, id) \
do {} while(0)
#else /* at least one profiler requested... */
/* ... hopefully only one. */
#if defined(GRPC_STAP_PROFILER) && defined(GRPC_BASIC_PROFILER)
#error "GRPC_STAP_PROFILER and GRPC_BASIC_PROFILER are mutually exclusive."
#endif
/* Generic profiling interface. */
#define GRPC_TIMER_MARK(tag, id) \
if (tag < GRPC_PTAG_IGNORE_THRESHOLD) { \
grpc_timer_add_mark(tag, ((void *)(gpr_intptr)(id)), __FILE__, __LINE__); \
}
#define GRPC_TIMER_BEGIN(tag, id) \
if (tag < GRPC_PTAG_IGNORE_THRESHOLD) { \
grpc_timer_begin(tag, ((void *)(gpr_intptr)(id)), __FILE__, __LINE__); \
}
#define GRPC_TIMER_END(tag, id) \
if (tag < GRPC_PTAG_IGNORE_THRESHOLD) { \
grpc_timer_end(tag, ((void *)(gpr_intptr)(id)), __FILE__, __LINE__); \
}
#ifdef GRPC_STAP_PROFILER
/* Empty placeholder for now. */
#endif /* GRPC_STAP_PROFILER */
#ifdef GRPC_BASIC_PROFILER
typedef struct grpc_timers_log grpc_timers_log;
extern grpc_timers_log *grpc_timers_log_global;
#endif /* GRPC_BASIC_PROFILER */
void grpc_timers_log_global_init(void);
void grpc_timers_log_global_destroy(void);
#endif /* at least one profiler requested. */
#ifdef __cplusplus
}

@ -64,7 +64,7 @@ void grpc_init(void) {
grpc_iomgr_init();
grpc_tracer_init("GRPC_TRACE");
census_init();
grpc_timers_log_global_init();
grpc_timers_global_init();
}
gpr_mu_unlock(&g_init_mu);
}
@ -74,7 +74,7 @@ void grpc_shutdown(void) {
if (--g_initializations == 0) {
grpc_iomgr_shutdown();
census_shutdown();
grpc_timers_log_global_destroy();
grpc_timers_global_destroy();
}
gpr_mu_unlock(&g_init_mu);
}

@ -70,7 +70,7 @@ Call Channel::CreateCall(const RpcMethod& method, ClientContext* context,
? target_.c_str()
: context->authority().c_str(),
context->raw_deadline());
GRPC_TIMER_MARK(CALL_CREATED, c_call);
GRPC_TIMER_MARK(GRPC_PTAG_CPP_CALL_CREATED, c_call);
context->set_call(c_call, shared_from_this());
return Call(c_call, this, cq);
}
@ -79,11 +79,11 @@ void Channel::PerformOpsOnCall(CallOpBuffer* buf, Call* call) {
static const size_t MAX_OPS = 8;
size_t nops = MAX_OPS;
grpc_op ops[MAX_OPS];
GRPC_TIMER_MARK(PERFORM_OPS_BEGIN, call->call());
GRPC_TIMER_BEGIN(GRPC_PTAG_CPP_PERFORM_OPS, call->call());
buf->FillOps(ops, &nops);
GPR_ASSERT(GRPC_CALL_OK ==
grpc_call_start_batch(call->call(), ops, nops, buf));
GRPC_TIMER_MARK(PERFORM_OPS_END, call->call());
GRPC_TIMER_END(GRPC_PTAG_CPP_PERFORM_OPS, call->call());
}
void* Channel::RegisterMethod(const char* method) {

@ -232,13 +232,13 @@ void CallOpBuffer::FillOps(grpc_op* ops, size_t* nops) {
}
if (send_message_ || send_message_buffer_) {
if (send_message_) {
GRPC_TIMER_MARK(SER_PROTO_BEGIN, 0);
GRPC_TIMER_BEGIN(GRPC_PTAG_PROTO_SERIALIZE, 0);
bool success = SerializeProto(*send_message_, &send_buf_);
if (!success) {
abort();
// TODO handle parse failure
}
GRPC_TIMER_MARK(SER_PROTO_END, 0);
GRPC_TIMER_END(GRPC_PTAG_PROTO_SERIALIZE, 0);
} else {
send_buf_ = send_message_buffer_->buffer();
}
@ -310,10 +310,10 @@ bool CallOpBuffer::FinalizeResult(void** tag, bool* status) {
if (recv_buf_) {
got_message = *status;
if (recv_message_) {
GRPC_TIMER_MARK(DESER_PROTO_BEGIN, 0);
GRPC_TIMER_BEGIN(GRPC_PTAG_PROTO_DESERIALIZE, 0);
*status = *status && DeserializeProto(recv_buf_, recv_message_);
grpc_byte_buffer_destroy(recv_buf_);
GRPC_TIMER_MARK(DESER_PROTO_END, 0);
GRPC_TIMER_END(GRPC_PTAG_PROTO_DESERIALIZE, 0);
} else {
recv_message_buffer_->set_buffer(recv_buf_);
}

@ -124,12 +124,12 @@ class Server::SyncRequest GRPC_FINAL : public CompletionQueueTag {
std::unique_ptr<grpc::protobuf::Message> req;
std::unique_ptr<grpc::protobuf::Message> res;
if (has_request_payload_) {
GRPC_TIMER_MARK(DESER_PROTO_BEGIN, call_.call());
GRPC_TIMER_BEGIN(GRPC_PTAG_PROTO_DESERIALIZE, call_.call());
req.reset(method_->AllocateRequestProto());
if (!DeserializeProto(request_payload_, req.get())) {
abort(); // for now
}
GRPC_TIMER_MARK(DESER_PROTO_END, call_.call());
GRPC_TIMER_END(GRPC_PTAG_PROTO_DESERIALIZE, call_.call());
}
if (has_response_payload_) {
res.reset(method_->AllocateResponseProto());
@ -346,9 +346,9 @@ class Server::AsyncRequest GRPC_FINAL : public CompletionQueueTag {
bool orig_status = *status;
if (*status && request_) {
if (payload_) {
GRPC_TIMER_MARK(DESER_PROTO_BEGIN, call_);
GRPC_TIMER_BEGIN(GRPC_PTAG_PROTO_DESERIALIZE, call_);
*status = DeserializeProto(payload_, request_);
GRPC_TIMER_MARK(DESER_PROTO_END, call_);
GRPC_TIMER_END(GRPC_PTAG_PROTO_DESERIALIZE, call_);
} else {
*status = false;
}

@ -101,14 +101,23 @@ CPPFLAGS_opt = -O2
LDFLAGS_opt =
DEFINES_opt = NDEBUG
VALID_CONFIG_latprof = 1
CC_latprof = $(DEFAULT_CC)
CXX_latprof = $(DEFAULT_CXX)
LD_latprof = $(DEFAULT_CC)
LDXX_latprof = $(DEFAULT_CXX)
CPPFLAGS_latprof = -O2 -DGRPC_LATENCY_PROFILER
LDFLAGS_latprof =
DEFINES_latprof = NDEBUG
VALID_CONFIG_basicprof = 1
CC_basicprof = $(DEFAULT_CC)
CXX_basicprof = $(DEFAULT_CXX)
LD_basicprof = $(DEFAULT_CC)
LDXX_basicprof = $(DEFAULT_CXX)
CPPFLAGS_basicprof = -O2 -DGRPC_BASIC_PROFILER
LDFLAGS_basicprof =
DEFINES_basicprof = NDEBUG
VALID_CONFIG_stapprof = 1
CC_stapprof = $(DEFAULT_CC)
CXX_stapprof = $(DEFAULT_CXX)
LD_stapprof = $(DEFAULT_CC)
LDXX_stapprof = $(DEFAULT_CXX)
CPPFLAGS_stapprof = -O2 -DGRPC_STAP_PROFILER
LDFLAGS_stapprof =
DEFINES_stapprof = NDEBUG
VALID_CONFIG_dbg = 1
CC_dbg = $(DEFAULT_CC)
@ -197,6 +206,7 @@ DEFINES_gcov = _DEBUG DEBUG
prefix ?= /usr/local
PROTOC = protoc
DTRACE = dtrace
CONFIG ?= opt
CC = $(CC_$(CONFIG))
CXX = $(CXX_$(CONFIG))
@ -364,6 +374,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
@ -396,6 +408,18 @@ 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
endif
endif
ifeq ($(wildcard third_party/openssl/ssl/ssl.h),)
HAS_EMBEDDED_OPENSSL_ALPN = false
else
@ -575,6 +599,17 @@ protoc_dep_message:
@echo " make run_dep_checks"
@echo
systemtap_dep_error:
@echo
@echo "DEPENDENCY ERROR"
@echo
@echo "Under the '$(CONFIG)' configutation, the target you are trying "
@echo "to build requires systemtap 2.7+ (on Linux) or dtrace (on other "
@echo "platforms such as Solaris and *BSD). "
@echo
@echo "Please consult INSTALL to get more information."
@echo
stop:
@false
@ -863,6 +898,18 @@ endif
% endfor
ifeq ($(CONFIG),stapprof)
src/core/profiling/stap_timers.c: $(GENDIR)/src/core/profiling/stap_probes.h
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 $@
else
$(GENDIR)/src/core/profiling/stap_probes.h: systemtap_dep_error stop
endif
endif
$(OBJDIR)/$(CONFIG)/%.o : %.c
$(E) "[C] Compiling $<"
$(Q) mkdir -p `dirname $@`
@ -883,7 +930,6 @@ $(OBJDIR)/$(CONFIG)/%.o : %.cc
$(Q) mkdir -p `dirname $@`
$(Q) $(CXX) $(CXXFLAGS) $(CPPFLAGS) -MMD -MF $(addsuffix .dep, $(basename $@)) -c -o $@ $<
install: install_c install_cxx install-plugins install-certs verify-install
install_c: install-headers_c install-static_c install-shared_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;
}

@ -0,0 +1,40 @@
/* This script requires a command line argument, to be used in the "process"
* probe definition.
*
* For a statically build binary, that'd be the name of the binary itself.
* For dinamically built ones, point to the location of the libgprc.so being
* used. */
global starts, times, times_per_tag
probe process(@1).mark("timing_ns_begin") {
starts[$arg1, tid()] = gettimeofday_ns();
}
probe process(@1).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]));
}
}

@ -76,8 +76,8 @@ void test_log_events(int num_seqs) {
int main(int argc, char **argv) {
grpc_test_init(argc, argv);
grpc_timers_log_global_init();
grpc_timers_global_init();
test_log_events(1000000);
grpc_timers_log_global_destroy();
grpc_timers_global_destroy();
return 0;
}

@ -399,7 +399,9 @@
</ClCompile>
<ClCompile Include="..\..\src\core\json\json_writer.c">
</ClCompile>
<ClCompile Include="..\..\src\core\profiling\timers.c">
<ClCompile Include="..\..\src\core\profiling\basic_timers.c">
</ClCompile>
<ClCompile Include="..\..\src\core\profiling\stap_timers.c">
</ClCompile>
<ClCompile Include="..\..\src\core\statistics\census_init.c">
</ClCompile>

@ -211,7 +211,10 @@
<ClCompile Include="..\..\src\core\json\json_writer.c">
<Filter>src\core\json</Filter>
</ClCompile>
<ClCompile Include="..\..\src\core\profiling\timers.c">
<ClCompile Include="..\..\src\core\profiling\basic_timers.c">
<Filter>src\core\profiling</Filter>
</ClCompile>
<ClCompile Include="..\..\src\core\profiling\stap_timers.c">
<Filter>src\core\profiling</Filter>
</ClCompile>
<ClCompile Include="..\..\src\core\statistics\census_init.c">

@ -344,7 +344,9 @@
</ClCompile>
<ClCompile Include="..\..\src\core\json\json_writer.c">
</ClCompile>
<ClCompile Include="..\..\src\core\profiling\timers.c">
<ClCompile Include="..\..\src\core\profiling\basic_timers.c">
</ClCompile>
<ClCompile Include="..\..\src\core\profiling\stap_timers.c">
</ClCompile>
<ClCompile Include="..\..\src\core\statistics\census_init.c">
</ClCompile>

@ -154,7 +154,10 @@
<ClCompile Include="..\..\src\core\json\json_writer.c">
<Filter>src\core\json</Filter>
</ClCompile>
<ClCompile Include="..\..\src\core\profiling\timers.c">
<ClCompile Include="..\..\src\core\profiling\basic_timers.c">
<Filter>src\core\profiling</Filter>
</ClCompile>
<ClCompile Include="..\..\src\core\profiling\stap_timers.c">
<Filter>src\core\profiling</Filter>
</ClCompile>
<ClCompile Include="..\..\src\core\statistics\census_init.c">

Loading…
Cancel
Save