Skip to content

Commit

Permalink
Merge pull request grpc#3754 from ctiller/latent-see
Browse files Browse the repository at this point in the history 
Latency profiling support
  • Loading branch information
@dgquintas
dgquintas committed Oct 13, 2015
2 parents a538c40 + 494f7da commit 93cec49
Show file tree
Hide file tree
Showing 49 changed files with 715 additions and 497 deletions.
3 changes: 2 additions & 1 deletion .gitignore
View file
Original file line number Diff line number Diff line change
Expand Up @@ -37,10 +37,11 @@ cache.mk

# Temporary test reports
report.xml
latency_trace.txt

# port server log
portlog.txt

# gyp generated make files
*-gyp.mk
out
out
17 changes: 8 additions & 9 deletions BUILD
View file
Original file line number Diff line number Diff line change
Expand Up @@ -44,6 +44,7 @@ package(default_visibility = ["//visibility:public"])
cc_library(
name = "gpr",
srcs = [
"src/core/profiling/timers.h",
"src/core/support/block_annotate.h",
"src/core/support/env.h",
"src/core/support/file.h",
Expand All @@ -53,6 +54,8 @@ cc_library(
"src/core/support/string_win32.h",
"src/core/support/thd_internal.h",
"src/core/support/time_precise.h",
"src/core/profiling/basic_timers.c",
"src/core/profiling/stap_timers.c",
"src/core/support/alloc.c",
"src/core/support/cmdline.c",
"src/core/support/cpu_iphone.c",
Expand Down Expand Up @@ -88,6 +91,7 @@ cc_library(
"src/core/support/thd_win32.c",
"src/core/support/time.c",
"src/core/support/time_posix.c",
"src/core/support/time_precise.c",
"src/core/support/time_win32.c",
"src/core/support/tls_pthread.c",
],
Expand Down Expand Up @@ -217,7 +221,6 @@ cc_library(
"src/core/json/json_common.h",
"src/core/json/json_reader.h",
"src/core/json/json_writer.h",
"src/core/profiling/timers.h",
"src/core/statistics/census_interface.h",
"src/core/statistics/census_rpc_stats.h",
"src/core/surface/api_trace.h",
Expand Down Expand Up @@ -356,8 +359,6 @@ cc_library(
"src/core/json/json_reader.c",
"src/core/json/json_string.c",
"src/core/json/json_writer.c",
"src/core/profiling/basic_timers.c",
"src/core/profiling/stap_timers.c",
"src/core/surface/api_trace.c",
"src/core/surface/byte_buffer.c",
"src/core/surface/byte_buffer_queue.c",
Expand Down Expand Up @@ -504,7 +505,6 @@ cc_library(
"src/core/json/json_common.h",
"src/core/json/json_reader.h",
"src/core/json/json_writer.h",
"src/core/profiling/timers.h",
"src/core/statistics/census_interface.h",
"src/core/statistics/census_rpc_stats.h",
"src/core/surface/api_trace.h",
Expand Down Expand Up @@ -623,8 +623,6 @@ cc_library(
"src/core/json/json_reader.c",
"src/core/json/json_string.c",
"src/core/json/json_writer.c",
"src/core/profiling/basic_timers.c",
"src/core/profiling/stap_timers.c",
"src/core/surface/api_trace.c",
"src/core/surface/byte_buffer.c",
"src/core/surface/byte_buffer_queue.c",
Expand Down Expand Up @@ -962,6 +960,8 @@ cc_library(
objc_library(
name = "gpr_objc",
srcs = [
"src/core/profiling/basic_timers.c",
"src/core/profiling/stap_timers.c",
"src/core/support/alloc.c",
"src/core/support/cmdline.c",
"src/core/support/cpu_iphone.c",
Expand Down Expand Up @@ -997,6 +997,7 @@ objc_library(
"src/core/support/thd_win32.c",
"src/core/support/time.c",
"src/core/support/time_posix.c",
"src/core/support/time_precise.c",
"src/core/support/time_win32.c",
"src/core/support/tls_pthread.c",
],
Expand Down Expand Up @@ -1028,6 +1029,7 @@ objc_library(
"include/grpc/support/tls_msvc.h",
"include/grpc/support/tls_pthread.h",
"include/grpc/support/useful.h",
"src/core/profiling/timers.h",
"src/core/support/block_annotate.h",
"src/core/support/env.h",
"src/core/support/file.h",
Expand Down Expand Up @@ -1147,8 +1149,6 @@ objc_library(
"src/core/json/json_reader.c",
"src/core/json/json_string.c",
"src/core/json/json_writer.c",
"src/core/profiling/basic_timers.c",
"src/core/profiling/stap_timers.c",
"src/core/surface/api_trace.c",
"src/core/surface/byte_buffer.c",
"src/core/surface/byte_buffer_queue.c",
Expand Down Expand Up @@ -1292,7 +1292,6 @@ objc_library(
"src/core/json/json_common.h",
"src/core/json/json_reader.h",
"src/core/json/json_writer.h",
"src/core/profiling/timers.h",
"src/core/statistics/census_interface.h",
"src/core/statistics/census_rpc_stats.h",
"src/core/surface/api_trace.h",
Expand Down
7 changes: 3 additions & 4 deletions Makefile
View file
Original file line number Diff line number Diff line change
Expand Up @@ -3893,6 +3893,8 @@ clean:


LIBGPR_SRC = \
src/core/profiling/basic_timers.c \
src/core/profiling/stap_timers.c \
src/core/support/alloc.c \
src/core/support/cmdline.c \
src/core/support/cpu_iphone.c \
Expand Down Expand Up @@ -3928,6 +3930,7 @@ LIBGPR_SRC = \
src/core/support/thd_win32.c \
src/core/support/time.c \
src/core/support/time_posix.c \
src/core/support/time_precise.c \
src/core/support/time_win32.c \
src/core/support/tls_pthread.c \

Expand Down Expand Up @@ -4117,8 +4120,6 @@ LIBGRPC_SRC = \
src/core/json/json_reader.c \
src/core/json/json_string.c \
src/core/json/json_writer.c \
src/core/profiling/basic_timers.c \
src/core/profiling/stap_timers.c \
src/core/surface/api_trace.c \
src/core/surface/byte_buffer.c \
src/core/surface/byte_buffer_queue.c \
Expand Down Expand Up @@ -4399,8 +4400,6 @@ LIBGRPC_UNSECURE_SRC = \
src/core/json/json_reader.c \
src/core/json/json_string.c \
src/core/json/json_writer.c \
src/core/profiling/basic_timers.c \
src/core/profiling/stap_timers.c \
src/core/surface/api_trace.c \
src/core/surface/byte_buffer.c \
src/core/surface/byte_buffer_queue.c \
Expand Down
5 changes: 3 additions & 2 deletions binding.gyp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -64,6 +64,8 @@
'dependencies': [
],
'sources': [
'src/core/profiling/basic_timers.c',
'src/core/profiling/stap_timers.c',
'src/core/support/alloc.c',
'src/core/support/cmdline.c',
'src/core/support/cpu_iphone.c',
Expand Down Expand Up @@ -99,6 +101,7 @@
'src/core/support/thd_win32.c',
'src/core/support/time.c',
'src/core/support/time_posix.c',
'src/core/support/time_precise.c',
'src/core/support/time_win32.c',
'src/core/support/tls_pthread.c',
],
Expand Down Expand Up @@ -208,8 +211,6 @@
'src/core/json/json_reader.c',
'src/core/json/json_string.c',
'src/core/json/json_writer.c',
'src/core/profiling/basic_timers.c',
'src/core/profiling/stap_timers.c',
'src/core/surface/api_trace.c',
'src/core/surface/byte_buffer.c',
'src/core/surface/byte_buffer_queue.c',
Expand Down
7 changes: 4 additions & 3 deletions build.yaml
View file
Original file line number Diff line number Diff line change
Expand Up @@ -177,7 +177,6 @@ filegroups:
- src/core/json/json_common.h
- src/core/json/json_reader.h
- src/core/json/json_writer.h
- src/core/profiling/timers.h
- src/core/statistics/census_interface.h
- src/core/statistics/census_rpc_stats.h
- src/core/surface/api_trace.h
Expand Down Expand Up @@ -293,8 +292,6 @@ filegroups:
- src/core/json/json_reader.c
- src/core/json/json_string.c
- src/core/json/json_writer.c
- src/core/profiling/basic_timers.c
- src/core/profiling/stap_timers.c
- src/core/surface/api_trace.c
- src/core/surface/byte_buffer.c
- src/core/surface/byte_buffer_queue.c
Expand Down Expand Up @@ -393,6 +390,7 @@ libs:
- include/grpc/support/tls_pthread.h
- include/grpc/support/useful.h
headers:
- src/core/profiling/timers.h
- src/core/support/block_annotate.h
- src/core/support/env.h
- src/core/support/file.h
Expand All @@ -403,6 +401,8 @@ libs:
- src/core/support/thd_internal.h
- src/core/support/time_precise.h
src:
- src/core/profiling/basic_timers.c
- src/core/profiling/stap_timers.c
- src/core/support/alloc.c
- src/core/support/cmdline.c
- src/core/support/cpu_iphone.c
Expand Down Expand Up @@ -438,6 +438,7 @@ libs:
- src/core/support/thd_win32.c
- src/core/support/time.c
- src/core/support/time_posix.c
- src/core/support/time_precise.c
- src/core/support/time_win32.c
- src/core/support/tls_pthread.c
secure: false
Expand Down
13 changes: 7 additions & 6 deletions gRPC.podspec
View file
Original file line number Diff line number Diff line change
Expand Up @@ -63,7 +63,8 @@ Pod::Spec.new do |s|

# Core cross-platform gRPC library, written in C.
s.subspec 'C-Core' do |ss|
ss.source_files = 'src/core/support/block_annotate.h',
ss.source_files = 'src/core/profiling/timers.h',
'src/core/support/block_annotate.h',
'src/core/support/env.h',
'src/core/support/file.h',
'src/core/support/murmur_hash.h',
Expand Down Expand Up @@ -99,6 +100,8 @@ Pod::Spec.new do |s|
'grpc/support/tls_msvc.h',
'grpc/support/tls_pthread.h',
'grpc/support/useful.h',
'src/core/profiling/basic_timers.c',
'src/core/profiling/stap_timers.c',
'src/core/support/alloc.c',
'src/core/support/cmdline.c',
'src/core/support/cpu_iphone.c',
Expand Down Expand Up @@ -134,6 +137,7 @@ Pod::Spec.new do |s|
'src/core/support/thd_win32.c',
'src/core/support/time.c',
'src/core/support/time_posix.c',
'src/core/support/time_precise.c',
'src/core/support/time_win32.c',
'src/core/support/tls_pthread.c',
'src/core/security/auth_filters.h',
Expand Down Expand Up @@ -221,7 +225,6 @@ Pod::Spec.new do |s|
'src/core/json/json_common.h',
'src/core/json/json_reader.h',
'src/core/json/json_writer.h',
'src/core/profiling/timers.h',
'src/core/statistics/census_interface.h',
'src/core/statistics/census_rpc_stats.h',
'src/core/surface/api_trace.h',
Expand Down Expand Up @@ -367,8 +370,6 @@ Pod::Spec.new do |s|
'src/core/json/json_reader.c',
'src/core/json/json_string.c',
'src/core/json/json_writer.c',
'src/core/profiling/basic_timers.c',
'src/core/profiling/stap_timers.c',
'src/core/surface/api_trace.c',
'src/core/surface/byte_buffer.c',
'src/core/surface/byte_buffer_queue.c',
Expand Down Expand Up @@ -419,7 +420,8 @@ Pod::Spec.new do |s|
'src/core/census/operation.c',
'src/core/census/tracing.c'

ss.private_header_files = 'src/core/support/block_annotate.h',
ss.private_header_files = 'src/core/profiling/timers.h',
'src/core/support/block_annotate.h',
'src/core/support/env.h',
'src/core/support/file.h',
'src/core/support/murmur_hash.h',
Expand Down Expand Up @@ -513,7 +515,6 @@ Pod::Spec.new do |s|
'src/core/json/json_common.h',
'src/core/json/json_reader.h',
'src/core/json/json_writer.h',
'src/core/profiling/timers.h',
'src/core/statistics/census_interface.h',
'src/core/statistics/census_rpc_stats.h',
'src/core/surface/api_trace.h',
Expand Down
19 changes: 14 additions & 5 deletions src/core/channel/client_channel.c
View file
Original file line number Diff line number Diff line change
Expand Up @@ -36,16 +36,18 @@
#include <stdio.h>
#include <string.h>

#include <grpc/support/alloc.h>
#include <grpc/support/log.h>
#include <grpc/support/sync.h>
#include <grpc/support/useful.h>

#include "src/core/channel/channel_args.h"
#include "src/core/channel/connected_channel.h"
#include "src/core/surface/channel.h"
#include "src/core/iomgr/iomgr.h"
#include "src/core/profiling/timers.h"
#include "src/core/support/string.h"
#include "src/core/surface/channel.h"
#include "src/core/transport/connectivity_state.h"
#include <grpc/support/alloc.h>
#include <grpc/support/log.h>
#include <grpc/support/sync.h>
#include <grpc/support/useful.h>

/* Client channel implementation */

Expand Down Expand Up @@ -242,6 +244,8 @@ static void picked_target(grpc_exec_ctx *exec_ctx, void *arg,
grpc_pollset *pollset;
grpc_subchannel_call_create_status call_creation_status;

GPR_TIMER_BEGIN("picked_target", 0);

if (calld->picked_channel == NULL) {
/* treat this like a cancellation */
calld->waiting_op.cancel_with_status = GRPC_STATUS_UNAVAILABLE;
Expand All @@ -266,6 +270,8 @@ static void picked_target(grpc_exec_ctx *exec_ctx, void *arg,
}
}
}

GPR_TIMER_END("picked_target", 0);
}

static grpc_closure *merge_into_waiting_op(grpc_call_element *elem,
Expand Down Expand Up @@ -326,6 +332,7 @@ static void perform_transport_stream_op(grpc_exec_ctx *exec_ctx,
grpc_subchannel_call *subchannel_call;
grpc_lb_policy *lb_policy;
grpc_transport_stream_op op2;
GPR_TIMER_BEGIN("perform_transport_stream_op", 0);
GPR_ASSERT(elem->filter == &grpc_client_channel_filter);
GRPC_CALL_LOG_OP(GPR_INFO, elem, op);

Expand Down Expand Up @@ -437,6 +444,8 @@ static void perform_transport_stream_op(grpc_exec_ctx *exec_ctx,
}
break;
}

GPR_TIMER_END("perform_transport_stream_op", 0);
}

static void cc_start_transport_stream_op(grpc_exec_ctx *exec_ctx,
Expand Down
5 changes: 5 additions & 0 deletions src/core/channel/compress_filter.c
View file
Original file line number Diff line number Diff line change
Expand Up @@ -41,6 +41,7 @@

#include "src/core/channel/compress_filter.h"
#include "src/core/channel/channel_args.h"
#include "src/core/profiling/timers.h"
#include "src/core/compression/message_compress.h"
#include "src/core/support/string.h"

Expand Down Expand Up @@ -271,10 +272,14 @@ static void process_send_ops(grpc_call_element *elem,
static void compress_start_transport_stream_op(grpc_exec_ctx *exec_ctx,
grpc_call_element *elem,
grpc_transport_stream_op *op) {
GPR_TIMER_BEGIN("compress_start_transport_stream_op", 0);

if (op->send_ops && op->send_ops->nops > 0) {
process_send_ops(elem, op->send_ops);
}

GPR_TIMER_END("compress_start_transport_stream_op", 0);

/* pass control down the stack */
grpc_call_next_op(exec_ctx, elem, op);
}
Expand Down
1 change: 1 addition & 0 deletions src/core/channel/connected_channel.c
View file
Original file line number Diff line number Diff line change
Expand Up @@ -39,6 +39,7 @@

#include "src/core/support/string.h"
#include "src/core/transport/transport.h"
#include "src/core/profiling/timers.h"
#include <grpc/byte_buffer.h>
#include <grpc/support/alloc.h>
#include <grpc/support/log.h>
Expand Down
3 changes: 3 additions & 0 deletions src/core/channel/http_client_filter.c
View file
Original file line number Diff line number Diff line change
Expand Up @@ -36,6 +36,7 @@
#include <grpc/support/log.h>
#include <grpc/support/string_util.h>
#include "src/core/support/string.h"
#include "src/core/profiling/timers.h"

typedef struct call_data {
grpc_linked_mdelem method;
Expand Down Expand Up @@ -162,8 +163,10 @@ static void hc_mutate_op(grpc_call_element *elem,
static void hc_start_transport_op(grpc_exec_ctx *exec_ctx,
grpc_call_element *elem,
grpc_transport_stream_op *op) {
GPR_TIMER_BEGIN("hc_start_transport_op", 0);
GRPC_CALL_LOG_OP(GPR_INFO, elem, op);
hc_mutate_op(elem, op);
GPR_TIMER_END("hc_start_transport_op", 0);
grpc_call_next_op(exec_ctx, elem, op);
}

Expand Down
Loading

0 comments on commit 93cec49

Please sign in to comment.