From 0bd59d2b36e56db4ef47294ed204caaf14af9061 Mon Sep 17 00:00:00 2001 From: pgomulka Date: Fri, 5 Mar 2021 12:42:10 +0100 Subject: [PATCH 1/2] Do not throtle deprecated field logs The commit #55115 removed the possibility to directly force deprecation log to be emitted. This means that usage of deprecated fields was throtthled 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 throthling. --- .../common/logging/JsonLoggerTests.java | 84 ++++++++++++++++--- .../logging/json_layout/log4j2.properties | 2 +- .../xcontent/LoggingDeprecationHandler.java | 6 +- 3 files changed, 77 insertions(+), 15 deletions(-) diff --git a/qa/logging-config/src/test/java/org/elasticsearch/common/logging/JsonLoggerTests.java b/qa/logging-config/src/test/java/org/elasticsearch/common/logging/JsonLoggerTests.java index fc3e67226a8f6..344aa104bec51 100644 --- a/qa/logging-config/src/test/java/org/elasticsearch/common/logging/JsonLoggerTests.java +++ b/qa/logging-config/src/test/java/org/elasticsearch/common/logging/JsonLoggerTests.java @@ -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; @@ -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"); @@ -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"), @@ -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"); @@ -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"), @@ -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"), @@ -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> stream = JsonLogsStream.mapStreamFrom(path)) { + List> 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( @@ -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"), @@ -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 -> { @@ -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"), @@ -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"), @@ -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"), diff --git a/qa/logging-config/src/test/resources/org/elasticsearch/common/logging/json_layout/log4j2.properties b/qa/logging-config/src/test/resources/org/elasticsearch/common/logging/json_layout/log4j2.properties index 43ba594236ec8..d29286d21d7b7 100644 --- a/qa/logging-config/src/test/resources/org/elasticsearch/common/logging/json_layout/log4j2.properties +++ b/qa/logging-config/src/test/resources/org/elasticsearch/common/logging/json_layout/log4j2.properties @@ -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 diff --git a/server/src/main/java/org/elasticsearch/common/xcontent/LoggingDeprecationHandler.java b/server/src/main/java/org/elasticsearch/common/xcontent/LoggingDeprecationHandler.java index 2e851ce3dcf99..ebe77e2355719 100644 --- a/server/src/main/java/org/elasticsearch/common/xcontent/LoggingDeprecationHandler.java +++ b/server/src/main/java/org/elasticsearch/common/xcontent/LoggingDeprecationHandler.java @@ -42,21 +42,21 @@ private LoggingDeprecationHandler() { @Override public void usedDeprecatedName(String parserName, Supplier 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 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 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); } } From bd7c8e5b693263928b5f5d548a04c36c149ce9e8 Mon Sep 17 00:00:00 2001 From: pgomulka Date: Fri, 5 Mar 2021 13:28:41 +0100 Subject: [PATCH 2/2] spacing --- .../common/xcontent/LoggingDeprecationHandler.java | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/server/src/main/java/org/elasticsearch/common/xcontent/LoggingDeprecationHandler.java b/server/src/main/java/org/elasticsearch/common/xcontent/LoggingDeprecationHandler.java index ebe77e2355719..bd3b27cfa5f11 100644 --- a/server/src/main/java/org/elasticsearch/common/xcontent/LoggingDeprecationHandler.java +++ b/server/src/main/java/org/elasticsearch/common/xcontent/LoggingDeprecationHandler.java @@ -42,21 +42,21 @@ private LoggingDeprecationHandler() { @Override public void usedDeprecatedName(String parserName, Supplier location, String usedName, String modernName) { String prefix = parserName == null ? "" : "[" + parserName + "][" + location.get() + "] "; - deprecationLogger.deprecate(DeprecationCategory.API, "deprecated_field_"+usedName, + deprecationLogger.deprecate(DeprecationCategory.API, "deprecated_field_" + usedName, "{}Deprecated field [{}] used, expected [{}] instead", prefix, usedName, modernName); } @Override public void usedDeprecatedField(String parserName, Supplier location, String usedName, String replacedWith) { String prefix = parserName == null ? "" : "[" + parserName + "][" + location.get() + "] "; - deprecationLogger.deprecate(DeprecationCategory.API, "deprecated_field_"+usedName, + deprecationLogger.deprecate(DeprecationCategory.API, "deprecated_field_" + usedName, "{}Deprecated field [{}] used, replaced by [{}]", prefix, usedName, replacedWith); } @Override public void usedDeprecatedField(String parserName, Supplier location, String usedName) { String prefix = parserName == null ? "" : "[" + parserName + "][" + location.get() + "] "; - deprecationLogger.deprecate(DeprecationCategory.API, "deprecated_field_"+usedName, + deprecationLogger.deprecate(DeprecationCategory.API, "deprecated_field_" + usedName, "{}Deprecated field [{}] used, this field is unused and will be removed entirely", prefix, usedName); } }