diff options
author | Vijay Pai <vpai@google.com> | 2018-02-02 11:21:07 -0800 |
---|---|---|
committer | Vijay Pai <vpai@google.com> | 2018-02-02 11:21:07 -0800 |
commit | 1acfaca3e630fbb4c64de1eb7267f969730e49da (patch) | |
tree | 08619d38599aeb5dfdff0a7b341a07014f7ea4d1 /src/core/lib/iomgr | |
parent | 7ce8b94b691e08efc7206ac9365d71502872e154 (diff) | |
parent | c8e07c4964c98fb216dfcd562229ae515fc84a09 (diff) |
Merge branch 'master' into gpr_review_host_port
Diffstat (limited to 'src/core/lib/iomgr')
-rw-r--r-- | src/core/lib/iomgr/call_combiner.cc | 6 | ||||
-rw-r--r-- | src/core/lib/iomgr/closure.h | 6 | ||||
-rw-r--r-- | src/core/lib/iomgr/combiner.cc | 22 | ||||
-rw-r--r-- | src/core/lib/iomgr/error.cc | 25 | ||||
-rw-r--r-- | src/core/lib/iomgr/ev_epoll1_linux.cc | 31 | ||||
-rw-r--r-- | src/core/lib/iomgr/ev_epollex_linux.cc | 37 | ||||
-rw-r--r-- | src/core/lib/iomgr/ev_epollsig_linux.cc | 21 | ||||
-rw-r--r-- | src/core/lib/iomgr/ev_poll_posix.cc | 13 | ||||
-rw-r--r-- | src/core/lib/iomgr/ev_posix.cc | 45 | ||||
-rw-r--r-- | src/core/lib/iomgr/exec_ctx.cc | 3 | ||||
-rw-r--r-- | src/core/lib/iomgr/tcp_posix.cc | 17 | ||||
-rw-r--r-- | src/core/lib/iomgr/wakeup_fd_eventfd.cc | 3 |
12 files changed, 123 insertions, 106 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 ad274b839c..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); @@ -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()) { @@ -1150,7 +1140,6 @@ static grpc_error* pollset_kick(grpc_pollset* pollset, 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; } |