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 grpc-status and grpc-message to spans #7996

Merged
merged 4 commits into from
Aug 27, 2019
Merged

tracing: add grpc-status and grpc-message to spans #7996

Show file tree
Hide file tree
Changes from 1 commit
Commits
Show all changes
4 commits
Select commit Hold shift + click to select a range
35aa35d
tracing: add grpc-status and grpc-message to spans
cgilmour Aug 21, 2019
e0be638
Set error tag for grpc when status not OK
cgilmour Aug 22, 2019
958947f
Tracing docs and release notes entry.
cgilmour Aug 22, 2019
93b43d0
Fix status code and handle trailers-only case.
cgilmour Aug 24, 2019
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
5 changes: 3 additions & 2 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 @@ -502,8 +502,9 @@ ConnectionManagerImpl::ActiveStream::~ActiveStream() {
}

if (active_span_) {
Tracing::HttpTracerUtility::finalizeSpan(*active_span_, request_headers_.get(), stream_info_,
*this);
Tracing::HttpTracerUtility::finalizeSpan(*active_span_, request_headers_.get(),
response_headers_.get(), response_trailers_.get(),
stream_info_, *this);
}
if (state_.successful_upgrade_) {
connection_manager_.stats_.named_.downstream_cx_upgrades_active_.dec();
Expand Down
16 changes: 16 additions & 0 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 @@ -7,6 +7,7 @@
#include "common/common/fmt.h"
#include "common/common/macros.h"
#include "common/common/utility.h"
#include "common/grpc/common.h"
#include "common/http/codes.h"
#include "common/http/header_map_impl.h"
#include "common/http/headers.h"
Expand Down Expand Up @@ -121,6 +122,8 @@ static void annotateVerbose(Span& span, const StreamInfo::StreamInfo& stream_inf
}

void HttpTracerUtility::finalizeSpan(Span& span, const Http::HeaderMap* request_headers,
const Http::HeaderMap* response_headers,
const Http::HeaderMap* response_trailers,
const StreamInfo::StreamInfo& stream_info,
const Config& tracing_config) {
// Pre response data.
Expand Down Expand Up @@ -163,6 +166,19 @@ void HttpTracerUtility::finalizeSpan(Span& span, const Http::HeaderMap* request_
span.setTag(Tracing::Tags::get().ResponseFlags,
StreamInfo::ResponseFlagUtils::toShortString(stream_info));

// GRPC data.
if (response_headers && response_trailers && stream_info.protocol() == Http::Protocol::Http2 &&
Copy link
Member

Choose a reason for hiding this comment

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

Q: Don't you want to handle trailer only (header only) gRPC responses also? These would be useful error cases. cc @lizan

/wait-any

Copy link
Member

Choose a reason for hiding this comment

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

Right this should be extract first of non-null HeaderMap in (response trailers, response headers), I'd not limit the protocol = HTTP2 here since it is also useful cases for grpc_http1_bridge etc, and future gRPC over QUIC(HTTP/3?).

Grpc::Common::hasGrpcContentType(*response_headers)) {
const Http::HeaderEntry* grpc_status_header = response_trailers->GrpcStatus();
if (grpc_status_header) {
span.setTag(Tracing::Tags::get().GrpcStatusCode, grpc_status_header->value().getStringView());
}
const Http::HeaderEntry* grpc_message_header = response_trailers->GrpcMessage();
if (grpc_message_header) {
span.setTag(Tracing::Tags::get().GrpcMessage, grpc_message_header->value().getStringView());
}
}
Copy link
Contributor

Choose a reason for hiding this comment

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

Would be good to also set the error tag, as for the async client, if the status is not Ok.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Thanks @objectiser - I've added this.


if (tracing_config.verbose()) {
annotateVerbose(span, stream_info);
}
Expand Down
3 changes: 3 additions & 0 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 @@ -41,6 +41,7 @@ class TracingTagValues {
// Non-standard tag names.
const std::string DownstreamCluster = "downstream_cluster";
const std::string GrpcStatusCode = "grpc.status_code";
const std::string GrpcMessage = "grpc.message";
const std::string GuidXClientTraceId = "guid:x-client-trace-id";
const std::string GuidXRequestId = "guid:x-request-id";
const std::string HttpProtocol = "http.protocol";
Expand Down Expand Up @@ -101,6 +102,8 @@ class HttpTracerUtility {
* 2) Finish active span.
*/
static void finalizeSpan(Span& span, const Http::HeaderMap* request_headers,
const Http::HeaderMap* response_headers,
const Http::HeaderMap* response_trailers,
const StreamInfo::StreamInfo& stream_info, const Config& tracing_config);

static const std::string IngressOperation;
Expand Down
73 changes: 62 additions & 11 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 @@ -122,12 +122,14 @@ TEST(HttpConnManFinalizerImpl, OriginalAndLongPath) {
{"x-envoy-original-path", path},
{":method", "GET"},
{"x-forwarded-proto", "http"}};
Http::TestHeaderMapImpl response_headers;
Http::TestHeaderMapImpl response_trailers;
NiceMock<StreamInfo::MockStreamInfo> stream_info;

absl::optional<Http::Protocol> protocol = Http::Protocol::Http2;
EXPECT_CALL(stream_info, bytesReceived()).WillOnce(Return(10));
EXPECT_CALL(stream_info, bytesSent()).WillOnce(Return(11));
EXPECT_CALL(stream_info, protocol()).WillOnce(ReturnPointee(&protocol));
EXPECT_CALL(stream_info, protocol()).WillRepeatedly(ReturnPointee(&protocol));
absl::optional<uint32_t> response_code;
EXPECT_CALL(stream_info, responseCode()).WillRepeatedly(ReturnPointee(&response_code));

Expand All @@ -137,7 +139,8 @@ TEST(HttpConnManFinalizerImpl, OriginalAndLongPath) {
EXPECT_CALL(span, setTag(Eq(Tracing::Tags::get().HttpProtocol), Eq("HTTP/2")));

NiceMock<MockConfig> config;
HttpTracerUtility::finalizeSpan(span, &request_headers, stream_info, config);
HttpTracerUtility::finalizeSpan(span, &request_headers, &response_headers, &response_trailers,
stream_info, config);
}

TEST(HttpConnManFinalizerImpl, NoGeneratedId) {
Expand All @@ -148,12 +151,14 @@ TEST(HttpConnManFinalizerImpl, NoGeneratedId) {

Http::TestHeaderMapImpl request_headers{
{"x-envoy-original-path", path}, {":method", "GET"}, {"x-forwarded-proto", "http"}};
Http::TestHeaderMapImpl response_headers;
Http::TestHeaderMapImpl response_trailers;
NiceMock<StreamInfo::MockStreamInfo> stream_info;

absl::optional<Http::Protocol> protocol = Http::Protocol::Http2;
EXPECT_CALL(stream_info, bytesReceived()).WillOnce(Return(10));
EXPECT_CALL(stream_info, bytesSent()).WillOnce(Return(11));
EXPECT_CALL(stream_info, protocol()).WillOnce(ReturnPointee(&protocol));
EXPECT_CALL(stream_info, protocol()).WillRepeatedly(ReturnPointee(&protocol));
absl::optional<uint32_t> response_code;
EXPECT_CALL(stream_info, responseCode()).WillRepeatedly(ReturnPointee(&response_code));

Expand All @@ -163,7 +168,8 @@ TEST(HttpConnManFinalizerImpl, NoGeneratedId) {
EXPECT_CALL(span, setTag(Eq(Tracing::Tags::get().HttpProtocol), Eq("HTTP/2")));

NiceMock<MockConfig> config;
HttpTracerUtility::finalizeSpan(span, &request_headers, stream_info, config);
HttpTracerUtility::finalizeSpan(span, &request_headers, &response_headers, &response_trailers,
stream_info, config);
}

TEST(HttpConnManFinalizerImpl, NullRequestHeaders) {
Expand All @@ -184,7 +190,7 @@ TEST(HttpConnManFinalizerImpl, NullRequestHeaders) {
EXPECT_CALL(span, setTag(Eq(Tracing::Tags::get().UpstreamCluster), _)).Times(0);

NiceMock<MockConfig> config;
HttpTracerUtility::finalizeSpan(span, nullptr, stream_info, config);
HttpTracerUtility::finalizeSpan(span, nullptr, nullptr, nullptr, stream_info, config);
}

TEST(HttpConnManFinalizerImpl, StreamInfoLogs) {
Expand Down Expand Up @@ -222,7 +228,7 @@ TEST(HttpConnManFinalizerImpl, StreamInfoLogs) {

NiceMock<MockConfig> config;
EXPECT_CALL(config, verbose).WillOnce(Return(true));
HttpTracerUtility::finalizeSpan(span, nullptr, stream_info, config);
HttpTracerUtility::finalizeSpan(span, nullptr, nullptr, nullptr, stream_info, config);
}

TEST(HttpConnManFinalizerImpl, UpstreamClusterTagSet) {
Expand All @@ -244,7 +250,7 @@ TEST(HttpConnManFinalizerImpl, UpstreamClusterTagSet) {
EXPECT_CALL(span, setTag(Eq(Tracing::Tags::get().RequestSize), Eq("10")));

NiceMock<MockConfig> config;
HttpTracerUtility::finalizeSpan(span, nullptr, stream_info, config);
HttpTracerUtility::finalizeSpan(span, nullptr, nullptr, nullptr, stream_info, config);
}

TEST(HttpConnManFinalizerImpl, SpanOptionalHeaders) {
Expand All @@ -254,11 +260,13 @@ TEST(HttpConnManFinalizerImpl, SpanOptionalHeaders) {
{":path", "/test"},
{":method", "GET"},
{"x-forwarded-proto", "https"}};
Http::TestHeaderMapImpl response_headers;
Http::TestHeaderMapImpl response_trailers;
NiceMock<StreamInfo::MockStreamInfo> stream_info;

absl::optional<Http::Protocol> protocol = Http::Protocol::Http10;
EXPECT_CALL(stream_info, bytesReceived()).WillOnce(Return(10));
EXPECT_CALL(stream_info, protocol()).WillOnce(ReturnPointee(&protocol));
EXPECT_CALL(stream_info, protocol()).WillRepeatedly(ReturnPointee(&protocol));
const std::string service_node = "i-453";

// Check that span is populated correctly.
Expand All @@ -282,7 +290,8 @@ TEST(HttpConnManFinalizerImpl, SpanOptionalHeaders) {
EXPECT_CALL(span, setTag(Eq(Tracing::Tags::get().UpstreamCluster), _)).Times(0);

NiceMock<MockConfig> config;
HttpTracerUtility::finalizeSpan(span, &request_headers, stream_info, config);
HttpTracerUtility::finalizeSpan(span, &request_headers, &response_headers, &response_trailers,
stream_info, config);
}

TEST(HttpConnManFinalizerImpl, SpanPopulatedFailureResponse) {
Expand All @@ -291,6 +300,8 @@ TEST(HttpConnManFinalizerImpl, SpanPopulatedFailureResponse) {
{":path", "/test"},
{":method", "GET"},
{"x-forwarded-proto", "http"}};
Http::TestHeaderMapImpl response_headers;
Http::TestHeaderMapImpl response_trailers;
NiceMock<StreamInfo::MockStreamInfo> stream_info;

request_headers.insertHost().value(std::string("api"));
Expand All @@ -299,7 +310,7 @@ TEST(HttpConnManFinalizerImpl, SpanPopulatedFailureResponse) {
request_headers.insertClientTraceId().value(std::string("client_trace_id"));

absl::optional<Http::Protocol> protocol = Http::Protocol::Http10;
EXPECT_CALL(stream_info, protocol()).WillOnce(ReturnPointee(&protocol));
EXPECT_CALL(stream_info, protocol()).WillRepeatedly(ReturnPointee(&protocol));
EXPECT_CALL(stream_info, bytesReceived()).WillOnce(Return(10));
const std::string service_node = "i-453";

Expand Down Expand Up @@ -339,7 +350,43 @@ TEST(HttpConnManFinalizerImpl, SpanPopulatedFailureResponse) {
EXPECT_CALL(span, setTag(Eq(Tracing::Tags::get().ResponseFlags), Eq("UT")));
EXPECT_CALL(span, setTag(Eq(Tracing::Tags::get().UpstreamCluster), _)).Times(0);

HttpTracerUtility::finalizeSpan(span, &request_headers, stream_info, config);
HttpTracerUtility::finalizeSpan(span, &request_headers, &response_headers, &response_trailers,
stream_info, config);
}

TEST(HttpConnManFinalizerImpl, Grpc) {
const std::string path_prefix = "http://";
NiceMock<MockSpan> span;

Http::TestHeaderMapImpl request_headers{{":method", "POST"},
{":scheme", "http"},
{":path", "/pb.Foo/Bar"},
{":authority", "example.com:80"},
{"content-type", "application/grpc"},
{"te", "trailers"}};

Http::TestHeaderMapImpl response_headers{{":status", "200"},
{"content-type", "application/grpc"}};
Http::TestHeaderMapImpl response_trailers{{"grpc-status", "0"}, {"grpc-message", ""}};
NiceMock<StreamInfo::MockStreamInfo> stream_info;

absl::optional<Http::Protocol> protocol = Http::Protocol::Http2;
absl::optional<uint32_t> response_code(200);
EXPECT_CALL(stream_info, responseCode()).WillRepeatedly(ReturnPointee(&response_code));
EXPECT_CALL(stream_info, bytesReceived()).WillOnce(Return(10));
EXPECT_CALL(stream_info, bytesSent()).WillOnce(Return(11));
EXPECT_CALL(stream_info, protocol()).WillRepeatedly(ReturnPointee(&protocol));

EXPECT_CALL(span, setTag(_, _)).Times(testing::AnyNumber());
EXPECT_CALL(span, setTag(Eq(Tracing::Tags::get().HttpMethod), Eq("POST")));
EXPECT_CALL(span, setTag(Eq(Tracing::Tags::get().HttpProtocol), Eq("HTTP/2")));
EXPECT_CALL(span, setTag(Eq(Tracing::Tags::get().HttpStatusCode), Eq("200")));
EXPECT_CALL(span, setTag(Eq(Tracing::Tags::get().GrpcStatusCode), Eq("0")));
EXPECT_CALL(span, setTag(Eq(Tracing::Tags::get().GrpcMessage), Eq("")));

NiceMock<MockConfig> config;
HttpTracerUtility::finalizeSpan(span, &request_headers, &response_headers, &response_trailers,
stream_info, config);
}

TEST(HttpTracerUtilityTest, operationTypeToString) {
Expand All @@ -352,6 +399,8 @@ TEST(HttpNullTracerTest, BasicFunctionality) {
MockConfig config;
StreamInfo::MockStreamInfo stream_info;
Http::TestHeaderMapImpl request_headers;
Http::TestHeaderMapImpl response_headers;
Http::TestHeaderMapImpl response_trailers;

SpanPtr span_ptr =
null_tracer.startSpan(config, request_headers, stream_info, {Reason::Sampling, true});
Expand All @@ -374,6 +423,8 @@ class HttpTracerImplTest : public testing::Test {

Http::TestHeaderMapImpl request_headers_{
{":path", "/"}, {":method", "GET"}, {"x-request-id", "foo"}, {":authority", "test"}};
Http::TestHeaderMapImpl response_headers;
Http::TestHeaderMapImpl response_trailers;
StreamInfo::MockStreamInfo stream_info_;
NiceMock<LocalInfo::MockLocalInfo> local_info_;
MockConfig config_;
Expand Down