Skip to content

Commit

Permalink
Do not throttle deprecated field logs (elastic#70009)
Browse files Browse the repository at this point in the history 
The commit elastic#55115 removed the possibility to directly force deprecation
log to be emitted. This means that usage of deprecated fields was
throttled and only one deprecation was logged. The key was common for
all fields = "deprecated_field".

This commit appends a used deprecated field name to prevent that
throttled.
  • Loading branch information
@pgomulka
pgomulka committed Mar 5, 2021
1 parent 048b7d4 commit 2e8e058
Show file tree
Hide file tree
Showing 3 changed files with 77 additions and 15 deletions.
84 changes: 73 additions & 11 deletions qa/logging-config/src/test/java/org/elasticsearch/common/logging/JsonLoggerTests.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -15,9 +15,11 @@
import org.apache.logging.log4j.core.config.Configurator;
import org.elasticsearch.cli.UserException;
import org.elasticsearch.common.CheckedConsumer;
import org.elasticsearch.common.ParseField;
import org.elasticsearch.common.io.PathUtils;
import org.elasticsearch.common.settings.Settings;
import org.elasticsearch.common.util.concurrent.ThreadContext;
import org.elasticsearch.common.xcontent.LoggingDeprecationHandler;
import org.elasticsearch.env.Environment;
import org.elasticsearch.index.shard.ShardId;
import org.elasticsearch.tasks.Task;
Expand Down Expand Up @@ -76,7 +78,7 @@ public void tearDown() throws Exception {
}

public void testDeprecatedMessageWithoutXOpaqueId() throws IOException {
final DeprecationLogger testLogger = DeprecationLogger.getLogger("test");
final DeprecationLogger testLogger = DeprecationLogger.getLogger("org.elasticsearch.test");

testLogger.deprecate(DeprecationCategory.OTHER, "a key", "deprecated message1");

Expand All @@ -91,7 +93,7 @@ public void testDeprecatedMessageWithoutXOpaqueId() throws IOException {
allOf(
hasEntry("event.dataset", "elasticsearch.deprecation"),
hasEntry("log.level", "DEPRECATION"),
hasEntry("log.logger", "deprecation.test"),
hasEntry("log.logger", "org.elasticsearch.deprecation.test"),
hasEntry("elasticsearch.cluster.name", "elasticsearch"),
hasEntry("elasticsearch.node.name", "sample-name"),
hasEntry("message", "deprecated message1"),
Expand All @@ -111,7 +113,7 @@ public void testDeprecatedMessageWithoutXOpaqueId() throws IOException {
public void testCompatibleLog() throws Exception {
withThreadContext(threadContext -> {
threadContext.putHeader(Task.X_OPAQUE_ID, "someId");
final DeprecationLogger testLogger = DeprecationLogger.getLogger("test");
final DeprecationLogger testLogger = DeprecationLogger.getLogger("org.elasticsearch.test");
testLogger.deprecate(DeprecationCategory.OTHER,"someKey", "deprecated message1")
.compatibleApiWarning("compatibleKey","compatible API message");

Expand All @@ -131,7 +133,7 @@ public void testCompatibleLog() throws Exception {
hasEntry("event.dataset", "elasticsearch.deprecation"),
hasEntry("data_stream.dataset", "elasticsearch.deprecation"),
hasEntry("data_stream.type", "logs"),
hasEntry("log.logger", "deprecation.test"),
hasEntry("log.logger", "org.elasticsearch.deprecation.test"),
hasEntry("ecs.version", DeprecatedMessage.ECS_VERSION),
hasEntry("elasticsearch.cluster.name", "elasticsearch"),
hasEntry("elasticsearch.node.name", "sample-name"),
Expand All @@ -146,7 +148,7 @@ public void testCompatibleLog() throws Exception {
hasEntry("event.dataset", "elasticsearch.deprecation"),
hasEntry("data_stream.dataset", "elasticsearch.deprecation"),
hasEntry("data_stream.type", "logs"),
hasEntry("log.logger", "deprecation.test"),
hasEntry("log.logger", "org.elasticsearch.deprecation.test"),
hasEntry("ecs.version", DeprecatedMessage.ECS_VERSION),
hasEntry("elasticsearch.cluster.name", "elasticsearch"),
hasEntry("elasticsearch.node.name", "sample-name"),
Expand All @@ -163,10 +165,70 @@ public void testCompatibleLog() throws Exception {
});
}

public void testParseFieldEmittingLogs() throws Exception {
withThreadContext(threadContext -> {
threadContext.putHeader(Task.X_OPAQUE_ID, "someId");

ParseField deprecatedField = new ParseField("new_name", "deprecated_name");
assertTrue(deprecatedField.match("deprecated_name", LoggingDeprecationHandler.INSTANCE));

ParseField deprecatedField2 = new ParseField("new_name", "deprecated_name2");
assertTrue(deprecatedField2.match("deprecated_name2", LoggingDeprecationHandler.INSTANCE));

final Path path = PathUtils.get(
System.getProperty("es.logs.base_path"),
System.getProperty("es.logs.cluster_name") + "_deprecated.json"
);

try (Stream<Map<String, String>> stream = JsonLogsStream.mapStreamFrom(path)) {
List<Map<String, String>> jsonLogs = stream.collect(Collectors.toList());

assertThat(
jsonLogs,
contains(
// deprecation log for field deprecated_name
allOf(
hasEntry("log.level", "DEPRECATION"),
hasEntry("event.dataset", "elasticsearch.deprecation"),
hasEntry("data_stream.dataset", "elasticsearch.deprecation"),
hasEntry("data_stream.type", "logs"),
hasEntry("log.logger", "org.elasticsearch.deprecation.common.ParseField"),
hasEntry("ecs.version", DeprecatedMessage.ECS_VERSION),
hasEntry("elasticsearch.cluster.name", "elasticsearch"),
hasEntry("elasticsearch.node.name", "sample-name"),
hasEntry("message", "Deprecated field [deprecated_name] used, expected [new_name] instead"),
hasEntry(DeprecatedMessage.KEY_FIELD_NAME, "deprecated_field_deprecated_name"),
hasEntry(DeprecatedMessage.X_OPAQUE_ID_FIELD_NAME, "someId"),
hasEntry("elasticsearch.event.category", "api")
),
// deprecation log for field deprecated_name2
allOf(
hasEntry("log.level", "DEPRECATION"),
hasEntry("event.dataset", "elasticsearch.deprecation"),
hasEntry("data_stream.dataset", "elasticsearch.deprecation"),
hasEntry("data_stream.type", "logs"),
hasEntry("log.logger", "org.elasticsearch.deprecation.common.ParseField"),
hasEntry("ecs.version", DeprecatedMessage.ECS_VERSION),
hasEntry("elasticsearch.cluster.name", "elasticsearch"),
hasEntry("elasticsearch.node.name", "sample-name"),
hasEntry("message", "Deprecated field [deprecated_name2] used, expected [new_name] instead"),
hasEntry(DeprecatedMessage.KEY_FIELD_NAME, "deprecated_field_deprecated_name2"),
hasEntry(DeprecatedMessage.X_OPAQUE_ID_FIELD_NAME, "someId"),
hasEntry("elasticsearch.event.category", "api")
)
)
);
}

assertWarnings("Deprecated field [deprecated_name] used, expected [new_name] instead",
"Deprecated field [deprecated_name2] used, expected [new_name] instead");
});
}

public void testDeprecatedMessage() throws Exception {
withThreadContext(threadContext -> {
threadContext.putHeader(Task.X_OPAQUE_ID, "someId");
final DeprecationLogger testLogger = DeprecationLogger.getLogger("test");
final DeprecationLogger testLogger = DeprecationLogger.getLogger("org.elasticsearch.test");
testLogger.deprecate(DeprecationCategory.OTHER, "someKey", "deprecated message1");

final Path path = PathUtils.get(
Expand All @@ -183,7 +245,7 @@ public void testDeprecatedMessage() throws Exception {
allOf(
hasEntry("event.dataset", "elasticsearch.deprecation"),
hasEntry("log.level", "DEPRECATION"),
hasEntry("log.logger", "deprecation.test"),
hasEntry("log.logger", "org.elasticsearch.deprecation.test"),
hasEntry("elasticsearch.cluster.name", "elasticsearch"),
hasEntry("elasticsearch.node.name", "sample-name"),
hasEntry("message", "deprecated message1"),
Expand Down Expand Up @@ -374,7 +436,7 @@ public void testJsonInStacktraceMessageIsNotSplitted() throws IOException {


public void testDuplicateLogMessages() throws Exception {
final DeprecationLogger deprecationLogger = DeprecationLogger.getLogger("test");
final DeprecationLogger deprecationLogger = DeprecationLogger.getLogger("org.elasticsearch.test");

// For the same key and X-Opaque-ID deprecation should be once
withThreadContext(threadContext -> {
Expand All @@ -393,7 +455,7 @@ public void testDuplicateLogMessages() throws Exception {
allOf(
hasEntry("event.dataset", "elasticsearch.deprecation"),
hasEntry("log.level", "DEPRECATION"),
hasEntry("log.logger", "deprecation.test"),
hasEntry("log.logger", "org.elasticsearch.deprecation.test"),
hasEntry("elasticsearch.cluster.name", "elasticsearch"),
hasEntry("elasticsearch.node.name", "sample-name"),
hasEntry("message", "message1"),
Expand Down Expand Up @@ -425,7 +487,7 @@ public void testDuplicateLogMessages() throws Exception {
allOf(
hasEntry("event.dataset", "elasticsearch.deprecation"),
hasEntry("log.level", "DEPRECATION"),
hasEntry("log.logger", "deprecation.test"),
hasEntry("log.logger", "org.elasticsearch.deprecation.test"),
hasEntry("elasticsearch.cluster.name", "elasticsearch"),
hasEntry("elasticsearch.node.name", "sample-name"),
hasEntry("message", "message1"),
Expand All @@ -435,7 +497,7 @@ public void testDuplicateLogMessages() throws Exception {
allOf(
hasEntry("event.dataset", "elasticsearch.deprecation"),
hasEntry("log.level", "DEPRECATION"),
hasEntry("log.logger", "deprecation.test"),
hasEntry("log.logger", "org.elasticsearch.deprecation.test"),
hasEntry("elasticsearch.cluster.name", "elasticsearch"),
hasEntry("elasticsearch.node.name", "sample-name"),
hasEntry("message", "message1"),
Expand Down
2 changes: 1 addition & 1 deletion ...-config/src/test/resources/org/elasticsearch/common/logging/json_layout/log4j2.properties
View file
Original file line number Diff line number Diff line change
Expand Up @@ -37,7 +37,7 @@ appender.plaintext.filter.rate_limit.type = RateLimitingFilter
appender.header_warning.type = HeaderWarningAppender
appender.header_warning.name = header_warning

logger.deprecation.name = deprecation.test
logger.deprecation.name = org.elasticsearch.deprecation
logger.deprecation.level = deprecation
logger.deprecation.appenderRef.deprecation_rolling.ref = deprecated
logger.deprecation.appenderRef.deprecatedconsole.ref = deprecatedconsole
Expand Down
6 changes: 3 additions & 3 deletions server/src/main/java/org/elasticsearch/common/xcontent/LoggingDeprecationHandler.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -42,21 +42,21 @@ private LoggingDeprecationHandler() {
@Override
public void usedDeprecatedName(String parserName, Supplier<XContentLocation> location, String usedName, String modernName) {
String prefix = parserName == null ? "" : "[" + parserName + "][" + location.get() + "] ";
deprecationLogger.deprecate(DeprecationCategory.API, "deprecated_field",
deprecationLogger.deprecate(DeprecationCategory.API, "deprecated_field_" + usedName,
"{}Deprecated field [{}] used, expected [{}] instead", prefix, usedName, modernName);
}

@Override
public void usedDeprecatedField(String parserName, Supplier<XContentLocation> location, String usedName, String replacedWith) {
String prefix = parserName == null ? "" : "[" + parserName + "][" + location.get() + "] ";
deprecationLogger.deprecate(DeprecationCategory.API, "deprecated_field",
deprecationLogger.deprecate(DeprecationCategory.API, "deprecated_field_" + usedName,
"{}Deprecated field [{}] used, replaced by [{}]", prefix, usedName, replacedWith);
}

@Override
public void usedDeprecatedField(String parserName, Supplier<XContentLocation> location, String usedName) {
String prefix = parserName == null ? "" : "[" + parserName + "][" + location.get() + "] ";
deprecationLogger.deprecate(DeprecationCategory.API, "deprecated_field",
deprecationLogger.deprecate(DeprecationCategory.API, "deprecated_field_" + usedName,
"{}Deprecated field [{}] used, this field is unused and will be removed entirely", prefix, usedName);
}
}

0 comments on commit 2e8e058

Please sign in to comment.