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

access_log: log requested_server_name in tcp proxy #4144

Merged
merged 11 commits into from
Aug 28, 2018
4 changes: 4 additions & 0 deletions docs/root/configuration/access_log.rst
Original file line number Diff line number Diff line change
Expand Up @@ -227,6 +227,10 @@ The following command operators are supported:
TCP
Not implemented ("-").

%REQUESTED_SERVER_NAME%
Copy link
Member

Choose a reason for hiding this comment

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

Better off naming this as SNI instead of requested server name, for clarity.

Copy link
Contributor

Choose a reason for hiding this comment

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

I disagree. In the future we may support sniffing the host header out of plaintext http, which is why it is named as it is in the listener filter code. Please leave it as REQUESTED_SERVER_NAME.

TCP
String value set on ssl connection socket for Server Name Indication (SNI)

.. _config_access_log_default_format:

Default format
Expand Down
1 change: 1 addition & 0 deletions docs/root/intro/version_history.rst
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,7 @@ Version history
* access log: added :ref:`response flag filter <envoy_api_msg_config.filter.accesslog.v2.ResponseFlagFilter>`
to filter based on the presence of Envoy response flags.
* access log: added RESPONSE_DURATION and RESPONSE_TX_DURATION.
* access log: added REQUESTED_SERVER_NAME for SNI
* admin: added :http:get:`/hystrix_event_stream` as an endpoint for monitoring envoy's statistics
through `Hystrix dashboard <https://github.com/Netflix-Skunkworks/hystrix-dashboard/wiki>`_.
* grpc-json: added support for building HTTP response from
Expand Down
10 changes: 10 additions & 0 deletions include/envoy/request_info/request_info.h
Original file line number Diff line number Diff line change
Expand Up @@ -301,6 +301,16 @@ class RequestInfo {
* the same key overriding existing.
*/
virtual void setDynamicMetadata(const std::string& name, const ProtobufWkt::Struct& value) PURE;

/**
* @param SNI value requested
*/
virtual void setRequestedServerName(const absl::string_view requested_server_name) PURE;

/**
* @return SNI value for downstream host
*/
virtual const std::string& requestedServerName() const PURE;
};

} // namespace RequestInfo
Expand Down
8 changes: 8 additions & 0 deletions source/common/access_log/access_log_formatter.cc
Original file line number Diff line number Diff line change
Expand Up @@ -301,6 +301,14 @@ RequestInfoFormatter::RequestInfoFormatter(const std::string& field_name) {
return RequestInfo::Utility::formatDownstreamAddressNoPort(
*request_info.downstreamRemoteAddress());
};
} else if (field_name == "REQUESTED_SERVER_NAME") {
field_extractor_ = [](const RequestInfo::RequestInfo& request_info) {
if (!request_info.requestedServerName().empty()) {
return request_info.requestedServerName();
} else {
return UnspecifiedValueString;
}
};
} else {
throw EnvoyException(fmt::format("Not supported field in RequestInfo: {}", field_name));
}
Expand Down
7 changes: 7 additions & 0 deletions source/common/request_info/request_info_impl.h
Original file line number Diff line number Diff line change
Expand Up @@ -178,6 +178,12 @@ struct RequestInfoImpl : public RequestInfo {
(*metadata_.mutable_filter_metadata())[name].MergeFrom(value);
};

void setRequestedServerName(absl::string_view requested_server_name) override {
requested_server_name_ = std::string(requested_server_name);
}

const std::string& requestedServerName() const override { return requested_server_name_; }

const SystemTime start_time_;
const MonotonicTime start_time_monotonic_;

Expand All @@ -204,6 +210,7 @@ struct RequestInfoImpl : public RequestInfo {
Network::Address::InstanceConstSharedPtr upstream_local_address_;
Network::Address::InstanceConstSharedPtr downstream_local_address_;
Network::Address::InstanceConstSharedPtr downstream_remote_address_;
std::string requested_server_name_;
};

} // namespace RequestInfo
Expand Down
3 changes: 3 additions & 0 deletions source/common/tcp_proxy/tcp_proxy.cc
Original file line number Diff line number Diff line change
Expand Up @@ -388,6 +388,9 @@ Network::FilterStatus Filter::onData(Buffer::Instance& data, bool end_stream) {
upstream_connection_->write(data, end_stream);
ASSERT(0 == data.length());
resetIdleTimer(); // TODO(ggreenway) PERF: do we need to reset timer on both send and receive?
getRequestInfo().setRequestedServerName(read_callbacks_->connection().requestedServerName());
Copy link
Contributor

Choose a reason for hiding this comment

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

onData seems like the wrong place for this call; this will be run everytime downstream data arrives. Is the needed data available in onNewConnection()? At a minimum, have a flag for whether this has happened yet and only do it once.

Copy link
Member Author

Choose a reason for hiding this comment

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

I was thinking the same upon reviewing where I called this today. I ended up hitting problems with null values in cases of TCP HalfOpen and thought it might make more sense to only do this when there is a confirmed ::Connected.

ENVOY_LOG(debug, "TCP:onData(), requestedServerName: {} ",
getRequestInfo().requestedServerName());
Copy link
Member

Choose a reason for hiding this comment

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

FYI: I think the coverage tests are failing because they enable trace-level logging and either this (or one of the other log messages) is being invoked in a test that doesn't set up the mock.

Copy link
Member Author

Choose a reason for hiding this comment

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

Ack, yep that sounds right upon downloading the results

Copy link
Member

Choose a reason for hiding this comment

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

You should be able to reproduce just by running regular tests with --test_arg="-l trace".

return Network::FilterStatus::StopIteration;
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -123,6 +123,7 @@ void Filter::onServername(absl::string_view name) {
if (!name.empty()) {
config_->stats().sni_found_.inc();
cb_->socket().setRequestedServerName(name);
ENVOY_LOG(debug, "tls:onServerName(), requestedServerName: {}", name);
} else {
config_->stats().sni_not_found_.inc();
}
Expand Down
16 changes: 16 additions & 0 deletions test/common/access_log/access_log_formatter_test.cc
Original file line number Diff line number Diff line change
Expand Up @@ -185,6 +185,22 @@ TEST(AccessLogFormatterTest, requestInfoFormatter) {
RequestInfoFormatter upstream_format("DOWNSTREAM_REMOTE_ADDRESS");
EXPECT_EQ("127.0.0.1:0", upstream_format.format(header, header, header, request_info));
}

{
RequestInfoFormatter upstream_format("REQUESTED_SERVER_NAME");
std::string requested_server_name = "stub_server";
EXPECT_CALL(request_info, requestedServerName())
.WillRepeatedly(ReturnRef(requested_server_name));
EXPECT_EQ("stub_server", upstream_format.format(header, header, header, request_info));
}

{
RequestInfoFormatter upstream_format("REQUESTED_SERVER_NAME");
std::string requested_server_name;
EXPECT_CALL(request_info, requestedServerName())
.WillRepeatedly(ReturnRef(requested_server_name));
EXPECT_EQ("-", upstream_format.format(header, header, header, request_info));
}
}

TEST(AccessLogFormatterTest, requestHeaderFormatter) {
Expand Down
7 changes: 7 additions & 0 deletions test/common/access_log/test_util.h
Original file line number Diff line number Diff line change
Expand Up @@ -154,6 +154,12 @@ class TestRequestInfo : public RequestInfo::RequestInfo {
(*metadata_.mutable_filter_metadata())[name].MergeFrom(value);
};

void setRequestedServerName(const absl::string_view requested_server_name) override {
requested_server_name_ = std::string(requested_server_name);
}

const std::string& requestedServerName() const override { return requested_server_name_; }

SystemTime start_time_;
MonotonicTime start_time_monotonic_;

Expand All @@ -176,6 +182,7 @@ class TestRequestInfo : public RequestInfo::RequestInfo {
Network::Address::InstanceConstSharedPtr downstream_remote_address_;
const Router::RouteEntry* route_entry_{};
envoy::api::v2::core::Metadata metadata_{};
std::string requested_server_name_;
};

} // namespace Envoy
5 changes: 5 additions & 0 deletions test/common/request_info/request_info_impl_test.cc
Original file line number Diff line number Diff line change
Expand Up @@ -140,6 +140,11 @@ TEST(RequestInfoImplTest, MiscSettersAndGetters) {
NiceMock<Router::MockRouteEntry> route_entry;
request_info.route_entry_ = &route_entry;
EXPECT_EQ(&route_entry, request_info.routeEntry());

EXPECT_EQ("", request_info.requestedServerName());
absl::string_view sni_name = "stubserver.org";
request_info.setRequestedServerName(sni_name);
EXPECT_EQ(std::string(sni_name), request_info.requestedServerName());
}
}

Expand Down
5 changes: 5 additions & 0 deletions test/mocks/request_info/mocks.cc
Original file line number Diff line number Diff line change
Expand Up @@ -64,6 +64,11 @@ MockRequestInfo::MockRequestInfo()
}));
ON_CALL(*this, bytesSent()).WillByDefault(ReturnPointee(&bytes_sent_));
ON_CALL(*this, dynamicMetadata()).WillByDefault(ReturnRef(metadata_));
ON_CALL(*this, setRequestedServerName(_))
.WillByDefault(Invoke([this](const absl::string_view requested_server_name) {
requested_server_name_ = std::string(requested_server_name);
}));
ON_CALL(*this, requestedServerName()).WillByDefault(ReturnRef(requested_server_name_));
}

MockRequestInfo::~MockRequestInfo() {}
Expand Down
3 changes: 3 additions & 0 deletions test/mocks/request_info/mocks.h
Original file line number Diff line number Diff line change
Expand Up @@ -60,6 +60,8 @@ class MockRequestInfo : public RequestInfo {
MOCK_METHOD2(setDynamicMetadata, void(const std::string&, const ProtobufWkt::Struct&));
MOCK_METHOD3(setDynamicMetadata,
void(const std::string&, const std::string&, const std::string&));
MOCK_METHOD1(setRequestedServerName, void(const absl::string_view));
MOCK_CONST_METHOD0(requestedServerName, const std::string&());

std::shared_ptr<testing::NiceMock<Upstream::MockHostDescription>> host_{
new testing::NiceMock<Upstream::MockHostDescription>()};
Expand All @@ -81,6 +83,7 @@ class MockRequestInfo : public RequestInfo {
Network::Address::InstanceConstSharedPtr upstream_local_address_;
Network::Address::InstanceConstSharedPtr downstream_local_address_;
Network::Address::InstanceConstSharedPtr downstream_remote_address_;
std::string requested_server_name_;
};

} // namespace RequestInfo
Expand Down