From d47946be2aba5b4197d168d38982ac71b2494e60 Mon Sep 17 00:00:00 2001 From: murgatroid99 Date: Mon, 9 Mar 2015 14:27:07 -0700 Subject: [PATCH 1/2] Added batch GRPC_TRACE option to trace calls to grpc_call_start_batch --- Makefile | 5 + build.json | 1 + src/core/surface/call.c | 2 + src/core/surface/call.h | 9 ++ src/core/surface/call_log_batch.c | 121 ++++++++++++++++++ src/core/surface/init.c | 3 +- vsprojects/vs2013/grpc.vcxproj | 2 + vsprojects/vs2013/grpc.vcxproj.filters | 3 + vsprojects/vs2013/grpc_shared.vcxproj | 2 + vsprojects/vs2013/grpc_shared.vcxproj.filters | 3 + vsprojects/vs2013/grpc_unsecure.vcxproj | 2 + .../vs2013/grpc_unsecure.vcxproj.filters | 3 + 12 files changed, 155 insertions(+), 1 deletion(-) create mode 100644 src/core/surface/call_log_batch.c diff --git a/Makefile b/Makefile index 8c6fc3220da..242ce7915ad 100644 --- a/Makefile +++ b/Makefile @@ -2436,6 +2436,7 @@ LIBGRPC_SRC = \ src/core/surface/byte_buffer_reader.c \ src/core/surface/call.c \ src/core/surface/call_details.c \ + src/core/surface/call_log_batch.c \ src/core/surface/channel.c \ src/core/surface/channel_create.c \ src/core/surface/client.c \ @@ -2581,6 +2582,7 @@ src/core/surface/byte_buffer_queue.c: $(OPENSSL_DEP) src/core/surface/byte_buffer_reader.c: $(OPENSSL_DEP) src/core/surface/call.c: $(OPENSSL_DEP) src/core/surface/call_details.c: $(OPENSSL_DEP) +src/core/surface/call_log_batch.c: $(OPENSSL_DEP) src/core/surface/channel.c: $(OPENSSL_DEP) src/core/surface/channel_create.c: $(OPENSSL_DEP) src/core/surface/client.c: $(OPENSSL_DEP) @@ -2743,6 +2745,7 @@ $(OBJDIR)/$(CONFIG)/src/core/surface/byte_buffer_queue.o: $(OBJDIR)/$(CONFIG)/src/core/surface/byte_buffer_reader.o: $(OBJDIR)/$(CONFIG)/src/core/surface/call.o: $(OBJDIR)/$(CONFIG)/src/core/surface/call_details.o: +$(OBJDIR)/$(CONFIG)/src/core/surface/call_log_batch.o: $(OBJDIR)/$(CONFIG)/src/core/surface/channel.o: $(OBJDIR)/$(CONFIG)/src/core/surface/channel_create.o: $(OBJDIR)/$(CONFIG)/src/core/surface/client.o: @@ -2918,6 +2921,7 @@ LIBGRPC_UNSECURE_SRC = \ src/core/surface/byte_buffer_reader.c \ src/core/surface/call.c \ src/core/surface/call_details.c \ + src/core/surface/call_log_batch.c \ src/core/surface/channel.c \ src/core/surface/channel_create.c \ src/core/surface/client.c \ @@ -3056,6 +3060,7 @@ $(OBJDIR)/$(CONFIG)/src/core/surface/byte_buffer_queue.o: $(OBJDIR)/$(CONFIG)/src/core/surface/byte_buffer_reader.o: $(OBJDIR)/$(CONFIG)/src/core/surface/call.o: $(OBJDIR)/$(CONFIG)/src/core/surface/call_details.o: +$(OBJDIR)/$(CONFIG)/src/core/surface/call_log_batch.o: $(OBJDIR)/$(CONFIG)/src/core/surface/channel.o: $(OBJDIR)/$(CONFIG)/src/core/surface/channel_create.o: $(OBJDIR)/$(CONFIG)/src/core/surface/client.o: diff --git a/build.json b/build.json index c9500ebe1bd..665080107aa 100644 --- a/build.json +++ b/build.json @@ -224,6 +224,7 @@ "src/core/surface/byte_buffer_reader.c", "src/core/surface/call.c", "src/core/surface/call_details.c", + "src/core/surface/call_log_batch.c", "src/core/surface/channel.c", "src/core/surface/channel_create.c", "src/core/surface/client.c", diff --git a/src/core/surface/call.c b/src/core/surface/call.c index cfce9437940..dba63058b83 100644 --- a/src/core/surface/call.c +++ b/src/core/surface/call.c @@ -1006,6 +1006,8 @@ grpc_call_error grpc_call_start_batch(grpc_call *call, const grpc_op *ops, const grpc_op *op; grpc_ioreq *req; + GRPC_CALL_LOG_BATCH(GPR_INFO, call, ops, nops, tag); + if (nops == 0) { grpc_cq_begin_op(call->cq, call, GRPC_OP_COMPLETE); grpc_cq_end_op_complete(call->cq, tag, call, do_nothing, NULL, GRPC_OP_OK); diff --git a/src/core/surface/call.h b/src/core/surface/call.h index cb81cb52c25..06434f87ac8 100644 --- a/src/core/surface/call.h +++ b/src/core/surface/call.h @@ -119,4 +119,13 @@ grpc_call_stack *grpc_call_get_call_stack(grpc_call *call); /* Given the top call_element, get the call object. */ grpc_call *grpc_call_from_top_element(grpc_call_element *surface_element); +extern int grpc_trace_batch; + +void grpc_call_log_batch(char *file, int line, gpr_log_severity severity, + grpc_call *call, const grpc_op *ops, size_t nops, + void *tag); + +#define GRPC_CALL_LOG_BATCH(sev, call, ops, nops, tag) \ + if (grpc_trace_batch) grpc_call_log_batch(sev, call, ops, nops, tag) + #endif /* GRPC_INTERNAL_CORE_SURFACE_CALL_H */ diff --git a/src/core/surface/call_log_batch.c b/src/core/surface/call_log_batch.c new file mode 100644 index 00000000000..482957d839a --- /dev/null +++ b/src/core/surface/call_log_batch.c @@ -0,0 +1,121 @@ +/* + * + * Copyright 2015, Google Inc. + * All rights reserved. + * + * Redistribution and use in source and binary forms, with or without + * modification, are permitted provided that the following conditions are + * met: + * + * * Redistributions of source code must retain the above copyright + * notice, this list of conditions and the following disclaimer. + * * Redistributions in binary form must reproduce the above + * copyright notice, this list of conditions and the following disclaimer + * in the documentation and/or other materials provided with the + * distribution. + * * Neither the name of Google Inc. nor the names of its + * contributors may be used to endorse or promote products derived from + * this software without specific prior written permission. + * + * THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS + * "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT + * LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR + * A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT + * OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, + * SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT + * LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, + * DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY + * THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT + * (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE + * OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE. + * + */ + +#include "src/core/surface/call.h" + +#include "src/core/support/string.h" +#include + +int grpc_trace_batch = 0; + +static void add_metadata(gpr_strvec *b, const grpc_metadata *md, size_t count) { + size_t i; + for(i = 0; i < count; i++) { + gpr_strvec_add(b, gpr_strdup("\nkey=")); + gpr_strvec_add(b, gpr_strdup(md[i].key)); + + gpr_strvec_add(b, gpr_strdup(" value=")); + gpr_strvec_add(b, gpr_hexdump(md[i].value, md[i].value_length, + GPR_HEXDUMP_PLAINTEXT)); + } +} + +char *grpc_op_string(const grpc_op *op) { + char *tmp; + char *out; + + gpr_strvec b; + gpr_strvec_init(&b); + + switch (op->op) { + case GRPC_OP_SEND_INITIAL_METADATA: + gpr_strvec_add(&b, gpr_strdup("SEND_INITIAL_METADATA")); + add_metadata(&b, op->data.send_initial_metadata.metadata, + op->data.send_initial_metadata.count); + break; + case GRPC_OP_SEND_MESSAGE: + gpr_asprintf(&tmp, "SEND_MESSAGE ptr=%p", op->data.send_message); + gpr_strvec_add(&b, tmp); + break; + case GRPC_OP_SEND_CLOSE_FROM_CLIENT: + gpr_strvec_add(&b, gpr_strdup("SEND_CLOSE_FROM_CLIENT")); + break; + case GRPC_OP_SEND_STATUS_FROM_SERVER: + gpr_asprintf(&tmp, "SEND_STATUS_FROM_SERVER status=%d details=%s", + op->data.send_status_from_server.status, + op->data.send_status_from_server.status_details); + gpr_strvec_add(&b, tmp); + add_metadata(&b, op->data.send_status_from_server.trailing_metadata, + op->data.send_status_from_server.trailing_metadata_count); + break; + case GRPC_OP_RECV_INITIAL_METADATA: + gpr_asprintf(&tmp, "RECV_INITIAL_METADATA ptr=%p", + op->data.recv_initial_metadata); + gpr_strvec_add(&b, tmp); + break; + case GRPC_OP_RECV_MESSAGE: + gpr_asprintf(&tmp, "RECV_MESSAGE ptr=%p", op->data.recv_message); + gpr_strvec_add(&b, tmp); + break; + case GRPC_OP_RECV_STATUS_ON_CLIENT: + gpr_asprintf(&tmp, + "RECV_STATUS_ON_CLIENT metadata=%p status=%p details=%p", + op->data.recv_status_on_client.trailing_metadata, + op->data.recv_status_on_client.status, + op->data.recv_status_on_client.status_details); + gpr_strvec_add(&b, tmp); + break; + case GRPC_OP_RECV_CLOSE_ON_SERVER: + gpr_asprintf(&tmp, "RECV_CLOSE_ON_SERVER cancelled=%p", + op->data.recv_close_on_server.cancelled); + gpr_strvec_add(&b, tmp); + } + out = gpr_strvec_flatten(&b, NULL); + gpr_strvec_destroy(&b); + + return out; +} + +void grpc_call_log_batch(char *file, int line, gpr_log_severity severity, + grpc_call *call, const grpc_op *ops, size_t nops, + void *tag) { + char *tmp; + size_t i; + gpr_log(file, line, severity, + "grpc_call_start_batch(%p, %p, %d, 0x%x)", call, ops, nops); + for(i = 0; i < nops; i++) { + tmp = grpc_op_string(&ops[i]); + gpr_log(file, line, severity, "ops[%d]: %s", i, tmp); + gpr_free(tmp); + } +} diff --git a/src/core/surface/init.c b/src/core/surface/init.c index e48c4202e58..d4f0eb40e8e 100644 --- a/src/core/surface/init.c +++ b/src/core/surface/init.c @@ -36,6 +36,7 @@ #include "src/core/debug/trace.h" #include "src/core/statistics/census_interface.h" #include "src/core/channel/channel_stack.h" +#include "src/core/surface/call.h" #include "src/core/surface/init.h" #include "src/core/surface/surface_trace.h" #include "src/core/transport/chttp2_transport.h" @@ -57,6 +58,7 @@ void grpc_init(void) { grpc_register_tracer("channel", &grpc_trace_channel); grpc_register_tracer("surface", &grpc_surface_trace); grpc_register_tracer("http", &grpc_http_trace); + grpc_register_tracer("batch", &grpc_trace_batch); grpc_security_pre_init(); grpc_tracer_init("GRPC_TRACE"); grpc_iomgr_init(); @@ -82,4 +84,3 @@ int grpc_is_initialized(void) { gpr_mu_unlock(&g_init_mu); return r; } - diff --git a/vsprojects/vs2013/grpc.vcxproj b/vsprojects/vs2013/grpc.vcxproj index 9d0bcb32716..d5079d6161c 100644 --- a/vsprojects/vs2013/grpc.vcxproj +++ b/vsprojects/vs2013/grpc.vcxproj @@ -355,6 +355,8 @@ + + diff --git a/vsprojects/vs2013/grpc.vcxproj.filters b/vsprojects/vs2013/grpc.vcxproj.filters index af38d8de35a..bb91b710380 100644 --- a/vsprojects/vs2013/grpc.vcxproj.filters +++ b/vsprojects/vs2013/grpc.vcxproj.filters @@ -253,6 +253,9 @@ src\core\surface + + src\core\surface + src\core\surface diff --git a/vsprojects/vs2013/grpc_shared.vcxproj b/vsprojects/vs2013/grpc_shared.vcxproj index f5575dc3f12..f81539ed559 100644 --- a/vsprojects/vs2013/grpc_shared.vcxproj +++ b/vsprojects/vs2013/grpc_shared.vcxproj @@ -359,6 +359,8 @@ + + diff --git a/vsprojects/vs2013/grpc_shared.vcxproj.filters b/vsprojects/vs2013/grpc_shared.vcxproj.filters index af38d8de35a..bb91b710380 100644 --- a/vsprojects/vs2013/grpc_shared.vcxproj.filters +++ b/vsprojects/vs2013/grpc_shared.vcxproj.filters @@ -253,6 +253,9 @@ src\core\surface + + src\core\surface + src\core\surface diff --git a/vsprojects/vs2013/grpc_unsecure.vcxproj b/vsprojects/vs2013/grpc_unsecure.vcxproj index ad7bf4762f5..ddf69827477 100644 --- a/vsprojects/vs2013/grpc_unsecure.vcxproj +++ b/vsprojects/vs2013/grpc_unsecure.vcxproj @@ -300,6 +300,8 @@ + + diff --git a/vsprojects/vs2013/grpc_unsecure.vcxproj.filters b/vsprojects/vs2013/grpc_unsecure.vcxproj.filters index 205942a4509..38c7109ae3d 100644 --- a/vsprojects/vs2013/grpc_unsecure.vcxproj.filters +++ b/vsprojects/vs2013/grpc_unsecure.vcxproj.filters @@ -193,6 +193,9 @@ src\core\surface + + src\core\surface + src\core\surface From dc9faa343080fe47bc60b3078cad9b42121b182d Mon Sep 17 00:00:00 2001 From: murgatroid99 Date: Mon, 9 Mar 2015 14:41:41 -0700 Subject: [PATCH 2/2] Added missing log argument --- src/core/surface/call_log_batch.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/core/surface/call_log_batch.c b/src/core/surface/call_log_batch.c index 482957d839a..a33583a12d1 100644 --- a/src/core/surface/call_log_batch.c +++ b/src/core/surface/call_log_batch.c @@ -112,7 +112,7 @@ void grpc_call_log_batch(char *file, int line, gpr_log_severity severity, char *tmp; size_t i; gpr_log(file, line, severity, - "grpc_call_start_batch(%p, %p, %d, 0x%x)", call, ops, nops); + "grpc_call_start_batch(%p, %p, %d, 0x%x)", call, ops, nops, tag); for(i = 0; i < nops; i++) { tmp = grpc_op_string(&ops[i]); gpr_log(file, line, severity, "ops[%d]: %s", i, tmp);