Chiebot-Mirror
/
grpc
mirror of https://github.com/grpc/grpc.git
8
0
Fork 0
Code Issues Projects Releases Wiki Activity

Get traces around everything

Browse Source
pull/7644/head
Craig Tiller 9 years ago
parent e7603b887e
commit c3df7b4924
5 changed files with 52 additions and 31 deletions
Whitespace
Show all changes Ignore whitespace when comparing lines Ignore changes in amount of whitespace Ignore changes in whitespace at EOL
Split View
Diff Options
Show Stats Download Patch File Download Diff File
  1. 53
      src/core/lib/iomgr/combiner.c
  2. 2
      src/core/lib/iomgr/combiner.h
  3. 2
      src/core/lib/iomgr/error.c
  4. 24
      src/core/lib/iomgr/tcp_posix.c
  5. 2
      src/core/lib/surface/init.c

53
src/core/lib/iomgr/combiner.c
Unescape View File

@ -43,10 +43,12 @@
int grpc_combiner_trace = 0;
#define COMBINER_TRACE(fn) \
if (grpc_combiner_trace) { \
fn \
}
#define GRPC_COMBINER_TRACE(fn) \
do { \
if (grpc_combiner_trace) { \
fn; \
} \
} while (0)
struct grpc_combiner {
grpc_workqueue *optional_workqueue;
@ -67,12 +69,12 @@ grpc_combiner *grpc_combiner_create(grpc_workqueue *optional_workqueue) {
gpr_mpscq_init(&lock->queue);
lock->take_async_break_before_final_list = false;
grpc_closure_list_init(&lock->final_list);
gpr_log(GPR_DEBUG, "C:%p create", lock);
GRPC_COMBINER_TRACE(gpr_log(GPR_DEBUG, "C:%p create", lock));
return lock;
}
static void really_destroy(grpc_exec_ctx *exec_ctx, grpc_combiner *lock) {
gpr_log(GPR_DEBUG, "C:%p really_destroy", lock);
GRPC_COMBINER_TRACE(gpr_log(GPR_DEBUG, "C:%p really_destroy", lock));
GPR_ASSERT(gpr_atm_no_barrier_load(&lock->state) == 0);
gpr_mpscq_destroy(&lock->queue);
GRPC_WORKQUEUE_UNREF(exec_ctx, lock->optional_workqueue, "combiner");
@ -81,8 +83,8 @@ static void really_destroy(grpc_exec_ctx *exec_ctx, grpc_combiner *lock) {
void grpc_combiner_destroy(grpc_exec_ctx *exec_ctx, grpc_combiner *lock) {
gpr_atm old_state = gpr_atm_full_fetch_add(&lock->state, -1);
gpr_log(GPR_DEBUG, "C:%p really_destroy old_state=%" PRIdPTR, lock,
old_state);
GRPC_COMBINER_TRACE(gpr_log(
GPR_DEBUG, "C:%p really_destroy old_state=%" PRIdPTR, lock, old_state));
if (old_state == 1) {
really_destroy(exec_ctx, lock);
}
@ -95,7 +97,8 @@ static void continue_finishing_mainline(grpc_exec_ctx *exec_ctx, void *arg,
grpc_error *error) {
GPR_TIMER_BEGIN("combiner.continue_executing_mainline", 0);
grpc_combiner *lock = arg;
gpr_log(GPR_DEBUG, "C:%p continue_finishing_mainline", lock);
GRPC_COMBINER_TRACE(
gpr_log(GPR_DEBUG, "C:%p continue_finishing_mainline", lock));
GPR_ASSERT(exec_ctx->active_combiner == NULL);
exec_ctx->active_combiner = lock;
if (maybe_finish_one(exec_ctx, lock)) finish(exec_ctx, lock);
@ -112,7 +115,8 @@ static void execute_final(grpc_exec_ctx *exec_ctx, grpc_combiner *lock) {
lock->take_async_break_before_final_list = false;
int loops = 0;
while (c != NULL) {
gpr_log(GPR_DEBUG, "C:%p execute_final[%d] c=%p", lock, loops, c);
GRPC_COMBINER_TRACE(
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;
c->cb(exec_ctx, c->cb_arg, error);
@ -127,7 +131,8 @@ static void continue_executing_final(grpc_exec_ctx *exec_ctx, void *arg,
grpc_error *error) {
GPR_TIMER_BEGIN("combiner.continue_executing_final", 0);
grpc_combiner *lock = arg;
gpr_log(GPR_DEBUG, "C:%p continue_executing_final", lock);
GRPC_COMBINER_TRACE(
gpr_log(GPR_DEBUG, "C:%p continue_executing_final", lock));
GPR_ASSERT(exec_ctx->active_combiner == NULL);
exec_ctx->active_combiner = lock;
// quick peek to see if new things have turned up on the queue: if so, go back
@ -146,9 +151,10 @@ static void continue_executing_final(grpc_exec_ctx *exec_ctx, void *arg,
static bool start_execute_final(grpc_exec_ctx *exec_ctx, grpc_combiner *lock) {
GPR_TIMER_BEGIN("combiner.start_execute_final", 0);
GPR_ASSERT(exec_ctx->active_combiner == lock);
gpr_log(GPR_DEBUG,
"C:%p start_execute_final take_async_break_before_final_list=%d",
lock, lock->take_async_break_before_final_list);
GRPC_COMBINER_TRACE(
gpr_log(GPR_DEBUG,
"C:%p start_execute_final take_async_break_before_final_list=%d",
lock, lock->take_async_break_before_final_list));
if (lock->take_async_break_before_final_list) {
grpc_closure_init(&lock->continue_finishing, continue_executing_final,
lock);
@ -166,7 +172,8 @@ static bool start_execute_final(grpc_exec_ctx *exec_ctx, grpc_combiner *lock) {
static bool maybe_finish_one(grpc_exec_ctx *exec_ctx, grpc_combiner *lock) {
GPR_TIMER_BEGIN("combiner.maybe_finish_one", 0);
gpr_mpscq_node *n = gpr_mpscq_pop(&lock->queue);
gpr_log(GPR_DEBUG, "C:%p maybe_finish_one n=%p", lock, n);
GRPC_COMBINER_TRACE(
gpr_log(GPR_DEBUG, "C:%p maybe_finish_one n=%p", lock, n));
GPR_ASSERT(exec_ctx->active_combiner == lock);
if (n == NULL) {
// queue is in an inconsistant state: use this as a cue that we should
@ -193,9 +200,9 @@ static void finish(grpc_exec_ctx *exec_ctx, grpc_combiner *lock) {
do {
executor = maybe_finish_one;
gpr_atm old_state = gpr_atm_full_fetch_add(&lock->state, -2);
gpr_log(GPR_DEBUG, "C:%p finish[%d] old_state=%" PRIdPTR " cl=[%p,%p]",
lock, loops, old_state, lock->final_list.head,
lock->final_list.tail);
GRPC_COMBINER_TRACE(gpr_log(
GPR_DEBUG, "C:%p finish[%d] old_state=%" PRIdPTR " cl=[%p,%p]", lock,
loops, old_state, lock->final_list.head, lock->final_list.tail));
switch (old_state) {
case 5: // we're down to one queued item: if it's the final list we
case 4: // should do that
@ -223,7 +230,8 @@ static void finish(grpc_exec_ctx *exec_ctx, grpc_combiner *lock) {
void grpc_combiner_execute(grpc_exec_ctx *exec_ctx, grpc_combiner *lock,
grpc_closure *cl, grpc_error *error) {
gpr_log(GPR_DEBUG, "C:%p grpc_combiner_execute c=%p", lock, cl);
GRPC_COMBINER_TRACE(
gpr_log(GPR_DEBUG, "C:%p grpc_combiner_execute c=%p", lock, cl));
GPR_TIMER_BEGIN("combiner.execute", 0);
gpr_atm last = gpr_atm_full_fetch_add(&lock->state, 2);
GPR_ASSERT(last & 1); // ensure lock has not been destroyed
@ -252,9 +260,10 @@ static void enqueue_finally(grpc_exec_ctx *exec_ctx, void *closure,
void grpc_combiner_execute_finally(grpc_exec_ctx *exec_ctx, grpc_combiner *lock,
grpc_closure *closure, grpc_error *error,
bool force_async_break) {
gpr_log(GPR_DEBUG,
"C:%p grpc_combiner_execute_finally c=%p force_async_break=%d; ac=%p",
lock, closure, force_async_break, exec_ctx->active_combiner);
GRPC_COMBINER_TRACE(gpr_log(
GPR_DEBUG,
"C:%p grpc_combiner_execute_finally c=%p force_async_break=%d; ac=%p",
lock, closure, force_async_break, exec_ctx->active_combiner));
GPR_TIMER_BEGIN("combiner.execute_finally", 0);
if (exec_ctx->active_combiner != lock) {
GPR_TIMER_MARK("slowpath", 0);

2
src/core/lib/iomgr/combiner.h
Unescape View File

@ -64,4 +64,6 @@ void grpc_combiner_execute_finally(grpc_exec_ctx *exec_ctx, grpc_combiner *lock,
bool hint_async_break);
void grpc_combiner_force_async_finally(grpc_combiner *lock);
extern int grpc_combiner_trace;
#endif /* GRPC_CORE_LIB_IOMGR_COMBINER_H */

2
src/core/lib/iomgr/error.c
Unescape View File

@ -332,7 +332,7 @@ grpc_error *grpc_error_add_child(grpc_error *src, grpc_error *child) {
return new;
}
static const char *no_error_string = "null";
static const char *no_error_string = "\"No Error\"";
static const char *oom_error_string = "\"Out of memory\"";
static const char *cancelled_error_string = "\"Cancelled\"";

24
src/core/lib/iomgr/tcp_posix.c
Unescape View File

@ -379,14 +379,18 @@ static void tcp_handle_write(grpc_exec_ctx *exec_ctx, void *arg /* grpc_tcp */,
}
if (!tcp_flush(tcp, &error)) {
gpr_log(GPR_DEBUG, "write: delayed");
if (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;
const char *str = grpc_error_string(error);
gpr_log(GPR_DEBUG, "write: %s", str);
grpc_error_free_string(str);
if (grpc_tcp_trace) {
const char *str = grpc_error_string(error);
gpr_log(GPR_DEBUG, "write: %s", str);
grpc_error_free_string(str);
}
GPR_TIMER_BEGIN("tcp_handle_write.cb", 0);
cb->cb(exec_ctx, cb->cb_arg, error);
@ -430,12 +434,16 @@ 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;
gpr_log(GPR_DEBUG, "write: delayed");
if (grpc_tcp_trace) {
gpr_log(GPR_DEBUG, "write: delayed");
}
grpc_fd_notify_on_write(exec_ctx, tcp->em_fd, &tcp->write_closure);
} else {
const char *str = grpc_error_string(error);
gpr_log(GPR_DEBUG, "write: %s", str);
grpc_error_free_string(str);
if (grpc_tcp_trace) {
const char *str = grpc_error_string(error);
gpr_log(GPR_DEBUG, "write: %s", str);
grpc_error_free_string(str);
}
grpc_exec_ctx_sched(exec_ctx, cb, error, NULL);
}

2
src/core/lib/surface/init.c
Unescape View File

@ -47,6 +47,7 @@
#include "src/core/lib/channel/http_server_filter.h"
#include "src/core/lib/debug/trace.h"
#include "src/core/lib/http/parser.h"
#include "src/core/lib/iomgr/combiner.h"
#include "src/core/lib/iomgr/executor.h"
#include "src/core/lib/iomgr/iomgr.h"
#include "src/core/lib/profiling/timers.h"
@ -165,6 +166,7 @@ void grpc_init(void) {
grpc_register_tracer("http1", &grpc_http1_trace);
grpc_register_tracer("compression", &grpc_compression_trace);
grpc_register_tracer("queue_pluck", &grpc_cq_pluck_trace);
grpc_register_tracer("combiner", &grpc_combiner_trace);
// Default pluck trace to 1
grpc_cq_pluck_trace = 1;
grpc_register_tracer("queue_timeout", &grpc_cq_event_timeout_trace);

Write Preview
Loading…
Cancel
Save