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 | |
parent | 7ce8b94b691e08efc7206ac9365d71502872e154 (diff) | |
parent | c8e07c4964c98fb216dfcd562229ae515fc84a09 (diff) |
Merge branch 'master' into gpr_review_host_port
Diffstat (limited to 'src/core')
43 files changed, 370 insertions, 560 deletions
diff --git a/src/core/ext/filters/client_channel/client_channel.cc b/src/core/ext/filters/client_channel/client_channel.cc index a8a7a37be0..49522ef3e4 100644 --- a/src/core/ext/filters/client_channel/client_channel.cc +++ b/src/core/ext/filters/client_channel/client_channel.cc @@ -1333,12 +1333,12 @@ static void on_complete(void* arg, grpc_error* error) { static void cc_start_transport_stream_op_batch( grpc_call_element* elem, grpc_transport_stream_op_batch* batch) { + GPR_TIMER_SCOPE("cc_start_transport_stream_op_batch", 0); call_data* calld = (call_data*)elem->call_data; channel_data* chand = (channel_data*)elem->channel_data; if (chand->deadline_checking_enabled) { grpc_deadline_state_client_start_transport_stream_op_batch(elem, batch); } - GPR_TIMER_BEGIN("cc_start_transport_stream_op_batch", 0); // If we've previously been cancelled, immediately fail any new batches. if (calld->error != GRPC_ERROR_NONE) { if (grpc_client_channel_trace.enabled()) { @@ -1347,7 +1347,7 @@ static void cc_start_transport_stream_op_batch( } grpc_transport_stream_op_batch_finish_with_failure( batch, GRPC_ERROR_REF(calld->error), calld->call_combiner); - goto done; + return; } if (batch->cancel_stream) { // Stash a copy of cancel_error in our call data, so that we can use @@ -1369,7 +1369,7 @@ static void cc_start_transport_stream_op_batch( waiting_for_pick_batches_add(calld, batch); waiting_for_pick_batches_fail(elem, GRPC_ERROR_REF(calld->error)); } - goto done; + return; } // Intercept on_complete for recv_trailing_metadata so that we can // check retry throttle status. @@ -1391,7 +1391,7 @@ static void cc_start_transport_stream_op_batch( calld, calld->subchannel_call); } grpc_subchannel_call_process_op(calld->subchannel_call, batch); - goto done; + return; } // We do not yet have a subchannel call. // Add the batch to the waiting-for-pick list. @@ -1417,8 +1417,6 @@ static void cc_start_transport_stream_op_batch( GRPC_CALL_COMBINER_STOP(calld->call_combiner, "batch does not include send_initial_metadata"); } -done: - GPR_TIMER_END("cc_start_transport_stream_op_batch", 0); } /* Constructor for call_data */ diff --git a/src/core/ext/filters/client_channel/lb_policy/grpclb/client_load_reporting_filter.cc b/src/core/ext/filters/client_channel/lb_policy/grpclb/client_load_reporting_filter.cc index 4596f90745..d6b759227e 100644 --- a/src/core/ext/filters/client_channel/lb_policy/grpclb/client_load_reporting_filter.cc +++ b/src/core/ext/filters/client_channel/lb_policy/grpclb/client_load_reporting_filter.cc @@ -98,7 +98,7 @@ static void destroy_call_elem(grpc_call_element* elem, static void start_transport_stream_op_batch( grpc_call_element* elem, grpc_transport_stream_op_batch* batch) { call_data* calld = (call_data*)elem->call_data; - GPR_TIMER_BEGIN("clr_start_transport_stream_op_batch", 0); + GPR_TIMER_SCOPE("clr_start_transport_stream_op_batch", 0); if (calld->client_stats != nullptr) { // Intercept send_initial_metadata. if (batch->send_initial_metadata) { @@ -120,7 +120,6 @@ static void start_transport_stream_op_batch( } // Chain to next filter. grpc_call_next_op(elem, batch); - GPR_TIMER_END("clr_start_transport_stream_op_batch", 0); } const grpc_channel_filter grpc_client_load_reporting_filter = { diff --git a/src/core/ext/filters/client_channel/resolver/dns/c_ares/dns_resolver_ares.cc b/src/core/ext/filters/client_channel/resolver/dns/c_ares/dns_resolver_ares.cc index 3ade00550b..f2f25bc7c0 100644 --- a/src/core/ext/filters/client_channel/resolver/dns/c_ares/dns_resolver_ares.cc +++ b/src/core/ext/filters/client_channel/resolver/dns/c_ares/dns_resolver_ares.cc @@ -66,8 +66,8 @@ typedef struct { grpc_pollset_set* interested_parties; /** Closures used by the combiner */ - grpc_closure dns_ares_on_retry_timer_locked; - grpc_closure dns_ares_on_resolved_locked; + grpc_closure dns_ares_on_next_resolution_timer_closure; + grpc_closure dns_ares_on_resolved_closure; /** Combiner guarding the rest of the state */ grpc_combiner* combiner; @@ -85,12 +85,15 @@ typedef struct { grpc_channel_args** target_result; /** current (fully resolved) result */ grpc_channel_args* resolved_result; - /** retry timer */ - bool have_retry_timer; - grpc_timer retry_timer; + /** next resolution timer */ + bool have_next_resolution_timer; + grpc_timer next_resolution_timer; /** retry backoff state */ grpc_core::ManualConstructor<grpc_core::BackOff> backoff; - + /** min resolution period. Max one resolution will happen per period */ + grpc_millis min_time_between_resolutions; + /** when was the last resolution? -1 if no resolution has happened yet */ + grpc_millis last_resolution_timestamp; /** currently resolving addresses */ grpc_lb_addresses* lb_addresses; /** currently resolving service config */ @@ -100,6 +103,7 @@ typedef struct { static void dns_ares_destroy(grpc_resolver* r); static void dns_ares_start_resolving_locked(ares_dns_resolver* r); +static void dns_ares_maybe_start_resolving_locked(ares_dns_resolver* r); static void dns_ares_maybe_finish_next_locked(ares_dns_resolver* r); static void dns_ares_shutdown_locked(grpc_resolver* r); @@ -114,8 +118,8 @@ static const grpc_resolver_vtable dns_ares_resolver_vtable = { static void dns_ares_shutdown_locked(grpc_resolver* resolver) { ares_dns_resolver* r = (ares_dns_resolver*)resolver; - if (r->have_retry_timer) { - grpc_timer_cancel(&r->retry_timer); + if (r->have_next_resolution_timer) { + grpc_timer_cancel(&r->next_resolution_timer); } if (r->pending_request != nullptr) { grpc_cancel_ares_request(r->pending_request); @@ -131,20 +135,20 @@ static void dns_ares_shutdown_locked(grpc_resolver* resolver) { static void dns_ares_channel_saw_error_locked(grpc_resolver* resolver) { ares_dns_resolver* r = (ares_dns_resolver*)resolver; if (!r->resolving) { - r->backoff->Reset(); - dns_ares_start_resolving_locked(r); + dns_ares_maybe_start_resolving_locked(r); } } -static void dns_ares_on_retry_timer_locked(void* arg, grpc_error* error) { +static void dns_ares_on_next_resolution_timer_locked(void* arg, + grpc_error* error) { ares_dns_resolver* r = (ares_dns_resolver*)arg; - r->have_retry_timer = false; + r->have_next_resolution_timer = false; if (error == GRPC_ERROR_NONE) { if (!r->resolving) { dns_ares_start_resolving_locked(r); } } - GRPC_RESOLVER_UNREF(&r->base, "retry-timer"); + GRPC_RESOLVER_UNREF(&r->base, "next_resolution_timer"); } static bool value_in_json_array(grpc_json* array, const char* value) { @@ -261,6 +265,9 @@ static void dns_ares_on_resolved_locked(void* arg, grpc_error* error) { if (service_config != nullptr) grpc_service_config_destroy(service_config); gpr_free(service_config_string); grpc_lb_addresses_destroy(r->lb_addresses); + // Reset backoff state so that we start from the beginning when the + // next request gets triggered. + r->backoff->Reset(); } else { const char* msg = grpc_error_string(error); gpr_log(GPR_DEBUG, "dns resolution failed: %s", msg); @@ -268,21 +275,22 @@ static void dns_ares_on_resolved_locked(void* arg, grpc_error* error) { grpc_millis timeout = next_try - grpc_core::ExecCtx::Get()->Now(); gpr_log(GPR_INFO, "dns resolution failed (will retry): %s", grpc_error_string(error)); - GPR_ASSERT(!r->have_retry_timer); - r->have_retry_timer = true; - GRPC_RESOLVER_REF(&r->base, "retry-timer"); + GPR_ASSERT(!r->have_next_resolution_timer); + r->have_next_resolution_timer = true; + GRPC_RESOLVER_REF(&r->base, "next_resolution_timer"); if (timeout > 0) { gpr_log(GPR_DEBUG, "retrying in %" PRIdPTR " milliseconds", timeout); } else { gpr_log(GPR_DEBUG, "retrying immediately"); } - grpc_timer_init(&r->retry_timer, next_try, - &r->dns_ares_on_retry_timer_locked); + grpc_timer_init(&r->next_resolution_timer, next_try, + &r->dns_ares_on_next_resolution_timer_closure); } if (r->resolved_result != nullptr) { grpc_channel_args_destroy(r->resolved_result); } r->resolved_result = result; + r->last_resolution_timestamp = grpc_core::ExecCtx::Get()->Now(); r->resolved_version++; dns_ares_maybe_finish_next_locked(r); GRPC_RESOLVER_UNREF(&r->base, "dns-resolving"); @@ -297,8 +305,7 @@ static void dns_ares_next_locked(grpc_resolver* resolver, r->next_completion = on_complete; r->target_result = target_result; if (r->resolved_version == 0 && !r->resolving) { - r->backoff->Reset(); - dns_ares_start_resolving_locked(r); + dns_ares_maybe_start_resolving_locked(r); } else { dns_ares_maybe_finish_next_locked(r); } @@ -312,7 +319,7 @@ static void dns_ares_start_resolving_locked(ares_dns_resolver* r) { r->service_config_json = nullptr; r->pending_request = grpc_dns_lookup_ares( r->dns_server, r->name_to_resolve, r->default_port, r->interested_parties, - &r->dns_ares_on_resolved_locked, &r->lb_addresses, + &r->dns_ares_on_resolved_closure, &r->lb_addresses, true /* check_grpclb */, r->request_service_config ? &r->service_config_json : nullptr); } @@ -330,6 +337,35 @@ static void dns_ares_maybe_finish_next_locked(ares_dns_resolver* r) { } } +static void dns_ares_maybe_start_resolving_locked(ares_dns_resolver* r) { + if (r->last_resolution_timestamp >= 0) { + const grpc_millis earliest_next_resolution = + r->last_resolution_timestamp + r->min_time_between_resolutions; + const grpc_millis ms_until_next_resolution = + earliest_next_resolution - grpc_core::ExecCtx::Get()->Now(); + if (ms_until_next_resolution > 0) { + const grpc_millis last_resolution_ago = + grpc_core::ExecCtx::Get()->Now() - r->last_resolution_timestamp; + gpr_log(GPR_DEBUG, + "In cooldown from last resolution (from %" PRIdPTR + " ms ago). Will resolve again in %" PRIdPTR " ms", + last_resolution_ago, ms_until_next_resolution); + if (!r->have_next_resolution_timer) { + r->have_next_resolution_timer = true; + GRPC_RESOLVER_REF(&r->base, "next_resolution_timer_cooldown"); + grpc_timer_init(&r->next_resolution_timer, ms_until_next_resolution, + &r->dns_ares_on_next_resolution_timer_closure); + } + // TODO(dgq): remove the following two lines once Pick First stops + // discarding subchannels after selecting. + ++r->resolved_version; + dns_ares_maybe_finish_next_locked(r); + return; + } + } + dns_ares_start_resolving_locked(r); +} + static void dns_ares_destroy(grpc_resolver* gr) { gpr_log(GPR_DEBUG, "dns_ares_destroy"); ares_dns_resolver* r = (ares_dns_resolver*)gr; @@ -374,12 +410,17 @@ static grpc_resolver* dns_ares_create(grpc_resolver_args* args, .set_jitter(GRPC_DNS_RECONNECT_JITTER) .set_max_backoff(GRPC_DNS_RECONNECT_MAX_BACKOFF_SECONDS * 1000); r->backoff.Init(grpc_core::BackOff(backoff_options)); - GRPC_CLOSURE_INIT(&r->dns_ares_on_retry_timer_locked, - dns_ares_on_retry_timer_locked, r, + GRPC_CLOSURE_INIT(&r->dns_ares_on_next_resolution_timer_closure, + dns_ares_on_next_resolution_timer_locked, r, grpc_combiner_scheduler(r->base.combiner)); - GRPC_CLOSURE_INIT(&r->dns_ares_on_resolved_locked, + GRPC_CLOSURE_INIT(&r->dns_ares_on_resolved_closure, dns_ares_on_resolved_locked, r, grpc_combiner_scheduler(r->base.combiner)); + const grpc_arg* period_arg = grpc_channel_args_find( + args->args, GRPC_ARG_DNS_MIN_TIME_BETWEEN_RESOLUTIONS_MS); + r->min_time_between_resolutions = + grpc_channel_arg_get_integer(period_arg, {1000, 0, INT_MAX}); + r->last_resolution_timestamp = -1; return &r->base; } diff --git a/src/core/ext/filters/client_channel/resolver/dns/c_ares/grpc_ares_wrapper.cc b/src/core/ext/filters/client_channel/resolver/dns/c_ares/grpc_ares_wrapper.cc index 03bd2acf6b..d76c8069d5 100644 --- a/src/core/ext/filters/client_channel/resolver/dns/c_ares/grpc_ares_wrapper.cc +++ b/src/core/ext/filters/client_channel/resolver/dns/c_ares/grpc_ares_wrapper.cc @@ -505,7 +505,7 @@ static void on_dns_lookup_done_cb(void* arg, grpc_error* error) { } } GRPC_CLOSURE_SCHED(r->on_resolve_address_done, GRPC_ERROR_REF(error)); - grpc_lb_addresses_destroy(r->lb_addrs); + if (r->lb_addrs != nullptr) grpc_lb_addresses_destroy(r->lb_addrs); gpr_free(r); } diff --git a/src/core/ext/filters/client_channel/resolver/dns/native/dns_resolver.cc b/src/core/ext/filters/client_channel/resolver/dns/native/dns_resolver.cc index 2f9a964628..478810d263 100644 --- a/src/core/ext/filters/client_channel/resolver/dns/native/dns_resolver.cc +++ b/src/core/ext/filters/client_channel/resolver/dns/native/dns_resolver.cc @@ -19,10 +19,12 @@ #include <grpc/support/port_platform.h> #include <inttypes.h> -#include <string.h> +#include <climits> +#include <cstring> #include <grpc/support/alloc.h> #include <grpc/support/string_util.h> +#include <grpc/support/time.h> #include "src/core/ext/filters/client_channel/lb_policy_registry.h" #include "src/core/ext/filters/client_channel/resolver_registry.h" @@ -65,13 +67,16 @@ typedef struct { grpc_channel_args** target_result; /** current (fully resolved) result */ grpc_channel_args* resolved_result; - /** retry timer */ - bool have_retry_timer; - grpc_timer retry_timer; - grpc_closure on_retry; + /** next resolution timer */ + bool have_next_resolution_timer; + grpc_timer next_resolution_timer; + grpc_closure next_resolution_closure; /** retry backoff state */ grpc_core::ManualConstructor<grpc_core::BackOff> backoff; - + /** min resolution period. Max one resolution will happen per period */ + grpc_millis min_time_between_resolutions; + /** when was the last resolution? -1 if no resolution has happened yet */ + grpc_millis last_resolution_timestamp; /** currently resolving addresses */ grpc_resolved_addresses* addresses; } dns_resolver; @@ -79,6 +84,7 @@ typedef struct { static void dns_destroy(grpc_resolver* r); static void dns_start_resolving_locked(dns_resolver* r); +static void maybe_start_resolving_locked(dns_resolver* r); static void dns_maybe_finish_next_locked(dns_resolver* r); static void dns_shutdown_locked(grpc_resolver* r); @@ -92,8 +98,8 @@ static const grpc_resolver_vtable dns_resolver_vtable = { static void dns_shutdown_locked(grpc_resolver* resolver) { dns_resolver* r = (dns_resolver*)resolver; - if (r->have_retry_timer) { - grpc_timer_cancel(&r->retry_timer); + if (r->have_next_resolution_timer) { + grpc_timer_cancel(&r->next_resolution_timer); } if (r->next_completion != nullptr) { *r->target_result = nullptr; @@ -106,8 +112,7 @@ static void dns_shutdown_locked(grpc_resolver* resolver) { static void dns_channel_saw_error_locked(grpc_resolver* resolver) { dns_resolver* r = (dns_resolver*)resolver; if (!r->resolving) { - r->backoff->Reset(); - dns_start_resolving_locked(r); + maybe_start_resolving_locked(r); } } @@ -119,24 +124,19 @@ static void dns_next_locked(grpc_resolver* resolver, r->next_completion = on_complete; r->target_result = target_result; if (r->resolved_version == 0 && !r->resolving) { - r->backoff->Reset(); - dns_start_resolving_locked(r); + maybe_start_resolving_locked(r); } else { dns_maybe_finish_next_locked(r); } } -static void dns_on_retry_timer_locked(void* arg, grpc_error* error) { +static void dns_on_next_resolution_timer_locked(void* arg, grpc_error* error) { dns_resolver* r = (dns_resolver*)arg; - - r->have_retry_timer = false; - if (error == GRPC_ERROR_NONE) { - if (!r->resolving) { - dns_start_resolving_locked(r); - } + r->have_next_resolution_timer = false; + if (error == GRPC_ERROR_NONE && !r->resolving) { + dns_start_resolving_locked(r); } - - GRPC_RESOLVER_UNREF(&r->base, "retry-timer"); + GRPC_RESOLVER_UNREF(&r->base, "next_resolution_timer"); } static void dns_on_resolved_locked(void* arg, grpc_error* error) { @@ -160,22 +160,24 @@ static void dns_on_resolved_locked(void* arg, grpc_error* error) { result = grpc_channel_args_copy_and_add(r->channel_args, &new_arg, 1); grpc_resolved_addresses_destroy(r->addresses); grpc_lb_addresses_destroy(addresses); + // Reset backoff state so that we start from the beginning when the + // next request gets triggered. + r->backoff->Reset(); } else { grpc_millis next_try = r->backoff->NextAttemptTime(); grpc_millis timeout = next_try - grpc_core::ExecCtx::Get()->Now(); gpr_log(GPR_INFO, "dns resolution failed (will retry): %s", grpc_error_string(error)); - GPR_ASSERT(!r->have_retry_timer); - r->have_retry_timer = true; - GRPC_RESOLVER_REF(&r->base, "retry-timer"); + GPR_ASSERT(!r->have_next_resolution_timer); + r->have_next_resolution_timer = true; + GRPC_RESOLVER_REF(&r->base, "next_resolution_timer"); if (timeout > 0) { gpr_log(GPR_DEBUG, "retrying in %" PRIdPTR " milliseconds", timeout); } else { gpr_log(GPR_DEBUG, "retrying immediately"); } - GRPC_CLOSURE_INIT(&r->on_retry, dns_on_retry_timer_locked, r, - grpc_combiner_scheduler(r->base.combiner)); - grpc_timer_init(&r->retry_timer, next_try, &r->on_retry); + grpc_timer_init(&r->next_resolution_timer, next_try, + &r->next_resolution_closure); } if (r->resolved_result != nullptr) { grpc_channel_args_destroy(r->resolved_result); @@ -188,6 +190,35 @@ static void dns_on_resolved_locked(void* arg, grpc_error* error) { GRPC_RESOLVER_UNREF(&r->base, "dns-resolving"); } +static void maybe_start_resolving_locked(dns_resolver* r) { + if (r->last_resolution_timestamp >= 0) { + const grpc_millis earliest_next_resolution = + r->last_resolution_timestamp + r->min_time_between_resolutions; + const grpc_millis ms_until_next_resolution = + earliest_next_resolution - grpc_core::ExecCtx::Get()->Now(); + if (ms_until_next_resolution > 0) { + const grpc_millis last_resolution_ago = + grpc_core::ExecCtx::Get()->Now() - r->last_resolution_timestamp; + gpr_log(GPR_DEBUG, + "In cooldown from last resolution (from %" PRIdPTR + " ms ago). Will resolve again in %" PRIdPTR " ms", + last_resolution_ago, ms_until_next_resolution); + if (!r->have_next_resolution_timer) { + r->have_next_resolution_timer = true; + GRPC_RESOLVER_REF(&r->base, "next_resolution_timer_cooldown"); + grpc_timer_init(&r->next_resolution_timer, ms_until_next_resolution, + &r->next_resolution_closure); + } + // TODO(dgq): remove the following two lines once Pick First stops + // discarding subchannels after selecting. + ++r->resolved_version; + dns_maybe_finish_next_locked(r); + return; + } + } + dns_start_resolving_locked(r); +} + static void dns_start_resolving_locked(dns_resolver* r) { GRPC_RESOLVER_REF(&r->base, "dns-resolving"); GPR_ASSERT(!r->resolving); @@ -198,6 +229,7 @@ static void dns_start_resolving_locked(dns_resolver* r) { GRPC_CLOSURE_CREATE(dns_on_resolved_locked, r, grpc_combiner_scheduler(r->base.combiner)), &r->addresses); + r->last_resolution_timestamp = grpc_core::ExecCtx::Get()->Now(); } static void dns_maybe_finish_next_locked(dns_resolver* r) { @@ -250,6 +282,14 @@ static grpc_resolver* dns_create(grpc_resolver_args* args, .set_jitter(GRPC_DNS_RECONNECT_JITTER) .set_max_backoff(GRPC_DNS_RECONNECT_MAX_BACKOFF_SECONDS * 1000); r->backoff.Init(grpc_core::BackOff(backoff_options)); + const grpc_arg* period_arg = grpc_channel_args_find( + args->args, GRPC_ARG_DNS_MIN_TIME_BETWEEN_RESOLUTIONS_MS); + r->min_time_between_resolutions = + grpc_channel_arg_get_integer(period_arg, {1000, 0, INT_MAX}); + r->last_resolution_timestamp = -1; + GRPC_CLOSURE_INIT(&r->next_resolution_closure, + dns_on_next_resolution_timer_locked, r, + grpc_combiner_scheduler(r->base.combiner)); return &r->base; } diff --git a/src/core/ext/filters/client_channel/subchannel.cc b/src/core/ext/filters/client_channel/subchannel.cc index cad8578511..dc1beee165 100644 --- a/src/core/ext/filters/client_channel/subchannel.cc +++ b/src/core/ext/filters/client_channel/subchannel.cc @@ -653,14 +653,13 @@ static void on_subchannel_connected(void* arg, grpc_error* error) { */ static void subchannel_call_destroy(void* call, grpc_error* error) { + GPR_TIMER_SCOPE("grpc_subchannel_call_unref.destroy", 0); grpc_subchannel_call* c = (grpc_subchannel_call*)call; GPR_ASSERT(c->schedule_closure_after_destroy != nullptr); - GPR_TIMER_BEGIN("grpc_subchannel_call_unref.destroy", 0); grpc_core::ConnectedSubchannel* connection = c->connection; grpc_call_stack_destroy(SUBCHANNEL_CALL_TO_CALL_STACK(c), nullptr, c->schedule_closure_after_destroy); connection->Unref(DEBUG_LOCATION, "subchannel_call"); - GPR_TIMER_END("grpc_subchannel_call_unref.destroy", 0); } void grpc_subchannel_call_set_cleanup_closure(grpc_subchannel_call* call, @@ -682,12 +681,11 @@ void grpc_subchannel_call_unref( void grpc_subchannel_call_process_op(grpc_subchannel_call* call, grpc_transport_stream_op_batch* batch) { - GPR_TIMER_BEGIN("grpc_subchannel_call_process_op", 0); + GPR_TIMER_SCOPE("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); GRPC_CALL_LOG_OP(GPR_INFO, top_elem, batch); top_elem->filter->start_transport_stream_op_batch(top_elem, batch); - GPR_TIMER_END("grpc_subchannel_call_process_op", 0); } grpc_core::RefCountedPtr<grpc_core::ConnectedSubchannel> diff --git a/src/core/ext/filters/http/client/http_client_filter.cc b/src/core/ext/filters/http/client/http_client_filter.cc index 5584d50018..befd5a3c28 100644 --- a/src/core/ext/filters/http/client/http_client_filter.cc +++ b/src/core/ext/filters/http/client/http_client_filter.cc @@ -289,7 +289,7 @@ static void hc_start_transport_stream_op_batch( grpc_call_element* elem, grpc_transport_stream_op_batch* batch) { call_data* calld = (call_data*)elem->call_data; channel_data* channeld = (channel_data*)elem->channel_data; - GPR_TIMER_BEGIN("hc_start_transport_stream_op_batch", 0); + GPR_TIMER_SCOPE("hc_start_transport_stream_op_batch", 0); if (batch->recv_initial_metadata) { /* substitute our callback for the higher callback */ @@ -404,7 +404,6 @@ done: } else if (!batch_will_be_handled_asynchronously) { grpc_call_next_op(elem, batch); } - GPR_TIMER_END("hc_start_transport_stream_op_batch", 0); } /* Constructor for call_data */ diff --git a/src/core/ext/filters/http/message_compress/message_compress_filter.cc b/src/core/ext/filters/http/message_compress/message_compress_filter.cc index 0218ec6e40..408301467c 100644 --- a/src/core/ext/filters/http/message_compress/message_compress_filter.cc +++ b/src/core/ext/filters/http/message_compress/message_compress_filter.cc @@ -347,8 +347,8 @@ static void start_send_message_batch(void* arg, grpc_error* unused) { static void compress_start_transport_stream_op_batch( grpc_call_element* elem, grpc_transport_stream_op_batch* batch) { + GPR_TIMER_SCOPE("compress_start_transport_stream_op_batch", 0); call_data* calld = (call_data*)elem->call_data; - GPR_TIMER_BEGIN("compress_start_transport_stream_op_batch", 0); // Handle cancel_stream. if (batch->cancel_stream) { GRPC_ERROR_UNREF(calld->cancel_error); @@ -371,7 +371,7 @@ static void compress_start_transport_stream_op_batch( } else if (calld->cancel_error != GRPC_ERROR_NONE) { grpc_transport_stream_op_batch_finish_with_failure( batch, GRPC_ERROR_REF(calld->cancel_error), calld->call_combiner); - goto done; + return; } // Handle send_initial_metadata. if (batch->send_initial_metadata) { @@ -383,7 +383,7 @@ static void compress_start_transport_stream_op_batch( if (error != GRPC_ERROR_NONE) { grpc_transport_stream_op_batch_finish_with_failure(batch, error, calld->call_combiner); - goto done; + return; } calld->send_initial_metadata_state = has_compression_algorithm ? HAS_COMPRESSION_ALGORITHM @@ -412,15 +412,13 @@ static void compress_start_transport_stream_op_batch( GRPC_CALL_COMBINER_STOP( calld->call_combiner, "send_message batch pending send_initial_metadata"); - goto done; + return; } start_send_message_batch(elem, GRPC_ERROR_NONE); } else { // Pass control down the stack. grpc_call_next_op(elem, batch); } -done: - GPR_TIMER_END("compress_start_transport_stream_op_batch", 0); } /* Constructor for call_data */ diff --git a/src/core/ext/filters/http/server/http_server_filter.cc b/src/core/ext/filters/http/server/http_server_filter.cc index 508a3bf9fc..6ea942f053 100644 --- a/src/core/ext/filters/http/server/http_server_filter.cc +++ b/src/core/ext/filters/http/server/http_server_filter.cc @@ -367,8 +367,8 @@ static grpc_error* hs_mutate_op(grpc_call_element* elem, static void hs_start_transport_stream_op_batch( grpc_call_element* elem, grpc_transport_stream_op_batch* op) { + GPR_TIMER_SCOPE("hs_start_transport_stream_op_batch", 0); call_data* calld = (call_data*)elem->call_data; - GPR_TIMER_BEGIN("hs_start_transport_stream_op_batch", 0); grpc_error* error = hs_mutate_op(elem, op); if (error != GRPC_ERROR_NONE) { grpc_transport_stream_op_batch_finish_with_failure(op, error, @@ -376,7 +376,6 @@ static void hs_start_transport_stream_op_batch( } else { grpc_call_next_op(elem, op); } - GPR_TIMER_END("hs_start_transport_stream_op_batch", 0); } /* Constructor for call_data */ diff --git a/src/core/ext/filters/load_reporting/server_load_reporting_filter.cc b/src/core/ext/filters/load_reporting/server_load_reporting_filter.cc index a414229768..4c87d9755e 100644 --- a/src/core/ext/filters/load_reporting/server_load_reporting_filter.cc +++ b/src/core/ext/filters/load_reporting/server_load_reporting_filter.cc @@ -184,7 +184,7 @@ static grpc_filtered_mdelem lr_trailing_md_filter(void* user_data, static void lr_start_transport_stream_op_batch( grpc_call_element* elem, grpc_transport_stream_op_batch* op) { - GPR_TIMER_BEGIN("lr_start_transport_stream_op_batch", 0); + GPR_TIMER_SCOPE("lr_start_transport_stream_op_batch", 0); call_data* calld = (call_data*)elem->call_data; if (op->recv_initial_metadata) { @@ -204,8 +204,6 @@ static void lr_start_transport_stream_op_batch( "LR trailing metadata filtering error")); } grpc_call_next_op(elem, op); - - GPR_TIMER_END("lr_start_transport_stream_op_batch", 0); } const grpc_channel_filter grpc_server_load_reporting_filter = { diff --git a/src/core/ext/transport/chttp2/transport/chttp2_transport.cc b/src/core/ext/transport/chttp2/transport/chttp2_transport.cc index 530ab17bc7..fe05e43960 100644 --- a/src/core/ext/transport/chttp2/transport/chttp2_transport.cc +++ b/src/core/ext/transport/chttp2/transport/chttp2_transport.cc @@ -656,7 +656,7 @@ void grpc_chttp2_stream_unref(grpc_chttp2_stream* s) { static int init_stream(grpc_transport* gt, grpc_stream* gs, grpc_stream_refcount* refcount, const void* server_data, gpr_arena* arena) { - GPR_TIMER_BEGIN("init_stream", 0); + GPR_TIMER_SCOPE("init_stream", 0); grpc_chttp2_transport* t = (grpc_chttp2_transport*)gt; grpc_chttp2_stream* s = (grpc_chttp2_stream*)gs; @@ -700,17 +700,15 @@ static int init_stream(grpc_transport* gt, grpc_stream* gs, } else { s->flow_control.Init<grpc_core::chttp2::StreamFlowControlDisabled>(); } - GPR_TIMER_END("init_stream", 0); return 0; } static void destroy_stream_locked(void* sp, grpc_error* error) { + GPR_TIMER_SCOPE("destroy_stream", 0); grpc_chttp2_stream* s = (grpc_chttp2_stream*)sp; grpc_chttp2_transport* t = s->t; - GPR_TIMER_BEGIN("destroy_stream", 0); - GPR_ASSERT((s->write_closed && s->read_closed) || s->id == 0); if (s->id != 0) { GPR_ASSERT(grpc_chttp2_stream_map_find(&t->stream_map, s->id) == nullptr); @@ -750,14 +748,12 @@ static void destroy_stream_locked(void* sp, grpc_error* error) { GRPC_CHTTP2_UNREF_TRANSPORT(t, "stream"); - GPR_TIMER_END("destroy_stream", 0); - GRPC_CLOSURE_SCHED(s->destroy_stream_arg, GRPC_ERROR_NONE); } static void destroy_stream(grpc_transport* gt, grpc_stream* gs, grpc_closure* then_schedule_closure) { - GPR_TIMER_BEGIN("destroy_stream", 0); + GPR_TIMER_SCOPE("destroy_stream", 0); grpc_chttp2_transport* t = (grpc_chttp2_transport*)gt; grpc_chttp2_stream* s = (grpc_chttp2_stream*)gs; @@ -775,7 +771,6 @@ static void destroy_stream(grpc_transport* gt, grpc_stream* gs, GRPC_CLOSURE_INIT(&s->destroy_stream, destroy_stream_locked, s, grpc_combiner_scheduler(t->combiner)), GRPC_ERROR_NONE); - GPR_TIMER_END("destroy_stream", 0); } grpc_chttp2_stream* grpc_chttp2_parsing_lookup_stream(grpc_chttp2_transport* t, @@ -898,7 +893,7 @@ static void inc_initiate_write_reason( void grpc_chttp2_initiate_write(grpc_chttp2_transport* t, grpc_chttp2_initiate_write_reason reason) { - GPR_TIMER_BEGIN("grpc_chttp2_initiate_write", 0); + GPR_TIMER_SCOPE("grpc_chttp2_initiate_write", 0); switch (t->write_state) { case GRPC_CHTTP2_WRITE_STATE_IDLE: @@ -920,7 +915,6 @@ void grpc_chttp2_initiate_write(grpc_chttp2_transport* t, case GRPC_CHTTP2_WRITE_STATE_WRITING_WITH_MORE: break; } - GPR_TIMER_END("grpc_chttp2_initiate_write", 0); } void grpc_chttp2_mark_stream_writable(grpc_chttp2_transport* t, @@ -974,7 +968,7 @@ static const char* begin_writing_desc(bool partial, bool inlined) { } static void write_action_begin_locked(void* gt, grpc_error* error_ignored) { - GPR_TIMER_BEGIN("write_action_begin_locked", 0); + GPR_TIMER_SCOPE("write_action_begin_locked", 0); grpc_chttp2_transport* t = (grpc_chttp2_transport*)gt; GPR_ASSERT(t->write_state != GRPC_CHTTP2_WRITE_STATE_IDLE); grpc_chttp2_begin_write_result r; @@ -1008,21 +1002,19 @@ static void write_action_begin_locked(void* gt, grpc_error* error_ignored) { set_write_state(t, GRPC_CHTTP2_WRITE_STATE_IDLE, "begin writing nothing"); GRPC_CHTTP2_UNREF_TRANSPORT(t, "writing"); } - GPR_TIMER_END("write_action_begin_locked", 0); } static void write_action(void* gt, grpc_error* error) { + GPR_TIMER_SCOPE("write_action", 0); grpc_chttp2_transport* t = (grpc_chttp2_transport*)gt; - GPR_TIMER_BEGIN("write_action", 0); grpc_endpoint_write( t->ep, &t->outbuf, GRPC_CLOSURE_INIT(&t->write_action_end_locked, write_action_end_locked, t, grpc_combiner_scheduler(t->combiner))); - GPR_TIMER_END("write_action", 0); } static void write_action_end_locked(void* tp, grpc_error* error) { - GPR_TIMER_BEGIN("terminate_writing_with_lock", 0); + GPR_TIMER_SCOPE("terminate_writing_with_lock", 0); grpc_chttp2_transport* t = (grpc_chttp2_transport*)tp; if (error != GRPC_ERROR_NONE) { @@ -1060,7 +1052,6 @@ static void write_action_end_locked(void* tp, grpc_error* error) { grpc_chttp2_end_write(t, GRPC_ERROR_REF(error)); GRPC_CHTTP2_UNREF_TRANSPORT(t, "writing"); - GPR_TIMER_END("terminate_writing_with_lock", 0); } // Dirties an HTTP2 setting to be sent out next time a writing path occurs. @@ -1335,7 +1326,7 @@ static void log_metadata(const grpc_metadata_batch* md_batch, uint32_t id, static void perform_stream_op_locked(void* stream_op, grpc_error* error_ignored) { - GPR_TIMER_BEGIN("perform_stream_op_locked", 0); + GPR_TIMER_SCOPE("perform_stream_op_locked", 0); grpc_transport_stream_op_batch* op = (grpc_transport_stream_op_batch*)stream_op; @@ -1609,13 +1600,12 @@ static void perform_stream_op_locked(void* stream_op, grpc_chttp2_complete_closure_step(t, s, &on_complete, GRPC_ERROR_NONE, "op->on_complete"); - GPR_TIMER_END("perform_stream_op_locked", 0); GRPC_CHTTP2_STREAM_UNREF(s, "perform_stream_op"); } static void perform_stream_op(grpc_transport* gt, grpc_stream* gs, grpc_transport_stream_op_batch* op) { - GPR_TIMER_BEGIN("perform_stream_op", 0); + GPR_TIMER_SCOPE("perform_stream_op", 0); grpc_chttp2_transport* t = (grpc_chttp2_transport*)gt; grpc_chttp2_stream* s = (grpc_chttp2_stream*)gs; @@ -1644,7 +1634,6 @@ static void perform_stream_op(grpc_transport* gt, grpc_stream* gs, GRPC_CLOSURE_INIT(&op->handler_private.closure, perform_stream_op_locked, op, grpc_combiner_scheduler(t->combiner)), GRPC_ERROR_NONE); - GPR_TIMER_END("perform_stream_op", 0); } static void cancel_pings(grpc_chttp2_transport* t, grpc_error* error) { @@ -2398,7 +2387,7 @@ static grpc_error* try_http_parsing(grpc_chttp2_transport* t) { } static void read_action_locked(void* tp, grpc_error* error) { - GPR_TIMER_BEGIN("reading_action_locked", 0); + GPR_TIMER_SCOPE("reading_action_locked", 0); grpc_chttp2_transport* t = (grpc_chttp2_transport*)tp; @@ -2414,7 +2403,7 @@ static void read_action_locked(void* tp, grpc_error* error) { GPR_SWAP(grpc_error*, err, error); GRPC_ERROR_UNREF(err); if (t->closed_with_error == GRPC_ERROR_NONE) { - GPR_TIMER_BEGIN("reading_action.parse", 0); + GPR_TIMER_SCOPE("reading_action.parse", 0); size_t i = 0; grpc_error* errors[3] = {GRPC_ERROR_REF(error), GRPC_ERROR_NONE, GRPC_ERROR_NONE}; @@ -2435,9 +2424,8 @@ static void read_action_locked(void* tp, grpc_error* error) { for (i = 0; i < GPR_ARRAY_SIZE(errors); i++) { GRPC_ERROR_UNREF(errors[i]); } - GPR_TIMER_END("reading_action.parse", 0); - GPR_TIMER_BEGIN("post_parse_locked", 0); + GPR_TIMER_SCOPE("post_parse_locked", 0); if (t->initial_window_update != 0) { if (t->initial_window_update > 0) { grpc_chttp2_stream* s; @@ -2449,10 +2437,9 @@ static void read_action_locked(void* tp, grpc_error* error) { } t->initial_window_update = 0; } - GPR_TIMER_END("post_parse_locked", 0); } - GPR_TIMER_BEGIN("post_reading_action_locked", 0); + GPR_TIMER_SCOPE("post_reading_action_locked", 0); bool keep_reading = false; if (error == GRPC_ERROR_NONE && t->closed_with_error != GRPC_ERROR_NONE) { error = GRPC_ERROR_CREATE_REFERENCING_FROM_STATIC_STRING( @@ -2482,11 +2469,7 @@ static void read_action_locked(void* tp, grpc_error* error) { GRPC_CHTTP2_UNREF_TRANSPORT(t, "reading_action"); } - GPR_TIMER_END("post_reading_action_locked", 0); - GRPC_ERROR_UNREF(error); - - GPR_TIMER_END("reading_action_locked", 0); } // t is reffed prior to calling the first time, and once the callback chain @@ -2786,12 +2769,11 @@ static void incoming_byte_stream_next_locked(void* argp, static bool incoming_byte_stream_next(grpc_byte_stream* byte_stream, size_t max_size_hint, grpc_closure* on_complete) { - GPR_TIMER_BEGIN("incoming_byte_stream_next", 0); + GPR_TIMER_SCOPE("incoming_byte_stream_next", 0); grpc_chttp2_incoming_byte_stream* bs = (grpc_chttp2_incoming_byte_stream*)byte_stream; grpc_chttp2_stream* s = bs->stream; if (s->unprocessed_incoming_frames_buffer.length > 0) { - GPR_TIMER_END("incoming_byte_stream_next", 0); return true; } else { gpr_ref(&bs->refs); @@ -2802,14 +2784,13 @@ static bool incoming_byte_stream_next(grpc_byte_stream* byte_stream, incoming_byte_stream_next_locked, bs, grpc_combiner_scheduler(bs->transport->combiner)), GRPC_ERROR_NONE); - GPR_TIMER_END("incoming_byte_stream_next", 0); return false; } } static grpc_error* incoming_byte_stream_pull(grpc_byte_stream* byte_stream, grpc_slice* slice) { - GPR_TIMER_BEGIN("incoming_byte_stream_pull", 0); + GPR_TIMER_SCOPE("incoming_byte_stream_pull", 0); grpc_chttp2_incoming_byte_stream* bs = (grpc_chttp2_incoming_byte_stream*)byte_stream; grpc_chttp2_stream* s = bs->stream; @@ -2853,7 +2834,6 @@ static grpc_error* incoming_byte_stream_pull(grpc_byte_stream* byte_stream, GRPC_CLOSURE_SCHED(&s->reset_byte_stream, GRPC_ERROR_REF(error)); return error; } - GPR_TIMER_END("incoming_byte_stream_pull", 0); return GRPC_ERROR_NONE; } @@ -2861,7 +2841,7 @@ static void incoming_byte_stream_destroy_locked(void* byte_stream, grpc_error* error_ignored); static void incoming_byte_stream_destroy(grpc_byte_stream* byte_stream) { - GPR_TIMER_BEGIN("incoming_byte_stream_destroy", 0); + GPR_TIMER_SCOPE("incoming_byte_stream_destroy", 0); grpc_chttp2_incoming_byte_stream* bs = (grpc_chttp2_incoming_byte_stream*)byte_stream; GRPC_CLOSURE_SCHED( @@ -2869,7 +2849,6 @@ static void incoming_byte_stream_destroy(grpc_byte_stream* byte_stream) { incoming_byte_stream_destroy_locked, bs, grpc_combiner_scheduler(bs->transport->combiner)), GRPC_ERROR_NONE); - GPR_TIMER_END("incoming_byte_stream_destroy", 0); } static void incoming_byte_stream_publish_error( diff --git a/src/core/ext/transport/chttp2/transport/hpack_parser.cc b/src/core/ext/transport/chttp2/transport/hpack_parser.cc index ebee5913cb..8d1c57a9cb 100644 --- a/src/core/ext/transport/chttp2/transport/hpack_parser.cc +++ b/src/core/ext/transport/chttp2/transport/hpack_parser.cc @@ -1618,19 +1618,17 @@ grpc_error* grpc_chttp2_header_parser_parse(void* hpack_parser, grpc_chttp2_transport* t, grpc_chttp2_stream* s, grpc_slice slice, int is_last) { + GPR_TIMER_SCOPE("grpc_chttp2_hpack_parser_parse", 0); grpc_chttp2_hpack_parser* parser = (grpc_chttp2_hpack_parser*)hpack_parser; - GPR_TIMER_BEGIN("grpc_chttp2_hpack_parser_parse", 0); if (s != nullptr) { s->stats.incoming.header_bytes += GRPC_SLICE_LENGTH(slice); } grpc_error* error = grpc_chttp2_hpack_parser_parse(parser, slice); if (error != GRPC_ERROR_NONE) { - GPR_TIMER_END("grpc_chttp2_hpack_parser_parse", 0); return error; } if (is_last) { if (parser->is_boundary && parser->state != parse_begin) { - GPR_TIMER_END("grpc_chttp2_hpack_parser_parse", 0); return GRPC_ERROR_CREATE_FROM_STATIC_STRING( "end of header frame not aligned with a hpack record boundary"); } @@ -1639,7 +1637,6 @@ grpc_error* grpc_chttp2_header_parser_parse(void* hpack_parser, if (s != nullptr) { if (parser->is_boundary) { if (s->header_frames_received == GPR_ARRAY_SIZE(s->metadata_buffer)) { - GPR_TIMER_END("grpc_chttp2_hpack_parser_parse", 0); return GRPC_ERROR_CREATE_FROM_STATIC_STRING( "Too many trailer frames"); } @@ -1674,6 +1671,5 @@ grpc_error* grpc_chttp2_header_parser_parse(void* hpack_parser, parser->is_eof = 0xde; parser->dynamic_table_update_allowed = 2; } - GPR_TIMER_END("grpc_chttp2_hpack_parser_parse", 0); return GRPC_ERROR_NONE; } diff --git a/src/core/ext/transport/chttp2/transport/parsing.cc b/src/core/ext/transport/chttp2/transport/parsing.cc index 59dc38ef98..fb6d30b62d 100644 --- a/src/core/ext/transport/chttp2/transport/parsing.cc +++ b/src/core/ext/transport/chttp2/transport/parsing.cc @@ -392,11 +392,10 @@ error_handler: static void free_timeout(void* p) { gpr_free(p); } static void on_initial_header(void* tp, grpc_mdelem md) { + GPR_TIMER_SCOPE("on_initial_header", 0); + grpc_chttp2_transport* t = (grpc_chttp2_transport*)tp; grpc_chttp2_stream* s = t->incoming_stream; - - GPR_TIMER_BEGIN("on_initial_header", 0); - GPR_ASSERT(s != nullptr); if (grpc_http_trace.enabled()) { @@ -470,16 +469,13 @@ static void on_initial_header(void* tp, grpc_mdelem md) { } } } - - GPR_TIMER_END("on_initial_header", 0); } static void on_trailing_header(void* tp, grpc_mdelem md) { + GPR_TIMER_SCOPE("on_trailing_header", 0); + grpc_chttp2_transport* t = (grpc_chttp2_transport*)tp; grpc_chttp2_stream* s = t->incoming_stream; - - GPR_TIMER_BEGIN("on_trailing_header", 0); - GPR_ASSERT(s != nullptr); if (grpc_http_trace.enabled()) { @@ -526,8 +522,6 @@ static void on_trailing_header(void* tp, grpc_mdelem md) { GRPC_MDELEM_UNREF(md); } } - - GPR_TIMER_END("on_trailing_header", 0); } static grpc_error* init_header_frame_parser(grpc_chttp2_transport* t, diff --git a/src/core/ext/transport/chttp2/transport/writing.cc b/src/core/ext/transport/chttp2/transport/writing.cc index 9a6f5e9bcf..95358ab525 100644 --- a/src/core/ext/transport/chttp2/transport/writing.cc +++ b/src/core/ext/transport/chttp2/transport/writing.cc @@ -180,7 +180,7 @@ class WriteContext { public: WriteContext(grpc_chttp2_transport* t) : t_(t) { GRPC_STATS_INC_HTTP2_WRITES_BEGUN(); - GPR_TIMER_BEGIN("grpc_chttp2_begin_write", 0); + GPR_TIMER_SCOPE("grpc_chttp2_begin_write", 0); } // TODO(ctiller): make this the destructor @@ -614,13 +614,11 @@ grpc_chttp2_begin_write_result grpc_chttp2_begin_write( maybe_initiate_ping(t); - GPR_TIMER_END("grpc_chttp2_begin_write", 0); - return ctx.Result(); } void grpc_chttp2_end_write(grpc_chttp2_transport* t, grpc_error* error) { - GPR_TIMER_BEGIN("grpc_chttp2_end_write", 0); + GPR_TIMER_SCOPE("grpc_chttp2_end_write", 0); grpc_chttp2_stream* s; while (grpc_chttp2_list_pop_writing_stream(t, &s)) { @@ -633,5 +631,4 @@ void grpc_chttp2_end_write(grpc_chttp2_transport* t, grpc_error* error) { } grpc_slice_buffer_reset_and_unref_internal(&t->outbuf); GRPC_ERROR_UNREF(error); - GPR_TIMER_END("grpc_chttp2_end_write", 0); } diff --git a/src/core/lib/gpr/alloc.cc b/src/core/lib/gpr/alloc.cc index 000b7dcb25..b1d1550630 100644 --- a/src/core/lib/gpr/alloc.cc +++ b/src/core/lib/gpr/alloc.cc @@ -50,43 +50,39 @@ void gpr_set_allocation_functions(gpr_allocation_functions functions) { } void* gpr_malloc(size_t size) { + GPR_TIMER_SCOPE("gpr_malloc", 0); void* p; if (size == 0) return nullptr; - GPR_TIMER_BEGIN("gpr_malloc", 0); p = g_alloc_functions.malloc_fn(size); if (!p) { abort(); } - GPR_TIMER_END("gpr_malloc", 0); return p; } void* gpr_zalloc(size_t size) { + GPR_TIMER_SCOPE("gpr_zalloc", 0); void* p; if (size == 0) return nullptr; - GPR_TIMER_BEGIN("gpr_zalloc", 0); p = g_alloc_functions.zalloc_fn(size); if (!p) { abort(); } - GPR_TIMER_END("gpr_zalloc", 0); return p; } void gpr_free(void* p) { - GPR_TIMER_BEGIN("gpr_free", 0); + GPR_TIMER_SCOPE("gpr_free", 0); g_alloc_functions.free_fn(p); - GPR_TIMER_END("gpr_free", 0); } void* gpr_realloc(void* p, size_t size) { + GPR_TIMER_SCOPE("gpr_realloc", 0); if ((size == 0) && (p == nullptr)) return nullptr; - GPR_TIMER_BEGIN("gpr_realloc", 0); p = g_alloc_functions.realloc_fn(p, size); if (!p) { abort(); } - GPR_TIMER_END("gpr_realloc", 0); return p; } diff --git a/src/core/lib/gpr/sync_posix.cc b/src/core/lib/gpr/sync_posix.cc index c3f6b10463..f23a8b2486 100644 --- a/src/core/lib/gpr/sync_posix.cc +++ b/src/core/lib/gpr/sync_posix.cc @@ -43,23 +43,19 @@ void gpr_mu_lock(gpr_mu* mu) { #ifdef GPR_LOW_LEVEL_COUNTERS GPR_ATM_INC_COUNTER(gpr_mu_locks); #endif - GPR_TIMER_BEGIN("gpr_mu_lock", 0); + GPR_TIMER_SCOPE("gpr_mu_lock", 0); GPR_ASSERT(pthread_mutex_lock(mu) == 0); - GPR_TIMER_END("gpr_mu_lock", 0); } void gpr_mu_unlock(gpr_mu* mu) { - GPR_TIMER_BEGIN("gpr_mu_unlock", 0); + GPR_TIMER_SCOPE("gpr_mu_unlock", 0); GPR_ASSERT(pthread_mutex_unlock(mu) == 0); - GPR_TIMER_END("gpr_mu_unlock", 0); } int gpr_mu_trylock(gpr_mu* mu) { - int err; - GPR_TIMER_BEGIN("gpr_mu_trylock", 0); - err = pthread_mutex_trylock(mu); + GPR_TIMER_SCOPE("gpr_mu_trylock", 0); + int err = pthread_mutex_trylock(mu); GPR_ASSERT(err == 0 || err == EBUSY); - GPR_TIMER_END("gpr_mu_trylock", 0); return err == 0; } 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; } diff --git a/src/core/lib/profiling/timers.h b/src/core/lib/profiling/timers.h index 9f11f771e6..d0188b5054 100644 --- a/src/core/lib/profiling/timers.h +++ b/src/core/lib/profiling/timers.h @@ -40,14 +40,10 @@ void gpr_timer_set_enabled(int enabled); do { \ } while (0) -#define GPR_TIMER_BEGIN(tag, important) \ +#define GPR_TIMER_SCOPE(tag, important) \ do { \ } while (0) -#define GPR_TIMER_END(tag, important) \ - do { \ - } while (0) - #else /* at least one profiler requested... */ /* ... hopefully only one. */ #if defined(GRPC_STAP_PROFILER) && defined(GRPC_BASIC_PROFILER) @@ -64,12 +60,6 @@ void gpr_timer_set_enabled(int enabled); #define GPR_TIMER_MARK(tag, important) \ gpr_timer_add_mark(tag, important, __FILE__, __LINE__); -#define GPR_TIMER_BEGIN(tag, important) \ - gpr_timer_begin(tag, important, __FILE__, __LINE__); - -#define GPR_TIMER_END(tag, important) \ - gpr_timer_end(tag, important, __FILE__, __LINE__); - #ifdef GRPC_STAP_PROFILER /* Empty placeholder for now. */ #endif /* GRPC_STAP_PROFILER */ @@ -78,10 +68,6 @@ void gpr_timer_set_enabled(int enabled); /* Empty placeholder for now. */ #endif /* GRPC_BASIC_PROFILER */ -#endif /* at least one profiler requested. */ - -#if (defined(GRPC_STAP_PROFILER) + defined(GRPC_BASIC_PROFILER) + \ - defined(GRPC_CUSTOM_PROFILER)) namespace grpc { class ProfileScope { public: @@ -99,10 +85,7 @@ class ProfileScope { #define GPR_TIMER_SCOPE(tag, important) \ ::grpc::ProfileScope _profile_scope_##__LINE__((tag), (important), __FILE__, \ __LINE__) -#else -#define GPR_TIMER_SCOPE(tag, important) \ - do { \ - } while (false) -#endif + +#endif /* at least one profiler requested. */ #endif /* GRPC_CORE_LIB_PROFILING_TIMERS_H */ diff --git a/src/core/lib/security/transport/client_auth_filter.cc b/src/core/lib/security/transport/client_auth_filter.cc index 045cb3e239..16814d2598 100644 --- a/src/core/lib/security/transport/client_auth_filter.cc +++ b/src/core/lib/security/transport/client_auth_filter.cc @@ -266,7 +266,7 @@ static void cancel_check_call_host(void* arg, grpc_error* error) { static void auth_start_transport_stream_op_batch( grpc_call_element* elem, grpc_transport_stream_op_batch* batch) { - GPR_TIMER_BEGIN("auth_start_transport_stream_op_batch", 0); + GPR_TIMER_SCOPE("auth_start_transport_stream_op_batch", 0); /* grab pointers to our data from the call element */ call_data* calld = (call_data*)elem->call_data; @@ -332,14 +332,12 @@ static void auth_start_transport_stream_op_batch( grpc_schedule_on_exec_ctx)); } gpr_free(call_host); - GPR_TIMER_END("auth_start_transport_stream_op_batch", 0); return; /* early exit */ } } /* pass control down the stack */ grpc_call_next_op(elem, batch); - GPR_TIMER_END("auth_start_transport_stream_op_batch", 0); } /* Constructor for call_data */ diff --git a/src/core/lib/security/transport/secure_endpoint.cc b/src/core/lib/security/transport/secure_endpoint.cc index bd8a6cd76a..9eaa299897 100644 --- a/src/core/lib/security/transport/secure_endpoint.cc +++ b/src/core/lib/security/transport/secure_endpoint.cc @@ -252,7 +252,7 @@ static void flush_write_staging_buffer(secure_endpoint* ep, uint8_t** cur, static void endpoint_write(grpc_endpoint* secure_ep, grpc_slice_buffer* slices, grpc_closure* cb) { - GPR_TIMER_BEGIN("secure_endpoint.endpoint_write", 0); + GPR_TIMER_SCOPE("secure_endpoint.endpoint_write", 0); unsigned i; tsi_result result = TSI_OK; @@ -336,12 +336,10 @@ static void endpoint_write(grpc_endpoint* secure_ep, grpc_slice_buffer* slices, GRPC_CLOSURE_SCHED( cb, grpc_set_tsi_error_result( GRPC_ERROR_CREATE_FROM_STATIC_STRING("Wrap failed"), result)); - GPR_TIMER_END("secure_endpoint.endpoint_write", 0); return; } grpc_endpoint_write(ep->wrapped_ep, &ep->output_buffer, cb); - GPR_TIMER_END("secure_endpoint.endpoint_write", 0); } static void endpoint_shutdown(grpc_endpoint* secure_ep, grpc_error* why) { diff --git a/src/core/lib/slice/slice_intern.cc b/src/core/lib/slice/slice_intern.cc index fe1770b92c..cf471f30f8 100644 --- a/src/core/lib/slice/slice_intern.cc +++ b/src/core/lib/slice/slice_intern.cc @@ -122,13 +122,13 @@ static const grpc_slice_refcount_vtable interned_slice_sub_vtable = { grpc_slice_default_eq_impl, grpc_slice_default_hash_impl}; static void grow_shard(slice_shard* shard) { + GPR_TIMER_SCOPE("grow_strtab", 0); + size_t capacity = shard->capacity * 2; size_t i; interned_slice_refcount** strtab; interned_slice_refcount *s, *next; - GPR_TIMER_BEGIN("grow_strtab", 0); - strtab = (interned_slice_refcount**)gpr_zalloc( sizeof(interned_slice_refcount*) * capacity); @@ -140,12 +140,9 @@ static void grow_shard(slice_shard* shard) { strtab[idx] = s; } } - gpr_free(shard->strs); shard->strs = strtab; shard->capacity = capacity; - - GPR_TIMER_END("grow_strtab", 0); } static grpc_slice materialize(interned_slice_refcount* s) { @@ -200,9 +197,8 @@ bool grpc_slice_is_interned(grpc_slice slice) { } grpc_slice grpc_slice_intern(grpc_slice slice) { - GPR_TIMER_BEGIN("grpc_slice_intern", 0); + GPR_TIMER_SCOPE("grpc_slice_intern", 0); if (GRPC_IS_STATIC_METADATA_STRING(slice)) { - GPR_TIMER_END("grpc_slice_intern", 0); return slice; } @@ -212,7 +208,6 @@ grpc_slice grpc_slice_intern(grpc_slice slice) { static_metadata_hash[(hash + i) % GPR_ARRAY_SIZE(static_metadata_hash)]; if (ent.hash == hash && ent.idx < GRPC_STATIC_MDSTR_COUNT && grpc_slice_eq(grpc_static_slice_table[ent.idx], slice)) { - GPR_TIMER_END("grpc_slice_intern", 0); return grpc_static_slice_table[ent.idx]; } } @@ -235,7 +230,6 @@ grpc_slice grpc_slice_intern(grpc_slice slice) { /* and treat this as if we were never here... sshhh */ } else { gpr_mu_unlock(&shard->mu); - GPR_TIMER_END("grpc_slice_intern", 0); return materialize(s); } } @@ -264,7 +258,6 @@ grpc_slice grpc_slice_intern(grpc_slice slice) { gpr_mu_unlock(&shard->mu); - GPR_TIMER_END("grpc_slice_intern", 0); return materialize(s); } diff --git a/src/core/lib/surface/alarm.cc b/src/core/lib/surface/alarm.cc deleted file mode 100644 index f6ea016c33..0000000000 --- a/src/core/lib/surface/alarm.cc +++ /dev/null @@ -1,137 +0,0 @@ -/* - * - * Copyright 2015 gRPC authors. - * - * Licensed under the Apache License, Version 2.0 (the "License"); - * you may not use this file except in compliance with the License. - * You may obtain a copy of the License at - * - * http://www.apache.org/licenses/LICENSE-2.0 - * - * Unless required by applicable law or agreed to in writing, software - * distributed under the License is distributed on an "AS IS" BASIS, - * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. - * See the License for the specific language governing permissions and - * limitations under the License. - * - */ -#include <grpc/support/port_platform.h> - -#include <inttypes.h> - -#include "src/core/lib/surface/alarm_internal.h" - -#include <grpc/grpc.h> -#include <grpc/support/alloc.h> -#include <grpc/support/log.h> -#include "src/core/lib/iomgr/timer.h" -#include "src/core/lib/surface/completion_queue.h" - -grpc_core::DebugOnlyTraceFlag grpc_trace_alarm_refcount(false, - "alarm_refcount"); - -struct grpc_alarm { - gpr_refcount refs; - grpc_timer alarm; - grpc_closure on_alarm; - grpc_cq_completion completion; - /** completion queue where events about this alarm will be posted */ - grpc_completion_queue* cq; - /** user supplied tag */ - void* tag; -}; - -static void alarm_ref(grpc_alarm* alarm) { gpr_ref(&alarm->refs); } - -static void alarm_unref(grpc_alarm* alarm) { - if (gpr_unref(&alarm->refs)) { - grpc_core::ExecCtx exec_ctx; - if (alarm->cq != nullptr) { - GRPC_CQ_INTERNAL_UNREF(alarm->cq, "alarm"); - } - - gpr_free(alarm); - } -} - -#ifndef NDEBUG -static void alarm_ref_dbg(grpc_alarm* alarm, const char* reason, - const char* file, int line) { - if (grpc_trace_alarm_refcount.enabled()) { - gpr_atm val = gpr_atm_no_barrier_load(&alarm->refs.count); - gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, - "Alarm:%p ref %" PRIdPTR " -> %" PRIdPTR " %s", alarm, val, - val + 1, reason); - } - - alarm_ref(alarm); -} - -static void alarm_unref_dbg(grpc_alarm* alarm, const char* reason, - const char* file, int line) { - if (grpc_trace_alarm_refcount.enabled()) { - gpr_atm val = gpr_atm_no_barrier_load(&alarm->refs.count); - gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, - "Alarm:%p Unref %" PRIdPTR " -> %" PRIdPTR " %s", alarm, val, - val - 1, reason); - } - - alarm_unref(alarm); -} -#endif - -static void alarm_end_completion(void* arg, grpc_cq_completion* c) { - grpc_alarm* alarm = (grpc_alarm*)arg; - GRPC_ALARM_UNREF(alarm, "dequeue-end-op"); -} - -static void alarm_cb(void* arg, grpc_error* error) { - grpc_alarm* alarm = (grpc_alarm*)arg; - - /* We are queuing an op on completion queue. This means, the alarm's structure - cannot be destroyed until the op is dequeued. Adding an extra ref - here and unref'ing when the op is dequeued will achieve this */ - GRPC_ALARM_REF(alarm, "queue-end-op"); - grpc_cq_end_op(alarm->cq, alarm->tag, error, alarm_end_completion, - (void*)alarm, &alarm->completion); -} - -grpc_alarm* grpc_alarm_create(void* reserved) { - grpc_alarm* alarm = (grpc_alarm*)gpr_malloc(sizeof(grpc_alarm)); - -#ifndef NDEBUG - if (grpc_trace_alarm_refcount.enabled()) { - gpr_log(GPR_DEBUG, "Alarm:%p created (ref: 1)", alarm); - } -#endif - - gpr_ref_init(&alarm->refs, 1); - grpc_timer_init_unset(&alarm->alarm); - alarm->cq = nullptr; - GRPC_CLOSURE_INIT(&alarm->on_alarm, alarm_cb, alarm, - grpc_schedule_on_exec_ctx); - return alarm; -} - -void grpc_alarm_set(grpc_alarm* alarm, grpc_completion_queue* cq, - gpr_timespec deadline, void* tag, void* reserved) { - grpc_core::ExecCtx exec_ctx; - - GRPC_CQ_INTERNAL_REF(cq, "alarm"); - alarm->cq = cq; - alarm->tag = tag; - - GPR_ASSERT(grpc_cq_begin_op(cq, tag)); - grpc_timer_init(&alarm->alarm, grpc_timespec_to_millis_round_up(deadline), - &alarm->on_alarm); -} - -void grpc_alarm_cancel(grpc_alarm* alarm, void* reserved) { - grpc_core::ExecCtx exec_ctx; - grpc_timer_cancel(&alarm->alarm); -} - -void grpc_alarm_destroy(grpc_alarm* alarm, void* reserved) { - grpc_alarm_cancel(alarm, reserved); - GRPC_ALARM_UNREF(alarm, "alarm_destroy"); -} diff --git a/src/core/lib/surface/alarm_internal.h b/src/core/lib/surface/alarm_internal.h deleted file mode 100644 index 99e981234d..0000000000 --- a/src/core/lib/surface/alarm_internal.h +++ /dev/null @@ -1,40 +0,0 @@ -/* - * - * Copyright 2015-2017 gRPC authors. - * - * Licensed under the Apache License, Version 2.0 (the "License"); - * you may not use this file except in compliance with the License. - * You may obtain a copy of the License at - * - * http://www.apache.org/licenses/LICENSE-2.0 - * - * Unless required by applicable law or agreed to in writing, software - * distributed under the License is distributed on an "AS IS" BASIS, - * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. - * See the License for the specific language governing permissions and - * limitations under the License. - * - */ - -#ifndef GRPC_CORE_LIB_SURFACE_ALARM_INTERNAL_H -#define GRPC_CORE_LIB_SURFACE_ALARM_INTERNAL_H - -#include <grpc/support/log.h> -#include "src/core/lib/debug/trace.h" - -extern grpc_core::DebugOnlyTraceFlag grpc_trace_alarm_refcount; - -#ifndef NDEBUG - -#define GRPC_ALARM_REF(a, reason) alarm_ref_dbg(a, reason, __FILE__, __LINE__) -#define GRPC_ALARM_UNREF(a, reason) \ - alarm_unref_dbg(a, reason, __FILE__, __LINE__) - -#else /* !defined(NDEBUG) */ - -#define GRPC_ALARM_REF(a, reason) alarm_ref(a) -#define GRPC_ALARM_UNREF(a, reason) alarm_unref(a) - -#endif /* defined(NDEBUG) */ - -#endif /* GRPC_CORE_LIB_SURFACE_ALARM_INTERNAL_H */ diff --git a/src/core/lib/surface/call.cc b/src/core/lib/surface/call.cc index ce63fa4d67..f2096d8937 100644 --- a/src/core/lib/surface/call.cc +++ b/src/core/lib/surface/call.cc @@ -321,12 +321,12 @@ static parent_call* get_parent_call(grpc_call* call) { grpc_error* grpc_call_create(const grpc_call_create_args* args, grpc_call** out_call) { + GPR_TIMER_SCOPE("grpc_call_create", 0); size_t i, j; grpc_error* error = GRPC_ERROR_NONE; grpc_channel_stack* channel_stack = grpc_channel_get_channel_stack(args->channel); grpc_call* call; - GPR_TIMER_BEGIN("grpc_call_create", 0); size_t initial_size = grpc_channel_get_call_size_estimate(args->channel); GRPC_STATS_INC_CALL_INITIAL_SIZE(initial_size); gpr_arena* arena = gpr_arena_create(initial_size); @@ -467,7 +467,6 @@ grpc_error* grpc_call_create(const grpc_call_create_args* args, grpc_slice_unref_internal(path); - GPR_TIMER_END("grpc_call_create", 0); return error; } @@ -511,10 +510,10 @@ static void release_call(void* call, grpc_error* error) { static void set_status_value_directly(grpc_status_code status, void* dest); static void destroy_call(void* call, grpc_error* error) { + GPR_TIMER_SCOPE("destroy_call", 0); size_t i; int ii; grpc_call* c = (grpc_call*)call; - GPR_TIMER_BEGIN("destroy_call", 0); for (i = 0; i < 2; i++) { grpc_metadata_batch_destroy( &c->metadata_batch[1 /* is_receiving */][i /* is_initial */]); @@ -551,7 +550,6 @@ static void destroy_call(void* call, grpc_error* error) { grpc_call_stack_destroy(CALL_STACK_FROM_CALL(c), &c->final_info, GRPC_CLOSURE_INIT(&c->release_call, release_call, c, grpc_schedule_on_exec_ctx)); - GPR_TIMER_END("destroy_call", 0); } void grpc_call_ref(grpc_call* c) { gpr_ref(&c->ext_ref); } @@ -559,10 +557,11 @@ void grpc_call_ref(grpc_call* c) { gpr_ref(&c->ext_ref); } void grpc_call_unref(grpc_call* c) { if (!gpr_unref(&c->ext_ref)) return; + GPR_TIMER_SCOPE("grpc_call_unref", 0); + child_call* cc = c->child; grpc_core::ExecCtx exec_ctx; - GPR_TIMER_BEGIN("grpc_call_unref", 0); GRPC_API_TRACE("grpc_call_unref(c=%p)", 1, (c)); if (cc) { @@ -594,8 +593,6 @@ void grpc_call_unref(grpc_call* c) { grpc_call_combiner_set_notify_on_cancel(&c->call_combiner, nullptr); } GRPC_CALL_INTERNAL_UNREF(c, "destroy"); - - GPR_TIMER_END("grpc_call_unref", 0); } grpc_call_error grpc_call_cancel(grpc_call* call, void* reserved) { @@ -610,13 +607,12 @@ grpc_call_error grpc_call_cancel(grpc_call* call, void* reserved) { // This is called via the call combiner to start sending a batch down // the filter stack. static void execute_batch_in_call_combiner(void* arg, grpc_error* ignored) { + GPR_TIMER_SCOPE("execute_batch", 0); grpc_transport_stream_op_batch* batch = (grpc_transport_stream_op_batch*)arg; grpc_call* call = (grpc_call*)batch->handler_private.extra_arg; - GPR_TIMER_BEGIN("execute_batch", 0); grpc_call_element* elem = CALL_ELEM_FROM_CALL(call, 0); GRPC_CALL_LOG_OP(GPR_INFO, elem, batch); elem->filter->start_transport_stream_op_batch(elem, batch); - GPR_TIMER_END("execute_batch", 0); } // start_batch_closure points to a caller-allocated closure to be used @@ -1036,7 +1032,7 @@ static grpc_stream_compression_algorithm decode_stream_compression( static void publish_app_metadata(grpc_call* call, grpc_metadata_batch* b, int is_trailing) { if (b->list.count == 0) return; - GPR_TIMER_BEGIN("publish_app_metadata", 0); + GPR_TIMER_SCOPE("publish_app_metadata", 0); grpc_metadata_array* dest; grpc_metadata* mdusr; dest = call->buffered_metadata[is_trailing]; @@ -1052,39 +1048,34 @@ static void publish_app_metadata(grpc_call* call, grpc_metadata_batch* b, mdusr->key = GRPC_MDKEY(l->md); mdusr->value = GRPC_MDVALUE(l->md); } - GPR_TIMER_END("publish_app_metadata", 0); } static void recv_initial_filter(grpc_call* call, grpc_metadata_batch* b) { if (b->idx.named.content_encoding != nullptr) { - GPR_TIMER_BEGIN("incoming_stream_compression_algorithm", 0); + GPR_TIMER_SCOPE("incoming_stream_compression_algorithm", 0); set_incoming_stream_compression_algorithm( call, decode_stream_compression(b->idx.named.content_encoding->md)); - GPR_TIMER_END("incoming_stream_compression_algorithm", 0); grpc_metadata_batch_remove(b, b->idx.named.content_encoding); } if (b->idx.named.grpc_encoding != nullptr) { - GPR_TIMER_BEGIN("incoming_message_compression_algorithm", 0); + GPR_TIMER_SCOPE("incoming_message_compression_algorithm", 0); set_incoming_message_compression_algorithm( call, decode_message_compression(b->idx.named.grpc_encoding->md)); - GPR_TIMER_END("incoming_message_compression_algorithm", 0); grpc_metadata_batch_remove(b, b->idx.named.grpc_encoding); } uint32_t message_encodings_accepted_by_peer = 1u; uint32_t stream_encodings_accepted_by_peer = 1u; if (b->idx.named.grpc_accept_encoding != nullptr) { - GPR_TIMER_BEGIN("encodings_accepted_by_peer", 0); + GPR_TIMER_SCOPE("encodings_accepted_by_peer", 0); set_encodings_accepted_by_peer(call, b->idx.named.grpc_accept_encoding->md, &message_encodings_accepted_by_peer, false); grpc_metadata_batch_remove(b, b->idx.named.grpc_accept_encoding); - GPR_TIMER_END("encodings_accepted_by_peer", 0); } if (b->idx.named.accept_encoding != nullptr) { - GPR_TIMER_BEGIN("stream_encodings_accepted_by_peer", 0); + GPR_TIMER_SCOPE("stream_encodings_accepted_by_peer", 0); set_encodings_accepted_by_peer(call, b->idx.named.accept_encoding->md, &stream_encodings_accepted_by_peer, true); grpc_metadata_batch_remove(b, b->idx.named.accept_encoding); - GPR_TIMER_END("stream_encodings_accepted_by_peer", 0); } call->encodings_accepted_by_peer = grpc_compression_bitset_from_message_stream_compression_bitset( @@ -1523,9 +1514,8 @@ static void receiving_initial_metadata_ready(void* bctlp, grpc_error* error) { recv_initial_filter(call, md); /* TODO(ctiller): this could be moved into recv_initial_filter now */ - GPR_TIMER_BEGIN("validate_filtered_metadata", 0); + GPR_TIMER_SCOPE("validate_filtered_metadata", 0); validate_filtered_metadata(bctl); - GPR_TIMER_END("validate_filtered_metadata", 0); if (md->deadline != GRPC_MILLIS_INF_FUTURE && !call->is_client) { call->send_deadline = md->deadline; @@ -1578,6 +1568,8 @@ static void free_no_op_completion(void* p, grpc_cq_completion* completion) { static grpc_call_error call_start_batch(grpc_call* call, const grpc_op* ops, size_t nops, void* notify_tag, int is_notify_tag_closure) { + GPR_TIMER_SCOPE("grpc_call_start_batch", 0); + size_t i; const grpc_op* op; batch_control* bctl; @@ -1586,7 +1578,6 @@ static grpc_call_error call_start_batch(grpc_call* call, const grpc_op* ops, grpc_transport_stream_op_batch* stream_op; grpc_transport_stream_op_batch_payload* stream_op_payload; - GPR_TIMER_BEGIN("grpc_call_start_batch", 0); GRPC_CALL_LOG_BATCH(GPR_INFO, call, ops, nops, notify_tag); if (nops == 0) { @@ -1923,7 +1914,6 @@ static grpc_call_error call_start_batch(grpc_call* call, const grpc_op* ops, execute_batch(call, stream_op, &bctl->start_batch); done: - GPR_TIMER_END("grpc_call_start_batch", 0); return error; done_with_error: diff --git a/src/core/lib/surface/completion_queue.cc b/src/core/lib/surface/completion_queue.cc index e731e2139f..8362522fa1 100644 --- a/src/core/lib/surface/completion_queue.cc +++ b/src/core/lib/surface/completion_queue.cc @@ -421,9 +421,9 @@ static long cq_event_queue_num_items(grpc_cq_event_queue* q) { grpc_completion_queue* grpc_completion_queue_create_internal( grpc_cq_completion_type completion_type, grpc_cq_polling_type polling_type) { - grpc_completion_queue* cq; + GPR_TIMER_SCOPE("grpc_completion_queue_create_internal", 0); - GPR_TIMER_BEGIN("grpc_completion_queue_create_internal", 0); + grpc_completion_queue* cq; GRPC_API_TRACE( "grpc_completion_queue_create_internal(completion_type=%d, " @@ -452,9 +452,6 @@ grpc_completion_queue* grpc_completion_queue_create_internal( GRPC_CLOSURE_INIT(&cq->pollset_shutdown_done, on_pollset_shutdown_done, cq, grpc_schedule_on_exec_ctx); - - GPR_TIMER_END("grpc_completion_queue_create_internal", 0); - return cq; } @@ -622,7 +619,7 @@ static void cq_end_op_for_next(grpc_completion_queue* cq, void* tag, void (*done)(void* done_arg, grpc_cq_completion* storage), void* done_arg, grpc_cq_completion* storage) { - GPR_TIMER_BEGIN("cq_end_op_for_next", 0); + GPR_TIMER_SCOPE("cq_end_op_for_next", 0); if (grpc_api_trace.enabled() || (grpc_trace_operation_failures.enabled() && error != GRPC_ERROR_NONE)) { @@ -691,8 +688,6 @@ static void cq_end_op_for_next(grpc_completion_queue* cq, void* tag, } } - GPR_TIMER_END("cq_end_op_for_next", 0); - GRPC_ERROR_UNREF(error); } @@ -704,11 +699,11 @@ static void cq_end_op_for_pluck(grpc_completion_queue* cq, void* tag, void (*done)(void* done_arg, grpc_cq_completion* storage), void* done_arg, grpc_cq_completion* storage) { + GPR_TIMER_SCOPE("cq_end_op_for_pluck", 0); + cq_pluck_data* cqd = (cq_pluck_data*)DATA_FROM_CQ(cq); int is_success = (error == GRPC_ERROR_NONE); - GPR_TIMER_BEGIN("cq_end_op_for_pluck", 0); - if (grpc_api_trace.enabled() || (grpc_trace_operation_failures.enabled() && error != GRPC_ERROR_NONE)) { const char* errmsg = grpc_error_string(error); @@ -760,8 +755,6 @@ static void cq_end_op_for_pluck(grpc_completion_queue* cq, void* tag, } } - GPR_TIMER_END("cq_end_op_for_pluck", 0); - GRPC_ERROR_UNREF(error); } @@ -840,11 +833,11 @@ static void dump_pending_tags(grpc_completion_queue* cq) {} static grpc_event cq_next(grpc_completion_queue* cq, gpr_timespec deadline, void* reserved) { + GPR_TIMER_SCOPE("grpc_completion_queue_next", 0); + grpc_event ret; cq_next_data* cqd = (cq_next_data*)DATA_FROM_CQ(cq); - GPR_TIMER_BEGIN("grpc_completion_queue_next", 0); - GRPC_API_TRACE( "grpc_completion_queue_next(" "cq=%p, " @@ -958,8 +951,6 @@ static grpc_event cq_next(grpc_completion_queue* cq, gpr_timespec deadline, GPR_ASSERT(is_finished_arg.stolen_completion == nullptr); - GPR_TIMER_END("grpc_completion_queue_next", 0); - return ret; } @@ -1078,14 +1069,14 @@ class ExecCtxPluck : public grpc_core::ExecCtx { static grpc_event cq_pluck(grpc_completion_queue* cq, void* tag, gpr_timespec deadline, void* reserved) { + GPR_TIMER_SCOPE("grpc_completion_queue_pluck", 0); + grpc_event ret; grpc_cq_completion* c; grpc_cq_completion* prev; grpc_pollset_worker* worker = nullptr; cq_pluck_data* cqd = (cq_pluck_data*)DATA_FROM_CQ(cq); - GPR_TIMER_BEGIN("grpc_completion_queue_pluck", 0); - if (grpc_cq_pluck_trace.enabled()) { GRPC_API_TRACE( "grpc_completion_queue_pluck(" @@ -1191,8 +1182,6 @@ done: GPR_ASSERT(is_finished_arg.stolen_completion == nullptr); - GPR_TIMER_END("grpc_completion_queue_pluck", 0); - return ret; } @@ -1240,23 +1229,19 @@ static void cq_shutdown_pluck(grpc_completion_queue* cq) { /* Shutdown simply drops a ref that we reserved at creation time; if we drop to zero here, then enter shutdown mode and wake up any waiters */ void grpc_completion_queue_shutdown(grpc_completion_queue* cq) { + GPR_TIMER_SCOPE("grpc_completion_queue_shutdown", 0); grpc_core::ExecCtx exec_ctx; - GPR_TIMER_BEGIN("grpc_completion_queue_shutdown", 0); GRPC_API_TRACE("grpc_completion_queue_shutdown(cq=%p)", 1, (cq)); cq->vtable->shutdown(cq); - - GPR_TIMER_END("grpc_completion_queue_shutdown", 0); } void grpc_completion_queue_destroy(grpc_completion_queue* cq) { + GPR_TIMER_SCOPE("grpc_completion_queue_destroy", 0); GRPC_API_TRACE("grpc_completion_queue_destroy(cq=%p)", 1, (cq)); - GPR_TIMER_BEGIN("grpc_completion_queue_destroy", 0); grpc_completion_queue_shutdown(cq); grpc_core::ExecCtx exec_ctx; GRPC_CQ_INTERNAL_UNREF(cq, "destroy"); - - GPR_TIMER_END("grpc_completion_queue_destroy", 0); } grpc_pollset* grpc_cq_pollset(grpc_completion_queue* cq) { diff --git a/src/core/lib/surface/init.cc b/src/core/lib/surface/init.cc index 70329b09f4..7f7947faaa 100644 --- a/src/core/lib/surface/init.cc +++ b/src/core/lib/surface/init.cc @@ -42,7 +42,6 @@ #include "src/core/lib/iomgr/timer_manager.h" #include "src/core/lib/profiling/timers.h" #include "src/core/lib/slice/slice_internal.h" -#include "src/core/lib/surface/alarm_internal.h" #include "src/core/lib/surface/api_trace.h" #include "src/core/lib/surface/call.h" #include "src/core/lib/surface/channel_init.h" @@ -162,9 +161,9 @@ void grpc_shutdown(void) { { grpc_core::ExecCtx exec_ctx(0); { - grpc_executor_shutdown(); grpc_timer_manager_set_threading( false); // shutdown timer_manager thread + grpc_executor_shutdown(); for (i = g_number_of_plugins; i >= 0; i--) { if (g_all_of_the_plugins[i].destroy != nullptr) { g_all_of_the_plugins[i].destroy(); diff --git a/src/core/lib/surface/version.cc b/src/core/lib/surface/version.cc index 19498a6df7..153b6e0297 100644 --- a/src/core/lib/surface/version.cc +++ b/src/core/lib/surface/version.cc @@ -21,6 +21,6 @@ #include <grpc/grpc.h> -const char* grpc_version_string(void) { return "5.0.0-dev"; } +const char* grpc_version_string(void) { return "6.0.0-dev"; } -const char* grpc_g_stands_for(void) { return "glamorous"; } +const char* grpc_g_stands_for(void) { return "glossy"; } diff --git a/src/core/lib/transport/metadata.cc b/src/core/lib/transport/metadata.cc index 652222bd0b..cc1edd586f 100644 --- a/src/core/lib/transport/metadata.cc +++ b/src/core/lib/transport/metadata.cc @@ -166,12 +166,13 @@ static void ref_md_locked(mdtab_shard* shard, } static void gc_mdtab(mdtab_shard* shard) { + GPR_TIMER_SCOPE("gc_mdtab", 0); + size_t i; interned_metadata** prev_next; interned_metadata *md, *next; gpr_atm num_freed = 0; - GPR_TIMER_BEGIN("gc_mdtab", 0); for (i = 0; i < shard->capacity; i++) { prev_next = &shard->elems[i]; for (md = shard->elems[i]; md; md = next) { @@ -194,18 +195,17 @@ static void gc_mdtab(mdtab_shard* shard) { } } gpr_atm_no_barrier_fetch_add(&shard->free_estimate, -num_freed); - GPR_TIMER_END("gc_mdtab", 0); } static void grow_mdtab(mdtab_shard* shard) { + GPR_TIMER_SCOPE("grow_mdtab", 0); + size_t capacity = shard->capacity * 2; size_t i; interned_metadata** mdtab; interned_metadata *md, *next; uint32_t hash; - GPR_TIMER_BEGIN("grow_mdtab", 0); - mdtab = (interned_metadata**)gpr_zalloc(sizeof(interned_metadata*) * capacity); @@ -220,12 +220,9 @@ static void grow_mdtab(mdtab_shard* shard) { mdtab[idx] = md; } } - gpr_free(shard->elems); shard->elems = mdtab; shard->capacity = capacity; - - GPR_TIMER_END("grow_mdtab", 0); } static void rehash_mdtab(mdtab_shard* shard) { @@ -280,7 +277,7 @@ grpc_mdelem grpc_mdelem_create( mdtab_shard* shard = &g_shards[SHARD_IDX(hash)]; size_t idx; - GPR_TIMER_BEGIN("grpc_mdelem_from_metadata_strings", 0); + GPR_TIMER_SCOPE("grpc_mdelem_from_metadata_strings", 0); gpr_mu_lock(&shard->mu); @@ -290,7 +287,6 @@ grpc_mdelem grpc_mdelem_create( if (grpc_slice_eq(key, md->key) && grpc_slice_eq(value, md->value)) { REF_MD_LOCKED(shard, md); gpr_mu_unlock(&shard->mu); - GPR_TIMER_END("grpc_mdelem_from_metadata_strings", 0); return GRPC_MAKE_MDELEM(md, GRPC_MDELEM_STORAGE_INTERNED); } } @@ -323,8 +319,6 @@ grpc_mdelem grpc_mdelem_create( gpr_mu_unlock(&shard->mu); - GPR_TIMER_END("grpc_mdelem_from_metadata_strings", 0); - return GRPC_MAKE_MDELEM(md, GRPC_MDELEM_STORAGE_INTERNED); } diff --git a/src/core/plugin_registry/grpc_cronet_plugin_registry.cc b/src/core/plugin_registry/grpc_cronet_plugin_registry.cc index 101e29c481..fe5eb28f05 100644 --- a/src/core/plugin_registry/grpc_cronet_plugin_registry.cc +++ b/src/core/plugin_registry/grpc_cronet_plugin_registry.cc @@ -26,8 +26,8 @@ void grpc_deadline_filter_init(void); void grpc_deadline_filter_shutdown(void); void grpc_client_channel_init(void); void grpc_client_channel_shutdown(void); -void grpc_tsi_gts_init(void); -void grpc_tsi_gts_shutdown(void); +void grpc_tsi_alts_init(void); +void grpc_tsi_alts_shutdown(void); void grpc_server_load_reporting_plugin_init(void); void grpc_server_load_reporting_plugin_shutdown(void); @@ -40,8 +40,8 @@ void grpc_register_built_in_plugins(void) { grpc_deadline_filter_shutdown); grpc_register_plugin(grpc_client_channel_init, grpc_client_channel_shutdown); - grpc_register_plugin(grpc_tsi_gts_init, - grpc_tsi_gts_shutdown); + grpc_register_plugin(grpc_tsi_alts_init, + grpc_tsi_alts_shutdown); grpc_register_plugin(grpc_server_load_reporting_plugin_init, grpc_server_load_reporting_plugin_shutdown); } diff --git a/src/core/plugin_registry/grpc_plugin_registry.cc b/src/core/plugin_registry/grpc_plugin_registry.cc index 89be351785..fdf9acc09c 100644 --- a/src/core/plugin_registry/grpc_plugin_registry.cc +++ b/src/core/plugin_registry/grpc_plugin_registry.cc @@ -22,8 +22,8 @@ void grpc_http_filters_init(void); void grpc_http_filters_shutdown(void); void grpc_chttp2_plugin_init(void); void grpc_chttp2_plugin_shutdown(void); -void grpc_tsi_gts_init(void); -void grpc_tsi_gts_shutdown(void); +void grpc_tsi_alts_init(void); +void grpc_tsi_alts_shutdown(void); void grpc_deadline_filter_init(void); void grpc_deadline_filter_shutdown(void); void grpc_client_channel_init(void); @@ -58,8 +58,8 @@ void grpc_register_built_in_plugins(void) { grpc_http_filters_shutdown); grpc_register_plugin(grpc_chttp2_plugin_init, grpc_chttp2_plugin_shutdown); - grpc_register_plugin(grpc_tsi_gts_init, - grpc_tsi_gts_shutdown); + grpc_register_plugin(grpc_tsi_alts_init, + grpc_tsi_alts_shutdown); grpc_register_plugin(grpc_deadline_filter_init, grpc_deadline_filter_shutdown); grpc_register_plugin(grpc_client_channel_init, diff --git a/src/core/tsi/gts_transport_security.cc b/src/core/tsi/alts_transport_security.cc index 2b099773c4..ddd75cbd02 100644 --- a/src/core/tsi/gts_transport_security.cc +++ b/src/core/tsi/alts_transport_security.cc @@ -16,25 +16,27 @@ * */ -#include "src/core/tsi/gts_transport_security.h" +#include "src/core/tsi/alts_transport_security.h" #include <string.h> -static gts_shared_resource g_gts_resource; +static alts_shared_resource g_alts_resource; -gts_shared_resource* gts_get_shared_resource(void) { return &g_gts_resource; } +alts_shared_resource* alts_get_shared_resource(void) { + return &g_alts_resource; +} -void grpc_tsi_gts_init() { - memset(&g_gts_resource, 0, sizeof(gts_shared_resource)); - gpr_mu_init(&g_gts_resource.mu); +void grpc_tsi_alts_init() { + memset(&g_alts_resource, 0, sizeof(alts_shared_resource)); + gpr_mu_init(&g_alts_resource.mu); } -void grpc_tsi_gts_shutdown() { - gpr_mu_destroy(&g_gts_resource.mu); - if (g_gts_resource.cq == nullptr) { +void grpc_tsi_alts_shutdown() { + gpr_mu_destroy(&g_alts_resource.mu); + if (g_alts_resource.cq == nullptr) { return; } - grpc_completion_queue_destroy(g_gts_resource.cq); - grpc_channel_destroy(g_gts_resource.channel); - gpr_thd_join(g_gts_resource.thread_id); + grpc_completion_queue_destroy(g_alts_resource.cq); + grpc_channel_destroy(g_alts_resource.channel); + gpr_thd_join(g_alts_resource.thread_id); } diff --git a/src/core/tsi/gts_transport_security.h b/src/core/tsi/alts_transport_security.h index 23b2b66fb3..c90e31478e 100644 --- a/src/core/tsi/gts_transport_security.h +++ b/src/core/tsi/alts_transport_security.h @@ -16,22 +16,22 @@ * */ -#ifndef GRPC_CORE_TSI_GTS_TRANSPORT_SECURITY_H -#define GRPC_CORE_TSI_GTS_TRANSPORT_SECURITY_H +#ifndef GRPC_CORE_TSI_ALTS_TRANSPORT_SECURITY_H +#define GRPC_CORE_TSI_ALTS_TRANSPORT_SECURITY_H #include <grpc/grpc.h> #include <grpc/support/sync.h> #include <grpc/support/thd.h> -typedef struct gts_shared_resource { +typedef struct alts_shared_resource { gpr_thd_id thread_id; grpc_channel* channel; grpc_completion_queue* cq; gpr_mu mu; -} gts_shared_resource; +} alts_shared_resource; -/* This method returns the address of gts_shared_resource object shared by all +/* This method returns the address of alts_shared_resource object shared by all * TSI handshakes. */ -gts_shared_resource* gts_get_shared_resource(void); +alts_shared_resource* alts_get_shared_resource(void); -#endif /* GRPC_CORE_TSI_GTS_TRANSPORT_SECURITY_H */ +#endif /* GRPC_CORE_TSI_ALTS_TRANSPORT_SECURITY_H */ |