diff --git a/src/core/ext/census/grpc_filter.c b/src/core/ext/census/grpc_filter.c
index 72e4e5427ebdc5d524207af35a6b938bac03a269..f51d850e013b88df231525c429a9fdaaf6319948 100644
--- a/src/core/ext/census/grpc_filter.c
+++ b/src/core/ext/census/grpc_filter.c
@@ -45,6 +45,7 @@
#include "src/core/ext/census/census_interface.h"
#include "src/core/ext/census/census_rpc_stats.h"
#include "src/core/lib/channel/channel_stack.h"
+#include "src/core/lib/profiling/timers.h"
#include "src/core/lib/transport/static_metadata.h"
typedef struct call_data {
@@ -92,6 +93,7 @@ static void client_start_transport_op(grpc_exec_ctx *exec_ctx,
static void server_on_done_recv(grpc_exec_ctx *exec_ctx, void *ptr,
grpc_error *error) {
+ GPR_TIMER_BEGIN("census-server:server_on_done_recv", 0);
grpc_call_element *elem = ptr;
call_data *calld = elem->call_data;
channel_data *chand = elem->channel_data;
@@ -99,6 +101,7 @@ static void server_on_done_recv(grpc_exec_ctx *exec_ctx, void *ptr,
extract_and_annotate_method_tag(calld->recv_initial_metadata, calld, chand);
}
calld->on_done_recv->cb(exec_ctx, calld->on_done_recv->cb_arg, error);
+ GPR_TIMER_END("census-server:server_on_done_recv", 0);
}
static void server_mutate_op(grpc_call_element *elem,
diff --git a/src/core/ext/client_config/client_channel.c b/src/core/ext/client_config/client_channel.c
index 1d5a7d52246c9c41184dd31488fd7d1637b5ea22..a096435c984d93cc2b556122d0007a543c04531b 100644
--- a/src/core/ext/client_config/client_channel.c
+++ b/src/core/ext/client_config/client_channel.c
@@ -367,6 +367,8 @@ static int cc_pick_subchannel(grpc_exec_ctx *exec_ctx, void *elemp,
uint32_t initial_metadata_flags,
grpc_connected_subchannel **connected_subchannel,
grpc_closure *on_ready) {
+ GPR_TIMER_BEGIN("cc_pick_subchannel", 0);
+
grpc_call_element *elem = elemp;
channel_data *chand = elem->channel_data;
call_data *calld = elem->call_data;
@@ -391,6 +393,7 @@ static int cc_pick_subchannel(grpc_exec_ctx *exec_ctx, void *elemp,
}
}
gpr_mu_unlock(&chand->mu_config);
+ GPR_TIMER_END("cc_pick_subchannel", 0);
return 1;
}
if (chand->lb_policy != NULL) {
@@ -402,6 +405,7 @@ static int cc_pick_subchannel(grpc_exec_ctx *exec_ctx, void *elemp,
initial_metadata, initial_metadata_flags,
connected_subchannel, on_ready);
GRPC_LB_POLICY_UNREF(exec_ctx, lb_policy, "cc_pick_subchannel");
+ GPR_TIMER_END("cc_pick_subchannel", 0);
return r;
}
if (chand->resolver != NULL && !chand->started_resolving) {
@@ -426,6 +430,8 @@ static int cc_pick_subchannel(grpc_exec_ctx *exec_ctx, void *elemp,
NULL);
}
gpr_mu_unlock(&chand->mu_config);
+
+ GPR_TIMER_END("cc_pick_subchannel", 0);
return 0;
}
diff --git a/src/core/ext/client_config/subchannel.c b/src/core/ext/client_config/subchannel.c
index 468067ea57c0c1c854635cb92378ad0f47531ec1..d089cd4399e8fc933abf63b2d0dd25d5e4b1439c 100644
--- a/src/core/ext/client_config/subchannel.c
+++ b/src/core/ext/client_config/subchannel.c
@@ -690,9 +690,11 @@ char *grpc_subchannel_call_get_peer(grpc_exec_ctx *exec_ctx,
void grpc_subchannel_call_process_op(grpc_exec_ctx *exec_ctx,
grpc_subchannel_call *call,
grpc_transport_stream_op *op) {
+ GPR_TIMER_BEGIN("grpc_subchannel_call_process_op", 0);
grpc_call_stack *call_stack = SUBCHANNEL_CALL_TO_CALL_STACK(call);
grpc_call_element *top_elem = grpc_call_stack_element(call_stack, 0);
top_elem->filter->start_transport_stream_op(exec_ctx, top_elem, op);
+ GPR_TIMER_END("grpc_subchannel_call_process_op", 0);
}
grpc_connected_subchannel *grpc_subchannel_get_connected_subchannel(
diff --git a/src/core/ext/transport/chttp2/transport/chttp2_transport.c b/src/core/ext/transport/chttp2/transport/chttp2_transport.c
index 9c125566d480d9b6b3092053cb17ef1a79196229..b710bbcb3cbd33882fb24e85431028fe2fb3701f 100644
--- a/src/core/ext/transport/chttp2/transport/chttp2_transport.c
+++ b/src/core/ext/transport/chttp2/transport/chttp2_transport.c
@@ -642,6 +642,8 @@ static void finish_global_actions(grpc_exec_ctx *exec_ctx,
grpc_chttp2_executor_action_header *hdr;
grpc_chttp2_executor_action_header *next;
+ GPR_TIMER_BEGIN("finish_global_actions", 0);
+
for (;;) {
if (!t->executor.writing_active && !t->closed &&
grpc_chttp2_unlocking_check_writes(exec_ctx, &t->global, &t->writing)) {
@@ -659,7 +661,9 @@ static void finish_global_actions(grpc_exec_ctx *exec_ctx,
NULL;
gpr_mu_unlock(&t->executor.mu);
while (hdr != NULL) {
+ GPR_TIMER_BEGIN("chttp2:locked_action", 0);
hdr->action(exec_ctx, t, hdr->stream, hdr->arg);
+ GPR_TIMER_END("chttp2:locked_action", 0);
next = hdr->next;
gpr_free(hdr);
UNREF_TRANSPORT(exec_ctx, t, "pending_action");
@@ -672,6 +676,8 @@ static void finish_global_actions(grpc_exec_ctx *exec_ctx,
gpr_mu_unlock(&t->executor.mu);
break;
}
+
+ GPR_TIMER_END("finish_global_actions", 0);
}
void grpc_chttp2_run_with_global_lock(grpc_exec_ctx *exec_ctx,
@@ -681,6 +687,8 @@ void grpc_chttp2_run_with_global_lock(grpc_exec_ctx *exec_ctx,
void *arg, size_t sizeof_arg) {
grpc_chttp2_executor_action_header *hdr;
+ GPR_TIMER_BEGIN("grpc_chttp2_run_with_global_lock", 0);
+
REF_TRANSPORT(t, "run_global");
gpr_mu_lock(&t->executor.mu);
@@ -689,7 +697,9 @@ void grpc_chttp2_run_with_global_lock(grpc_exec_ctx *exec_ctx,
t->executor.global_active = 1;
gpr_mu_unlock(&t->executor.mu);
+ GPR_TIMER_BEGIN("chttp2:locked_action", 0);
action(exec_ctx, t, optional_stream, arg);
+ GPR_TIMER_END("chttp2:locked_action", 0);
finish_global_actions(exec_ctx, t);
} else {
@@ -726,6 +736,8 @@ void grpc_chttp2_run_with_global_lock(grpc_exec_ctx *exec_ctx,
}
UNREF_TRANSPORT(exec_ctx, t, "run_global");
+
+ GPR_TIMER_END("grpc_chttp2_run_with_global_lock", 0);
}
/*******************************************************************************