From cc437bd03098c380f5b40eeba03a1443809c5209 Mon Sep 17 00:00:00 2001 From: tyxia Date: Wed, 28 Feb 2024 03:52:53 +0000 Subject: [PATCH 1/4] rlqs: add logging around token bucket Signed-off-by: tyxia --- .../filters/http/rate_limit_quota/client_impl.cc | 10 +++++++--- .../extensions/filters/http/rate_limit_quota/filter.cc | 2 ++ 2 files changed, 9 insertions(+), 3 deletions(-) diff --git a/source/extensions/filters/http/rate_limit_quota/client_impl.cc b/source/extensions/filters/http/rate_limit_quota/client_impl.cc index 62154c371de0..f1d959c2115f 100644 --- a/source/extensions/filters/http/rate_limit_quota/client_impl.cc +++ b/source/extensions/filters/http/rate_limit_quota/client_impl.cc @@ -98,9 +98,13 @@ void RateLimitClientImpl::onReceiveMessage(RateLimitQuotaResponsePtr&& response) double fill_rate_per_sec = static_cast(rate_limit_strategy.token_bucket().tokens_per_fill().value()) / fill_interval_sec; - - quota_buckets_[bucket_id]->token_bucket_limiter = std::make_unique( - rate_limit_strategy.token_bucket().max_tokens(), time_source_, fill_rate_per_sec); + uint32_t max_tokens = rate_limit_strategy.token_bucket().max_tokens(); + ENVOY_LOG(trace, + "Create the token bucket limiter with max_tokens: {}; " + "fill_interval_sec: {}; fill_rate_per_sec: {}", + max_tokens, fill_interval_sec, fill_rate_per_sec); + quota_buckets_[bucket_id]->token_bucket_limiter = + std::make_unique(max_tokens, time_source_, fill_rate_per_sec); } } } diff --git a/source/extensions/filters/http/rate_limit_quota/filter.cc b/source/extensions/filters/http/rate_limit_quota/filter.cc index 48dc20ee61e1..67787a26cf4f 100644 --- a/source/extensions/filters/http/rate_limit_quota/filter.cc +++ b/source/extensions/filters/http/rate_limit_quota/filter.cc @@ -190,9 +190,11 @@ Http::FilterHeadersStatus RateLimitQuotaFilter::processCachedBucket(size_t bucke if (limiter->consume(1, /*allow_partial=*/false)) { // Request is allowed. quota_buckets_[bucket_id]->quota_usage.num_requests_allowed += 1; + ENVOY_LOG(trace, "Request is allowed by token bucket limiter"); } else { // Request is throttled. quota_buckets_[bucket_id]->quota_usage.num_requests_denied += 1; + ENVOY_LOG(trace, "Request is throttled by token bucket limiter"); // TODO(tyxia) Build the customized response based on `DenyResponseSettings` if it is // configured. callbacks_->sendLocalReply(Envoy::Http::Code::TooManyRequests, "", nullptr, absl::nullopt, From a2b01f7686b5110e78bf550b5ca6f4b1ab2c64d1 Mon Sep 17 00:00:00 2001 From: tyxia Date: Mon, 4 Mar 2024 15:31:26 +0000 Subject: [PATCH 2/4] update Signed-off-by: tyxia --- .../filters/http/rate_limit_quota/client_impl.cc | 15 ++++++++++----- .../filters/http/rate_limit_quota/filter.cc | 8 ++++++-- 2 files changed, 16 insertions(+), 7 deletions(-) diff --git a/source/extensions/filters/http/rate_limit_quota/client_impl.cc b/source/extensions/filters/http/rate_limit_quota/client_impl.cc index f1d959c2115f..04d8d9e17e59 100644 --- a/source/extensions/filters/http/rate_limit_quota/client_impl.cc +++ b/source/extensions/filters/http/rate_limit_quota/client_impl.cc @@ -76,10 +76,14 @@ void RateLimitClientImpl::onReceiveMessage(RateLimitQuotaResponsePtr&& response) // Get the hash id value from BucketId in the response. const size_t bucket_id = MessageUtil::hash(action.bucket_id()); + ENVOY_LOG(trace, + "Received a response for bucket id proto :\n {}, and generated " + "the associated hashed bucket id: {}", + action.bucket_id().DebugString(), bucket_id); if (quota_buckets_.find(bucket_id) == quota_buckets_.end()) { // The response should be matched to the report we sent. ENVOY_LOG(error, - "Received a response, but but it is not matched any quota " + "The received response is not matched any quota " "cache entry: ", response->ShortDebugString()); } else { @@ -99,10 +103,11 @@ void RateLimitClientImpl::onReceiveMessage(RateLimitQuotaResponsePtr&& response) static_cast(rate_limit_strategy.token_bucket().tokens_per_fill().value()) / fill_interval_sec; uint32_t max_tokens = rate_limit_strategy.token_bucket().max_tokens(); - ENVOY_LOG(trace, - "Create the token bucket limiter with max_tokens: {}; " - "fill_interval_sec: {}; fill_rate_per_sec: {}", - max_tokens, fill_interval_sec, fill_rate_per_sec); + ENVOY_LOG( + trace, + "Create the token bucket limiter for hashed bucket id: {}, with max_tokens: {}; " + "fill_interval_sec: {}; fill_rate_per_sec: {}.", + bucket_id, max_tokens, fill_interval_sec, fill_rate_per_sec); quota_buckets_[bucket_id]->token_bucket_limiter = std::make_unique(max_tokens, time_source_, fill_rate_per_sec); } diff --git a/source/extensions/filters/http/rate_limit_quota/filter.cc b/source/extensions/filters/http/rate_limit_quota/filter.cc index 67787a26cf4f..ec83101c8ea2 100644 --- a/source/extensions/filters/http/rate_limit_quota/filter.cc +++ b/source/extensions/filters/http/rate_limit_quota/filter.cc @@ -38,6 +38,8 @@ Http::FilterHeadersStatus RateLimitQuotaFilter::decodeHeaders(Http::RequestHeade BucketId bucket_id_proto = ret.value(); const size_t bucket_id = MessageUtil::hash(bucket_id_proto); + ENVOY_LOG(trace, "Generated the associated hashed bucket id: {} for bucket id proto:\n {}", + bucket_id, bucket_id_proto.DebugString()); if (quota_buckets_.find(bucket_id) == quota_buckets_.end()) { // For first matched request, create a new bucket in the cache and sent the report to RLQS // server immediately. @@ -190,11 +192,13 @@ Http::FilterHeadersStatus RateLimitQuotaFilter::processCachedBucket(size_t bucke if (limiter->consume(1, /*allow_partial=*/false)) { // Request is allowed. quota_buckets_[bucket_id]->quota_usage.num_requests_allowed += 1; - ENVOY_LOG(trace, "Request is allowed by token bucket limiter"); + ENVOY_LOG(trace, "Request with hashed bucket_id {} is allowed by token bucket limiter.", + bucket_id); } else { // Request is throttled. quota_buckets_[bucket_id]->quota_usage.num_requests_denied += 1; - ENVOY_LOG(trace, "Request is throttled by token bucket limiter"); + ENVOY_LOG(trace, "Request with hashed bucket_id {} is throttled by token bucket limiter", + bucket_id); // TODO(tyxia) Build the customized response based on `DenyResponseSettings` if it is // configured. callbacks_->sendLocalReply(Envoy::Http::Code::TooManyRequests, "", nullptr, absl::nullopt, From cf299c552f5bf09a5e72dc8ae587b79a3626a726 Mon Sep 17 00:00:00 2001 From: tyxia Date: Mon, 4 Mar 2024 15:32:48 +0000 Subject: [PATCH 3/4] typo Signed-off-by: tyxia --- .../extensions/filters/http/rate_limit_quota/client_impl.cc | 4 +--- 1 file changed, 1 insertion(+), 3 deletions(-) diff --git a/source/extensions/filters/http/rate_limit_quota/client_impl.cc b/source/extensions/filters/http/rate_limit_quota/client_impl.cc index 04d8d9e17e59..2f998ec615a2 100644 --- a/source/extensions/filters/http/rate_limit_quota/client_impl.cc +++ b/source/extensions/filters/http/rate_limit_quota/client_impl.cc @@ -82,9 +82,7 @@ void RateLimitClientImpl::onReceiveMessage(RateLimitQuotaResponsePtr&& response) action.bucket_id().DebugString(), bucket_id); if (quota_buckets_.find(bucket_id) == quota_buckets_.end()) { // The response should be matched to the report we sent. - ENVOY_LOG(error, - "The received response is not matched any quota " - "cache entry: ", + ENVOY_LOG(error, "The received response is not matched to any quota cache entry: ", response->ShortDebugString()); } else { quota_buckets_[bucket_id]->bucket_action = action; From c7f875b42bc87e3cb229fdc859001ef7b214e1ad Mon Sep 17 00:00:00 2001 From: tyxia Date: Mon, 4 Mar 2024 15:33:52 +0000 Subject: [PATCH 4/4] typo Signed-off-by: tyxia --- source/extensions/filters/http/rate_limit_quota/client_impl.cc | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/source/extensions/filters/http/rate_limit_quota/client_impl.cc b/source/extensions/filters/http/rate_limit_quota/client_impl.cc index 2f998ec615a2..6dbfecacb55b 100644 --- a/source/extensions/filters/http/rate_limit_quota/client_impl.cc +++ b/source/extensions/filters/http/rate_limit_quota/client_impl.cc @@ -103,7 +103,7 @@ void RateLimitClientImpl::onReceiveMessage(RateLimitQuotaResponsePtr&& response) uint32_t max_tokens = rate_limit_strategy.token_bucket().max_tokens(); ENVOY_LOG( trace, - "Create the token bucket limiter for hashed bucket id: {}, with max_tokens: {}; " + "Created the token bucket limiter for hashed bucket id: {}, with max_tokens: {}; " "fill_interval_sec: {}; fill_rate_per_sec: {}.", bucket_id, max_tokens, fill_interval_sec, fill_rate_per_sec); quota_buckets_[bucket_id]->token_bucket_limiter =