Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

tracing: Enable decorated operation in outbound (egress) listener to … #1858

Merged
merged 10 commits into from
Oct 18, 2017
1 change: 1 addition & 0 deletions docs/configuration/http_conn_man/header_sanitizing.rst
Original file line number Diff line number Diff line change
Expand Up @@ -12,6 +12,7 @@ depends on the :ref:`use_remote_address <config_http_conn_man_use_remote_address

Envoy will potentially sanitize the following headers:

* :ref:`x-envoy-decorator-operation <config_http_filters_router_x-envoy-decorator-operation>`
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think this needs to be implemented? (Remove header on external requests, need to add test for that also in conn_manager_utility)

* :ref:`x-envoy-downstream-service-cluster
<config_http_conn_man_headers_downstream-service-cluster>`
* :ref:`x-envoy-downstream-service-node <config_http_conn_man_headers_downstream-service-node>`
Expand Down
4 changes: 3 additions & 1 deletion docs/configuration/http_conn_man/route_config/route.rst
Original file line number Diff line number Diff line change
Expand Up @@ -450,7 +450,9 @@ Specifies the route's decorator.

operation
*(required, string)* The operation name associated with the request matched to this route. If tracing is
enabled, this information will be used as the span name reported for this request.
enabled, this information will be used as the span name reported for this request. NOTE: For ingress
(inbound) requests this value may be overridden by the
:ref:`x-envoy-decorator-operation <config_http_filters_router_x-envoy-decorator-operation>` request header.

.. _config_http_conn_man_route_table_route_add_req_headers:

Expand Down
8 changes: 8 additions & 0 deletions docs/configuration/http_filters/router_filter.rst
Original file line number Diff line number Diff line change
Expand Up @@ -236,6 +236,14 @@ if a request was dropped due to either :ref:`maintenance mode
<config_http_filters_router_runtime_maintenance_mode>` or upstream :ref:`circuit breaking
<arch_overview_circuit_break>`.

.. _config_http_filters_router_x-envoy-decorator-operation:

x-envoy-decorator-operation
^^^^^^^^^^^^^^^^^^^^^^^^^^^

If this header is present on ingress requests, its value will override any locally defined
operation (span) name on the server span generated by the tracing mechanism.

.. _config_http_filters_router_stats:

Statistics
Expand Down
4 changes: 3 additions & 1 deletion docs/intro/arch_overview/tracing.rst
Original file line number Diff line number Diff line change
Expand Up @@ -90,7 +90,9 @@ associated with it. Each span generated by Envoy contains the following data:
* 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.
However this can be customized using a :ref:`config_http_conn_man_route_table_decorator` on the route. The
name used for the server (ingress) span 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
Expand Down
1 change: 1 addition & 0 deletions include/envoy/http/header_map.h
Original file line number Diff line number Diff line change
Expand Up @@ -215,6 +215,7 @@ class HeaderEntry {
HEADER_FUNC(ContentLength) \
HEADER_FUNC(ContentType) \
HEADER_FUNC(Date) \
HEADER_FUNC(EnvoyDecoratorOperation) \
HEADER_FUNC(EnvoyDownstreamServiceCluster) \
HEADER_FUNC(EnvoyDownstreamServiceNode) \
HEADER_FUNC(EnvoyExpectedRequestTimeoutMs) \
Expand Down
6 changes: 6 additions & 0 deletions include/envoy/router/router.h
Original file line number Diff line number Diff line change
Expand Up @@ -370,6 +370,12 @@ class Decorator {
* @param Tracing::Span& the span.
*/
virtual void apply(Tracing::Span& span) const PURE;

/**
* This method returns the operation name.
* @return the operation name
*/
virtual const std::string& getOperation() const PURE;
};

typedef std::unique_ptr<const Decorator> DecoratorConstPtr;
Expand Down
56 changes: 44 additions & 12 deletions source/common/http/conn_manager_impl.cc
Original file line number Diff line number Diff line change
Expand Up @@ -502,6 +502,11 @@ void ConnectionManagerImpl::ActiveStream::decodeHeaders(HeaderMapPtr&& headers,
state_.saw_connection_close_ = true;
}

std::string decorator_operation;
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Instead of allocating a string here on the stack, it would be faster to just pass the pointer value of the header entry into the trace function as you did before. Any reason to switch it?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I got a core dump when running the coverage tests - although strangely not when doing the bazel.dev build which also runs the tests. The problem seems to be caused by the header entry being removed/unallocated.

[----------] 38 tests from HttpConnectionManagerImplTest
[ RUN ] HttpConnectionManagerImplTest.HeaderOnlyRequestAndResponse
[ OK ] HttpConnectionManagerImplTest.HeaderOnlyRequestAndResponse (2 ms)
[ RUN ] HttpConnectionManagerImplTest.InvalidPathWithDualFilter
[ OK ] HttpConnectionManagerImplTest.InvalidPathWithDualFilter (1 ms)
[ RUN ] HttpConnectionManagerImplTest.StartAndFinishSpanNormalFlow
pure virtual method called
terminate called without an active exception
[2017-10-17 19:29:59.086][2295][critical][backtrace] bazel-out/local-dbg/bin/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:101] Caught Aborted, suspect faulting address 0x3e8000008f7
[2017-10-17 19:29:59.086][2295][critical][backtrace] bazel-out/local-dbg/bin/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:85] Backtrace obj</lib/x86_64-linux-gnu/libc.so.6> thr<0> (use tools/stack_decode.py):
[2017-10-17 19:29:59.086][2295][critical][backtrace] bazel-out/local-dbg/bin/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:95] thr<0> #0 0x7f26ff0d0428
[2017-10-17 19:29:59.086][2295][critical][backtrace] bazel-out/local-dbg/bin/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:95] thr<0> #1 0x7f26ff0d2029
[2017-10-17 19:29:59.086][2295][critical][backtrace] bazel-out/local-dbg/bin/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:93] thr<0> obj</usr/lib/x86_64-linux-gnu/libstdc++.so.6>

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Can you put the code back? If it fails I can help you figure out what the issue is.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done

if (request_headers_->EnvoyDecoratorOperation()) {
decorator_operation = request_headers_->EnvoyDecoratorOperation()->value().c_str();
}

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

so, there is some work going on in Istio to be able to decode a request using swagger spec/openapi spec.. And if that is the case, one might want to set the operation name based on the API spec. Would it make sense to have an interface for a filter to overwrite the operation name, in addition to the inbound header name doing the full override?

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think that makes sense, but let's track in a separate issue?

ConnectionManagerUtility::mutateRequestHeaders(
*request_headers_, protocol, connection_manager_.read_callbacks_->connection(),
connection_manager_.config_, *snapped_route_config_, connection_manager_.random_generator_,
Expand Down Expand Up @@ -541,25 +546,52 @@ void ConnectionManagerImpl::ActiveStream::decodeHeaders(HeaderMapPtr&& headers,

// Check if tracing is enabled at all.
if (connection_manager_.config_.tracingConfig()) {
Tracing::Decision tracing_decision =
Tracing::HttpTracerUtility::isTracing(request_info_, *request_headers_);
ConnectionManagerImpl::chargeTracingStats(tracing_decision.reason,
connection_manager_.config_.tracingStats());

if (tracing_decision.is_tracing) {
active_span_ = connection_manager_.tracer_.startSpan(*this, *request_headers_, request_info_);
if (cached_route_.value() && cached_route_.value()->decorator()) {
cached_route_.value()->decorator()->apply(*active_span_);
}
active_span_->injectContext(*request_headers_);
}
traceRequest(decorator_operation);
}

// Set the trusted address for the connection by taking the last address in XFF.
request_info_.downstream_address_ = Utility::getLastAddressFromXFF(*request_headers_);
decodeHeaders(nullptr, *request_headers_, end_stream);
}

void ConnectionManagerImpl::ActiveStream::traceRequest(const std::string& decorator_operation) {
Tracing::Decision tracing_decision =
Tracing::HttpTracerUtility::isTracing(request_info_, *request_headers_);
ConnectionManagerImpl::chargeTracingStats(tracing_decision.reason,
connection_manager_.config_.tracingStats());

if (!tracing_decision.is_tracing) {
return;
}

active_span_ = connection_manager_.tracer_.startSpan(*this, *request_headers_, request_info_);

// If a decorator has been defined, apply it to the active span
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

super nit: please end sentences with '.'. Here and below.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

should be sorted.

if (cached_route_.value() && cached_route_.value()->decorator()) {
cached_route_.value()->decorator()->apply(*active_span_);

// For egress (outbound) requests, pass the decorator's operation name (if defined)
// as a request header to enable the receiving service to use it in its server span
if (connection_manager_.config_.tracingConfig()->operation_name_ ==
Tracing::OperationName::Egress &&
!cached_route_.value()->decorator()->getOperation().empty()) {
request_headers_->insertEnvoyDecoratorOperation().value(
cached_route_.value()->decorator()->getOperation());
}
}

// For igress (inbound) requests, if a decorator operation name has been provided, it
// should be used to override the active span's operation
if (!decorator_operation.empty() &&
connection_manager_.config_.tracingConfig()->operation_name_ ==
Tracing::OperationName::Ingress) {
active_span_->setOperation(decorator_operation.c_str());
}

// Inject the active span's tracing context into the request headers
active_span_->injectContext(*request_headers_);
}

void ConnectionManagerImpl::ActiveStream::decodeHeaders(ActiveStreamDecoderFilter* filter,
HeaderMap& headers, bool end_stream) {
std::list<ActiveStreamDecoderFilterPtr>::iterator entry;
Expand Down
2 changes: 2 additions & 0 deletions source/common/http/conn_manager_impl.h
Original file line number Diff line number Diff line change
Expand Up @@ -520,6 +520,8 @@ class ConnectionManagerImpl : Logger::Loggable<Logger::Id::http>,
virtual Tracing::OperationName operationName() const override;
virtual const std::vector<Http::LowerCaseString>& requestHeadersForTags() const override;

void traceRequest(const std::string& decorator_operation);

// Pass on watermark callbacks to watermark subscribers. This boils down to passing watermark
// events for this stream and the downstream connection to the router filter.
void callHighWatermarkCallbacks();
Expand Down
1 change: 1 addition & 0 deletions source/common/http/conn_manager_utility.cc
Original file line number Diff line number Diff line change
Expand Up @@ -93,6 +93,7 @@ void ConnectionManagerUtility::mutateRequestHeaders(
request_headers.removeEnvoyUpstreamRequestTimeoutAltResponse();
request_headers.removeEnvoyExpectedRequestTimeoutMs();
request_headers.removeEnvoyForceTrace();
request_headers.removeEnvoyDecoratorOperation();

for (const Http::LowerCaseString& header : route_config.internalOnlyHeaders()) {
request_headers.remove(header);
Expand Down
1 change: 1 addition & 0 deletions source/common/http/headers.h
Original file line number Diff line number Diff line change
Expand Up @@ -51,6 +51,7 @@ class HeaderValues {
const LowerCaseString EnvoyExpectedRequestTimeoutMs{"x-envoy-expected-rq-timeout-ms"};
const LowerCaseString EnvoyUpstreamServiceTime{"x-envoy-upstream-service-time"};
const LowerCaseString EnvoyUpstreamHealthCheckedCluster{"x-envoy-upstream-healthchecked-cluster"};
const LowerCaseString EnvoyDecoratorOperation{"x-envoy-decorator-operation"};
const LowerCaseString Expect{"expect"};
const LowerCaseString ForwardedClientCert{"x-forwarded-client-cert"};
const LowerCaseString ForwardedFor{"x-forwarded-for"};
Expand Down
2 changes: 2 additions & 0 deletions source/common/router/config_impl.cc
Original file line number Diff line number Diff line change
Expand Up @@ -183,6 +183,8 @@ void DecoratorImpl::apply(Tracing::Span& span) const {
}
}

const std::string& DecoratorImpl::getOperation() const { return operation_; }

const uint64_t RouteEntryImplBase::WeightedClusterEntry::MAX_CLUSTER_WEIGHT = 100UL;

RouteEntryImplBase::RouteEntryImplBase(const VirtualHostImpl& vhost,
Expand Down
3 changes: 3 additions & 0 deletions source/common/router/config_impl.h
Original file line number Diff line number Diff line change
Expand Up @@ -273,6 +273,9 @@ class DecoratorImpl : public Decorator {
// Decorator::apply
void apply(Tracing::Span& span) const override;

// Decorator::getOperation
const std::string& getOperation() const override;

private:
const std::string operation_;
};
Expand Down
71 changes: 71 additions & 0 deletions test/common/http/conn_manager_impl_test.cc
Original file line number Diff line number Diff line change
Expand Up @@ -395,6 +395,70 @@ TEST_F(HttpConnectionManagerImplTest, StartAndFinishSpanNormalFlow) {
EXPECT_CALL(*span, setTag(":method", "GET"));
// Verify if the activeSpan interface returns reference to the current span.
EXPECT_CALL(*span, setTag("service-cluster", "scoobydoo"));
EXPECT_CALL(runtime_.snapshot_, featureEnabled("tracing.global_enabled", 100, _))
.WillOnce(Return(true));
EXPECT_CALL(*span, setOperation("testOp"));

std::shared_ptr<MockStreamDecoderFilter> filter(new NiceMock<MockStreamDecoderFilter>());

EXPECT_CALL(filter_factory_, createFilterChain(_))
.WillRepeatedly(Invoke([&](FilterChainFactoryCallbacks& callbacks) -> void {
callbacks.addStreamDecoderFilter(filter);
}));

// Treat request as internal, otherwise x-request-id header will be overwritten.
use_remote_address_ = false;
EXPECT_CALL(random_, uuid()).Times(0);

StreamDecoder* decoder = nullptr;
NiceMock<MockStreamEncoder> encoder;
EXPECT_CALL(*codec_, dispatch(_)).WillRepeatedly(Invoke([&](Buffer::Instance& data) -> void {
decoder = &conn_manager_->newStream(encoder);

HeaderMapPtr headers{
new TestHeaderMapImpl{{":method", "GET"},
{":authority", "host"},
{":path", "/"},
{"x-request-id", "125a4afb-6f55-a4ba-ad80-413f09f48a28"},
{"x-envoy-decorator-operation", "testOp"}}};
decoder->decodeHeaders(std::move(headers), true);

HeaderMapPtr response_headers{new TestHeaderMapImpl{{":status", "200"}}};
filter->callbacks_->encodeHeaders(std::move(response_headers), true);
filter->callbacks_->activeSpan().setTag("service-cluster", "scoobydoo");

data.drain(4);
}));

Buffer::OwnedImpl fake_input("1234");
conn_manager_->onData(fake_input);

EXPECT_EQ(1UL, tracing_stats_.service_forced_.value());
EXPECT_EQ(0UL, tracing_stats_.random_sampling_.value());
}

TEST_F(HttpConnectionManagerImplTest, StartAndFinishSpanNormalFlowEgress) {
setup(false, "");
tracing_config_.reset(new TracingConnectionManagerConfig(
{Tracing::OperationName::Egress, {LowerCaseString(":method")}}));

NiceMock<Tracing::MockSpan>* span = new NiceMock<Tracing::MockSpan>();
EXPECT_CALL(tracer_, startSpan_(_, _, _))
.WillOnce(Invoke([&](const Tracing::Config& config, const HeaderMap&,
const AccessLog::RequestInfo&) -> Tracing::Span* {
EXPECT_EQ(Tracing::OperationName::Egress, config.operationName());

return span;
}));
route_config_provider_.route_config_->route_->decorator_.operation_ = "testOp";
EXPECT_CALL(*route_config_provider_.route_config_->route_, decorator()).Times(4);
EXPECT_CALL(route_config_provider_.route_config_->route_->decorator_, apply(_))
.WillOnce(
Invoke([&](const Tracing::Span& applyToSpan) -> void { EXPECT_EQ(span, &applyToSpan); }));
EXPECT_CALL(*span, finishSpan(_))
.WillOnce(
Invoke([span](Tracing::SpanFinalizer& finalizer) -> void { finalizer.finalize(*span); }));
EXPECT_CALL(*span, setTag(_, _)).Times(testing::AnyNumber());
EXPECT_CALL(runtime_.snapshot_, featureEnabled("tracing.global_enabled", 100, _))
.WillOnce(Return(true));

Expand Down Expand Up @@ -428,6 +492,13 @@ TEST_F(HttpConnectionManagerImplTest, StartAndFinishSpanNormalFlow) {
data.drain(4);
}));

EXPECT_CALL(*filter, decodeHeaders(_, true))
.WillOnce(Invoke([](HeaderMap& headers, bool) -> FilterHeadersStatus {
EXPECT_NE(nullptr, headers.EnvoyDecoratorOperation());
EXPECT_STREQ("testOp", headers.EnvoyDecoratorOperation()->value().c_str());
return FilterHeadersStatus::StopIteration;
}));

Buffer::OwnedImpl fake_input("1234");
conn_manager_->onData(fake_input);

Expand Down
4 changes: 3 additions & 1 deletion test/common/http/conn_manager_utility_test.cc
Original file line number Diff line number Diff line change
Expand Up @@ -324,7 +324,8 @@ TEST_F(ConnectionManagerUtilityTest, ExternalAddressExternalRequestUseRemote) {

route_config_.internal_only_headers_.push_back(LowerCaseString("custom_header"));

TestHeaderMapImpl headers{{"x-envoy-downstream-service-cluster", "foo"},
TestHeaderMapImpl headers{{"x-envoy-decorator-operation", "foo"},
{"x-envoy-downstream-service-cluster", "foo"},
{"x-envoy-retry-on", "foo"},
{"x-envoy-retry-grpc-on", "foo"},
{"x-envoy-max-retries", "foo"},
Expand All @@ -337,6 +338,7 @@ TEST_F(ConnectionManagerUtilityTest, ExternalAddressExternalRequestUseRemote) {
route_config_, random_, runtime_, local_info_);
EXPECT_EQ("50.0.0.1", headers.get_("x-envoy-external-address"));
EXPECT_FALSE(headers.has("x-envoy-internal"));
EXPECT_FALSE(headers.has("x-envoy-decorator-operation"));
EXPECT_FALSE(headers.has("x-envoy-downstream-service-cluster"));
EXPECT_FALSE(headers.has("x-envoy-retry-on"));
EXPECT_FALSE(headers.has("x-envoy-retry-grpc-on"));
Expand Down
4 changes: 3 additions & 1 deletion test/mocks/router/mocks.cc
Original file line number Diff line number Diff line change
Expand Up @@ -78,7 +78,9 @@ MockConfig::MockConfig() : route_(new NiceMock<MockRoute>()) {

MockConfig::~MockConfig() {}

MockDecorator::MockDecorator() { ON_CALL(*this, operation()).WillByDefault(ReturnRef(operation_)); }
MockDecorator::MockDecorator() {
ON_CALL(*this, getOperation()).WillByDefault(ReturnRef(operation_));
}
MockDecorator::~MockDecorator() {}

MockRoute::MockRoute() {
Expand Down
2 changes: 1 addition & 1 deletion test/mocks/router/mocks.h
Original file line number Diff line number Diff line change
Expand Up @@ -227,7 +227,7 @@ class MockDecorator : public Decorator {
~MockDecorator();

// Router::Decorator
MOCK_CONST_METHOD0(operation, const std::string&());
MOCK_CONST_METHOD0(getOperation, const std::string&());
MOCK_CONST_METHOD1(apply, void(Tracing::Span& span));

std::string operation_{"fake_operation"};
Expand Down