diff options
Diffstat (limited to 'src/core')
| -rw-r--r-- | src/core/iomgr/tcp_posix.c | 11 | ||||
| -rw-r--r-- | src/core/profiling/timers.c | 8 | ||||
| -rw-r--r-- | src/core/profiling/timers.h | 9 |
3 files changed, 20 insertions, 8 deletions
diff --git a/src/core/iomgr/tcp_posix.c b/src/core/iomgr/tcp_posix.c index 597a2a62d3..86721e9c95 100644 --- a/src/core/iomgr/tcp_posix.c +++ b/src/core/iomgr/tcp_posix.c @@ -46,6 +46,7 @@ #include "src/core/support/string.h" #include "src/core/debug/trace.h" +#include "src/core/profiling/timers.h" #include <grpc/support/alloc.h> #include <grpc/support/log.h> #include <grpc/support/slice.h> @@ -326,6 +327,7 @@ static void grpc_tcp_handle_read(void *arg /* grpc_tcp */, int success) { gpr_slice *final_slices; size_t final_nslices; + GRPC_TIMER_MARK(HANDLE_READ_BEGIN, 0); slice_state_init(&read_state, static_read_slices, INLINE_SLICE_BUFFER_SIZE, 0); @@ -348,9 +350,11 @@ static void grpc_tcp_handle_read(void *arg /* grpc_tcp */, int success) { msg.msg_controllen = 0; msg.msg_flags = 0; + GRPC_TIMER_MARK(RECVMSG_BEGIN, 0); do { read_bytes = recvmsg(tcp->fd, &msg, 0); } while (read_bytes < 0 && errno == EINTR); + GRPC_TIMER_MARK(RECVMSG_END, 0); if (read_bytes < allocated_bytes) { /* TODO(klempner): Consider a second read first, in hopes of getting a @@ -402,6 +406,7 @@ static void grpc_tcp_handle_read(void *arg /* grpc_tcp */, int success) { ++iov_size; } } + GRPC_TIMER_MARK(HANDLE_READ_END, 0); } static void grpc_tcp_notify_on_read(grpc_endpoint *ep, grpc_endpoint_read_cb cb, @@ -433,10 +438,12 @@ static grpc_endpoint_write_status grpc_tcp_flush(grpc_tcp *tcp) { msg.msg_controllen = 0; msg.msg_flags = 0; + GRPC_TIMER_MARK(SENDMSG_BEGIN, 0); do { /* TODO(klempner): Cork if this is a partial write */ sent_length = sendmsg(tcp->fd, &msg, 0); } while (sent_length < 0 && errno == EINTR); + GRPC_TIMER_MARK(SENDMSG_END, 0); if (sent_length < 0) { if (errno == EAGAIN) { @@ -472,6 +479,7 @@ static void grpc_tcp_handle_write(void *arg /* grpc_tcp */, int success) { return; } + GRPC_TIMER_MARK(CB_WRITE_BEGIN, 0); write_status = grpc_tcp_flush(tcp); if (write_status == GRPC_ENDPOINT_WRITE_PENDING) { grpc_fd_notify_on_write(tcp->em_fd, &tcp->write_closure); @@ -487,6 +495,7 @@ static void grpc_tcp_handle_write(void *arg /* grpc_tcp */, int success) { cb(tcp->write_user_data, cb_status); grpc_tcp_unref(tcp); } + GRPC_TIMER_MARK(CB_WRITE_END, 0); } static grpc_endpoint_write_status grpc_tcp_write(grpc_endpoint *ep, @@ -509,6 +518,7 @@ static grpc_endpoint_write_status grpc_tcp_write(grpc_endpoint *ep, } } + GRPC_TIMER_MARK(WRITE_BEGIN, 0); GPR_ASSERT(tcp->write_cb == NULL); slice_state_init(&tcp->write_state, slices, nslices, nslices); @@ -522,6 +532,7 @@ static grpc_endpoint_write_status grpc_tcp_write(grpc_endpoint *ep, grpc_fd_notify_on_write(tcp->em_fd, &tcp->write_closure); } + GRPC_TIMER_MARK(WRITE_END, 0); return status; } diff --git a/src/core/profiling/timers.c b/src/core/profiling/timers.c index 478397d1bf..7cc79bd22b 100644 --- a/src/core/profiling/timers.c +++ b/src/core/profiling/timers.c @@ -45,7 +45,7 @@ typedef struct grpc_timer_entry { grpc_precise_clock tm; const char* tag; - int seq; + void* id; const char* file; int line; } grpc_timer_entry; @@ -85,7 +85,7 @@ static void log_report_locked(grpc_timers_log* log) { grpc_timer_entry* entry = &(log->log[i]); fprintf(fp, "GRPC_LAT_PROF "); grpc_precise_clock_print(&entry->tm, fp); - fprintf(fp, " %s#%d,%s:%d\n", entry->tag, entry->seq, entry->file, + fprintf(fp, " %s %p %s %d\n", entry->tag, entry->id, entry->file, entry->line); } @@ -104,7 +104,7 @@ void grpc_timers_log_destroy(grpc_timers_log* log) { gpr_free(log); } -void grpc_timers_log_add(grpc_timers_log* log, const char* tag, int seq, +void grpc_timers_log_add(grpc_timers_log* log, const char* tag, void* id, const char* file, int line) { grpc_timer_entry* entry; @@ -118,7 +118,7 @@ void grpc_timers_log_add(grpc_timers_log* log, const char* tag, int seq, grpc_precise_clock_now(&entry->tm); entry->tag = tag; - entry->seq = seq; + entry->id = id; entry->file = file; entry->line = line; diff --git a/src/core/profiling/timers.h b/src/core/profiling/timers.h index ef4cad112a..1a6b9ffac9 100644 --- a/src/core/profiling/timers.h +++ b/src/core/profiling/timers.h @@ -44,15 +44,16 @@ extern "C" { typedef struct grpc_timers_log grpc_timers_log; -grpc_timers_log *grpc_timers_log_create(int capacity_limit, FILE *dump); -void grpc_timers_log_add(grpc_timers_log *, const char *tag, int seq, - const char *file, int line); +grpc_timers_log* grpc_timers_log_create(int capacity_limit, FILE* dump); +void grpc_timers_log_add(grpc_timers_log*, const char* tag, void* id, + const char* file, int line); void grpc_timers_log_destroy(grpc_timers_log *); extern grpc_timers_log *grpc_timers_log_global; #define GRPC_TIMER_MARK(x, s) \ - grpc_timers_log_add(grpc_timers_log_global, #x, s, __FILE__, __LINE__) + grpc_timers_log_add(grpc_timers_log_global, #x, ((void *)(gpr_intptr)(s)), \ + __FILE__, __LINE__) #else /* !GRPC_LATENCY_PROFILER */ #define GRPC_TIMER_MARK(x, s) \ |