From 04bd69e13db23ac6b0dbeb9f215fffdb163bdc01 Mon Sep 17 00:00:00 2001 From: Przemyslaw Gomulka Date: Tue, 25 Jan 2022 10:59:49 +0100 Subject: [PATCH] Do no use x-opaque-id for deduplicating elastic originating requests backport (#82855) deprecated log messages originating from any elastic product requests should not be deduplicated with the use of x-opaque-id. If present, the value of X-elastic-product-origin will be used as part of the throttling key. relates #82810 --- docs/changelog/82855.yaml | 5 ++ .../common/logging/RateLimitingFilter.java | 12 +++-- .../logging/RateLimitingFilterTests.java | 50 ++++++++++++++----- 3 files changed, 52 insertions(+), 15 deletions(-) create mode 100644 docs/changelog/82855.yaml diff --git a/docs/changelog/82855.yaml b/docs/changelog/82855.yaml new file mode 100644 index 0000000000000..6d5fc07abd889 --- /dev/null +++ b/docs/changelog/82855.yaml @@ -0,0 +1,5 @@ +pr: 82855 +summary: Do no use x-opaque-id for deduplicating elastic originating requests +area: Infra/Logging +type: enhancement +issues: [] diff --git a/server/src/main/java/org/elasticsearch/common/logging/RateLimitingFilter.java b/server/src/main/java/org/elasticsearch/common/logging/RateLimitingFilter.java index 4a034fb474dd0..2c9576fbe1271 100644 --- a/server/src/main/java/org/elasticsearch/common/logging/RateLimitingFilter.java +++ b/server/src/main/java/org/elasticsearch/common/logging/RateLimitingFilter.java @@ -19,12 +19,14 @@ import org.apache.logging.log4j.core.config.plugins.PluginFactory; import org.apache.logging.log4j.core.filter.AbstractFilter; import org.apache.logging.log4j.message.Message; +import org.elasticsearch.common.Strings; import java.util.Collections; import java.util.LinkedHashMap; import java.util.Map; import java.util.Set; +import static org.elasticsearch.common.logging.DeprecatedMessage.ELASTIC_ORIGIN_FIELD_NAME; import static org.elasticsearch.common.logging.DeprecatedMessage.KEY_FIELD_NAME; import static org.elasticsearch.common.logging.DeprecatedMessage.X_OPAQUE_ID_FIELD_NAME; @@ -34,13 +36,14 @@ * passed by a user on a HTTP header. * This filter works by using a lruKeyCache - a set of keys which prevents a second message with the same key to be logged. * The lruKeyCache has a size limited to 128, which when breached will remove the oldest entries. - * + *

* It is possible to disable use of `x-opaque-id` as a key with {@link RateLimitingFilter#setUseXOpaqueId(boolean) } + * * @see Log4j2 Filters */ @Plugin(name = "RateLimitingFilter", category = Node.CATEGORY, elementType = Filter.ELEMENT_TYPE) public class RateLimitingFilter extends AbstractFilter { - + // a flag to disable/enable use of xOpaqueId controlled by changing cluster setting private volatile boolean useXOpaqueId = true; private final Set lruKeyCache = Collections.newSetFromMap(Collections.synchronizedMap(new LinkedHashMap() { @@ -71,7 +74,6 @@ public Result filter(Message message) { final String key = getKey(esLogMessage); return lruKeyCache.add(key) ? Result.ACCEPT : Result.DENY; - } else { return Result.NEUTRAL; } @@ -79,6 +81,10 @@ public Result filter(Message message) { private String getKey(ESLogMessage esLogMessage) { final String key = esLogMessage.getValueFor(KEY_FIELD_NAME); + final String productOrigin = esLogMessage.getValueFor(ELASTIC_ORIGIN_FIELD_NAME); + if (Strings.isNullOrEmpty(productOrigin) == false) { + return productOrigin + key; + } if (useXOpaqueId) { String xOpaqueId = esLogMessage.getValueFor(X_OPAQUE_ID_FIELD_NAME); return xOpaqueId + key; diff --git a/server/src/test/java/org/elasticsearch/common/logging/RateLimitingFilterTests.java b/server/src/test/java/org/elasticsearch/common/logging/RateLimitingFilterTests.java index 6577ea665c4b6..4fce23127c031 100644 --- a/server/src/test/java/org/elasticsearch/common/logging/RateLimitingFilterTests.java +++ b/server/src/test/java/org/elasticsearch/common/logging/RateLimitingFilterTests.java @@ -84,20 +84,20 @@ public void testMessagesAreRateLimitedByXOpaqueId() { public void testMessagesAreRateLimitedByKeyAndXOpaqueId() { // Fill up the cache for (int i = 0; i < 128; i++) { - Message message = new DeprecatedMessage(DeprecationCategory.OTHER, "key " + i, "opaque-id " + i, "productName", "msg " + i); + Message message = new DeprecatedMessage(DeprecationCategory.OTHER, "key " + i, "opaque-id " + i, null, "msg " + i); assertThat("Expected key" + i + " to be accepted", filter.filter(message), equalTo(Result.ACCEPT)); } // Should be rate-limited because it's still in the cache - Message message = new DeprecatedMessage(DeprecationCategory.OTHER, "key 0", "opaque-id 0", "productName", "msg 0"); + Message message = new DeprecatedMessage(DeprecationCategory.OTHER, "key 0", "opaque-id 0", null, "msg 0"); assertThat(filter.filter(message), equalTo(Result.DENY)); // Filter a message with a previously unseen key, in order to evict key0 as it's the oldest - message = new DeprecatedMessage(DeprecationCategory.OTHER, "key 129", "opaque-id 129", "productName", "msg 129"); + message = new DeprecatedMessage(DeprecationCategory.OTHER, "key 129", "opaque-id 129", null, "msg 129"); assertThat(filter.filter(message), equalTo(Result.ACCEPT)); // Should be allowed because key 0 was evicted from the cache - message = new DeprecatedMessage(DeprecationCategory.OTHER, "key 0", "opaque-id 0", "productName", "msg 0"); + message = new DeprecatedMessage(DeprecationCategory.OTHER, "key 0", "opaque-id 0", null, "msg 0"); assertThat(filter.filter(message), equalTo(Result.ACCEPT)); } @@ -106,18 +106,18 @@ public void testMessagesAreRateLimitedByKeyAndXOpaqueId() { * independently and checking that a message is not filtered. */ public void testVariationsInKeyAndXOpaqueId() { - Message message = new DeprecatedMessage(DeprecationCategory.OTHER, "key 0", "opaque-id 0", "productName", "msg 0"); + Message message = new DeprecatedMessage(DeprecationCategory.OTHER, "key 0", "opaque-id 0", null, "msg 0"); assertThat(filter.filter(message), equalTo(Result.ACCEPT)); - message = new DeprecatedMessage(DeprecationCategory.OTHER, "key 0", "opaque-id 0", "productName", "msg 0"); + message = new DeprecatedMessage(DeprecationCategory.OTHER, "key 0", "opaque-id 0", null, "msg 0"); // Rejected because the "x-opaque-id" and "key" values are the same as above assertThat(filter.filter(message), equalTo(Result.DENY)); - message = new DeprecatedMessage(DeprecationCategory.OTHER, "key 1", "opaque-id 0", "productName", "msg 0"); + message = new DeprecatedMessage(DeprecationCategory.OTHER, "key 1", "opaque-id 0", null, "msg 0"); // Accepted because the "key" value is different assertThat(filter.filter(message), equalTo(Result.ACCEPT)); - message = new DeprecatedMessage(DeprecationCategory.OTHER, "key 0", "opaque-id 1", "productName", "msg 0"); + message = new DeprecatedMessage(DeprecationCategory.OTHER, "key 0", "opaque-id 1", null, "msg 0"); // Accepted because the "x-opaque-id" value is different assertThat(filter.filter(message), equalTo(Result.ACCEPT)); } @@ -154,19 +154,45 @@ public void testMessagesXOpaqueIsIgnoredWhenDisabled() { filter.start(); // Should NOT be rate-limited because it's not in the cache - Message message = new DeprecatedMessage(DeprecationCategory.OTHER, "key 0", "opaque-id 0", "productName", "msg 0"); + Message message = new DeprecatedMessage(DeprecationCategory.OTHER, "key 0", "opaque-id 0", null, "msg 0"); assertThat(filter.filter(message), equalTo(Result.ACCEPT)); // Should be rate-limited because it was just added to the cache - message = new DeprecatedMessage(DeprecationCategory.OTHER, "key 0", "opaque-id 0", "productName", "msg 0"); + message = new DeprecatedMessage(DeprecationCategory.OTHER, "key 0", "opaque-id 0", null, "msg 0"); assertThat(filter.filter(message), equalTo(Result.DENY)); // Should be rate-limited because X-Opaque-Id is not used - message = new DeprecatedMessage(DeprecationCategory.OTHER, "key 0", "opaque-id 1", "productName", "msg 0"); + message = new DeprecatedMessage(DeprecationCategory.OTHER, "key 0", "opaque-id 1", null, "msg 0"); assertThat(filter.filter(message), equalTo(Result.DENY)); // Should NOT be rate-limited because "key 1" it not in the cache - message = new DeprecatedMessage(DeprecationCategory.OTHER, "key 1", "opaque-id 1", "productName", "msg 0"); + message = new DeprecatedMessage(DeprecationCategory.OTHER, "key 1", "opaque-id 1", null, "msg 0"); + assertThat(filter.filter(message), equalTo(Result.ACCEPT)); + } + + public void testXOpaqueIdNotBeingUsedFromElasticOriginatingRequests() { + RateLimitingFilter filter = new RateLimitingFilter(); + filter.setUseXOpaqueId(true); + filter.start(); + + // Should NOT be rate-limited because it's not in the cache + Message message = new DeprecatedMessage(DeprecationCategory.OTHER, "key", "opaque-id 0", "kibana", "msg 0"); + assertThat(filter.filter(message), equalTo(Result.ACCEPT)); + + // Should be rate-limited even though the x-opaque-id is unique because it originates from kibana + message = new DeprecatedMessage(DeprecationCategory.OTHER, "key", "opaque-id 1", "kibana", "msg 0"); + assertThat(filter.filter(message), equalTo(Result.DENY)); + + // Should not be rate-limited - it is the first request from beats. (x-opaque-id ignored as it originates from elastic) + message = new DeprecatedMessage(DeprecationCategory.OTHER, "key", "opaque-id 0", "beats", "msg 0"); + assertThat(filter.filter(message), equalTo(Result.ACCEPT)); + + // second request from beats (elastic originating), should be rate-limited + message = new DeprecatedMessage(DeprecationCategory.OTHER, "key", "opaque-id 1", "beats", "msg 0"); + assertThat(filter.filter(message), equalTo(Result.DENY)); + + // request from beats (elastic originating), but with a different key- should not be rate-limited + message = new DeprecatedMessage(DeprecationCategory.OTHER, "key2", "opaque-id 1", "beats", "msg 1"); assertThat(filter.filter(message), equalTo(Result.ACCEPT)); } }