From 2e8e058c3d27149a73cd157bfb82f75dda75d6af Mon Sep 17 00:00:00 2001 From: Przemyslaw Gomulka Date: Fri, 5 Mar 2021 15:02:20 +0100 Subject: [PATCH] Do not throttle deprecated field logs (#70009) The commit #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. --- .../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..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", + 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); } }