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

Setting to disable x-opaque-id in logs throttling #78911

Merged
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
11 changes: 11 additions & 0 deletions docs/reference/setup/logging-config.asciidoc
Original file line number Diff line number Diff line change
Expand Up @@ -234,6 +234,17 @@ The user ID is included in the `X-Opaque-ID` field in deprecation JSON logs.
---------------------------
// NOTCONSOLE

Deprecation logs can be indexed into `.logs-deprecation.elasticsearch-default` data stream
`cluster.deprecation_indexing.enabled` setting is set to true.

==== Deprecation logs throttling
Deprecation logs are deduplicated based on a deprecated feature key
and x-opaque-id so that if a feature is repeatedly used, it will not overload the deprecation logs.
This applies to both indexed deprecation logs and logs emitted to log files.
You can disable the use of `x-opaque-id` in throttling by changing
`cluster.deprecation_indexing.x_opaque_id_used.enabled` to false
See link:./server/src/main/java/org/elasticsearch/common/logging/RateLimitingFilter.java[RateLimitingFilter]
Copy link
Contributor

Choose a reason for hiding this comment

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

I'm not sure we should be linked to the source code. It implies we can't or don't want to explain what's going on. cc @jrodewig for his input.

Also, can we link x-opaque-id to something descriptive?

Copy link
Contributor Author

@pgomulka pgomulka Oct 11, 2021

Choose a reason for hiding this comment

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

I thought I will link to a javadoc for more low level internals documentation.


[discrete]
[[json-logging]]
=== JSON log format
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -28,9 +28,21 @@
import static org.elasticsearch.common.logging.DeprecatedMessage.KEY_FIELD_NAME;
import static org.elasticsearch.common.logging.DeprecatedMessage.X_OPAQUE_ID_FIELD_NAME;

/**
* A filter used for throttling deprecation logs.
* A throttling is based on a combined key which consists of `key` from the logged ESMessage and `x-opaque-id`
* 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.
pugnascotia marked this conversation as resolved.
Show resolved Hide resolved
*
* It is possible to disable use of `x-opaque-id` as a key with {@link RateLimitingFilter#setUseXOpaqueId(boolean) }
* @see <a href="https://logging.apache.org/log4j/2.x/manual/filters.htmlf">Log4j2 Filters</a>
*/
@Plugin(name = "RateLimitingFilter", category = Node.CATEGORY, elementType = Filter.ELEMENT_TYPE)
public class RateLimitingFilter extends AbstractFilter {

private volatile boolean useXOpaqueId = true;

private final Set<String> lruKeyCache = Collections.newSetFromMap(Collections.synchronizedMap(new LinkedHashMap<>() {
@Override
protected boolean removeEldestEntry(final Map.Entry<String, Boolean> eldest) {
Expand All @@ -57,16 +69,23 @@ public Result filter(Message message) {
if (message instanceof ESLogMessage) {
final ESLogMessage esLogMessage = (ESLogMessage) message;

String xOpaqueId = esLogMessage.get(X_OPAQUE_ID_FIELD_NAME);
final String key = esLogMessage.get(KEY_FIELD_NAME);

return lruKeyCache.add(xOpaqueId + key) ? Result.ACCEPT : Result.DENY;
final String key = getKey(esLogMessage);
return lruKeyCache.add(key) ? Result.ACCEPT : Result.DENY;

} else {
return Result.NEUTRAL;
}
}

private String getKey(ESLogMessage esLogMessage) {
final String key = esLogMessage.get(KEY_FIELD_NAME);
if (useXOpaqueId) {
String xOpaqueId = esLogMessage.get(X_OPAQUE_ID_FIELD_NAME);
return xOpaqueId + key;
}
return key;
}

@Override
public Result filter(LogEvent event) {
return filter(event.getMessage());
Expand All @@ -84,4 +103,8 @@ public static RateLimitingFilter createFilter(
) {
return new RateLimitingFilter(match, mismatch);
}

public void setUseXOpaqueId(boolean useXOpaqueId) {
this.useXOpaqueId = useXOpaqueId;
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -147,4 +147,26 @@ public void testFilterCanBeReset() {
// Third time, it is allowed again
assertThat(filter.filter(message), equalTo(Result.ACCEPT));
}

public void testMessagesXOpaqueIsIgnoredWhenDisabled() {
RateLimitingFilter filter = new RateLimitingFilter();
filter.setUseXOpaqueId(false);
filter.start();

// Should NOT be rate-limited because it's not in the cache
Message message = DeprecatedMessage.of(DeprecationCategory.OTHER, "key 0", "opaque-id 0", "msg 0");
assertThat(filter.filter(message), equalTo(Result.ACCEPT));

// Should be rate-limited because it was just added to the cache
message = DeprecatedMessage.of(DeprecationCategory.OTHER, "key 0", "opaque-id 0", "msg 0");
assertThat(filter.filter(message), equalTo(Result.DENY));

// Should be rate-limited because X-Opaque-Id is not used
message = DeprecatedMessage.of(DeprecationCategory.OTHER, "key 0", "opaque-id 1", "msg 0");
assertThat(filter.filter(message), equalTo(Result.DENY));

// Should NOT be rate-limited because "key 1" it not in the cache
message = DeprecatedMessage.of(DeprecationCategory.OTHER, "key 1", "opaque-id 1", "msg 0");
assertThat(filter.filter(message), equalTo(Result.ACCEPT));
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,7 @@
"template": {
"settings": {
"index": {
"hidden" : true,
Copy link
Contributor

Choose a reason for hiding this comment

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

I don't think this change is related?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

not necessarily related, not even covered in testing here (index backing data stream is implementation detail)
do you recon we should do this in a separate PR?

Copy link
Contributor

Choose a reason for hiding this comment

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

I don't suppose it matters either way, we can leave this in.

"lifecycle": {
"name": ".deprecation-indexing-ilm-policy"
},
Expand Down
Loading