diff --git a/src/core/channel/client_channel.c b/src/core/channel/client_channel.c
index 8e7cb27cfd2bb3e7d6f23a6f9ea91bcadc512dc2..b3e10b023722e259efb2bc71816aa3e4f6afa422 100644
--- a/src/core/channel/client_channel.c
+++ b/src/core/channel/client_channel.c
@@ -36,16 +36,18 @@
#include <stdio.h>
#include <string.h>
+#include <grpc/support/alloc.h>
+#include <grpc/support/log.h>
+#include <grpc/support/sync.h>
+#include <grpc/support/useful.h>
+
#include "src/core/channel/channel_args.h"
#include "src/core/channel/connected_channel.h"
-#include "src/core/surface/channel.h"
#include "src/core/iomgr/iomgr.h"
+#include "src/core/profiling/timers.h"
#include "src/core/support/string.h"
+#include "src/core/surface/channel.h"
#include "src/core/transport/connectivity_state.h"
-#include <grpc/support/alloc.h>
-#include <grpc/support/log.h>
-#include <grpc/support/sync.h>
-#include <grpc/support/useful.h>
/* Client channel implementation */
@@ -235,6 +237,8 @@ static void picked_target(grpc_exec_ctx *exec_ctx, void *arg,
call_data *calld = arg;
grpc_pollset *pollset;
+ GRPC_TIMER_BEGIN(GRPC_PTAG_CHANNEL_PICKED_TARGET, 0);
+
if (calld->picked_channel == NULL) {
/* treat this like a cancellation */
calld->waiting_op.cancel_with_status = GRPC_STATUS_UNAVAILABLE;
@@ -255,6 +259,8 @@ static void picked_target(grpc_exec_ctx *exec_ctx, void *arg,
&calld->async_setup_task);
}
}
+
+ GRPC_TIMER_END(GRPC_PTAG_CHANNEL_PICKED_TARGET, 0);
}
static grpc_closure *merge_into_waiting_op(grpc_call_element *elem,
diff --git a/src/core/iomgr/exec_ctx.c b/src/core/iomgr/exec_ctx.c
index 10786b44c2010a4f7191e6a53894c7467b49ae9c..7e40c551721470b6155361d91007434e5dff2102 100644
--- a/src/core/iomgr/exec_ctx.c
+++ b/src/core/iomgr/exec_ctx.c
@@ -45,8 +45,10 @@ int grpc_exec_ctx_flush(grpc_exec_ctx *exec_ctx) {
exec_ctx->closure_list.head = exec_ctx->closure_list.tail = NULL;
while (c != NULL) {
grpc_closure *next = c->next;
- did_something = 1;
+ did_something++;
+ GRPC_TIMER_BEGIN(GRPC_PTAG_EXEC_CTX_STEP, 0);
c->cb(exec_ctx, c->cb_arg, c->success);
+ GRPC_TIMER_END(GRPC_PTAG_EXEC_CTX_STEP, 0);
c = next;
}
}
diff --git a/src/core/profiling/timers.h b/src/core/profiling/timers.h
index 326c1997c32cf17db391c11efdb788cfc05b8db5..8305dac2cff0e371c2abd3a8a1e21ca24bcb982a 100644
--- a/src/core/profiling/timers.h
+++ b/src/core/profiling/timers.h
@@ -65,6 +65,12 @@ enum grpc_profiling_tags {
GRPC_PTAG_TCP_WRITE = 205 + GRPC_PTAG_IGNORE_THRESHOLD,
GRPC_PTAG_BECOME_READABLE = 207,
+ GRPC_PTAG_MUTEX_LOCK = 250,
+ GRPC_PTAG_MUTEX_UNLOCK = 254,
+ GRPC_PTAG_MALLOC = 251,
+ GRPC_PTAG_REALLOC = 252,
+ GRPC_PTAG_FREE = 253,
+
/* C++ */
GRPC_PTAG_CPP_CALL_CREATED = 300 + GRPC_PTAG_IGNORE_THRESHOLD,
GRPC_PTAG_CPP_PERFORM_OPS = 301 + GRPC_PTAG_IGNORE_THRESHOLD,
@@ -74,19 +80,25 @@ enum grpc_profiling_tags {
/* Transports */
GRPC_PTAG_HTTP2_RECV_DATA = 400,
- GRPC_PTAG_HTTP2_UNLOCK = 401 + GRPC_PTAG_IGNORE_THRESHOLD,
- GRPC_PTAG_HTTP2_UNLOCK_CLEANUP = 402 + GRPC_PTAG_IGNORE_THRESHOLD,
+ GRPC_PTAG_HTTP2_UNLOCK = 401,
+ GRPC_PTAG_HTTP2_WRITING_ACTION = 402,
+ GRPC_PTAG_HTTP2_TERMINATE_WRITING = 403,
/* Completion queue */
GRPC_PTAG_CQ_NEXT = 501,
GRPC_PTAG_CQ_PLUCK = 502,
GRPC_PTAG_POLLSET_WORK = 503,
GRPC_PTAG_EXEC_CTX_FLUSH = 504,
+ GRPC_PTAG_EXEC_CTX_STEP = 505,
/* Surface */
GRPC_PTAG_CALL_START_BATCH = 600,
GRPC_PTAG_CALL_ON_DONE_RECV = 601,
GRPC_PTAG_CALL_UNLOCK = 602,
+ GRPC_PTAG_CALL_ON_DONE_SEND = 602,
+
+ /* Channel */
+ GRPC_PTAG_CHANNEL_PICKED_TARGET = 700,
/* > 1024 Unassigned reserved. For any miscellaneous use.
* Use addition to generate tags from this base or take advantage of the 10
diff --git a/src/core/support/alloc.c b/src/core/support/alloc.c
index d2ed82e7717b328adff2ba1e093f05efea68cd41..5e17daafe2dfc06ae413a20cb2487428eeeb4ec7 100644
--- a/src/core/support/alloc.c
+++ b/src/core/support/alloc.c
@@ -35,22 +35,32 @@
#include <stdlib.h>
#include <grpc/support/port_platform.h>
+#include "src/core/profiling/timers.h"
void *gpr_malloc(size_t size) {
- void *p = malloc(size);
+ void *p;
+ GRPC_TIMER_BEGIN(GRPC_PTAG_MALLOC, 0);
+ p = malloc(size);
if (!p) {
abort();
}
+ GRPC_TIMER_END(GRPC_PTAG_MALLOC, 0);
return p;
}
-void gpr_free(void *p) { free(p); }
+void gpr_free(void *p) {
+ GRPC_TIMER_BEGIN(GRPC_PTAG_FREE, 0);
+ free(p);
+ GRPC_TIMER_END(GRPC_PTAG_FREE, 0);
+}
void *gpr_realloc(void *p, size_t size) {
+ GRPC_TIMER_BEGIN(GRPC_PTAG_REALLOC, 0);
p = realloc(p, size);
if (!p) {
abort();
}
+ GRPC_TIMER_END(GRPC_PTAG_REALLOC, 0);
return p;
}
diff --git a/src/core/support/sync_posix.c b/src/core/support/sync_posix.c
index 91c30989ce8676a55194504609cc9a3ec5f5eee5..25a580c289d557e9427595380f016ec58637d11d 100644
--- a/src/core/support/sync_posix.c
+++ b/src/core/support/sync_posix.c
@@ -40,14 +40,23 @@
#include <grpc/support/log.h>
#include <grpc/support/sync.h>
#include <grpc/support/time.h>
+#include "src/core/profiling/timers.h"
void gpr_mu_init(gpr_mu* mu) { GPR_ASSERT(pthread_mutex_init(mu, NULL) == 0); }
void gpr_mu_destroy(gpr_mu* mu) { GPR_ASSERT(pthread_mutex_destroy(mu) == 0); }
-void gpr_mu_lock(gpr_mu* mu) { GPR_ASSERT(pthread_mutex_lock(mu) == 0); }
+void gpr_mu_lock(gpr_mu* mu) {
+ GRPC_TIMER_BEGIN(GRPC_PTAG_MUTEX_LOCK, 0);
+ GPR_ASSERT(pthread_mutex_lock(mu) == 0);
+ GRPC_TIMER_END(GRPC_PTAG_MUTEX_LOCK, 0);
+}
-void gpr_mu_unlock(gpr_mu* mu) { GPR_ASSERT(pthread_mutex_unlock(mu) == 0); }
+void gpr_mu_unlock(gpr_mu* mu) {
+ GRPC_TIMER_BEGIN(GRPC_PTAG_MUTEX_UNLOCK, 0);
+ GPR_ASSERT(pthread_mutex_unlock(mu) == 0);
+ GRPC_TIMER_END(GRPC_PTAG_MUTEX_UNLOCK, 0);
+}
int gpr_mu_trylock(gpr_mu* mu) {
int err = pthread_mutex_trylock(mu);
diff --git a/src/core/surface/call.c b/src/core/surface/call.c
index 6747c8af561f6264efd55ac4bb8cbb523b4ea556..9e2182952b68fdca0bffe2cc84aeee094cdecf14 100644
--- a/src/core/surface/call.c
+++ b/src/core/surface/call.c
@@ -836,6 +836,7 @@ static void early_out_write_ops(grpc_call *call) {
static void call_on_done_send(grpc_exec_ctx *exec_ctx, void *pc, int success) {
grpc_call *call = pc;
+ GRPC_TIMER_BEGIN(GRPC_PTAG_CALL_ON_DONE_SEND, 0);
lock(call);
if (call->last_send_contains & (1 << GRPC_IOREQ_SEND_INITIAL_METADATA)) {
finish_ioreq_op(call, GRPC_IOREQ_SEND_INITIAL_METADATA, success);
@@ -859,6 +860,7 @@ static void call_on_done_send(grpc_exec_ctx *exec_ctx, void *pc, int success) {
call->sending = 0;
unlock(exec_ctx, call);
GRPC_CALL_INTERNAL_UNREF(exec_ctx, call, "sending");
+ GRPC_TIMER_END(GRPC_PTAG_CALL_ON_DONE_SEND, 0);
}
static void finish_message(grpc_call *call) {
diff --git a/src/core/transport/chttp2_transport.c b/src/core/transport/chttp2_transport.c
index b4508b42bcda2d57bea2fcddbc98ce8c77e59227..0a1b3a8176b6ba28fe033a3972bb0e7a60e9f816 100644
--- a/src/core/transport/chttp2_transport.c
+++ b/src/core/transport/chttp2_transport.c
@@ -546,6 +546,8 @@ void grpc_chttp2_terminate_writing(grpc_exec_ctx *exec_ctx,
grpc_chttp2_transport_writing *transport_writing = transport_writing_ptr;
grpc_chttp2_transport *t = TRANSPORT_FROM_WRITING(transport_writing);
+ GRPC_TIMER_BEGIN(GRPC_PTAG_HTTP2_TERMINATE_WRITING, 0);
+
lock(t);
allow_endpoint_shutdown_locked(exec_ctx, t);
@@ -567,12 +569,16 @@ void grpc_chttp2_terminate_writing(grpc_exec_ctx *exec_ctx,
unlock(exec_ctx, t);
UNREF_TRANSPORT(exec_ctx, t, "writing");
+
+ GRPC_TIMER_END(GRPC_PTAG_HTTP2_TERMINATE_WRITING, 0);
}
static void writing_action(grpc_exec_ctx *exec_ctx, void *gt,
int iomgr_success_ignored) {
grpc_chttp2_transport *t = gt;
+ GRPC_TIMER_BEGIN(GRPC_PTAG_HTTP2_WRITING_ACTION, 0);
grpc_chttp2_perform_writes(exec_ctx, &t->writing, t->ep);
+ GRPC_TIMER_END(GRPC_PTAG_HTTP2_WRITING_ACTION, 0);
}
void grpc_chttp2_add_incoming_goaway(