Fix ASAN/TSAN failures

- trace system is now thread safe when run with TSAN
- fix a race in client_auth_filter.c
- allow timer manager to run in single threaded mode for fuzzers
reviewable/pr10961/r1
Craig Tiller 8 years ago
parent 4d03ffbdc6
commit 84f75d448e
  1. 2
      src/core/ext/filters/client_channel/channel_connectivity.c
  2. 40
      src/core/ext/filters/client_channel/lb_policy/grpclb/grpclb.c
  3. 22
      src/core/ext/filters/client_channel/lb_policy/round_robin/round_robin.c
  4. 1
      src/core/ext/filters/http/http_filters_plugin.c
  5. 5
      src/core/ext/filters/http/message_compress/message_compress_filter.c
  6. 2
      src/core/ext/filters/http/message_compress/message_compress_filter.h
  7. 22
      src/core/ext/transport/chttp2/transport/chttp2_transport.c
  8. 5
      src/core/ext/transport/chttp2/transport/chttp2_transport.h
  9. 6
      src/core/ext/transport/chttp2/transport/frame_settings.c
  10. 6
      src/core/ext/transport/chttp2/transport/hpack_parser.c
  11. 18
      src/core/ext/transport/chttp2/transport/internal.h
  12. 8
      src/core/ext/transport/chttp2/transport/parsing.c
  13. 9
      src/core/ext/transport/chttp2/transport/writing.c
  14. 2
      src/core/lib/channel/channel_stack.c
  15. 4
      src/core/lib/channel/channel_stack.h
  16. 2
      src/core/lib/channel/channel_stack_builder.c
  17. 2
      src/core/lib/channel/channel_stack_builder.h
  18. 16
      src/core/lib/debug/trace.c
  19. 26
      src/core/lib/debug/trace.h
  20. 4
      src/core/lib/http/parser.c
  21. 3
      src/core/lib/http/parser.h
  22. 12
      src/core/lib/iomgr/combiner.c
  23. 3
      src/core/lib/iomgr/combiner.h
  24. 3
      src/core/lib/iomgr/iomgr.c
  25. 3
      src/core/lib/iomgr/iomgr.h
  26. 16
      src/core/lib/iomgr/resource_quota.c
  27. 3
      src/core/lib/iomgr/resource_quota.h
  28. 8
      src/core/lib/iomgr/tcp_client_posix.c
  29. 14
      src/core/lib/iomgr/tcp_posix.c
  30. 3
      src/core/lib/iomgr/tcp_posix.h
  31. 2
      src/core/lib/iomgr/tcp_server_posix.c
  32. 49
      src/core/lib/iomgr/timer_generic.c
  33. 56
      src/core/lib/iomgr/timer_manager.c
  34. 9
      src/core/lib/iomgr/timer_manager.h
  35. 2
      src/core/lib/security/credentials/jwt/jwt_credentials.c
  36. 2
      src/core/lib/security/credentials/oauth2/oauth2_credentials.c
  37. 2
      src/core/lib/security/transport/client_auth_filter.c
  38. 6
      src/core/lib/security/transport/secure_endpoint.c
  39. 2
      src/core/lib/security/transport/secure_endpoint.h
  40. 2
      src/core/lib/surface/api_trace.c
  41. 4
      src/core/lib/surface/api_trace.h
  42. 11
      src/core/lib/surface/call.c
  43. 6
      src/core/lib/surface/call.h
  44. 33
      src/core/lib/surface/completion_queue.c
  45. 9
      src/core/lib/surface/completion_queue.h
  46. 3
      src/core/lib/surface/init.c
  47. 4
      src/core/lib/surface/server.c
  48. 3
      src/core/lib/surface/server.h
  49. 10
      src/core/lib/transport/bdp_estimator.c
  50. 3
      src/core/lib/transport/bdp_estimator.h
  51. 12
      src/core/lib/transport/connectivity_state.c
  52. 3
      src/core/lib/transport/connectivity_state.h
  53. 8
      src/core/tsi/fake_transport_security.c
  54. 2
      src/core/tsi/ssl_transport_security.c
  55. 2
      src/core/tsi/transport_security.c
  56. 3
      src/core/tsi/transport_security.h
  57. 5
      src/core/tsi/transport_security_interface.h
  58. 4
      test/core/end2end/fuzzers/api_fuzzer.c
  59. 2
      test/core/transport/connectivity_state_test.c

@ -132,7 +132,7 @@ static void partly_done(grpc_exec_ctx *exec_ctx, state_watcher *w,
gpr_mu_lock(&w->mu);
if (due_to_completion) {
if (grpc_trace_operation_failures) {
if (GRPC_TRACER_ON(grpc_trace_operation_failures)) {
GRPC_LOG_IF_ERROR("watch_completion_error", GRPC_ERROR_REF(error));
}
GRPC_ERROR_UNREF(error);

@ -138,7 +138,7 @@
#define GRPC_GRPCLB_RECONNECT_MAX_BACKOFF_SECONDS 120
#define GRPC_GRPCLB_RECONNECT_JITTER 0.2
int grpc_lb_glb_trace = 0;
grpc_tracer_flag grpc_lb_glb_trace;
/* add lb_token of selected subchannel (address) to the call's initial
* metadata */
@ -224,7 +224,7 @@ static void wrapped_rr_closure(grpc_exec_ctx *exec_ctx, void *arg,
} else {
grpc_grpclb_client_stats_unref(wc_arg->client_stats);
}
if (grpc_lb_glb_trace) {
if (GRPC_TRACER_ON(grpc_lb_glb_trace)) {
gpr_log(GPR_INFO, "Unreffing RR %p", (void *)wc_arg->rr_policy);
}
GRPC_LB_POLICY_UNREF(exec_ctx, wc_arg->rr_policy, "wrapped_rr_closure");
@ -575,7 +575,7 @@ static bool update_lb_connectivity_status_locked(
GPR_ASSERT(new_rr_state_error == GRPC_ERROR_NONE);
}
if (grpc_lb_glb_trace) {
if (GRPC_TRACER_ON(grpc_lb_glb_trace)) {
gpr_log(GPR_INFO,
"Setting grpclb's state to %s from new RR policy %p state.",
grpc_connectivity_state_name(new_rr_state),
@ -600,7 +600,7 @@ static bool pick_from_internal_rr_locked(
(void **)&wc_arg->lb_token, &wc_arg->wrapper_closure);
if (pick_done) {
/* synchronous grpc_lb_policy_pick call. Unref the RR policy. */
if (grpc_lb_glb_trace) {
if (GRPC_TRACER_ON(grpc_lb_glb_trace)) {
gpr_log(GPR_INFO, "Unreffing RR (0x%" PRIxPTR ")",
(intptr_t)wc_arg->rr_policy);
}
@ -686,7 +686,7 @@ static void rr_handover_locked(grpc_exec_ctx *exec_ctx,
if (!replace_old_rr) {
/* dispose of the new RR policy that won't be used after all */
GRPC_LB_POLICY_UNREF(exec_ctx, new_rr_policy, "rr_handover_no_replace");
if (grpc_lb_glb_trace) {
if (GRPC_TRACER_ON(grpc_lb_glb_trace)) {
gpr_log(GPR_INFO,
"Keeping old RR policy (%p) despite new serverlist: new RR "
"policy was in %s connectivity state.",
@ -696,7 +696,7 @@ static void rr_handover_locked(grpc_exec_ctx *exec_ctx,
return;
}
if (grpc_lb_glb_trace) {
if (GRPC_TRACER_ON(grpc_lb_glb_trace)) {
gpr_log(GPR_INFO, "Created RR policy (%p) to replace old RR (%p)",
(void *)new_rr_policy, (void *)glb_policy->rr_policy);
}
@ -741,7 +741,7 @@ static void rr_handover_locked(grpc_exec_ctx *exec_ctx,
pp->wrapped_on_complete_arg.rr_policy = glb_policy->rr_policy;
pp->wrapped_on_complete_arg.client_stats =
grpc_grpclb_client_stats_ref(glb_policy->client_stats);
if (grpc_lb_glb_trace) {
if (GRPC_TRACER_ON(grpc_lb_glb_trace)) {
gpr_log(GPR_INFO, "Pending pick about to PICK from 0x%" PRIxPTR "",
(intptr_t)glb_policy->rr_policy);
}
@ -755,7 +755,7 @@ static void rr_handover_locked(grpc_exec_ctx *exec_ctx,
glb_policy->pending_pings = pping->next;
GRPC_LB_POLICY_REF(glb_policy->rr_policy, "rr_handover_pending_ping");
pping->wrapped_notify_arg.rr_policy = glb_policy->rr_policy;
if (grpc_lb_glb_trace) {
if (GRPC_TRACER_ON(grpc_lb_glb_trace)) {
gpr_log(GPR_INFO, "Pending ping about to PING from 0x%" PRIxPTR "",
(intptr_t)glb_policy->rr_policy);
}
@ -908,7 +908,7 @@ static grpc_lb_policy *glb_create(grpc_exec_ctx *exec_ctx,
GPR_ASSERT(uri->path[0] != '\0');
glb_policy->server_name =
gpr_strdup(uri->path[0] == '/' ? uri->path + 1 : uri->path);
if (grpc_lb_glb_trace) {
if (GRPC_TRACER_ON(grpc_lb_glb_trace)) {
gpr_log(GPR_INFO, "Will use '%s' as the server name for LB request.",
glb_policy->server_name);
}
@ -1093,7 +1093,7 @@ static int glb_pick_locked(grpc_exec_ctx *exec_ctx, grpc_lb_policy *pol,
bool pick_done;
if (glb_policy->rr_policy != NULL) {
if (grpc_lb_glb_trace) {
if (GRPC_TRACER_ON(grpc_lb_glb_trace)) {
gpr_log(GPR_INFO, "grpclb %p about to PICK from RR %p",
(void *)glb_policy, (void *)glb_policy->rr_policy);
}
@ -1116,7 +1116,7 @@ static int glb_pick_locked(grpc_exec_ctx *exec_ctx, grpc_lb_policy *pol,
pick_done = pick_from_internal_rr_locked(exec_ctx, glb_policy->rr_policy,
pick_args, target, wc_arg);
} else {
if (grpc_lb_glb_trace) {
if (GRPC_TRACER_ON(grpc_lb_glb_trace)) {
gpr_log(GPR_DEBUG,
"No RR policy in grpclb instance %p. Adding to grpclb's pending "
"picks",
@ -1347,7 +1347,7 @@ static void query_for_backends_locked(grpc_exec_ctx *exec_ctx,
lb_call_init_locked(exec_ctx, glb_policy);
if (grpc_lb_glb_trace) {
if (GRPC_TRACER_ON(grpc_lb_glb_trace)) {
gpr_log(GPR_INFO, "Query for backends (grpclb: %p, lb_call: %p)",
(void *)glb_policy, (void *)glb_policy->lb_call);
}
@ -1453,7 +1453,7 @@ static void lb_on_response_received_locked(grpc_exec_ctx *exec_ctx, void *arg,
gpr_time_max(gpr_time_from_seconds(1, GPR_TIMESPAN),
grpc_grpclb_duration_to_timespec(
&response->client_stats_report_interval));
if (grpc_lb_glb_trace) {
if (GRPC_TRACER_ON(grpc_lb_glb_trace)) {
gpr_log(GPR_INFO,
"received initial LB response message; "
"client load reporting interval = %" PRId64 ".%09d sec",
@ -1466,7 +1466,7 @@ static void lb_on_response_received_locked(grpc_exec_ctx *exec_ctx, void *arg,
glb_policy->client_load_report_timer_pending = true;
GRPC_LB_POLICY_WEAK_REF(&glb_policy->base, "client_load_report");
schedule_next_client_load_report(exec_ctx, glb_policy);
} else if (grpc_lb_glb_trace) {
} else if (GRPC_TRACER_ON(grpc_lb_glb_trace)) {
gpr_log(GPR_INFO,
"received initial LB response message; "
"client load reporting NOT enabled");
@ -1478,7 +1478,7 @@ static void lb_on_response_received_locked(grpc_exec_ctx *exec_ctx, void *arg,
grpc_grpclb_response_parse_serverlist(response_slice);
if (serverlist != NULL) {
GPR_ASSERT(glb_policy->lb_call != NULL);
if (grpc_lb_glb_trace) {
if (GRPC_TRACER_ON(grpc_lb_glb_trace)) {
gpr_log(GPR_INFO, "Serverlist with %lu servers received",
(unsigned long)serverlist->num_servers);
for (size_t i = 0; i < serverlist->num_servers; ++i) {
@ -1495,7 +1495,7 @@ static void lb_on_response_received_locked(grpc_exec_ctx *exec_ctx, void *arg,
if (serverlist->num_servers > 0) {
if (grpc_grpclb_serverlist_equals(glb_policy->serverlist,
serverlist)) {
if (grpc_lb_glb_trace) {
if (GRPC_TRACER_ON(grpc_lb_glb_trace)) {
gpr_log(GPR_INFO,
"Incoming server list identical to current, ignoring.");
}
@ -1513,7 +1513,7 @@ static void lb_on_response_received_locked(grpc_exec_ctx *exec_ctx, void *arg,
rr_handover_locked(exec_ctx, glb_policy);
}
} else {
if (grpc_lb_glb_trace) {
if (GRPC_TRACER_ON(grpc_lb_glb_trace)) {
gpr_log(GPR_INFO,
"Received empty server list. Picks will stay pending until "
"a response with > 0 servers is received");
@ -1555,7 +1555,7 @@ static void lb_call_on_retry_timer_locked(grpc_exec_ctx *exec_ctx, void *arg,
glb_lb_policy *glb_policy = arg;
if (!glb_policy->shutting_down) {
if (grpc_lb_glb_trace) {
if (GRPC_TRACER_ON(grpc_lb_glb_trace)) {
gpr_log(GPR_INFO, "Restaring call to LB server (grpclb %p)",
(void *)glb_policy);
}
@ -1572,7 +1572,7 @@ static void lb_on_server_status_received_locked(grpc_exec_ctx *exec_ctx,
GPR_ASSERT(glb_policy->lb_call != NULL);
if (grpc_lb_glb_trace) {
if (GRPC_TRACER_ON(grpc_lb_glb_trace)) {
char *status_details =
grpc_slice_to_c_string(glb_policy->lb_call_status_details);
gpr_log(GPR_DEBUG,
@ -1591,7 +1591,7 @@ static void lb_on_server_status_received_locked(grpc_exec_ctx *exec_ctx,
gpr_timespec now = gpr_now(GPR_CLOCK_MONOTONIC);
gpr_timespec next_try =
gpr_backoff_step(&glb_policy->lb_call_backoff_state, now);
if (grpc_lb_glb_trace) {
if (GRPC_TRACER_ON(grpc_lb_glb_trace)) {
gpr_log(GPR_DEBUG, "Connection to LB server lost (grpclb: %p)...",
(void *)glb_policy);
gpr_timespec timeout = gpr_time_sub(next_try, now);

@ -74,7 +74,7 @@
typedef struct round_robin_lb_policy round_robin_lb_policy;
int grpc_lb_round_robin_trace = 0;
grpc_tracer_flag grpc_lb_round_robin_trace;
/** List of entities waiting for a pick.
*
@ -198,7 +198,7 @@ static void advance_last_picked_locked(round_robin_lb_policy *p) {
GPR_ASSERT(p->ready_list_last_pick == &p->ready_list);
}
if (grpc_lb_round_robin_trace) {
if (GRPC_TRACER_ON(grpc_lb_round_robin_trace)) {
gpr_log(GPR_DEBUG,
"[READYLIST, RR: %p] ADVANCED LAST PICK. NOW AT NODE %p (SC %p, "
"CSC %p)",
@ -228,7 +228,7 @@ static ready_list *add_connected_sc_locked(round_robin_lb_policy *p,
p->ready_list.prev->next = new_elem;
p->ready_list.prev = new_elem;
}
if (grpc_lb_round_robin_trace) {
if (GRPC_TRACER_ON(grpc_lb_round_robin_trace)) {
gpr_log(GPR_DEBUG, "[READYLIST] ADDING NODE %p (Conn. SC %p)",
(void *)new_elem, (void *)sd->subchannel);
}
@ -256,7 +256,7 @@ static void remove_disconnected_sc_locked(round_robin_lb_policy *p,
node->next->prev = node->prev;
}
if (grpc_lb_round_robin_trace) {
if (GRPC_TRACER_ON(grpc_lb_round_robin_trace)) {
gpr_log(GPR_DEBUG, "[READYLIST] REMOVED NODE %p (SC %p)", (void *)node,
(void *)node->subchannel);
}
@ -276,7 +276,7 @@ static void rr_destroy(grpc_exec_ctx *exec_ctx, grpc_lb_policy *pol) {
round_robin_lb_policy *p = (round_robin_lb_policy *)pol;
ready_list *elem;
if (grpc_lb_round_robin_trace) {
if (GRPC_TRACER_ON(grpc_lb_round_robin_trace)) {
gpr_log(GPR_DEBUG, "Destroying Round Robin policy at %p", (void *)pol);
}
@ -312,7 +312,7 @@ static void rr_shutdown_locked(grpc_exec_ctx *exec_ctx, grpc_lb_policy *pol) {
pending_pick *pp;
size_t i;
if (grpc_lb_round_robin_trace) {
if (GRPC_TRACER_ON(grpc_lb_round_robin_trace)) {
gpr_log(GPR_DEBUG, "Shutting down Round Robin policy at %p", (void *)pol);
}
@ -421,7 +421,7 @@ static int rr_pick_locked(grpc_exec_ctx *exec_ctx, grpc_lb_policy *pol,
pending_pick *pp;
ready_list *selected;
if (grpc_lb_round_robin_trace) {
if (GRPC_TRACER_ON(grpc_lb_round_robin_trace)) {
gpr_log(GPR_INFO, "Round Robin %p trying to pick", (void *)pol);
}
@ -434,7 +434,7 @@ static int rr_pick_locked(grpc_exec_ctx *exec_ctx, grpc_lb_policy *pol,
if (user_data != NULL) {
*user_data = selected->user_data;
}
if (grpc_lb_round_robin_trace) {
if (GRPC_TRACER_ON(grpc_lb_round_robin_trace)) {
gpr_log(GPR_DEBUG,
"[RR PICK] TARGET <-- CONNECTED SUBCHANNEL %p (NODE %p)",
(void *)*target, (void *)selected);
@ -566,7 +566,7 @@ static void rr_connectivity_changed_locked(grpc_exec_ctx *exec_ctx, void *arg,
if (pp->user_data != NULL) {
*pp->user_data = selected->user_data;
}
if (grpc_lb_round_robin_trace) {
if (GRPC_TRACER_ON(grpc_lb_round_robin_trace)) {
gpr_log(GPR_DEBUG,
"[RR CONN CHANGED] TARGET <-- SUBCHANNEL %p (NODE %p)",
(void *)selected->subchannel, (void *)selected);
@ -724,7 +724,7 @@ static grpc_lb_policy *round_robin_create(grpc_exec_ctx *exec_ctx,
sc_args.args = new_args;
grpc_subchannel *subchannel = grpc_client_channel_factory_create_subchannel(
exec_ctx, args->client_channel_factory, &sc_args);
if (grpc_lb_round_robin_trace) {
if (GRPC_TRACER_ON(grpc_lb_round_robin_trace)) {
char *address_uri =
grpc_sockaddr_to_uri(&addresses->addresses[i].address);
gpr_log(GPR_DEBUG, "Created subchannel %p for address uri %s",
@ -768,7 +768,7 @@ static grpc_lb_policy *round_robin_create(grpc_exec_ctx *exec_ctx,
grpc_connectivity_state_init(&p->state_tracker, GRPC_CHANNEL_IDLE,
"round_robin");
if (grpc_lb_round_robin_trace) {
if (GRPC_TRACER_ON(grpc_lb_round_robin_trace)) {
gpr_log(GPR_DEBUG, "Created RR policy at %p with %lu subchannels",
(void *)p, (unsigned long)p->num_subchannels);
}

@ -37,6 +37,7 @@
#include "src/core/ext/filters/http/message_compress/message_compress_filter.h"
#include "src/core/ext/filters/http/server/http_server_filter.h"
#include "src/core/lib/channel/channel_stack_builder.h"
#include "src/core/lib/surface/call.h"
#include "src/core/lib/surface/channel_init.h"
#include "src/core/lib/transport/transport_impl.h"

@ -47,6 +47,7 @@
#include "src/core/lib/slice/slice_internal.h"
#include "src/core/lib/slice/slice_string_helpers.h"
#include "src/core/lib/support/string.h"
#include "src/core/lib/surface/call.h"
#include "src/core/lib/transport/static_metadata.h"
#define INITIAL_METADATA_UNSEEN 0
@ -197,7 +198,7 @@ static void finish_send_message(grpc_exec_ctx *exec_ctx,
did_compress = grpc_msg_compress(exec_ctx, calld->compression_algorithm,
&calld->slices, &tmp);
if (did_compress) {
if (grpc_compression_trace) {
if (GRPC_TRACER_ON(grpc_compression_trace)) {
char *algo_name;
const size_t before_size = calld->slices.length;
const size_t after_size = tmp.length;
@ -211,7 +212,7 @@ static void finish_send_message(grpc_exec_ctx *exec_ctx,
grpc_slice_buffer_swap(&calld->slices, &tmp);
calld->send_flags |= GRPC_WRITE_INTERNAL_COMPRESS;
} else {
if (grpc_compression_trace) {
if (GRPC_TRACER_ON(grpc_compression_trace)) {
char *algo_name;
GPR_ASSERT(grpc_compression_algorithm_name(calld->compression_algorithm,
&algo_name));

@ -38,8 +38,6 @@
#include "src/core/lib/channel/channel_stack.h"
extern int grpc_compression_trace;
/** Compression filter for outgoing data.
*
* See <grpc/compression.h> for the available compression settings.

@ -89,8 +89,8 @@ static bool g_default_keepalive_permit_without_calls =
DEFAULT_KEEPALIVE_PERMIT_WITHOUT_CALLS;
#define MAX_CLIENT_STREAM_ID 0x7fffffffu
int grpc_http_trace = 0;
int grpc_flowctl_trace = 0;
grpc_tracer_flag grpc_http_trace;
grpc_tracer_flag grpc_flowctl_trace;
static const grpc_transport_vtable vtable;
@ -1095,7 +1095,7 @@ void grpc_chttp2_complete_closure_step(grpc_exec_ctx *exec_ctx,
return;
}
closure->next_data.scratch -= CLOSURE_BARRIER_FIRST_REF_BIT;
if (grpc_http_trace) {
if (GRPC_TRACER_ON(grpc_http_trace)) {
const char *errstr = grpc_error_string(error);
gpr_log(GPR_DEBUG,
"complete_closure_step: %p refs=%d flags=0x%04x desc=%s err=%s",
@ -1240,7 +1240,7 @@ static void perform_stream_op_locked(grpc_exec_ctx *exec_ctx, void *stream_op,
grpc_transport_stream_op_batch_payload *op_payload = op->payload;
grpc_chttp2_transport *t = s->t;
if (grpc_http_trace) {
if (GRPC_TRACER_ON(grpc_http_trace)) {
char *str = grpc_transport_stream_op_batch_string(op);
gpr_log(GPR_DEBUG, "perform_stream_op_locked: %s; on_complete = %p", str,
op->on_complete);
@ -1483,7 +1483,7 @@ static void perform_stream_op(grpc_exec_ctx *exec_ctx, grpc_transport *gt,
grpc_chttp2_transport *t = (grpc_chttp2_transport *)gt;
grpc_chttp2_stream *s = (grpc_chttp2_stream *)gs;
if (grpc_http_trace) {
if (GRPC_TRACER_ON(grpc_http_trace)) {
char *str = grpc_transport_stream_op_batch_string(op);
gpr_log(GPR_DEBUG, "perform_stream_op[s=%p/%d]: %s", s, s->id, str);
gpr_free(str);
@ -2145,7 +2145,7 @@ static void update_bdp(grpc_exec_ctx *exec_ctx, grpc_chttp2_transport *t,
if (delta == 0 || (bdp != 0 && delta > -1024 && delta < 1024)) {
return;
}
if (grpc_bdp_estimator_trace) {
if (GRPC_TRACER_ON(grpc_bdp_estimator_trace)) {
gpr_log(GPR_DEBUG, "%s: update initial window size to %d", t->peer_string,
(int)bdp);
}
@ -2305,7 +2305,7 @@ static void read_action_locked(grpc_exec_ctx *exec_ctx, void *tp,
static void start_bdp_ping_locked(grpc_exec_ctx *exec_ctx, void *tp,
grpc_error *error) {
grpc_chttp2_transport *t = tp;
if (grpc_http_trace) {
if (GRPC_TRACER_ON(grpc_http_trace)) {
gpr_log(GPR_DEBUG, "%s: Start BDP ping", t->peer_string);
}
/* Reset the keepalive ping timer */
@ -2318,7 +2318,7 @@ static void start_bdp_ping_locked(grpc_exec_ctx *exec_ctx, void *tp,
static void finish_bdp_ping_locked(grpc_exec_ctx *exec_ctx, void *tp,
grpc_error *error) {
grpc_chttp2_transport *t = tp;
if (grpc_http_trace) {
if (GRPC_TRACER_ON(grpc_http_trace)) {
gpr_log(GPR_DEBUG, "%s: Complete BDP ping", t->peer_string);
}
grpc_bdp_estimator_complete_ping(&t->bdp_estimator);
@ -2779,7 +2779,7 @@ static void benign_reclaimer_locked(grpc_exec_ctx *exec_ctx, void *arg,
grpc_chttp2_stream_map_size(&t->stream_map) == 0) {
/* Channel with no active streams: send a goaway to try and make it
* disconnect cleanly */
if (grpc_resource_quota_trace) {
if (GRPC_TRACER_ON(grpc_resource_quota_trace)) {
gpr_log(GPR_DEBUG, "HTTP2: %s - send goaway to free memory",
t->peer_string);
}
@ -2787,7 +2787,7 @@ static void benign_reclaimer_locked(grpc_exec_ctx *exec_ctx, void *arg,
grpc_error_set_int(
GRPC_ERROR_CREATE_FROM_STATIC_STRING("Buffers full"),
GRPC_ERROR_INT_HTTP2_ERROR, GRPC_HTTP2_ENHANCE_YOUR_CALM));
} else if (error == GRPC_ERROR_NONE && grpc_resource_quota_trace) {
} else if (error == GRPC_ERROR_NONE && GRPC_TRACER_ON(grpc_resource_quota_trace)) {
gpr_log(GPR_DEBUG,
"HTTP2: %s - skip benign reclamation, there are still %" PRIdPTR
" streams",
@ -2808,7 +2808,7 @@ static void destructive_reclaimer_locked(grpc_exec_ctx *exec_ctx, void *arg,
t->destructive_reclaimer_registered = false;
if (error == GRPC_ERROR_NONE && n > 0) {
grpc_chttp2_stream *s = grpc_chttp2_stream_map_rand(&t->stream_map);
if (grpc_resource_quota_trace) {
if (GRPC_TRACER_ON(grpc_resource_quota_trace)) {
gpr_log(GPR_DEBUG, "HTTP2: %s - abandon stream id %d", t->peer_string,
s->id);
}

@ -34,11 +34,12 @@
#ifndef GRPC_CORE_EXT_TRANSPORT_CHTTP2_TRANSPORT_CHTTP2_TRANSPORT_H
#define GRPC_CORE_EXT_TRANSPORT_CHTTP2_TRANSPORT_CHTTP2_TRANSPORT_H
#include "src/core/lib/debug/trace.h"
#include "src/core/lib/iomgr/endpoint.h"
#include "src/core/lib/transport/transport.h"
extern int grpc_http_trace;
extern int grpc_flowctl_trace;
extern grpc_tracer_flag grpc_http_trace;
extern grpc_tracer_flag grpc_flowctl_trace;
grpc_transport *grpc_create_chttp2_transport(
grpc_exec_ctx *exec_ctx, const grpc_channel_args *channel_args,

@ -218,18 +218,18 @@ grpc_error *grpc_chttp2_settings_parser_parse(grpc_exec_ctx *exec_ctx, void *p,
parser->incoming_settings[id] != parser->value) {
t->initial_window_update +=
(int64_t)parser->value - parser->incoming_settings[id];
if (grpc_http_trace) {
if (GRPC_TRACER_ON(grpc_http_trace)) {
gpr_log(GPR_DEBUG, "adding %d for initial_window change",
(int)t->initial_window_update);
}
}
parser->incoming_settings[id] = parser->value;
if (grpc_http_trace) {
if (GRPC_TRACER_ON(grpc_http_trace)) {
gpr_log(GPR_DEBUG, "CHTTP2:%s:%s: got setting %s = %d",
t->is_client ? "CLI" : "SVR", t->peer_string, sp->name,
parser->value);
}
} else if (grpc_http_trace) {
} else if (GRPC_TRACER_ON(grpc_http_trace)) {
gpr_log(GPR_ERROR, "CHTTP2: Ignoring unknown setting %d (value %d)",
parser->id, parser->value);
}

@ -50,8 +50,6 @@
#include "src/core/lib/support/string.h"
#include "src/core/lib/transport/http2_errors.h"
extern int grpc_http_trace;
typedef enum {
NOT_BINARY,
BINARY_BEGIN,
@ -666,7 +664,7 @@ static const uint8_t inverse_base64[256] = {
/* emission helpers */
static grpc_error *on_hdr(grpc_exec_ctx *exec_ctx, grpc_chttp2_hpack_parser *p,
grpc_mdelem md, int add_to_table) {
if (grpc_http_trace && !GRPC_MDELEM_IS_INTERNED(md)) {
if (GRPC_TRACER_ON(grpc_http_trace) && !GRPC_MDELEM_IS_INTERNED(md)) {
char *k = grpc_slice_to_c_string(GRPC_MDKEY(md));
char *v = grpc_slice_to_c_string(GRPC_MDVALUE(md));
gpr_log(
@ -1052,7 +1050,7 @@ static grpc_error *parse_lithdr_nvridx_v(grpc_exec_ctx *exec_ctx,
static grpc_error *finish_max_tbl_size(grpc_exec_ctx *exec_ctx,
grpc_chttp2_hpack_parser *p,
const uint8_t *cur, const uint8_t *end) {
if (grpc_http_trace) {
if (GRPC_TRACER_ON(grpc_http_trace)) {
gpr_log(GPR_INFO, "MAX TABLE SIZE: %d", p->index);
}
grpc_error *err =

@ -629,13 +629,13 @@ void grpc_chttp2_complete_closure_step(grpc_exec_ctx *exec_ctx,
#define GRPC_CHTTP2_CLIENT_CONNECT_STRLEN \
(sizeof(GRPC_CHTTP2_CLIENT_CONNECT_STRING) - 1)
extern int grpc_http_trace;
extern int grpc_flowctl_trace;
extern grpc_tracer_flag grpc_http_trace;
extern grpc_tracer_flag grpc_flowctl_trace;
#define GRPC_CHTTP2_IF_TRACING(stmt) \
if (!(grpc_http_trace)) \
; \
else \
#define GRPC_CHTTP2_IF_TRACING(stmt) \
if (!(GRPC_TRACER_ON(grpc_http_trace))) \
; \
else \
stmt
typedef enum {
@ -648,7 +648,7 @@ typedef enum {
dst_var, src_context, src_var) \
do { \
assert(id1 == id2); \
if (grpc_flowctl_trace) { \
if (GRPC_TRACER_ON(grpc_flowctl_trace)) { \
grpc_chttp2_flowctl_trace( \
__FILE__, __LINE__, phase, GRPC_CHTTP2_FLOWCTL_MOVE, #dst_context, \
#dst_var, #src_context, #src_var, transport->is_client, id1, \
@ -671,7 +671,7 @@ typedef enum {
#define GRPC_CHTTP2_FLOW_CREDIT_COMMON(phase, transport, id, dst_context, \
dst_var, amount) \
do { \
if (grpc_flowctl_trace) { \
if (GRPC_TRACER_ON(grpc_flowctl_trace)) { \
grpc_chttp2_flowctl_trace(__FILE__, __LINE__, phase, \
GRPC_CHTTP2_FLOWCTL_CREDIT, #dst_context, \
#dst_var, NULL, #amount, transport->is_client, \
@ -729,7 +729,7 @@ typedef enum {
#define GRPC_CHTTP2_FLOW_DEBIT_COMMON(phase, transport, id, dst_context, \
dst_var, amount) \
do { \
if (grpc_flowctl_trace) { \
if (GRPC_TRACER_ON(grpc_flowctl_trace)) { \
grpc_chttp2_flowctl_trace(__FILE__, __LINE__, phase, \
GRPC_CHTTP2_FLOWCTL_DEBIT, #dst_context, \
#dst_var, NULL, #amount, transport->is_client, \

@ -324,7 +324,7 @@ static grpc_error *init_frame_parser(grpc_exec_ctx *exec_ctx,
case GRPC_CHTTP2_FRAME_GOAWAY:
return init_goaway_parser(exec_ctx, t);
default:
if (grpc_http_trace) {
if (GRPC_TRACER_ON(grpc_http_trace)) {
gpr_log(GPR_ERROR, "Unknown frame type %02x", t->incoming_frame_type);
}
return init_skip_frame_parser(exec_ctx, t, 0);
@ -494,7 +494,7 @@ static void on_initial_header(grpc_exec_ctx *exec_ctx, void *tp,
GPR_ASSERT(s != NULL);
if (grpc_http_trace) {
if (GRPC_TRACER_ON(grpc_http_trace)) {
char *key = grpc_slice_to_c_string(GRPC_MDKEY(md));
char *value =
grpc_dump_slice(GRPC_MDVALUE(md), GPR_DUMP_HEX | GPR_DUMP_ASCII);
@ -574,7 +574,7 @@ static void on_trailing_header(grpc_exec_ctx *exec_ctx, void *tp,
GPR_ASSERT(s != NULL);
if (grpc_http_trace) {
if (GRPC_TRACER_ON(grpc_http_trace)) {
char *key = grpc_slice_to_c_string(GRPC_MDKEY(md));
char *value =
grpc_dump_slice(GRPC_MDVALUE(md), GPR_DUMP_HEX | GPR_DUMP_ASCII);
@ -807,7 +807,7 @@ static grpc_error *parse_frame_slice(grpc_exec_ctx *exec_ctx,
if (err == GRPC_ERROR_NONE) {
return err;
} else if (grpc_error_get_int(err, GRPC_ERROR_INT_STREAM_ID, NULL)) {
if (grpc_http_trace) {
if (GRPC_TRACER_ON(grpc_http_trace)) {
const char *msg = grpc_error_string(err);
gpr_log(GPR_ERROR, "%s", msg);
}

@ -74,7 +74,8 @@ static void maybe_initiate_ping(grpc_exec_ctx *exec_ctx,
}
if (!grpc_closure_list_empty(pq->lists[GRPC_CHTTP2_PCL_INFLIGHT])) {
/* ping already in-flight: wait */
if (grpc_http_trace || grpc_bdp_estimator_trace) {
if (GRPC_TRACER_ON(grpc_http_trace) ||
GRPC_TRACER_ON(grpc_bdp_estimator_trace)) {
gpr_log(GPR_DEBUG, "Ping delayed [%p]: already pinging", t->peer_string);
}
return;
@ -82,7 +83,8 @@ static void maybe_initiate_ping(grpc_exec_ctx *exec_ctx,
if (t->ping_state.pings_before_data_required == 0 &&
t->ping_policy.max_pings_without_data != 0) {
/* need to send something of substance before sending a ping again */
if (grpc_http_trace || grpc_bdp_estimator_trace) {
if (GRPC_TRACER_ON(grpc_http_trace) ||
GRPC_TRACER_ON(grpc_bdp_estimator_trace)) {
gpr_log(GPR_DEBUG, "Ping delayed [%p]: too many recent pings: %d/%d",
t->peer_string, t->ping_state.pings_before_data_required,
t->ping_policy.max_pings_without_data);
@ -96,7 +98,8 @@ static void maybe_initiate_ping(grpc_exec_ctx *exec_ctx,
(int)t->ping_policy.min_time_between_pings.tv_nsec);*/
if (gpr_time_cmp(elapsed, t->ping_policy.min_time_between_pings) < 0) {
/* not enough elapsed time between successive pings */
if (grpc_http_trace || grpc_bdp_estimator_trace) {
if (GRPC_TRACER_ON(grpc_http_trace) ||
GRPC_TRACER_ON(grpc_bdp_estimator_trace)) {
gpr_log(GPR_DEBUG,
"Ping delayed [%p]: not enough time elapsed since last ping",
t->peer_string);

@ -38,7 +38,7 @@
#include <stdlib.h>
#include <string.h>
int grpc_trace_channel = 0;
grpc_tracer_flag grpc_trace_channel;
/* Memory layouts.

@ -307,10 +307,10 @@ void grpc_call_element_signal_error(grpc_exec_ctx *exec_ctx,
grpc_call_element *cur_elem,
grpc_error *error);
extern int grpc_trace_channel;
extern grpc_tracer_flag grpc_trace_channel;
#define GRPC_CALL_LOG_OP(sev, elem, op) \
if (grpc_trace_channel) grpc_call_log_op(sev, elem, op)
if (GRPC_TRACER_ON(grpc_trace_channel)) grpc_call_log_op(sev, elem, op)
#ifdef __cplusplus
}

@ -38,7 +38,7 @@
#include <grpc/support/alloc.h>
#include <grpc/support/string_util.h>
int grpc_trace_channel_stack_builder = 0;
grpc_tracer_flag grpc_trace_channel_stack_builder;
typedef struct filter_node {
struct filter_node *next;

@ -165,7 +165,7 @@ grpc_error *grpc_channel_stack_builder_finish(
void grpc_channel_stack_builder_destroy(grpc_exec_ctx *exec_ctx,
grpc_channel_stack_builder *builder);
extern int grpc_trace_channel_stack_builder;
extern grpc_tracer_flag grpc_trace_channel_stack_builder;
#ifdef __cplusplus
}

@ -42,17 +42,23 @@
typedef struct tracer {
const char *name;
int *flag;
grpc_tracer_flag *flag;
struct tracer *next;
} tracer;
static tracer *tracers;
void grpc_register_tracer(const char *name, int *flag) {
#ifdef GRPC_THREADSAFE_TRACER
#define TRACER_SET(flag, on) gpr_atm_no_barrier_store(&(flag).value, (on))
#else
#define TRACER_SET(flag, on) (flag).value = (on)
#endif
void grpc_register_tracer(const char *name, grpc_tracer_flag *flag) {
tracer *t = gpr_malloc(sizeof(*t));
t->name = name;
t->flag = flag;
t->next = tracers;
*flag = 0;
TRACER_SET(*flag, false);
tracers = t;
}
@ -121,13 +127,13 @@ int grpc_tracer_set_enabled(const char *name, int enabled) {
tracer *t;
if (0 == strcmp(name, "all")) {
for (t = tracers; t; t = t->next) {
*t->flag = enabled;
TRACER_SET(*t->flag, enabled);
}
} else {
int found = 0;
for (t = tracers; t; t = t->next) {
if (0 == strcmp(name, t->name)) {
*t->flag = enabled;
TRACER_SET(*t->flag, enabled);
found = 1;
}
}

@ -34,9 +34,33 @@
#ifndef GRPC_CORE_LIB_DEBUG_TRACE_H
#define GRPC_CORE_LIB_DEBUG_TRACE_H
#include <grpc/support/atm.h>
#include <grpc/support/port_platform.h>
#include <stdbool.h>
void grpc_register_tracer(const char *name, int *flag);
#if defined(__has_feature) && __has_feature(thread_sanitizer)
#define GRPC_THREADSAFE_TRACER
#endif
typedef struct {
#ifdef GRPC_THREADSAFE_TRACER
gpr_atm value;
#else
bool value;
#endif
} grpc_tracer_flag;
#ifdef GRPC_THREADSAFE_TRACER
#define GRPC_TRACER_ON(flag) (gpr_atm_no_barrier_load(&(flag).value) != 0)
#define GRPC_TRACER_INITIALIZER(on) \
{ (gpr_atm)(on) }
#else
#define GRPC_TRACER_ON(flag) ((flag).value)
#define GRPC_TRACER_INITIALIZER(on) \
{ (on) }
#endif
void grpc_register_tracer(const char *name, grpc_tracer_flag *flag);
void grpc_tracer_init(const char *env_var_name);
void grpc_tracer_shutdown(void);

@ -40,7 +40,7 @@
#include <grpc/support/log.h>
#include <grpc/support/useful.h>
int grpc_http1_trace = 0;
grpc_tracer_flag grpc_http1_trace;
static char *buf2str(void *buffer, size_t length) {
char *out = gpr_malloc(length + 1);
@ -308,7 +308,7 @@ static grpc_error *addbyte(grpc_http_parser *parser, uint8_t byte,
case GRPC_HTTP_FIRST_LINE:
case GRPC_HTTP_HEADERS:
if (parser->cur_line_length >= GRPC_HTTP_PARSER_MAX_HEADER_LENGTH) {
if (grpc_http1_trace)
if (GRPC_TRACER_ON(grpc_http1_trace))
gpr_log(GPR_ERROR, "HTTP header max line length (%d) exceeded",
GRPC_HTTP_PARSER_MAX_HEADER_LENGTH);
return GRPC_ERROR_CREATE_FROM_STATIC_STRING(

@ -36,6 +36,7 @@
#include <grpc/slice.h>
#include <grpc/support/port_platform.h>
#include "src/core/lib/debug/trace.h"
#include "src/core/lib/iomgr/error.h"
/* Maximum length of a header string of the form 'Key: Value\r\n' */
@ -121,6 +122,6 @@ grpc_error *grpc_http_parser_eof(grpc_http_parser *parser);
void grpc_http_request_destroy(grpc_http_request *request);
void grpc_http_response_destroy(grpc_http_response *response);
extern int grpc_http1_trace;
extern grpc_tracer_flag grpc_http1_trace;
#endif /* GRPC_CORE_LIB_HTTP_PARSER_H */

@ -42,13 +42,13 @@
#include "src/core/lib/iomgr/workqueue.h"
#include "src/core/lib/profiling/timers.h"
int grpc_combiner_trace = 0;
grpc_tracer_flag grpc_combiner_trace;
#define GRPC_COMBINER_TRACE(fn) \
do { \
if (grpc_combiner_trace) { \
fn; \
} \
#define GRPC_COMBINER_TRACE(fn) \
do { \
if (GRPC_TRACER_ON(grpc_combiner_trace)) { \
fn; \
} \
} while (0)
#define STATE_UNORPHANED 1

@ -37,6 +37,7 @@
#include <stddef.h>
#include <grpc/support/atm.h>
#include "src/core/lib/debug/trace.h"
#include "src/core/lib/iomgr/exec_ctx.h"
#include "src/core/lib/support/mpscq.h"
@ -78,6 +79,6 @@ grpc_closure_scheduler *grpc_combiner_finally_scheduler(grpc_combiner *lock,
bool grpc_combiner_continue_exec_ctx(grpc_exec_ctx *exec_ctx);
extern int grpc_combiner_trace;
extern grpc_tracer_flag grpc_combiner_trace;
#endif /* GRPC_CORE_LIB_IOMGR_COMBINER_H */

@ -66,6 +66,9 @@ void grpc_iomgr_init(void) {
g_root_object.name = "root";
grpc_network_status_init();
grpc_iomgr_platform_init();
}
void grpc_iomgr_start(void) {
grpc_timer_manager_init();
}

@ -40,6 +40,9 @@
/** Initializes the iomgr. */
void grpc_iomgr_init(void);
/** Starts any background threads for iomgr. */
void grpc_iomgr_start(void);
/** Signals the intention to shutdown the iomgr. Expects to be able to flush
* exec_ctx. */
void grpc_iomgr_shutdown(grpc_exec_ctx *exec_ctx);

@ -44,7 +44,7 @@
#include "src/core/lib/iomgr/combiner.h"
int grpc_resource_quota_trace = 0;
grpc_tracer_flag grpc_resource_quota_trace;
#define MEMORY_USAGE_ESTIMATION_MAX 65536
@ -307,13 +307,13 @@ static bool rq_alloc(grpc_exec_ctx *exec_ctx,
resource_user->free_pool = 0;
resource_quota->free_pool -= amt;
rq_update_estimate(resource_quota);
if (grpc_resource_quota_trace) {
if (GRPC_TRACER_ON(grpc_resource_quota_trace)) {
gpr_log(GPR_DEBUG, "RQ %s %s: grant alloc %" PRId64
" bytes; rq_free_pool -> %" PRId64,
resource_quota->name, resource_user->name, amt,
resource_quota->free_pool);
}
} else if (grpc_resource_quota_trace && resource_user->free_pool >= 0) {
} else if (GRPC_TRACER_ON(grpc_resource_quota_trace) && resource_user->free_pool >= 0) {
gpr_log(GPR_DEBUG, "RQ %s %s: discard already satisfied alloc request",
resource_quota->name, resource_user->name);
}
@ -342,7 +342,7 @@ static bool rq_reclaim_from_per_user_free_pool(
resource_user->free_pool = 0;
resource_quota->free_pool += amt;
rq_update_estimate(resource_quota);
if (grpc_resource_quota_trace) {
if (GRPC_TRACER_ON(grpc_resource_quota_trace)) {
gpr_log(GPR_DEBUG, "RQ %s %s: reclaim_from_per_user_free_pool %" PRId64
" bytes; rq_free_pool -> %" PRId64,
resource_quota->name, resource_user->name, amt,
@ -365,7 +365,7 @@ static bool rq_reclaim(grpc_exec_ctx *exec_ctx,
: GRPC_RULIST_RECLAIMER_BENIGN;
grpc_resource_user *resource_user = rulist_pop_head(resource_quota, list);
if (resource_user == NULL) return false;
if (grpc_resource_quota_trace) {
if (GRPC_TRACER_ON(grpc_resource_quota_trace)) {
gpr_log(GPR_DEBUG, "RQ %s %s: initiate %s reclamation",
resource_quota->name, resource_user->name,
destructive ? "destructive" : "benign");
@ -786,7 +786,7 @@ void grpc_resource_user_alloc(grpc_exec_ctx *exec_ctx,
gpr_mu_lock(&resource_user->mu);
ru_ref_by(resource_user, (gpr_atm)size);
resource_user->free_pool -= (int64_t)size;
if (grpc_resource_quota_trace) {
if (GRPC_TRACER_ON(grpc_resource_quota_trace)) {
gpr_log(GPR_DEBUG, "RQ %s %s: alloc %" PRIdPTR "; free_pool -> %" PRId64,
resource_user->resource_quota->name, resource_user->name, size,
resource_user->free_pool);
@ -810,7 +810,7 @@ void grpc_resource_user_free(grpc_exec_ctx *exec_ctx,
gpr_mu_lock(&resource_user->mu);
bool was_zero_or_negative = resource_user->free_pool <= 0;
resource_user->free_pool += (int64_t)size;
if (grpc_resource_quota_trace) {
if (GRPC_TRACER_ON(grpc_resource_quota_trace)) {
gpr_log(GPR_DEBUG, "RQ %s %s: free %" PRIdPTR "; free_pool -> %" PRId64,
resource_user->resource_quota->name, resource_user->name, size,
resource_user->free_pool);
@ -839,7 +839,7 @@ void grpc_resource_user_post_reclaimer(grpc_exec_ctx *exec_ctx,
void grpc_resource_user_finish_reclamation(grpc_exec_ctx *exec_ctx,
grpc_resource_user *resource_user) {
if (grpc_resource_quota_trace) {
if (GRPC_TRACER_ON(grpc_resource_quota_trace)) {
gpr_log(GPR_DEBUG, "RQ %s %s: reclamation complete",
resource_user->resource_quota->name, resource_user->name);
}

@ -36,6 +36,7 @@
#include <grpc/grpc.h>
#include "src/core/lib/debug/trace.h"
#include "src/core/lib/iomgr/exec_ctx.h"
/** \file Tracks resource usage against a pool.
@ -75,7 +76,7 @@
maintain lists of users (which users arrange to leave before they are
destroyed) */
extern int grpc_resource_quota_trace;
extern grpc_tracer_flag grpc_resource_quota_trace;
grpc_resource_quota *grpc_resource_quota_ref_internal(
grpc_resource_quota *resource_quota);

@ -58,7 +58,7 @@
#include "src/core/lib/iomgr/unix_sockets_posix.h"
#include "src/core/lib/support/string.h"
extern int grpc_tcp_trace;
extern grpc_tracer_flag grpc_tcp_trace;
typedef struct {
gpr_mu mu;
@ -114,7 +114,7 @@ done:
static void tc_on_alarm(grpc_exec_ctx *exec_ctx, void *acp, grpc_error *error) {
int done;
async_connect *ac = acp;
if (grpc_tcp_trace) {
if (GRPC_TRACER_ON(grpc_tcp_trace)) {
const char *str = grpc_error_string(error);
gpr_log(GPR_DEBUG, "CLIENT_CONNECT: %s: on_alarm: error=%s", ac->addr_str,
str);
@ -152,7 +152,7 @@ static void on_writable(grpc_exec_ctx *exec_ctx, void *acp, grpc_error *error) {
GRPC_ERROR_REF(error);
if (grpc_tcp_trace) {
if (GRPC_TRACER_ON(grpc_tcp_trace)) {
const char *str = grpc_error_string(error);
gpr_log(GPR_DEBUG, "CLIENT_CONNECT: %s: on_writable: error=%s",
ac->addr_str, str);
@ -330,7 +330,7 @@ static void tcp_client_connect_impl(grpc_exec_ctx *exec_ctx,
grpc_schedule_on_exec_ctx);
ac->channel_args = grpc_channel_args_copy(channel_args);
if (grpc_tcp_trace) {
if (GRPC_TRACER_ON(grpc_tcp_trace)) {
gpr_log(GPR_DEBUG, "CLIENT_CONNECT: %s: asynchronously connecting",
ac->addr_str);
}

@ -74,7 +74,7 @@ typedef GRPC_MSG_IOVLEN_TYPE msg_iovlen_type;
typedef size_t msg_iovlen_type;
#endif
int grpc_tcp_trace = 0;
grpc_tracer_flag grpc_tcp_trace;
typedef struct {
grpc_endpoint base;
@ -221,7 +221,7 @@ static void call_read_cb(grpc_exec_ctx *exec_ctx, grpc_tcp *tcp,
grpc_error *error) {
grpc_closure *cb = tcp->read_cb;
if (grpc_tcp_trace) {
if (GRPC_TRACER_ON(grpc_tcp_trace)) {
size_t i;
const char *str = grpc_error_string(error);
gpr_log(GPR_DEBUG, "read: error=%s", str);
@ -468,14 +468,14 @@ static void tcp_handle_write(grpc_exec_ctx *exec_ctx, void *arg /* grpc_tcp */,
}
if (!tcp_flush(tcp, &error)) {
if (grpc_tcp_trace) {
if (GRPC_TRACER_ON(grpc_tcp_trace)) {
gpr_log(GPR_DEBUG, "write: delayed");
}
grpc_fd_notify_on_write(exec_ctx, tcp->em_fd, &tcp->write_closure);
} else {
cb = tcp->write_cb;
tcp->write_cb = NULL;
if (grpc_tcp_trace) {
if (GRPC_TRACER_ON(grpc_tcp_trace)) {
const char *str = grpc_error_string(error);
gpr_log(GPR_DEBUG, "write: %s", str);
}
@ -490,7 +490,7 @@ static void tcp_write(grpc_exec_ctx *exec_ctx, grpc_endpoint *ep,
grpc_tcp *tcp = (grpc_tcp *)ep;
grpc_error *error = GRPC_ERROR_NONE;
if (grpc_tcp_trace) {
if (GRPC_TRACER_ON(grpc_tcp_trace)) {
size_t i;
for (i = 0; i < buf->count; i++) {
@ -521,12 +521,12 @@ static void tcp_write(grpc_exec_ctx *exec_ctx, grpc_endpoint *ep,
if (!tcp_flush(tcp, &error)) {
TCP_REF(tcp, "write");
tcp->write_cb = cb;
if (grpc_tcp_trace) {
if (GRPC_TRACER_ON(grpc_tcp_trace)) {
gpr_log(GPR_DEBUG, "write: delayed");
}
grpc_fd_notify_on_write(exec_ctx, tcp->em_fd, &tcp->write_closure);
} else {
if (grpc_tcp_trace) {
if (GRPC_TRACER_ON(grpc_tcp_trace)) {
const char *str = grpc_error_string(error);
gpr_log(GPR_DEBUG, "write: %s", str);
}

@ -44,10 +44,11 @@
otherwise specified.
*/
#include "src/core/lib/debug/trace.h"
#include "src/core/lib/iomgr/endpoint.h"
#include "src/core/lib/iomgr/ev_posix.h"
extern int grpc_tcp_trace;
extern grpc_tracer_flag grpc_tcp_trace;
/* Create a tcp endpoint given a file desciptor and a read slice size.
Takes ownership of fd. */

@ -257,7 +257,7 @@ static void on_read(grpc_exec_ctx *exec_ctx, void *arg, grpc_error *err) {
addr_str = grpc_sockaddr_to_uri(&addr);
gpr_asprintf(&name, "tcp-server-connection:%s", addr_str);
if (grpc_tcp_trace) {
if (GRPC_TRACER_ON(grpc_tcp_trace)) {
gpr_log(GPR_DEBUG, "SERVER_CONNECT: incoming connection: %s", addr_str);
}

@ -56,8 +56,8 @@
#define MIN_QUEUE_WINDOW_DURATION 0.01
#define MAX_QUEUE_WINDOW_DURATION 1
int grpc_timer_trace = 0;
int grpc_timer_check_trace = 0;
grpc_tracer_flag grpc_timer_trace;
grpc_tracer_flag grpc_timer_check_trace;
typedef struct {
gpr_mu mu;
@ -232,14 +232,13 @@ void grpc_timer_init(grpc_exec_ctx *exec_ctx, grpc_timer *timer,
GPR_ASSERT(deadline.clock_type == g_clock_type);
GPR_ASSERT(now.clock_type == g_clock_type);
timer->closure = closure;
timer->deadline = timespec_to_atm_round_up(deadline);
gpr_atm deadline_atm = timer->deadline = timespec_to_atm_round_up(deadline);
if (grpc_timer_trace) {
if (GRPC_TRACER_ON(grpc_timer_trace)) {
gpr_log(GPR_DEBUG, "TIMER %p: SET %" PRId64 ".%09d [%" PRIdPTR
"] now %" PRId64 ".%09d [%" PRIdPTR "] call %p[%p]",
timer, deadline.tv_sec, deadline.tv_nsec, timer->deadline,
now.tv_sec, now.tv_nsec, timespec_to_atm_round_down(now), closure,
closure->cb);
timer, deadline.tv_sec, deadline.tv_nsec, deadline_atm, now.tv_sec,
now.tv_nsec, timespec_to_atm_round_down(now), closure, closure->cb);
}
if (!g_shared_mutables.initialized) {
@ -262,13 +261,13 @@ void grpc_timer_init(grpc_exec_ctx *exec_ctx, grpc_timer *timer,
grpc_time_averaged_stats_add_sample(&shard->stats,
ts_to_dbl(gpr_time_sub(deadline, now)));
if (timer->deadline < shard->queue_deadline_cap) {
if (deadline_atm < shard->queue_deadline_cap) {
is_first_timer = grpc_timer_heap_add(&shard->heap, timer);
} else {
timer->heap_index = INVALID_HEAP_INDEX;
list_join(&shard->list, timer);
}
if (grpc_timer_trace) {
if (GRPC_TRACER_ON(grpc_timer_trace)) {
gpr_log(GPR_DEBUG, " .. add to shard %d with queue_deadline_cap=%" PRIdPTR
" => is_first_timer=%s",
(int)(shard - g_shards), shard->queue_deadline_cap,
@ -289,16 +288,16 @@ void grpc_timer_init(grpc_exec_ctx *exec_ctx, grpc_timer *timer,
grpc_timer_check. */
if (is_first_timer) {
gpr_mu_lock(&g_shared_mutables.mu);
if (grpc_timer_trace) {
if (GRPC_TRACER_ON(grpc_timer_trace)) {
gpr_log(GPR_DEBUG, " .. old shard min_deadline=%" PRIdPTR,
shard->min_deadline);
}
if (timer->deadline < shard->min_deadline) {
if (deadline_atm < shard->min_deadline) {
gpr_atm old_min_deadline = g_shard_queue[0]->min_deadline;
shard->min_deadline = timer->deadline;
shard->min_deadline = deadline_atm;
note_deadline_change(shard);
if (shard->shard_queue_index == 0 && timer->deadline < old_min_deadline) {
gpr_atm_no_barrier_store(&g_shared_mutables.min_timer, timer->deadline);
if (shard->shard_queue_index == 0 && deadline_atm < old_min_deadline) {
gpr_atm_no_barrier_store(&g_shared_mutables.min_timer, deadline_atm);
grpc_kick_poller();
}
}
@ -319,7 +318,7 @@ void grpc_timer_cancel(grpc_exec_ctx *exec_ctx, grpc_timer *timer) {
shard_type *shard = &g_shards[GPR_HASH_POINTER(timer, NUM_SHARDS)];
gpr_mu_lock(&shard->mu);
if (grpc_timer_trace) {
if (GRPC_TRACER_ON(grpc_timer_trace)) {
gpr_log(GPR_DEBUG, "TIMER %p: CANCEL pending=%s", timer,
timer->pending ? "true" : "false");
}
@ -355,7 +354,7 @@ static int refill_queue(shard_type *shard, gpr_atm now) {
saturating_add(GPR_MAX(now, shard->queue_deadline_cap),
(gpr_atm)(deadline_delta * 1000.0));
if (grpc_timer_check_trace) {
if (GRPC_TRACER_ON(grpc_timer_check_trace)) {
gpr_log(GPR_DEBUG, " .. shard[%d]->queue_deadline_cap --> %" PRIdPTR,
(int)(shard - g_shards), shard->queue_deadline_cap);
}
@ -363,7 +362,7 @@ static int refill_queue(shard_type *shard, gpr_atm now) {
next = timer->next;
if (timer->deadline < shard->queue_deadline_cap) {
if (grpc_timer_check_trace) {
if (GRPC_TRACER_ON(grpc_timer_check_trace)) {
gpr_log(GPR_DEBUG, " .. add timer with deadline %" PRIdPTR " to heap",
timer->deadline);
}
@ -380,7 +379,7 @@ static int refill_queue(shard_type *shard, gpr_atm now) {
static grpc_timer *pop_one(shard_type *shard, gpr_atm now) {
grpc_timer *timer;
for (;;) {
if (grpc_timer_check_trace) {
if (GRPC_TRACER_ON(grpc_timer_check_trace)) {
gpr_log(GPR_DEBUG, " .. shard[%d]: heap_empty=%s",
(int)(shard - g_shards),
grpc_timer_heap_is_empty(&shard->heap) ? "true" : "false");
@ -390,13 +389,13 @@ static grpc_timer *pop_one(shard_type *shard, gpr_atm now) {
if (!refill_queue(shard, now)) return NULL;
}
timer = grpc_timer_heap_top(&shard->heap);
if (grpc_timer_check_trace) {
if (GRPC_TRACER_ON(grpc_timer_check_trace)) {
gpr_log(GPR_DEBUG,
" .. check top timer deadline=%" PRIdPTR " now=%" PRIdPTR,
timer->deadline, now);
}
if (timer->deadline > now) return NULL;
if (grpc_timer_trace) {
if (GRPC_TRACER_ON(grpc_timer_trace)) {
gpr_log(GPR_DEBUG, "TIMER %p: FIRE %" PRIdPTR "ms late", timer,
now - timer->deadline);
}
@ -436,7 +435,7 @@ static int run_some_expired_timers(grpc_exec_ctx *exec_ctx, gpr_atm now,
if (gpr_spinlock_trylock(&g_shared_mutables.checker_mu)) {
gpr_mu_lock(&g_shared_mutables.mu);
if (grpc_timer_check_trace) {
if (GRPC_TRACER_ON(grpc_timer_check_trace)) {
gpr_log(GPR_DEBUG, " .. shard[%d]->min_deadline = %" PRIdPTR,
(int)(g_shard_queue[0] - g_shards),
g_shard_queue[0]->min_deadline);
@ -452,7 +451,7 @@ static int run_some_expired_timers(grpc_exec_ctx *exec_ctx, gpr_atm now,
n +=
pop_timers(exec_ctx, g_shard_queue[0], now, &new_min_deadline, error);
if (grpc_timer_check_trace) {
if (GRPC_TRACER_ON(grpc_timer_check_trace)) {
gpr_log(GPR_DEBUG, " .. popped --> %" PRIdPTR
", shard[%d]->min_deadline %" PRIdPTR
" --> %" PRIdPTR ", now=%" PRIdPTR,
@ -509,7 +508,7 @@ bool grpc_timer_check(grpc_exec_ctx *exec_ctx, gpr_timespec now,
*next =
atm_to_timespec(GPR_MIN(timespec_to_atm_round_up(*next), min_timer));
}
if (grpc_timer_check_trace) {
if (GRPC_TRACER_ON(grpc_timer_check_trace)) {
gpr_log(GPR_DEBUG,
"TIMER CHECK SKIP: now_atm=%" PRIdPTR " min_timer=%" PRIdPTR,
now_atm, min_timer);
@ -523,7 +522,7 @@ bool grpc_timer_check(grpc_exec_ctx *exec_ctx, gpr_timespec now,
: GRPC_ERROR_CREATE_FROM_STATIC_STRING("Shutting down timer system");
// tracing
if (grpc_timer_check_trace) {
if (GRPC_TRACER_ON(grpc_timer_check_trace)) {
char *next_str;
if (next == NULL) {
next_str = gpr_strdup("NULL");
@ -549,7 +548,7 @@ bool grpc_timer_check(grpc_exec_ctx *exec_ctx, gpr_timespec now,
*next = atm_to_timespec(next_atm);
}
// tracing
if (grpc_timer_check_trace) {
if (GRPC_TRACER_ON(grpc_timer_check_trace)) {
char *next_str;
if (next == NULL) {
next_str = gpr_strdup("NULL");

@ -45,11 +45,11 @@ typedef struct completed_thread {
} completed_thread;
static gpr_mu g_mu;
static bool g_threaded;
static gpr_cv g_cv_wait;
static gpr_cv g_cv_shutdown;
static int g_thread_count;
static int g_waiter_count;
static bool g_shutdown;
static completed_thread *g_completed_threads;
static bool g_kicked;
@ -83,6 +83,14 @@ static void start_timer_thread_and_unlock(void) {
gpr_thd_new(&thd, timer_thread, NULL, &opt);
}
void grpc_timer_manager_tick() {
grpc_exec_ctx exec_ctx = GRPC_EXEC_CTX_INIT;
gpr_timespec next = gpr_inf_future(GPR_CLOCK_MONOTONIC);
gpr_timespec now = gpr_now(GPR_CLOCK_MONOTONIC);
grpc_timer_check(&exec_ctx, now, &next);
grpc_exec_ctx_finish(&exec_ctx);
}
static void timer_thread(void *unused) {
grpc_exec_ctx exec_ctx =
GRPC_EXEC_CTX_INITIALIZER(0, grpc_never_ready_to_finish, NULL);
@ -93,7 +101,7 @@ static void timer_thread(void *unused) {
gpr_mu_lock(&g_mu);
--g_waiter_count;
bool start_thread = g_waiter_count == 0;
if (start_thread && !g_shutdown) {
if (start_thread && g_threaded) {
start_timer_thread_and_unlock();
} else {
gpr_mu_unlock(&g_mu);
@ -105,7 +113,7 @@ static void timer_thread(void *unused) {
gpr_mu_unlock(&g_mu);
} else {
gpr_mu_lock(&g_mu);
if (g_shutdown) break;
if (!g_threaded) break;
if (gpr_cv_wait(&g_cv_wait, &g_mu, next)) {
if (g_kicked) {
grpc_timer_consume_kick();
@ -130,34 +138,58 @@ static void timer_thread(void *unused) {
gpr_log(GPR_DEBUG, "End timer thread");
}
static void start_threads(void) {
gpr_mu_lock(&g_mu);
if (!g_threaded) {
g_threaded = true;
start_timer_thread_and_unlock();
} else {
g_threaded = false;
gpr_mu_unlock(&g_mu);
}
}
void grpc_timer_manager_init(void) {
gpr_mu_init(&g_mu);
gpr_cv_init(&g_cv_wait);
gpr_cv_init(&g_cv_shutdown);
g_threaded = false;
g_thread_count = 0;
g_waiter_count = 0;
g_shutdown = false;
g_completed_threads = NULL;
gpr_mu_lock(&g_mu);
start_timer_thread_and_unlock();
start_threads();
}
void grpc_timer_manager_shutdown(void) {
static void stop_threads(void) {
gpr_mu_lock(&g_mu);
g_shutdown = true;
gpr_cv_broadcast(&g_cv_wait);
while (g_thread_count > 0) {
gpr_cv_wait(&g_cv_shutdown, &g_mu, gpr_inf_future(GPR_CLOCK_REALTIME));
gc_completed_threads();
if (g_threaded) {
g_threaded = false;
gpr_cv_broadcast(&g_cv_wait);
while (g_thread_count > 0) {
gpr_cv_wait(&g_cv_shutdown, &g_mu, gpr_inf_future(GPR_CLOCK_REALTIME));
gc_completed_threads();
}
}
gpr_mu_unlock(&g_mu);
}
void grpc_timer_manager_shutdown(void) {
stop_threads();
gpr_mu_destroy(&g_mu);
gpr_cv_destroy(&g_cv_wait);
gpr_cv_destroy(&g_cv_shutdown);
}
void grpc_timer_manager_set_threading(bool threaded) {
if (threaded) {
start_threads();
} else {
stop_threads();
}
}
void grpc_kick_poller(void) {
gpr_mu_lock(&g_mu);
g_kicked = true;

@ -34,10 +34,19 @@
#ifndef GRPC_CORE_IOMGR_TIMER_MANAGER_H
#define GRPC_CORE_IOMGR_TIMER_MANAGER_H
#include <stdbool.h>
/* Timer Manager tries to keep one thread waiting for the next timeout at all
times */
void grpc_timer_manager_init(void);
void grpc_timer_manager_shutdown(void);
/* enable/disable threading - must be called after grpc_timer_manager_init and
* before grpc_timer_manager_shutdown */
void grpc_timer_manager_set_threading(bool enabled);
/* explicitly perform one tick of the timer system - for when threading is
* disabled */
void grpc_timer_manager_tick(void);
#endif

@ -171,7 +171,7 @@ static char *redact_private_key(const char *json_key) {
grpc_call_credentials *grpc_service_account_jwt_access_credentials_create(
const char *json_key, gpr_timespec token_lifetime, void *reserved) {
if (grpc_api_trace) {
if (GRPC_TRACER_ON(grpc_api_trace)) {
char *clean_json = redact_private_key(json_key);
gpr_log(GPR_INFO,
"grpc_service_account_jwt_access_credentials_create("

@ -412,7 +412,7 @@ grpc_call_credentials *grpc_google_refresh_token_credentials_create(
const char *json_refresh_token, void *reserved) {
grpc_auth_refresh_token token =
grpc_auth_refresh_token_create_from_string(json_refresh_token);
if (grpc_api_trace) {
if (GRPC_TRACER_ON(grpc_api_trace)) {
char *loggable_token = create_loggable_refresh_token(&token);
gpr_log(GPR_INFO,
"grpc_refresh_token_credentials_create(json_refresh_token=%s, "

@ -253,7 +253,7 @@ static void auth_start_transport_op(grpc_exec_ctx *exec_ctx,
grpc_linked_mdelem *l;
grpc_client_security_context *sec_ctx = NULL;
if (calld->security_context_set == 0 && !op->cancel_stream) {
if (!op->cancel_stream && calld->security_context_set == 0) {
calld->security_context_set = 1;
GPR_ASSERT(op->payload->context != NULL);
if (op->payload->context[GRPC_CONTEXT_SECURITY].value == NULL) {

@ -75,7 +75,7 @@ typedef struct {
gpr_refcount ref;
} secure_endpoint;
int grpc_trace_secure_endpoint = 0;
grpc_tracer_flag grpc_trace_secure_endpoint;
static void destroy(grpc_exec_ctx *exec_ctx, secure_endpoint *secure_ep) {
secure_endpoint *ep = secure_ep;
@ -137,7 +137,7 @@ static void flush_read_staging_buffer(secure_endpoint *ep, uint8_t **cur,
static void call_read_cb(grpc_exec_ctx *exec_ctx, secure_endpoint *ep,
grpc_error *error) {
if (grpc_trace_secure_endpoint) {
if (GRPC_TRACER_ON(grpc_trace_secure_endpoint)) {
size_t i;
for (i = 0; i < ep->read_buffer->count; i++) {
char *data = grpc_dump_slice(ep->read_buffer->slices[i],
@ -269,7 +269,7 @@ static void endpoint_write(grpc_exec_ctx *exec_ctx, grpc_endpoint *secure_ep,
grpc_slice_buffer_reset_and_unref_internal(exec_ctx, &ep->output_buffer);
if (grpc_trace_secure_endpoint) {
if (GRPC_TRACER_ON(grpc_trace_secure_endpoint)) {
for (i = 0; i < slices->count; i++) {
char *data =
grpc_dump_slice(slices->slices[i], GPR_DUMP_HEX | GPR_DUMP_ASCII);

@ -39,7 +39,7 @@
struct tsi_frame_protector;
extern int grpc_trace_secure_endpoint;
extern grpc_tracer_flag grpc_trace_secure_endpoint;
/* Takes ownership of protector and to_wrap, and refs leftover_slices. */
grpc_endpoint *grpc_secure_endpoint_create(

@ -33,4 +33,4 @@
#include "src/core/lib/surface/api_trace.h"
int grpc_api_trace = 0;
grpc_tracer_flag grpc_api_trace;

@ -37,7 +37,7 @@
#include <grpc/support/log.h>
#include "src/core/lib/debug/trace.h"
extern int grpc_api_trace;
extern grpc_tracer_flag grpc_api_trace;
/* Provide unwrapping macros because we're in C89 and variadic macros weren't
introduced until C99... */
@ -58,7 +58,7 @@ extern int grpc_api_trace;
/* Due to the limitations of C89's preprocessor, the arity of the var-arg list
'nargs' must be specified. */
#define GRPC_API_TRACE(fmt, nargs, args) \
if (grpc_api_trace) { \
if (GRPC_TRACER_ON(grpc_api_trace)) { \
gpr_log(GPR_INFO, fmt GRPC_API_TRACE_UNWRAP##nargs args); \
}

@ -244,8 +244,8 @@ struct grpc_call {
void *saved_receiving_stream_ready_bctlp;
};
int grpc_call_error_trace = 0;
int grpc_compression_trace = 0;
grpc_tracer_flag grpc_call_error_trace;
grpc_tracer_flag grpc_compression_trace;
#define CALL_STACK_FROM_CALL(call) ((grpc_call_stack *)((call) + 1))
#define CALL_FROM_CALL_STACK(call_stack) (((grpc_call *)(call_stack)) - 1)
@ -702,7 +702,7 @@ static void get_final_status(grpc_call *call,
for (i = 0; i < STATUS_SOURCE_COUNT; i++) {
status[i] = unpack_received_status(gpr_atm_acq_load(&call->status[i]));
}
if (grpc_call_error_trace) {
if (GRPC_TRACER_ON(grpc_call_error_trace)) {
gpr_log(GPR_DEBUG, "get_final_status %s", call->is_client ? "CLI" : "SVR");
for (i = 0; i < STATUS_SOURCE_COUNT; i++) {
if (status[i].is_set) {
@ -1259,7 +1259,7 @@ static void receiving_slice_ready(grpc_exec_ctx *exec_ctx, void *bctlp,
}
if (error != GRPC_ERROR_NONE) {
if (grpc_trace_operation_failures) {
if (GRPC_TRACER_ON(grpc_trace_operation_failures)) {
GRPC_LOG_IF_ERROR("receiving_slice_ready", GRPC_ERROR_REF(error));
}
grpc_byte_stream_destroy(exec_ctx, call->receiving_stream);
@ -1355,8 +1355,7 @@ static void validate_filtered_metadata(grpc_exec_ctx *exec_ctx,
GPR_ASSERT(call->encodings_accepted_by_peer != 0);
if (!GPR_BITGET(call->encodings_accepted_by_peer,
call->incoming_compression_algorithm)) {
extern int grpc_compression_trace;
if (grpc_compression_trace) {
if (GRPC_TRACER_ON(grpc_compression_trace)) {
char *algo_name = NULL;
grpc_compression_algorithm_name(call->incoming_compression_algorithm,
&algo_name);

@ -117,7 +117,8 @@ void grpc_call_context_set(grpc_call *call, grpc_context_index elem,
void *grpc_call_context_get(grpc_call *call, grpc_context_index elem);
#define GRPC_CALL_LOG_BATCH(sev, call, ops, nops, tag) \
if (grpc_api_trace) grpc_call_log_batch(sev, call, ops, nops, tag)
if (GRPC_TRACER_ON(grpc_api_trace)) \
grpc_call_log_batch(sev, call, ops, nops, tag)
uint8_t grpc_call_is_client(grpc_call *call);
@ -126,7 +127,8 @@ uint8_t grpc_call_is_client(grpc_call *call);
grpc_compression_algorithm grpc_call_compression_for_level(
grpc_call *call, grpc_compression_level level);
extern int grpc_call_error_trace;
extern grpc_tracer_flag grpc_call_error_trace;
extern grpc_tracer_flag grpc_compression_trace;
#ifdef __cplusplus
}

@ -50,9 +50,9 @@
#include "src/core/lib/surface/call.h"
#include "src/core/lib/surface/event_string.h"
int grpc_trace_operation_failures;
grpc_tracer_flag grpc_trace_operation_failures;
#ifndef NDEBUG
int grpc_trace_pending_tags;
grpc_tracer_flag grpc_trace_pending_tags;
#endif
typedef struct {
@ -242,15 +242,16 @@ struct grpc_completion_queue {
#define POLLSET_FROM_CQ(cq) ((grpc_pollset *)(cq + 1))
#define CQ_FROM_POLLSET(ps) (((grpc_completion_queue *)ps) - 1)
int grpc_cq_pluck_trace;
int grpc_cq_event_timeout_trace;
grpc_tracer_flag grpc_cq_pluck_trace = GRPC_TRACER_INITIALIZER(true);
grpc_tracer_flag grpc_cq_event_timeout_trace = GRPC_TRACER_INITIALIZER(true);
#define GRPC_SURFACE_TRACE_RETURNED_EVENT(cq, event) \
if (grpc_api_trace && \
(grpc_cq_pluck_trace || (event)->type != GRPC_QUEUE_TIMEOUT)) { \
char *_ev = grpc_event_string(event); \
gpr_log(GPR_INFO, "RETURN_EVENT[%p]: %s", cq, _ev); \
gpr_free(_ev); \
#define GRPC_SURFACE_TRACE_RETURNED_EVENT(cq, event) \
if (GRPC_TRACER_ON(grpc_api_trace) && \
(GRPC_TRACER_ON(grpc_cq_pluck_trace) || \
(event)->type != GRPC_QUEUE_TIMEOUT)) { \
char *_ev = grpc_event_string(event); \
gpr_log(GPR_INFO, "RETURN_EVENT[%p]: %s", cq, _ev); \
gpr_free(_ev); \
}
static void on_pollset_shutdown_done(grpc_exec_ctx *exec_ctx, void *cc,
@ -375,14 +376,16 @@ void grpc_cq_end_op(grpc_exec_ctx *exec_ctx, grpc_completion_queue *cc,
#endif
GPR_TIMER_BEGIN("grpc_cq_end_op", 0);
if (grpc_api_trace ||
(grpc_trace_operation_failures && error != GRPC_ERROR_NONE)) {
if (GRPC_TRACER_ON(grpc_api_trace) ||
(GRPC_TRACER_ON(grpc_trace_operation_failures) &&
error != GRPC_ERROR_NONE)) {
const char *errmsg = grpc_error_string(error);
GRPC_API_TRACE(
"grpc_cq_end_op(exec_ctx=%p, cc=%p, tag=%p, error=%s, done=%p, "
"done_arg=%p, storage=%p)",
7, (exec_ctx, cc, tag, errmsg, done, done_arg, storage));
if (grpc_trace_operation_failures && error != GRPC_ERROR_NONE) {
if (GRPC_TRACER_ON(grpc_trace_operation_failures) &&
error != GRPC_ERROR_NONE) {
gpr_log(GPR_ERROR, "Operation failed: tag=%p, error=%s", tag, errmsg);
}
}
@ -481,7 +484,7 @@ static bool cq_is_next_finished(grpc_exec_ctx *exec_ctx, void *arg) {
#ifndef NDEBUG
static void dump_pending_tags(grpc_completion_queue *cc) {
if (!grpc_trace_pending_tags) return;
if (!GRPC_TRACER_ON(grpc_trace_pending_tags)) return;
gpr_strvec v;
gpr_strvec_init(&v);
@ -677,7 +680,7 @@ grpc_event grpc_completion_queue_pluck(grpc_completion_queue *cc, void *tag,
abort();
}
if (grpc_cq_pluck_trace) {
if (GRPC_TRACER_ON(grpc_cq_pluck_trace)) {
GRPC_API_TRACE(
"grpc_completion_queue_pluck("
"cc=%p, tag=%p, "

@ -37,15 +37,16 @@
/* Internal API for completion queues */
#include <grpc/grpc.h>
#include "src/core/lib/debug/trace.h"
#include "src/core/lib/iomgr/pollset.h"
/* These trace flags default to 1. The corresponding lines are only traced
if grpc_api_trace is also truthy */
extern int grpc_cq_pluck_trace;
extern int grpc_cq_event_timeout_trace;
extern int grpc_trace_operation_failures;
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 int grpc_trace_pending_tags;
extern grpc_tracer_flag grpc_trace_pending_tags;
#endif
typedef struct grpc_cq_completion {

@ -145,10 +145,8 @@ void grpc_init(void) {
grpc_register_tracer("server_channel", &grpc_server_channel_trace);
grpc_register_tracer("bdp_estimator", &grpc_bdp_estimator_trace);
// Default pluck trace to 1
grpc_cq_pluck_trace = 1;
grpc_register_tracer("queue_timeout", &grpc_cq_event_timeout_trace);
// Default timeout trace to 1
grpc_cq_event_timeout_trace = 1;
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);
@ -173,6 +171,7 @@ void grpc_init(void) {
grpc_tracer_init("GRPC_TRACE");
/* no more changes to channel init pipelines */
grpc_channel_init_finalize();
grpc_iomgr_start();
}
gpr_mu_unlock(&g_init_mu);
GRPC_API_TRACE("grpc_init(void)", 0, ());

@ -73,7 +73,7 @@ typedef struct registered_method registered_method;
typedef enum { BATCH_CALL, REGISTERED_CALL } requested_call_type;
int grpc_server_channel_trace = 0;
grpc_tracer_flag grpc_server_channel_trace;
typedef struct requested_call {
requested_call_type type;
@ -456,7 +456,7 @@ static void destroy_channel(grpc_exec_ctx *exec_ctx, channel_data *chand,
grpc_closure_init(&chand->finish_destroy_channel_closure,
finish_destroy_channel, chand, grpc_schedule_on_exec_ctx);
if (grpc_server_channel_trace && error != GRPC_ERROR_NONE) {
if (GRPC_TRACER_ON(grpc_server_channel_trace) && error != GRPC_ERROR_NONE) {
const char *msg = grpc_error_string(error);
gpr_log(GPR_INFO, "Disconnected client: %s", msg);
}

@ -36,12 +36,13 @@
#include <grpc/grpc.h>
#include "src/core/lib/channel/channel_stack.h"
#include "src/core/lib/debug/trace.h"
#include "src/core/lib/transport/transport.h"
extern const grpc_channel_filter grpc_server_top_filter;
/** Lightweight tracing of server channel state */
extern int grpc_server_channel_trace;
extern grpc_tracer_flag grpc_server_channel_trace;
/* Add a listener to the server: when the server starts, it will call start,
and when it shuts down, it will call destroy */

@ -38,7 +38,7 @@
#include <grpc/support/log.h>
#include <grpc/support/useful.h>
int grpc_bdp_estimator_trace = 0;
grpc_tracer_flag grpc_bdp_estimator_trace;
void grpc_bdp_estimator_init(grpc_bdp_estimator *estimator, const char *name) {
estimator->estimate = 65536;
@ -67,7 +67,7 @@ bool grpc_bdp_estimator_add_incoming_bytes(grpc_bdp_estimator *estimator,
}
void grpc_bdp_estimator_schedule_ping(grpc_bdp_estimator *estimator) {
if (grpc_bdp_estimator_trace) {
if (GRPC_TRACER_ON(grpc_bdp_estimator_trace)) {
gpr_log(GPR_DEBUG, "bdp[%s]:sched acc=%" PRId64 " est=%" PRId64,
estimator->name, estimator->accumulator, estimator->estimate);
}
@ -77,7 +77,7 @@ void grpc_bdp_estimator_schedule_ping(grpc_bdp_estimator *estimator) {
}
void grpc_bdp_estimator_start_ping(grpc_bdp_estimator *estimator) {
if (grpc_bdp_estimator_trace) {
if (GRPC_TRACER_ON(grpc_bdp_estimator_trace)) {
gpr_log(GPR_DEBUG, "bdp[%s]:start acc=%" PRId64 " est=%" PRId64,
estimator->name, estimator->accumulator, estimator->estimate);
}
@ -87,14 +87,14 @@ void grpc_bdp_estimator_start_ping(grpc_bdp_estimator *estimator) {
}
void grpc_bdp_estimator_complete_ping(grpc_bdp_estimator *estimator) {
if (grpc_bdp_estimator_trace) {
if (GRPC_TRACER_ON(grpc_bdp_estimator_trace)) {
gpr_log(GPR_DEBUG, "bdp[%s]:complete acc=%" PRId64 " est=%" PRId64,
estimator->name, estimator->accumulator, estimator->estimate);
}
GPR_ASSERT(estimator->ping_state == GRPC_BDP_PING_STARTED);
if (estimator->accumulator > 2 * estimator->estimate / 3) {
estimator->estimate *= 2;
if (grpc_bdp_estimator_trace) {
if (GRPC_TRACER_ON(grpc_bdp_estimator_trace)) {
gpr_log(GPR_DEBUG, "bdp[%s]: estimate increased to %" PRId64,
estimator->name, estimator->estimate);
}

@ -36,11 +36,12 @@
#include <stdbool.h>
#include <stdint.h>
#include "src/core/lib/debug/trace.h"
#define GRPC_BDP_SAMPLES 16
#define GRPC_BDP_MIN_SAMPLES_FOR_ESTIMATE 3
extern int grpc_bdp_estimator_trace;
extern grpc_tracer_flag grpc_bdp_estimator_trace;
typedef enum {
GRPC_BDP_PING_UNSCHEDULED,

@ -39,7 +39,7 @@
#include <grpc/support/log.h>
#include <grpc/support/string_util.h>
int grpc_connectivity_state_trace = 0;
grpc_tracer_flag grpc_connectivity_state_trace;
const char *grpc_connectivity_state_name(grpc_connectivity_state state) {
switch (state) {
@ -94,7 +94,7 @@ grpc_connectivity_state grpc_connectivity_state_check(
grpc_connectivity_state cur =
(grpc_connectivity_state)gpr_atm_no_barrier_load(
&tracker->current_state_atm);
if (grpc_connectivity_state_trace) {
if (GRPC_TRACER_ON(grpc_connectivity_state_trace)) {
gpr_log(GPR_DEBUG, "CONWATCH: %p %s: get %s", tracker, tracker->name,
grpc_connectivity_state_name(cur));
}
@ -106,7 +106,7 @@ grpc_connectivity_state grpc_connectivity_state_get(
grpc_connectivity_state cur =
(grpc_connectivity_state)gpr_atm_no_barrier_load(
&tracker->current_state_atm);
if (grpc_connectivity_state_trace) {
if (GRPC_TRACER_ON(grpc_connectivity_state_trace)) {
gpr_log(GPR_DEBUG, "CONWATCH: %p %s: get %s", tracker, tracker->name,
grpc_connectivity_state_name(cur));
}
@ -127,7 +127,7 @@ bool grpc_connectivity_state_notify_on_state_change(
grpc_connectivity_state cur =
(grpc_connectivity_state)gpr_atm_no_barrier_load(
&tracker->current_state_atm);
if (grpc_connectivity_state_trace) {
if (GRPC_TRACER_ON(grpc_connectivity_state_trace)) {
if (current == NULL) {
gpr_log(GPR_DEBUG, "CONWATCH: %p %s: unsubscribe notify=%p", tracker,
tracker->name, notify);
@ -180,7 +180,7 @@ void grpc_connectivity_state_set(grpc_exec_ctx *exec_ctx,
(grpc_connectivity_state)gpr_atm_no_barrier_load(
&tracker->current_state_atm);
grpc_connectivity_state_watcher *w;
if (grpc_connectivity_state_trace) {
if (GRPC_TRACER_ON(grpc_connectivity_state_trace)) {
const char *error_string = grpc_error_string(error);
gpr_log(GPR_DEBUG, "SET: %p %s: %s --> %s [%s] error=%p %s", tracker,
tracker->name, grpc_connectivity_state_name(cur),
@ -208,7 +208,7 @@ void grpc_connectivity_state_set(grpc_exec_ctx *exec_ctx,
while ((w = tracker->watchers) != NULL) {
*w->current = state;
tracker->watchers = w->next;
if (grpc_connectivity_state_trace) {
if (GRPC_TRACER_ON(grpc_connectivity_state_trace)) {
gpr_log(GPR_DEBUG, "NOTIFY: %p %s: %p", tracker, tracker->name,
w->notify);
}

@ -35,6 +35,7 @@
#define GRPC_CORE_LIB_TRANSPORT_CONNECTIVITY_STATE_H
#include <grpc/grpc.h>
#include "src/core/lib/debug/trace.h"
#include "src/core/lib/iomgr/exec_ctx.h"
typedef struct grpc_connectivity_state_watcher {
@ -57,7 +58,7 @@ typedef struct {
char *name;
} grpc_connectivity_state_tracker;
extern int grpc_connectivity_state_trace;
extern grpc_tracer_flag grpc_connectivity_state_trace;
/** enum --> string conversion */
const char *grpc_connectivity_state_name(grpc_connectivity_state state);

@ -396,7 +396,7 @@ static tsi_result fake_handshaker_get_bytes_to_send_to_peer(
if (next_message_to_send > TSI_FAKE_HANDSHAKE_MESSAGE_MAX) {
next_message_to_send = TSI_FAKE_HANDSHAKE_MESSAGE_MAX;
}
if (tsi_tracing_enabled) {
if (GRPC_TRACER_ON(tsi_tracing_enabled)) {
gpr_log(GPR_INFO, "%s prepared %s.",
impl->is_client ? "Client" : "Server",
tsi_fake_handshake_message_to_string(impl->next_message_to_send));
@ -408,7 +408,7 @@ static tsi_result fake_handshaker_get_bytes_to_send_to_peer(
if (!impl->is_client &&
impl->next_message_to_send == TSI_FAKE_HANDSHAKE_MESSAGE_MAX) {
/* We're done. */
if (tsi_tracing_enabled) {
if (GRPC_TRACER_ON(tsi_tracing_enabled)) {
gpr_log(GPR_INFO, "Server is done.");
}
impl->result = TSI_OK;
@ -445,7 +445,7 @@ static tsi_result fake_handshaker_process_bytes_from_peer(
tsi_fake_handshake_message_to_string(received_msg),
tsi_fake_handshake_message_to_string(expected_msg));
}
if (tsi_tracing_enabled) {
if (GRPC_TRACER_ON(tsi_tracing_enabled)) {
gpr_log(GPR_INFO, "%s received %s.", impl->is_client ? "Client" : "Server",
tsi_fake_handshake_message_to_string(received_msg));
}
@ -453,7 +453,7 @@ static tsi_result fake_handshaker_process_bytes_from_peer(
impl->needs_incoming_message = 0;
if (impl->next_message_to_send == TSI_FAKE_HANDSHAKE_MESSAGE_MAX) {
/* We're done. */
if (tsi_tracing_enabled) {
if (GRPC_TRACER_ON(tsi_tracing_enabled)) {
gpr_log(GPR_INFO, "%s is done.", impl->is_client ? "Client" : "Server");
}
impl->result = TSI_OK;

@ -180,7 +180,7 @@ static const char *ssl_error_string(int error) {
/* TODO(jboeuf): Remove when we are past the debugging phase with this code. */
static void ssl_log_where_info(const SSL *ssl, int where, int flag,
const char *msg) {
if ((where & flag) && tsi_tracing_enabled) {
if ((where & flag) && GRPC_TRACER_ON(tsi_tracing_enabled)) {
gpr_log(GPR_INFO, "%20.20s - %30.30s - %5.10s", msg,
SSL_state_string_long(ssl), SSL_state_string(ssl));
}

@ -41,7 +41,7 @@
/* --- Tracing. --- */
int tsi_tracing_enabled = 0;
grpc_tracer_flag tsi_tracing_enabled;
/* --- tsi_result common implementation. --- */

@ -36,13 +36,14 @@
#include <stdbool.h>
#include "src/core/lib/debug/trace.h"
#include "src/core/tsi/transport_security_interface.h"
#ifdef __cplusplus
extern "C" {
#endif
extern int tsi_tracing_enabled;
extern grpc_tracer_flag tsi_tracing_enabled;
/* Base for tsi_frame_protector implementations.
See transport_security_interface.h for documentation. */

@ -37,6 +37,8 @@
#include <stdint.h>
#include <stdlib.h>
#include "src/core/lib/debug/trace.h"
#ifdef __cplusplus
extern "C" {
#endif
@ -73,8 +75,7 @@ const char *tsi_result_to_string(tsi_result result);
/* --- tsi tracing --- */
/* Set this early to avoid races */
extern int tsi_tracing_enabled;
extern grpc_tracer_flag tsi_tracing_enabled;
/* --- tsi_frame_protector object ---

@ -44,6 +44,7 @@
#include "src/core/lib/iomgr/resolve_address.h"
#include "src/core/lib/iomgr/tcp_client.h"
#include "src/core/lib/iomgr/timer.h"
#include "src/core/lib/iomgr/timer_manager.h"
#include "src/core/lib/slice/slice_internal.h"
#include "src/core/lib/surface/server.h"
#include "src/core/lib/transport/metadata.h"
@ -722,6 +723,7 @@ int LLVMFuzzerTestOneInput(const uint8_t *data, size_t size) {
grpc_tcp_client_connect_impl = my_tcp_client_connect;
gpr_now_impl = now_impl;
grpc_init();
grpc_timer_manager_set_threading(false);
grpc_resolve_address = my_resolve_address;
GPR_ASSERT(g_channel == NULL);
@ -769,6 +771,8 @@ int LLVMFuzzerTestOneInput(const uint8_t *data, size_t size) {
g_now = gpr_time_add(g_now, gpr_time_from_seconds(1, GPR_TIMESPAN));
}
grpc_timer_manager_tick();
switch (next_byte(&inp)) {
// terminate on bad bytes
default:

@ -151,7 +151,7 @@ static void test_subscribe_with_failure_then_destroy(void) {
int main(int argc, char **argv) {
grpc_test_init(argc, argv);
grpc_connectivity_state_trace = 1;
grpc_connectivity_state_trace.value = 1;
test_connectivity_state_name();
test_check();
test_subscribe_then_unsubscribe();

Loading…
Cancel
Save