From 453b51138c5e23e2072297b6a2cb85d74c4d39c7 Mon Sep 17 00:00:00 2001 From: ccaraman Date: Wed, 11 Jan 2017 13:54:25 -0800 Subject: [PATCH] Log rate limited requests with new response flag. (#346) --- docs/configuration/http_conn_man/access_log.rst | 1 + include/envoy/http/access_log.h | 4 +++- source/common/http/access_log/access_log_formatter.cc | 5 +++++ source/common/http/access_log/access_log_formatter.h | 1 + source/common/http/filter/ratelimit.cc | 1 + test/common/http/access_log/access_log_formatter_test.cc | 3 ++- test/common/http/filter/ratelimit_test.cc | 7 +++++++ 7 files changed, 20 insertions(+), 2 deletions(-) diff --git a/docs/configuration/http_conn_man/access_log.rst b/docs/configuration/http_conn_man/access_log.rst index 31577321594c..5fe87f181ec2 100644 --- a/docs/configuration/http_conn_man/access_log.rst +++ b/docs/configuration/http_conn_man/access_log.rst @@ -85,6 +85,7 @@ The following command operators are supported: * **NR**: No :ref:`route configured ` for a given request in addition to 404 response code. * **DI**: The request processing was delayed for a period specified via :ref:`fault injection `. * **FI**: The request was aborted with a response code specified via :ref:`fault injection `. + * **RL**: The request was ratelimited locally by the :ref:`HTTP rate limit filter ` in addition to 429 response code. %UPSTREAM_HOST% Upstream host URL (e.g., tcp://ip:port for TCP connections). diff --git a/include/envoy/http/access_log.h b/include/envoy/http/access_log.h index 407d1933b98c..d136ef6053b5 100644 --- a/include/envoy/http/access_log.h +++ b/include/envoy/http/access_log.h @@ -32,7 +32,9 @@ enum ResponseFlag { // Request was delayed before proxying. DelayInjected = 0x200, // Abort with error code was injected. - FaultInjected = 0x400 + FaultInjected = 0x400, + // Request was ratelimited locally by rate limit filter. + RateLimited = 0x800 }; /** diff --git a/source/common/http/access_log/access_log_formatter.cc b/source/common/http/access_log/access_log_formatter.cc index 14396d895878..f6d00f7005d0 100644 --- a/source/common/http/access_log/access_log_formatter.cc +++ b/source/common/http/access_log/access_log_formatter.cc @@ -18,6 +18,7 @@ const std::string ResponseFlagUtils::UPSTREAM_OVERFLOW = "UO"; const std::string ResponseFlagUtils::NO_ROUTE_FOUND = "NR"; const std::string ResponseFlagUtils::DELAY_INJECTED = "DI"; const std::string ResponseFlagUtils::FAULT_INJECTED = "FI"; +const std::string ResponseFlagUtils::RATE_LIMITED = "RL"; void ResponseFlagUtils::appendString(std::string& result, const std::string& append) { if (result.empty()) { @@ -74,6 +75,10 @@ const std::string ResponseFlagUtils::toShortString(const RequestInfo& request_in appendString(result, FAULT_INJECTED); } + if (request_info.getResponseFlag(ResponseFlag::RateLimited)) { + appendString(result, RATE_LIMITED); + } + return result.empty() ? NONE : result; } diff --git a/source/common/http/access_log/access_log_formatter.h b/source/common/http/access_log/access_log_formatter.h index 36cf7a75000f..803a9b8433df 100644 --- a/source/common/http/access_log/access_log_formatter.h +++ b/source/common/http/access_log/access_log_formatter.h @@ -29,6 +29,7 @@ class ResponseFlagUtils { const static std::string NO_ROUTE_FOUND; const static std::string DELAY_INJECTED; const static std::string FAULT_INJECTED; + const static std::string RATE_LIMITED; }; /** diff --git a/source/common/http/filter/ratelimit.cc b/source/common/http/filter/ratelimit.cc index bbcf02c4d7c4..d567fefa1b00 100644 --- a/source/common/http/filter/ratelimit.cc +++ b/source/common/http/filter/ratelimit.cc @@ -94,6 +94,7 @@ void Filter::complete(::RateLimit::LimitStatus status) { state_ = State::Responded; Http::HeaderMapPtr response_headers{new HeaderMapImpl(*TOO_MANY_REQUESTS_HEADER)}; callbacks_->encodeHeaders(std::move(response_headers), true); + callbacks_->requestInfo().setResponseFlag(Http::AccessLog::ResponseFlag::RateLimited); } else if (!initiating_call_) { callbacks_->continueDecoding(); } diff --git a/test/common/http/access_log/access_log_formatter_test.cc b/test/common/http/access_log/access_log_formatter_test.cc index 48b7dda7ee02..fbb51b34f01c 100644 --- a/test/common/http/access_log/access_log_formatter_test.cc +++ b/test/common/http/access_log/access_log_formatter_test.cc @@ -25,7 +25,8 @@ TEST(ResponseFlagUtilsTest, toShortStringConversion) { std::make_pair(ResponseFlag::UpstreamOverflow, "UO"), std::make_pair(ResponseFlag::NoRouteFound, "NR"), std::make_pair(ResponseFlag::DelayInjected, "DI"), - std::make_pair(ResponseFlag::FaultInjected, "FI")}; + std::make_pair(ResponseFlag::FaultInjected, "FI"), + std::make_pair(ResponseFlag::RateLimited, "RL")}; for (const auto& testCase : expected) { NiceMock request_info; diff --git a/test/common/http/filter/ratelimit_test.cc b/test/common/http/filter/ratelimit_test.cc index 35f6accd8be0..f4b4c29931be 100644 --- a/test/common/http/filter/ratelimit_test.cc +++ b/test/common/http/filter/ratelimit_test.cc @@ -137,6 +137,8 @@ TEST_F(HttpRateLimitFilterTest, OkResponse) { EXPECT_EQ(FilterTrailersStatus::StopIteration, filter_->decodeTrailers(request_headers_)); EXPECT_CALL(filter_callbacks_, continueDecoding()); + EXPECT_CALL(filter_callbacks_.request_info_, + setResponseFlag(Http::AccessLog::ResponseFlag::RateLimited)).Times(0); request_callbacks_->complete(::RateLimit::LimitStatus::OK); EXPECT_EQ(1U, cm_.cluster_.info_->stats_store_.counter("ratelimit.ok").value()); @@ -180,6 +182,8 @@ TEST_F(HttpRateLimitFilterTest, ErrorResponse) { EXPECT_EQ(FilterDataStatus::Continue, filter_->decodeData(data_, false)); EXPECT_EQ(FilterTrailersStatus::Continue, filter_->decodeTrailers(request_headers_)); + EXPECT_CALL(filter_callbacks_.request_info_, + setResponseFlag(Http::AccessLog::ResponseFlag::RateLimited)).Times(0); EXPECT_EQ(1U, cm_.cluster_.info_->stats_store_.counter("ratelimit.error").value()); } @@ -199,6 +203,9 @@ TEST_F(HttpRateLimitFilterTest, LimitResponse) { Http::TestHeaderMapImpl response_headers{{":status", "429"}}; EXPECT_CALL(filter_callbacks_, encodeHeaders_(HeaderMapEqualRef(&response_headers), true)); EXPECT_CALL(filter_callbacks_, continueDecoding()).Times(0); + EXPECT_CALL(filter_callbacks_.request_info_, + setResponseFlag(Http::AccessLog::ResponseFlag::RateLimited)); + request_callbacks_->complete(::RateLimit::LimitStatus::OverLimit); EXPECT_EQ(1U, cm_.cluster_.info_->stats_store_.counter("ratelimit.over_limit").value());