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 785a17c commit ef00e2a
Show file tree
Hide file tree
Showing 4 changed files with 70 additions and 37 deletions.
1 change: 1 addition & 0 deletions qa/logging-config/src/test/java/org/elasticsearch/common/logging/ESJsonLayoutTests.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -24,6 +24,7 @@ public void testEmptyType() {
}

public void testLayout() {

ESJsonLayout server = ESJsonLayout.newBuilder()
.setType("server")
.build();
Expand Down
98 changes: 65 additions & 33 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 @@ -53,6 +55,7 @@ public class JsonLoggerTests extends ESTestCase {

@BeforeClass
public static void initNodeName() {
assert "false".equals(System.getProperty("tests.security.manager")) : "-Dtests.security.manager=false has to be set";
JsonLogsTestSetup.init();
}

Expand All @@ -70,10 +73,60 @@ public void tearDown() throws Exception {
super.tearDown();
}

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("type", "deprecation"),
hasEntry("level", "DEPRECATION"),
hasEntry("component", "o.e.d.c.ParseField"),
hasEntry("cluster.name", "elasticsearch"),
hasEntry("node.name", "sample-name"),
hasEntry("message", "Deprecated field [deprecated_name] used, expected [new_name] instead"),
hasEntry("x-opaque-id", "someId")
),
allOf(
hasEntry("type", "deprecation"),
hasEntry("level", "DEPRECATION"),
hasEntry("component", "o.e.d.c.ParseField"),
hasEntry("cluster.name", "elasticsearch"),
hasEntry("node.name", "sample-name"),
hasEntry("message", "Deprecated field [deprecated_name2] used, expected [new_name] instead"),
hasEntry("x-opaque-id", "someId")
)

)
);
}

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 @@ -90,7 +143,7 @@ public void testDeprecatedMessage() throws Exception {
allOf(
hasEntry("type", "deprecation"),
hasEntry("level", "DEPRECATION"),
hasEntry("component", "d.test"),
hasEntry("component", "o.e.d.test"),
hasEntry("cluster.name", "elasticsearch"),
hasEntry("node.name", "sample-name"),
hasEntry("message", "deprecated message1"),
Expand All @@ -106,12 +159,8 @@ public void testDeprecatedMessage() throws Exception {


public void testDeprecatedMessageWithoutXOpaqueId() throws IOException {
final Logger testLogger = LogManager.getLogger("test");
testLogger.info(new DeprecatedMessage(DeprecationCategory.OTHER, "key", "someId", "deprecated message1"));
testLogger.info(new DeprecatedMessage(DeprecationCategory.OTHER, "key", "", "deprecated message2"));
// This message will be filtered out by the RateLimitingFilter because an empty ID is the same as a null one.
testLogger.info(new DeprecatedMessage(DeprecationCategory.OTHER, "key", null, "deprecated message3"));
testLogger.info("deprecated message4");
final DeprecationLogger testLogger = DeprecationLogger.getLogger("org.elasticsearch.test");
testLogger.deprecate(DeprecationCategory.OTHER, "a key", "deprecated message1");

final Path path = PathUtils.get(System.getProperty("es.logs.base_path"),
System.getProperty("es.logs.cluster_name") + "_deprecated.json");
Expand All @@ -122,33 +171,16 @@ public void testDeprecatedMessageWithoutXOpaqueId() throws IOException {
assertThat(jsonLogs, contains(
allOf(
hasEntry("type", "deprecation"),
hasEntry("level", "INFO"),
hasEntry("component", "test"),
hasEntry("level", "DEPRECATION"),
hasEntry("component", "o.e.d.test"),
hasEntry("cluster.name", "elasticsearch"),
hasEntry("node.name", "sample-name"),
hasEntry("message", "deprecated message1"),
hasEntry("x-opaque-id", "someId")),
allOf(
hasEntry("type", "deprecation"),
hasEntry("level", "INFO"),
hasEntry("component", "test"),
hasEntry("cluster.name", "elasticsearch"),
hasEntry("node.name", "sample-name"),
hasEntry("message", "deprecated message2"),
not(hasKey("x-opaque-id"))
),
allOf(
hasEntry("type", "deprecation"),
hasEntry("level", "INFO"),
hasEntry("component", "test"),
hasEntry("cluster.name", "elasticsearch"),
hasEntry("node.name", "sample-name"),
hasEntry("message", "deprecated message4"),
not(hasKey("x-opaque-id"))
)
)
);
));
}
assertWarnings("deprecated message1");
}

public void testJsonLayout() throws IOException {
Expand Down Expand Up @@ -265,7 +297,7 @@ public void testJsonInStacktraceMessageIsSplitted() 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 @@ -284,7 +316,7 @@ public void testDuplicateLogMessages() throws Exception {
allOf(
hasEntry("type", "deprecation"),
hasEntry("level", "DEPRECATION"),
hasEntry("component", "d.test"),
hasEntry("component", "o.e.d.test"),
hasEntry("cluster.name", "elasticsearch"),
hasEntry("node.name", "sample-name"),
hasEntry("message", "message1"),
Expand Down Expand Up @@ -318,7 +350,7 @@ public void testDuplicateLogMessages() throws Exception {
allOf(
hasEntry("type", "deprecation"),
hasEntry("level", "DEPRECATION"),
hasEntry("component", "d.test"),
hasEntry("component", "o.e.d.test"),
hasEntry("cluster.name", "elasticsearch"),
hasEntry("node.name", "sample-name"),
hasEntry("message", "message1"),
Expand All @@ -327,7 +359,7 @@ public void testDuplicateLogMessages() throws Exception {
allOf(
hasEntry("type", "deprecation"),
hasEntry("level", "DEPRECATION"),
hasEntry("component", "d.test"),
hasEntry("component", "o.e.d.test"),
hasEntry("cluster.name", "elasticsearch"),
hasEntry("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 @@ -46,7 +46,7 @@ rootLogger.appenderRef.file.ref = file
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.console.ref = console
logger.deprecation.appenderRef.file.ref = file
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 ef00e2a

Please sign in to comment.