aboutsummaryrefslogtreecommitdiffhomepage
path: root/src/core/lib/iomgr
diff options
context:
space:
mode:
Diffstat (limited to 'src/core/lib/iomgr')
-rw-r--r--src/core/lib/iomgr/call_combiner.cc6
-rw-r--r--src/core/lib/iomgr/closure.h6
-rw-r--r--src/core/lib/iomgr/combiner.cc22
-rw-r--r--src/core/lib/iomgr/error.cc25
-rw-r--r--src/core/lib/iomgr/ev_epoll1_linux.cc67
-rw-r--r--src/core/lib/iomgr/ev_epollex_linux.cc37
-rw-r--r--src/core/lib/iomgr/ev_epollsig_linux.cc21
-rw-r--r--src/core/lib/iomgr/ev_poll_posix.cc13
-rw-r--r--src/core/lib/iomgr/ev_posix.cc45
-rw-r--r--src/core/lib/iomgr/exec_ctx.cc3
-rw-r--r--src/core/lib/iomgr/tcp_posix.cc17
-rw-r--r--src/core/lib/iomgr/wakeup_fd_eventfd.cc3
12 files changed, 141 insertions, 124 deletions
diff --git a/src/core/lib/iomgr/call_combiner.cc b/src/core/lib/iomgr/call_combiner.cc
index a9f48fb3c2..0e4c9cb3b3 100644
--- a/src/core/lib/iomgr/call_combiner.cc
+++ b/src/core/lib/iomgr/call_combiner.cc
@@ -60,7 +60,7 @@ void grpc_call_combiner_start(grpc_call_combiner* call_combiner,
grpc_closure* closure,
grpc_error* error DEBUG_ARGS,
const char* reason) {
- GPR_TIMER_BEGIN("call_combiner_start", 0);
+ GPR_TIMER_SCOPE("call_combiner_start", 0);
if (grpc_call_combiner_trace.enabled()) {
gpr_log(GPR_DEBUG,
"==> grpc_call_combiner_start() [%p] closure=%p [" DEBUG_FMT_STR
@@ -92,12 +92,11 @@ void grpc_call_combiner_start(grpc_call_combiner* call_combiner,
closure->error_data.error = error;
gpr_mpscq_push(&call_combiner->queue, (gpr_mpscq_node*)closure);
}
- GPR_TIMER_END("call_combiner_start", 0);
}
void grpc_call_combiner_stop(grpc_call_combiner* call_combiner DEBUG_ARGS,
const char* reason) {
- GPR_TIMER_BEGIN("call_combiner_stop", 0);
+ GPR_TIMER_SCOPE("call_combiner_stop", 0);
if (grpc_call_combiner_trace.enabled()) {
gpr_log(GPR_DEBUG,
"==> grpc_call_combiner_stop() [%p] [" DEBUG_FMT_STR "%s]",
@@ -136,7 +135,6 @@ void grpc_call_combiner_stop(grpc_call_combiner* call_combiner DEBUG_ARGS,
} else if (grpc_call_combiner_trace.enabled()) {
gpr_log(GPR_DEBUG, " queue empty");
}
- GPR_TIMER_END("call_combiner_stop", 0);
}
void grpc_call_combiner_set_notify_on_cancel(grpc_call_combiner* call_combiner,
diff --git a/src/core/lib/iomgr/closure.h b/src/core/lib/iomgr/closure.h
index 249fca6cd6..2bf2578c63 100644
--- a/src/core/lib/iomgr/closure.h
+++ b/src/core/lib/iomgr/closure.h
@@ -247,7 +247,7 @@ inline void grpc_closure_run(const char* file, int line, grpc_closure* c,
#else
inline void grpc_closure_run(grpc_closure* c, grpc_error* error) {
#endif
- GPR_TIMER_BEGIN("grpc_closure_run", 0);
+ GPR_TIMER_SCOPE("grpc_closure_run", 0);
if (c != nullptr) {
#ifndef NDEBUG
c->file_initiated = file;
@@ -259,7 +259,6 @@ inline void grpc_closure_run(grpc_closure* c, grpc_error* error) {
} else {
GRPC_ERROR_UNREF(error);
}
- GPR_TIMER_END("grpc_closure_run", 0);
}
/** Run a closure directly. Caller ensures that no locks are being held above.
@@ -278,7 +277,7 @@ inline void grpc_closure_sched(const char* file, int line, grpc_closure* c,
#else
inline void grpc_closure_sched(grpc_closure* c, grpc_error* error) {
#endif
- GPR_TIMER_BEGIN("grpc_closure_sched", 0);
+ GPR_TIMER_SCOPE("grpc_closure_sched", 0);
if (c != nullptr) {
#ifndef NDEBUG
if (c->scheduled) {
@@ -299,7 +298,6 @@ inline void grpc_closure_sched(grpc_closure* c, grpc_error* error) {
} else {
GRPC_ERROR_UNREF(error);
}
- GPR_TIMER_END("grpc_closure_sched", 0);
}
/** Schedule a closure to be run. Does not need to be run from a safe point. */
diff --git a/src/core/lib/iomgr/combiner.cc b/src/core/lib/iomgr/combiner.cc
index e4d7a6abd8..2965d807c1 100644
--- a/src/core/lib/iomgr/combiner.cc
+++ b/src/core/lib/iomgr/combiner.cc
@@ -153,8 +153,8 @@ static void push_first_on_exec_ctx(grpc_combiner* lock) {
offsetof(grpc_combiner, scheduler_name)))
static void combiner_exec(grpc_closure* cl, grpc_error* error) {
+ GPR_TIMER_SCOPE("combiner.execute", 0);
GRPC_STATS_INC_COMBINER_LOCKS_SCHEDULED_ITEMS();
- GPR_TIMER_BEGIN("combiner.execute", 0);
grpc_combiner* lock = COMBINER_FROM_CLOSURE_SCHEDULER(cl, scheduler);
gpr_atm last = gpr_atm_full_fetch_add(&lock->state, STATE_ELEM_COUNT_LOW_BIT);
GRPC_COMBINER_TRACE(gpr_log(GPR_DEBUG,
@@ -181,7 +181,6 @@ static void combiner_exec(grpc_closure* cl, grpc_error* error) {
assert(cl->cb);
cl->error_data.error = error;
gpr_mpscq_push(&lock->queue, &cl->next_data.atm_next);
- GPR_TIMER_END("combiner.execute", 0);
}
static void move_next() {
@@ -207,11 +206,10 @@ static void queue_offload(grpc_combiner* lock) {
}
bool grpc_combiner_continue_exec_ctx() {
- GPR_TIMER_BEGIN("combiner.continue_exec_ctx", 0);
+ GPR_TIMER_SCOPE("combiner.continue_exec_ctx", 0);
grpc_combiner* lock =
grpc_core::ExecCtx::Get()->combiner_data()->active_combiner;
if (lock == nullptr) {
- GPR_TIMER_END("combiner.continue_exec_ctx", 0);
return false;
}
@@ -233,7 +231,6 @@ bool grpc_combiner_continue_exec_ctx() {
// this execution context wants to move on: schedule remaining work to be
// picked up on the executor
queue_offload(lock);
- GPR_TIMER_END("combiner.continue_exec_ctx", 0);
return true;
}
@@ -249,10 +246,9 @@ bool grpc_combiner_continue_exec_ctx() {
// go off and do something else for a while (and come back later)
GPR_TIMER_MARK("delay_busy", 0);
queue_offload(lock);
- GPR_TIMER_END("combiner.continue_exec_ctx", 0);
return true;
}
- GPR_TIMER_BEGIN("combiner.exec1", 0);
+ GPR_TIMER_SCOPE("combiner.exec1", 0);
grpc_closure* cl = (grpc_closure*)n;
grpc_error* cl_err = cl->error_data.error;
#ifndef NDEBUG
@@ -260,14 +256,13 @@ bool grpc_combiner_continue_exec_ctx() {
#endif
cl->cb(cl->cb_arg, cl_err);
GRPC_ERROR_UNREF(cl_err);
- GPR_TIMER_END("combiner.exec1", 0);
} else {
grpc_closure* c = lock->final_list.head;
GPR_ASSERT(c != nullptr);
grpc_closure_list_init(&lock->final_list);
int loops = 0;
while (c != nullptr) {
- GPR_TIMER_BEGIN("combiner.exec_1final", 0);
+ GPR_TIMER_SCOPE("combiner.exec_1final", 0);
GRPC_COMBINER_TRACE(
gpr_log(GPR_DEBUG, "C:%p execute_final[%d] c=%p", lock, loops, c));
grpc_closure* next = c->next_data.next;
@@ -278,7 +273,6 @@ bool grpc_combiner_continue_exec_ctx() {
c->cb(c->cb_arg, error);
GRPC_ERROR_UNREF(error);
c = next;
- GPR_TIMER_END("combiner.exec_1final", 0);
}
}
@@ -308,41 +302,36 @@ bool grpc_combiner_continue_exec_ctx() {
break;
case OLD_STATE_WAS(false, 1):
// had one count, one unorphaned --> unlocked unorphaned
- GPR_TIMER_END("combiner.continue_exec_ctx", 0);
return true;
case OLD_STATE_WAS(true, 1):
// and one count, one orphaned --> unlocked and orphaned
really_destroy(lock);
- GPR_TIMER_END("combiner.continue_exec_ctx", 0);
return true;
case OLD_STATE_WAS(false, 0):
case OLD_STATE_WAS(true, 0):
// these values are illegal - representing an already unlocked or
// deleted lock
- GPR_TIMER_END("combiner.continue_exec_ctx", 0);
GPR_UNREACHABLE_CODE(return true);
}
push_first_on_exec_ctx(lock);
- GPR_TIMER_END("combiner.continue_exec_ctx", 0);
return true;
}
static void enqueue_finally(void* closure, grpc_error* error);
static void combiner_finally_exec(grpc_closure* closure, grpc_error* error) {
+ GPR_TIMER_SCOPE("combiner.execute_finally", 0);
GRPC_STATS_INC_COMBINER_LOCKS_SCHEDULED_FINAL_ITEMS();
grpc_combiner* lock =
COMBINER_FROM_CLOSURE_SCHEDULER(closure, finally_scheduler);
GRPC_COMBINER_TRACE(gpr_log(
GPR_DEBUG, "C:%p grpc_combiner_execute_finally c=%p; ac=%p", lock,
closure, grpc_core::ExecCtx::Get()->combiner_data()->active_combiner));
- GPR_TIMER_BEGIN("combiner.execute_finally", 0);
if (grpc_core::ExecCtx::Get()->combiner_data()->active_combiner != lock) {
GPR_TIMER_MARK("slowpath", 0);
GRPC_CLOSURE_SCHED(GRPC_CLOSURE_CREATE(enqueue_finally, closure,
grpc_combiner_scheduler(lock)),
error);
- GPR_TIMER_END("combiner.execute_finally", 0);
return;
}
@@ -350,7 +339,6 @@ static void combiner_finally_exec(grpc_closure* closure, grpc_error* error) {
gpr_atm_full_fetch_add(&lock->state, STATE_ELEM_COUNT_LOW_BIT);
}
grpc_closure_list_append(&lock->final_list, closure, error);
- GPR_TIMER_END("combiner.execute_finally", 0);
}
static void enqueue_finally(void* closure, grpc_error* error) {
diff --git a/src/core/lib/iomgr/error.cc b/src/core/lib/iomgr/error.cc
index 67c3caf5ee..0e27ad427c 100644
--- a/src/core/lib/iomgr/error.cc
+++ b/src/core/lib/iomgr/error.cc
@@ -314,7 +314,7 @@ static void internal_add_error(grpc_error** err, grpc_error* new_err) {
grpc_error* grpc_error_create(const char* file, int line, grpc_slice desc,
grpc_error** referencing,
size_t num_referencing) {
- GPR_TIMER_BEGIN("grpc_error_create", 0);
+ GPR_TIMER_SCOPE("grpc_error_create", 0);
uint8_t initial_arena_capacity = (uint8_t)(
DEFAULT_ERROR_CAPACITY +
(uint8_t)(num_referencing * SLOTS_PER_LINKED_ERROR) + SURPLUS_CAPACITY);
@@ -355,7 +355,6 @@ grpc_error* grpc_error_create(const char* file, int line, grpc_slice desc,
gpr_atm_no_barrier_store(&err->atomics.error_string, 0);
gpr_ref_init(&err->atomics.refs, 1);
- GPR_TIMER_END("grpc_error_create", 0);
return err;
}
@@ -378,7 +377,7 @@ static void ref_errs(grpc_error* err) {
}
static grpc_error* copy_error_and_unref(grpc_error* in) {
- GPR_TIMER_BEGIN("copy_error_and_unref", 0);
+ GPR_TIMER_SCOPE("copy_error_and_unref", 0);
grpc_error* out;
if (grpc_error_is_special(in)) {
out = GRPC_ERROR_CREATE_FROM_STATIC_STRING("unknown");
@@ -422,16 +421,14 @@ static grpc_error* copy_error_and_unref(grpc_error* in) {
ref_errs(out);
GRPC_ERROR_UNREF(in);
}
- GPR_TIMER_END("copy_error_and_unref", 0);
return out;
}
grpc_error* grpc_error_set_int(grpc_error* src, grpc_error_ints which,
intptr_t value) {
- GPR_TIMER_BEGIN("grpc_error_set_int", 0);
+ GPR_TIMER_SCOPE("grpc_error_set_int", 0);
grpc_error* new_err = copy_error_and_unref(src);
internal_set_int(&new_err, which, value);
- GPR_TIMER_END("grpc_error_set_int", 0);
return new_err;
}
@@ -447,36 +444,31 @@ static special_error_status_map error_status_map[] = {
};
bool grpc_error_get_int(grpc_error* err, grpc_error_ints which, intptr_t* p) {
- GPR_TIMER_BEGIN("grpc_error_get_int", 0);
+ GPR_TIMER_SCOPE("grpc_error_get_int", 0);
if (grpc_error_is_special(err)) {
if (which == GRPC_ERROR_INT_GRPC_STATUS) {
for (size_t i = 0; i < GPR_ARRAY_SIZE(error_status_map); i++) {
if (error_status_map[i].error == err) {
if (p != nullptr) *p = error_status_map[i].code;
- GPR_TIMER_END("grpc_error_get_int", 0);
return true;
}
}
}
- GPR_TIMER_END("grpc_error_get_int", 0);
return false;
}
uint8_t slot = err->ints[which];
if (slot != UINT8_MAX) {
if (p != nullptr) *p = err->arena[slot];
- GPR_TIMER_END("grpc_error_get_int", 0);
return true;
}
- GPR_TIMER_END("grpc_error_get_int", 0);
return false;
}
grpc_error* grpc_error_set_str(grpc_error* src, grpc_error_strs which,
grpc_slice str) {
- GPR_TIMER_BEGIN("grpc_error_set_str", 0);
+ GPR_TIMER_SCOPE("grpc_error_set_str", 0);
grpc_error* new_err = copy_error_and_unref(src);
internal_set_str(&new_err, which, str);
- GPR_TIMER_END("grpc_error_set_str", 0);
return new_err;
}
@@ -503,10 +495,9 @@ bool grpc_error_get_str(grpc_error* err, grpc_error_strs which,
}
grpc_error* grpc_error_add_child(grpc_error* src, grpc_error* child) {
- GPR_TIMER_BEGIN("grpc_error_add_child", 0);
+ GPR_TIMER_SCOPE("grpc_error_add_child", 0);
grpc_error* new_err = copy_error_and_unref(src);
internal_add_error(&new_err, child);
- GPR_TIMER_END("grpc_error_add_child", 0);
return new_err;
}
@@ -722,14 +713,13 @@ static char* finish_kvs(kv_pairs* kvs) {
}
const char* grpc_error_string(grpc_error* err) {
- GPR_TIMER_BEGIN("grpc_error_string", 0);
+ GPR_TIMER_SCOPE("grpc_error_string", 0);
if (err == GRPC_ERROR_NONE) return no_error_string;
if (err == GRPC_ERROR_OOM) return oom_error_string;
if (err == GRPC_ERROR_CANCELLED) return cancelled_error_string;
void* p = (void*)gpr_atm_acq_load(&err->atomics.error_string);
if (p != nullptr) {
- GPR_TIMER_END("grpc_error_string", 0);
return (const char*)p;
}
@@ -752,7 +742,6 @@ const char* grpc_error_string(grpc_error* err) {
out = (char*)gpr_atm_acq_load(&err->atomics.error_string);
}
- GPR_TIMER_END("grpc_error_string", 0);
return out;
}
diff --git a/src/core/lib/iomgr/ev_epoll1_linux.cc b/src/core/lib/iomgr/ev_epoll1_linux.cc
index 42d7cdd348..1ef70d2f80 100644
--- a/src/core/lib/iomgr/ev_epoll1_linux.cc
+++ b/src/core/lib/iomgr/ev_epoll1_linux.cc
@@ -519,7 +519,7 @@ static void pollset_destroy(grpc_pollset* pollset) {
}
static grpc_error* pollset_kick_all(grpc_pollset* pollset) {
- GPR_TIMER_BEGIN("pollset_kick_all", 0);
+ GPR_TIMER_SCOPE("pollset_kick_all", 0);
grpc_error* error = GRPC_ERROR_NONE;
if (pollset->root_worker != nullptr) {
grpc_pollset_worker* worker = pollset->root_worker;
@@ -549,7 +549,6 @@ static grpc_error* pollset_kick_all(grpc_pollset* pollset) {
}
// TODO: sreek. Check if we need to set 'kicked_without_poller' to true here
// in the else case
- GPR_TIMER_END("pollset_kick_all", 0);
return error;
}
@@ -563,14 +562,13 @@ static void pollset_maybe_finish_shutdown(grpc_pollset* pollset) {
}
static void pollset_shutdown(grpc_pollset* pollset, grpc_closure* closure) {
- GPR_TIMER_BEGIN("pollset_shutdown", 0);
+ GPR_TIMER_SCOPE("pollset_shutdown", 0);
GPR_ASSERT(pollset->shutdown_closure == nullptr);
GPR_ASSERT(!pollset->shutting_down);
pollset->shutdown_closure = closure;
pollset->shutting_down = true;
GRPC_LOG_IF_ERROR("pollset_shutdown", pollset_kick_all(pollset));
pollset_maybe_finish_shutdown(pollset);
- GPR_TIMER_END("pollset_shutdown", 0);
}
static int poll_deadline_to_millis_timeout(grpc_millis millis) {
@@ -594,10 +592,10 @@ static int poll_deadline_to_millis_timeout(grpc_millis millis) {
called by g_active_poller thread. So there is no need for synchronization
when accessing fields in g_epoll_set */
static grpc_error* process_epoll_events(grpc_pollset* pollset) {
+ GPR_TIMER_SCOPE("process_epoll_events", 0);
+
static const char* err_desc = "process_events";
grpc_error* error = GRPC_ERROR_NONE;
-
- GPR_TIMER_BEGIN("process_epoll_events", 0);
long num_events = gpr_atm_acq_load(&g_epoll_set.num_events);
long cursor = gpr_atm_acq_load(&g_epoll_set.cursor);
for (int idx = 0;
@@ -626,7 +624,6 @@ static grpc_error* process_epoll_events(grpc_pollset* pollset) {
}
}
gpr_atm_rel_store(&g_epoll_set.cursor, cursor);
- GPR_TIMER_END("process_epoll_events", 0);
return error;
}
@@ -638,7 +635,7 @@ static grpc_error* process_epoll_events(grpc_pollset* pollset) {
(i.e the designated poller thread) will be calling this function. So there is
no need for any synchronization when accesing fields in g_epoll_set */
static grpc_error* do_epoll_wait(grpc_pollset* ps, grpc_millis deadline) {
- GPR_TIMER_BEGIN("do_epoll_wait", 0);
+ GPR_TIMER_SCOPE("do_epoll_wait", 0);
int r;
int timeout = poll_deadline_to_millis_timeout(deadline);
@@ -665,14 +662,13 @@ static grpc_error* do_epoll_wait(grpc_pollset* ps, grpc_millis deadline) {
gpr_atm_rel_store(&g_epoll_set.num_events, r);
gpr_atm_rel_store(&g_epoll_set.cursor, 0);
- GPR_TIMER_END("do_epoll_wait", 0);
return GRPC_ERROR_NONE;
}
static bool begin_worker(grpc_pollset* pollset, grpc_pollset_worker* worker,
grpc_pollset_worker** worker_hdl,
grpc_millis deadline) {
- GPR_TIMER_BEGIN("begin_worker", 0);
+ GPR_TIMER_SCOPE("begin_worker", 0);
if (worker_hdl != nullptr) *worker_hdl = worker;
worker->initialized_cv = false;
SET_KICK_STATE(worker, UNKICKED);
@@ -680,7 +676,7 @@ static bool begin_worker(grpc_pollset* pollset, grpc_pollset_worker* worker,
pollset->begin_refs++;
if (grpc_polling_trace.enabled()) {
- gpr_log(GPR_ERROR, "PS:%p BEGIN_STARTS:%p", pollset, worker);
+ gpr_log(GPR_DEBUG, "PS:%p BEGIN_STARTS:%p", pollset, worker);
}
if (pollset->seen_inactive) {
@@ -699,7 +695,7 @@ static bool begin_worker(grpc_pollset* pollset, grpc_pollset_worker* worker,
gpr_mu_lock(&neighborhood->mu);
gpr_mu_lock(&pollset->mu);
if (grpc_polling_trace.enabled()) {
- gpr_log(GPR_ERROR, "PS:%p BEGIN_REORG:%p kick_state=%s is_reassigning=%d",
+ gpr_log(GPR_DEBUG, "PS:%p BEGIN_REORG:%p kick_state=%s is_reassigning=%d",
pollset, worker, kick_state_string(worker->state),
is_reassigning);
}
@@ -751,7 +747,7 @@ static bool begin_worker(grpc_pollset* pollset, grpc_pollset_worker* worker,
gpr_cv_init(&worker->cv);
while (worker->state == UNKICKED && !pollset->shutting_down) {
if (grpc_polling_trace.enabled()) {
- gpr_log(GPR_ERROR, "PS:%p BEGIN_WAIT:%p kick_state=%s shutdown=%d",
+ gpr_log(GPR_DEBUG, "PS:%p BEGIN_WAIT:%p kick_state=%s shutdown=%d",
pollset, worker, kick_state_string(worker->state),
pollset->shutting_down);
}
@@ -768,7 +764,7 @@ static bool begin_worker(grpc_pollset* pollset, grpc_pollset_worker* worker,
}
if (grpc_polling_trace.enabled()) {
- gpr_log(GPR_ERROR,
+ gpr_log(GPR_DEBUG,
"PS:%p BEGIN_DONE:%p kick_state=%s shutdown=%d "
"kicked_without_poller: %d",
pollset, worker, kick_state_string(worker->state),
@@ -786,17 +782,15 @@ static bool begin_worker(grpc_pollset* pollset, grpc_pollset_worker* worker,
if (pollset->kicked_without_poller) {
pollset->kicked_without_poller = false;
- GPR_TIMER_END("begin_worker", 0);
return false;
}
- GPR_TIMER_END("begin_worker", 0);
return worker->state == DESIGNATED_POLLER && !pollset->shutting_down;
}
static bool check_neighborhood_for_available_poller(
pollset_neighborhood* neighborhood) {
- GPR_TIMER_BEGIN("check_neighborhood_for_available_poller", 0);
+ GPR_TIMER_SCOPE("check_neighborhood_for_available_poller", 0);
bool found_worker = false;
do {
grpc_pollset* inspect = neighborhood->active_root;
@@ -855,13 +849,12 @@ static bool check_neighborhood_for_available_poller(
}
gpr_mu_unlock(&inspect->mu);
} while (!found_worker);
- GPR_TIMER_END("check_neighborhood_for_available_poller", 0);
return found_worker;
}
static void end_worker(grpc_pollset* pollset, grpc_pollset_worker* worker,
grpc_pollset_worker** worker_hdl) {
- GPR_TIMER_BEGIN("end_worker", 0);
+ GPR_TIMER_SCOPE("end_worker", 0);
if (grpc_polling_trace.enabled()) {
gpr_log(GPR_DEBUG, "PS:%p END_WORKER:%p", pollset, worker);
}
@@ -931,7 +924,6 @@ static void end_worker(grpc_pollset* pollset, grpc_pollset_worker* worker,
pollset_maybe_finish_shutdown(pollset);
}
GPR_ASSERT(gpr_atm_no_barrier_load(&g_active_poller) != (gpr_atm)worker);
- GPR_TIMER_END("end_worker", 0);
}
/* pollset->po.mu lock must be held by the caller before calling this.
@@ -941,13 +933,12 @@ static void end_worker(grpc_pollset* pollset, grpc_pollset_worker* worker,
static grpc_error* pollset_work(grpc_pollset* ps,
grpc_pollset_worker** worker_hdl,
grpc_millis deadline) {
+ GPR_TIMER_SCOPE("pollset_work", 0);
grpc_pollset_worker worker;
grpc_error* error = GRPC_ERROR_NONE;
static const char* err_desc = "pollset_work";
- GPR_TIMER_BEGIN("pollset_work", 0);
if (ps->kicked_without_poller) {
ps->kicked_without_poller = false;
- GPR_TIMER_END("pollset_work", 0);
return GRPC_ERROR_NONE;
}
@@ -987,13 +978,12 @@ static grpc_error* pollset_work(grpc_pollset* ps,
end_worker(ps, &worker, worker_hdl);
gpr_tls_set(&g_current_thread_pollset, 0);
- GPR_TIMER_END("pollset_work", 0);
return error;
}
static grpc_error* pollset_kick(grpc_pollset* pollset,
grpc_pollset_worker* specific_worker) {
- GPR_TIMER_BEGIN("pollset_kick", 0);
+ GPR_TIMER_SCOPE("pollset_kick", 0);
GRPC_STATS_INC_POLLSET_KICK();
grpc_error* ret_err = GRPC_ERROR_NONE;
if (grpc_polling_trace.enabled()) {
@@ -1019,7 +1009,7 @@ static grpc_error* pollset_kick(grpc_pollset* pollset,
}
tmp = gpr_strvec_flatten(&log, nullptr);
gpr_strvec_destroy(&log);
- gpr_log(GPR_ERROR, "%s", tmp);
+ gpr_log(GPR_DEBUG, "%s", tmp);
gpr_free(tmp);
}
@@ -1030,7 +1020,7 @@ static grpc_error* pollset_kick(grpc_pollset* pollset,
GRPC_STATS_INC_POLLSET_KICKED_WITHOUT_POLLER();
pollset->kicked_without_poller = true;
if (grpc_polling_trace.enabled()) {
- gpr_log(GPR_ERROR, " .. kicked_without_poller");
+ gpr_log(GPR_DEBUG, " .. kicked_without_poller");
}
goto done;
}
@@ -1038,14 +1028,14 @@ static grpc_error* pollset_kick(grpc_pollset* pollset,
if (root_worker->state == KICKED) {
GRPC_STATS_INC_POLLSET_KICKED_AGAIN();
if (grpc_polling_trace.enabled()) {
- gpr_log(GPR_ERROR, " .. already kicked %p", root_worker);
+ gpr_log(GPR_DEBUG, " .. already kicked %p", root_worker);
}
SET_KICK_STATE(root_worker, KICKED);
goto done;
} else if (next_worker->state == KICKED) {
GRPC_STATS_INC_POLLSET_KICKED_AGAIN();
if (grpc_polling_trace.enabled()) {
- gpr_log(GPR_ERROR, " .. already kicked %p", next_worker);
+ gpr_log(GPR_DEBUG, " .. already kicked %p", next_worker);
}
SET_KICK_STATE(next_worker, KICKED);
goto done;
@@ -1056,7 +1046,7 @@ static grpc_error* pollset_kick(grpc_pollset* pollset,
&g_active_poller)) {
GRPC_STATS_INC_POLLSET_KICK_WAKEUP_FD();
if (grpc_polling_trace.enabled()) {
- gpr_log(GPR_ERROR, " .. kicked %p", root_worker);
+ gpr_log(GPR_DEBUG, " .. kicked %p", root_worker);
}
SET_KICK_STATE(root_worker, KICKED);
ret_err = grpc_wakeup_fd_wakeup(&global_wakeup_fd);
@@ -1064,7 +1054,7 @@ static grpc_error* pollset_kick(grpc_pollset* pollset,
} else if (next_worker->state == UNKICKED) {
GRPC_STATS_INC_POLLSET_KICK_WAKEUP_CV();
if (grpc_polling_trace.enabled()) {
- gpr_log(GPR_ERROR, " .. kicked %p", next_worker);
+ gpr_log(GPR_DEBUG, " .. kicked %p", next_worker);
}
GPR_ASSERT(next_worker->initialized_cv);
SET_KICK_STATE(next_worker, KICKED);
@@ -1074,7 +1064,7 @@ static grpc_error* pollset_kick(grpc_pollset* pollset,
if (root_worker->state != DESIGNATED_POLLER) {
if (grpc_polling_trace.enabled()) {
gpr_log(
- GPR_ERROR,
+ GPR_DEBUG,
" .. kicked root non-poller %p (initialized_cv=%d) (poller=%p)",
root_worker, root_worker->initialized_cv, next_worker);
}
@@ -1087,7 +1077,7 @@ static grpc_error* pollset_kick(grpc_pollset* pollset,
} else {
GRPC_STATS_INC_POLLSET_KICK_WAKEUP_FD();
if (grpc_polling_trace.enabled()) {
- gpr_log(GPR_ERROR, " .. non-root poller %p (root=%p)", next_worker,
+ gpr_log(GPR_DEBUG, " .. non-root poller %p (root=%p)", next_worker,
root_worker);
}
SET_KICK_STATE(next_worker, KICKED);
@@ -1103,7 +1093,7 @@ static grpc_error* pollset_kick(grpc_pollset* pollset,
} else {
GRPC_STATS_INC_POLLSET_KICK_OWN_THREAD();
if (grpc_polling_trace.enabled()) {
- gpr_log(GPR_ERROR, " .. kicked while waking up");
+ gpr_log(GPR_DEBUG, " .. kicked while waking up");
}
goto done;
}
@@ -1113,14 +1103,14 @@ static grpc_error* pollset_kick(grpc_pollset* pollset,
if (specific_worker->state == KICKED) {
if (grpc_polling_trace.enabled()) {
- gpr_log(GPR_ERROR, " .. specific worker already kicked");
+ gpr_log(GPR_DEBUG, " .. specific worker already kicked");
}
goto done;
} else if (gpr_tls_get(&g_current_thread_worker) ==
(intptr_t)specific_worker) {
GRPC_STATS_INC_POLLSET_KICK_OWN_THREAD();
if (grpc_polling_trace.enabled()) {
- gpr_log(GPR_ERROR, " .. mark %p kicked", specific_worker);
+ gpr_log(GPR_DEBUG, " .. mark %p kicked", specific_worker);
}
SET_KICK_STATE(specific_worker, KICKED);
goto done;
@@ -1128,7 +1118,7 @@ static grpc_error* pollset_kick(grpc_pollset* pollset,
(grpc_pollset_worker*)gpr_atm_no_barrier_load(&g_active_poller)) {
GRPC_STATS_INC_POLLSET_KICK_WAKEUP_FD();
if (grpc_polling_trace.enabled()) {
- gpr_log(GPR_ERROR, " .. kick active poller");
+ gpr_log(GPR_DEBUG, " .. kick active poller");
}
SET_KICK_STATE(specific_worker, KICKED);
ret_err = grpc_wakeup_fd_wakeup(&global_wakeup_fd);
@@ -1136,7 +1126,7 @@ static grpc_error* pollset_kick(grpc_pollset* pollset,
} else if (specific_worker->initialized_cv) {
GRPC_STATS_INC_POLLSET_KICK_WAKEUP_CV();
if (grpc_polling_trace.enabled()) {
- gpr_log(GPR_ERROR, " .. kick waiting worker");
+ gpr_log(GPR_DEBUG, " .. kick waiting worker");
}
SET_KICK_STATE(specific_worker, KICKED);
gpr_cv_signal(&specific_worker->cv);
@@ -1144,13 +1134,12 @@ static grpc_error* pollset_kick(grpc_pollset* pollset,
} else {
GRPC_STATS_INC_POLLSET_KICKED_AGAIN();
if (grpc_polling_trace.enabled()) {
- gpr_log(GPR_ERROR, " .. kick non-waiting worker");
+ gpr_log(GPR_DEBUG, " .. kick non-waiting worker");
}
SET_KICK_STATE(specific_worker, KICKED);
goto done;
}
done:
- GPR_TIMER_END("pollset_kick", 0);
return ret_err;
}
diff --git a/src/core/lib/iomgr/ev_epollex_linux.cc b/src/core/lib/iomgr/ev_epollex_linux.cc
index 416e8384b4..178ebd8977 100644
--- a/src/core/lib/iomgr/ev_epollex_linux.cc
+++ b/src/core/lib/iomgr/ev_epollex_linux.cc
@@ -199,6 +199,7 @@ struct grpc_pollset {
pollable* active_pollable;
bool kicked_without_poller;
grpc_closure* shutdown_closure;
+ bool already_shutdown;
grpc_pollset_worker* root_worker;
int containing_pollset_set_count;
};
@@ -560,8 +561,10 @@ static void pollset_maybe_finish_shutdown(grpc_pollset* pollset) {
}
if (pollset->shutdown_closure != nullptr && pollset->root_worker == nullptr &&
pollset->containing_pollset_set_count == 0) {
+ GPR_TIMER_MARK("pollset_finish_shutdown", 0);
GRPC_CLOSURE_SCHED(pollset->shutdown_closure, GRPC_ERROR_NONE);
pollset->shutdown_closure = nullptr;
+ pollset->already_shutdown = true;
}
}
@@ -569,6 +572,7 @@ static void pollset_maybe_finish_shutdown(grpc_pollset* pollset) {
* pollset->active_pollable->mu & specific_worker->pollable_obj->mu must not be
* held */
static grpc_error* kick_one_worker(grpc_pollset_worker* specific_worker) {
+ GPR_TIMER_SCOPE("kick_one_worker", 0);
pollable* p = specific_worker->pollable_obj;
grpc_core::mu_guard lock(&p->mu);
GPR_ASSERT(specific_worker != nullptr);
@@ -612,6 +616,7 @@ static grpc_error* kick_one_worker(grpc_pollset_worker* specific_worker) {
static grpc_error* pollset_kick(grpc_pollset* pollset,
grpc_pollset_worker* specific_worker) {
+ GPR_TIMER_SCOPE("pollset_kick", 0);
GRPC_STATS_INC_POLLSET_KICK();
if (grpc_polling_trace.enabled()) {
gpr_log(GPR_DEBUG,
@@ -661,6 +666,7 @@ static grpc_error* pollset_kick(grpc_pollset* pollset,
}
static grpc_error* pollset_kick_all(grpc_pollset* pollset) {
+ GPR_TIMER_SCOPE("pollset_kick_all", 0);
grpc_error* error = GRPC_ERROR_NONE;
const char* err_desc = "pollset_kick_all";
grpc_pollset_worker* w = pollset->root_worker;
@@ -677,6 +683,11 @@ static grpc_error* pollset_kick_all(grpc_pollset* pollset) {
static void pollset_init(grpc_pollset* pollset, gpr_mu** mu) {
gpr_mu_init(&pollset->mu);
pollset->active_pollable = POLLABLE_REF(g_empty_pollable, "pollset");
+ pollset->kicked_without_poller = false;
+ pollset->shutdown_closure = nullptr;
+ pollset->already_shutdown = false;
+ pollset->root_worker = nullptr;
+ pollset->containing_pollset_set_count = 0;
*mu = &pollset->mu;
}
@@ -733,6 +744,7 @@ static grpc_error* fd_get_or_become_pollable(grpc_fd* fd, pollable** p) {
/* pollset->po.mu lock must be held by the caller before calling this */
static void pollset_shutdown(grpc_pollset* pollset, grpc_closure* closure) {
+ GPR_TIMER_SCOPE("pollset_shutdown", 0);
GPR_ASSERT(pollset->shutdown_closure == nullptr);
pollset->shutdown_closure = closure;
GRPC_LOG_IF_ERROR("pollset_shutdown", pollset_kick_all(pollset));
@@ -741,6 +753,7 @@ static void pollset_shutdown(grpc_pollset* pollset, grpc_closure* closure) {
static grpc_error* pollable_process_events(grpc_pollset* pollset,
pollable* pollable_obj, bool drain) {
+ GPR_TIMER_SCOPE("pollable_process_events", 0);
static const char* err_desc = "pollset_process_events";
grpc_error* error = GRPC_ERROR_NONE;
for (int i = 0; (drain || i < MAX_EPOLL_EVENTS_HANDLED_EACH_POLL_CALL) &&
@@ -787,6 +800,7 @@ static void pollset_destroy(grpc_pollset* pollset) {
}
static grpc_error* pollable_epoll(pollable* p, grpc_millis deadline) {
+ GPR_TIMER_SCOPE("pollable_epoll", 0);
int timeout = poll_deadline_to_millis_timeout(deadline);
if (grpc_polling_trace.enabled()) {
@@ -862,7 +876,9 @@ static worker_remove_result worker_remove(grpc_pollset_worker** root_worker,
static bool begin_worker(grpc_pollset* pollset, grpc_pollset_worker* worker,
grpc_pollset_worker** worker_hdl,
grpc_millis deadline) {
- bool do_poll = (pollset->shutdown_closure == nullptr);
+ GPR_TIMER_SCOPE("begin_worker", 0);
+ bool do_poll =
+ (pollset->shutdown_closure == nullptr && !pollset->already_shutdown);
if (worker_hdl != nullptr) *worker_hdl = worker;
worker->initialized_cv = false;
worker->kicked = false;
@@ -913,6 +929,7 @@ static bool begin_worker(grpc_pollset* pollset, grpc_pollset_worker* worker,
static void end_worker(grpc_pollset* pollset, grpc_pollset_worker* worker,
grpc_pollset_worker** worker_hdl) {
+ GPR_TIMER_SCOPE("end_worker", 0);
gpr_mu_lock(&pollset->mu);
gpr_mu_lock(&worker->pollable_obj->mu);
switch (worker_remove(&worker->pollable_obj->root_worker, worker,
@@ -955,6 +972,7 @@ static long gettid(void) { return syscall(__NR_gettid); }
static grpc_error* pollset_work(grpc_pollset* pollset,
grpc_pollset_worker** worker_hdl,
grpc_millis deadline) {
+ GPR_TIMER_SCOPE("pollset_work", 0);
#ifdef GRPC_EPOLLEX_CREATE_WORKERS_ON_HEAP
grpc_pollset_worker* worker =
(grpc_pollset_worker*)gpr_malloc(sizeof(*worker));
@@ -1092,6 +1110,16 @@ static grpc_error* pollset_as_multipollable_locked(grpc_pollset* pollset,
case PO_EMPTY:
POLLABLE_UNREF(pollset->active_pollable, "pollset");
error = pollable_create(PO_MULTI, &pollset->active_pollable);
+ /* Any workers currently polling on this pollset must now be woked up so
+ * that they can pick up the new active_pollable */
+ if (grpc_polling_trace.enabled()) {
+ gpr_log(GPR_DEBUG,
+ "PS:%p active pollable transition from empty to multi",
+ pollset);
+ }
+ static const char* err_desc =
+ "pollset_as_multipollable_locked: empty -> multi";
+ append_error(&error, pollset_kick_all(pollset), err_desc);
break;
case PO_FD:
gpr_mu_lock(&po_at_start->owner_fd->orphan_mu);
@@ -1120,6 +1148,7 @@ static grpc_error* pollset_as_multipollable_locked(grpc_pollset* pollset,
}
static void pollset_add_fd(grpc_pollset* pollset, grpc_fd* fd) {
+ GPR_TIMER_SCOPE("pollset_add_fd", 0);
gpr_mu_lock(&pollset->mu);
grpc_error* error = pollset_add_fd_locked(pollset, fd);
gpr_mu_unlock(&pollset->mu);
@@ -1168,6 +1197,7 @@ static void pollset_set_unref(grpc_pollset_set* pss) {
}
static void pollset_set_add_fd(grpc_pollset_set* pss, grpc_fd* fd) {
+ GPR_TIMER_SCOPE("pollset_set_add_fd", 0);
if (grpc_polling_trace.enabled()) {
gpr_log(GPR_DEBUG, "PSS:%p: add fd %p (%d)", pss, fd, fd->fd);
}
@@ -1191,6 +1221,7 @@ static void pollset_set_add_fd(grpc_pollset_set* pss, grpc_fd* fd) {
}
static void pollset_set_del_fd(grpc_pollset_set* pss, grpc_fd* fd) {
+ GPR_TIMER_SCOPE("pollset_set_del_fd", 0);
if (grpc_polling_trace.enabled()) {
gpr_log(GPR_DEBUG, "PSS:%p: del fd %p", pss, fd);
}
@@ -1211,6 +1242,7 @@ static void pollset_set_del_fd(grpc_pollset_set* pss, grpc_fd* fd) {
}
static void pollset_set_del_pollset(grpc_pollset_set* pss, grpc_pollset* ps) {
+ GPR_TIMER_SCOPE("pollset_set_del_pollset", 0);
if (grpc_polling_trace.enabled()) {
gpr_log(GPR_DEBUG, "PSS:%p: del pollset %p", pss, ps);
}
@@ -1241,6 +1273,7 @@ static grpc_error* add_fds_to_pollsets(grpc_fd** fds, size_t fd_count,
size_t pollset_count,
const char* err_desc, grpc_fd** out_fds,
size_t* out_fd_count) {
+ GPR_TIMER_SCOPE("add_fds_to_pollsets", 0);
grpc_error* error = GRPC_ERROR_NONE;
for (size_t i = 0; i < fd_count; i++) {
gpr_mu_lock(&fds[i]->orphan_mu);
@@ -1261,6 +1294,7 @@ static grpc_error* add_fds_to_pollsets(grpc_fd** fds, size_t fd_count,
}
static void pollset_set_add_pollset(grpc_pollset_set* pss, grpc_pollset* ps) {
+ GPR_TIMER_SCOPE("pollset_set_add_pollset", 0);
if (grpc_polling_trace.enabled()) {
gpr_log(GPR_DEBUG, "PSS:%p: add pollset %p", pss, ps);
}
@@ -1297,6 +1331,7 @@ static void pollset_set_add_pollset(grpc_pollset_set* pss, grpc_pollset* ps) {
static void pollset_set_add_pollset_set(grpc_pollset_set* a,
grpc_pollset_set* b) {
+ GPR_TIMER_SCOPE("pollset_set_add_pollset_set", 0);
if (grpc_polling_trace.enabled()) {
gpr_log(GPR_DEBUG, "PSS: merge (%p, %p)", a, b);
}
diff --git a/src/core/lib/iomgr/ev_epollsig_linux.cc b/src/core/lib/iomgr/ev_epollsig_linux.cc
index 1518348992..c8954894ec 100644
--- a/src/core/lib/iomgr/ev_epollsig_linux.cc
+++ b/src/core/lib/iomgr/ev_epollsig_linux.cc
@@ -1024,7 +1024,7 @@ static void push_front_worker(grpc_pollset* p, grpc_pollset_worker* worker) {
/* p->mu must be held before calling this function */
static grpc_error* pollset_kick(grpc_pollset* p,
grpc_pollset_worker* specific_worker) {
- GPR_TIMER_BEGIN("pollset_kick", 0);
+ GPR_TIMER_SCOPE("pollset_kick", 0);
grpc_error* error = GRPC_ERROR_NONE;
GRPC_STATS_INC_POLLSET_KICK();
const char* err_desc = "Kick Failure";
@@ -1032,14 +1032,13 @@ static grpc_error* pollset_kick(grpc_pollset* p,
if (worker != nullptr) {
if (worker == GRPC_POLLSET_KICK_BROADCAST) {
if (pollset_has_workers(p)) {
- GPR_TIMER_BEGIN("pollset_kick.broadcast", 0);
+ GPR_TIMER_SCOPE("pollset_kick.broadcast", 0);
for (worker = p->root_worker.next; worker != &p->root_worker;
worker = worker->next) {
if (gpr_tls_get(&g_current_thread_worker) != (intptr_t)worker) {
append_error(&error, pollset_worker_kick(worker), err_desc);
}
}
- GPR_TIMER_END("pollset_kick.broadcast", 0);
} else {
p->kicked_without_pollers = true;
}
@@ -1069,7 +1068,6 @@ static grpc_error* pollset_kick(grpc_pollset* p,
}
}
- GPR_TIMER_END("pollset_kick", 0);
GRPC_LOG_IF_ERROR("pollset_kick", GRPC_ERROR_REF(error));
return error;
}
@@ -1136,7 +1134,7 @@ static void finish_shutdown_locked(grpc_pollset* pollset) {
/* pollset->po.mu lock must be held by the caller before calling this */
static void pollset_shutdown(grpc_pollset* pollset, grpc_closure* closure) {
- GPR_TIMER_BEGIN("pollset_shutdown", 0);
+ GPR_TIMER_SCOPE("pollset_shutdown", 0);
GPR_ASSERT(!pollset->shutting_down);
pollset->shutting_down = true;
pollset->shutdown_done = closure;
@@ -1150,7 +1148,6 @@ static void pollset_shutdown(grpc_pollset* pollset, grpc_closure* closure) {
GPR_TIMER_MARK("pollset_shutdown.finish_shutdown_locked", 0);
finish_shutdown_locked(pollset);
}
- GPR_TIMER_END("pollset_shutdown", 0);
}
/* pollset_shutdown is guaranteed to be called before pollset_destroy. So other
@@ -1166,13 +1163,13 @@ static void pollset_destroy(grpc_pollset* pollset) {
static void pollset_work_and_unlock(grpc_pollset* pollset,
grpc_pollset_worker* worker, int timeout_ms,
sigset_t* sig_mask, grpc_error** error) {
+ GPR_TIMER_SCOPE("pollset_work_and_unlock", 0);
struct epoll_event ep_ev[GRPC_EPOLL_MAX_EVENTS];
int epoll_fd = -1;
int ep_rv;
polling_island* pi = nullptr;
char* err_msg;
const char* err_desc = "pollset_work_and_unlock";
- GPR_TIMER_BEGIN("pollset_work_and_unlock", 0);
/* We need to get the epoll_fd to wait on. The epoll_fd is in inside the
latest polling island pointed by pollset->po.pi
@@ -1187,7 +1184,6 @@ static void pollset_work_and_unlock(grpc_pollset* pollset,
if (pollset->po.pi == nullptr) {
pollset->po.pi = polling_island_create(nullptr, error);
if (pollset->po.pi == nullptr) {
- GPR_TIMER_END("pollset_work_and_unlock", 0);
return; /* Fatal error. We cannot continue */
}
@@ -1279,8 +1275,6 @@ static void pollset_work_and_unlock(grpc_pollset* pollset,
pollset->po.pi pointer might get udpated in other parts of the
code when there is an island merge while we are doing epoll_wait() above */
PI_UNREF(pi, "ps_work");
-
- GPR_TIMER_END("pollset_work_and_unlock", 0);
}
/* pollset->po.mu lock must be held by the caller before calling this.
@@ -1290,7 +1284,7 @@ static void pollset_work_and_unlock(grpc_pollset* pollset,
static grpc_error* pollset_work(grpc_pollset* pollset,
grpc_pollset_worker** worker_hdl,
grpc_millis deadline) {
- GPR_TIMER_BEGIN("pollset_work", 0);
+ GPR_TIMER_SCOPE("pollset_work", 0);
grpc_error* error = GRPC_ERROR_NONE;
int timeout_ms = poll_deadline_to_millis_timeout(deadline);
@@ -1384,15 +1378,13 @@ static grpc_error* pollset_work(grpc_pollset* pollset,
gpr_tls_set(&g_current_thread_pollset, (intptr_t)0);
gpr_tls_set(&g_current_thread_worker, (intptr_t)0);
- GPR_TIMER_END("pollset_work", 0);
-
GRPC_LOG_IF_ERROR("pollset_work", GRPC_ERROR_REF(error));
return error;
}
static void add_poll_object(poll_obj* bag, poll_obj_type bag_type,
poll_obj* item, poll_obj_type item_type) {
- GPR_TIMER_BEGIN("add_poll_object", 0);
+ GPR_TIMER_SCOPE("add_poll_object", 0);
#ifndef NDEBUG
GPR_ASSERT(item->obj_type == item_type);
@@ -1535,7 +1527,6 @@ retry:
gpr_mu_unlock(&bag->mu);
GRPC_LOG_IF_ERROR("add_poll_object", error);
- GPR_TIMER_END("add_poll_object", 0);
}
static void pollset_add_fd(grpc_pollset* pollset, grpc_fd* fd) {
diff --git a/src/core/lib/iomgr/ev_poll_posix.cc b/src/core/lib/iomgr/ev_poll_posix.cc
index 3b79728055..ad92a93beb 100644
--- a/src/core/lib/iomgr/ev_poll_posix.cc
+++ b/src/core/lib/iomgr/ev_poll_posix.cc
@@ -706,14 +706,14 @@ static void kick_append_error(grpc_error** composite, grpc_error* error) {
static grpc_error* pollset_kick_ext(grpc_pollset* p,
grpc_pollset_worker* specific_worker,
uint32_t flags) {
- GPR_TIMER_BEGIN("pollset_kick_ext", 0);
+ GPR_TIMER_SCOPE("pollset_kick_ext", 0);
grpc_error* error = GRPC_ERROR_NONE;
GRPC_STATS_INC_POLLSET_KICK();
/* pollset->mu already held */
if (specific_worker != nullptr) {
if (specific_worker == GRPC_POLLSET_KICK_BROADCAST) {
- GPR_TIMER_BEGIN("pollset_kick_ext.broadcast", 0);
+ GPR_TIMER_SCOPE("pollset_kick_ext.broadcast", 0);
GPR_ASSERT((flags & GRPC_POLLSET_REEVALUATE_POLLING_ON_WAKEUP) == 0);
for (specific_worker = p->root_worker.next;
specific_worker != &p->root_worker;
@@ -722,7 +722,6 @@ static grpc_error* pollset_kick_ext(grpc_pollset* p,
&error, grpc_wakeup_fd_wakeup(&specific_worker->wakeup_fd->fd));
}
p->kicked_without_pollers = true;
- GPR_TIMER_END("pollset_kick_ext.broadcast", 0);
} else if (gpr_tls_get(&g_current_thread_worker) !=
(intptr_t)specific_worker) {
GPR_TIMER_MARK("different_thread_worker", 0);
@@ -769,7 +768,6 @@ static grpc_error* pollset_kick_ext(grpc_pollset* p,
}
}
- GPR_TIMER_END("pollset_kick_ext", 0);
GRPC_LOG_IF_ERROR("pollset_kick_ext", GRPC_ERROR_REF(error));
return error;
}
@@ -864,6 +862,8 @@ static void work_combine_error(grpc_error** composite, grpc_error* error) {
static grpc_error* pollset_work(grpc_pollset* pollset,
grpc_pollset_worker** worker_hdl,
grpc_millis deadline) {
+ GPR_TIMER_SCOPE("pollset_work", 0);
+
grpc_pollset_worker worker;
if (worker_hdl) *worker_hdl = &worker;
grpc_error* error = GRPC_ERROR_NONE;
@@ -878,7 +878,6 @@ static grpc_error* pollset_work(grpc_pollset* pollset,
int locked = 1;
int queued_work = 0;
int keep_polling = 0;
- GPR_TIMER_BEGIN("pollset_work", 0);
/* this must happen before we (potentially) drop pollset->mu */
worker.next = worker.prev = nullptr;
worker.reevaluate_polling_on_wakeup = 0;
@@ -921,7 +920,7 @@ static grpc_error* pollset_work(grpc_pollset* pollset,
added_worker = 1;
gpr_tls_set(&g_current_thread_worker, (intptr_t)&worker);
}
- GPR_TIMER_BEGIN("maybe_work_and_unlock", 0);
+ GPR_TIMER_SCOPE("maybe_work_and_unlock", 0);
#define POLLOUT_CHECK (POLLOUT | POLLHUP | POLLERR)
#define POLLIN_CHECK (POLLIN | POLLHUP | POLLERR)
@@ -1037,7 +1036,6 @@ static grpc_error* pollset_work(grpc_pollset* pollset,
gpr_free(pfds);
}
- GPR_TIMER_END("maybe_work_and_unlock", 0);
locked = 0;
} else {
GPR_TIMER_MARK("pollset_work.kicked_without_pollers", 0);
@@ -1097,7 +1095,6 @@ static grpc_error* pollset_work(grpc_pollset* pollset,
}
}
if (worker_hdl) *worker_hdl = nullptr;
- GPR_TIMER_END("pollset_work", 0);
GRPC_LOG_IF_ERROR("pollset_work", GRPC_ERROR_REF(error));
return error;
}
diff --git a/src/core/lib/iomgr/ev_posix.cc b/src/core/lib/iomgr/ev_posix.cc
index 3a5714132d..8100bece8f 100644
--- a/src/core/lib/iomgr/ev_posix.cc
+++ b/src/core/lib/iomgr/ev_posix.cc
@@ -39,6 +39,18 @@
grpc_core::TraceFlag grpc_polling_trace(false,
"polling"); /* Disabled by default */
grpc_core::DebugOnlyTraceFlag grpc_trace_fd_refcount(false, "fd_refcount");
+grpc_core::DebugOnlyTraceFlag grpc_polling_api_trace(false, "polling_api");
+
+#ifndef NDEBUG
+
+// Polling API trace only enabled in debug builds
+#define GRPC_POLLING_API_TRACE(format, ...) \
+ if (grpc_polling_api_trace.enabled()) { \
+ gpr_log(GPR_DEBUG, "(polling-api) " format, __VA_ARGS__); \
+ }
+#else
+#define GRPC_POLLING_API_TRACE(...)
+#endif
/** Default poll() function - a pointer so that it can be overridden by some
* tests */
@@ -177,6 +189,7 @@ void grpc_event_engine_shutdown(void) {
}
grpc_fd* grpc_fd_create(int fd, const char* name) {
+ GRPC_POLLING_API_TRACE("fd_create(%d, %s)", fd, name);
return g_event_engine->fd_create(fd, name);
}
@@ -186,10 +199,14 @@ int grpc_fd_wrapped_fd(grpc_fd* fd) {
void grpc_fd_orphan(grpc_fd* fd, grpc_closure* on_done, int* release_fd,
bool already_closed, const char* reason) {
+ GRPC_POLLING_API_TRACE("fd_orphan(%d, %p, %p, %d, %s)",
+ grpc_fd_wrapped_fd(fd), on_done, release_fd,
+ already_closed, reason);
g_event_engine->fd_orphan(fd, on_done, release_fd, already_closed, reason);
}
void grpc_fd_shutdown(grpc_fd* fd, grpc_error* why) {
+ GRPC_POLLING_API_TRACE("fd_shutdown(%d)", grpc_fd_wrapped_fd(fd));
g_event_engine->fd_shutdown(fd, why);
}
@@ -208,65 +225,89 @@ void grpc_fd_notify_on_write(grpc_fd* fd, grpc_closure* closure) {
size_t grpc_pollset_size(void) { return g_event_engine->pollset_size; }
void grpc_pollset_init(grpc_pollset* pollset, gpr_mu** mu) {
+ GRPC_POLLING_API_TRACE("pollset_init(%p)", pollset);
g_event_engine->pollset_init(pollset, mu);
}
void grpc_pollset_shutdown(grpc_pollset* pollset, grpc_closure* closure) {
+ GRPC_POLLING_API_TRACE("pollset_shutdown(%p)", pollset);
g_event_engine->pollset_shutdown(pollset, closure);
}
void grpc_pollset_destroy(grpc_pollset* pollset) {
+ GRPC_POLLING_API_TRACE("pollset_destroy(%p)", pollset);
g_event_engine->pollset_destroy(pollset);
}
grpc_error* grpc_pollset_work(grpc_pollset* pollset,
grpc_pollset_worker** worker,
grpc_millis deadline) {
- return g_event_engine->pollset_work(pollset, worker, deadline);
+ GRPC_POLLING_API_TRACE("pollset_work(%p, %" PRIdPTR ") begin", pollset,
+ deadline);
+ grpc_error* err = g_event_engine->pollset_work(pollset, worker, deadline);
+ GRPC_POLLING_API_TRACE("pollset_work(%p, %" PRIdPTR ") end", pollset,
+ deadline);
+ return err;
}
grpc_error* grpc_pollset_kick(grpc_pollset* pollset,
grpc_pollset_worker* specific_worker) {
+ GRPC_POLLING_API_TRACE("pollset_kick(%p, %p)", pollset, specific_worker);
return g_event_engine->pollset_kick(pollset, specific_worker);
}
void grpc_pollset_add_fd(grpc_pollset* pollset, struct grpc_fd* fd) {
+ GRPC_POLLING_API_TRACE("pollset_add_fd(%p, %d)", pollset,
+ grpc_fd_wrapped_fd(fd));
g_event_engine->pollset_add_fd(pollset, fd);
}
grpc_pollset_set* grpc_pollset_set_create(void) {
- return g_event_engine->pollset_set_create();
+ grpc_pollset_set* pss = g_event_engine->pollset_set_create();
+ GRPC_POLLING_API_TRACE("pollset_set_create(%p)", pss);
+ return pss;
}
void grpc_pollset_set_destroy(grpc_pollset_set* pollset_set) {
+ GRPC_POLLING_API_TRACE("pollset_set_destroy(%p)", pollset_set);
g_event_engine->pollset_set_destroy(pollset_set);
}
void grpc_pollset_set_add_pollset(grpc_pollset_set* pollset_set,
grpc_pollset* pollset) {
+ GRPC_POLLING_API_TRACE("pollset_set_add_pollset(%p, %p)", pollset_set,
+ pollset);
g_event_engine->pollset_set_add_pollset(pollset_set, pollset);
}
void grpc_pollset_set_del_pollset(grpc_pollset_set* pollset_set,
grpc_pollset* pollset) {
+ GRPC_POLLING_API_TRACE("pollset_set_del_pollset(%p, %p)", pollset_set,
+ pollset);
g_event_engine->pollset_set_del_pollset(pollset_set, pollset);
}
void grpc_pollset_set_add_pollset_set(grpc_pollset_set* bag,
grpc_pollset_set* item) {
+ GRPC_POLLING_API_TRACE("pollset_set_add_pollset_set(%p, %p)", bag, item);
g_event_engine->pollset_set_add_pollset_set(bag, item);
}
void grpc_pollset_set_del_pollset_set(grpc_pollset_set* bag,
grpc_pollset_set* item) {
+ GRPC_POLLING_API_TRACE("pollset_set_del_pollset_set(%p, %p)", bag, item);
g_event_engine->pollset_set_del_pollset_set(bag, item);
}
void grpc_pollset_set_add_fd(grpc_pollset_set* pollset_set, grpc_fd* fd) {
+ GRPC_POLLING_API_TRACE("pollset_set_add_fd(%p, %d)", pollset_set,
+ grpc_fd_wrapped_fd(fd));
g_event_engine->pollset_set_add_fd(pollset_set, fd);
}
void grpc_pollset_set_del_fd(grpc_pollset_set* pollset_set, grpc_fd* fd) {
+ GRPC_POLLING_API_TRACE("pollset_set_del_fd(%p, %d)", pollset_set,
+ grpc_fd_wrapped_fd(fd));
g_event_engine->pollset_set_del_fd(pollset_set, fd);
}
diff --git a/src/core/lib/iomgr/exec_ctx.cc b/src/core/lib/iomgr/exec_ctx.cc
index e005437e0a..03c833ff07 100644
--- a/src/core/lib/iomgr/exec_ctx.cc
+++ b/src/core/lib/iomgr/exec_ctx.cc
@@ -113,7 +113,7 @@ void ExecCtx::GlobalInit(void) {
bool ExecCtx::Flush() {
bool did_something = 0;
- GPR_TIMER_BEGIN("grpc_exec_ctx_flush", 0);
+ GPR_TIMER_SCOPE("grpc_exec_ctx_flush", 0);
for (;;) {
if (!grpc_closure_list_empty(closure_list_)) {
grpc_closure* c = closure_list_.head;
@@ -130,7 +130,6 @@ bool ExecCtx::Flush() {
}
}
GPR_ASSERT(combiner_data_.active_combiner == nullptr);
- GPR_TIMER_END("grpc_exec_ctx_flush", 0);
return did_something;
}
diff --git a/src/core/lib/iomgr/tcp_posix.cc b/src/core/lib/iomgr/tcp_posix.cc
index 0ec5926227..07aed2d1fd 100644
--- a/src/core/lib/iomgr/tcp_posix.cc
+++ b/src/core/lib/iomgr/tcp_posix.cc
@@ -130,7 +130,7 @@ static void run_poller(void* bp, grpc_error* error_ignored) {
gpr_log(GPR_DEBUG, "BACKUP_POLLER:%p run", p);
}
gpr_mu_lock(p->pollset_mu);
- grpc_millis deadline = grpc_core::ExecCtx::Get()->Now() + 13 * GPR_MS_PER_SEC;
+ grpc_millis deadline = grpc_core::ExecCtx::Get()->Now() + 10 * GPR_MS_PER_SEC;
GRPC_STATS_INC_TCP_BACKUP_POLLER_POLLS();
GRPC_LOG_IF_ERROR(
"backup_poller:pollset_work",
@@ -368,6 +368,7 @@ static void call_read_cb(grpc_tcp* tcp, grpc_error* error) {
#define MAX_READ_IOVEC 4
static void tcp_do_read(grpc_tcp* tcp) {
+ GPR_TIMER_SCOPE("tcp_continue_read", 0);
struct msghdr msg;
struct iovec iov[MAX_READ_IOVEC];
ssize_t read_bytes;
@@ -375,7 +376,6 @@ static void tcp_do_read(grpc_tcp* tcp) {
GPR_ASSERT(!tcp->finished_edge);
GPR_ASSERT(tcp->incoming_buffer->count <= MAX_READ_IOVEC);
- GPR_TIMER_BEGIN("tcp_continue_read", 0);
for (i = 0; i < tcp->incoming_buffer->count; i++) {
iov[i].iov_base = GRPC_SLICE_START_PTR(tcp->incoming_buffer->slices[i]);
@@ -393,12 +393,11 @@ static void tcp_do_read(grpc_tcp* tcp) {
GRPC_STATS_INC_TCP_READ_OFFER(tcp->incoming_buffer->length);
GRPC_STATS_INC_TCP_READ_OFFER_IOV_SIZE(tcp->incoming_buffer->count);
- GPR_TIMER_BEGIN("recvmsg", 0);
do {
+ GPR_TIMER_SCOPE("recvmsg", 0);
GRPC_STATS_INC_SYSCALL_READ();
read_bytes = recvmsg(tcp->fd, &msg, 0);
} while (read_bytes < 0 && errno == EINTR);
- GPR_TIMER_END("recvmsg", read_bytes >= 0);
if (read_bytes < 0) {
/* NB: After calling call_read_cb a parallel call of the read handler may
@@ -434,8 +433,6 @@ static void tcp_do_read(grpc_tcp* tcp) {
call_read_cb(tcp, GRPC_ERROR_NONE);
TCP_UNREF(tcp, "read");
}
-
- GPR_TIMER_END("tcp_continue_read", 0);
}
static void tcp_read_allocation_done(void* tcpp, grpc_error* error) {
@@ -552,13 +549,12 @@ static bool tcp_flush(grpc_tcp* tcp, grpc_error** error) {
GRPC_STATS_INC_TCP_WRITE_SIZE(sending_length);
GRPC_STATS_INC_TCP_WRITE_IOV_SIZE(iov_size);
- GPR_TIMER_BEGIN("sendmsg", 1);
+ GPR_TIMER_SCOPE("sendmsg", 1);
do {
/* TODO(klempner): Cork if this is a partial write */
GRPC_STATS_INC_SYSCALL_WRITE();
sent_length = sendmsg(tcp->fd, &msg, SENDMSG_FLAGS);
} while (sent_length < 0 && errno == EINTR);
- GPR_TIMER_END("sendmsg", 0);
if (sent_length < 0) {
if (errno == EAGAIN) {
@@ -637,6 +633,7 @@ static void tcp_handle_write(void* arg /* grpc_tcp */, grpc_error* error) {
static void tcp_write(grpc_endpoint* ep, grpc_slice_buffer* buf,
grpc_closure* cb) {
+ GPR_TIMER_SCOPE("tcp_write", 0);
grpc_tcp* tcp = (grpc_tcp*)ep;
grpc_error* error = GRPC_ERROR_NONE;
@@ -651,11 +648,9 @@ static void tcp_write(grpc_endpoint* ep, grpc_slice_buffer* buf,
}
}
- GPR_TIMER_BEGIN("tcp_write", 0);
GPR_ASSERT(tcp->write_cb == nullptr);
if (buf->length == 0) {
- GPR_TIMER_END("tcp_write", 0);
GRPC_CLOSURE_SCHED(
cb, grpc_fd_is_shutdown(tcp->em_fd)
? tcp_annotate_error(
@@ -680,8 +675,6 @@ static void tcp_write(grpc_endpoint* ep, grpc_slice_buffer* buf,
}
GRPC_CLOSURE_SCHED(cb, error);
}
-
- GPR_TIMER_END("tcp_write", 0);
}
static void tcp_add_to_pollset(grpc_endpoint* ep, grpc_pollset* pollset) {
diff --git a/src/core/lib/iomgr/wakeup_fd_eventfd.cc b/src/core/lib/iomgr/wakeup_fd_eventfd.cc
index 81cb7ee280..421ac55b00 100644
--- a/src/core/lib/iomgr/wakeup_fd_eventfd.cc
+++ b/src/core/lib/iomgr/wakeup_fd_eventfd.cc
@@ -52,15 +52,14 @@ static grpc_error* eventfd_consume(grpc_wakeup_fd* fd_info) {
}
static grpc_error* eventfd_wakeup(grpc_wakeup_fd* fd_info) {
+ GPR_TIMER_SCOPE("eventfd_wakeup", 0);
int err;
- GPR_TIMER_BEGIN("eventfd_wakeup", 0);
do {
err = eventfd_write(fd_info->read_fd, 1);
} while (err < 0 && errno == EINTR);
if (err < 0) {
return GRPC_OS_ERROR(errno, "eventfd_write");
}
- GPR_TIMER_END("eventfd_wakeup", 0);
return GRPC_ERROR_NONE;
}
generated by cgit v1.2.3 (git 2.39.1) at 2024-07-02 10:21:02 +0000