diff --git a/doc/environment_variables.md b/doc/environment_variables.md index dce434ff30d..0a289ac94d4 100644 --- a/doc/environment_variables.md +++ b/doc/environment_variables.md @@ -51,8 +51,6 @@ some configuration as environment variables that can be set. - flowctl - traces http2 flow control - op_failure - traces error information when failure is pushed onto a completion queue - - pending_tags - [debug builds only] traces still-in-progress tags on - completion queues - round_robin - traces the round_robin load balancing policy - glb - traces the grpclb load balancer - queue_pluck @@ -63,6 +61,23 @@ some configuration as environment variables that can be set. - transport_security - traces metadata about secure channel establishment - tcp - traces bytes in and out of a channel + The following tracers will only run in binaries built in DEBUG mode. This is + accomplished by invoking `CONFIG=dbg make ` + - metadata - tracks creation and mutation of metadata + - closure - tracks closure creation, scheduling, and completion + - pending_tags - traces still-in-progress tags on completion queues + - polling - traces the selected polling engine + - queue_refcount + - error_refcount + - stream_refcount + - workqueue_refcount + - fd_refcount + - auth_context_refcount + - security_connector_refcount + - resolver_refcount + - lb_policy_refcount + - chttp2_refcount + 'all' can additionally be used to turn all traces on. Individual traces can be disabled by prefixing them with '-'. diff --git a/src/core/ext/filters/client_channel/client_channel_plugin.c b/src/core/ext/filters/client_channel/client_channel_plugin.c index 2c6af1d78e2..60e77d62683 100644 --- a/src/core/ext/filters/client_channel/client_channel_plugin.c +++ b/src/core/ext/filters/client_channel/client_channel_plugin.c @@ -78,6 +78,9 @@ void grpc_client_channel_init(void) { GRPC_CLIENT_CHANNEL, GRPC_CHANNEL_INIT_BUILTIN_PRIORITY, append_filter, (void *)&grpc_client_channel_filter); grpc_http_connect_register_handshaker_factory(); +#ifndef NDEBUG + grpc_register_tracer("resolver_refcount", &grpc_trace_resolver_refcount); +#endif } void grpc_client_channel_shutdown(void) { diff --git a/src/core/ext/filters/client_channel/lb_policy.c b/src/core/ext/filters/client_channel/lb_policy.c index 50f8faef8e5..8d69ba6af52 100644 --- a/src/core/ext/filters/client_channel/lb_policy.c +++ b/src/core/ext/filters/client_channel/lb_policy.c @@ -21,6 +21,10 @@ #define WEAK_REF_BITS 16 +#ifndef NDEBUG +grpc_tracer_flag grpc_trace_lb_policy_refcount = GRPC_TRACER_INITIALIZER(false); +#endif + void grpc_lb_policy_init(grpc_lb_policy *policy, const grpc_lb_policy_vtable *vtable, grpc_combiner *combiner) { @@ -30,7 +34,7 @@ void grpc_lb_policy_init(grpc_lb_policy *policy, policy->combiner = GRPC_COMBINER_REF(combiner, "lb_policy"); } -#ifdef GRPC_LB_POLICY_REFCOUNT_DEBUG +#ifndef NDEBUG #define REF_FUNC_EXTRA_ARGS , const char *file, int line, const char *reason #define REF_MUTATE_EXTRA_ARGS REF_FUNC_EXTRA_ARGS, const char *purpose #define REF_FUNC_PASS_ARGS(new_reason) , file, line, new_reason @@ -46,11 +50,12 @@ static gpr_atm ref_mutate(grpc_lb_policy *c, gpr_atm delta, int barrier REF_MUTATE_EXTRA_ARGS) { gpr_atm old_val = barrier ? gpr_atm_full_fetch_add(&c->ref_pair, delta) : gpr_atm_no_barrier_fetch_add(&c->ref_pair, delta); -#ifdef GRPC_LB_POLICY_REFCOUNT_DEBUG - gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, - "LB_POLICY: 0x%" PRIxPTR " %12s 0x%" PRIxPTR " -> 0x%" PRIxPTR - " [%s]", - (intptr_t)c, purpose, old_val, old_val + delta, reason); +#ifndef NDEBUG + if (GRPC_TRACER_ON(grpc_trace_lb_policy_refcount)) { + gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, + "LB_POLICY: 0x%p %12s 0x%" PRIxPTR " -> 0x%" PRIxPTR " [%s]", c, + purpose, old_val, old_val + delta, reason); + } #endif return old_val; } diff --git a/src/core/ext/filters/client_channel/lb_policy.h b/src/core/ext/filters/client_channel/lb_policy.h index 42503c37ca2..645d51e1385 100644 --- a/src/core/ext/filters/client_channel/lb_policy.h +++ b/src/core/ext/filters/client_channel/lb_policy.h @@ -29,6 +29,10 @@ typedef struct grpc_lb_policy grpc_lb_policy; typedef struct grpc_lb_policy_vtable grpc_lb_policy_vtable; typedef struct grpc_lb_policy_args grpc_lb_policy_args; +#ifndef NDEBUG +extern grpc_tracer_flag grpc_trace_lb_policy_refcount; +#endif + struct grpc_lb_policy { const grpc_lb_policy_vtable *vtable; gpr_atm ref_pair; @@ -96,8 +100,7 @@ struct grpc_lb_policy_vtable { const grpc_lb_policy_args *args); }; -//#define GRPC_LB_POLICY_REFCOUNT_DEBUG -#ifdef GRPC_LB_POLICY_REFCOUNT_DEBUG +#ifndef NDEBUG /* Strong references: the policy will shutdown when they reach zero */ #define GRPC_LB_POLICY_REF(p, r) \ diff --git a/src/core/ext/filters/client_channel/lb_policy/grpclb/grpclb.c b/src/core/ext/filters/client_channel/lb_policy/grpclb/grpclb.c index e80b1dcd80f..5a5ff2902d0 100644 --- a/src/core/ext/filters/client_channel/lb_policy/grpclb/grpclb.c +++ b/src/core/ext/filters/client_channel/lb_policy/grpclb/grpclb.c @@ -1880,6 +1880,9 @@ static bool maybe_add_client_load_reporting_filter( void grpc_lb_policy_grpclb_init() { grpc_register_lb_policy(grpc_glb_lb_factory_create()); grpc_register_tracer("glb", &grpc_lb_glb_trace); +#ifndef NDEBUG + grpc_register_tracer("lb_policy_refcount", &grpc_trace_lb_policy_refcount); +#endif grpc_channel_init_register_stage(GRPC_CLIENT_SUBCHANNEL, GRPC_CHANNEL_INIT_BUILTIN_PRIORITY, maybe_add_client_load_reporting_filter, diff --git a/src/core/ext/filters/client_channel/resolver.c b/src/core/ext/filters/client_channel/resolver.c index 69b1c31e592..de9a8ce41b9 100644 --- a/src/core/ext/filters/client_channel/resolver.c +++ b/src/core/ext/filters/client_channel/resolver.c @@ -19,6 +19,10 @@ #include "src/core/ext/filters/client_channel/resolver.h" #include "src/core/lib/iomgr/combiner.h" +#ifndef NDEBUG +grpc_tracer_flag grpc_trace_resolver_refcount = GRPC_TRACER_INITIALIZER(false); +#endif + void grpc_resolver_init(grpc_resolver *resolver, const grpc_resolver_vtable *vtable, grpc_combiner *combiner) { @@ -27,25 +31,30 @@ void grpc_resolver_init(grpc_resolver *resolver, gpr_ref_init(&resolver->refs, 1); } -#ifdef GRPC_RESOLVER_REFCOUNT_DEBUG -void grpc_resolver_ref(grpc_resolver *resolver, grpc_closure_list *closure_list, - const char *file, int line, const char *reason) { - gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, "RESOLVER:%p ref %d -> %d %s", - resolver, (int)resolver->refs.count, (int)resolver->refs.count + 1, - reason); +#ifndef NDEBUG +void grpc_resolver_ref(grpc_resolver *resolver, const char *file, int line, + const char *reason) { + if (GRPC_TRACER_ON(grpc_trace_resolver_refcount)) { + gpr_atm old_refs = gpr_atm_no_barrier_load(&resolver->refs.count); + gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, + "RESOLVER:%p ref %" PRIdPTR " -> %" PRIdPTR " %s", resolver, + old_refs, old_refs + 1, reason); + } #else void grpc_resolver_ref(grpc_resolver *resolver) { #endif gpr_ref(&resolver->refs); } -#ifdef GRPC_RESOLVER_REFCOUNT_DEBUG -void grpc_resolver_unref(grpc_resolver *resolver, - grpc_closure_list *closure_list, const char *file, - int line, const char *reason) { - gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, "RESOLVER:%p unref %d -> %d %s", - resolver, (int)resolver->refs.count, (int)resolver->refs.count - 1, - reason); +#ifndef NDEBUG +void grpc_resolver_unref(grpc_exec_ctx *exec_ctx, grpc_resolver *resolver, + const char *file, int line, const char *reason) { + if (GRPC_TRACER_ON(grpc_trace_resolver_refcount)) { + gpr_atm old_refs = gpr_atm_no_barrier_load(&resolver->refs.count); + gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, + "RESOLVER:%p unref %" PRIdPTR " -> %" PRIdPTR " %s", resolver, + old_refs, old_refs - 1, reason); + } #else void grpc_resolver_unref(grpc_exec_ctx *exec_ctx, grpc_resolver *resolver) { #endif diff --git a/src/core/ext/filters/client_channel/resolver.h b/src/core/ext/filters/client_channel/resolver.h index c78bb316cbc..ae9c8f66fed 100644 --- a/src/core/ext/filters/client_channel/resolver.h +++ b/src/core/ext/filters/client_channel/resolver.h @@ -25,6 +25,10 @@ typedef struct grpc_resolver grpc_resolver; typedef struct grpc_resolver_vtable grpc_resolver_vtable; +#ifndef NDEBUG +extern grpc_tracer_flag grpc_trace_resolver_refcount; +#endif + /** \a grpc_resolver provides \a grpc_channel_args objects to its caller */ struct grpc_resolver { const grpc_resolver_vtable *vtable; @@ -41,17 +45,17 @@ struct grpc_resolver_vtable { grpc_channel_args **result, grpc_closure *on_complete); }; -#ifdef GRPC_RESOLVER_REFCOUNT_DEBUG +#ifndef NDEBUG #define GRPC_RESOLVER_REF(p, r) grpc_resolver_ref((p), __FILE__, __LINE__, (r)) -#define GRPC_RESOLVER_UNREF(cl, p, r) \ - grpc_resolver_unref((cl), (p), __FILE__, __LINE__, (r)) +#define GRPC_RESOLVER_UNREF(e, p, r) \ + grpc_resolver_unref((e), (p), __FILE__, __LINE__, (r)) void grpc_resolver_ref(grpc_resolver *policy, const char *file, int line, const char *reason); -void grpc_resolver_unref(grpc_resolver *policy, grpc_closure_list *closure_list, +void grpc_resolver_unref(grpc_exec_ctx *exec_ctx, grpc_resolver *policy, const char *file, int line, const char *reason); #else #define GRPC_RESOLVER_REF(p, r) grpc_resolver_ref((p)) -#define GRPC_RESOLVER_UNREF(cl, p, r) grpc_resolver_unref((cl), (p)) +#define GRPC_RESOLVER_UNREF(e, p, r) grpc_resolver_unref((e), (p)) void grpc_resolver_ref(grpc_resolver *policy); void grpc_resolver_unref(grpc_exec_ctx *exec_ctx, grpc_resolver *policy); #endif diff --git a/src/core/ext/filters/client_channel/subchannel.c b/src/core/ext/filters/client_channel/subchannel.c index 0877ef4e671..88157ed738c 100644 --- a/src/core/ext/filters/client_channel/subchannel.c +++ b/src/core/ext/filters/client_channel/subchannel.c @@ -140,25 +140,13 @@ struct grpc_subchannel_call { static void subchannel_connected(grpc_exec_ctx *exec_ctx, void *subchannel, grpc_error *error); -#ifdef GRPC_STREAM_REFCOUNT_DEBUG +#ifndef NDEBUG #define REF_REASON reason -#define REF_LOG(name, p) \ - gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, "%s: %p ref %d -> %d %s", \ - (name), (p), (p)->refs.count, (p)->refs.count + 1, reason) -#define UNREF_LOG(name, p) \ - gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, "%s: %p unref %d -> %d %s", \ - (name), (p), (p)->refs.count, (p)->refs.count - 1, reason) #define REF_MUTATE_EXTRA_ARGS \ GRPC_SUBCHANNEL_REF_EXTRA_ARGS, const char *purpose #define REF_MUTATE_PURPOSE(x) , file, line, reason, x #else #define REF_REASON "" -#define REF_LOG(name, p) \ - do { \ - } while (0) -#define UNREF_LOG(name, p) \ - do { \ - } while (0) #define REF_MUTATE_EXTRA_ARGS #define REF_MUTATE_PURPOSE(x) #endif @@ -207,10 +195,12 @@ static gpr_atm ref_mutate(grpc_subchannel *c, gpr_atm delta, int barrier REF_MUTATE_EXTRA_ARGS) { gpr_atm old_val = barrier ? gpr_atm_full_fetch_add(&c->ref_pair, delta) : gpr_atm_no_barrier_fetch_add(&c->ref_pair, delta); -#ifdef GRPC_STREAM_REFCOUNT_DEBUG - gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, - "SUBCHANNEL: %p %s 0x%08" PRIxPTR " -> 0x%08" PRIxPTR " [%s]", c, - purpose, old_val, old_val + delta, reason); +#ifndef NDEBUG + if (GRPC_TRACER_ON(grpc_trace_stream_refcount)) { + gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, + "SUBCHANNEL: %p %12s 0x%" PRIxPTR " -> 0x%" PRIxPTR " [%s]", c, + purpose, old_val, old_val + delta, reason); + } #endif return old_val; } diff --git a/src/core/ext/filters/client_channel/subchannel.h b/src/core/ext/filters/client_channel/subchannel.h index f38bf42803c..6d2abb04df5 100644 --- a/src/core/ext/filters/client_channel/subchannel.h +++ b/src/core/ext/filters/client_channel/subchannel.h @@ -37,7 +37,7 @@ typedef struct grpc_subchannel_call grpc_subchannel_call; typedef struct grpc_subchannel_args grpc_subchannel_args; typedef struct grpc_subchannel_key grpc_subchannel_key; -#ifdef GRPC_STREAM_REFCOUNT_DEBUG +#ifndef NDEBUG #define GRPC_SUBCHANNEL_REF(p, r) \ grpc_subchannel_ref((p), __FILE__, __LINE__, (r)) #define GRPC_SUBCHANNEL_REF_FROM_WEAK_REF(p, r) \ diff --git a/src/core/ext/transport/chttp2/transport/chttp2_plugin.c b/src/core/ext/transport/chttp2/transport/chttp2_plugin.c index b0ffdc0cf92..6a8c81445a1 100644 --- a/src/core/ext/transport/chttp2/transport/chttp2_plugin.c +++ b/src/core/ext/transport/chttp2/transport/chttp2_plugin.c @@ -23,6 +23,9 @@ void grpc_chttp2_plugin_init(void) { grpc_register_tracer("http", &grpc_http_trace); grpc_register_tracer("flowctl", &grpc_flowctl_trace); +#ifndef NDEBUG + grpc_register_tracer("chttp2_refcount", &grpc_trace_chttp2_refcount); +#endif } void grpc_chttp2_plugin_shutdown(void) {} diff --git a/src/core/ext/transport/chttp2/transport/chttp2_transport.c b/src/core/ext/transport/chttp2/transport/chttp2_transport.c index cd2c6cc4926..1f4abbc792c 100644 --- a/src/core/ext/transport/chttp2/transport/chttp2_transport.c +++ b/src/core/ext/transport/chttp2/transport/chttp2_transport.c @@ -76,6 +76,10 @@ static bool g_default_keepalive_permit_without_calls = grpc_tracer_flag grpc_http_trace = GRPC_TRACER_INITIALIZER(false); grpc_tracer_flag grpc_flowctl_trace = GRPC_TRACER_INITIALIZER(false); +#ifndef NDEBUG +grpc_tracer_flag grpc_trace_chttp2_refcount = GRPC_TRACER_INITIALIZER(false); +#endif + static const grpc_transport_vtable vtable; /* forward declarations of various callbacks that we'll build closures around */ @@ -213,20 +217,26 @@ static void destruct_transport(grpc_exec_ctx *exec_ctx, gpr_free(t); } -#ifdef GRPC_CHTTP2_REFCOUNTING_DEBUG +#ifndef NDEBUG void grpc_chttp2_unref_transport(grpc_exec_ctx *exec_ctx, grpc_chttp2_transport *t, const char *reason, const char *file, int line) { - gpr_log(GPR_DEBUG, "chttp2:unref:%p %" PRIdPTR "->%" PRIdPTR " %s [%s:%d]", t, - t->refs.count, t->refs.count - 1, reason, file, line); + if (GRPC_TRACER_ON(grpc_trace_chttp2_refcount)) { + gpr_atm val = gpr_atm_no_barrier_load(&t->refs.count); + gpr_log(GPR_DEBUG, "chttp2:unref:%p %" PRIdPTR "->%" PRIdPTR " %s [%s:%d]", + t, val, val - 1, reason, file, line); + } if (!gpr_unref(&t->refs)) return; destruct_transport(exec_ctx, t); } void grpc_chttp2_ref_transport(grpc_chttp2_transport *t, const char *reason, const char *file, int line) { - gpr_log(GPR_DEBUG, "chttp2: ref:%p %" PRIdPTR "->%" PRIdPTR " %s [%s:%d]", t, - t->refs.count, t->refs.count + 1, reason, file, line); + if (GRPC_TRACER_ON(grpc_trace_chttp2_refcount)) { + gpr_atm val = gpr_atm_no_barrier_load(&t->refs.count); + gpr_log(GPR_DEBUG, "chttp2: ref:%p %" PRIdPTR "->%" PRIdPTR " %s [%s:%d]", + t, val, val + 1, reason, file, line); + } gpr_ref(&t->refs); } #else @@ -622,7 +632,7 @@ static void close_transport_locked(grpc_exec_ctx *exec_ctx, GRPC_ERROR_UNREF(error); } -#ifdef GRPC_STREAM_REFCOUNT_DEBUG +#ifndef NDEBUG void grpc_chttp2_stream_ref(grpc_chttp2_stream *s, const char *reason) { grpc_stream_ref(s->refcount, reason); } diff --git a/src/core/ext/transport/chttp2/transport/chttp2_transport.h b/src/core/ext/transport/chttp2/transport/chttp2_transport.h index 0a1fb4d772a..0c4e2a91c03 100644 --- a/src/core/ext/transport/chttp2/transport/chttp2_transport.h +++ b/src/core/ext/transport/chttp2/transport/chttp2_transport.h @@ -26,6 +26,10 @@ extern grpc_tracer_flag grpc_http_trace; extern grpc_tracer_flag grpc_flowctl_trace; +#ifndef NDEBUG +extern grpc_tracer_flag grpc_trace_chttp2_refcount; +#endif + grpc_transport *grpc_create_chttp2_transport( grpc_exec_ctx *exec_ctx, const grpc_channel_args *channel_args, grpc_endpoint *ep, int is_client); diff --git a/src/core/ext/transport/chttp2/transport/internal.h b/src/core/ext/transport/chttp2/transport/internal.h index 4041b29fecb..b7ac7447956 100644 --- a/src/core/ext/transport/chttp2/transport/internal.h +++ b/src/core/ext/transport/chttp2/transport/internal.h @@ -748,7 +748,7 @@ void grpc_chttp2_mark_stream_closed(grpc_exec_ctx *exec_ctx, void grpc_chttp2_start_writing(grpc_exec_ctx *exec_ctx, grpc_chttp2_transport *t); -#ifdef GRPC_STREAM_REFCOUNT_DEBUG +#ifndef NDEBUG #define GRPC_CHTTP2_STREAM_REF(stream, reason) \ grpc_chttp2_stream_ref(stream, reason) #define GRPC_CHTTP2_STREAM_UNREF(exec_ctx, stream, reason) \ @@ -764,8 +764,7 @@ void grpc_chttp2_stream_ref(grpc_chttp2_stream *s); void grpc_chttp2_stream_unref(grpc_exec_ctx *exec_ctx, grpc_chttp2_stream *s); #endif -//#define GRPC_CHTTP2_REFCOUNTING_DEBUG 1 -#ifdef GRPC_CHTTP2_REFCOUNTING_DEBUG +#ifndef NDEBUG #define GRPC_CHTTP2_REF_TRANSPORT(t, r) \ grpc_chttp2_ref_transport(t, r, __FILE__, __LINE__) #define GRPC_CHTTP2_UNREF_TRANSPORT(cl, t, r) \ diff --git a/src/core/lib/channel/channel_stack.h b/src/core/lib/channel/channel_stack.h index b0559ad745c..a80f8aa8268 100644 --- a/src/core/lib/channel/channel_stack.h +++ b/src/core/lib/channel/channel_stack.h @@ -234,7 +234,7 @@ void grpc_call_stack_set_pollset_or_pollset_set(grpc_exec_ctx *exec_ctx, grpc_call_stack *call_stack, grpc_polling_entity *pollent); -#ifdef GRPC_STREAM_REFCOUNT_DEBUG +#ifndef NDEBUG #define GRPC_CALL_STACK_REF(call_stack, reason) \ grpc_stream_ref(&(call_stack)->refcount, reason) #define GRPC_CALL_STACK_UNREF(exec_ctx, call_stack, reason) \ diff --git a/src/core/lib/iomgr/closure.c b/src/core/lib/iomgr/closure.c index 719e2e8cee0..e028e72ed6d 100644 --- a/src/core/lib/iomgr/closure.c +++ b/src/core/lib/iomgr/closure.c @@ -24,7 +24,11 @@ #include "src/core/lib/profiling/timers.h" -#ifdef GRPC_CLOSURE_RICH_DEBUG +#ifndef NDEBUG +grpc_tracer_flag grpc_trace_closure = GRPC_TRACER_INITIALIZER(false); +#endif + +#ifndef NDEBUG grpc_closure *grpc_closure_init(const char *file, int line, grpc_closure *closure, grpc_iomgr_cb_func cb, void *cb_arg, @@ -37,7 +41,7 @@ grpc_closure *grpc_closure_init(grpc_closure *closure, grpc_iomgr_cb_func cb, closure->cb = cb; closure->cb_arg = cb_arg; closure->scheduler = scheduler; -#ifdef GRPC_CLOSURE_RICH_DEBUG +#ifndef NDEBUG closure->scheduled = false; closure->file_initiated = NULL; closure->line_initiated = 0; @@ -112,7 +116,7 @@ static void closure_wrapper(grpc_exec_ctx *exec_ctx, void *arg, cb(exec_ctx, cb_arg, error); } -#ifdef GRPC_CLOSURE_RICH_DEBUG +#ifndef NDEBUG grpc_closure *grpc_closure_create(const char *file, int line, grpc_iomgr_cb_func cb, void *cb_arg, grpc_closure_scheduler *scheduler) { @@ -123,7 +127,7 @@ grpc_closure *grpc_closure_create(grpc_iomgr_cb_func cb, void *cb_arg, wrapped_closure *wc = gpr_malloc(sizeof(*wc)); wc->cb = cb; wc->cb_arg = cb_arg; -#ifdef GRPC_CLOSURE_RICH_DEBUG +#ifndef NDEBUG grpc_closure_init(file, line, &wc->wrapper, closure_wrapper, wc, scheduler); #else grpc_closure_init(&wc->wrapper, closure_wrapper, wc, scheduler); @@ -131,7 +135,7 @@ grpc_closure *grpc_closure_create(grpc_iomgr_cb_func cb, void *cb_arg, return &wc->wrapper; } -#ifdef GRPC_CLOSURE_RICH_DEBUG +#ifndef NDEBUG void grpc_closure_run(const char *file, int line, grpc_exec_ctx *exec_ctx, grpc_closure *c, grpc_error *error) { #else @@ -140,7 +144,7 @@ void grpc_closure_run(grpc_exec_ctx *exec_ctx, grpc_closure *c, #endif GPR_TIMER_BEGIN("grpc_closure_run", 0); if (c != NULL) { -#ifdef GRPC_CLOSURE_RICH_DEBUG +#ifndef NDEBUG c->file_initiated = file; c->line_initiated = line; c->run = true; @@ -153,7 +157,7 @@ void grpc_closure_run(grpc_exec_ctx *exec_ctx, grpc_closure *c, GPR_TIMER_END("grpc_closure_run", 0); } -#ifdef GRPC_CLOSURE_RICH_DEBUG +#ifndef NDEBUG void grpc_closure_sched(const char *file, int line, grpc_exec_ctx *exec_ctx, grpc_closure *c, grpc_error *error) { #else @@ -162,7 +166,7 @@ void grpc_closure_sched(grpc_exec_ctx *exec_ctx, grpc_closure *c, #endif GPR_TIMER_BEGIN("grpc_closure_sched", 0); if (c != NULL) { -#ifdef GRPC_CLOSURE_RICH_DEBUG +#ifndef NDEBUG GPR_ASSERT(!c->scheduled); c->scheduled = true; c->file_initiated = file; @@ -177,7 +181,7 @@ void grpc_closure_sched(grpc_exec_ctx *exec_ctx, grpc_closure *c, GPR_TIMER_END("grpc_closure_sched", 0); } -#ifdef GRPC_CLOSURE_RICH_DEBUG +#ifndef NDEBUG void grpc_closure_list_sched(const char *file, int line, grpc_exec_ctx *exec_ctx, grpc_closure_list *list) { #else @@ -186,7 +190,7 @@ void grpc_closure_list_sched(grpc_exec_ctx *exec_ctx, grpc_closure_list *list) { grpc_closure *c = list->head; while (c != NULL) { grpc_closure *next = c->next_data.next; -#ifdef GRPC_CLOSURE_RICH_DEBUG +#ifndef NDEBUG GPR_ASSERT(!c->scheduled); c->scheduled = true; c->file_initiated = file; diff --git a/src/core/lib/iomgr/closure.h b/src/core/lib/iomgr/closure.h index 3ecf9e947bf..2ec6f77e761 100644 --- a/src/core/lib/iomgr/closure.h +++ b/src/core/lib/iomgr/closure.h @@ -29,6 +29,10 @@ struct grpc_closure; typedef struct grpc_closure grpc_closure; +#ifndef NDEBUG +extern grpc_tracer_flag grpc_trace_closure; +#endif + typedef struct grpc_closure_list { grpc_closure *head; grpc_closure *tail; @@ -59,8 +63,6 @@ struct grpc_closure_scheduler { const grpc_closure_scheduler_vtable *vtable; }; -// #define GRPC_CLOSURE_RICH_DEBUG - /** A closure over a grpc_iomgr_cb_func. */ struct grpc_closure { /** Once queued, next indicates the next queued closure; before then, scratch @@ -89,7 +91,7 @@ struct grpc_closure { // extra tracing and debugging for grpc_closure. This incurs a decent amount of // overhead per closure, so it must be enabled at compile time. -#ifdef GRPC_CLOSURE_RICH_DEBUG +#ifndef NDEBUG bool scheduled; bool run; // true = run, false = scheduled const char *file_created; @@ -100,7 +102,7 @@ struct grpc_closure { }; /** Initializes \a closure with \a cb and \a cb_arg. Returns \a closure. */ -#ifdef GRPC_CLOSURE_RICH_DEBUG +#ifndef NDEBUG grpc_closure *grpc_closure_init(const char *file, int line, grpc_closure *closure, grpc_iomgr_cb_func cb, void *cb_arg, @@ -116,7 +118,7 @@ grpc_closure *grpc_closure_init(grpc_closure *closure, grpc_iomgr_cb_func cb, #endif /* Create a heap allocated closure: try to avoid except for very rare events */ -#ifdef GRPC_CLOSURE_RICH_DEBUG +#ifndef NDEBUG grpc_closure *grpc_closure_create(const char *file, int line, grpc_iomgr_cb_func cb, void *cb_arg, grpc_closure_scheduler *scheduler); @@ -153,7 +155,7 @@ bool grpc_closure_list_empty(grpc_closure_list list); /** Run a closure directly. Caller ensures that no locks are being held above. * Note that calling this at the end of a closure callback function itself is * by definition safe. */ -#ifdef GRPC_CLOSURE_RICH_DEBUG +#ifndef NDEBUG void grpc_closure_run(const char *file, int line, grpc_exec_ctx *exec_ctx, grpc_closure *closure, grpc_error *error); #define GRPC_CLOSURE_RUN(exec_ctx, closure, error) \ @@ -166,7 +168,7 @@ void grpc_closure_run(grpc_exec_ctx *exec_ctx, grpc_closure *closure, #endif /** Schedule a closure to be run. Does not need to be run from a safe point. */ -#ifdef GRPC_CLOSURE_RICH_DEBUG +#ifndef NDEBUG void grpc_closure_sched(const char *file, int line, grpc_exec_ctx *exec_ctx, grpc_closure *closure, grpc_error *error); #define GRPC_CLOSURE_SCHED(exec_ctx, closure, error) \ @@ -180,7 +182,7 @@ void grpc_closure_sched(grpc_exec_ctx *exec_ctx, grpc_closure *closure, /** Schedule all closures in a list to be run. Does not need to be run from a * safe point. */ -#ifdef GRPC_CLOSURE_RICH_DEBUG +#ifndef NDEBUG void grpc_closure_list_sched(const char *file, int line, grpc_exec_ctx *exec_ctx, grpc_closure_list *closure_list); diff --git a/src/core/lib/iomgr/combiner.c b/src/core/lib/iomgr/combiner.c index 750ff102ff3..7f9c5d837f8 100644 --- a/src/core/lib/iomgr/combiner.c +++ b/src/core/lib/iomgr/combiner.c @@ -102,12 +102,14 @@ static void start_destroy(grpc_exec_ctx *exec_ctx, grpc_combiner *lock) { } } -#ifdef GRPC_COMBINER_REFCOUNT_DEBUG -#define GRPC_COMBINER_DEBUG_SPAM(op, delta) \ - gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, \ - "combiner[%p] %s %" PRIdPTR " --> %" PRIdPTR " %s", lock, (op), \ - gpr_atm_no_barrier_load(&lock->refs.count), \ - gpr_atm_no_barrier_load(&lock->refs.count) + (delta), reason); +#ifndef NDEBUG +#define GRPC_COMBINER_DEBUG_SPAM(op, delta) \ + if (GRPC_TRACER_ON(grpc_combiner_trace)) { \ + gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, \ + "C:%p %s %" PRIdPTR " --> %" PRIdPTR " %s", lock, (op), \ + gpr_atm_no_barrier_load(&lock->refs.count), \ + gpr_atm_no_barrier_load(&lock->refs.count) + (delta), reason); \ + } #else #define GRPC_COMBINER_DEBUG_SPAM(op, delta) #endif @@ -247,7 +249,7 @@ bool grpc_combiner_continue_exec_ctx(grpc_exec_ctx *exec_ctx) { GPR_TIMER_BEGIN("combiner.exec1", 0); grpc_closure *cl = (grpc_closure *)n; grpc_error *cl_err = cl->error_data.error; -#ifdef GRPC_CLOSURE_RICH_DEBUG +#ifndef NDEBUG cl->scheduled = false; #endif cl->cb(exec_ctx, cl->cb_arg, cl_err); @@ -264,7 +266,7 @@ bool grpc_combiner_continue_exec_ctx(grpc_exec_ctx *exec_ctx) { gpr_log(GPR_DEBUG, "C:%p execute_final[%d] c=%p", lock, loops, c)); grpc_closure *next = c->next_data.next; grpc_error *error = c->error_data.error; -#ifdef GRPC_CLOSURE_RICH_DEBUG +#ifndef NDEBUG c->scheduled = false; #endif c->cb(exec_ctx, c->cb_arg, error); diff --git a/src/core/lib/iomgr/combiner.h b/src/core/lib/iomgr/combiner.h index a616113ca0b..8e0434369d3 100644 --- a/src/core/lib/iomgr/combiner.h +++ b/src/core/lib/iomgr/combiner.h @@ -35,8 +35,7 @@ // necessary grpc_combiner *grpc_combiner_create(void); -//#define GRPC_COMBINER_REFCOUNT_DEBUG -#ifdef GRPC_COMBINER_REFCOUNT_DEBUG +#ifndef NDEBUG #define GRPC_COMBINER_DEBUG_ARGS \ , const char *file, int line, const char *reason #define GRPC_COMBINER_REF(combiner, reason) \ diff --git a/src/core/lib/iomgr/error.c b/src/core/lib/iomgr/error.c index 68884226b55..a95929a1fb5 100644 --- a/src/core/lib/iomgr/error.c +++ b/src/core/lib/iomgr/error.c @@ -30,10 +30,15 @@ #include #endif +#include "src/core/lib/debug/trace.h" #include "src/core/lib/iomgr/error_internal.h" #include "src/core/lib/profiling/timers.h" #include "src/core/lib/slice/slice_internal.h" +#ifndef NDEBUG +grpc_tracer_flag grpc_trace_error_refcount = GRPC_TRACER_INITIALIZER(false); +#endif + static const char *error_int_name(grpc_error_ints key) { switch (key) { case GRPC_ERROR_INT_ERRNO: @@ -119,14 +124,14 @@ bool grpc_error_is_special(grpc_error *err) { err == GRPC_ERROR_CANCELLED; } -#ifdef GRPC_ERROR_REFCOUNT_DEBUG -grpc_error *grpc_error_ref(grpc_error *err, const char *file, int line, - const char *func) { +#ifndef NDEBUG +grpc_error *grpc_error_ref(grpc_error *err, const char *file, int line) { if (grpc_error_is_special(err)) return err; - gpr_log(GPR_DEBUG, "%p: %" PRIdPTR " -> %" PRIdPTR " [%s:%d %s]", err, - gpr_atm_no_barrier_load(&err->atomics.refs.count), - gpr_atm_no_barrier_load(&err->atomics.refs.count) + 1, file, line, - func); + if (GRPC_TRACER_ON(grpc_trace_error_refcount)) { + gpr_log(GPR_DEBUG, "%p: %" PRIdPTR " -> %" PRIdPTR " [%s:%d]", err, + gpr_atm_no_barrier_load(&err->atomics.refs.count), + gpr_atm_no_barrier_load(&err->atomics.refs.count) + 1, file, line); + } gpr_ref(&err->atomics.refs); return err; } @@ -172,14 +177,14 @@ static void error_destroy(grpc_error *err) { gpr_free(err); } -#ifdef GRPC_ERROR_REFCOUNT_DEBUG -void grpc_error_unref(grpc_error *err, const char *file, int line, - const char *func) { +#ifndef NDEBUG +void grpc_error_unref(grpc_error *err, const char *file, int line) { if (grpc_error_is_special(err)) return; - gpr_log(GPR_DEBUG, "%p: %" PRIdPTR " -> %" PRIdPTR " [%s:%d %s]", err, - gpr_atm_no_barrier_load(&err->atomics.refs.count), - gpr_atm_no_barrier_load(&err->atomics.refs.count) - 1, file, line, - func); + if (GRPC_TRACER_ON(grpc_trace_error_refcount)) { + gpr_log(GPR_DEBUG, "%p: %" PRIdPTR " -> %" PRIdPTR " [%s:%d]", err, + gpr_atm_no_barrier_load(&err->atomics.refs.count), + gpr_atm_no_barrier_load(&err->atomics.refs.count) - 1, file, line); + } if (gpr_unref(&err->atomics.refs)) { error_destroy(err); } @@ -202,13 +207,17 @@ static uint8_t get_placement(grpc_error **err, size_t size) { if ((*err)->arena_size + slots > (*err)->arena_capacity) { return UINT8_MAX; } -#ifdef GRPC_ERROR_REFCOUNT_DEBUG +#ifndef NDEBUG grpc_error *orig = *err; #endif *err = gpr_realloc( *err, sizeof(grpc_error) + (*err)->arena_capacity * sizeof(intptr_t)); -#ifdef GRPC_ERROR_REFCOUNT_DEBUG - if (*err != orig) gpr_log(GPR_DEBUG, "realloc %p -> %p", orig, *err); +#ifndef NDEBUG + if (GRPC_TRACER_ON(grpc_trace_error_refcount)) { + if (*err != orig) { + gpr_log(GPR_DEBUG, "realloc %p -> %p", orig, *err); + } + } #endif } uint8_t placement = (*err)->arena_size; @@ -316,8 +325,10 @@ grpc_error *grpc_error_create(const char *file, int line, grpc_slice desc, if (err == NULL) { // TODO(ctiller): make gpr_malloc return NULL return GRPC_ERROR_OOM; } -#ifdef GRPC_ERROR_REFCOUNT_DEBUG - gpr_log(GPR_DEBUG, "%p create [%s:%d]", err, file, line); +#ifndef NDEBUG + if (GRPC_TRACER_ON(grpc_trace_error_refcount)) { + gpr_log(GPR_DEBUG, "%p create [%s:%d]", err, file, line); + } #endif err->arena_size = 0; @@ -395,8 +406,10 @@ static grpc_error *copy_error_and_unref(grpc_error *in) { new_arena_capacity = (uint8_t)(3 * new_arena_capacity / 2); } out = gpr_malloc(sizeof(*in) + new_arena_capacity * sizeof(intptr_t)); -#ifdef GRPC_ERROR_REFCOUNT_DEBUG - gpr_log(GPR_DEBUG, "%p create copying %p", out, in); +#ifndef NDEBUG + if (GRPC_TRACER_ON(grpc_trace_error_refcount)) { + gpr_log(GPR_DEBUG, "%p create copying %p", out, in); + } #endif // bulk memcpy of the rest of the struct. size_t skip = sizeof(&out->atomics); diff --git a/src/core/lib/iomgr/error.h b/src/core/lib/iomgr/error.h index 1ce916f2ec5..b3629486918 100644 --- a/src/core/lib/iomgr/error.h +++ b/src/core/lib/iomgr/error.h @@ -26,6 +26,8 @@ #include #include +#include "src/core/lib/debug/trace.h" + #ifdef __cplusplus extern "C" { #endif @@ -36,6 +38,10 @@ extern "C" { typedef struct grpc_error grpc_error; +#ifndef NDEBUG +extern grpc_tracer_flag grpc_trace_error_refcount; +#endif + typedef enum { /// 'errno' from the operating system GRPC_ERROR_INT_ERRNO, @@ -149,15 +155,11 @@ grpc_error *grpc_error_create(const char *file, int line, grpc_slice desc, grpc_error_create(__FILE__, __LINE__, grpc_slice_from_copied_string(desc), \ errs, count) -// #define GRPC_ERROR_REFCOUNT_DEBUG -#ifdef GRPC_ERROR_REFCOUNT_DEBUG -grpc_error *grpc_error_ref(grpc_error *err, const char *file, int line, - const char *func); -void grpc_error_unref(grpc_error *err, const char *file, int line, - const char *func); -#define GRPC_ERROR_REF(err) grpc_error_ref(err, __FILE__, __LINE__, __func__) -#define GRPC_ERROR_UNREF(err) \ - grpc_error_unref(err, __FILE__, __LINE__, __func__) +#ifndef NDEBUG +grpc_error *grpc_error_ref(grpc_error *err, const char *file, int line); +void grpc_error_unref(grpc_error *err, const char *file, int line); +#define GRPC_ERROR_REF(err) grpc_error_ref(err, __FILE__, __LINE__) +#define GRPC_ERROR_UNREF(err) grpc_error_unref(err, __FILE__, __LINE__) #else grpc_error *grpc_error_ref(grpc_error *err); void grpc_error_unref(grpc_error *err); diff --git a/src/core/lib/iomgr/ev_epoll1_linux.c b/src/core/lib/iomgr/ev_epoll1_linux.c index e0c05457e35..66ba601adb9 100644 --- a/src/core/lib/iomgr/ev_epoll1_linux.c +++ b/src/core/lib/iomgr/ev_epoll1_linux.c @@ -194,8 +194,10 @@ static grpc_fd *fd_create(int fd, const char *name) { char *fd_name; gpr_asprintf(&fd_name, "%s fd=%d", name, fd); grpc_iomgr_register_object(&new_fd->iomgr_object, fd_name); -#ifdef GRPC_FD_REF_COUNT_DEBUG - gpr_log(GPR_DEBUG, "FD %d %p create %s", fd, (void *)new_fd, fd_name); +#ifndef NDEBUG + if (GRPC_TRACER_ON(grpc_trace_fd_refcount)) { + gpr_log(GPR_DEBUG, "FD %d %p create %s", fd, new_fd, fd_name); + } #endif gpr_free(fd_name); diff --git a/src/core/lib/iomgr/ev_epoll_limited_pollers_linux.c b/src/core/lib/iomgr/ev_epoll_limited_pollers_linux.c index 761e2ed5fee..2c91ad357cc 100644 --- a/src/core/lib/iomgr/ev_epoll_limited_pollers_linux.c +++ b/src/core/lib/iomgr/ev_epoll_limited_pollers_linux.c @@ -147,8 +147,7 @@ struct grpc_fd { }; /* Reference counting for fds */ -// #define GRPC_FD_REF_COUNT_DEBUG -#ifdef GRPC_FD_REF_COUNT_DEBUG +#ifndef NDEBUG static void fd_ref(grpc_fd *fd, const char *reason, const char *file, int line); static void fd_unref(grpc_fd *fd, const char *reason, const char *file, int line); @@ -168,20 +167,18 @@ static void fd_global_shutdown(void); * Polling island Declarations */ -//#define PI_REFCOUNT_DEBUG - -#ifdef PI_REFCOUNT_DEBUG +#ifndef NDEBUG #define PI_ADD_REF(p, r) pi_add_ref_dbg((p), (r), __FILE__, __LINE__) #define PI_UNREF(exec_ctx, p, r) \ pi_unref_dbg((exec_ctx), (p), (r), __FILE__, __LINE__) -#else /* defined(PI_REFCOUNT_DEBUG) */ +#else #define PI_ADD_REF(p, r) pi_add_ref((p)) #define PI_UNREF(exec_ctx, p, r) pi_unref((exec_ctx), (p)) -#endif /* !defined(GRPC_PI_REF_COUNT_DEBUG) */ +#endif typedef struct worker_node { struct worker_node *next; @@ -313,21 +310,27 @@ gpr_atm g_epoll_sync; static void pi_add_ref(polling_island *pi); static void pi_unref(grpc_exec_ctx *exec_ctx, polling_island *pi); -#ifdef PI_REFCOUNT_DEBUG +#ifndef NDEBUG static void pi_add_ref_dbg(polling_island *pi, const char *reason, const char *file, int line) { - long old_cnt = gpr_atm_acq_load(&pi->ref_count); + if (GRPC_TRACER_ON(grpc_polling_trace)) { + gpr_atm old_cnt = gpr_atm_acq_load(&pi->ref_count); + gpr_log(GPR_DEBUG, "Add ref pi: %p, old:%" PRIdPTR " -> new:%" PRIdPTR + " (%s) - (%s, %d)", + pi, old_cnt, old_cnt + 1, reason, file, line); + } pi_add_ref(pi); - gpr_log(GPR_DEBUG, "Add ref pi: %p, old: %ld -> new:%ld (%s) - (%s, %d)", - (void *)pi, old_cnt, old_cnt + 1, reason, file, line); } static void pi_unref_dbg(grpc_exec_ctx *exec_ctx, polling_island *pi, const char *reason, const char *file, int line) { - long old_cnt = gpr_atm_acq_load(&pi->ref_count); + if (GRPC_TRACER_ON(grpc_polling_trace)) { + gpr_atm old_cnt = gpr_atm_acq_load(&pi->ref_count); + gpr_log(GPR_DEBUG, "Unref pi: %p, old:%" PRIdPTR " -> new:%" PRIdPTR + " (%s) - (%s, %d)", + pi, old_cnt, (old_cnt - 1), reason, file, line); + } pi_unref(exec_ctx, pi); - gpr_log(GPR_DEBUG, "Unref pi: %p, old:%ld -> new:%ld (%s) - (%s, %d)", - (void *)pi, old_cnt, (old_cnt - 1), reason, file, line); } #endif @@ -792,14 +795,17 @@ static void polling_island_global_shutdown() { static grpc_fd *fd_freelist = NULL; static gpr_mu fd_freelist_mu; -#ifdef GRPC_FD_REF_COUNT_DEBUG +#ifndef NDEBUG #define REF_BY(fd, n, reason) ref_by(fd, n, reason, __FILE__, __LINE__) #define UNREF_BY(fd, n, reason) unref_by(fd, n, reason, __FILE__, __LINE__) static void ref_by(grpc_fd *fd, int n, const char *reason, const char *file, int line) { - gpr_log(GPR_DEBUG, "FD %d %p ref %d %ld -> %ld [%s; %s:%d]", fd->fd, - (void *)fd, n, gpr_atm_no_barrier_load(&fd->refst), - gpr_atm_no_barrier_load(&fd->refst) + n, reason, file, line); + if (GRPC_TRACER_ON(grpc_trace_fd_refcount)) { + gpr_log(GPR_DEBUG, + "FD %d %p ref %d %" PRIdPTR " -> %" PRIdPTR " [%s; %s:%d]", + fd->fd, fd, n, gpr_atm_no_barrier_load(&fd->refst), + gpr_atm_no_barrier_load(&fd->refst) + n, reason, file, line); + } #else #define REF_BY(fd, n, reason) ref_by(fd, n) #define UNREF_BY(fd, n, reason) unref_by(fd, n) @@ -808,18 +814,19 @@ static void ref_by(grpc_fd *fd, int n) { GPR_ASSERT(gpr_atm_no_barrier_fetch_add(&fd->refst, n) > 0); } -#ifdef GRPC_FD_REF_COUNT_DEBUG +#ifndef NDEBUG static void unref_by(grpc_fd *fd, int n, const char *reason, const char *file, int line) { - gpr_atm old; - gpr_log(GPR_DEBUG, "FD %d %p unref %d %ld -> %ld [%s; %s:%d]", fd->fd, - (void *)fd, n, gpr_atm_no_barrier_load(&fd->refst), - gpr_atm_no_barrier_load(&fd->refst) - n, reason, file, line); + if (GRPC_TRACER_ON(grpc_trace_fd_refcount)) { + gpr_log(GPR_DEBUG, + "FD %d %p unref %d %" PRIdPTR " -> %" PRIdPTR " [%s; %s:%d]", + fd->fd, fd, n, gpr_atm_no_barrier_load(&fd->refst), + gpr_atm_no_barrier_load(&fd->refst) - n, reason, file, line); + } #else static void unref_by(grpc_fd *fd, int n) { - gpr_atm old; #endif - old = gpr_atm_full_fetch_add(&fd->refst, -n); + gpr_atm old = gpr_atm_full_fetch_add(&fd->refst, -n); if (old == n) { /* Add the fd to the freelist */ gpr_mu_lock(&fd_freelist_mu); @@ -837,7 +844,7 @@ static void unref_by(grpc_fd *fd, int n) { } /* Increment refcount by two to avoid changing the orphan bit */ -#ifdef GRPC_FD_REF_COUNT_DEBUG +#ifndef NDEBUG static void fd_ref(grpc_fd *fd, const char *reason, const char *file, int line) { ref_by(fd, 2, reason, file, line); @@ -905,8 +912,10 @@ static grpc_fd *fd_create(int fd, const char *name) { char *fd_name; gpr_asprintf(&fd_name, "%s fd=%d", name, fd); grpc_iomgr_register_object(&new_fd->iomgr_object, fd_name); -#ifdef GRPC_FD_REF_COUNT_DEBUG - gpr_log(GPR_DEBUG, "FD %d %p create %s", fd, (void *)new_fd, fd_name); +#ifndef NDEBUG + if (GRPC_TRACER_ON(grpc_trace_fd_refcount)) { + gpr_log(GPR_DEBUG, "FD %d %p create %s", fd, new_fd, fd_name); + } #endif gpr_free(fd_name); return new_fd; diff --git a/src/core/lib/iomgr/ev_epoll_thread_pool_linux.c b/src/core/lib/iomgr/ev_epoll_thread_pool_linux.c index 0ab35948180..49be72c03e0 100644 --- a/src/core/lib/iomgr/ev_epoll_thread_pool_linux.c +++ b/src/core/lib/iomgr/ev_epoll_thread_pool_linux.c @@ -93,20 +93,18 @@ static void fd_global_shutdown(void); * epoll set Declarations */ -//#define EPS_REFCOUNT_DEBUG - -#ifdef EPS_REFCOUNT_DEBUG +#ifndef NDEBUG #define EPS_ADD_REF(p, r) eps_add_ref_dbg((p), (r), __FILE__, __LINE__) #define EPS_UNREF(exec_ctx, p, r) \ eps_unref_dbg((exec_ctx), (p), (r), __FILE__, __LINE__) -#else /* defined(EPS_REFCOUNT_DEBUG) */ +#else #define EPS_ADD_REF(p, r) eps_add_ref((p)) #define EPS_UNREF(exec_ctx, p, r) eps_unref((exec_ctx), (p)) -#endif /* !defined(GRPC_EPS_REF_COUNT_DEBUG) */ +#endif typedef struct epoll_set { /* Mutex poller should acquire to poll this. This enforces that only one @@ -226,21 +224,27 @@ gpr_atm g_epoll_sync; static void eps_add_ref(epoll_set *eps); static void eps_unref(grpc_exec_ctx *exec_ctx, epoll_set *eps); -#ifdef EPS_REFCOUNT_DEBUG +#ifndef NDEBUG static void eps_add_ref_dbg(epoll_set *eps, const char *reason, const char *file, int line) { - long old_cnt = gpr_atm_acq_load(&eps->ref_count); + if (GRPC_TRACER_ON(grpc_polling_trace)) { + gpr_atm old_cnt = gpr_atm_acq_load(&eps->ref_count); + gpr_log(GPR_DEBUG, "Add ref eps: %p, old:%" PRIdPTR " -> new:%" PRIdPTR + " (%s) - (%s, %d)", + eps, old_cnt, old_cnt + 1, reason, file, line); + } eps_add_ref(eps); - gpr_log(GPR_DEBUG, "Add ref eps: %p, old: %ld -> new:%ld (%s) - (%s, %d)", - (void *)eps, old_cnt, old_cnt + 1, reason, file, line); } static void eps_unref_dbg(grpc_exec_ctx *exec_ctx, epoll_set *eps, const char *reason, const char *file, int line) { - long old_cnt = gpr_atm_acq_load(&eps->ref_count); + if (GRPC_TRACER_ON(grpc_polling_trace)) { + gpr_atm old_cnt = gpr_atm_acq_load(&eps->ref_count); + gpr_log(GPR_DEBUG, "Unref eps: %p, old:%" PRIdPTR " -> new:%" PRIdPTR + " (%s) - (%s, %d)", + eps, old_cnt, (old_cnt - 1), reason, file, line); + } eps_unref(exec_ctx, eps); - gpr_log(GPR_DEBUG, "Unref eps: %p, old:%ld -> new:%ld (%s) - (%s, %d)", - (void *)eps, old_cnt, (old_cnt - 1), reason, file, line); } #endif diff --git a/src/core/lib/iomgr/ev_epollex_linux.c b/src/core/lib/iomgr/ev_epollex_linux.c index 949f8a845d4..55748381876 100644 --- a/src/core/lib/iomgr/ev_epollex_linux.c +++ b/src/core/lib/iomgr/ev_epollex_linux.c @@ -231,15 +231,18 @@ static bool append_error(grpc_error **composite, grpc_error *error, static grpc_fd *fd_freelist = NULL; static gpr_mu fd_freelist_mu; -#ifdef GRPC_FD_REF_COUNT_DEBUG +#ifndef NDEBUG #define REF_BY(fd, n, reason) ref_by(fd, n, reason, __FILE__, __LINE__) #define UNREF_BY(ec, fd, n, reason) \ unref_by(ec, fd, n, reason, __FILE__, __LINE__) static void ref_by(grpc_fd *fd, int n, const char *reason, const char *file, int line) { - gpr_log(GPR_DEBUG, "FD %d %p ref %d %ld -> %ld [%s; %s:%d]", fd->fd, - (void *)fd, n, gpr_atm_no_barrier_load(&fd->refst), - gpr_atm_no_barrier_load(&fd->refst) + n, reason, file, line); + if (GRPC_TRACER_ON(grpc_trace_fd_refcount)) { + gpr_log(GPR_DEBUG, + "FD %d %p ref %d %" PRIdPTR " -> %" PRIdPTR " [%s; %s:%d]", + fd->fd, fd, n, gpr_atm_no_barrier_load(&fd->refst), + gpr_atm_no_barrier_load(&fd->refst) + n, reason, file, line); + } #else #define REF_BY(fd, n, reason) ref_by(fd, n) #define UNREF_BY(ec, fd, n, reason) unref_by(ec, fd, n) @@ -264,18 +267,19 @@ static void fd_destroy(grpc_exec_ctx *exec_ctx, void *arg, grpc_error *error) { gpr_mu_unlock(&fd_freelist_mu); } -#ifdef GRPC_FD_REF_COUNT_DEBUG +#ifndef NDEBUG static void unref_by(grpc_exec_ctx *exec_ctx, grpc_fd *fd, int n, const char *reason, const char *file, int line) { - gpr_atm old; - gpr_log(GPR_DEBUG, "FD %d %p unref %d %ld -> %ld [%s; %s:%d]", fd->fd, - (void *)fd, n, gpr_atm_no_barrier_load(&fd->refst), - gpr_atm_no_barrier_load(&fd->refst) - n, reason, file, line); + if (GRPC_TRACER_ON(grpc_trace_fd_refcount)) { + gpr_log(GPR_DEBUG, + "FD %d %p unref %d %" PRIdPTR " -> %" PRIdPTR " [%s; %s:%d]", + fd->fd, fd, n, gpr_atm_no_barrier_load(&fd->refst), + gpr_atm_no_barrier_load(&fd->refst) - n, reason, file, line); + } #else static void unref_by(grpc_exec_ctx *exec_ctx, grpc_fd *fd, int n) { - gpr_atm old; #endif - old = gpr_atm_full_fetch_add(&fd->refst, -n); + gpr_atm old = gpr_atm_full_fetch_add(&fd->refst, -n); if (old == n) { GRPC_CLOSURE_SCHED(exec_ctx, GRPC_CLOSURE_CREATE(fd_destroy, fd, grpc_schedule_on_exec_ctx), @@ -328,8 +332,10 @@ static grpc_fd *fd_create(int fd, const char *name) { char *fd_name; gpr_asprintf(&fd_name, "%s fd=%d", name, fd); grpc_iomgr_register_object(&new_fd->iomgr_object, fd_name); -#ifdef GRPC_FD_REF_COUNT_DEBUG - gpr_log(GPR_DEBUG, "FD %d %p create %s", fd, (void *)new_fd, fd_name); +#ifndef NDEBUG + if (GRPC_TRACER_ON(grpc_trace_fd_refcount)) { + gpr_log(GPR_DEBUG, "FD %d %p create %s", fd, new_fd, fd_name); + } #endif gpr_free(fd_name); return new_fd; diff --git a/src/core/lib/iomgr/ev_epollsig_linux.c b/src/core/lib/iomgr/ev_epollsig_linux.c index fa4b4e8d0ac..17fef01e6ea 100644 --- a/src/core/lib/iomgr/ev_epollsig_linux.c +++ b/src/core/lib/iomgr/ev_epollsig_linux.c @@ -140,8 +140,7 @@ struct grpc_fd { }; /* Reference counting for fds */ -// #define GRPC_FD_REF_COUNT_DEBUG -#ifdef GRPC_FD_REF_COUNT_DEBUG +#ifndef NDEBUG static void fd_ref(grpc_fd *fd, const char *reason, const char *file, int line); static void fd_unref(grpc_fd *fd, const char *reason, const char *file, int line); @@ -161,20 +160,18 @@ static void fd_global_shutdown(void); * Polling island Declarations */ -//#define PI_REFCOUNT_DEBUG - -#ifdef PI_REFCOUNT_DEBUG +#ifndef NDEBUG #define PI_ADD_REF(p, r) pi_add_ref_dbg((p), (r), __FILE__, __LINE__) #define PI_UNREF(exec_ctx, p, r) \ pi_unref_dbg((exec_ctx), (p), (r), __FILE__, __LINE__) -#else /* defined(GRPC_WORKQUEUE_REFCOUNT_DEBUG) */ +#else #define PI_ADD_REF(p, r) pi_add_ref((p)) #define PI_UNREF(exec_ctx, p, r) pi_unref((exec_ctx), (p)) -#endif /* !defined(GRPC_PI_REF_COUNT_DEBUG) */ +#endif /* This is also used as grpc_workqueue (by directly casing it) */ typedef struct polling_island { @@ -287,21 +284,27 @@ gpr_atm g_epoll_sync; static void pi_add_ref(polling_island *pi); static void pi_unref(grpc_exec_ctx *exec_ctx, polling_island *pi); -#ifdef PI_REFCOUNT_DEBUG +#ifndef NDEBUG static void pi_add_ref_dbg(polling_island *pi, const char *reason, const char *file, int line) { - long old_cnt = gpr_atm_acq_load(&pi->ref_count); + if (GRPC_TRACER_ON(grpc_polling_trace)) { + gpr_atm old_cnt = gpr_atm_acq_load(&pi->ref_count); + gpr_log(GPR_DEBUG, "Add ref pi: %p, old:%" PRIdPTR " -> new:%" PRIdPTR + " (%s) - (%s, %d)", + pi, old_cnt, old_cnt + 1, reason, file, line); + } pi_add_ref(pi); - gpr_log(GPR_DEBUG, "Add ref pi: %p, old: %ld -> new:%ld (%s) - (%s, %d)", - (void *)pi, old_cnt, old_cnt + 1, reason, file, line); } static void pi_unref_dbg(grpc_exec_ctx *exec_ctx, polling_island *pi, const char *reason, const char *file, int line) { - long old_cnt = gpr_atm_acq_load(&pi->ref_count); + if (GRPC_TRACER_ON(grpc_polling_trace)) { + gpr_atm old_cnt = gpr_atm_acq_load(&pi->ref_count); + gpr_log(GPR_DEBUG, "Unref pi: %p, old:%" PRIdPTR " -> new:%" PRIdPTR + " (%s) - (%s, %d)", + pi, old_cnt, (old_cnt - 1), reason, file, line); + } pi_unref(exec_ctx, pi); - gpr_log(GPR_DEBUG, "Unref pi: %p, old:%ld -> new:%ld (%s) - (%s, %d)", - (void *)pi, old_cnt, (old_cnt - 1), reason, file, line); } #endif @@ -720,14 +723,17 @@ static void polling_island_global_shutdown() { static grpc_fd *fd_freelist = NULL; static gpr_mu fd_freelist_mu; -#ifdef GRPC_FD_REF_COUNT_DEBUG +#ifndef NDEBUG #define REF_BY(fd, n, reason) ref_by(fd, n, reason, __FILE__, __LINE__) #define UNREF_BY(fd, n, reason) unref_by(fd, n, reason, __FILE__, __LINE__) static void ref_by(grpc_fd *fd, int n, const char *reason, const char *file, int line) { - gpr_log(GPR_DEBUG, "FD %d %p ref %d %ld -> %ld [%s; %s:%d]", fd->fd, - (void *)fd, n, gpr_atm_no_barrier_load(&fd->refst), - gpr_atm_no_barrier_load(&fd->refst) + n, reason, file, line); + if (GRPC_TRACER_ON(grpc_trace_fd_refcount)) { + gpr_log(GPR_DEBUG, + "FD %d %p ref %d %" PRIdPTR " -> %" PRIdPTR " [%s; %s:%d]", + fd->fd, fd, n, gpr_atm_no_barrier_load(&fd->refst), + gpr_atm_no_barrier_load(&fd->refst) + n, reason, file, line); + } #else #define REF_BY(fd, n, reason) ref_by(fd, n) #define UNREF_BY(fd, n, reason) unref_by(fd, n) @@ -736,18 +742,19 @@ static void ref_by(grpc_fd *fd, int n) { GPR_ASSERT(gpr_atm_no_barrier_fetch_add(&fd->refst, n) > 0); } -#ifdef GRPC_FD_REF_COUNT_DEBUG +#ifndef NDEBUG static void unref_by(grpc_fd *fd, int n, const char *reason, const char *file, int line) { - gpr_atm old; - gpr_log(GPR_DEBUG, "FD %d %p unref %d %ld -> %ld [%s; %s:%d]", fd->fd, - (void *)fd, n, gpr_atm_no_barrier_load(&fd->refst), - gpr_atm_no_barrier_load(&fd->refst) - n, reason, file, line); + if (GRPC_TRACER_ON(grpc_trace_fd_refcount)) { + gpr_log(GPR_DEBUG, + "FD %d %p unref %d %" PRIdPTR " -> %" PRIdPTR " [%s; %s:%d]", + fd->fd, fd, n, gpr_atm_no_barrier_load(&fd->refst), + gpr_atm_no_barrier_load(&fd->refst) - n, reason, file, line); + } #else static void unref_by(grpc_fd *fd, int n) { - gpr_atm old; #endif - old = gpr_atm_full_fetch_add(&fd->refst, -n); + gpr_atm old = gpr_atm_full_fetch_add(&fd->refst, -n); if (old == n) { /* Add the fd to the freelist */ gpr_mu_lock(&fd_freelist_mu); @@ -765,7 +772,7 @@ static void unref_by(grpc_fd *fd, int n) { } /* Increment refcount by two to avoid changing the orphan bit */ -#ifdef GRPC_FD_REF_COUNT_DEBUG +#ifndef NDEBUG static void fd_ref(grpc_fd *fd, const char *reason, const char *file, int line) { ref_by(fd, 2, reason, file, line); @@ -833,8 +840,10 @@ static grpc_fd *fd_create(int fd, const char *name) { char *fd_name; gpr_asprintf(&fd_name, "%s fd=%d", name, fd); grpc_iomgr_register_object(&new_fd->iomgr_object, fd_name); -#ifdef GRPC_FD_REF_COUNT_DEBUG - gpr_log(GPR_DEBUG, "FD %d %p create %s", fd, (void *)new_fd, fd_name); +#ifndef NDEBUG + if (GRPC_TRACER_ON(grpc_trace_fd_refcount)) { + gpr_log(GPR_DEBUG, "FD %d %p create %s", fd, new_fd, fd_name); + } #endif gpr_free(fd_name); return new_fd; diff --git a/src/core/lib/iomgr/ev_poll_posix.c b/src/core/lib/iomgr/ev_poll_posix.c index d1a27b82287..1f66159c4a1 100644 --- a/src/core/lib/iomgr/ev_poll_posix.c +++ b/src/core/lib/iomgr/ev_poll_posix.c @@ -134,9 +134,7 @@ static void fd_end_poll(grpc_exec_ctx *exec_ctx, grpc_fd_watcher *rec, /* Return 1 if this fd is orphaned, 0 otherwise */ static bool fd_is_orphaned(grpc_fd *fd); -/* Reference counting for fds */ -//#define GRPC_FD_REF_COUNT_DEBUG -#ifdef GRPC_FD_REF_COUNT_DEBUG +#ifndef NDEBUG static void fd_ref(grpc_fd *fd, const char *reason, const char *file, int line); static void fd_unref(grpc_fd *fd, const char *reason, const char *file, int line); @@ -263,14 +261,17 @@ cv_fd_table g_cvfds; * fd_posix.c */ -#ifdef GRPC_FD_REF_COUNT_DEBUG +#ifndef NDEBUG #define REF_BY(fd, n, reason) ref_by(fd, n, reason, __FILE__, __LINE__) #define UNREF_BY(fd, n, reason) unref_by(fd, n, reason, __FILE__, __LINE__) static void ref_by(grpc_fd *fd, int n, const char *reason, const char *file, int line) { - gpr_log(GPR_DEBUG, "FD %d %p ref %d %d -> %d [%s; %s:%d]", fd->fd, fd, n, - (int)gpr_atm_no_barrier_load(&fd->refst), - (int)gpr_atm_no_barrier_load(&fd->refst) + n, reason, file, line); + if (GRPC_TRACER_ON(grpc_trace_fd_refcount)) { + gpr_log(GPR_DEBUG, + "FD %d %p ref %d %" PRIdPTR " -> %" PRIdPTR " [%s; %s:%d]", + fd->fd, fd, n, gpr_atm_no_barrier_load(&fd->refst), + gpr_atm_no_barrier_load(&fd->refst) + n, reason, file, line); + } #else #define REF_BY(fd, n, reason) ref_by(fd, n) #define UNREF_BY(fd, n, reason) unref_by(fd, n) @@ -279,18 +280,19 @@ static void ref_by(grpc_fd *fd, int n) { GPR_ASSERT(gpr_atm_no_barrier_fetch_add(&fd->refst, n) > 0); } -#ifdef GRPC_FD_REF_COUNT_DEBUG +#ifndef NDEBUG static void unref_by(grpc_fd *fd, int n, const char *reason, const char *file, int line) { - gpr_atm old; - gpr_log(GPR_DEBUG, "FD %d %p unref %d %d -> %d [%s; %s:%d]", fd->fd, fd, n, - (int)gpr_atm_no_barrier_load(&fd->refst), - (int)gpr_atm_no_barrier_load(&fd->refst) - n, reason, file, line); + if (GRPC_TRACER_ON(grpc_trace_fd_refcount)) { + gpr_log(GPR_DEBUG, + "FD %d %p unref %d %" PRIdPTR " -> %" PRIdPTR " [%s; %s:%d]", + fd->fd, fd, n, gpr_atm_no_barrier_load(&fd->refst), + gpr_atm_no_barrier_load(&fd->refst) - n, reason, file, line); + } #else static void unref_by(grpc_fd *fd, int n) { - gpr_atm old; #endif - old = gpr_atm_full_fetch_add(&fd->refst, -n); + gpr_atm old = gpr_atm_full_fetch_add(&fd->refst, -n); if (old == n) { gpr_mu_destroy(&fd->mu); grpc_iomgr_unregister_object(&fd->iomgr_object); @@ -321,8 +323,10 @@ static grpc_fd *fd_create(int fd, const char *name) { gpr_asprintf(&name2, "%s fd=%d", name, fd); grpc_iomgr_register_object(&r->iomgr_object, name2); gpr_free(name2); -#ifdef GRPC_FD_REF_COUNT_DEBUG - gpr_log(GPR_DEBUG, "FD %d %p create %s", fd, r, name); +#ifndef NDEBUG + if (GRPC_TRACER_ON(grpc_trace_fd_refcount)) { + gpr_log(GPR_DEBUG, "FD %d %p create %s", fd, r, name); + } #endif return r; } @@ -417,7 +421,7 @@ static void fd_orphan(grpc_exec_ctx *exec_ctx, grpc_fd *fd, } /* increment refcount by two to avoid changing the orphan bit */ -#ifdef GRPC_FD_REF_COUNT_DEBUG +#ifndef NDEBUG static void fd_ref(grpc_fd *fd, const char *reason, const char *file, int line) { ref_by(fd, 2, reason, file, line); diff --git a/src/core/lib/iomgr/ev_posix.c b/src/core/lib/iomgr/ev_posix.c index dacdb9f4da6..2648df393d7 100644 --- a/src/core/lib/iomgr/ev_posix.c +++ b/src/core/lib/iomgr/ev_posix.c @@ -41,6 +41,10 @@ grpc_tracer_flag grpc_polling_trace = GRPC_TRACER_INITIALIZER(false); /* Disabled by default */ +#ifndef NDEBUG +grpc_tracer_flag grpc_trace_fd_refcount = GRPC_TRACER_INITIALIZER(false); +#endif + /** Default poll() function - a pointer so that it can be overridden by some * tests */ grpc_poll_function_type grpc_poll_function = poll; diff --git a/src/core/lib/iomgr/exec_ctx.c b/src/core/lib/iomgr/exec_ctx.c index 51c36216c5d..833170ceed5 100644 --- a/src/core/lib/iomgr/exec_ctx.c +++ b/src/core/lib/iomgr/exec_ctx.c @@ -62,7 +62,7 @@ bool grpc_exec_ctx_flush(grpc_exec_ctx *exec_ctx) { grpc_closure *next = c->next_data.next; grpc_error *error = c->error_data.error; did_something = true; -#ifdef GRPC_CLOSURE_RICH_DEBUG +#ifndef NDEBUG c->scheduled = false; #endif c->cb(exec_ctx, c->cb_arg, error); @@ -85,10 +85,21 @@ void grpc_exec_ctx_finish(grpc_exec_ctx *exec_ctx) { static void exec_ctx_run(grpc_exec_ctx *exec_ctx, grpc_closure *closure, grpc_error *error) { -#ifdef GRPC_CLOSURE_RICH_DEBUG +#ifndef NDEBUG closure->scheduled = false; + if (GRPC_TRACER_ON(grpc_trace_closure)) { + gpr_log(GPR_DEBUG, "running closure %p: created [%s:%d]: %s [%s:%d]", + closure, closure->file_created, closure->line_created, + closure->run ? "run" : "scheduled", closure->file_initiated, + closure->line_initiated); + } #endif closure->cb(exec_ctx, closure->cb_arg, error); +#ifndef NDEBUG + if (GRPC_TRACER_ON(grpc_trace_closure)) { + gpr_log(GPR_DEBUG, "closure %p finished", closure); + } +#endif GRPC_ERROR_UNREF(error); } diff --git a/src/core/lib/iomgr/executor.c b/src/core/lib/iomgr/executor.c index fda274e7978..7621a7fe75a 100644 --- a/src/core/lib/iomgr/executor.c +++ b/src/core/lib/iomgr/executor.c @@ -58,7 +58,7 @@ static size_t run_closures(grpc_exec_ctx *exec_ctx, grpc_closure_list list) { while (c != NULL) { grpc_closure *next = c->next_data.next; grpc_error *error = c->error_data.error; -#ifdef GRPC_CLOSURE_RICH_DEBUG +#ifndef NDEBUG c->scheduled = false; #endif c->cb(exec_ctx, c->cb_arg, error); diff --git a/src/core/lib/iomgr/pollset.h b/src/core/lib/iomgr/pollset.h index 3ff878e5960..a609a3877a7 100644 --- a/src/core/lib/iomgr/pollset.h +++ b/src/core/lib/iomgr/pollset.h @@ -25,6 +25,10 @@ #include "src/core/lib/iomgr/exec_ctx.h" +#ifndef NDEBUG +extern grpc_tracer_flag grpc_trace_fd_refcount; +#endif + /* A grpc_pollset is a set of file descriptors that a higher level item is interested in. For example: - a server will typically keep a pollset containing all connected channels, diff --git a/src/core/lib/iomgr/pollset_uv.c b/src/core/lib/iomgr/pollset_uv.c index 07c7c045591..1a54065a914 100644 --- a/src/core/lib/iomgr/pollset_uv.c +++ b/src/core/lib/iomgr/pollset_uv.c @@ -31,6 +31,12 @@ #include "src/core/lib/iomgr/pollset.h" #include "src/core/lib/iomgr/pollset_uv.h" +#include "src/core/lib/debug/trace.h" + +#ifndef NDEBUG +grpc_tracer_flag grpc_trace_fd_refcount = GRPC_TRACER_INITIALIZER(false); +#endif + struct grpc_pollset { uv_timer_t timer; int shutting_down; diff --git a/src/core/lib/iomgr/pollset_windows.c b/src/core/lib/iomgr/pollset_windows.c index d5a03732cbe..1bfc2a22a8b 100644 --- a/src/core/lib/iomgr/pollset_windows.c +++ b/src/core/lib/iomgr/pollset_windows.c @@ -30,6 +30,10 @@ #define GRPC_POLLSET_KICK_BROADCAST ((grpc_pollset_worker *)1) +#ifndef NDEBUG +grpc_tracer_flag grpc_trace_fd_refcount = GRPC_TRACER_INITIALIZER(false); +#endif + gpr_mu grpc_polling_mu; static grpc_pollset_worker *g_active_poller; static grpc_pollset_worker g_global_root_worker; diff --git a/src/core/lib/iomgr/tcp_posix.c b/src/core/lib/iomgr/tcp_posix.c index 66e81bf81f7..5de2b0f4ee0 100644 --- a/src/core/lib/iomgr/tcp_posix.c +++ b/src/core/lib/iomgr/tcp_posix.c @@ -163,15 +163,18 @@ static void tcp_free(grpc_exec_ctx *exec_ctx, grpc_tcp *tcp) { gpr_free(tcp); } -/*#define GRPC_TCP_REFCOUNT_DEBUG*/ -#ifdef GRPC_TCP_REFCOUNT_DEBUG +#ifndef NDEBUG #define TCP_UNREF(cl, tcp, reason) \ tcp_unref((cl), (tcp), (reason), __FILE__, __LINE__) #define TCP_REF(tcp, reason) tcp_ref((tcp), (reason), __FILE__, __LINE__) static void tcp_unref(grpc_exec_ctx *exec_ctx, grpc_tcp *tcp, const char *reason, const char *file, int line) { - gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, "TCP unref %p : %s %d -> %d", tcp, - reason, tcp->refcount.count, tcp->refcount.count - 1); + if (GRPC_TRACER_ON(grpc_tcp_trace)) { + gpr_atm val = gpr_atm_no_barrier_load(&tcp->refcount.count); + gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, + "TCP unref %p : %s %" PRIdPTR " -> %" PRIdPTR, tcp, reason, val, + val - 1); + } if (gpr_unref(&tcp->refcount)) { tcp_free(exec_ctx, tcp); } @@ -179,8 +182,12 @@ static void tcp_unref(grpc_exec_ctx *exec_ctx, grpc_tcp *tcp, static void tcp_ref(grpc_tcp *tcp, const char *reason, const char *file, int line) { - gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, "TCP ref %p : %s %d -> %d", tcp, - reason, tcp->refcount.count, tcp->refcount.count + 1); + if (GRPC_TRACER_ON(grpc_tcp_trace)) { + gpr_atm val = gpr_atm_no_barrier_load(&tcp->refcount.count); + gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, + "TCP ref %p : %s %" PRIdPTR " -> %" PRIdPTR, tcp, reason, val, + val + 1); + } gpr_ref(&tcp->refcount); } #else diff --git a/src/core/lib/iomgr/tcp_uv.c b/src/core/lib/iomgr/tcp_uv.c index ab5bb9f7dac..7c21b44e76c 100644 --- a/src/core/lib/iomgr/tcp_uv.c +++ b/src/core/lib/iomgr/tcp_uv.c @@ -69,16 +69,18 @@ static void tcp_free(grpc_exec_ctx *exec_ctx, grpc_tcp *tcp) { gpr_free(tcp); } -/*#define GRPC_TCP_REFCOUNT_DEBUG*/ -#ifdef GRPC_TCP_REFCOUNT_DEBUG +#ifndef NDEBUG #define TCP_UNREF(exec_ctx, tcp, reason) \ tcp_unref((exec_ctx), (tcp), (reason), __FILE__, __LINE__) #define TCP_REF(tcp, reason) tcp_ref((tcp), (reason), __FILE__, __LINE__) static void tcp_unref(grpc_exec_ctx *exec_ctx, grpc_tcp *tcp, const char *reason, const char *file, int line) { - gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, - "TCP unref %p : %s %" PRIiPTR " -> %" PRIiPTR, tcp, reason, - tcp->refcount.count, tcp->refcount.count - 1); + if (GRPC_TRACER_ON(grpc_tcp_trace)) { + gpr_atm val = gpr_atm_no_barrier_load(&tcp->refcount.count); + gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, + "TCP unref %p : %s %" PRIdPTR " -> %" PRIdPTR, tcp, reason, val, + val - 1); + } if (gpr_unref(&tcp->refcount)) { tcp_free(exec_ctx, tcp); } @@ -86,9 +88,12 @@ static void tcp_unref(grpc_exec_ctx *exec_ctx, grpc_tcp *tcp, static void tcp_ref(grpc_tcp *tcp, const char *reason, const char *file, int line) { - gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, - "TCP ref %p : %s %" PRIiPTR " -> %" PRIiPTR, tcp, reason, - tcp->refcount.count, tcp->refcount.count + 1); + if (GRPC_TRACER_ON(grpc_tcp_trace)) { + gpr_atm val = gpr_atm_no_barrier_load(&tcp->refcount.count); + gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, + "TCP ref %p : %s %" PRIdPTR " -> %" PRIdPTR, tcp, reason, val, + val + 1); + } gpr_ref(&tcp->refcount); } #else diff --git a/src/core/lib/iomgr/tcp_windows.c b/src/core/lib/iomgr/tcp_windows.c index 161b3975349..6704a158ceb 100644 --- a/src/core/lib/iomgr/tcp_windows.c +++ b/src/core/lib/iomgr/tcp_windows.c @@ -48,6 +48,8 @@ #define GRPC_FIONBIO FIONBIO #endif +grpc_tracer_flag grpc_tcp_trace = GRPC_TRACER_INITIALIZER(false); + static grpc_error *set_non_block(SOCKET sock) { int status; uint32_t param = 1; @@ -115,15 +117,18 @@ static void tcp_free(grpc_exec_ctx *exec_ctx, grpc_tcp *tcp) { gpr_free(tcp); } -/*#define GRPC_TCP_REFCOUNT_DEBUG*/ -#ifdef GRPC_TCP_REFCOUNT_DEBUG +#ifndef NDEBUG #define TCP_UNREF(exec_ctx, tcp, reason) \ tcp_unref((exec_ctx), (tcp), (reason), __FILE__, __LINE__) #define TCP_REF(tcp, reason) tcp_ref((tcp), (reason), __FILE__, __LINE__) static void tcp_unref(grpc_exec_ctx *exec_ctx, grpc_tcp *tcp, const char *reason, const char *file, int line) { - gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, "TCP unref %p : %s %d -> %d", tcp, - reason, tcp->refcount.count, tcp->refcount.count - 1); + if (GRPC_TRACER_ON(grpc_tcp_trace)) { + gpr_atm val = gpr_atm_no_barrier_load(&tcp->refcount.count); + gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, + "TCP unref %p : %s %" PRIdPTR " -> %" PRIdPTR, tcp, reason, val, + val - 1); + } if (gpr_unref(&tcp->refcount)) { tcp_free(exec_ctx, tcp); } @@ -131,8 +136,12 @@ static void tcp_unref(grpc_exec_ctx *exec_ctx, grpc_tcp *tcp, static void tcp_ref(grpc_tcp *tcp, const char *reason, const char *file, int line) { - gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, "TCP ref %p : %s %d -> %d", tcp, - reason, tcp->refcount.count, tcp->refcount.count + 1); + if (GRPC_TRACER_ON(grpc_tcp_trace)) { + gpr_atm val = gpr_atm_no_barrier_load(&tcp->refcount.count); + gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, + "TCP ref %p : %s %" PRIdPTR " -> %" PRIdPTR, tcp, reason, val, + val + 1); + } gpr_ref(&tcp->refcount); } #else diff --git a/src/core/lib/security/context/security_context.c b/src/core/lib/security/context/security_context.c index 02b6d0164b3..dffe6d2e912 100644 --- a/src/core/lib/security/context/security_context.c +++ b/src/core/lib/security/context/security_context.c @@ -29,6 +29,11 @@ #include #include +#ifndef NDEBUG +grpc_tracer_flag grpc_trace_auth_context_refcount = + GRPC_TRACER_INITIALIZER(false); +#endif + /* --- grpc_call --- */ grpc_call_error grpc_call_set_credentials(grpc_call *call, @@ -122,14 +127,17 @@ grpc_auth_context *grpc_auth_context_create(grpc_auth_context *chained) { return ctx; } -#ifdef GRPC_AUTH_CONTEXT_REFCOUNT_DEBUG +#ifndef NDEBUG grpc_auth_context *grpc_auth_context_ref(grpc_auth_context *ctx, const char *file, int line, const char *reason) { if (ctx == NULL) return NULL; - gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, - "AUTH_CONTEXT:%p ref %d -> %d %s", ctx, (int)ctx->refcount.count, - (int)ctx->refcount.count + 1, reason); + if (GRPC_TRACER_ON(grpc_trace_auth_context_refcount)) { + gpr_atm val = gpr_atm_no_barrier_load(&ctx->refcount.count); + gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, + "AUTH_CONTEXT:%p ref %" PRIdPTR " -> %" PRIdPTR " %s", ctx, val, + val + 1, reason); + } #else grpc_auth_context *grpc_auth_context_ref(grpc_auth_context *ctx) { if (ctx == NULL) return NULL; @@ -138,13 +146,16 @@ grpc_auth_context *grpc_auth_context_ref(grpc_auth_context *ctx) { return ctx; } -#ifdef GRPC_AUTH_CONTEXT_REFCOUNT_DEBUG +#ifndef NDEBUG void grpc_auth_context_unref(grpc_auth_context *ctx, const char *file, int line, const char *reason) { if (ctx == NULL) return; - gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, - "AUTH_CONTEXT:%p unref %d -> %d %s", ctx, (int)ctx->refcount.count, - (int)ctx->refcount.count - 1, reason); + if (GRPC_TRACER_ON(grpc_trace_auth_context_refcount)) { + gpr_atm val = gpr_atm_no_barrier_load(&ctx->refcount.count); + gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, + "AUTH_CONTEXT:%p unref %" PRIdPTR " -> %" PRIdPTR " %s", ctx, val, + val - 1, reason); + } #else void grpc_auth_context_unref(grpc_auth_context *ctx) { if (ctx == NULL) return; diff --git a/src/core/lib/security/context/security_context.h b/src/core/lib/security/context/security_context.h index 102f9d6e2ff..0df39257a7a 100644 --- a/src/core/lib/security/context/security_context.h +++ b/src/core/lib/security/context/security_context.h @@ -22,6 +22,10 @@ #include "src/core/lib/iomgr/pollset.h" #include "src/core/lib/security/credentials/credentials.h" +#ifndef NDEBUG +extern grpc_tracer_flag grpc_trace_auth_context_refcount; +#endif + #ifdef __cplusplus extern "C" { #endif @@ -50,7 +54,7 @@ struct grpc_auth_context { grpc_auth_context *grpc_auth_context_create(grpc_auth_context *chained); /* Refcounting. */ -#ifdef GRPC_AUTH_CONTEXT_REFCOUNT_DEBUG +#ifndef NDEBUG #define GRPC_AUTH_CONTEXT_REF(p, r) \ grpc_auth_context_ref((p), __FILE__, __LINE__, (r)) #define GRPC_AUTH_CONTEXT_UNREF(p, r) \ diff --git a/src/core/lib/security/transport/secure_endpoint.c b/src/core/lib/security/transport/secure_endpoint.c index 140cf294aed..f4ed81db1a0 100644 --- a/src/core/lib/security/transport/secure_endpoint.c +++ b/src/core/lib/security/transport/secure_endpoint.c @@ -75,18 +75,20 @@ static void destroy(grpc_exec_ctx *exec_ctx, secure_endpoint *secure_ep) { gpr_free(ep); } -/*#define GRPC_SECURE_ENDPOINT_REFCOUNT_DEBUG*/ -#ifdef GRPC_SECURE_ENDPOINT_REFCOUNT_DEBUG +#ifndef NDEBUG #define SECURE_ENDPOINT_UNREF(exec_ctx, ep, reason) \ secure_endpoint_unref((exec_ctx), (ep), (reason), __FILE__, __LINE__) #define SECURE_ENDPOINT_REF(ep, reason) \ secure_endpoint_ref((ep), (reason), __FILE__, __LINE__) -static void secure_endpoint_unref(secure_endpoint *ep, - grpc_closure_list *closure_list, +static void secure_endpoint_unref(grpc_exec_ctx *exec_ctx, secure_endpoint *ep, const char *reason, const char *file, int line) { - gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, "SECENDP unref %p : %s %d -> %d", - ep, reason, ep->ref.count, ep->ref.count - 1); + if (GRPC_TRACER_ON(grpc_trace_secure_endpoint)) { + gpr_atm val = gpr_atm_no_barrier_load(&ep->ref.count); + gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, + "SECENDP unref %p : %s %" PRIdPTR " -> %" PRIdPTR, ep, reason, val, + val - 1); + } if (gpr_unref(&ep->ref)) { destroy(exec_ctx, ep); } @@ -94,8 +96,12 @@ static void secure_endpoint_unref(secure_endpoint *ep, static void secure_endpoint_ref(secure_endpoint *ep, const char *reason, const char *file, int line) { - gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, "SECENDP ref %p : %s %d -> %d", - ep, reason, ep->ref.count, ep->ref.count + 1); + if (GRPC_TRACER_ON(grpc_trace_secure_endpoint)) { + gpr_atm val = gpr_atm_no_barrier_load(&ep->ref.count); + gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, + "SECENDP ref %p : %s %" PRIdPTR " -> %" PRIdPTR, ep, reason, val, + val + 1); + } gpr_ref(&ep->ref); } #else diff --git a/src/core/lib/security/transport/security_connector.c b/src/core/lib/security/transport/security_connector.c index 9934d57ee62..3c0c24254b7 100644 --- a/src/core/lib/security/transport/security_connector.c +++ b/src/core/lib/security/transport/security_connector.c @@ -43,6 +43,11 @@ #include "src/core/tsi/ssl_transport_security.h" #include "src/core/tsi/transport_security_adapter.h" +#ifndef NDEBUG +grpc_tracer_flag grpc_trace_security_connector_refcount = + GRPC_TRACER_INITIALIZER(false); +#endif + /* -- Constants. -- */ #ifndef INSTALL_PREFIX @@ -142,14 +147,17 @@ void grpc_channel_security_connector_check_call_host( } } -#ifdef GRPC_SECURITY_CONNECTOR_REFCOUNT_DEBUG +#ifndef NDEBUG grpc_security_connector *grpc_security_connector_ref( grpc_security_connector *sc, const char *file, int line, const char *reason) { if (sc == NULL) return NULL; - gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, - "SECURITY_CONNECTOR:%p ref %d -> %d %s", sc, - (int)sc->refcount.count, (int)sc->refcount.count + 1, reason); + if (GRPC_TRACER_ON(grpc_trace_security_connector_refcount)) { + gpr_atm val = gpr_atm_no_barrier_load(&sc->refcount.count); + gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, + "SECURITY_CONNECTOR:%p ref %" PRIdPTR " -> %" PRIdPTR " %s", sc, + val, val + 1, reason); + } #else grpc_security_connector *grpc_security_connector_ref( grpc_security_connector *sc) { @@ -159,15 +167,18 @@ grpc_security_connector *grpc_security_connector_ref( return sc; } -#ifdef GRPC_SECURITY_CONNECTOR_REFCOUNT_DEBUG +#ifndef NDEBUG void grpc_security_connector_unref(grpc_exec_ctx *exec_ctx, grpc_security_connector *sc, const char *file, int line, const char *reason) { if (sc == NULL) return; - gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, - "SECURITY_CONNECTOR:%p unref %d -> %d %s", sc, - (int)sc->refcount.count, (int)sc->refcount.count - 1, reason); + if (GRPC_TRACER_ON(grpc_trace_security_connector_refcount)) { + gpr_atm val = gpr_atm_no_barrier_load(&sc->refcount.count); + gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, + "SECURITY_CONNECTOR:%p unref %" PRIdPTR " -> %" PRIdPTR " %s", sc, + val, val - 1, reason); + } #else void grpc_security_connector_unref(grpc_exec_ctx *exec_ctx, grpc_security_connector *sc) { diff --git a/src/core/lib/security/transport/security_connector.h b/src/core/lib/security/transport/security_connector.h index 24b1086ee3a..1c0fe40045d 100644 --- a/src/core/lib/security/transport/security_connector.h +++ b/src/core/lib/security/transport/security_connector.h @@ -29,6 +29,10 @@ #include "src/core/tsi/ssl_transport_security.h" #include "src/core/tsi/transport_security_interface.h" +#ifndef NDEBUG +extern grpc_tracer_flag grpc_trace_security_connector_refcount; +#endif + /* --- status enum. --- */ typedef enum { GRPC_SECURITY_OK = 0, GRPC_SECURITY_ERROR } grpc_security_status; @@ -66,7 +70,7 @@ struct grpc_security_connector { }; /* Refcounting. */ -#ifdef GRPC_SECURITY_CONNECTOR_REFCOUNT_DEBUG +#ifndef NDEBUG #define GRPC_SECURITY_CONNECTOR_REF(p, r) \ grpc_security_connector_ref((p), __FILE__, __LINE__, (r)) #define GRPC_SECURITY_CONNECTOR_UNREF(exec_ctx, p, r) \ diff --git a/src/core/lib/surface/call.c b/src/core/lib/surface/call.c index b499219e170..bea75bc2d68 100644 --- a/src/core/lib/surface/call.c +++ b/src/core/lib/surface/call.c @@ -457,7 +457,7 @@ void grpc_call_set_completion_queue(grpc_exec_ctx *exec_ctx, grpc_call *call, exec_ctx, CALL_STACK_FROM_CALL(call), &call->pollent); } -#ifdef GRPC_STREAM_REFCOUNT_DEBUG +#ifndef NDEBUG #define REF_REASON reason #define REF_ARG , const char *reason #else diff --git a/src/core/lib/surface/call.h b/src/core/lib/surface/call.h index 60b661cf8cd..185bfccb77d 100644 --- a/src/core/lib/surface/call.h +++ b/src/core/lib/surface/call.h @@ -62,7 +62,7 @@ grpc_error *grpc_call_create(grpc_exec_ctx *exec_ctx, void grpc_call_set_completion_queue(grpc_exec_ctx *exec_ctx, grpc_call *call, grpc_completion_queue *cq); -#ifdef GRPC_STREAM_REFCOUNT_DEBUG +#ifndef NDEBUG void grpc_call_internal_ref(grpc_call *call, const char *reason); void grpc_call_internal_unref(grpc_exec_ctx *exec_ctx, grpc_call *call, const char *reason); diff --git a/src/core/lib/surface/channel.c b/src/core/lib/surface/channel.c index 5647dff28b1..5780a18ce8e 100644 --- a/src/core/lib/surface/channel.c +++ b/src/core/lib/surface/channel.c @@ -345,7 +345,7 @@ grpc_call *grpc_channel_create_registered_call( return call; } -#ifdef GRPC_STREAM_REFCOUNT_DEBUG +#ifndef NDEBUG #define REF_REASON reason #define REF_ARG , const char *reason #else diff --git a/src/core/lib/surface/channel.h b/src/core/lib/surface/channel.h index 848debc7c58..528bb868e2c 100644 --- a/src/core/lib/surface/channel.h +++ b/src/core/lib/surface/channel.h @@ -59,7 +59,7 @@ grpc_mdelem grpc_channel_get_reffed_status_elem(grpc_exec_ctx *exec_ctx, size_t grpc_channel_get_call_size_estimate(grpc_channel *channel); void grpc_channel_update_call_size_estimate(grpc_channel *channel, size_t size); -#ifdef GRPC_STREAM_REFCOUNT_DEBUG +#ifndef NDEBUG void grpc_channel_internal_ref(grpc_channel *channel, const char *reason); void grpc_channel_internal_unref(grpc_exec_ctx *exec_ctx, grpc_channel *channel, const char *reason); diff --git a/src/core/lib/surface/completion_queue.c b/src/core/lib/surface/completion_queue.c index 1a5c7212148..b04aee6c73b 100644 --- a/src/core/lib/surface/completion_queue.c +++ b/src/core/lib/surface/completion_queue.c @@ -38,6 +38,7 @@ grpc_tracer_flag grpc_trace_operation_failures = GRPC_TRACER_INITIALIZER(false); #ifndef NDEBUG grpc_tracer_flag grpc_trace_pending_tags = GRPC_TRACER_INITIALIZER(false); +grpc_tracer_flag grpc_trace_cq_refcount = GRPC_TRACER_INITIALIZER(false); #endif typedef struct { @@ -437,12 +438,16 @@ int grpc_get_cq_poll_num(grpc_completion_queue *cc) { return cur_num_polls; } -#ifdef GRPC_CQ_REF_COUNT_DEBUG +#ifndef NDEBUG void grpc_cq_internal_ref(grpc_completion_queue *cc, const char *reason, const char *file, int line) { cq_data *cqd = &cc->data; - gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, "CQ:%p ref %d -> %d %s", cc, - (int)cqd->owning_refs.count, (int)cqd->owning_refs.count + 1, reason); + if (GRPC_TRACER_ON(grpc_trace_cq_refcount)) { + gpr_atm val = gpr_atm_no_barrier_load(&cqd->owning_refs.count); + gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, + "CQ:%p ref %" PRIdPTR " -> %" PRIdPTR " %s", cc, val, val + 1, + reason); + } #else void grpc_cq_internal_ref(grpc_completion_queue *cc) { cq_data *cqd = &cc->data; @@ -456,12 +461,16 @@ static void on_pollset_shutdown_done(grpc_exec_ctx *exec_ctx, void *arg, GRPC_CQ_INTERNAL_UNREF(exec_ctx, cc, "pollset_destroy"); } -#ifdef GRPC_CQ_REF_COUNT_DEBUG -void grpc_cq_internal_unref(grpc_completion_queue *cc, const char *reason, - const char *file, int line) { +#ifndef NDEBUG +void grpc_cq_internal_unref(grpc_exec_ctx *exec_ctx, grpc_completion_queue *cc, + const char *reason, const char *file, int line) { cq_data *cqd = &cc->data; - gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, "CQ:%p unref %d -> %d %s", cc, - (int)cqd->owning_refs.count, (int)cqd->owning_refs.count - 1, reason); + if (GRPC_TRACER_ON(grpc_trace_cq_refcount)) { + gpr_atm val = gpr_atm_no_barrier_load(&cqd->owning_refs.count); + gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, + "CQ:%p unref %" PRIdPTR " -> %" PRIdPTR " %s", cc, val, val - 1, + reason); + } #else void grpc_cq_internal_unref(grpc_exec_ctx *exec_ctx, grpc_completion_queue *cc) { diff --git a/src/core/lib/surface/completion_queue.h b/src/core/lib/surface/completion_queue.h index 49097bac395..97ea9cae209 100644 --- a/src/core/lib/surface/completion_queue.h +++ b/src/core/lib/surface/completion_queue.h @@ -30,8 +30,10 @@ extern grpc_tracer_flag grpc_cq_pluck_trace; extern grpc_tracer_flag grpc_cq_event_timeout_trace; extern grpc_tracer_flag grpc_trace_operation_failures; + #ifndef NDEBUG extern grpc_tracer_flag grpc_trace_pending_tags; +extern grpc_tracer_flag grpc_trace_cq_refcount; #endif #ifdef __cplusplus @@ -52,9 +54,7 @@ typedef struct grpc_cq_completion { uintptr_t next; } grpc_cq_completion; -//#define GRPC_CQ_REF_COUNT_DEBUG - -#ifdef GRPC_CQ_REF_COUNT_DEBUG +#ifndef NDEBUG void grpc_cq_internal_ref(grpc_completion_queue *cc, const char *reason, const char *file, int line); void grpc_cq_internal_unref(grpc_exec_ctx *exec_ctx, grpc_completion_queue *cc, diff --git a/src/core/lib/surface/init.c b/src/core/lib/surface/init.c index 01a1f33db2f..14a86bfa0a8 100644 --- a/src/core/lib/surface/init.c +++ b/src/core/lib/surface/init.c @@ -126,18 +126,23 @@ void grpc_init(void) { grpc_register_tracer("channel_stack_builder", &grpc_trace_channel_stack_builder); grpc_register_tracer("http1", &grpc_http1_trace); - grpc_register_tracer("queue_pluck", &grpc_cq_pluck_trace); + grpc_register_tracer("queue_pluck", &grpc_cq_pluck_trace); // default on grpc_register_tracer("combiner", &grpc_combiner_trace); grpc_register_tracer("server_channel", &grpc_server_channel_trace); grpc_register_tracer("bdp_estimator", &grpc_bdp_estimator_trace); - // Default pluck trace to 1 - grpc_register_tracer("queue_timeout", &grpc_cq_event_timeout_trace); - // Default timeout trace to 1 + grpc_register_tracer("queue_timeout", + &grpc_cq_event_timeout_trace); // default on grpc_register_tracer("op_failure", &grpc_trace_operation_failures); grpc_register_tracer("resource_quota", &grpc_resource_quota_trace); grpc_register_tracer("call_error", &grpc_call_error_trace); #ifndef NDEBUG grpc_register_tracer("pending_tags", &grpc_trace_pending_tags); + grpc_register_tracer("queue_refcount", &grpc_trace_cq_refcount); + grpc_register_tracer("closure", &grpc_trace_closure); + grpc_register_tracer("error_refcount", &grpc_trace_error_refcount); + grpc_register_tracer("stream_refcount", &grpc_trace_stream_refcount); + grpc_register_tracer("fd_refcount", &grpc_trace_fd_refcount); + grpc_register_tracer("metadata", &grpc_trace_metadata); #endif grpc_security_pre_init(); grpc_iomgr_init(&exec_ctx); diff --git a/src/core/lib/surface/init_secure.c b/src/core/lib/surface/init_secure.c index fb6635716d1..7dbea581d01 100644 --- a/src/core/lib/surface/init_secure.c +++ b/src/core/lib/surface/init_secure.c @@ -32,9 +32,19 @@ #include "src/core/lib/surface/channel_init.h" #include "src/core/tsi/transport_security_interface.h" +#ifndef NDEBUG +#include "src/core/lib/security/context/security_context.h" +#endif + void grpc_security_pre_init(void) { grpc_register_tracer("secure_endpoint", &grpc_trace_secure_endpoint); grpc_register_tracer("transport_security", &tsi_tracing_enabled); +#ifndef NDEBUG + grpc_register_tracer("auth_context_refcount", + &grpc_trace_auth_context_refcount); + grpc_register_tracer("security_connector_refcount", + &grpc_trace_security_connector_refcount); +#endif } static bool maybe_prepend_client_auth_filter( diff --git a/src/core/lib/transport/metadata.c b/src/core/lib/transport/metadata.c index 94917307193..87a2abf3443 100644 --- a/src/core/lib/transport/metadata.c +++ b/src/core/lib/transport/metadata.c @@ -47,7 +47,8 @@ * used to determine which kind of element a pointer refers to. */ -#ifdef GRPC_METADATA_REFCOUNT_DEBUG +#ifndef NDEBUG +grpc_tracer_flag grpc_trace_metadata = GRPC_TRACER_INITIALIZER(false); #define DEBUG_ARGS , const char *file, int line #define FWD_DEBUG_ARGS , file, line #define REF_MD_LOCKED(shard, s) ref_md_locked((shard), (s), __FILE__, __LINE__) @@ -144,15 +145,17 @@ static int is_mdelem_static(grpc_mdelem e) { static void ref_md_locked(mdtab_shard *shard, interned_metadata *md DEBUG_ARGS) { -#ifdef GRPC_METADATA_REFCOUNT_DEBUG - char *key_str = grpc_slice_to_c_string(md->key); - char *value_str = grpc_slice_to_c_string(md->value); - gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, - "ELM REF:%p:%zu->%zu: '%s' = '%s'", (void *)md, - gpr_atm_no_barrier_load(&md->refcnt), - gpr_atm_no_barrier_load(&md->refcnt) + 1, key_str, value_str); - gpr_free(key_str); - gpr_free(value_str); +#ifndef NDEBUG + if (GRPC_TRACER_ON(grpc_trace_metadata)) { + char *key_str = grpc_slice_to_c_string(md->key); + char *value_str = grpc_slice_to_c_string(md->value); + gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, + "ELM REF:%p:%" PRIdPTR "->%" PRIdPTR ": '%s' = '%s'", (void *)md, + gpr_atm_no_barrier_load(&md->refcnt), + gpr_atm_no_barrier_load(&md->refcnt) + 1, key_str, value_str); + gpr_free(key_str); + gpr_free(value_str); + } #endif if (0 == gpr_atm_no_barrier_fetch_add(&md->refcnt, 1)) { gpr_atm_no_barrier_fetch_add(&shard->free_estimate, -1); @@ -243,13 +246,16 @@ grpc_mdelem grpc_mdelem_create( allocated->key = grpc_slice_ref_internal(key); allocated->value = grpc_slice_ref_internal(value); gpr_atm_rel_store(&allocated->refcnt, 1); -#ifdef GRPC_METADATA_REFCOUNT_DEBUG - char *key_str = grpc_slice_to_c_string(allocated->key); - char *value_str = grpc_slice_to_c_string(allocated->value); - gpr_log(GPR_DEBUG, "ELM ALLOC:%p:%zu: '%s' = '%s'", (void *)allocated, - gpr_atm_no_barrier_load(&allocated->refcnt), key_str, value_str); - gpr_free(key_str); - gpr_free(value_str); +#ifndef NDEBUG + if (GRPC_TRACER_ON(grpc_trace_metadata)) { + char *key_str = grpc_slice_to_c_string(allocated->key); + char *value_str = grpc_slice_to_c_string(allocated->value); + gpr_log(GPR_DEBUG, "ELM ALLOC:%p:%" PRIdPTR ": '%s' = '%s'", + (void *)allocated, gpr_atm_no_barrier_load(&allocated->refcnt), + key_str, value_str); + gpr_free(key_str); + gpr_free(value_str); + } #endif return GRPC_MAKE_MDELEM(allocated, GRPC_MDELEM_STORAGE_ALLOCATED); } @@ -294,13 +300,15 @@ grpc_mdelem grpc_mdelem_create( md->bucket_next = shard->elems[idx]; shard->elems[idx] = md; gpr_mu_init(&md->mu_user_data); -#ifdef GRPC_METADATA_REFCOUNT_DEBUG - char *key_str = grpc_slice_to_c_string(md->key); - char *value_str = grpc_slice_to_c_string(md->value); - gpr_log(GPR_DEBUG, "ELM NEW:%p:%zu: '%s' = '%s'", (void *)md, - gpr_atm_no_barrier_load(&md->refcnt), key_str, value_str); - gpr_free(key_str); - gpr_free(value_str); +#ifndef NDEBUG + if (GRPC_TRACER_ON(grpc_trace_metadata)) { + char *key_str = grpc_slice_to_c_string(md->key); + char *value_str = grpc_slice_to_c_string(md->value); + gpr_log(GPR_DEBUG, "ELM NEW:%p:%" PRIdPTR ": '%s' = '%s'", (void *)md, + gpr_atm_no_barrier_load(&md->refcnt), key_str, value_str); + gpr_free(key_str); + gpr_free(value_str); + } #endif shard->count++; @@ -356,15 +364,17 @@ grpc_mdelem grpc_mdelem_ref(grpc_mdelem gmd DEBUG_ARGS) { break; case GRPC_MDELEM_STORAGE_INTERNED: { interned_metadata *md = (interned_metadata *)GRPC_MDELEM_DATA(gmd); -#ifdef GRPC_METADATA_REFCOUNT_DEBUG - char *key_str = grpc_slice_to_c_string(md->key); - char *value_str = grpc_slice_to_c_string(md->value); - gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, - "ELM REF:%p:%zu->%zu: '%s' = '%s'", (void *)md, - gpr_atm_no_barrier_load(&md->refcnt), - gpr_atm_no_barrier_load(&md->refcnt) + 1, key_str, value_str); - gpr_free(key_str); - gpr_free(value_str); +#ifndef NDEBUG + if (GRPC_TRACER_ON(grpc_trace_metadata)) { + char *key_str = grpc_slice_to_c_string(md->key); + char *value_str = grpc_slice_to_c_string(md->value); + gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, + "ELM REF:%p:%" PRIdPTR "->%" PRIdPTR ": '%s' = '%s'", + (void *)md, gpr_atm_no_barrier_load(&md->refcnt), + gpr_atm_no_barrier_load(&md->refcnt) + 1, key_str, value_str); + gpr_free(key_str); + gpr_free(value_str); + } #endif /* we can assume the ref count is >= 1 as the application is calling this function - meaning that no adjustment to mdtab_free is necessary, @@ -376,15 +386,17 @@ grpc_mdelem grpc_mdelem_ref(grpc_mdelem gmd DEBUG_ARGS) { } case GRPC_MDELEM_STORAGE_ALLOCATED: { allocated_metadata *md = (allocated_metadata *)GRPC_MDELEM_DATA(gmd); -#ifdef GRPC_METADATA_REFCOUNT_DEBUG - char *key_str = grpc_slice_to_c_string(md->key); - char *value_str = grpc_slice_to_c_string(md->value); - gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, - "ELM REF:%p:%zu->%zu: '%s' = '%s'", (void *)md, - gpr_atm_no_barrier_load(&md->refcnt), - gpr_atm_no_barrier_load(&md->refcnt) + 1, key_str, value_str); - gpr_free(key_str); - gpr_free(value_str); +#ifndef NDEBUG + if (GRPC_TRACER_ON(grpc_trace_metadata)) { + char *key_str = grpc_slice_to_c_string(md->key); + char *value_str = grpc_slice_to_c_string(md->value); + gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, + "ELM REF:%p:%" PRIdPTR "->%" PRIdPTR ": '%s' = '%s'", + (void *)md, gpr_atm_no_barrier_load(&md->refcnt), + gpr_atm_no_barrier_load(&md->refcnt) + 1, key_str, value_str); + gpr_free(key_str); + gpr_free(value_str); + } #endif /* we can assume the ref count is >= 1 as the application is calling this function - meaning that no adjustment to mdtab_free is necessary, @@ -404,15 +416,17 @@ void grpc_mdelem_unref(grpc_exec_ctx *exec_ctx, grpc_mdelem gmd DEBUG_ARGS) { break; case GRPC_MDELEM_STORAGE_INTERNED: { interned_metadata *md = (interned_metadata *)GRPC_MDELEM_DATA(gmd); -#ifdef GRPC_METADATA_REFCOUNT_DEBUG - char *key_str = grpc_slice_to_c_string(md->key); - char *value_str = grpc_slice_to_c_string(md->value); - gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, - "ELM UNREF:%p:%zu->%zu: '%s' = '%s'", (void *)md, - gpr_atm_no_barrier_load(&md->refcnt), - gpr_atm_no_barrier_load(&md->refcnt) - 1, key_str, value_str); - gpr_free(key_str); - gpr_free(value_str); +#ifndef NDEBUG + if (GRPC_TRACER_ON(grpc_trace_metadata)) { + char *key_str = grpc_slice_to_c_string(md->key); + char *value_str = grpc_slice_to_c_string(md->value); + gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, + "ELM UNREF:%p:%" PRIdPTR "->%" PRIdPTR ": '%s' = '%s'", + (void *)md, gpr_atm_no_barrier_load(&md->refcnt), + gpr_atm_no_barrier_load(&md->refcnt) - 1, key_str, value_str); + gpr_free(key_str); + gpr_free(value_str); + } #endif uint32_t hash = GRPC_MDSTR_KV_HASH(grpc_slice_hash(md->key), grpc_slice_hash(md->value)); @@ -428,15 +442,17 @@ void grpc_mdelem_unref(grpc_exec_ctx *exec_ctx, grpc_mdelem gmd DEBUG_ARGS) { } case GRPC_MDELEM_STORAGE_ALLOCATED: { allocated_metadata *md = (allocated_metadata *)GRPC_MDELEM_DATA(gmd); -#ifdef GRPC_METADATA_REFCOUNT_DEBUG - char *key_str = grpc_slice_to_c_string(md->key); - char *value_str = grpc_slice_to_c_string(md->value); - gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, - "ELM UNREF:%p:%zu->%zu: '%s' = '%s'", (void *)md, - gpr_atm_no_barrier_load(&md->refcnt), - gpr_atm_no_barrier_load(&md->refcnt) - 1, key_str, value_str); - gpr_free(key_str); - gpr_free(value_str); +#ifndef NDEBUG + if (GRPC_TRACER_ON(grpc_trace_metadata)) { + char *key_str = grpc_slice_to_c_string(md->key); + char *value_str = grpc_slice_to_c_string(md->value); + gpr_log(file, line, GPR_LOG_SEVERITY_DEBUG, + "ELM UNREF:%p:%" PRIdPTR "->%" PRIdPTR ": '%s' = '%s'", + (void *)md, gpr_atm_no_barrier_load(&md->refcnt), + gpr_atm_no_barrier_load(&md->refcnt) - 1, key_str, value_str); + gpr_free(key_str); + gpr_free(value_str); + } #endif const gpr_atm prev_refcount = gpr_atm_full_fetch_add(&md->refcnt, -1); GPR_ASSERT(prev_refcount >= 1); diff --git a/src/core/lib/transport/metadata.h b/src/core/lib/transport/metadata.h index 5e1afecd2e5..974469e436f 100644 --- a/src/core/lib/transport/metadata.h +++ b/src/core/lib/transport/metadata.h @@ -25,6 +25,10 @@ #include "src/core/lib/iomgr/exec_ctx.h" +#ifndef NDEBUG +extern grpc_tracer_flag grpc_trace_metadata; +#endif + #ifdef __cplusplus extern "C" { #endif @@ -132,9 +136,7 @@ void *grpc_mdelem_get_user_data(grpc_mdelem md, void *grpc_mdelem_set_user_data(grpc_mdelem md, void (*destroy_func)(void *), void *user_data); -/* Reference counting */ -//#define GRPC_METADATA_REFCOUNT_DEBUG -#ifdef GRPC_METADATA_REFCOUNT_DEBUG +#ifndef NDEBUG #define GRPC_MDELEM_REF(s) grpc_mdelem_ref((s), __FILE__, __LINE__) #define GRPC_MDELEM_UNREF(exec_ctx, s) \ grpc_mdelem_unref((exec_ctx), (s), __FILE__, __LINE__) diff --git a/src/core/lib/transport/transport.c b/src/core/lib/transport/transport.c index c2afedec585..52725846e66 100644 --- a/src/core/lib/transport/transport.c +++ b/src/core/lib/transport/transport.c @@ -31,25 +31,33 @@ #include "src/core/lib/support/string.h" #include "src/core/lib/transport/transport_impl.h" -#ifdef GRPC_STREAM_REFCOUNT_DEBUG +#ifndef NDEBUG +grpc_tracer_flag grpc_trace_stream_refcount = GRPC_TRACER_INITIALIZER(false); +#endif + +#ifndef NDEBUG void grpc_stream_ref(grpc_stream_refcount *refcount, const char *reason) { - gpr_atm val = gpr_atm_no_barrier_load(&refcount->refs.count); - gpr_log(GPR_DEBUG, "%s %p:%p REF %" PRIdPTR "->%" PRIdPTR " %s", - refcount->object_type, refcount, refcount->destroy.cb_arg, val, - val + 1, reason); + if (GRPC_TRACER_ON(grpc_trace_stream_refcount)) { + gpr_atm val = gpr_atm_no_barrier_load(&refcount->refs.count); + gpr_log(GPR_DEBUG, "%s %p:%p REF %" PRIdPTR "->%" PRIdPTR " %s", + refcount->object_type, refcount, refcount->destroy.cb_arg, val, + val + 1, reason); + } #else void grpc_stream_ref(grpc_stream_refcount *refcount) { #endif gpr_ref_non_zero(&refcount->refs); } -#ifdef GRPC_STREAM_REFCOUNT_DEBUG +#ifndef NDEBUG void grpc_stream_unref(grpc_exec_ctx *exec_ctx, grpc_stream_refcount *refcount, const char *reason) { - gpr_atm val = gpr_atm_no_barrier_load(&refcount->refs.count); - gpr_log(GPR_DEBUG, "%s %p:%p UNREF %" PRIdPTR "->%" PRIdPTR " %s", - refcount->object_type, refcount, refcount->destroy.cb_arg, val, - val - 1, reason); + if (GRPC_TRACER_ON(grpc_trace_stream_refcount)) { + gpr_atm val = gpr_atm_no_barrier_load(&refcount->refs.count); + gpr_log(GPR_DEBUG, "%s %p:%p UNREF %" PRIdPTR "->%" PRIdPTR " %s", + refcount->object_type, refcount, refcount->destroy.cb_arg, val, + val - 1, reason); + } #else void grpc_stream_unref(grpc_exec_ctx *exec_ctx, grpc_stream_refcount *refcount) { @@ -74,7 +82,7 @@ void grpc_stream_unref(grpc_exec_ctx *exec_ctx, offsetof(grpc_stream_refcount, slice_refcount))) static void slice_stream_ref(void *p) { -#ifdef GRPC_STREAM_REFCOUNT_DEBUG +#ifndef NDEBUG grpc_stream_ref(STREAM_REF_FROM_SLICE_REF(p), "slice"); #else grpc_stream_ref(STREAM_REF_FROM_SLICE_REF(p)); @@ -82,7 +90,7 @@ static void slice_stream_ref(void *p) { } static void slice_stream_unref(grpc_exec_ctx *exec_ctx, void *p) { -#ifdef GRPC_STREAM_REFCOUNT_DEBUG +#ifndef NDEBUG grpc_stream_unref(exec_ctx, STREAM_REF_FROM_SLICE_REF(p), "slice"); #else grpc_stream_unref(exec_ctx, STREAM_REF_FROM_SLICE_REF(p)); @@ -102,7 +110,7 @@ static const grpc_slice_refcount_vtable stream_ref_slice_vtable = { .eq = grpc_slice_default_eq_impl, .hash = grpc_slice_default_hash_impl}; -#ifdef GRPC_STREAM_REFCOUNT_DEBUG +#ifndef NDEBUG void grpc_stream_ref_init(grpc_stream_refcount *refcount, int initial_refs, grpc_iomgr_cb_func cb, void *cb_arg, const char *object_type) { diff --git a/src/core/lib/transport/transport.h b/src/core/lib/transport/transport.h index d231157c874..811610ffbfb 100644 --- a/src/core/lib/transport/transport.h +++ b/src/core/lib/transport/transport.h @@ -42,18 +42,20 @@ typedef struct grpc_transport grpc_transport; for a stream. */ typedef struct grpc_stream grpc_stream; -//#define GRPC_STREAM_REFCOUNT_DEBUG +#ifndef NDEBUG +extern grpc_tracer_flag grpc_trace_stream_refcount; +#endif typedef struct grpc_stream_refcount { gpr_refcount refs; grpc_closure destroy; -#ifdef GRPC_STREAM_REFCOUNT_DEBUG +#ifndef NDEBUG const char *object_type; #endif grpc_slice_refcount slice_refcount; } grpc_stream_refcount; -#ifdef GRPC_STREAM_REFCOUNT_DEBUG +#ifndef NDEBUG void grpc_stream_ref_init(grpc_stream_refcount *refcount, int initial_refs, grpc_iomgr_cb_func cb, void *cb_arg, const char *object_type); diff --git a/test/core/end2end/fixtures/http_proxy_fixture.c b/test/core/end2end/fixtures/http_proxy_fixture.c index 248f721cbb3..54693c49001 100644 --- a/test/core/end2end/fixtures/http_proxy_fixture.c +++ b/test/core/end2end/fixtures/http_proxy_fixture.c @@ -493,7 +493,7 @@ void grpc_end2end_http_proxy_destroy(grpc_end2end_http_proxy* proxy) { grpc_pollset_shutdown(&exec_ctx, proxy->pollset, GRPC_CLOSURE_CREATE(destroy_pollset, proxy->pollset, grpc_schedule_on_exec_ctx)); - grpc_combiner_unref(&exec_ctx, proxy->combiner); + GRPC_COMBINER_UNREF(&exec_ctx, proxy->combiner, "test"); gpr_free(proxy); grpc_exec_ctx_finish(&exec_ctx); }