envoyproxy · mattklein123 · Oct 31, 2017 · Oct 20, 2017 · Oct 30, 2017 · Oct 31, 2017
diff --git a/docs/configuration/http_filters/router_filter.rst b/docs/configuration/http_filters/router_filter.rst
@@ -13,7 +13,8 @@ redirection, the filter also handles retry, statistics, etc.
   {
     "name": "router",
     "config": {
-      "dynamic_stats": "..."
+      "dynamic_stats": "...",
+      "start_child_span": "..."
     }
   }
 
@@ -22,6 +23,13 @@ dynamic_stats
   <config_cluster_manager_cluster_stats_dynamic_http>`. Defaults to *true*. Can be disabled in high
   performance scenarios.
 
+.. _config_http_filters_router_start_child_span:
+
+start_child_span
+  *(optional, boolean)* Whether to start a child :ref:`tracing <arch_overview_tracing>` span for
+  egress routed calls. This can be useful in scenarios where other filters (auth, ratelimit, etc.)
+  make outbound calls and have child spans rooted at the same ingress parent. Defaults to *false*.
+
 .. _config_http_filters_router_headers:
 
 HTTP headers

diff --git a/docs/intro/arch_overview/tracing.rst b/docs/intro/arch_overview/tracing.rst
@@ -33,23 +33,26 @@ initiated:
 * Randomly sampled via the :ref:`random_sampling <config_http_conn_man_runtime_random_sampling>`
   runtime setting.
 
+The router filter is also capable of creating a child span for egress calls via the
+:ref:`start_child_span <config_http_filters_router_start_child_span>` option.
+
 Trace context propagation
 -------------------------
 Envoy provides the capability for reporting tracing information regarding communications between
-services in the mesh. However, to be able to correlate the pieces of tracing information generated by the
-various proxies within a call flow, the services must propagate certain trace context between the inbound
-and outbound requests.
+services in the mesh. However, to be able to correlate the pieces of tracing information generated
+by the various proxies within a call flow, the services must propagate certain trace context between
+the inbound and outbound requests.
 
 Whichever tracing provider is being used, the service should propagate the
 :ref:`config_http_conn_man_headers_x-request-id` to enable logging across the invoked services
 to be correlated.
 
 The tracing providers also require additional context, to enable the parent/child relationships
-between the spans (logical units of work) to be understood.
-This can be achieved by using the LightStep (via OpenTracing API) or Zipkin tracer directly within the service itself,
-to extract the trace context from the inbound request and inject it into any subsequent outbound requests.
-This approach would also enable the service to create additional spans, describing work being done internally
-within the service, that may be useful when examining the end-to-end trace.
+between the spans (logical units of work) to be understood. This can be achieved by using the
+LightStep (via OpenTracing API) or Zipkin tracer directly within the service itself, to extract the
+trace context from the inbound request and inject it into any subsequent outbound requests. This
+approach would also enable the service to create additional spans, describing work being done
+internally within the service, that may be useful when examining the end-to-end trace.
 
 Alternatively the trace context can be manually propagated by the service:
 
@@ -67,11 +70,10 @@ Alternatively the trace context can be manually propagated by the service:
   also possible to just propagate the
   :ref:`config_http_conn_man_headers_x-ot-span-context` HTTP header.
 
-NOTE: Work is currently underway in the distributed tracing community to define a standard
-for trace context propagation. Once a suitable approach has been adopted, the use of the non-standard
-single header :ref:`config_http_conn_man_headers_x-ot-span-context` for propagating Zipkin trace
-context will be replaced.
-
+NOTE: Work is currently underway in the distributed tracing community to define a standard for trace
+context propagation. Once a suitable approach has been adopted, the use of the non-standard single
+header :ref:`config_http_conn_man_headers_x-ot-span-context` for propagating Zipkin trace context
+will be replaced.
 
 What data each trace contains
 -----------------------------
@@ -89,14 +91,15 @@ associated with it. Each span generated by Envoy contains the following data:
 * HTTP response code.
 * Tracing system-specific metadata.
 
-The span also includes a name (or operation) which by default is defined as the host of the invoked service.
-However this can be customized using a :ref:`config_http_conn_man_route_table_decorator` on the route. The
-name can also be overridden using the :ref:`config_http_filters_router_x-envoy-decorator-operation` header.
+The span also includes a name (or operation) which by default is defined as the host of the invoked
+service. However this can be customized using a :ref:`config_http_conn_man_route_table_decorator` on
+the route. The name can also be overridden using the
+:ref:`config_http_filters_router_x-envoy-decorator-operation` header.
 
 Envoy automatically sends spans to tracing collectors. Depending on the tracing collector,
 multiple spans are stitched together using common information such as the globally unique
 request ID :ref:`config_http_conn_man_headers_x-request-id` (LightStep) or
 the trace ID :ref:`configuration <config_tracing>` (Zipkin).
 
-See tracing :ref:`configuration <config_tracing>` for more information on
-how to setup tracing in Envoy.
+See tracing :ref:`configuration <config_tracing>` for more information on how to setup tracing in
+Envoy.
diff --git a/source/common/grpc/async_client_impl.h b/source/common/grpc/async_client_impl.h
@@ -260,14 +260,8 @@ class AsyncStreamImpl : public AsyncStream<RequestType>,
   friend class AsyncClientImpl<RequestType, ResponseType>;
 };
 
-class AsyncClientTracingConfig : public Tracing::Config {
+class AsyncClientTracingConfig : public Tracing::EgressConfigImpl {
 public:
-  // Tracing::Config
-  Tracing::OperationName operationName() const override { return Tracing::OperationName::Egress; }
-  const std::vector<Http::LowerCaseString>& requestHeadersForTags() const override {
-    return request_headers_for_tags_;
-  }
-
   struct {
     const std::string STATUS = "status";
     const std::string GRPC_STATUS = "grpc.status_code";
@@ -276,9 +270,6 @@ class AsyncClientTracingConfig : public Tracing::Config {
     const std::string TRUE = "true";
     const std::string UPSTREAM_CLUSTER_NAME = "upstream_cluster_name";
   } TagStrings;
-
-private:
-  const std::vector<Http::LowerCaseString> request_headers_for_tags_;
 };
 
 typedef ConstSingleton<AsyncClientTracingConfig> TracingConfig;

diff --git a/source/common/http/async_client_impl.cc b/source/common/http/async_client_impl.cc
@@ -29,7 +29,7 @@ AsyncClientImpl::AsyncClientImpl(const Upstream::ClusterInfo& cluster, Stats::St
                                  Runtime::RandomGenerator& random,
                                  Router::ShadowWriterPtr&& shadow_writer)
     : cluster_(cluster), config_("http.async-client.", local_info, stats_store, cm, runtime, random,
-                                 std::move(shadow_writer), true),
+                                 std::move(shadow_writer), true, false),
       dispatcher_(dispatcher) {}
 
 AsyncClientImpl::~AsyncClientImpl() {

diff --git a/source/common/json/config_schemas.cc b/source/common/json/config_schemas.cc
@@ -1081,7 +1081,8 @@ const std::string Json::Schema::ROUTER_HTTP_FILTER_SCHEMA(R"EOF(
     "$schema": "http://json-schema.org/schema#",
     "type" : "object",
     "properties" : {
-      "dynamic_stats" : {"type" : "boolean"}
+      "dynamic_stats" : {"type" : "boolean"},
+      "start_child_span" : {"type" : "boolean"}
     },
     "additionalProperties" : false
   }

diff --git a/source/common/router/BUILD b/source/common/router/BUILD
@@ -154,6 +154,7 @@ envoy_cc_library(
         "//source/common/http:headers_lib",
         "//source/common/http:message_lib",
         "//source/common/http:utility_lib",
+        "//source/common/tracing:http_tracer_lib",
     ],
 )
 

diff --git a/source/common/router/router.cc b/source/common/router/router.cc
@@ -25,6 +25,7 @@
 #include "common/http/utility.h"
 #include "common/router/config_impl.h"
 #include "common/router/retry_state_impl.h"
+#include "common/tracing/http_tracer_impl.h"
 
 namespace Envoy {
 namespace Router {
@@ -736,8 +737,24 @@ void Filter::doRetry() {
   }
 }
 
+Filter::UpstreamRequest::UpstreamRequest(Filter& parent, Http::ConnectionPool::Instance& pool)
+    : parent_(parent), conn_pool_(pool), grpc_rq_success_deferred_(false),
+      calling_encode_headers_(false), upstream_canary_(false), encode_complete_(false),
+      encode_trailers_(false) {
+
+  if (parent_.config_.start_child_span_) {
+    span_ = parent_.callbacks_->activeSpan().spawnChild(
+        Tracing::EgressConfig::get(), "router " + parent.cluster_->name() + " egress",
+        ProdSystemTimeSource::instance_.currentTime());
+  }
+}
+
 Filter::UpstreamRequest::~UpstreamRequest() {
-  if (per_try_timeout_) {
+  if (span_ != nullptr) {
+    // TODO(mattklein123): Add tags based on what happened to this request (retries, reset, etc.).
+    span_->finishSpan();
+  }
+  if (per_try_timeout_ != nullptr) {
     // Allows for testing.
     per_try_timeout_->disableTimer();
   }
@@ -876,6 +893,10 @@ void Filter::UpstreamRequest::onPoolReady(Http::StreamEncoder& request_encoder,
     parent_.downstream_headers_->Host()->value(host->hostname());
   }
 
+  if (span_ != nullptr) {
+    span_->injectContext(*parent_.downstream_headers_);
+  }
+
   request_encoder.encodeHeaders(*parent_.downstream_headers_,
                                 !buffered_request_body_ && encode_complete_ && !encode_trailers_);
   calling_encode_headers_ = false;

diff --git a/source/common/router/router.h b/source/common/router/router.h
@@ -85,10 +85,11 @@ class FilterConfig {
   FilterConfig(const std::string& stat_prefix, const LocalInfo::LocalInfo& local_info,
                Stats::Scope& scope, Upstream::ClusterManager& cm, Runtime::Loader& runtime,
                Runtime::RandomGenerator& random, ShadowWriterPtr&& shadow_writer,
-               bool emit_dynamic_stats)
+               bool emit_dynamic_stats, bool start_child_span)
       : scope_(scope), local_info_(local_info), cm_(cm), runtime_(runtime),
         random_(random), stats_{ALL_ROUTER_STATS(POOL_COUNTER_PREFIX(scope, stat_prefix))},
-        emit_dynamic_stats_(emit_dynamic_stats), shadow_writer_(std::move(shadow_writer)) {}
+        emit_dynamic_stats_(emit_dynamic_stats), start_child_span_(start_child_span),
+        shadow_writer_(std::move(shadow_writer)) {}
 
   ShadowWriter& shadowWriter() { return *shadow_writer_; }
 
@@ -99,6 +100,7 @@ class FilterConfig {
   Runtime::RandomGenerator& random_;
   FilterStats stats_;
   const bool emit_dynamic_stats_;
+  const bool start_child_span_;
 
 private:
   ShadowWriterPtr shadow_writer_;
@@ -181,11 +183,7 @@ class Filter : Logger::Loggable<Logger::Id::router>,
   struct UpstreamRequest : public Http::StreamDecoder,
                            public Http::StreamCallbacks,
                            public Http::ConnectionPool::Callbacks {
-    UpstreamRequest(Filter& parent, Http::ConnectionPool::Instance& pool)
-        : parent_(parent), conn_pool_(pool), grpc_rq_success_deferred_(false),
-          calling_encode_headers_(false), upstream_canary_(false), encode_complete_(false),
-          encode_trailers_(false) {}
-
+    UpstreamRequest(Filter& parent, Http::ConnectionPool::Instance& pool);
     ~UpstreamRequest();
 
     void encodeHeaders(bool end_stream);
@@ -250,6 +248,7 @@ class Filter : Logger::Loggable<Logger::Id::router>,
     Buffer::WatermarkBufferPtr buffered_request_body_;
     Upstream::HostDescriptionConstSharedPtr upstream_host_;
     DownstreamWatermarkManager downstream_watermark_manager_{*this};
+    Tracing::SpanPtr span_;
 
     bool calling_encode_headers_ : 1;
     bool upstream_canary_ : 1;

diff --git a/source/common/tracing/http_tracer_impl.h b/source/common/tracing/http_tracer_impl.h
@@ -62,6 +62,20 @@ class HttpTracerUtility {
   static const std::string EGRESS_OPERATION;
 };
 
+class EgressConfigImpl : public Config {
+public:
+  // Tracing::Config
+  Tracing::OperationName operationName() const override { return Tracing::OperationName::Egress; }
+  const std::vector<Http::LowerCaseString>& requestHeadersForTags() const override {
+    return request_headers_for_tags_;
+  }
+
+private:
+  const std::vector<Http::LowerCaseString> request_headers_for_tags_;
+};
+
+typedef ConstSingleton<EgressConfigImpl> EgressConfig;
+
 class NullSpan : public Span {
 public:
   static NullSpan& instance() {

diff --git a/source/server/config/http/router.cc b/source/server/config/http/router.cc
@@ -21,7 +21,8 @@ HttpFilterFactoryCb RouterFilterConfig::createFilterFactory(const Json::Object&
       stat_prefix, context.localInfo(), context.scope(), context.clusterManager(),
       context.runtime(), context.random(),
       Router::ShadowWriterPtr{new Router::ShadowWriterImpl(context.clusterManager())},
-      json_config.getBoolean("dynamic_stats", true)));
+      json_config.getBoolean("dynamic_stats", true),
+      json_config.getBoolean("start_child_span", false)));
 
   return [config](Http::FilterChainFactoryCallbacks& callbacks) -> void {
     callbacks.addStreamDecoderFilter(std::make_shared<Router::ProdFilter>(*config));

diff --git a/test/common/router/router_test.cc b/test/common/router/router_test.cc
@@ -56,12 +56,12 @@ class TestFilter : public Filter {
   MockRetryState* retry_state_{};
 };
 
-class RouterTest : public testing::Test {
+class RouterTestBase : public testing::Test {
 public:
-  RouterTest()
+  RouterTestBase(bool start_child_span)
       : shadow_writer_(new MockShadowWriter()),
         config_("test.", local_info_, stats_store_, cm_, runtime_, random_,
-                ShadowWriterPtr{shadow_writer_}, true),
+                ShadowWriterPtr{shadow_writer_}, true, start_child_span),
         router_(config_) {
     router_.setDecoderFilterCallbacks(callbacks_);
     upstream_locality_.set_zone("to_az");
@@ -120,6 +120,11 @@ class RouterTest : public testing::Test {
       Network::Utility::parseInternetAddressAndPort("1.2.3.4:80")};
 };
 
+class RouterTest : public RouterTestBase {
+public:
+  RouterTest() : RouterTestBase(false) { EXPECT_CALL(callbacks_, activeSpan()).Times(0); }
+};
+
 TEST_F(RouterTest, RouteNotFound) {
   EXPECT_CALL(callbacks_.request_info_,
               setResponseFlag(Http::AccessLog::ResponseFlag::NoRouteFound));
@@ -1831,5 +1836,70 @@ TEST_F(WatermarkTest, RetryRequestNotComplete) {
   encoder1.stream_.resetStream(Http::StreamResetReason::RemoteReset);
 }
 
+class RouterTestChildSpan : public RouterTestBase {
+public:
+  RouterTestChildSpan() : RouterTestBase(true) {}
+};
+
+// Make sure child spans start/inject/finish with a normal flow.
+TEST_F(RouterTestChildSpan, BasicFlow) {
+  EXPECT_CALL(callbacks_.route_->route_entry_, timeout())
+      .WillOnce(Return(std::chrono::milliseconds(0)));
+  EXPECT_CALL(callbacks_.dispatcher_, createTimer_(_)).Times(0);
+
+  NiceMock<Http::MockStreamEncoder> encoder;
+  Http::StreamDecoder* response_decoder = nullptr;
+  Tracing::MockSpan* child_span{new Tracing::MockSpan()};
+  EXPECT_CALL(cm_.conn_pool_, newStream(_, _))
+      .WillOnce(Invoke([&](Http::StreamDecoder& decoder, Http::ConnectionPool::Callbacks& callbacks)
+                           -> Http::ConnectionPool::Cancellable* {
+        response_decoder = &decoder;
+        EXPECT_CALL(*child_span, injectContext(_));
+        callbacks.onPoolReady(encoder, cm_.conn_pool_.host_);
+        return nullptr;
+      }));
+
+  Http::TestHeaderMapImpl headers;
+  HttpTestUtility::addDefaultHeaders(headers);
+  EXPECT_CALL(callbacks_.active_span_, spawnChild_(_, "router fake_cluster egress", _))
+      .WillOnce(Return(child_span));
+  router_.decodeHeaders(headers, true);
+
+  Http::HeaderMapPtr response_headers(new Http::TestHeaderMapImpl{{":status", "200"}});
+  EXPECT_CALL(*child_span, finishSpan());
+  response_decoder->decodeHeaders(std::move(response_headers), true);
+}
+
+// Make sure child spans start/inject/finish with a reset flow.
+TEST_F(RouterTestChildSpan, ResetFlow) {
+  EXPECT_CALL(callbacks_.route_->route_entry_, timeout())
+      .WillOnce(Return(std::chrono::milliseconds(0)));
+  EXPECT_CALL(callbacks_.dispatcher_, createTimer_(_)).Times(0);
+
+  NiceMock<Http::MockStreamEncoder> encoder;
+  Http::StreamDecoder* response_decoder = nullptr;
+  Tracing::MockSpan* child_span{new Tracing::MockSpan()};
+  EXPECT_CALL(cm_.conn_pool_, newStream(_, _))
+      .WillOnce(Invoke([&](Http::StreamDecoder& decoder, Http::ConnectionPool::Callbacks& callbacks)
+                           -> Http::ConnectionPool::Cancellable* {
+        response_decoder = &decoder;
+        EXPECT_CALL(*child_span, injectContext(_));
+        callbacks.onPoolReady(encoder, cm_.conn_pool_.host_);
+        return nullptr;
+      }));
+
+  Http::TestHeaderMapImpl headers;
+  HttpTestUtility::addDefaultHeaders(headers);
+  EXPECT_CALL(callbacks_.active_span_, spawnChild_(_, "router fake_cluster egress", _))
+      .WillOnce(Return(child_span));
+  router_.decodeHeaders(headers, true);
+
+  Http::HeaderMapPtr response_headers(new Http::TestHeaderMapImpl{{":status", "200"}});
+  response_decoder->decodeHeaders(std::move(response_headers), false);
+
+  EXPECT_CALL(*child_span, finishSpan());
+  encoder.stream_.resetStream(Http::StreamResetReason::RemoteReset);
+}
+
 } // namespace Router
 } // namespace Envoy
diff --git a/test/server/config/http/config_test.cc b/test/server/config/http/config_test.cc
@@ -196,7 +196,8 @@ TEST(HttpFilterConfigTest, BadHealthCheckFilterConfig) {
 TEST(HttpFilterConfigTest, RouterFilter) {
   std::string json_string = R"EOF(
   {
-    "dynamic_stats" : true
+    "dynamic_stats" : true,
+    "start_child_span" : true
   }
   )EOF";