From 6c8383af699211963debb76e2f96dee09497c26a Mon Sep 17 00:00:00 2001 From: Craig Tiller <ctiller@google.com> Date: Fri, 5 May 2017 16:54:42 +0000 Subject: [PATCH] Fix missing edge, add tracing --- src/core/lib/iomgr/ev_epoll1_linux.c | 1 - src/core/lib/iomgr/ev_epollex_linux.c | 26 +++++++++++++++++++++++--- src/core/lib/iomgr/lockfree_event.c | 16 ++++++++++++++++ src/core/lib/iomgr/tcp_client_posix.c | 4 ++-- 4 files changed, 41 insertions(+), 6 deletions(-) diff --git a/src/core/lib/iomgr/ev_epoll1_linux.c b/src/core/lib/iomgr/ev_epoll1_linux.c index 8aa69cd73a..d31eafc70b 100644 --- a/src/core/lib/iomgr/ev_epoll1_linux.c +++ b/src/core/lib/iomgr/ev_epoll1_linux.c @@ -57,7 +57,6 @@ #include "src/core/lib/iomgr/ev_posix.h" #include "src/core/lib/iomgr/iomgr_internal.h" #include "src/core/lib/iomgr/lockfree_event.h" -#include "src/core/lib/iomgr/timer.h" #include "src/core/lib/iomgr/wakeup_fd_posix.h" #include "src/core/lib/iomgr/workqueue.h" #include "src/core/lib/profiling/timers.h" diff --git a/src/core/lib/iomgr/ev_epollex_linux.c b/src/core/lib/iomgr/ev_epollex_linux.c index 5a7c0448b6..cb6814e89e 100644 --- a/src/core/lib/iomgr/ev_epollex_linux.c +++ b/src/core/lib/iomgr/ev_epollex_linux.c @@ -582,6 +582,10 @@ static grpc_error *pollable_add_fd(pollable *p, grpc_fd *fd) { const int epfd = p->epfd; GPR_ASSERT(epfd != -1); + if (GRPC_TRACER_ON(grpc_polling_trace)) { + gpr_log(GPR_DEBUG, "add fd %p to pollable %p", fd, p); + } + gpr_mu_lock(&fd->orphaned_mu); if (fd->orphaned) { gpr_mu_unlock(&fd->orphaned_mu); @@ -961,7 +965,8 @@ static bool begin_worker(grpc_pollset *pollset, grpc_pollset_worker *worker, if (worker->pollable != &pollset->pollable) { gpr_mu_unlock(&pollset->pollable.po.mu); } - if (GRPC_TRACER_ON(grpc_polling_trace) && worker->pollable->root_worker != worker) { + if (GRPC_TRACER_ON(grpc_polling_trace) && + worker->pollable->root_worker != worker) { gpr_log(GPR_DEBUG, "PS:%p wait %p w=%p for %dms", pollset, worker->pollable, worker, poll_deadline_to_millis_timeout(deadline, *now)); @@ -1080,6 +1085,10 @@ static grpc_error *pollset_add_fd_locked(grpc_exec_ctx *exec_ctx, static const char *err_desc = "pollset_add_fd"; grpc_error *error = GRPC_ERROR_NONE; if (pollset->current_pollable == &g_empty_pollable) { + if (GRPC_TRACER_ON(grpc_polling_trace)) + gpr_log(GPR_DEBUG, + "PS:%p add fd %p; transition pollable from empty to fd", pollset, + fd); /* empty pollable --> single fd pollable */ append_error(&error, pollset_kick_all(pollset), err_desc); pollset->current_pollable = &fd->pollable; @@ -1088,10 +1097,17 @@ static grpc_error *pollset_add_fd_locked(grpc_exec_ctx *exec_ctx, if (!fd_locked) gpr_mu_unlock(&fd->pollable.po.mu); REF_BY(fd, 2, "pollset_pollable"); } else if (pollset->current_pollable == &pollset->pollable) { + if (GRPC_TRACER_ON(grpc_polling_trace)) + gpr_log(GPR_DEBUG, "PS:%p add fd %p; already multipolling", pollset, fd); append_error(&error, pollable_add_fd(pollset->current_pollable, fd), err_desc); } else if (pollset->current_pollable != &fd->pollable) { grpc_fd *had_fd = (grpc_fd *)pollset->current_pollable; + if (GRPC_TRACER_ON(grpc_polling_trace)) + gpr_log(GPR_DEBUG, + "PS:%p add fd %p; transition pollable from fd %p to multipoller", + pollset, fd, had_fd); + append_error(&error, pollset_kick_all(pollset), err_desc); pollset->current_pollable = &pollset->pollable; if (append_error(&error, pollable_materialize(&pollset->pollable), err_desc)) { @@ -1458,7 +1474,8 @@ static const grpc_event_engine_vtable vtable = { .shutdown_engine = shutdown_engine, }; -const grpc_event_engine_vtable *grpc_init_epollex_linux(bool explicitly_requested) { +const grpc_event_engine_vtable *grpc_init_epollex_linux( + bool explicitly_requested) { if (!grpc_has_wakeup_fd()) { return NULL; } @@ -1483,7 +1500,10 @@ const grpc_event_engine_vtable *grpc_init_epollex_linux(bool explicitly_requeste #include "src/core/lib/iomgr/ev_posix.h" /* If GRPC_LINUX_EPOLL is not defined, it means epoll is not available. Return * NULL */ -const grpc_event_engine_vtable *grpc_init_epollex_linux(bool explicitly_requested) { return NULL; } +const grpc_event_engine_vtable *grpc_init_epollex_linux( + bool explicitly_requested) { + return NULL; +} #endif /* defined(GRPC_POSIX_SOCKET) */ #endif /* !defined(GRPC_LINUX_EPOLL) */ diff --git a/src/core/lib/iomgr/lockfree_event.c b/src/core/lib/iomgr/lockfree_event.c index 17e3bbf727..898ec1cb1b 100644 --- a/src/core/lib/iomgr/lockfree_event.c +++ b/src/core/lib/iomgr/lockfree_event.c @@ -35,6 +35,10 @@ #include <grpc/support/log.h> +#include "src/core/lib/debug/trace.h" + +extern grpc_tracer_flag grpc_polling_trace; + /* 'state' holds the to call when the fd is readable or writable respectively. It can contain one of the following values: CLOSURE_READY : The fd has an I/O event of interest but there is no @@ -93,6 +97,10 @@ void grpc_lfev_notify_on(grpc_exec_ctx *exec_ctx, gpr_atm *state, grpc_closure *closure) { while (true) { gpr_atm curr = gpr_atm_no_barrier_load(state); + if (GRPC_TRACER_ON(grpc_polling_trace)) { + gpr_log(GPR_DEBUG, "lfev_notify_on: %p curr=%p closure=%p", state, + (void *)curr, closure); + } switch (curr) { case CLOSURE_NOT_READY: { /* CLOSURE_NOT_READY -> <closure>. @@ -155,6 +163,10 @@ bool grpc_lfev_set_shutdown(grpc_exec_ctx *exec_ctx, gpr_atm *state, while (true) { gpr_atm curr = gpr_atm_no_barrier_load(state); + if (GRPC_TRACER_ON(grpc_polling_trace)) { + gpr_log(GPR_DEBUG, "lfev_set_shutdown: %p curr=%p err=%s", state, + (void *)curr, grpc_error_string(shutdown_err)); + } switch (curr) { case CLOSURE_READY: case CLOSURE_NOT_READY: @@ -200,6 +212,10 @@ void grpc_lfev_set_ready(grpc_exec_ctx *exec_ctx, gpr_atm *state) { while (true) { gpr_atm curr = gpr_atm_no_barrier_load(state); + if (GRPC_TRACER_ON(grpc_polling_trace)) { + gpr_log(GPR_DEBUG, "lfev_set_ready: %p curr=%p", state, (void *)curr); + } + switch (curr) { case CLOSURE_READY: { /* Already ready. We are done here */ diff --git a/src/core/lib/iomgr/tcp_client_posix.c b/src/core/lib/iomgr/tcp_client_posix.c index ed3fd94a98..5c7da999e0 100644 --- a/src/core/lib/iomgr/tcp_client_posix.c +++ b/src/core/lib/iomgr/tcp_client_posix.c @@ -331,8 +331,8 @@ static void tcp_client_connect_impl(grpc_exec_ctx *exec_ctx, ac->channel_args = grpc_channel_args_copy(channel_args); if (GRPC_TRACER_ON(grpc_tcp_trace)) { - gpr_log(GPR_DEBUG, "CLIENT_CONNECT: %s: asynchronously connecting", - ac->addr_str); + gpr_log(GPR_DEBUG, "CLIENT_CONNECT: %s: asynchronously connecting fd %p", + ac->addr_str, fdobj); } gpr_mu_lock(&ac->mu); -- GitLab