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.

Sign up for GitHub

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

Jump to bottom

tracing: add SpanFinalizer and test and use NullSpan #1029

Merged
merged 13 commits into from
Jun 9, 2017
Merged

tracing: add SpanFinalizer and test and use NullSpan #1029

Show file tree
Hide file tree
Changes from 7 commits
Commits
Show all changes
13 commits
Select commit Hold shift + click to select a range
8e59030
tracing: adopt NullSpan and add finalizer
goaway May 23, 2017
3e83c33
checkpoint: compiles
goaway May 25, 2017
4ea0ef7
checkpoint: tests pass
goaway May 30, 2017
53ec11b
minor fix
goaway May 30, 2017
1ffcde9
updates for comments
goaway May 30, 2017
0956877
improve test
goaway May 31, 2017
8fc3d01
delete stray comment
goaway May 31, 2017
a67ef7c
update tests
goaway Jun 1, 2017
469f3c3
asan and tsan failurse
goaway Jun 2, 2017
a70d244
remove comment.
RomanDzhabarov Jun 8, 2017
5d7d560
Merge branch 'master' into nullspan
RomanDzhabarov Jun 8, 2017
27b0875
fix
Jun 9, 2017
5b91a78
pass header map *
RomanDzhabarov Jun 9, 2017
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
23 changes: 19 additions & 4 deletions include/envoy/tracing/http_tracer.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -31,13 +31,27 @@ class Config {
virtual const std::vector<Http::LowerCaseString>& requestHeadersForTags() const PURE;
};

/*
* Basic abstraction for span.
*/
class Span;

typedef std::unique_ptr<Span> SpanPtr;

/*
* Interface to perform context-specific tasks when completing a Span.
*/
class SpanFinalizer {
public:
virtual ~SpanFinalizer() {}

/**
* Finalize the Span.
* @param span the Span to be finalized
*/
virtual void finalize(Span& span) PURE;
};

/*
* Basic abstraction for span.
*/
class Span {
public:
virtual ~Span() {}
Expand All @@ -52,8 +66,9 @@ class Span {
/**
* Capture the final duration for this Span and carry out any work necessary to complete it.
* Once this method is called, the Span may be safely discarded.
* @param finalizer callback for context-specific work to complete the Span
*/
virtual void finishSpan() PURE;
virtual void finishSpan(SpanFinalizer& finalizer) PURE;

/**
* Mutate the provided headers with the context necessary to propagate this
Expand Down
12 changes: 5 additions & 7 deletions source/common/http/conn_manager_impl.cc
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -335,13 +335,11 @@ ConnectionManagerImpl::ActiveStream::~ActiveStream() {
log_handler->log(request_headers_.get(), response_headers_.get(), request_info_);
}

if (active_span_) {
if (request_info_.healthCheck()) {
connection_manager_.config_.tracingStats().health_check_.inc();
} else {
Tracing::HttpTracerUtility::finalizeSpan(*active_span_, *request_headers_, request_info_,
*this);
}
if (request_info_.healthCheck()) {
connection_manager_.config_.tracingStats().health_check_.inc();
} else {
Tracing::HttpConnManFinalizerImpl finalizer{*request_headers_, request_info_, *this};
Copy link
Member

Choose a reason for hiding this comment

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

Is it worth constructing the finalizer here in the common case (e.g. when not tracing) that active_span_ is NullSpan?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Possibly not, especially given it's not all that cheap to construct. I can't think of a super clean way to check that here though. I mean we could have an isNull check on the Span itself, though that doesn't seem all that great. Any suggestions?

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 we all agree that this is not necessary, but it involves 3 ref copies during the creation ultimately we could fix with isNull check if this appears in the perf traces.
Open to suggestions as well

Copy link
Member

Choose a reason for hiding this comment

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

If this is the only place we do this we could consider just keeping track of the tracing decision from where active_span_ was set, but then you're essentially going back to treating this as nullptr. In general though it seems that there is the pattern of "some setup work; do something on a span that might be null;", so it would be useful to have a cheap way to know if actively tracing. iSNull seems reasonable in the absence of some other object with trace context info.

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 think @RomanDzhabarov has a fair point - all the really expensive stuff is in the actual finalize() call, which gets skipped entirely in the case of a NullSpan (I for some reason was thinking for a moment that more of it was in the constructor, but now recall I deliberately pushed it all into the finalize call for that reason).

I'm leaning slightly towards sticking with the unnecessary instantiation for now, since it keeps things a little tidier. No very strong feelings about it though.

Copy link
Member

Choose a reason for hiding this comment

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

OK, it's fine for now, we can solve this issue further down the track if/when the unnecessary work ends up being larger.

active_span_->finishSpan(finalizer);
}

ASSERT(state_.filter_call_state_ == 0);
Expand Down
2 changes: 1 addition & 1 deletion source/common/http/conn_manager_impl.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -445,7 +445,7 @@ class ConnectionManagerImpl : Logger::Loggable<Logger::Id::http>,

ConnectionManagerImpl& connection_manager_;
Router::ConfigConstSharedPtr snapped_route_config_;
Tracing::SpanPtr active_span_;
Tracing::SpanPtr active_span_{new Tracing::NullSpan()};
const uint64_t stream_id_;
StreamEncoder* response_encoder_{};
HeaderMapPtr response_headers_;
Expand Down
56 changes: 28 additions & 28 deletions source/common/tracing/http_tracer_impl.cc
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -116,44 +116,44 @@ Decision HttpTracerUtility::isTracing(const Http::AccessLog::RequestInfo& reques
NOT_REACHED;
}

void HttpTracerUtility::finalizeSpan(Span& active_span, const Http::HeaderMap& request_headers,
const Http::AccessLog::RequestInfo& request_info,
const Config& config) {
HttpConnManFinalizerImpl::HttpConnManFinalizerImpl(Http::HeaderMap& request_headers,
Http::AccessLog::RequestInfo& request_info,
Config& tracing_config)
: request_headers_(request_headers), request_info_(request_info),
tracing_config_(tracing_config) {}

void HttpConnManFinalizerImpl::finalize(Span& span) {
// Pre response data.
active_span.setTag("guid:x-request-id",
std::string(request_headers.RequestId()->value().c_str()));
active_span.setTag("request_line", buildRequestLine(request_headers, request_info));
active_span.setTag("request_size", std::to_string(request_info.bytesReceived()));
active_span.setTag("host_header", valueOrDefault(request_headers.Host(), "-"));
active_span.setTag("downstream_cluster",
valueOrDefault(request_headers.EnvoyDownstreamServiceCluster(), "-"));
active_span.setTag("user_agent", valueOrDefault(request_headers.UserAgent(), "-"));

if (request_headers.ClientTraceId()) {
active_span.setTag("guid:x-client-trace-id",
std::string(request_headers.ClientTraceId()->value().c_str()));
span.setTag("guid:x-request-id", std::string(request_headers_.RequestId()->value().c_str()));
span.setTag("request_line", buildRequestLine(request_headers_, request_info_));
span.setTag("request_size", std::to_string(request_info_.bytesReceived()));
span.setTag("host_header", valueOrDefault(request_headers_.Host(), "-"));
span.setTag("downstream_cluster",
valueOrDefault(request_headers_.EnvoyDownstreamServiceCluster(), "-"));
span.setTag("user_agent", valueOrDefault(request_headers_.UserAgent(), "-"));

if (request_headers_.ClientTraceId()) {
span.setTag("guid:x-client-trace-id",
std::string(request_headers_.ClientTraceId()->value().c_str()));
}

// Build tags based on the custom headers.
for (const Http::LowerCaseString& header : config.requestHeadersForTags()) {
const Http::HeaderEntry* entry = request_headers.get(header);
for (const Http::LowerCaseString& header : tracing_config_.requestHeadersForTags()) {
const Http::HeaderEntry* entry = request_headers_.get(header);
if (entry) {
active_span.setTag(header.get(), entry->value().c_str());
span.setTag(header.get(), entry->value().c_str());
}
}

// Post response data.
active_span.setTag("response_code", buildResponseCode(request_info));
active_span.setTag("response_size", std::to_string(request_info.bytesSent()));
active_span.setTag("response_flags",
Http::AccessLog::ResponseFlagUtils::toShortString(request_info));

if (request_info.responseCode().valid() &&
Http::CodeUtility::is5xx(request_info.responseCode().value())) {
active_span.setTag("error", "true");
}
span.setTag("response_code", buildResponseCode(request_info_));
span.setTag("response_size", std::to_string(request_info_.bytesSent()));
span.setTag("response_flags", Http::AccessLog::ResponseFlagUtils::toShortString(request_info_));

active_span.finishSpan();
if (request_info_.responseCode().valid() &&
Http::CodeUtility::is5xx(request_info_.responseCode().value())) {
span.setTag("error", "true");
}
}

HttpTracerImpl::HttpTracerImpl(DriverPtr&& driver, const LocalInfo::LocalInfo& local_info)
Expand Down
42 changes: 32 additions & 10 deletions source/common/tracing/http_tracer_impl.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -62,11 +62,42 @@ class HttpTracerUtility {
static const std::string EGRESS_OPERATION;
};

class NullSpan : public Span {
public:
// Tracing::Span
void setTag(const std::string&, const std::string&) override {}
void finishSpan(SpanFinalizer&) override {}
void injectContext(Http::HeaderMap&) override {}
SpanPtr spawnChild(const std::string&, SystemTime) override { return SpanPtr{new NullSpan()}; }
};

class NullFinalizer : public SpanFinalizer {
public:
// Tracing::SpanFinalizer
void finalize(Span&) override {}
};

/**
* Finalizer for Spans covering standard request ingress.
*/
class HttpConnManFinalizerImpl : public SpanFinalizer {
public:
HttpConnManFinalizerImpl(Http::HeaderMap& request_headers,
Http::AccessLog::RequestInfo& request_info, Config& tracing_config);

void finalize(Span& span) override;

private:
Http::HeaderMap& request_headers_;
Http::AccessLog::RequestInfo& request_info_;
Config& tracing_config_;
};

class HttpNullTracer : public HttpTracer {
public:
// Tracing::HttpTracer
SpanPtr startSpan(const Config&, Http::HeaderMap&, const Http::AccessLog::RequestInfo&) override {
return nullptr;
return SpanPtr{new NullSpan()};
}
};

Expand All @@ -83,14 +114,5 @@ class HttpTracerImpl : public HttpTracer {
const LocalInfo::LocalInfo& local_info_;
};

class NullSpan : public Tracing::Span {
public:
// Tracing::Span
void setTag(const std::string&, const std::string&) override {}
void finishSpan() override {}
void injectContext(Http::HeaderMap&) override {}
SpanPtr spawnChild(const std::string&, SystemTime) override { return SpanPtr{new NullSpan()}; }
};

} // Tracing
} // Envoy
5 changes: 4 additions & 1 deletion source/common/tracing/lightstep_tracer_impl.cc
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -18,7 +18,10 @@ namespace Tracing {
LightStepSpan::LightStepSpan(lightstep::Span& span, lightstep::Tracer& tracer)
: span_(span), tracer_(tracer) {}

void LightStepSpan::finishSpan() { span_.Finish(); }
void LightStepSpan::finishSpan(SpanFinalizer& finalizer) {
finalizer.finalize(*this);
span_.Finish();
}

void LightStepSpan::setTag(const std::string& name, const std::string& value) {
span_.SetTag(name, value);
Expand Down
2 changes: 1 addition & 1 deletion source/common/tracing/lightstep_tracer_impl.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -32,7 +32,7 @@ class LightStepSpan : public Span {
LightStepSpan(lightstep::Span& span, lightstep::Tracer& tracer);

// Tracing::Span
void finishSpan() override;
void finishSpan(SpanFinalizer& finalizer) override;
void setTag(const std::string& name, const std::string& value) override;
void injectContext(Http::HeaderMap& request_headers) override;
SpanPtr spawnChild(const std::string& name, SystemTime start_time) override;
Expand Down
5 changes: 4 additions & 1 deletion source/common/tracing/zipkin/zipkin_tracer_impl.cc
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -14,7 +14,10 @@ namespace Zipkin {

ZipkinSpan::ZipkinSpan(Zipkin::Span& span, Zipkin::Tracer& tracer) : span_(span), tracer_(tracer) {}

void ZipkinSpan::finishSpan() { span_.finish(); }
void ZipkinSpan::finishSpan(Tracing::SpanFinalizer& finalizer) {
finalizer.finalize(*this);
span_.finish();
}

void ZipkinSpan::setTag(const std::string& name, const std::string& value) {
if (this->hasCSAnnotation()) {
Expand Down
4 changes: 3 additions & 1 deletion source/common/tracing/zipkin/zipkin_tracer_impl.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -40,8 +40,10 @@ class ZipkinSpan : public Tracing::Span {
/**
* Calls Zipkin::Span::finishSpan() to perform all actions needed to finalize the span.
* This function is called by Tracing::HttpTracerUtility::finalizeSpan().
*
* @param finalizer SpanFinalizer to be called to complete this Span
*/
void finishSpan() override;
void finishSpan(Tracing::SpanFinalizer& finalizer) override;

/**
* This function adds a Zipkin "string" binary annotation to this span.
Expand Down
6 changes: 4 additions & 2 deletions test/common/http/conn_manager_impl_test.cc
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -290,7 +290,9 @@ TEST_F(HttpConnectionManagerImplTest, StartAndFinishSpanNormalFlow) {

return span;
}));
EXPECT_CALL(*span, finishSpan());
EXPECT_CALL(*span, finishSpan(_))
.WillOnce(
Invoke([&](Tracing::SpanFinalizer& finalizer) -> void { finalizer.finalize(*span); }));
EXPECT_CALL(*span, setTag(_, _)).Times(testing::AnyNumber());
// Verify tag is set based on the request headers.
EXPECT_CALL(*span, setTag(":method", "GET"));
Expand Down Expand Up @@ -419,7 +421,7 @@ TEST_F(HttpConnectionManagerImplTest, StartSpanOnlyHealthCheckRequest) {
NiceMock<Tracing::MockSpan>* span = new NiceMock<Tracing::MockSpan>();

EXPECT_CALL(tracer_, startSpan_(_, _, _)).WillOnce(Return(span));
EXPECT_CALL(*span, finishSpan()).Times(0);
EXPECT_CALL(*span, finishSpan(_)).Times(0);

EXPECT_CALL(runtime_.snapshot_, featureEnabled("tracing.global_enabled", 100, _))
.WillOnce(Return(true));
Expand Down
22 changes: 13 additions & 9 deletions test/common/tracing/http_tracer_impl_test.cc
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -234,7 +234,7 @@ TEST(HttpTracerUtilityTest, IsTracing) {
}
}

TEST(HttpTracerUtilityTest, OriginalAndLongPath) {
TEST(HttpConnManFinalizerImpl, OriginalAndLongPath) {
const std::string path(300, 'a');
const std::string expected_path(128, 'a');
std::unique_ptr<NiceMock<MockSpan>> span(new NiceMock<MockSpan>());
Expand All @@ -253,10 +253,12 @@ TEST(HttpTracerUtilityTest, OriginalAndLongPath) {
EXPECT_CALL(*span, setTag(_, _)).Times(testing::AnyNumber());
EXPECT_CALL(*span, setTag("request_line", "GET " + expected_path + " HTTP/2"));
NiceMock<MockConfig> config;
HttpTracerUtility::finalizeSpan(*span, request_headers, request_info, config);

HttpConnManFinalizerImpl finalizer{request_headers, request_info, config};
finalizer.finalize(*span);
}

TEST(HttpTracerUtilityTest, SpanOptionalHeaders) {
TEST(HttpConnManFinalizerImpl, SpanOptionalHeaders) {
std::unique_ptr<NiceMock<MockSpan>> span(new NiceMock<MockSpan>());

Http::TestHeaderMapImpl request_headers{
Expand Down Expand Up @@ -284,12 +286,13 @@ TEST(HttpTracerUtilityTest, SpanOptionalHeaders) {
EXPECT_CALL(*span, setTag("response_size", "100"));
EXPECT_CALL(*span, setTag("response_flags", "-"));

EXPECT_CALL(*span, finishSpan());
NiceMock<MockConfig> config;
HttpTracerUtility::finalizeSpan(*span, request_headers, request_info, config);

HttpConnManFinalizerImpl finalizer{request_headers, request_info, config};
finalizer.finalize(*span);
}

TEST(HttpTracerUtilityTest, SpanPopulatedFailureResponse) {
TEST(HttpConnManFinalizerImpl, SpanPopulatedFailureResponse) {
std::unique_ptr<NiceMock<MockSpan>> span(new NiceMock<MockSpan>());
Http::TestHeaderMapImpl request_headers{
{"x-request-id", "id"}, {":path", "/test"}, {":method", "GET"}};
Expand Down Expand Up @@ -337,8 +340,8 @@ TEST(HttpTracerUtilityTest, SpanPopulatedFailureResponse) {
EXPECT_CALL(*span, setTag("response_size", "100"));
EXPECT_CALL(*span, setTag("response_flags", "UT"));

EXPECT_CALL(*span, finishSpan());
HttpTracerUtility::finalizeSpan(*span, request_headers, request_info, config);
HttpConnManFinalizerImpl finalizer{request_headers, request_info, config};
finalizer.finalize(*span);
}

TEST(HttpTracerUtilityTest, operationTypeToString) {
Expand All @@ -352,7 +355,8 @@ TEST(HttpNullTracerTest, BasicFunctionality) {
Http::AccessLog::MockRequestInfo request_info;
Http::TestHeaderMapImpl request_headers;

EXPECT_EQ(nullptr, null_tracer.startSpan(config, request_headers, request_info));
SpanPtr span_ptr = null_tracer.startSpan(config, request_headers, request_info);
EXPECT_TRUE(dynamic_cast<NullSpan*>(span_ptr.get()) != nullptr);
}

class HttpTracerImplTest : public Test {
Expand Down
16 changes: 12 additions & 4 deletions test/common/tracing/lightstep_tracer_impl_test.cc
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -166,10 +166,16 @@ TEST_F(LightStepDriverTest, FlushSeveralSpans) {
.WillOnce(Return(5000U));

SpanPtr first_span = driver_->startSpan(request_headers_, operation_name_, start_time_);
first_span->finishSpan();
// MockFinalizer finalizer;
NullFinalizer finalizer;
Copy link
Member

Choose a reason for hiding this comment

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

why not MockFinalizer, we could check later on that finalize is called on this mock


// EXPECT_CALL(finalizer, finalize(*first_span));
first_span->finishSpan(finalizer);

SpanPtr second_span = driver_->startSpan(request_headers_, operation_name_, start_time_);
second_span->finishSpan();

// EXPECT_CALL(finalizer, finalize(*second_span));
second_span->finishSpan(finalizer);

Http::MessagePtr msg(new Http::ResponseMessageImpl(
Http::HeaderMapPtr{new Http::TestHeaderMapImpl{{":status", "200"}}}));
Expand Down Expand Up @@ -203,7 +209,8 @@ TEST_F(LightStepDriverTest, FlushSpansTimer) {
.WillOnce(Return(5));

SpanPtr span = driver_->startSpan(request_headers_, operation_name_, start_time_);
span->finishSpan();
NullFinalizer finalizer;
span->finishSpan(finalizer);

// Timer should be re-enabled.
EXPECT_CALL(*timer_, enableTimer(std::chrono::milliseconds(1000)));
Expand Down Expand Up @@ -244,7 +251,8 @@ TEST_F(LightStepDriverTest, FlushOneSpanGrpcFailure) {
.WillOnce(Return(5000U));

SpanPtr span = driver_->startSpan(request_headers_, operation_name_, start_time_);
span->finishSpan();
NullFinalizer finalizer;
span->finishSpan(finalizer);

Http::MessagePtr msg(new Http::ResponseMessageImpl(
Http::HeaderMapPtr{new Http::TestHeaderMapImpl{{":status", "200"}}}));
Expand Down
Loading