From 6db470e8190e27b42cc720b186bf2c93c8721f27 Mon Sep 17 00:00:00 2001 From: John Esmet Date: Mon, 21 Dec 2020 19:53:25 +0000 Subject: [PATCH] Add custom formatting to downstream cert start and end dates --- .../formatter/substitution_formatter.cc | 127 +++++++----- .../common/formatter/substitution_formatter.h | 48 ++++- .../formatter/substitution_formatter_test.cc | 180 +++++++++++------- 3 files changed, 237 insertions(+), 118 deletions(-) diff --git a/source/common/formatter/substitution_formatter.cc b/source/common/formatter/substitution_formatter.cc index 4400ca3f6510..41f89082609f 100644 --- a/source/common/formatter/substitution_formatter.cc +++ b/source/common/formatter/substitution_formatter.cc @@ -43,8 +43,8 @@ void truncate(std::string& str, absl::optional max_length) { str = str.substr(0, max_length.value()); } -// Matches newline pattern in a StartTimeFormatter format string. -const std::regex& getStartTimeNewlinePattern() { +// Matches newline pattern in a system time format string (e.g. start time) +const std::regex& getSystemTimeFormatNewlinePattern() { CONSTRUCT_ON_FIRST_USE(std::regex, "%[-_0^#]*[1-9]*n"); } const std::regex& getNewlinePattern() { CONSTRUCT_ON_FIRST_USE(std::regex, "\n"); } @@ -318,18 +318,11 @@ std::vector SubstitutionFormatParser::parse(const std::str formatters.push_back( std::make_unique(key, max_length, serialize_as_string)); } else if (absl::StartsWith(token, "START_TIME")) { - const size_t parameters_length = pos + StartTimeParamStart + 1; - const size_t parameters_end = command_end_position - parameters_length; - - const std::string args = token[StartTimeParamStart - 1] == '(' - ? token.substr(StartTimeParamStart, parameters_end) - : ""; - // Validate the input specifier here. The formatted string may be destined for a header, and - // should not contain invalid characters {NUL, LR, CF}. - if (std::regex_search(args, getStartTimeNewlinePattern())) { - throw EnvoyException("Invalid header configuration. Format string contains newline."); - } - formatters.emplace_back(FormatterProviderPtr{new StartTimeFormatter(args)}); + formatters.emplace_back(FormatterProviderPtr{new StartTimeFormatter(token)}); + } else if (absl::StartsWith(token, "DOWNSTREAM_PEER_CERT_V_START")) { + formatters.emplace_back(FormatterProviderPtr{new DownstreamPeerCertVStartFormatter(token)}); + } else if (absl::StartsWith(token, "DOWNSTREAM_PEER_CERT_V_END")) { + formatters.emplace_back(FormatterProviderPtr{new DownstreamPeerCertVEndFormatter(token)}); } else if (absl::StartsWith(token, "GRPC_STATUS")) { formatters.emplace_back(FormatterProviderPtr{ new GrpcStatusFormatter("grpc-status", "", absl::optional())}); @@ -731,24 +724,6 @@ StreamInfoFormatter::StreamInfoFormatter(const std::string& field_name) { [](const Ssl::ConnectionInfo& connection_info) { return connection_info.urlEncodedPemEncodedPeerCertificate(); }); - } else if (field_name == "DOWNSTREAM_PEER_CERT_V_START") { - field_extractor_ = std::make_unique( - [](const Ssl::ConnectionInfo& connection_info) { - absl::optional time = connection_info.validFromPeerCertificate(); - if (!time.has_value()) { - return EMPTY_STRING; - } - return AccessLogDateTimeFormatter::fromTime(time.value()); - }); - } else if (field_name == "DOWNSTREAM_PEER_CERT_V_END") { - field_extractor_ = std::make_unique( - [](const Ssl::ConnectionInfo& connection_info) { - absl::optional time = connection_info.expirationPeerCertificate(); - if (!time.has_value()) { - return EMPTY_STRING; - } - return AccessLogDateTimeFormatter::fromTime(time.value()); - }); } else if (field_name == "UPSTREAM_TRANSPORT_FAILURE_REASON") { field_extractor_ = std::make_unique( [](const StreamInfo::StreamInfo& stream_info) { @@ -1093,26 +1068,84 @@ ProtobufWkt::Value FilterStateFormatter::formatValue(const Http::RequestHeaderMa return val; } -StartTimeFormatter::StartTimeFormatter(const std::string& format) : date_formatter_(format) {} +// Given a token, extract the command string between parenthesis if it exists. +std::string SystemTimeFormatter::parseFormat(const std::string& token, size_t parameters_start) { + const size_t parameters_length = token.length() - (parameters_start + 1); + return token[parameters_start - 1] == '(' ? token.substr(parameters_start, parameters_length) + : ""; +} -std::string StartTimeFormatter::format(const Http::RequestHeaderMap&, - const Http::ResponseHeaderMap&, - const Http::ResponseTrailerMap&, - const StreamInfo::StreamInfo& stream_info, - absl::string_view) const { +// A SystemTime formatter that extracts the startTime from StreamInfo. Must be provided +// an access log token that starts with `START_TIME`. +StartTimeFormatter::StartTimeFormatter(const std::string& token) + : SystemTimeFormatter( + parseFormat(token, sizeof("START_TIME(") - 1), + std::make_unique( + [](const StreamInfo::StreamInfo& stream_info) -> absl::optional { + return stream_info.startTime(); + })) {} + +// A SystemTime formatter that optionally extracts the start date from the downstream peer's +// certificate. Must be provided an access log token that starts with `DOWNSTREAM_PEER_CERT_V_START` +DownstreamPeerCertVStartFormatter::DownstreamPeerCertVStartFormatter(const std::string& token) + : SystemTimeFormatter( + parseFormat(token, sizeof("DOWNSTREAM_PEER_CERT_V_START(") - 1), + std::make_unique( + [](const StreamInfo::StreamInfo& stream_info) -> absl::optional { + const auto connection_info = stream_info.downstreamSslConnection(); + return connection_info != nullptr ? connection_info->validFromPeerCertificate() + : absl::optional(); + })) {} + +// A SystemTime formatter that optionally extracts the end date from the downstream peer's +// certificate. Must be provided an access log token that starts with `DOWNSTREAM_PEER_CERT_V_END` +DownstreamPeerCertVEndFormatter::DownstreamPeerCertVEndFormatter(const std::string& token) + : SystemTimeFormatter( + parseFormat(token, sizeof("DOWNSTREAM_PEER_CERT_V_END(") - 1), + std::make_unique( + [](const StreamInfo::StreamInfo& stream_info) -> absl::optional { + const auto connection_info = stream_info.downstreamSslConnection(); + return connection_info != nullptr ? connection_info->expirationPeerCertificate() + : absl::optional(); + })) {} + +SystemTimeFormatter::SystemTimeFormatter(const std::string& format, TimeFieldExtractorPtr f) + : date_formatter_(format), time_field_extractor_(std::move(f)) { + // Validate the input specifier here. The formatted string may be destined for a header, and + // should not contain invalid characters {NUL, LR, CF}. + if (std::regex_search(format, getSystemTimeFormatNewlinePattern())) { + throw EnvoyException("Invalid header configuration. Format string contains newline."); + } +} + +std::string SystemTimeFormatter::format(const Http::RequestHeaderMap&, + const Http::ResponseHeaderMap&, + const Http::ResponseTrailerMap&, + const StreamInfo::StreamInfo& stream_info, + absl::string_view) const { + const auto time_field = (*time_field_extractor_)(stream_info); + if (!time_field.has_value()) { + return UnspecifiedValueString; + } if (date_formatter_.formatString().empty()) { - return AccessLogDateTimeFormatter::fromTime(stream_info.startTime()); - } else { - return date_formatter_.fromTime(stream_info.startTime()); + return AccessLogDateTimeFormatter::fromTime(time_field.value()); } + return date_formatter_.fromTime(time_field.value()); } -ProtobufWkt::Value StartTimeFormatter::formatValue( - const Http::RequestHeaderMap& request_headers, const Http::ResponseHeaderMap& response_headers, - const Http::ResponseTrailerMap& response_trailers, const StreamInfo::StreamInfo& stream_info, - absl::string_view local_reply_body) const { - return ValueUtil::stringValue( - format(request_headers, response_headers, response_trailers, stream_info, local_reply_body)); +ProtobufWkt::Value SystemTimeFormatter::formatValue(const Http::RequestHeaderMap&, + const Http::ResponseHeaderMap&, + const Http::ResponseTrailerMap&, + const StreamInfo::StreamInfo& stream_info, + absl::string_view) const { + const auto time_field = (*time_field_extractor_)(stream_info); + if (!time_field.has_value()) { + return unspecifiedValue(); + } + if (date_formatter_.formatString().empty()) { + return ValueUtil::stringValue(AccessLogDateTimeFormatter::fromTime(time_field.value())); + } + return ValueUtil::stringValue(date_formatter_.fromTime(time_field.value())); } } // namespace Formatter diff --git a/source/common/formatter/substitution_formatter.h b/source/common/formatter/substitution_formatter.h index 00b4be31ac0d..22b12a599b1b 100644 --- a/source/common/formatter/substitution_formatter.h +++ b/source/common/formatter/substitution_formatter.h @@ -65,7 +65,6 @@ class SubstitutionFormatParser { static const size_t ReqParamStart{sizeof("REQ(") - 1}; static const size_t RespParamStart{sizeof("RESP(") - 1}; static const size_t TrailParamStart{sizeof("TRAILER(") - 1}; - static const size_t StartTimeParamStart{sizeof("START_TIME(") - 1}; }; /** @@ -337,11 +336,15 @@ class FilterStateFormatter : public FormatterProvider { }; /** - * FormatterProvider for request start time from StreamInfo. + * Base FormatterProvider for system times from StreamInfo. */ -class StartTimeFormatter : public FormatterProvider { +class SystemTimeFormatter : public FormatterProvider { public: - StartTimeFormatter(const std::string& format); + using TimeFieldExtractor = + std::function(const StreamInfo::StreamInfo& stream_info)>; + using TimeFieldExtractorPtr = std::unique_ptr; + + SystemTimeFormatter(const std::string& format, TimeFieldExtractorPtr f); // FormatterProvider std::string format(const Http::RequestHeaderMap&, const Http::ResponseHeaderMap&, @@ -351,8 +354,45 @@ class StartTimeFormatter : public FormatterProvider { const Http::ResponseTrailerMap&, const StreamInfo::StreamInfo&, absl::string_view) const override; +protected: + // Given an access log token, attempt to parse out the format string between parenthesis. + // + // @param token The access log token, e.g. `START_TIME` or `START_TIME(...)` + // @param parameters_start The index of the first character where the parameters parenthesis would + // begin if it exists. Must not be out of bounds of `token` or its NUL + // char. + // @return The format string between parenthesis, or an empty string if none exists. + static std::string parseFormat(const std::string& token, size_t parameters_start); + private: const Envoy::DateFormatter date_formatter_; + const TimeFieldExtractorPtr time_field_extractor_; +}; + +/** + * SystemTimeFormatter (FormatterProvider) for request start time from StreamInfo. + */ +class StartTimeFormatter : public SystemTimeFormatter { +public: + StartTimeFormatter(const std::string& format); +}; + +/** + * SystemTimeFormatter (FormatterProvider) for downstream cert start time from the StreamInfo's + * ConnectionInfo. + */ +class DownstreamPeerCertVStartFormatter : public SystemTimeFormatter { +public: + DownstreamPeerCertVStartFormatter(const std::string& format); +}; + +/** + * SystemTimeFormatter (FormatterProvider) for downstream cert end time from the StreamInfo's + * ConnectionInfo. + */ +class DownstreamPeerCertVEndFormatter : public SystemTimeFormatter { +public: + DownstreamPeerCertVEndFormatter(const std::string& format); }; } // namespace Formatter diff --git a/test/common/formatter/substitution_formatter_test.cc b/test/common/formatter/substitution_formatter_test.cc index b5caec7619ef..2001eda7956e 100644 --- a/test/common/formatter/substitution_formatter_test.cc +++ b/test/common/formatter/substitution_formatter_test.cc @@ -889,71 +889,6 @@ TEST(SubstitutionFormatterTest, streamInfoFormatter) { stream_info, body), ProtoEq(ValueUtil::nullValue())); } - { - StreamInfoFormatter upstream_format("DOWNSTREAM_PEER_CERT_V_START"); - auto connection_info = std::make_shared(); - absl::Time abslStartTime = - TestUtility::parseTime("Dec 18 01:50:34 2018 GMT", "%b %e %H:%M:%S %Y GMT"); - SystemTime startTime = absl::ToChronoTime(abslStartTime); - EXPECT_CALL(*connection_info, validFromPeerCertificate()).WillRepeatedly(Return(startTime)); - EXPECT_CALL(stream_info, downstreamSslConnection()).WillRepeatedly(Return(connection_info)); - EXPECT_EQ("2018-12-18T01:50:34.000Z", - upstream_format.format(request_headers, response_headers, response_trailers, - stream_info, body)); - } - { - StreamInfoFormatter upstream_format("DOWNSTREAM_PEER_CERT_V_START"); - auto connection_info = std::make_shared(); - EXPECT_CALL(*connection_info, validFromPeerCertificate()).WillRepeatedly(Return(absl::nullopt)); - EXPECT_CALL(stream_info, downstreamSslConnection()).WillRepeatedly(Return(connection_info)); - EXPECT_EQ("-", upstream_format.format(request_headers, response_headers, response_trailers, - stream_info, body)); - EXPECT_THAT(upstream_format.formatValue(request_headers, response_headers, response_trailers, - stream_info, body), - ProtoEq(ValueUtil::nullValue())); - } - { - EXPECT_CALL(stream_info, downstreamSslConnection()).WillRepeatedly(Return(nullptr)); - StreamInfoFormatter upstream_format("DOWNSTREAM_PEER_CERT_V_START"); - EXPECT_EQ("-", upstream_format.format(request_headers, response_headers, response_trailers, - stream_info, body)); - EXPECT_THAT(upstream_format.formatValue(request_headers, response_headers, response_trailers, - stream_info, body), - ProtoEq(ValueUtil::nullValue())); - } - { - StreamInfoFormatter upstream_format("DOWNSTREAM_PEER_CERT_V_END"); - auto connection_info = std::make_shared(); - absl::Time abslEndTime = - TestUtility::parseTime("Dec 17 01:50:34 2020 GMT", "%b %e %H:%M:%S %Y GMT"); - SystemTime endTime = absl::ToChronoTime(abslEndTime); - EXPECT_CALL(*connection_info, expirationPeerCertificate()).WillRepeatedly(Return(endTime)); - EXPECT_CALL(stream_info, downstreamSslConnection()).WillRepeatedly(Return(connection_info)); - EXPECT_EQ("2020-12-17T01:50:34.000Z", - upstream_format.format(request_headers, response_headers, response_trailers, - stream_info, body)); - } - { - StreamInfoFormatter upstream_format("DOWNSTREAM_PEER_CERT_V_END"); - auto connection_info = std::make_shared(); - EXPECT_CALL(*connection_info, expirationPeerCertificate()) - .WillRepeatedly(Return(absl::nullopt)); - EXPECT_CALL(stream_info, downstreamSslConnection()).WillRepeatedly(Return(connection_info)); - EXPECT_EQ("-", upstream_format.format(request_headers, response_headers, response_trailers, - stream_info, body)); - EXPECT_THAT(upstream_format.formatValue(request_headers, response_headers, response_trailers, - stream_info, body), - ProtoEq(ValueUtil::nullValue())); - } - { - EXPECT_CALL(stream_info, downstreamSslConnection()).WillRepeatedly(Return(nullptr)); - StreamInfoFormatter upstream_format("DOWNSTREAM_PEER_CERT_V_END"); - EXPECT_EQ("-", upstream_format.format(request_headers, response_headers, response_trailers, - stream_info, body)); - EXPECT_THAT(upstream_format.formatValue(request_headers, response_headers, response_trailers, - stream_info, body), - ProtoEq(ValueUtil::nullValue())); - } { StreamInfoFormatter upstream_format("UPSTREAM_TRANSPORT_FAILURE_REASON"); std::string upstream_transport_failure_reason = "SSL error"; @@ -1373,6 +1308,117 @@ TEST(SubstitutionFormatterTest, FilterStateFormatter) { } } +TEST(SubstitutionFormatterTest, DownstreamPeerCertVStartFormatter) { + NiceMock stream_info; + Http::TestRequestHeaderMapImpl request_headers{{":method", "GET"}, {":path", "/"}}; + Http::TestResponseHeaderMapImpl response_headers; + Http::TestResponseTrailerMapImpl response_trailers; + std::string body; + + // No downstreamSslConnection + { + EXPECT_CALL(stream_info, downstreamSslConnection()).WillRepeatedly(Return(nullptr)); + DownstreamPeerCertVStartFormatter cert_start_formart("DOWNSTREAM_PEER_CERT_V_START(%Y/%m/%d)"); + EXPECT_EQ("-", cert_start_formart.format(request_headers, response_headers, + response_trailers, stream_info, body)); + EXPECT_THAT(cert_start_formart.formatValue(request_headers, response_headers, response_trailers, + stream_info, body), + ProtoEq(ValueUtil::nullValue())); + } + // No validFromPeerCertificate + { + DownstreamPeerCertVStartFormatter cert_start_formart("DOWNSTREAM_PEER_CERT_V_START(%Y/%m/%d)"); + auto connection_info = std::make_shared(); + EXPECT_CALL(*connection_info, validFromPeerCertificate()).WillRepeatedly(Return(absl::nullopt)); + EXPECT_CALL(stream_info, downstreamSslConnection()).WillRepeatedly(Return(connection_info)); + EXPECT_EQ("-", cert_start_formart.format(request_headers, response_headers, + response_trailers, stream_info, body)); + EXPECT_THAT(cert_start_formart.formatValue(request_headers, response_headers, response_trailers, + stream_info, body), + ProtoEq(ValueUtil::nullValue())); + } + // Default format string + { + DownstreamPeerCertVStartFormatter cert_start_format("DOWNSTREAM_PEER_CERT_V_START"); + auto connection_info = std::make_shared(); + time_t test_epoch = 1522280158; + SystemTime time = std::chrono::system_clock::from_time_t(test_epoch); + EXPECT_CALL(*connection_info, validFromPeerCertificate()).WillRepeatedly(Return(time)); + EXPECT_CALL(stream_info, downstreamSslConnection()).WillRepeatedly(Return(connection_info)); + EXPECT_EQ(AccessLogDateTimeFormatter::fromTime(time), + cert_start_format.format(request_headers, response_headers, response_trailers, + stream_info, body)); + } + // Custom format string + { + DownstreamPeerCertVStartFormatter cert_start_format("DOWNSTREAM_PEER_CERT_V_START(%b %e %H:%M:%S %Y %Z)"); + auto connection_info = std::make_shared(); + time_t test_epoch = 1522280158; + SystemTime time = std::chrono::system_clock::from_time_t(test_epoch); + EXPECT_CALL(*connection_info, validFromPeerCertificate()).WillRepeatedly(Return(time)); + EXPECT_CALL(stream_info, downstreamSslConnection()).WillRepeatedly(Return(connection_info)); + EXPECT_EQ("Mar 28 23:35:58 2018 UTC", + cert_start_format.format(request_headers, response_headers, response_trailers, + stream_info, body)); + } +} + +TEST(SubstitutionFormatterTest, DownstreamPeerCertVEndFormatter) { + NiceMock stream_info; + Http::TestRequestHeaderMapImpl request_headers{{":method", "GET"}, {":path", "/"}}; + Http::TestResponseHeaderMapImpl response_headers; + Http::TestResponseTrailerMapImpl response_trailers; + std::string body; + + // No downstreamSslConnection + { + EXPECT_CALL(stream_info, downstreamSslConnection()).WillRepeatedly(Return(nullptr)); + DownstreamPeerCertVEndFormatter cert_end_format("DOWNSTREAM_PEER_CERT_V_END(%Y/%m/%d)"); + EXPECT_EQ("-", cert_end_format.format(request_headers, response_headers, + response_trailers, stream_info, body)); + EXPECT_THAT(cert_end_format.formatValue(request_headers, response_headers, response_trailers, + stream_info, body), + ProtoEq(ValueUtil::nullValue())); + } + // No expirationPeerCertificate + { + DownstreamPeerCertVEndFormatter cert_end_format("DOWNSTREAM_PEER_CERT_V_END(%Y/%m/%d)"); + auto connection_info = std::make_shared(); + EXPECT_CALL(*connection_info, expirationPeerCertificate()) + .WillRepeatedly(Return(absl::nullopt)); + EXPECT_CALL(stream_info, downstreamSslConnection()).WillRepeatedly(Return(connection_info)); + EXPECT_EQ("-", cert_end_format.format(request_headers, response_headers, + response_trailers, stream_info, body)); + EXPECT_THAT(cert_end_format.formatValue(request_headers, response_headers, response_trailers, + stream_info, body), + ProtoEq(ValueUtil::nullValue())); + } + // Default format string + { + DownstreamPeerCertVEndFormatter cert_end_format("DOWNSTREAM_PEER_CERT_V_END"); + auto connection_info = std::make_shared(); + time_t test_epoch = 1522280158; + SystemTime time = std::chrono::system_clock::from_time_t(test_epoch); + EXPECT_CALL(*connection_info, expirationPeerCertificate()).WillRepeatedly(Return(time)); + EXPECT_CALL(stream_info, downstreamSslConnection()).WillRepeatedly(Return(connection_info)); + EXPECT_EQ(AccessLogDateTimeFormatter::fromTime(time), + cert_end_format.format(request_headers, response_headers, response_trailers, + stream_info, body)); + } + // Custom format string + { + DownstreamPeerCertVEndFormatter cert_end_format("DOWNSTREAM_PEER_CERT_V_END(%b %e %H:%M:%S %Y %Z)"); + auto connection_info = std::make_shared(); + time_t test_epoch = 1522280158; + SystemTime time = std::chrono::system_clock::from_time_t(test_epoch); + EXPECT_CALL(*connection_info, expirationPeerCertificate()).WillRepeatedly(Return(time)); + EXPECT_CALL(stream_info, downstreamSslConnection()).WillRepeatedly(Return(connection_info)); + EXPECT_EQ("Mar 28 23:35:58 2018 UTC", + cert_end_format.format(request_headers, response_headers, response_trailers, + stream_info, body)); + } +} + TEST(SubstitutionFormatterTest, StartTimeFormatter) { NiceMock stream_info; Http::TestRequestHeaderMapImpl request_headers{{":method", "GET"}, {":path", "/"}}; @@ -1381,7 +1427,7 @@ TEST(SubstitutionFormatterTest, StartTimeFormatter) { std::string body; { - StartTimeFormatter start_time_format("%Y/%m/%d"); + StartTimeFormatter start_time_format("START_TIME(%Y/%m/%d)"); time_t test_epoch = 1522280158; SystemTime time = std::chrono::system_clock::from_time_t(test_epoch); EXPECT_CALL(stream_info, startTime()).WillRepeatedly(Return(time)); @@ -1393,7 +1439,7 @@ TEST(SubstitutionFormatterTest, StartTimeFormatter) { } { - StartTimeFormatter start_time_format(""); + StartTimeFormatter start_time_format("START_TIME"); SystemTime time; EXPECT_CALL(stream_info, startTime()).WillRepeatedly(Return(time)); EXPECT_EQ(AccessLogDateTimeFormatter::fromTime(time),