Merge pull request #768 from ctiller/http

Add HTTP2 header tracing

src/core/debug/trace.c

@@ -81,6 +81,8 @@ static void parse(const char *s) {
       grpc_trace_bits |= GRPC_TRACE_TCP;
     } else if (0 == strcmp(s, "secure_endpoint")) {
       grpc_trace_bits |= GRPC_TRACE_SECURE_ENDPOINT;
+    } else if (0 == strcmp(s, "http")) {
+      grpc_trace_bits |= GRPC_TRACE_HTTP;
     } else if (0 == strcmp(s, "all")) {
       grpc_trace_bits = -1;
     } else {

src/core/debug/trace.h

@@ -45,7 +45,8 @@ typedef enum {
   GRPC_TRACE_SURFACE = 1 << 0,
   GRPC_TRACE_CHANNEL = 1 << 1,
   GRPC_TRACE_TCP = 1 << 2,
-  GRPC_TRACE_SECURE_ENDPOINT = 1 << 3
+  GRPC_TRACE_SECURE_ENDPOINT = 1 << 3,
+  GRPC_TRACE_HTTP = 1 << 4
 } grpc_trace_bit_value;
 
 #if GRPC_ENABLE_TRACING

src/core/transport/chttp2/frame_settings.c

@@ -35,6 +35,7 @@
 
 #include <string.h>
 
+#include "src/core/debug/trace.h"
 #include "src/core/transport/chttp2/frame.h"
 #include <grpc/support/log.h>
 #include <grpc/support/useful.h>
@@ -53,7 +54,8 @@ const grpc_chttp2_setting_parameters
         {"MAX_FRAME_SIZE", 16384, 16384, 16777215,
          GRPC_CHTTP2_DISCONNECT_ON_INVALID_VALUE},
         {"MAX_HEADER_LIST_SIZE", 0xffffffffu, 0, 0xffffffffu,
-         GRPC_CHTTP2_CLAMP_INVALID_VALUE}, };
+         GRPC_CHTTP2_CLAMP_INVALID_VALUE},
+};
 
 static gpr_uint8 *fill_header(gpr_uint8 *out, gpr_uint32 length,
                               gpr_uint8 flags) {
@@ -155,7 +157,7 @@ grpc_chttp2_parse_error grpc_chttp2_settings_parser_parse(
           }
           return GRPC_CHTTP2_PARSE_OK;
         }
-        parser->id = ((gpr_uint16) * cur) << 8;
+        parser->id = ((gpr_uint16)*cur) << 8;
         cur++;
       /* fallthrough */
       case GRPC_CHTTP2_SPS_ID1:
@@ -171,7 +173,7 @@ grpc_chttp2_parse_error grpc_chttp2_settings_parser_parse(
           parser->state = GRPC_CHTTP2_SPS_VAL0;
           return GRPC_CHTTP2_PARSE_OK;
         }
-        parser->value = ((gpr_uint32) * cur) << 24;
+        parser->value = ((gpr_uint32)*cur) << 24;
         cur++;
       /* fallthrough */
       case GRPC_CHTTP2_SPS_VAL1:
@@ -179,7 +181,7 @@ grpc_chttp2_parse_error grpc_chttp2_settings_parser_parse(
           parser->state = GRPC_CHTTP2_SPS_VAL1;
           return GRPC_CHTTP2_PARSE_OK;
         }
-        parser->value |= ((gpr_uint32) * cur) << 16;
+        parser->value |= ((gpr_uint32)*cur) << 16;
         cur++;
       /* fallthrough */
       case GRPC_CHTTP2_SPS_VAL2:
@@ -187,7 +189,7 @@ grpc_chttp2_parse_error grpc_chttp2_settings_parser_parse(
           parser->state = GRPC_CHTTP2_SPS_VAL2;
           return GRPC_CHTTP2_PARSE_OK;
         }
-        parser->value |= ((gpr_uint32) * cur) << 8;
+        parser->value |= ((gpr_uint32)*cur) << 8;
         cur++;
       /* fallthrough */
       case GRPC_CHTTP2_SPS_VAL3:
@@ -216,8 +218,10 @@ grpc_chttp2_parse_error grpc_chttp2_settings_parser_parse(
             }
           }
           parser->incoming_settings[parser->id] = parser->value;
-          gpr_log(GPR_DEBUG, "CHTTP2: got setting %d = %d", parser->id,
-                  parser->value);
+          if (grpc_trace_bits & GRPC_TRACE_HTTP) {
+            gpr_log(GPR_DEBUG, "CHTTP2: got setting %d = %d", parser->id,
+                    parser->value);
+          }
         } else {
           gpr_log(GPR_ERROR, "CHTTP2: Ignoring unknown setting %d (value %d)",
                   parser->id, parser->value);

src/core/transport/chttp2_transport.c

@@ -37,6 +37,7 @@
 #include <stdio.h>
 #include <string.h>
 
+#include "src/core/debug/trace.h"
 #include "src/core/support/string.h"
 #include "src/core/transport/chttp2/frame_data.h"
 #include "src/core/transport/chttp2/frame_goaway.h"
@@ -66,6 +67,12 @@
 typedef struct transport transport;
 typedef struct stream stream;
 
+#define IF_TRACING(stmt)                    \
+  if (!(grpc_trace_bits & GRPC_TRACE_HTTP)) \
+    ;                                       \
+  else                                      \
+  stmt
+
 /* streams are kept in various linked lists depending on what things need to
    happen to them... this enum labels each list */
 typedef enum {
@@ -552,7 +559,7 @@ static int init_stream(grpc_transport *gt, grpc_stream *gs,
     lock(t);
     s->id = 0;
   } else {
-    s->id = (gpr_uint32)(gpr_uintptr)server_data;
+    s->id = (gpr_uint32)(gpr_uintptr) server_data;
     t->incoming_stream = s;
     grpc_chttp2_stream_map_add(&t->stream_map, s->id, s);
   }
@@ -1206,6 +1213,11 @@ static void on_header(void *tp, grpc_mdelem *md) {
   stream *s = t->incoming_stream;
 
   GPR_ASSERT(s);
+
+  IF_TRACING(gpr_log(GPR_INFO, "HTTP:%d:HDR: %s: %s", s->id,
+                     grpc_mdstr_as_c_string(md->key),
+                     grpc_mdstr_as_c_string(md->value)));
+
   stream_list_join(t, s, PENDING_CALLBACKS);
   if (md->key == t->str_grpc_timeout) {
     gpr_timespec *cached_timeout = grpc_mdelem_get_user_data(md, free_timeout);
@@ -1269,7 +1281,7 @@ static int init_header_frame_parser(transport *t, int is_continuation) {
     t->incoming_stream = NULL;
     /* if stream is accepted, we set incoming_stream in init_stream */
     t->cb->accept_stream(t->cb_user_data, &t->base,
-                         (void *)(gpr_uintptr)t->incoming_stream_id);
+                         (void *)(gpr_uintptr) t->incoming_stream_id);
     s = t->incoming_stream;
     if (!s) {
       gpr_log(GPR_ERROR, "stream not accepted");
@@ -1534,8 +1546,8 @@ static int process_read(transport *t, gpr_slice slice) {
                   "Connect string mismatch: expected '%c' (%d) got '%c' (%d) "
                   "at byte %d",
                   CLIENT_CONNECT_STRING[t->deframe_state],
-                  (int)(gpr_uint8)CLIENT_CONNECT_STRING[t->deframe_state], *cur,
-                  (int)*cur, t->deframe_state);
+                  (int)(gpr_uint8) CLIENT_CONNECT_STRING[t->deframe_state],
+                  *cur, (int)*cur, t->deframe_state);
           drop_connection(t);
           return 0;
         }
@@ -1765,9 +1777,9 @@ static void add_to_pollset(grpc_transport *gt, grpc_pollset *pollset) {
  */
 
 static const grpc_transport_vtable vtable = {
-    sizeof(stream), init_stream, send_batch, set_allow_window_updates,
-    add_to_pollset, destroy_stream, abort_stream, goaway, close_transport,
-    send_ping, destroy_transport};
+    sizeof(stream),  init_stream,    send_batch,       set_allow_window_updates,
+    add_to_pollset,  destroy_stream, abort_stream,     goaway,
+    close_transport, send_ping,      destroy_transport};
 
 void grpc_create_chttp2_transport(grpc_transport_setup_callback setup,
                                   void *arg,