From 6ebceb5894030b8d0669a46317d35b2f5b23ae44 Mon Sep 17 00:00:00 2001 From: Nik Everett Date: Thu, 21 Jun 2018 09:44:43 -0400 Subject: [PATCH 01/13] Logging: Make node name consistent in logger First, some background: we have 15 different methods to get a logger in Elasticsearch but they can be broken down into three broad categories based on what information is provided when building the logger. Just a class like: ``` private static final Logger logger = ESLoggerFactory.getLogger(ActionModule.class); ``` or: ``` protected final Logger logger = Loggers.getLogger(getClass()); ``` The class and settings: ``` this.logger = Loggers.getLogger(getClass(), settings); ``` Or more information like: ``` Loggers.getLogger("index.store.deletes", settings, shardId) ``` The goal of the "class and settings" variant is to attach the node name to the logger. Because we don't always have the settings available, we often use the "just a class" variant and get loggers without node names attached. There isn't any real consistency here. Some loggers get the node name because it is convenient and some do not. This change makes the node name available to all loggers all the time. Almost. There are some caveats are testing that I'll get to. But in *production* code the node name is node available to all loggers. This means we can stop using the "class and settings" variants to fetch loggers which was the real goal here, but a pleasant side effect is that the ndoe name is now consitent on every log line and optional by editing the logging pattern. This is all powered by setting the node name statically on a logging formatter very early in initialization. Now to tests: tests can't set the node name statically because subclasses of `ESIntegTestCase` run many nodes in the same jvm, even in the same class loader. Also, lots of tests don't run with a real node so they don't *have* a node name at all. To support multiple nodes in the ame JVM tests suss out the node name from the thread name which works surprisingly well and easy to test in a nice way. For those threads that are not part of an `ESIntegTestCase` node we stick whatever useful information we can get form the thread name in the place of the node name. This allows us to keep the logger format consistent. --- .../src/main/resources/log4j2.properties | 2 +- .../src/main/resources/log4j2.properties | 2 +- distribution/src/config/log4j2.properties | 10 +- docs/java-api/index.asciidoc | 2 +- docs/reference/index-modules/slowlog.asciidoc | 4 +- docs/reference/setup/logging-config.asciidoc | 2 +- .../bootstrap/EvilBootstrapChecksTests.java | 2 +- .../common/logging/EvilLoggerTests.java | 6 +- .../common/logging/config/log4j2.properties | 7 +- .../logging/config/third/log4j2.properties | 2 +- .../logging/deprecation/log4j2.properties | 6 +- .../logging/find_appender/log4j2.properties | 2 +- .../logging/location_info/log4j2.properties | 4 +- .../common/logging/prefix/log4j2.properties | 4 +- .../common/logging/settings/log4j2.properties | 6 +- .../elasticsearch/bootstrap/Bootstrap.java | 8 +- .../bootstrap/BootstrapChecks.java | 10 +- ...ElasticsearchUncaughtExceptionHandler.java | 11 +- .../common/logging/ESLoggerFactory.java | 3 + .../common/logging/LogConfigurator.java | 10 ++ .../elasticsearch/common/logging/Loggers.java | 29 +--- .../logging/NodeNamePatternConverter.java | 72 ++++++++++ .../java/org/elasticsearch/node/Node.java | 17 ++- .../bootstrap/BootstrapChecksTests.java | 89 ++++++------ ...icsearchUncaughtExceptionHandlerTests.java | 4 +- .../index/engine/InternalEngineTests.java | 2 +- .../bootstrap/BootstrapForTesting.java | 3 + .../TestThreadInfoPatternConverter.java | 130 ++++++++++++++++++ .../org/elasticsearch/test/ESTestCase.java | 4 +- .../src/main/resources/log4j2-test.properties | 2 +- .../resources/log4j2.component.properties | 7 + .../TestThreadInfoPatternConverterTests.java | 53 +++++++ 32 files changed, 382 insertions(+), 133 deletions(-) create mode 100644 server/src/main/java/org/elasticsearch/common/logging/NodeNamePatternConverter.java create mode 100644 test/framework/src/main/java/org/elasticsearch/common/logging/TestThreadInfoPatternConverter.java create mode 100644 test/framework/src/main/resources/log4j2.component.properties create mode 100644 test/framework/src/test/java/org/elasticsearch/common/logging/TestThreadInfoPatternConverterTests.java diff --git a/benchmarks/src/main/resources/log4j2.properties b/benchmarks/src/main/resources/log4j2.properties index c3ae1fe56d3d1..808d611670f31 100644 --- a/benchmarks/src/main/resources/log4j2.properties +++ b/benchmarks/src/main/resources/log4j2.properties @@ -1,7 +1,7 @@ appender.console.type = Console appender.console.name = console appender.console.layout.type = PatternLayout -appender.console.layout.pattern = [%d{ISO8601}][%-5p][%-25c] %marker%m%n +appender.console.layout.pattern = [%d{ISO8601}][%-5p][%-25c] [%node_name]%marker %m%n # Do not log at all if it is not really critical - we're in a benchmark rootLogger.level = error diff --git a/client/benchmark/src/main/resources/log4j2.properties b/client/benchmark/src/main/resources/log4j2.properties index 8652131bf4916..a68c7f5653f87 100644 --- a/client/benchmark/src/main/resources/log4j2.properties +++ b/client/benchmark/src/main/resources/log4j2.properties @@ -1,7 +1,7 @@ appender.console.type = Console appender.console.name = console appender.console.layout.type = PatternLayout -appender.console.layout.pattern = [%d{ISO8601}][%-5p][%-25c] %marker%m%n +appender.console.layout.pattern = [%d{ISO8601}][%-5p][%-25c] [%node_name]%marker %m%n rootLogger.level = info rootLogger.appenderRef.console.ref = console diff --git a/distribution/src/config/log4j2.properties b/distribution/src/config/log4j2.properties index 589f529e83eaa..6de21cd48f67b 100644 --- a/distribution/src/config/log4j2.properties +++ b/distribution/src/config/log4j2.properties @@ -7,13 +7,13 @@ logger.action.level = debug appender.console.type = Console appender.console.name = console appender.console.layout.type = PatternLayout -appender.console.layout.pattern = [%d{ISO8601}][%-5p][%-25c{1.}] %marker%m%n +appender.console.layout.pattern = [%d{ISO8601}][%-5p][%-25c{1.}] [%node_name]%marker %m%n appender.rolling.type = RollingFile appender.rolling.name = rolling appender.rolling.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}.log appender.rolling.layout.type = PatternLayout -appender.rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c{1.}] %marker%.-10000m%n +appender.rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c{1.}] [%node_name]%marker %.-10000m%n appender.rolling.filePattern = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}-%d{yyyy-MM-dd}-%i.log.gz appender.rolling.policies.type = Policies appender.rolling.policies.time.type = TimeBasedTriggeringPolicy @@ -38,7 +38,7 @@ appender.deprecation_rolling.type = RollingFile appender.deprecation_rolling.name = deprecation_rolling appender.deprecation_rolling.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_deprecation.log appender.deprecation_rolling.layout.type = PatternLayout -appender.deprecation_rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c{1.}] %marker%.-10000m%n +appender.deprecation_rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c{1.}] [%node_name]%marker %.-10000m%n appender.deprecation_rolling.filePattern = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_deprecation-%i.log.gz appender.deprecation_rolling.policies.type = Policies appender.deprecation_rolling.policies.size.type = SizeBasedTriggeringPolicy @@ -55,7 +55,7 @@ appender.index_search_slowlog_rolling.type = RollingFile appender.index_search_slowlog_rolling.name = index_search_slowlog_rolling appender.index_search_slowlog_rolling.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_index_search_slowlog.log appender.index_search_slowlog_rolling.layout.type = PatternLayout -appender.index_search_slowlog_rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c] %marker%.-10000m%n +appender.index_search_slowlog_rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c] [%node_name]%marker %.-10000m%n appender.index_search_slowlog_rolling.filePattern = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_index_search_slowlog-%i.log.gz appender.index_search_slowlog_rolling.policies.type = Policies appender.index_search_slowlog_rolling.policies.size.type = SizeBasedTriggeringPolicy @@ -72,7 +72,7 @@ appender.index_indexing_slowlog_rolling.type = RollingFile appender.index_indexing_slowlog_rolling.name = index_indexing_slowlog_rolling appender.index_indexing_slowlog_rolling.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_index_indexing_slowlog.log appender.index_indexing_slowlog_rolling.layout.type = PatternLayout -appender.index_indexing_slowlog_rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c] %marker%.-10000m%n +appender.index_indexing_slowlog_rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c] [%node_name]%marker %.-10000m%n appender.index_indexing_slowlog_rolling.filePattern = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_index_indexing_slowlog-%i.log.gz appender.index_indexing_slowlog_rolling.policies.type = Policies appender.index_indexing_slowlog_rolling.policies.size.type = SizeBasedTriggeringPolicy diff --git a/docs/java-api/index.asciidoc b/docs/java-api/index.asciidoc index 4fb7db4c4abf6..c268915da9390 100644 --- a/docs/java-api/index.asciidoc +++ b/docs/java-api/index.asciidoc @@ -94,7 +94,7 @@ For example, you can add in your `src/main/resources` project dir a `log4j2.prop appender.console.type = Console appender.console.name = console appender.console.layout.type = PatternLayout -appender.console.layout.pattern = [%d{ISO8601}][%-5p][%-25c] %marker%m%n +appender.console.layout.pattern = [%d{ISO8601}][%-5p][%-25c] %marker %m%n rootLogger.level = info rootLogger.appenderRef.console.ref = console diff --git a/docs/reference/index-modules/slowlog.asciidoc b/docs/reference/index-modules/slowlog.asciidoc index 1dc84f380f509..235256bdce7c0 100644 --- a/docs/reference/index-modules/slowlog.asciidoc +++ b/docs/reference/index-modules/slowlog.asciidoc @@ -50,7 +50,7 @@ appender.index_search_slowlog_rolling.type = RollingFile appender.index_search_slowlog_rolling.name = index_search_slowlog_rolling appender.index_search_slowlog_rolling.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_index_search_slowlog.log appender.index_search_slowlog_rolling.layout.type = PatternLayout -appender.index_search_slowlog_rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c] %marker%.-10000m%n +appender.index_search_slowlog_rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c] [%node_name]%marker %.-10000m%n appender.index_search_slowlog_rolling.filePattern = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_index_search_slowlog-%i.log.gz appender.index_search_slowlog_rolling.policies.type = Policies appender.index_search_slowlog_rolling.policies.size.type = SizeBasedTriggeringPolicy @@ -103,7 +103,7 @@ appender.index_indexing_slowlog_rolling.type = RollingFile appender.index_indexing_slowlog_rolling.name = index_indexing_slowlog_rolling appender.index_indexing_slowlog_rolling.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_index_indexing_slowlog.log appender.index_indexing_slowlog_rolling.layout.type = PatternLayout -appender.index_indexing_slowlog_rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c] %marker%.-10000m%n +appender.index_indexing_slowlog_rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c] [%node_name]%marker %.-10000m%n appender.index_indexing_slowlog_rolling.filePattern = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_index_indexing_slowlog-%i.log.gz appender.index_indexing_slowlog_rolling.policies.type = Policies appender.index_indexing_slowlog_rolling.policies.size.type = SizeBasedTriggeringPolicy diff --git a/docs/reference/setup/logging-config.asciidoc b/docs/reference/setup/logging-config.asciidoc index d35b3db2df7f3..ac949bc941a9c 100644 --- a/docs/reference/setup/logging-config.asciidoc +++ b/docs/reference/setup/logging-config.asciidoc @@ -25,7 +25,7 @@ appender.rolling.type = RollingFile <1> appender.rolling.name = rolling appender.rolling.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}.log <2> appender.rolling.layout.type = PatternLayout -appender.rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c{1.}] %marker%.-10000m%n +appender.rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c{1.}] [%node_name]%marker %.-10000m%n appender.rolling.filePattern = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}-%d{yyyy-MM-dd}-%i.log.gz <3> appender.rolling.policies.type = Policies appender.rolling.policies.time.type = TimeBasedTriggeringPolicy <4> diff --git a/qa/evil-tests/src/test/java/org/elasticsearch/bootstrap/EvilBootstrapChecksTests.java b/qa/evil-tests/src/test/java/org/elasticsearch/bootstrap/EvilBootstrapChecksTests.java index 0dc9ea0a170ba..b034cd08d77d6 100644 --- a/qa/evil-tests/src/test/java/org/elasticsearch/bootstrap/EvilBootstrapChecksTests.java +++ b/qa/evil-tests/src/test/java/org/elasticsearch/bootstrap/EvilBootstrapChecksTests.java @@ -87,7 +87,7 @@ public void testInvalidValue() { final boolean enforceLimits = randomBoolean(); final IllegalArgumentException e = expectThrows( IllegalArgumentException.class, - () -> BootstrapChecks.check(new BootstrapContext(Settings.EMPTY, null), enforceLimits, emptyList(), "testInvalidValue")); + () -> BootstrapChecks.check(new BootstrapContext(Settings.EMPTY, null), enforceLimits, emptyList())); final Matcher matcher = containsString( "[es.enforce.bootstrap.checks] must be [true] but was [" + value + "]"); assertThat(e, hasToString(matcher)); diff --git a/qa/evil-tests/src/test/java/org/elasticsearch/common/logging/EvilLoggerTests.java b/qa/evil-tests/src/test/java/org/elasticsearch/common/logging/EvilLoggerTests.java index d4bc754689e68..8ff2a185e90bc 100644 --- a/qa/evil-tests/src/test/java/org/elasticsearch/common/logging/EvilLoggerTests.java +++ b/qa/evil-tests/src/test/java/org/elasticsearch/common/logging/EvilLoggerTests.java @@ -319,9 +319,11 @@ public void testPrefixLogger() throws IOException, IllegalAccessException, UserE assertThat(events.size(), equalTo(expectedLogLines + stackTraceLength)); for (int i = 0; i < expectedLogLines; i++) { if (prefix == null) { - assertThat(events.get(i), startsWith("test")); + assertThat("Contents of [" + path + "] are wrong", + events.get(i), startsWith("[" + getTestName() + "] test")); } else { - assertThat(events.get(i), startsWith("[" + prefix + "] test")); + assertThat("Contents of [" + path + "] are wrong", + events.get(i), startsWith("[" + getTestName() + "][" + prefix + "] test")); } } } diff --git a/qa/evil-tests/src/test/resources/org/elasticsearch/common/logging/config/log4j2.properties b/qa/evil-tests/src/test/resources/org/elasticsearch/common/logging/config/log4j2.properties index 8b956421458d0..2c9f48a359a46 100644 --- a/qa/evil-tests/src/test/resources/org/elasticsearch/common/logging/config/log4j2.properties +++ b/qa/evil-tests/src/test/resources/org/elasticsearch/common/logging/config/log4j2.properties @@ -1,13 +1,13 @@ appender.console.type = Console appender.console.name = console appender.console.layout.type = PatternLayout -appender.console.layout.pattern = [%d{ISO8601}][%-5p][%-25c] %marker%m%n +appender.console.layout.pattern = [%d{ISO8601}][%-5p][%-25c] [%test_thread_info]%marker %m%n appender.file.type = File appender.file.name = file appender.file.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}.log appender.file.layout.type = PatternLayout -appender.file.layout.pattern = [%p][%l] %marker%m%n +appender.file.layout.pattern = [%p][%l] [%test_thread_info]%marker %m%n rootLogger.level = info rootLogger.appenderRef.console.ref = console @@ -23,10 +23,9 @@ appender.deprecation_file.type = File appender.deprecation_file.name = deprecation_file appender.deprecation_file.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_deprecation.log appender.deprecation_file.layout.type = PatternLayout -appender.deprecation_file.layout.pattern = [%p][%l] %marker%m%n +appender.deprecation_file.layout.pattern = [%p][%l] [%test_thread_info]%marker %m%n logger.deprecation.name = deprecation logger.deprecation.level = warn logger.deprecation.appenderRef.deprecation_file.ref = deprecation_file logger.deprecation.additivity = false - diff --git a/qa/evil-tests/src/test/resources/org/elasticsearch/common/logging/config/third/log4j2.properties b/qa/evil-tests/src/test/resources/org/elasticsearch/common/logging/config/third/log4j2.properties index ed794cb7c3b59..8a9ec160fb1e8 100644 --- a/qa/evil-tests/src/test/resources/org/elasticsearch/common/logging/config/third/log4j2.properties +++ b/qa/evil-tests/src/test/resources/org/elasticsearch/common/logging/config/third/log4j2.properties @@ -1,7 +1,7 @@ appender.console3.type = Console appender.console3.name = console3 appender.console3.layout.type = PatternLayout -appender.console3.layout.pattern = [%d{ISO8601}][%-5p][%-25c] %marker%m%n +appender.console3.layout.pattern = [%d{ISO8601}][%-5p][%-25c] [%test_thread_info]%marker %m%n logger.third.name = third logger.third.level = debug diff --git a/qa/evil-tests/src/test/resources/org/elasticsearch/common/logging/deprecation/log4j2.properties b/qa/evil-tests/src/test/resources/org/elasticsearch/common/logging/deprecation/log4j2.properties index fd7af2ce73136..388c9f9b2fc64 100644 --- a/qa/evil-tests/src/test/resources/org/elasticsearch/common/logging/deprecation/log4j2.properties +++ b/qa/evil-tests/src/test/resources/org/elasticsearch/common/logging/deprecation/log4j2.properties @@ -1,13 +1,13 @@ appender.console.type = Console appender.console.name = console appender.console.layout.type = PatternLayout -appender.console.layout.pattern = [%d{ISO8601}][%-5p][%-25c] %marker%m%n +appender.console.layout.pattern = [%d{ISO8601}][%-5p][%-25c] [%test_thread_info]%marker %m%n appender.file.type = File appender.file.name = file appender.file.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}.log appender.file.layout.type = PatternLayout -appender.file.layout.pattern = [%p][%l] %marker%m%n +appender.file.layout.pattern = [%p][%l] [%test_thread_info]%marker %m%n rootLogger.level = info rootLogger.appenderRef.console.ref = console @@ -17,7 +17,7 @@ appender.deprecation_file.type = File appender.deprecation_file.name = deprecation_file appender.deprecation_file.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_deprecation.log appender.deprecation_file.layout.type = PatternLayout -appender.deprecation_file.layout.pattern = [%p][%l] %marker%m%n +appender.deprecation_file.layout.pattern = [%p][%l] [%test_thread_info]%marker %m%n logger.deprecation.name = deprecation logger.deprecation.level = warn diff --git a/qa/evil-tests/src/test/resources/org/elasticsearch/common/logging/find_appender/log4j2.properties b/qa/evil-tests/src/test/resources/org/elasticsearch/common/logging/find_appender/log4j2.properties index 8553ec5e7915f..d036e571cf0c0 100644 --- a/qa/evil-tests/src/test/resources/org/elasticsearch/common/logging/find_appender/log4j2.properties +++ b/qa/evil-tests/src/test/resources/org/elasticsearch/common/logging/find_appender/log4j2.properties @@ -1,7 +1,7 @@ appender.console.type = Console appender.console.name = console appender.console.layout.type = PatternLayout -appender.console.layout.pattern = [%d{ISO8601}][%-5p][%-25c] %marker%m%n +appender.console.layout.pattern = [%d{ISO8601}][%-5p][%-25c] [%test_thread_info]%marker %m%n logger.has_console_appender.name = has_console_appender logger.has_console_appender.level = trace diff --git a/qa/evil-tests/src/test/resources/org/elasticsearch/common/logging/location_info/log4j2.properties b/qa/evil-tests/src/test/resources/org/elasticsearch/common/logging/location_info/log4j2.properties index 5fa85b5d156b3..ee59755a2d784 100644 --- a/qa/evil-tests/src/test/resources/org/elasticsearch/common/logging/location_info/log4j2.properties +++ b/qa/evil-tests/src/test/resources/org/elasticsearch/common/logging/location_info/log4j2.properties @@ -1,13 +1,13 @@ appender.console.type = Console appender.console.name = console appender.console.layout.type = PatternLayout -appender.console.layout.pattern = [%d{ISO8601}][%-5p][%-25c] %marker%m%n +appender.console.layout.pattern = [%d{ISO8601}][%-5p][%-25c] [%test_thread_info]%marker %m%n appender.file.type = File appender.file.name = file appender.file.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}.log appender.file.layout.type = PatternLayout -appender.file.layout.pattern = [%p][%l] %marker%m%n +appender.file.layout.pattern = [%p][%l] [%test_thread_info]%marker %m%n rootLogger.level = info rootLogger.appenderRef.console.ref = console diff --git a/qa/evil-tests/src/test/resources/org/elasticsearch/common/logging/prefix/log4j2.properties b/qa/evil-tests/src/test/resources/org/elasticsearch/common/logging/prefix/log4j2.properties index 5dfa369a3bd25..199fddc31c681 100644 --- a/qa/evil-tests/src/test/resources/org/elasticsearch/common/logging/prefix/log4j2.properties +++ b/qa/evil-tests/src/test/resources/org/elasticsearch/common/logging/prefix/log4j2.properties @@ -1,13 +1,13 @@ appender.console.type = Console appender.console.name = console appender.console.layout.type = PatternLayout -appender.console.layout.pattern = [%d{ISO8601}][%-5p][%-25c] %marker%m%n +appender.console.layout.pattern = [%d{ISO8601}][%-5p][%-25c] [%test_thread_info]%marker %m%n appender.file.type = File appender.file.name = file appender.file.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}.log appender.file.layout.type = PatternLayout -appender.file.layout.pattern = %marker%m%n +appender.file.layout.pattern = [%test_thread_info]%marker %m%n rootLogger.level = info rootLogger.appenderRef.console.ref = console diff --git a/qa/evil-tests/src/test/resources/org/elasticsearch/common/logging/settings/log4j2.properties b/qa/evil-tests/src/test/resources/org/elasticsearch/common/logging/settings/log4j2.properties index 1acb65511d607..abe4a279dc820 100644 --- a/qa/evil-tests/src/test/resources/org/elasticsearch/common/logging/settings/log4j2.properties +++ b/qa/evil-tests/src/test/resources/org/elasticsearch/common/logging/settings/log4j2.properties @@ -1,13 +1,13 @@ appender.console.type = Console appender.console.name = console appender.console.layout.type = PatternLayout -appender.console.layout.pattern = [%d{ISO8601}][%-5p][%-25c] %marker%m%n +appender.console.layout.pattern = [%d{ISO8601}][%-5p][%-25c] [%test_thread_info]%marker %m%n appender.file.type = File appender.file.name = file appender.file.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}.log appender.file.layout.type = PatternLayout -appender.file.layout.pattern = [%p][%l] %marker%m%n +appender.file.layout.pattern = [%p][%l] [%test_thread_info]%marker %m%n rootLogger.level = info rootLogger.appenderRef.console.ref = console @@ -17,7 +17,7 @@ appender.deprecation_file.type = File appender.deprecation_file.name = deprecation_file appender.deprecation_file.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_deprecation.log appender.deprecation_file.layout.type = PatternLayout -appender.deprecation_file.layout.pattern = [%p][%l] %marker%m%n +appender.deprecation_file.layout.pattern = [%p][%l] [%test_thread_info]%marker %m%n logger.deprecation.name = org.elasticsearch.deprecation.common.settings logger.deprecation.level = warn diff --git a/server/src/main/java/org/elasticsearch/bootstrap/Bootstrap.java b/server/src/main/java/org/elasticsearch/bootstrap/Bootstrap.java index 870c537e020c5..76db6db767469 100644 --- a/server/src/main/java/org/elasticsearch/bootstrap/Bootstrap.java +++ b/server/src/main/java/org/elasticsearch/bootstrap/Bootstrap.java @@ -37,6 +37,7 @@ import org.elasticsearch.common.logging.ESLoggerFactory; import org.elasticsearch.common.logging.LogConfigurator; import org.elasticsearch.common.logging.Loggers; +import org.elasticsearch.common.logging.NodeNamePatternConverter; import org.elasticsearch.common.network.IfConfig; import org.elasticsearch.common.settings.KeyStoreWrapper; import org.elasticsearch.common.settings.SecureSettings; @@ -287,6 +288,10 @@ static void init( final SecureSettings keystore = loadSecureSettings(initialEnv); final Environment environment = createEnvironment(pidFile, keystore, initialEnv.settings(), initialEnv.configFile()); + + String nodeName = Node.NODE_NAME_SETTING.get(environment.settings()); + NodeNamePatternConverter.setNodeName(nodeName); + try { LogConfigurator.configure(environment); } catch (IOException e) { @@ -317,8 +322,7 @@ static void init( // install the default uncaught exception handler; must be done before security is // initialized as we do not want to grant the runtime permission // setDefaultUncaughtExceptionHandler - Thread.setDefaultUncaughtExceptionHandler( - new ElasticsearchUncaughtExceptionHandler(() -> Node.NODE_NAME_SETTING.get(environment.settings()))); + Thread.setDefaultUncaughtExceptionHandler(new ElasticsearchUncaughtExceptionHandler()); INSTANCE.setup(true, environment); diff --git a/server/src/main/java/org/elasticsearch/bootstrap/BootstrapChecks.java b/server/src/main/java/org/elasticsearch/bootstrap/BootstrapChecks.java index 19fdb8837d69b..1a028042db29b 100644 --- a/server/src/main/java/org/elasticsearch/bootstrap/BootstrapChecks.java +++ b/server/src/main/java/org/elasticsearch/bootstrap/BootstrapChecks.java @@ -30,7 +30,6 @@ import org.elasticsearch.discovery.DiscoveryModule; import org.elasticsearch.monitor.jvm.JvmInfo; import org.elasticsearch.monitor.process.ProcessProbe; -import org.elasticsearch.node.Node; import org.elasticsearch.node.NodeValidationException; import java.io.BufferedReader; @@ -74,8 +73,7 @@ static void check(final BootstrapContext context, final BoundTransportAddress bo combinedChecks.addAll(additionalChecks); check( context, enforceLimits(boundTransportAddress, DiscoveryModule.DISCOVERY_TYPE_SETTING.get(context.settings)), - Collections.unmodifiableList(combinedChecks), - Node.NODE_NAME_SETTING.get(context.settings)); + Collections.unmodifiableList(combinedChecks)); } /** @@ -86,14 +84,12 @@ static void check(final BootstrapContext context, final BoundTransportAddress bo * @param context the current node boostrap context * @param enforceLimits {@code true} if the checks should be enforced or otherwise warned * @param checks the checks to execute - * @param nodeName the node name to be used as a logging prefix */ static void check( final BootstrapContext context, final boolean enforceLimits, - final List checks, - final String nodeName) throws NodeValidationException { - check(context, enforceLimits, checks, Loggers.getLogger(BootstrapChecks.class, nodeName)); + final List checks) throws NodeValidationException { + check(context, enforceLimits, checks, Loggers.getLogger(BootstrapChecks.class)); } /** diff --git a/server/src/main/java/org/elasticsearch/bootstrap/ElasticsearchUncaughtExceptionHandler.java b/server/src/main/java/org/elasticsearch/bootstrap/ElasticsearchUncaughtExceptionHandler.java index 857ff65b6c2b8..1ef9b7740c205 100644 --- a/server/src/main/java/org/elasticsearch/bootstrap/ElasticsearchUncaughtExceptionHandler.java +++ b/server/src/main/java/org/elasticsearch/bootstrap/ElasticsearchUncaughtExceptionHandler.java @@ -27,16 +27,9 @@ import java.io.IOError; import java.security.AccessController; import java.security.PrivilegedAction; -import java.util.Objects; -import java.util.function.Supplier; class ElasticsearchUncaughtExceptionHandler implements Thread.UncaughtExceptionHandler { - - private final Supplier loggingPrefixSupplier; - - ElasticsearchUncaughtExceptionHandler(final Supplier loggingPrefixSupplier) { - this.loggingPrefixSupplier = Objects.requireNonNull(loggingPrefixSupplier); - } + private static final Logger logger = Loggers.getLogger(ElasticsearchUncaughtExceptionHandler.class); @Override public void uncaughtException(Thread t, Throwable e) { @@ -70,12 +63,10 @@ static boolean isFatalUncaught(Throwable e) { } void onFatalUncaught(final String threadName, final Throwable t) { - final Logger logger = Loggers.getLogger(ElasticsearchUncaughtExceptionHandler.class, loggingPrefixSupplier.get()); logger.error(() -> new ParameterizedMessage("fatal error in thread [{}], exiting", threadName), t); } void onNonFatalUncaught(final String threadName, final Throwable t) { - final Logger logger = Loggers.getLogger(ElasticsearchUncaughtExceptionHandler.class, loggingPrefixSupplier.get()); logger.warn(() -> new ParameterizedMessage("uncaught exception in thread [{}]", threadName), t); } diff --git a/server/src/main/java/org/elasticsearch/common/logging/ESLoggerFactory.java b/server/src/main/java/org/elasticsearch/common/logging/ESLoggerFactory.java index 44d7d17b59325..cf864edb11830 100644 --- a/server/src/main/java/org/elasticsearch/common/logging/ESLoggerFactory.java +++ b/server/src/main/java/org/elasticsearch/common/logging/ESLoggerFactory.java @@ -46,6 +46,9 @@ public static Logger getLogger(String prefix, Class clazz) { } public static Logger getLogger(String prefix, Logger logger) { + if (prefix == null || prefix.length() == 0) { + return logger; + } return new PrefixLogger((ExtendedLogger)logger, logger.getName(), prefix); } diff --git a/server/src/main/java/org/elasticsearch/common/logging/LogConfigurator.java b/server/src/main/java/org/elasticsearch/common/logging/LogConfigurator.java index 01aca53db051d..ea25890ae7e9c 100644 --- a/server/src/main/java/org/elasticsearch/common/logging/LogConfigurator.java +++ b/server/src/main/java/org/elasticsearch/common/logging/LogConfigurator.java @@ -28,6 +28,7 @@ import org.apache.logging.log4j.core.config.builder.api.ConfigurationBuilderFactory; import org.apache.logging.log4j.core.config.builder.impl.BuiltConfiguration; import org.apache.logging.log4j.core.config.composite.CompositeConfiguration; +import org.apache.logging.log4j.core.config.plugins.util.PluginManager; import org.apache.logging.log4j.core.config.properties.PropertiesConfiguration; import org.apache.logging.log4j.core.config.properties.PropertiesConfigurationFactory; import org.apache.logging.log4j.status.StatusConsoleListener; @@ -119,6 +120,13 @@ public static void configure(final Environment environment) throws IOException, configure(environment.settings(), environment.configFile(), environment.logsFile()); } + /** + * Load logging plugins so we can have {@code node_name} in the pattern. + */ + public static void loadPlugins() { + PluginManager.addPackage(LogConfigurator.class.getPackage().getName()); + } + private static void checkErrorListener() { assert errorListenerIsRegistered() : "expected error listener to be registered"; if (error.get()) { @@ -135,6 +143,8 @@ private static void configure(final Settings settings, final Path configsPath, f Objects.requireNonNull(configsPath); Objects.requireNonNull(logsPath); + loadPlugins(); + setLogConfigurationSystemProperty(logsPath, settings); // we initialize the status logger immediately otherwise Log4j will complain when we try to get the context configureStatusLogger(); diff --git a/server/src/main/java/org/elasticsearch/common/logging/Loggers.java b/server/src/main/java/org/elasticsearch/common/logging/Loggers.java index 40983c517c72f..58ffe2775316b 100644 --- a/server/src/main/java/org/elasticsearch/common/logging/Loggers.java +++ b/server/src/main/java/org/elasticsearch/common/logging/Loggers.java @@ -31,13 +31,9 @@ import org.elasticsearch.common.settings.Settings; import org.elasticsearch.index.Index; import org.elasticsearch.index.shard.ShardId; -import org.elasticsearch.node.Node; -import java.util.ArrayList; -import java.util.List; import java.util.Map; -import static java.util.Arrays.asList; import static org.elasticsearch.common.util.CollectionUtils.asArrayList; /** @@ -71,29 +67,19 @@ public static Logger getLogger(Class clazz, Settings settings, Index index, S } public static Logger getLogger(Class clazz, Settings settings, String... prefixes) { - final List prefixesList = prefixesList(settings, prefixes); - return Loggers.getLogger(clazz, prefixesList.toArray(new String[prefixesList.size()])); + return Loggers.getLogger(clazz, prefixes); } public static Logger getLogger(String loggerName, Settings settings, String... prefixes) { - final List prefixesList = prefixesList(settings, prefixes); - return Loggers.getLogger(loggerName, prefixesList.toArray(new String[prefixesList.size()])); - } - - private static List prefixesList(Settings settings, String... prefixes) { - List prefixesList = new ArrayList<>(); - if (Node.NODE_NAME_SETTING.exists(settings)) { - prefixesList.add(Node.NODE_NAME_SETTING.get(settings)); - } - if (prefixes != null && prefixes.length > 0) { - prefixesList.addAll(asList(prefixes)); - } - return prefixesList; + return Loggers.getLogger(loggerName, prefixes); } public static Logger getLogger(Logger parentLogger, String s) { - assert parentLogger instanceof PrefixLogger; - return ESLoggerFactory.getLogger(((PrefixLogger)parentLogger).prefix(), parentLogger.getName() + s); + String prefix = null; + if (parentLogger instanceof PrefixLogger) { + prefix = ((PrefixLogger)parentLogger).prefix(); + } + return ESLoggerFactory.getLogger(prefix, parentLogger.getName() + s); } public static Logger getLogger(String s) { @@ -126,7 +112,6 @@ private static String formatPrefix(String... prefixes) { } } if (sb.length() > 0) { - sb.append(" "); prefix = sb.toString(); } } diff --git a/server/src/main/java/org/elasticsearch/common/logging/NodeNamePatternConverter.java b/server/src/main/java/org/elasticsearch/common/logging/NodeNamePatternConverter.java new file mode 100644 index 0000000000000..ca4c9ab776f6e --- /dev/null +++ b/server/src/main/java/org/elasticsearch/common/logging/NodeNamePatternConverter.java @@ -0,0 +1,72 @@ +/* + * Licensed to Elasticsearch under one or more contributor + * license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright + * ownership. Elasticsearch licenses this file to you under + * the Apache License, Version 2.0 (the "License"); you may + * not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, + * software distributed under the License is distributed on an + * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY + * KIND, either express or implied. See the License for the + * specific language governing permissions and limitations + * under the License. + */ + +package org.elasticsearch.common.logging; + +import java.util.Arrays; + +import org.apache.logging.log4j.core.LogEvent; +import org.apache.logging.log4j.core.config.plugins.Plugin; +import org.apache.logging.log4j.core.pattern.ConverterKeys; +import org.apache.logging.log4j.core.pattern.LogEventPatternConverter; +import org.apache.logging.log4j.core.pattern.PatternConverter; +import org.apache.lucene.util.SetOnce; + +/** + * Converts {@code %node_name} in log4j patterns into the current node name. + * We *could* use a system property lookup instead but this is very explicit + * and fails fast if we try to use the logger without initializing the node + * name. As a bonus it ought to be ever so slightly faster because it doesn't + * have to look up the system property every time. + */ +@Plugin(category = PatternConverter.CATEGORY, name = "NodeNamePatternConverter") +@ConverterKeys({"node_name"}) +public class NodeNamePatternConverter extends LogEventPatternConverter { + private static final SetOnce NODE_NAME = new SetOnce<>(); + + /** + * Set the name of this node. + */ + public static void setNodeName(String nodeName) { + NODE_NAME.set(nodeName); + } + + /** + * Called by log4j2 to initialize this converter. + */ + public static NodeNamePatternConverter newInstance(final String[] options) { + if (options.length > 0) { + throw new IllegalArgumentException("no options supported but options provided: " + + Arrays.toString(options)); + } + return new NodeNamePatternConverter(NODE_NAME.get()); + } + + private final String nodeName; + + private NodeNamePatternConverter(String nodeName) { + super("NodeName", "node_name"); + this.nodeName = nodeName; + } + + @Override + public void format(LogEvent event, StringBuilder toAppendTo) { + toAppendTo.append(nodeName); + } +} diff --git a/server/src/main/java/org/elasticsearch/node/Node.java b/server/src/main/java/org/elasticsearch/node/Node.java index 4440153dd361e..07dfcdfef87f9 100644 --- a/server/src/main/java/org/elasticsearch/node/Node.java +++ b/server/src/main/java/org/elasticsearch/node/Node.java @@ -228,7 +228,14 @@ public static final Settings addNodeNameIfNeeded(Settings settings, final String } private static final String CLIENT_TYPE = "node"; + private final Lifecycle lifecycle = new Lifecycle(); + + /** + * Logger initialized in the ctor because if it were initialized statically + * then it wouldn't get the node name. + */ + private final Logger logger; private final Injector injector; private final Settings settings; private final Settings originalSettings; @@ -254,13 +261,9 @@ public Node(Environment environment) { } protected Node(final Environment environment, Collection> classpathPlugins) { + logger = Loggers.getLogger(Node.class); final List resourcesToClose = new ArrayList<>(); // register everything we need to release in the case of an error boolean success = false; - { - // use temp logger just to say we are starting. we can't use it later on because the node name might not be set - Logger logger = Loggers.getLogger(Node.class, NODE_NAME_SETTING.get(environment.settings())); - logger.info("initializing ..."); - } try { originalSettings = environment.settings(); Settings tmpSettings = Settings.builder().put(environment.settings()) @@ -276,7 +279,6 @@ protected Node(final Environment environment, Collection final boolean hadPredefinedNodeName = NODE_NAME_SETTING.exists(tmpSettings); final String nodeId = nodeEnvironment.nodeId(); tmpSettings = addNodeNameIfNeeded(tmpSettings, nodeId); - final Logger logger = Loggers.getLogger(Node.class, tmpSettings); // this must be captured after the node name is possibly added to the settings final String nodeName = NODE_NAME_SETTING.get(tmpSettings); if (hadPredefinedNodeName == false) { @@ -620,7 +622,6 @@ public Node start() throws NodeValidationException { return this; } - Logger logger = Loggers.getLogger(Node.class, NODE_NAME_SETTING.get(settings)); logger.info("starting ..."); pluginLifecycleComponents.forEach(LifecycleComponent::start); @@ -731,7 +732,6 @@ private Node stop() { if (!lifecycle.moveToStopped()) { return this; } - Logger logger = Loggers.getLogger(Node.class, NODE_NAME_SETTING.get(settings)); logger.info("stopping ..."); injector.getInstance(ResourceWatcherService.class).stop(); @@ -774,7 +774,6 @@ public synchronized void close() throws IOException { return; } - Logger logger = Loggers.getLogger(Node.class, NODE_NAME_SETTING.get(settings)); logger.info("closing ..."); List toClose = new ArrayList<>(); StopWatch stopWatch = new StopWatch("node_close"); diff --git a/server/src/test/java/org/elasticsearch/bootstrap/BootstrapChecksTests.java b/server/src/test/java/org/elasticsearch/bootstrap/BootstrapChecksTests.java index e3ba6d19b39ca..8180dd96e8e18 100644 --- a/server/src/test/java/org/elasticsearch/bootstrap/BootstrapChecksTests.java +++ b/server/src/test/java/org/elasticsearch/bootstrap/BootstrapChecksTests.java @@ -131,7 +131,7 @@ public void testExceptionAggregation() { final NodeValidationException e = expectThrows(NodeValidationException.class, - () -> BootstrapChecks.check(defaultContext, true, checks, "testExceptionAggregation")); + () -> BootstrapChecks.check(defaultContext, true, checks)); assertThat(e, hasToString(allOf(containsString("bootstrap checks failed"), containsString("first"), containsString("second")))); final Throwable[] suppressed = e.getSuppressed(); assertThat(suppressed.length, equalTo(2)); @@ -162,7 +162,7 @@ long getMaxHeapSize() { final NodeValidationException e = expectThrows( NodeValidationException.class, - () -> BootstrapChecks.check(defaultContext, true, Collections.singletonList(check), "testHeapSizeCheck")); + () -> BootstrapChecks.check(defaultContext, true, Collections.singletonList(check))); assertThat( e.getMessage(), containsString("initial heap size [" + initialHeapSize.get() + "] " + @@ -170,7 +170,7 @@ long getMaxHeapSize() { initialHeapSize.set(maxHeapSize.get()); - BootstrapChecks.check(defaultContext, true, Collections.singletonList(check), "testHeapSizeCheck"); + BootstrapChecks.check(defaultContext, true, Collections.singletonList(check)); // nothing should happen if the initial heap size or the max // heap size is not available @@ -179,7 +179,7 @@ long getMaxHeapSize() { } else { maxHeapSize.set(0); } - BootstrapChecks.check(defaultContext, true, Collections.singletonList(check), "testHeapSizeCheck"); + BootstrapChecks.check(defaultContext, true, Collections.singletonList(check)); } public void testFileDescriptorLimits() throws NodeValidationException { @@ -205,17 +205,17 @@ long getMaxFileDescriptorCount() { final NodeValidationException e = expectThrows(NodeValidationException.class, - () -> BootstrapChecks.check(defaultContext, true, Collections.singletonList(check), "testFileDescriptorLimits")); + () -> BootstrapChecks.check(defaultContext, true, Collections.singletonList(check))); assertThat(e.getMessage(), containsString("max file descriptors")); maxFileDescriptorCount.set(randomIntBetween(limit + 1, Integer.MAX_VALUE)); - BootstrapChecks.check(defaultContext, true, Collections.singletonList(check), "testFileDescriptorLimits"); + BootstrapChecks.check(defaultContext, true, Collections.singletonList(check)); // nothing should happen if current file descriptor count is // not available maxFileDescriptorCount.set(-1); - BootstrapChecks.check(defaultContext, true, Collections.singletonList(check), "testFileDescriptorLimits"); + BootstrapChecks.check(defaultContext, true, Collections.singletonList(check)); } public void testFileDescriptorLimitsThrowsOnInvalidLimit() { @@ -262,15 +262,13 @@ boolean isMemoryLocked() { () -> BootstrapChecks.check( bootstrapContext, true, - Collections.singletonList(check), - "testFileDescriptorLimitsThrowsOnInvalidLimit")); + Collections.singletonList(check))); assertThat( e.getMessage(), containsString("memory locking requested for elasticsearch process but memory is not locked")); } else { // nothing should happen - BootstrapChecks.check(bootstrapContext, true, Collections.singletonList(check), - "testFileDescriptorLimitsThrowsOnInvalidLimit"); + BootstrapChecks.check(bootstrapContext, true, Collections.singletonList(check)); } } } @@ -287,17 +285,17 @@ long getMaxNumberOfThreads() { final NodeValidationException e = expectThrows( NodeValidationException.class, - () -> BootstrapChecks.check(defaultContext, true, Collections.singletonList(check), "testMaxNumberOfThreadsCheck")); + () -> BootstrapChecks.check(defaultContext, true, Collections.singletonList(check))); assertThat(e.getMessage(), containsString("max number of threads")); maxNumberOfThreads.set(randomIntBetween(limit + 1, Integer.MAX_VALUE)); - BootstrapChecks.check(defaultContext, true, Collections.singletonList(check), "testMaxNumberOfThreadsCheck"); + BootstrapChecks.check(defaultContext, true, Collections.singletonList(check)); // nothing should happen if current max number of threads is // not available maxNumberOfThreads.set(-1); - BootstrapChecks.check(defaultContext, true, Collections.singletonList(check), "testMaxNumberOfThreadsCheck"); + BootstrapChecks.check(defaultContext, true, Collections.singletonList(check)); } public void testMaxSizeVirtualMemory() throws NodeValidationException { @@ -317,16 +315,16 @@ long getRlimInfinity() { final NodeValidationException e = expectThrows( NodeValidationException.class, - () -> BootstrapChecks.check(defaultContext, true, Collections.singletonList(check), "testMaxSizeVirtualMemory")); + () -> BootstrapChecks.check(defaultContext, true, Collections.singletonList(check))); assertThat(e.getMessage(), containsString("max size virtual memory")); maxSizeVirtualMemory.set(rlimInfinity); - BootstrapChecks.check(defaultContext, true, Collections.singletonList(check), "testMaxSizeVirtualMemory"); + BootstrapChecks.check(defaultContext, true, Collections.singletonList(check)); // nothing should happen if max size virtual memory is not available maxSizeVirtualMemory.set(Long.MIN_VALUE); - BootstrapChecks.check(defaultContext, true, Collections.singletonList(check), "testMaxSizeVirtualMemory"); + BootstrapChecks.check(defaultContext, true, Collections.singletonList(check)); } public void testMaxFileSizeCheck() throws NodeValidationException { @@ -346,16 +344,16 @@ long getRlimInfinity() { final NodeValidationException e = expectThrows( NodeValidationException.class, - () -> BootstrapChecks.check(defaultContext, true, Collections.singletonList(check), "testMaxFileSize")); + () -> BootstrapChecks.check(defaultContext, true, Collections.singletonList(check))); assertThat(e.getMessage(), containsString("max file size")); maxFileSize.set(rlimInfinity); - BootstrapChecks.check(defaultContext, true, Collections.singletonList(check), "testMaxFileSize"); + BootstrapChecks.check(defaultContext, true, Collections.singletonList(check)); // nothing should happen if max file size is not available maxFileSize.set(Long.MIN_VALUE); - BootstrapChecks.check(defaultContext, true, Collections.singletonList(check), "testMaxFileSize"); + BootstrapChecks.check(defaultContext, true, Collections.singletonList(check)); } public void testMaxMapCountCheck() throws NodeValidationException { @@ -370,17 +368,17 @@ long getMaxMapCount() { final NodeValidationException e = expectThrows( NodeValidationException.class, - () -> BootstrapChecks.check(defaultContext, true, Collections.singletonList(check), "testMaxMapCountCheck")); + () -> BootstrapChecks.check(defaultContext, true, Collections.singletonList(check))); assertThat(e.getMessage(), containsString("max virtual memory areas vm.max_map_count")); maxMapCount.set(randomIntBetween(limit + 1, Integer.MAX_VALUE)); - BootstrapChecks.check(defaultContext, true, Collections.singletonList(check), "testMaxMapCountCheck"); + BootstrapChecks.check(defaultContext, true, Collections.singletonList(check)); // nothing should happen if current vm.max_map_count is not // available maxMapCount.set(-1); - BootstrapChecks.check(defaultContext, true, Collections.singletonList(check), "testMaxMapCountCheck"); + BootstrapChecks.check(defaultContext, true, Collections.singletonList(check)); } public void testClientJvmCheck() throws NodeValidationException { @@ -394,14 +392,14 @@ String getVmName() { final NodeValidationException e = expectThrows( NodeValidationException.class, - () -> BootstrapChecks.check(defaultContext, true, Collections.singletonList(check), "testClientJvmCheck")); + () -> BootstrapChecks.check(defaultContext, true, Collections.singletonList(check))); assertThat( e.getMessage(), containsString("JVM is using the client VM [Java HotSpot(TM) 32-Bit Client VM] " + "but should be using a server VM for the best performance")); vmName.set("Java HotSpot(TM) 32-Bit Server VM"); - BootstrapChecks.check(defaultContext, true, Collections.singletonList(check), "testClientJvmCheck"); + BootstrapChecks.check(defaultContext, true, Collections.singletonList(check)); } public void testUseSerialGCCheck() throws NodeValidationException { @@ -415,14 +413,14 @@ String getUseSerialGC() { final NodeValidationException e = expectThrows( NodeValidationException.class, - () -> BootstrapChecks.check(defaultContext, true, Collections.singletonList(check), "testUseSerialGCCheck")); + () -> BootstrapChecks.check(defaultContext, true, Collections.singletonList(check))); assertThat( e.getMessage(), containsString("JVM is using the serial collector but should not be for the best performance; " + "" + "either it's the default for the VM [" + JvmInfo.jvmInfo().getVmName() +"] or -XX:+UseSerialGC was explicitly specified")); useSerialGC.set("false"); - BootstrapChecks.check(defaultContext, true, Collections.singletonList(check), "testUseSerialGCCheck"); + BootstrapChecks.check(defaultContext, true, Collections.singletonList(check)); } public void testSystemCallFilterCheck() throws NodeValidationException { @@ -439,15 +437,14 @@ boolean isSystemCallFilterInstalled() { final NodeValidationException e = expectThrows( NodeValidationException.class, - () -> BootstrapChecks.check(context, true, Collections.singletonList(systemCallFilterEnabledCheck), - "testSystemCallFilterCheck")); + () -> BootstrapChecks.check(context, true, Collections.singletonList(systemCallFilterEnabledCheck))); assertThat( e.getMessage(), containsString("system call filters failed to install; " + "check the logs and fix your configuration or disable system call filters at your own risk")); isSystemCallFilterInstalled.set(true); - BootstrapChecks.check(context, true, Collections.singletonList(systemCallFilterEnabledCheck), "testSystemCallFilterCheck"); + BootstrapChecks.check(context, true, Collections.singletonList(systemCallFilterEnabledCheck)); BootstrapContext context_1 = new BootstrapContext(Settings.builder().put("bootstrap.system_call_filter", false).build(), null); final BootstrapChecks.SystemCallFilterCheck systemCallFilterNotEnabledCheck = new BootstrapChecks.SystemCallFilterCheck() { @Override @@ -456,9 +453,9 @@ boolean isSystemCallFilterInstalled() { } }; isSystemCallFilterInstalled.set(false); - BootstrapChecks.check(context_1, true, Collections.singletonList(systemCallFilterNotEnabledCheck), "testSystemCallFilterCheck"); + BootstrapChecks.check(context_1, true, Collections.singletonList(systemCallFilterNotEnabledCheck)); isSystemCallFilterInstalled.set(true); - BootstrapChecks.check(context_1, true, Collections.singletonList(systemCallFilterNotEnabledCheck), "testSystemCallFilterCheck"); + BootstrapChecks.check(context_1, true, Collections.singletonList(systemCallFilterNotEnabledCheck)); } public void testMightForkCheck() throws NodeValidationException { @@ -553,8 +550,6 @@ private void runMightForkTest( final Runnable enableMightFork, final Consumer consumer) throws NodeValidationException { - final String methodName = Thread.currentThread().getStackTrace()[2].getMethodName(); - // if system call filter is disabled, nothing should happen isSystemCallFilterInstalled.set(false); if (randomBoolean()) { @@ -562,13 +557,13 @@ private void runMightForkTest( } else { enableMightFork.run(); } - BootstrapChecks.check(defaultContext, true, Collections.singletonList(check), methodName); + BootstrapChecks.check(defaultContext, true, Collections.singletonList(check)); // if system call filter is enabled, but we will not fork, nothing should // happen isSystemCallFilterInstalled.set(true); disableMightFork.run(); - BootstrapChecks.check(defaultContext, true, Collections.singletonList(check), methodName); + BootstrapChecks.check(defaultContext, true, Collections.singletonList(check)); // if system call filter is enabled, and we might fork, the check should be enforced, regardless of bootstrap checks being enabled // or not @@ -577,7 +572,7 @@ private void runMightForkTest( final NodeValidationException e = expectThrows( NodeValidationException.class, - () -> BootstrapChecks.check(defaultContext, randomBoolean(), Collections.singletonList(check), methodName)); + () -> BootstrapChecks.check(defaultContext, randomBoolean(), Collections.singletonList(check))); consumer.accept(e); } @@ -602,7 +597,7 @@ String javaVersion() { final NodeValidationException e = expectThrows( NodeValidationException.class, () -> { - BootstrapChecks.check(defaultContext, true, checks, "testEarlyAccessCheck"); + BootstrapChecks.check(defaultContext, true, checks); }); assertThat( e.getMessage(), @@ -613,7 +608,7 @@ String javaVersion() { // if not on an early-access build, nothing should happen javaVersion.set(randomFrom("1.8.0_152", "9")); - BootstrapChecks.check(defaultContext, true, checks, "testEarlyAccessCheck"); + BootstrapChecks.check(defaultContext, true, checks); } @@ -649,7 +644,7 @@ boolean isJava8() { final NodeValidationException e = expectThrows( NodeValidationException.class, - () -> BootstrapChecks.check(defaultContext, true, Collections.singletonList(g1GCCheck), "testG1GCCheck")); + () -> BootstrapChecks.check(defaultContext, true, Collections.singletonList(g1GCCheck))); assertThat( e.getMessage(), containsString( @@ -657,12 +652,12 @@ boolean isJava8() { // if G1GC is disabled, nothing should happen isG1GCEnabled.set(false); - BootstrapChecks.check(defaultContext, true, Collections.singletonList(g1GCCheck), "testG1GCCheck"); + BootstrapChecks.check(defaultContext, true, Collections.singletonList(g1GCCheck)); // if on or after update 40, nothing should happen independent of whether or not G1GC is enabled isG1GCEnabled.set(randomBoolean()); jvmVersion.set(String.format(Locale.ROOT, "25.%d-b%d", randomIntBetween(40, 112), randomIntBetween(1, 128))); - BootstrapChecks.check(defaultContext, true, Collections.singletonList(g1GCCheck), "testG1GCCheck"); + BootstrapChecks.check(defaultContext, true, Collections.singletonList(g1GCCheck)); final BootstrapChecks.G1GCCheck nonOracleCheck = new BootstrapChecks.G1GCCheck() { @@ -674,7 +669,7 @@ String jvmVendor() { }; // if not on an Oracle JVM, nothing should happen - BootstrapChecks.check(defaultContext, true, Collections.singletonList(nonOracleCheck), "testG1GCCheck"); + BootstrapChecks.check(defaultContext, true, Collections.singletonList(nonOracleCheck)); final BootstrapChecks.G1GCCheck nonJava8Check = new BootstrapChecks.G1GCCheck() { @@ -686,7 +681,7 @@ boolean isJava8() { }; // if not Java 8, nothing should happen - BootstrapChecks.check(defaultContext, true, Collections.singletonList(nonJava8Check), "testG1GCCheck"); + BootstrapChecks.check(defaultContext, true, Collections.singletonList(nonJava8Check)); } public void testAllPermissionCheck() throws NodeValidationException { @@ -701,12 +696,12 @@ boolean isAllPermissionGranted() { final List checks = Collections.singletonList(allPermissionCheck); final NodeValidationException e = expectThrows( NodeValidationException.class, - () -> BootstrapChecks.check(defaultContext, true, checks, "testIsAllPermissionCheck")); + () -> BootstrapChecks.check(defaultContext, true, checks)); assertThat(e, hasToString(containsString("granting the all permission effectively disables security"))); // if all permissions are not granted, nothing should happen isAllPermissionGranted.set(false); - BootstrapChecks.check(defaultContext, true, checks, "testIsAllPermissionCheck"); + BootstrapChecks.check(defaultContext, true, checks); } public void testAlwaysEnforcedChecks() { @@ -724,7 +719,7 @@ public boolean alwaysEnforce() { final NodeValidationException alwaysEnforced = expectThrows( NodeValidationException.class, - () -> BootstrapChecks.check(defaultContext, randomBoolean(), Collections.singletonList(check), "testAlwaysEnforcedChecks")); + () -> BootstrapChecks.check(defaultContext, randomBoolean(), Collections.singletonList(check))); assertThat(alwaysEnforced, hasToString(containsString("error"))); } diff --git a/server/src/test/java/org/elasticsearch/bootstrap/ElasticsearchUncaughtExceptionHandlerTests.java b/server/src/test/java/org/elasticsearch/bootstrap/ElasticsearchUncaughtExceptionHandlerTests.java index e2bf07b7d0bb4..a6e50170d7e80 100644 --- a/server/src/test/java/org/elasticsearch/bootstrap/ElasticsearchUncaughtExceptionHandlerTests.java +++ b/server/src/test/java/org/elasticsearch/bootstrap/ElasticsearchUncaughtExceptionHandlerTests.java @@ -65,7 +65,7 @@ public void testUncaughtError() throws InterruptedException { final AtomicInteger observedStatus = new AtomicInteger(); final AtomicReference threadNameReference = new AtomicReference<>(); final AtomicReference throwableReference = new AtomicReference<>(); - thread.setUncaughtExceptionHandler(new ElasticsearchUncaughtExceptionHandler(() -> "testUncaughtError") { + thread.setUncaughtExceptionHandler(new ElasticsearchUncaughtExceptionHandler() { @Override void halt(int status) { @@ -106,7 +106,7 @@ public void testUncaughtException() throws InterruptedException { thread.setName(name); final AtomicReference threadNameReference = new AtomicReference<>(); final AtomicReference throwableReference = new AtomicReference<>(); - thread.setUncaughtExceptionHandler(new ElasticsearchUncaughtExceptionHandler(() -> "testUncaughtException") { + thread.setUncaughtExceptionHandler(new ElasticsearchUncaughtExceptionHandler() { @Override void halt(int status) { fail(); diff --git a/server/src/test/java/org/elasticsearch/index/engine/InternalEngineTests.java b/server/src/test/java/org/elasticsearch/index/engine/InternalEngineTests.java index 2e89a66805ce1..26a8b56b54c6e 100644 --- a/server/src/test/java/org/elasticsearch/index/engine/InternalEngineTests.java +++ b/server/src/test/java/org/elasticsearch/index/engine/InternalEngineTests.java @@ -1979,7 +1979,7 @@ private static class MockAppender extends AbstractAppender { @Override public void append(LogEvent event) { final String formattedMessage = event.getMessage().getFormattedMessage(); - if (event.getLevel() == Level.TRACE && event.getMarker().getName().contains("[index][0] ")) { + if (event.getLevel() == Level.TRACE && event.getMarker().getName().contains("[index][0]")) { if (event.getLoggerName().endsWith(".IW") && formattedMessage.contains("IW: now apply all deletes")) { sawIndexWriterMessage = true; diff --git a/test/framework/src/main/java/org/elasticsearch/bootstrap/BootstrapForTesting.java b/test/framework/src/main/java/org/elasticsearch/bootstrap/BootstrapForTesting.java index c4bf2518a9f8f..f9f3a718b8adf 100644 --- a/test/framework/src/main/java/org/elasticsearch/bootstrap/BootstrapForTesting.java +++ b/test/framework/src/main/java/org/elasticsearch/bootstrap/BootstrapForTesting.java @@ -28,6 +28,7 @@ import org.elasticsearch.common.io.FileSystemUtils; import org.elasticsearch.common.io.PathUtils; import org.elasticsearch.common.logging.ESLoggerFactory; +import org.elasticsearch.common.logging.LogConfigurator; import org.elasticsearch.common.network.IfConfig; import org.elasticsearch.plugins.PluginInfo; import org.elasticsearch.secure_sm.SecureSM; @@ -68,6 +69,8 @@ public class BootstrapForTesting { // without making things complex??? static { + LogConfigurator.loadPlugins(); + // make sure java.io.tmpdir exists always (in case code uses it in a static initializer) Path javaTmpDir = PathUtils.get(Objects.requireNonNull(System.getProperty("java.io.tmpdir"), "please set ${java.io.tmpdir} in pom.xml")); diff --git a/test/framework/src/main/java/org/elasticsearch/common/logging/TestThreadInfoPatternConverter.java b/test/framework/src/main/java/org/elasticsearch/common/logging/TestThreadInfoPatternConverter.java new file mode 100644 index 0000000000000..bd310458fdaea --- /dev/null +++ b/test/framework/src/main/java/org/elasticsearch/common/logging/TestThreadInfoPatternConverter.java @@ -0,0 +1,130 @@ +/* + * Licensed to Elasticsearch under one or more contributor + * license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright + * ownership. Elasticsearch licenses this file to you under + * the Apache License, Version 2.0 (the "License"); you may + * not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, + * software distributed under the License is distributed on an + * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY + * KIND, either express or implied. See the License for the + * specific language governing permissions and limitations + * under the License. + */ + +package org.elasticsearch.common.logging; + +import java.util.Arrays; +import java.util.regex.Matcher; +import java.util.regex.Pattern; + +import org.apache.logging.log4j.core.LogEvent; +import org.apache.logging.log4j.core.config.plugins.Plugin; +import org.apache.logging.log4j.core.pattern.ConverterKeys; +import org.apache.logging.log4j.core.pattern.LogEventPatternConverter; +import org.apache.logging.log4j.core.pattern.PatternConverter; +import org.apache.lucene.util.CloseableThreadLocal; +import org.elasticsearch.common.collect.Tuple; +import org.elasticsearch.test.ESIntegTestCase; + +/** + * Converts {@code %test_thread_info} in log4j patterns into information + * based on the loggin thread's name. If that thread is part of an + * {@link ESIntegTestCase} then this information is the node name. + */ +@Plugin(category = PatternConverter.CATEGORY, name = "TestInfoPatternConverter") +@ConverterKeys({"test_thread_info"}) +public class TestThreadInfoPatternConverter extends LogEventPatternConverter { + /** + * Called by log4j2 to initialize this converter. + */ + public static TestThreadInfoPatternConverter newInstance(final String[] options) { + if (options.length > 0) { + throw new IllegalArgumentException("no options supported but options provided: " + + Arrays.toString(options)); + } + return new TestThreadInfoPatternConverter(); + } + + private TestThreadInfoPatternConverter() { + super("TestInfo", "test_thread_info"); + } + + /** + * Cache of the string to output for this thread. It is a thread local + * because Elasticsearch's tests log synchronously so the formatting + * thread should be the same as the logging thread so the cache + * *should* only miss when a thread changes its name. Which they do. + * + * Having the cache saves a couple of milliseconds off of a test run + * of a few minutes. + */ + private static final CloseableThreadLocal> cache = new CloseableThreadLocal<>(); + + @Override + public void format(LogEvent event, StringBuilder toAppendTo) { + String threadName = event.getThreadName(); + Tuple t = cache.get(); + if (t == null || false == t.v1().equals(threadName)) { + t = new Tuple<>(threadName, threadInfo(threadName)); + cache.set(t); + } + toAppendTo.append(t.v2()); + } + + private static final Pattern ELASTICSEARCH_THREAD_NAME_PATTERN = + Pattern.compile("elasticsearch\\[(.+)\\]\\[.+\\].+"); + private static final Pattern TEST_THREAD_NAME_PATTERN = + Pattern.compile("TEST-.+\\.(.+)-seed#\\[.+\\]"); + private static final Pattern TEST_SUITE_INIT_THREAD_NAME_PATTERN = + Pattern.compile("SUITE-.+-worker"); + private static final Pattern NOT_YET_NAMED_NODE_THREAD_NAME_PATTERN = + Pattern.compile("test_SUITE-CHILD_VM.+cluster\\[T#(.+)\\]"); + static String threadInfo(String threadName) { + Matcher m = ELASTICSEARCH_THREAD_NAME_PATTERN.matcher(threadName); + if (m.matches()) { + // Thread looks like a node thread so use the node name + return m.group(1); + } + m = TEST_THREAD_NAME_PATTERN.matcher(threadName); + if (m.matches()) { + /* + * Thread looks like a test thread so use the test method name. + * It'd be pretty reasonable not to use a prefix at all here but + * the logger layout pretty much expects one and the test method + * can be pretty nice to have around anyway. + */ + return m.group(1); + } + m = TEST_SUITE_INIT_THREAD_NAME_PATTERN.matcher(threadName); + if (m.matches()) { + /* + * Thread looks like test suite initialization or tead down and + * we don't have any more information to give. Like above, we + * could spit out nothing here but the logger layout expect + * something and it *is* nice to know what lines come from test + * teardown and initialization. + */ + return "suite"; + } + m = NOT_YET_NAMED_NODE_THREAD_NAME_PATTERN.matcher(threadName); + if (m.matches()) { + /* + * These are as yet unnamed integ test nodes. I'd prefer to log + * the node name but I don't have it yet. + */ + return "integ_" + m.group(1) + ""; + } + /* + * These are uncategorized threads. We log the entire thread name in + * case it is useful. We wrap it in `[]` so you tell that it is a + * thread name rather than a node name or something. + */ + return "[" + threadName + "]"; + } +} diff --git a/test/framework/src/main/java/org/elasticsearch/test/ESTestCase.java b/test/framework/src/main/java/org/elasticsearch/test/ESTestCase.java index 7d44b3230a15f..a1b7021a17644 100644 --- a/test/framework/src/main/java/org/elasticsearch/test/ESTestCase.java +++ b/test/framework/src/main/java/org/elasticsearch/test/ESTestCase.java @@ -285,7 +285,7 @@ public static void restoreContentType() { @Before public final void before() { - logger.info("[{}]: before test", getTestName()); + logger.info("before test"); assertNull("Thread context initialized twice", threadContext); if (enableWarningsCheck()) { this.threadContext = new ThreadContext(Settings.EMPTY); @@ -314,7 +314,7 @@ public final void after() throws Exception { } ensureAllSearchContextsReleased(); ensureCheckIndexPassed(); - logger.info("[{}]: after test", getTestName()); + logger.info("after test"); } private void ensureNoWarnings() throws IOException { diff --git a/test/framework/src/main/resources/log4j2-test.properties b/test/framework/src/main/resources/log4j2-test.properties index 828555ed52e6f..842c9c79d7963 100644 --- a/test/framework/src/main/resources/log4j2-test.properties +++ b/test/framework/src/main/resources/log4j2-test.properties @@ -1,7 +1,7 @@ appender.console.type = Console appender.console.name = console appender.console.layout.type = PatternLayout -appender.console.layout.pattern = [%d{ISO8601}][%-5p][%-25c{1.}] %marker%m%n +appender.console.layout.pattern = [%d{ISO8601}][%-5p][%-25c{1.}] [%test_thread_info]%marker %m%n rootLogger.level = ${sys:tests.es.logger.level:-info} rootLogger.appenderRef.console.ref = console diff --git a/test/framework/src/main/resources/log4j2.component.properties b/test/framework/src/main/resources/log4j2.component.properties new file mode 100644 index 0000000000000..03999d8a266da --- /dev/null +++ b/test/framework/src/main/resources/log4j2.component.properties @@ -0,0 +1,7 @@ +# RandomizedRunner renames threads and we'd like to look at accurate thread +# names. Also, this is the default in log4j2's master branch for versions of +# Java after 1.8_102 which most of the versions we use are anyway. After that +# version of Java calling `Thread.getName()` doesn't allocate so UNCACHED +# ought to be faster than CACHED because it doesn't have to deal with +# ThreadLocals. +AsyncLogger.ThreadNameStrategy = UNCACHED diff --git a/test/framework/src/test/java/org/elasticsearch/common/logging/TestThreadInfoPatternConverterTests.java b/test/framework/src/test/java/org/elasticsearch/common/logging/TestThreadInfoPatternConverterTests.java new file mode 100644 index 0000000000000..8a98b867a46f5 --- /dev/null +++ b/test/framework/src/test/java/org/elasticsearch/common/logging/TestThreadInfoPatternConverterTests.java @@ -0,0 +1,53 @@ +/* + * Licensed to Elasticsearch under one or more contributor + * license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright + * ownership. Elasticsearch licenses this file to you under + * the Apache License, Version 2.0 (the "License"); you may + * not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, + * software distributed under the License is distributed on an + * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY + * KIND, either express or implied. See the License for the + * specific language governing permissions and limitations + * under the License. + */ + +package org.elasticsearch.common.logging; + +import org.elasticsearch.common.util.concurrent.EsExecutors; +import org.elasticsearch.test.ESTestCase; +import org.junit.BeforeClass; + +import static org.elasticsearch.common.logging.TestThreadInfoPatternConverter.threadInfo; + +public class TestThreadInfoPatternConverterTests extends ESTestCase { + private static String suiteInfo; + + @BeforeClass + public static void captureSuiteInfo() { + suiteInfo = threadInfo(Thread.currentThread().getName()); + } + + public void testThreadInfo() { + // Threads that are part of a node get the node name + String nodeName = randomAlphaOfLength(5); + String threadName = EsExecutors.threadName(nodeName, randomAlphaOfLength(20)) + + "[T#" + between(0, 1000) + "]"; + assertEquals(nodeName, threadInfo(threadName)); + + // Test threads get the test name + assertEquals(getTestName(), threadInfo(Thread.currentThread().getName())); + + // Suite initalization gets "suite" + assertEquals("suite", suiteInfo); + + // And stuff that doesn't match anything gets wrapped in [] so we can see it + String unmatched = randomAlphaOfLength(5); + assertEquals("[" + unmatched + "]", threadInfo(unmatched)); + } +} From 29074b2dab5f38629fa34266be09de54324f8ed5 Mon Sep 17 00:00:00 2001 From: Nik Everett Date: Wed, 27 Jun 2018 09:39:53 -0400 Subject: [PATCH 02/13] Cleanup from review --- .../rest-api-spec/test/info/10_info.yml | 2 +- .../common/logging/ESLoggerFactory.java | 4 ++++ .../common/logging/LogConfigurator.java | 4 ++-- .../bootstrap/BootstrapForTesting.java | 2 +- .../TestThreadInfoPatternConverter.java | 21 +------------------ .../resources/log4j2.component.properties | 2 ++ 6 files changed, 11 insertions(+), 24 deletions(-) diff --git a/rest-api-spec/src/main/resources/rest-api-spec/test/info/10_info.yml b/rest-api-spec/src/main/resources/rest-api-spec/test/info/10_info.yml index d0c99ee0a7c5b..1b32327f04138 100644 --- a/rest-api-spec/src/main/resources/rest-api-spec/test/info/10_info.yml +++ b/rest-api-spec/src/main/resources/rest-api-spec/test/info/10_info.yml @@ -6,4 +6,4 @@ - is_true: cluster_uuid - is_true: tagline - is_true: version - - is_true: version.number + - is_false: version.number diff --git a/server/src/main/java/org/elasticsearch/common/logging/ESLoggerFactory.java b/server/src/main/java/org/elasticsearch/common/logging/ESLoggerFactory.java index cf864edb11830..8770c1f3754d2 100644 --- a/server/src/main/java/org/elasticsearch/common/logging/ESLoggerFactory.java +++ b/server/src/main/java/org/elasticsearch/common/logging/ESLoggerFactory.java @@ -47,6 +47,10 @@ public static Logger getLogger(String prefix, Class clazz) { public static Logger getLogger(String prefix, Logger logger) { if (prefix == null || prefix.length() == 0) { + /* + * In an followup we'll throw an exception in this case directing + * folks to LogManger.getLogger. + */ return logger; } return new PrefixLogger((ExtendedLogger)logger, logger.getName(), prefix); diff --git a/server/src/main/java/org/elasticsearch/common/logging/LogConfigurator.java b/server/src/main/java/org/elasticsearch/common/logging/LogConfigurator.java index ea25890ae7e9c..a026af59291fd 100644 --- a/server/src/main/java/org/elasticsearch/common/logging/LogConfigurator.java +++ b/server/src/main/java/org/elasticsearch/common/logging/LogConfigurator.java @@ -123,7 +123,7 @@ public static void configure(final Environment environment) throws IOException, /** * Load logging plugins so we can have {@code node_name} in the pattern. */ - public static void loadPlugins() { + public static void loadLog4jPlugins() { PluginManager.addPackage(LogConfigurator.class.getPackage().getName()); } @@ -143,7 +143,7 @@ private static void configure(final Settings settings, final Path configsPath, f Objects.requireNonNull(configsPath); Objects.requireNonNull(logsPath); - loadPlugins(); + loadLog4jPlugins(); setLogConfigurationSystemProperty(logsPath, settings); // we initialize the status logger immediately otherwise Log4j will complain when we try to get the context diff --git a/test/framework/src/main/java/org/elasticsearch/bootstrap/BootstrapForTesting.java b/test/framework/src/main/java/org/elasticsearch/bootstrap/BootstrapForTesting.java index 56b512db9a142..318b566013ee2 100644 --- a/test/framework/src/main/java/org/elasticsearch/bootstrap/BootstrapForTesting.java +++ b/test/framework/src/main/java/org/elasticsearch/bootstrap/BootstrapForTesting.java @@ -70,7 +70,7 @@ public class BootstrapForTesting { // without making things complex??? static { - LogConfigurator.loadPlugins(); + LogConfigurator.loadLog4jPlugins(); // make sure java.io.tmpdir exists always (in case code uses it in a static initializer) Path javaTmpDir = PathUtils.get(Objects.requireNonNull(System.getProperty("java.io.tmpdir"), diff --git a/test/framework/src/main/java/org/elasticsearch/common/logging/TestThreadInfoPatternConverter.java b/test/framework/src/main/java/org/elasticsearch/common/logging/TestThreadInfoPatternConverter.java index bd310458fdaea..35ad331f532ff 100644 --- a/test/framework/src/main/java/org/elasticsearch/common/logging/TestThreadInfoPatternConverter.java +++ b/test/framework/src/main/java/org/elasticsearch/common/logging/TestThreadInfoPatternConverter.java @@ -28,8 +28,6 @@ import org.apache.logging.log4j.core.pattern.ConverterKeys; import org.apache.logging.log4j.core.pattern.LogEventPatternConverter; import org.apache.logging.log4j.core.pattern.PatternConverter; -import org.apache.lucene.util.CloseableThreadLocal; -import org.elasticsearch.common.collect.Tuple; import org.elasticsearch.test.ESIntegTestCase; /** @@ -55,26 +53,9 @@ private TestThreadInfoPatternConverter() { super("TestInfo", "test_thread_info"); } - /** - * Cache of the string to output for this thread. It is a thread local - * because Elasticsearch's tests log synchronously so the formatting - * thread should be the same as the logging thread so the cache - * *should* only miss when a thread changes its name. Which they do. - * - * Having the cache saves a couple of milliseconds off of a test run - * of a few minutes. - */ - private static final CloseableThreadLocal> cache = new CloseableThreadLocal<>(); - @Override public void format(LogEvent event, StringBuilder toAppendTo) { - String threadName = event.getThreadName(); - Tuple t = cache.get(); - if (t == null || false == t.v1().equals(threadName)) { - t = new Tuple<>(threadName, threadInfo(threadName)); - cache.set(t); - } - toAppendTo.append(t.v2()); + toAppendTo.append(threadInfo(event.getThreadName())); } private static final Pattern ELASTICSEARCH_THREAD_NAME_PATTERN = diff --git a/test/framework/src/main/resources/log4j2.component.properties b/test/framework/src/main/resources/log4j2.component.properties index 03999d8a266da..8ce0fb493b7b6 100644 --- a/test/framework/src/main/resources/log4j2.component.properties +++ b/test/framework/src/main/resources/log4j2.component.properties @@ -4,4 +4,6 @@ # version of Java calling `Thread.getName()` doesn't allocate so UNCACHED # ought to be faster than CACHED because it doesn't have to deal with # ThreadLocals. +# While we don't use AsyncLogger, we do end up with mutable log events and +# those use this key for configuration. AsyncLogger.ThreadNameStrategy = UNCACHED From 76a6607db01a978cc0b6c719d28e50168fe2777b Mon Sep 17 00:00:00 2001 From: Nik Everett Date: Wed, 27 Jun 2018 10:11:07 -0400 Subject: [PATCH 03/13] Add back test parameters if there are any --- .../resources/rest-api-spec/test/info/10_info.yml | 2 +- .../java/org/elasticsearch/test/ESTestCase.java | 13 +++++++++++-- 2 files changed, 12 insertions(+), 3 deletions(-) diff --git a/rest-api-spec/src/main/resources/rest-api-spec/test/info/10_info.yml b/rest-api-spec/src/main/resources/rest-api-spec/test/info/10_info.yml index 1b32327f04138..d0c99ee0a7c5b 100644 --- a/rest-api-spec/src/main/resources/rest-api-spec/test/info/10_info.yml +++ b/rest-api-spec/src/main/resources/rest-api-spec/test/info/10_info.yml @@ -6,4 +6,4 @@ - is_true: cluster_uuid - is_true: tagline - is_true: version - - is_false: version.number + - is_true: version.number diff --git a/test/framework/src/main/java/org/elasticsearch/test/ESTestCase.java b/test/framework/src/main/java/org/elasticsearch/test/ESTestCase.java index a1b7021a17644..3e1f841fb578f 100644 --- a/test/framework/src/main/java/org/elasticsearch/test/ESTestCase.java +++ b/test/framework/src/main/java/org/elasticsearch/test/ESTestCase.java @@ -285,7 +285,7 @@ public static void restoreContentType() { @Before public final void before() { - logger.info("before test"); + logger.info("{}before test", getTestParamsForLogging()); assertNull("Thread context initialized twice", threadContext); if (enableWarningsCheck()) { this.threadContext = new ThreadContext(Settings.EMPTY); @@ -314,7 +314,16 @@ public final void after() throws Exception { } ensureAllSearchContextsReleased(); ensureCheckIndexPassed(); - logger.info("after test"); + logger.info("{}after test", getTestParamsForLogging()); + } + + private String getTestParamsForLogging() { + String name = getTestName(); + int start = name.indexOf('{'); + if (start < 0) return ""; + int end = name.lastIndexOf('}'); + if (end < 0) return ""; + return "[" + name.substring(start + 1, end) + "] "; } private void ensureNoWarnings() throws IOException { From c924ade5d52514626130905aae1480a2b20f54e1 Mon Sep 17 00:00:00 2001 From: Nik Everett Date: Wed, 18 Jul 2018 14:43:24 -0400 Subject: [PATCH 04/13] Revert log4j2.properties changes Revert the log4j2.properties changes and instead hack the changes in at configuration time. This should allow us to backport this entire change set to 6.x which should make backporting other changes simpler. We'll replace the hack in the master branch only in a followup change. --- .../src/main/resources/log4j2.properties | 2 +- .../src/main/resources/log4j2.properties | 2 +- distribution/src/config/log4j2.properties | 10 ++--- .../common/logging/ESLoggerFactory.java | 12 ++++-- .../common/logging/LogConfigurator.java | 43 ++++++++++++++++++- 5 files changed, 57 insertions(+), 12 deletions(-) diff --git a/benchmarks/src/main/resources/log4j2.properties b/benchmarks/src/main/resources/log4j2.properties index 808d611670f31..c3ae1fe56d3d1 100644 --- a/benchmarks/src/main/resources/log4j2.properties +++ b/benchmarks/src/main/resources/log4j2.properties @@ -1,7 +1,7 @@ appender.console.type = Console appender.console.name = console appender.console.layout.type = PatternLayout -appender.console.layout.pattern = [%d{ISO8601}][%-5p][%-25c] [%node_name]%marker %m%n +appender.console.layout.pattern = [%d{ISO8601}][%-5p][%-25c] %marker%m%n # Do not log at all if it is not really critical - we're in a benchmark rootLogger.level = error diff --git a/client/benchmark/src/main/resources/log4j2.properties b/client/benchmark/src/main/resources/log4j2.properties index a68c7f5653f87..8652131bf4916 100644 --- a/client/benchmark/src/main/resources/log4j2.properties +++ b/client/benchmark/src/main/resources/log4j2.properties @@ -1,7 +1,7 @@ appender.console.type = Console appender.console.name = console appender.console.layout.type = PatternLayout -appender.console.layout.pattern = [%d{ISO8601}][%-5p][%-25c] [%node_name]%marker %m%n +appender.console.layout.pattern = [%d{ISO8601}][%-5p][%-25c] %marker%m%n rootLogger.level = info rootLogger.appenderRef.console.ref = console diff --git a/distribution/src/config/log4j2.properties b/distribution/src/config/log4j2.properties index 6de21cd48f67b..589f529e83eaa 100644 --- a/distribution/src/config/log4j2.properties +++ b/distribution/src/config/log4j2.properties @@ -7,13 +7,13 @@ logger.action.level = debug appender.console.type = Console appender.console.name = console appender.console.layout.type = PatternLayout -appender.console.layout.pattern = [%d{ISO8601}][%-5p][%-25c{1.}] [%node_name]%marker %m%n +appender.console.layout.pattern = [%d{ISO8601}][%-5p][%-25c{1.}] %marker%m%n appender.rolling.type = RollingFile appender.rolling.name = rolling appender.rolling.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}.log appender.rolling.layout.type = PatternLayout -appender.rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c{1.}] [%node_name]%marker %.-10000m%n +appender.rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c{1.}] %marker%.-10000m%n appender.rolling.filePattern = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}-%d{yyyy-MM-dd}-%i.log.gz appender.rolling.policies.type = Policies appender.rolling.policies.time.type = TimeBasedTriggeringPolicy @@ -38,7 +38,7 @@ appender.deprecation_rolling.type = RollingFile appender.deprecation_rolling.name = deprecation_rolling appender.deprecation_rolling.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_deprecation.log appender.deprecation_rolling.layout.type = PatternLayout -appender.deprecation_rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c{1.}] [%node_name]%marker %.-10000m%n +appender.deprecation_rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c{1.}] %marker%.-10000m%n appender.deprecation_rolling.filePattern = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_deprecation-%i.log.gz appender.deprecation_rolling.policies.type = Policies appender.deprecation_rolling.policies.size.type = SizeBasedTriggeringPolicy @@ -55,7 +55,7 @@ appender.index_search_slowlog_rolling.type = RollingFile appender.index_search_slowlog_rolling.name = index_search_slowlog_rolling appender.index_search_slowlog_rolling.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_index_search_slowlog.log appender.index_search_slowlog_rolling.layout.type = PatternLayout -appender.index_search_slowlog_rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c] [%node_name]%marker %.-10000m%n +appender.index_search_slowlog_rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c] %marker%.-10000m%n appender.index_search_slowlog_rolling.filePattern = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_index_search_slowlog-%i.log.gz appender.index_search_slowlog_rolling.policies.type = Policies appender.index_search_slowlog_rolling.policies.size.type = SizeBasedTriggeringPolicy @@ -72,7 +72,7 @@ appender.index_indexing_slowlog_rolling.type = RollingFile appender.index_indexing_slowlog_rolling.name = index_indexing_slowlog_rolling appender.index_indexing_slowlog_rolling.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_index_indexing_slowlog.log appender.index_indexing_slowlog_rolling.layout.type = PatternLayout -appender.index_indexing_slowlog_rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c] [%node_name]%marker %.-10000m%n +appender.index_indexing_slowlog_rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c] %marker%.-10000m%n appender.index_indexing_slowlog_rolling.filePattern = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_index_indexing_slowlog-%i.log.gz appender.index_indexing_slowlog_rolling.policies.type = Policies appender.index_indexing_slowlog_rolling.policies.size.type = SizeBasedTriggeringPolicy diff --git a/server/src/main/java/org/elasticsearch/common/logging/ESLoggerFactory.java b/server/src/main/java/org/elasticsearch/common/logging/ESLoggerFactory.java index 8770c1f3754d2..ace0f63ed6c98 100644 --- a/server/src/main/java/org/elasticsearch/common/logging/ESLoggerFactory.java +++ b/server/src/main/java/org/elasticsearch/common/logging/ESLoggerFactory.java @@ -46,11 +46,15 @@ public static Logger getLogger(String prefix, Class clazz) { } public static Logger getLogger(String prefix, Logger logger) { + /* + * In a followup we'll throw an exception if prefix is null or empty + * redirecting folks to LogManager.getLogger. No need to create a + * PrefixLogger or even go through our own logging classes in that + * case. + * + * This and more is tracker in https://github.com/elastic/elasticsearch/issues/32174 + */ if (prefix == null || prefix.length() == 0) { - /* - * In an followup we'll throw an exception in this case directing - * folks to LogManger.getLogger. - */ return logger; } return new PrefixLogger((ExtendedLogger)logger, logger.getName(), prefix); diff --git a/server/src/main/java/org/elasticsearch/common/logging/LogConfigurator.java b/server/src/main/java/org/elasticsearch/common/logging/LogConfigurator.java index a026af59291fd..3ebbbfde2388b 100644 --- a/server/src/main/java/org/elasticsearch/common/logging/LogConfigurator.java +++ b/server/src/main/java/org/elasticsearch/common/logging/LogConfigurator.java @@ -23,6 +23,8 @@ import org.apache.logging.log4j.LogManager; import org.apache.logging.log4j.core.LoggerContext; import org.apache.logging.log4j.core.config.AbstractConfiguration; +import org.apache.logging.log4j.core.config.ConfigurationException; +import org.apache.logging.log4j.core.config.ConfigurationSource; import org.apache.logging.log4j.core.config.Configurator; import org.apache.logging.log4j.core.config.builder.api.ConfigurationBuilder; import org.apache.logging.log4j.core.config.builder.api.ConfigurationBuilderFactory; @@ -30,6 +32,7 @@ import org.apache.logging.log4j.core.config.composite.CompositeConfiguration; import org.apache.logging.log4j.core.config.plugins.util.PluginManager; import org.apache.logging.log4j.core.config.properties.PropertiesConfiguration; +import org.apache.logging.log4j.core.config.properties.PropertiesConfigurationBuilder; import org.apache.logging.log4j.core.config.properties.PropertiesConfigurationFactory; import org.apache.logging.log4j.status.StatusConsoleListener; import org.apache.logging.log4j.status.StatusData; @@ -44,6 +47,7 @@ import org.elasticsearch.node.Node; import java.io.IOException; +import java.io.InputStream; import java.nio.file.FileVisitOption; import java.nio.file.FileVisitResult; import java.nio.file.Files; @@ -54,6 +58,7 @@ import java.util.EnumSet; import java.util.List; import java.util.Objects; +import java.util.Properties; import java.util.Set; import java.util.concurrent.atomic.AtomicBoolean; import java.util.stream.StreamSupport; @@ -152,7 +157,43 @@ private static void configure(final Settings settings, final Path configsPath, f final LoggerContext context = (LoggerContext) LogManager.getContext(false); final List configurations = new ArrayList<>(); - final PropertiesConfigurationFactory factory = new PropertiesConfigurationFactory(); + /* + * Subclass the properties configurator to hack the new pattern in + * place of the so users don't have to change log4j2.properties in + * a minor release. In 7.0 we'll remove this and force users to + * change log4j2.properties. If they don't customize log4j2.properties + * then they won't have to do anything anyway. + * + * Everything in this subclass that isn't marked as a hack is copied + * from log4j2's source. + */ + final PropertiesConfigurationFactory factory = new PropertiesConfigurationFactory() { + @Override + public PropertiesConfiguration getConfiguration(final LoggerContext loggerContext, final ConfigurationSource source) { + final Properties properties = new Properties(); + try (InputStream configStream = source.getInputStream()) { + properties.load(configStream); + } catch (final IOException ioe) { + throw new ConfigurationException("Unable to load " + source.toString(), ioe); + } + // Hack the new pattern into place + for (String name : properties.stringPropertyNames()) { + if (false == name.endsWith(".pattern")) { + continue; + } + String value = properties.getProperty(name); + if (value != null && value.contains("%marker") && false == value.contains("%test_thread_info")) { + properties.setProperty(name, value.replace("%marker", "[%node_name]%marker ")); + } + } + // end hack + return new PropertiesConfigurationBuilder() + .setConfigurationSource(source) + .setRootProperties(properties) + .setLoggerContext(loggerContext) + .build(); + } + }; final Set options = EnumSet.of(FileVisitOption.FOLLOW_LINKS); Files.walkFileTree(configsPath, options, Integer.MAX_VALUE, new SimpleFileVisitor() { @Override From a98de4a4a8e5d9e0f21fcc1fdb25c607c9fef055 Mon Sep 17 00:00:00 2001 From: Nik Everett Date: Wed, 18 Jul 2018 14:49:27 -0400 Subject: [PATCH 05/13] Rever asciidoc changes --- docs/reference/index-modules/slowlog.asciidoc | 4 ++-- docs/reference/setup/logging-config.asciidoc | 2 +- 2 files changed, 3 insertions(+), 3 deletions(-) diff --git a/docs/reference/index-modules/slowlog.asciidoc b/docs/reference/index-modules/slowlog.asciidoc index 235256bdce7c0..1dc84f380f509 100644 --- a/docs/reference/index-modules/slowlog.asciidoc +++ b/docs/reference/index-modules/slowlog.asciidoc @@ -50,7 +50,7 @@ appender.index_search_slowlog_rolling.type = RollingFile appender.index_search_slowlog_rolling.name = index_search_slowlog_rolling appender.index_search_slowlog_rolling.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_index_search_slowlog.log appender.index_search_slowlog_rolling.layout.type = PatternLayout -appender.index_search_slowlog_rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c] [%node_name]%marker %.-10000m%n +appender.index_search_slowlog_rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c] %marker%.-10000m%n appender.index_search_slowlog_rolling.filePattern = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_index_search_slowlog-%i.log.gz appender.index_search_slowlog_rolling.policies.type = Policies appender.index_search_slowlog_rolling.policies.size.type = SizeBasedTriggeringPolicy @@ -103,7 +103,7 @@ appender.index_indexing_slowlog_rolling.type = RollingFile appender.index_indexing_slowlog_rolling.name = index_indexing_slowlog_rolling appender.index_indexing_slowlog_rolling.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_index_indexing_slowlog.log appender.index_indexing_slowlog_rolling.layout.type = PatternLayout -appender.index_indexing_slowlog_rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c] [%node_name]%marker %.-10000m%n +appender.index_indexing_slowlog_rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c] %marker%.-10000m%n appender.index_indexing_slowlog_rolling.filePattern = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_index_indexing_slowlog-%i.log.gz appender.index_indexing_slowlog_rolling.policies.type = Policies appender.index_indexing_slowlog_rolling.policies.size.type = SizeBasedTriggeringPolicy diff --git a/docs/reference/setup/logging-config.asciidoc b/docs/reference/setup/logging-config.asciidoc index ac949bc941a9c..d35b3db2df7f3 100644 --- a/docs/reference/setup/logging-config.asciidoc +++ b/docs/reference/setup/logging-config.asciidoc @@ -25,7 +25,7 @@ appender.rolling.type = RollingFile <1> appender.rolling.name = rolling appender.rolling.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}.log <2> appender.rolling.layout.type = PatternLayout -appender.rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c{1.}] [%node_name]%marker %.-10000m%n +appender.rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c{1.}] %marker%.-10000m%n appender.rolling.filePattern = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}-%d{yyyy-MM-dd}-%i.log.gz <3> appender.rolling.policies.type = Policies appender.rolling.policies.time.type = TimeBasedTriggeringPolicy <4> From c428a081b62f00bee9e610d17900e8062d198ae0 Mon Sep 17 00:00:00 2001 From: Nik Everett Date: Wed, 18 Jul 2018 14:54:11 -0400 Subject: [PATCH 06/13] Remove another asciidoc change This one should stay reverted, I think. --- docs/java-api/index.asciidoc | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/docs/java-api/index.asciidoc b/docs/java-api/index.asciidoc index c268915da9390..4fb7db4c4abf6 100644 --- a/docs/java-api/index.asciidoc +++ b/docs/java-api/index.asciidoc @@ -94,7 +94,7 @@ For example, you can add in your `src/main/resources` project dir a `log4j2.prop appender.console.type = Console appender.console.name = console appender.console.layout.type = PatternLayout -appender.console.layout.pattern = [%d{ISO8601}][%-5p][%-25c] %marker %m%n +appender.console.layout.pattern = [%d{ISO8601}][%-5p][%-25c] %marker%m%n rootLogger.level = info rootLogger.appenderRef.console.ref = console From d1b1999f707184576ffec386fc0e0f6f7abbd1e4 Mon Sep 17 00:00:00 2001 From: Nik Everett Date: Wed, 18 Jul 2018 14:56:31 -0400 Subject: [PATCH 07/13] Update docs --- .../org/elasticsearch/common/logging/ESLoggerFactory.java | 4 +--- 1 file changed, 1 insertion(+), 3 deletions(-) diff --git a/server/src/main/java/org/elasticsearch/common/logging/ESLoggerFactory.java b/server/src/main/java/org/elasticsearch/common/logging/ESLoggerFactory.java index ace0f63ed6c98..0f4f6b308ab42 100644 --- a/server/src/main/java/org/elasticsearch/common/logging/ESLoggerFactory.java +++ b/server/src/main/java/org/elasticsearch/common/logging/ESLoggerFactory.java @@ -48,9 +48,7 @@ public static Logger getLogger(String prefix, Class clazz) { public static Logger getLogger(String prefix, Logger logger) { /* * In a followup we'll throw an exception if prefix is null or empty - * redirecting folks to LogManager.getLogger. No need to create a - * PrefixLogger or even go through our own logging classes in that - * case. + * redirecting folks to LogManager.getLogger. * * This and more is tracker in https://github.com/elastic/elasticsearch/issues/32174 */ From 25c1b3e7177d5d490cc261bacea716af833c6f98 Mon Sep 17 00:00:00 2001 From: Nik Everett Date: Fri, 20 Jul 2018 10:33:00 -0400 Subject: [PATCH 08/13] Add warning --- .../src/main/resources/log4j2.properties | 2 +- .../src/main/resources/log4j2.properties | 2 +- distribution/src/config/log4j2.properties | 10 +++---- docs/reference/index-modules/slowlog.asciidoc | 4 +-- docs/reference/setup/logging-config.asciidoc | 2 +- .../common/logging/LogConfigurator.java | 29 ++++++++++++++++--- 6 files changed, 35 insertions(+), 14 deletions(-) diff --git a/benchmarks/src/main/resources/log4j2.properties b/benchmarks/src/main/resources/log4j2.properties index c3ae1fe56d3d1..808d611670f31 100644 --- a/benchmarks/src/main/resources/log4j2.properties +++ b/benchmarks/src/main/resources/log4j2.properties @@ -1,7 +1,7 @@ appender.console.type = Console appender.console.name = console appender.console.layout.type = PatternLayout -appender.console.layout.pattern = [%d{ISO8601}][%-5p][%-25c] %marker%m%n +appender.console.layout.pattern = [%d{ISO8601}][%-5p][%-25c] [%node_name]%marker %m%n # Do not log at all if it is not really critical - we're in a benchmark rootLogger.level = error diff --git a/client/benchmark/src/main/resources/log4j2.properties b/client/benchmark/src/main/resources/log4j2.properties index 8652131bf4916..a68c7f5653f87 100644 --- a/client/benchmark/src/main/resources/log4j2.properties +++ b/client/benchmark/src/main/resources/log4j2.properties @@ -1,7 +1,7 @@ appender.console.type = Console appender.console.name = console appender.console.layout.type = PatternLayout -appender.console.layout.pattern = [%d{ISO8601}][%-5p][%-25c] %marker%m%n +appender.console.layout.pattern = [%d{ISO8601}][%-5p][%-25c] [%node_name]%marker %m%n rootLogger.level = info rootLogger.appenderRef.console.ref = console diff --git a/distribution/src/config/log4j2.properties b/distribution/src/config/log4j2.properties index 589f529e83eaa..6de21cd48f67b 100644 --- a/distribution/src/config/log4j2.properties +++ b/distribution/src/config/log4j2.properties @@ -7,13 +7,13 @@ logger.action.level = debug appender.console.type = Console appender.console.name = console appender.console.layout.type = PatternLayout -appender.console.layout.pattern = [%d{ISO8601}][%-5p][%-25c{1.}] %marker%m%n +appender.console.layout.pattern = [%d{ISO8601}][%-5p][%-25c{1.}] [%node_name]%marker %m%n appender.rolling.type = RollingFile appender.rolling.name = rolling appender.rolling.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}.log appender.rolling.layout.type = PatternLayout -appender.rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c{1.}] %marker%.-10000m%n +appender.rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c{1.}] [%node_name]%marker %.-10000m%n appender.rolling.filePattern = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}-%d{yyyy-MM-dd}-%i.log.gz appender.rolling.policies.type = Policies appender.rolling.policies.time.type = TimeBasedTriggeringPolicy @@ -38,7 +38,7 @@ appender.deprecation_rolling.type = RollingFile appender.deprecation_rolling.name = deprecation_rolling appender.deprecation_rolling.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_deprecation.log appender.deprecation_rolling.layout.type = PatternLayout -appender.deprecation_rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c{1.}] %marker%.-10000m%n +appender.deprecation_rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c{1.}] [%node_name]%marker %.-10000m%n appender.deprecation_rolling.filePattern = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_deprecation-%i.log.gz appender.deprecation_rolling.policies.type = Policies appender.deprecation_rolling.policies.size.type = SizeBasedTriggeringPolicy @@ -55,7 +55,7 @@ appender.index_search_slowlog_rolling.type = RollingFile appender.index_search_slowlog_rolling.name = index_search_slowlog_rolling appender.index_search_slowlog_rolling.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_index_search_slowlog.log appender.index_search_slowlog_rolling.layout.type = PatternLayout -appender.index_search_slowlog_rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c] %marker%.-10000m%n +appender.index_search_slowlog_rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c] [%node_name]%marker %.-10000m%n appender.index_search_slowlog_rolling.filePattern = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_index_search_slowlog-%i.log.gz appender.index_search_slowlog_rolling.policies.type = Policies appender.index_search_slowlog_rolling.policies.size.type = SizeBasedTriggeringPolicy @@ -72,7 +72,7 @@ appender.index_indexing_slowlog_rolling.type = RollingFile appender.index_indexing_slowlog_rolling.name = index_indexing_slowlog_rolling appender.index_indexing_slowlog_rolling.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_index_indexing_slowlog.log appender.index_indexing_slowlog_rolling.layout.type = PatternLayout -appender.index_indexing_slowlog_rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c] %marker%.-10000m%n +appender.index_indexing_slowlog_rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c] [%node_name]%marker %.-10000m%n appender.index_indexing_slowlog_rolling.filePattern = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_index_indexing_slowlog-%i.log.gz appender.index_indexing_slowlog_rolling.policies.type = Policies appender.index_indexing_slowlog_rolling.policies.size.type = SizeBasedTriggeringPolicy diff --git a/docs/reference/index-modules/slowlog.asciidoc b/docs/reference/index-modules/slowlog.asciidoc index 1dc84f380f509..235256bdce7c0 100644 --- a/docs/reference/index-modules/slowlog.asciidoc +++ b/docs/reference/index-modules/slowlog.asciidoc @@ -50,7 +50,7 @@ appender.index_search_slowlog_rolling.type = RollingFile appender.index_search_slowlog_rolling.name = index_search_slowlog_rolling appender.index_search_slowlog_rolling.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_index_search_slowlog.log appender.index_search_slowlog_rolling.layout.type = PatternLayout -appender.index_search_slowlog_rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c] %marker%.-10000m%n +appender.index_search_slowlog_rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c] [%node_name]%marker %.-10000m%n appender.index_search_slowlog_rolling.filePattern = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_index_search_slowlog-%i.log.gz appender.index_search_slowlog_rolling.policies.type = Policies appender.index_search_slowlog_rolling.policies.size.type = SizeBasedTriggeringPolicy @@ -103,7 +103,7 @@ appender.index_indexing_slowlog_rolling.type = RollingFile appender.index_indexing_slowlog_rolling.name = index_indexing_slowlog_rolling appender.index_indexing_slowlog_rolling.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_index_indexing_slowlog.log appender.index_indexing_slowlog_rolling.layout.type = PatternLayout -appender.index_indexing_slowlog_rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c] %marker%.-10000m%n +appender.index_indexing_slowlog_rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c] [%node_name]%marker %.-10000m%n appender.index_indexing_slowlog_rolling.filePattern = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_index_indexing_slowlog-%i.log.gz appender.index_indexing_slowlog_rolling.policies.type = Policies appender.index_indexing_slowlog_rolling.policies.size.type = SizeBasedTriggeringPolicy diff --git a/docs/reference/setup/logging-config.asciidoc b/docs/reference/setup/logging-config.asciidoc index d35b3db2df7f3..ac949bc941a9c 100644 --- a/docs/reference/setup/logging-config.asciidoc +++ b/docs/reference/setup/logging-config.asciidoc @@ -25,7 +25,7 @@ appender.rolling.type = RollingFile <1> appender.rolling.name = rolling appender.rolling.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}.log <2> appender.rolling.layout.type = PatternLayout -appender.rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c{1.}] %marker%.-10000m%n +appender.rolling.layout.pattern = [%d{ISO8601}][%-5p][%-25c{1.}] [%node_name]%marker %.-10000m%n appender.rolling.filePattern = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}-%d{yyyy-MM-dd}-%i.log.gz <3> appender.rolling.policies.type = Policies appender.rolling.policies.time.type = TimeBasedTriggeringPolicy <4> diff --git a/server/src/main/java/org/elasticsearch/common/logging/LogConfigurator.java b/server/src/main/java/org/elasticsearch/common/logging/LogConfigurator.java index 3ebbbfde2388b..adfdb4b273f56 100644 --- a/server/src/main/java/org/elasticsearch/common/logging/LogConfigurator.java +++ b/server/src/main/java/org/elasticsearch/common/logging/LogConfigurator.java @@ -55,11 +55,14 @@ import java.nio.file.SimpleFileVisitor; import java.nio.file.attribute.BasicFileAttributes; import java.util.ArrayList; +import java.util.Collections; import java.util.EnumSet; +import java.util.HashSet; import java.util.List; import java.util.Objects; import java.util.Properties; import java.util.Set; +import java.util.concurrent.CopyOnWriteArrayList; import java.util.concurrent.atomic.AtomicBoolean; import java.util.stream.StreamSupport; @@ -157,6 +160,7 @@ private static void configure(final Settings settings, final Path configsPath, f final LoggerContext context = (LoggerContext) LogManager.getContext(false); final List configurations = new ArrayList<>(); + /* * Subclass the properties configurator to hack the new pattern in * place of the so users don't have to change log4j2.properties in @@ -167,6 +171,7 @@ private static void configure(final Settings settings, final Path configsPath, f * Everything in this subclass that isn't marked as a hack is copied * from log4j2's source. */ + Set locationsWithDeprecatedPatterns = Collections.synchronizedSet(new HashSet<>()); final PropertiesConfigurationFactory factory = new PropertiesConfigurationFactory() { @Override public PropertiesConfiguration getConfiguration(final LoggerContext loggerContext, final ConfigurationSource source) { @@ -178,11 +183,19 @@ public PropertiesConfiguration getConfiguration(final LoggerContext loggerContex } // Hack the new pattern into place for (String name : properties.stringPropertyNames()) { - if (false == name.endsWith(".pattern")) { - continue; - } + if (false == name.endsWith(".pattern")) continue; + // Null is weird here but we can't do anything with it so ignore it String value = properties.getProperty(name); - if (value != null && value.contains("%marker") && false == value.contains("%test_thread_info")) { + if (value == null) continue; + // Tests don't need to be changed + if (value.contains("%test_thread_info")) continue; + /* + * Patterns without a marker are sufficiently customized + * that we don't have an opinion about them. + */ + if (false == value.contains("%marker")) continue; + if (false == value.contains("%node_name")) { + locationsWithDeprecatedPatterns.add(source.getLocation()); properties.setProperty(name, value.replace("%marker", "[%node_name]%marker ")); } } @@ -214,6 +227,14 @@ public FileVisitResult visitFile(final Path file, final BasicFileAttributes attr context.start(new CompositeConfiguration(configurations)); configureLoggerLevels(settings); + + final String deprecatedLocationsString = String.join("\n ", locationsWithDeprecatedPatterns); + if (deprecatedLocationsString.length() > 0) { + LogManager.getLogger(LogConfigurator.class).warn("Some logging configurations have %marker but don't have %node_name. " + + "We will automatically add %node_name to the pattern to ease the migration for users who customize " + + "log4j2.properties but will stop this behavior in 7.0. You should manually replace `%node_name` with " + + "`[%node_name]%marker ` in these locations:\n {}", deprecatedLocationsString); + } } private static void configureStatusLogger() { From 75a10e2c05d045b6568c406b67357e625402900d Mon Sep 17 00:00:00 2001 From: Nik Everett Date: Fri, 20 Jul 2018 13:30:50 -0400 Subject: [PATCH 09/13] Checkstyle --- .../java/org/elasticsearch/common/logging/LogConfigurator.java | 1 - 1 file changed, 1 deletion(-) diff --git a/server/src/main/java/org/elasticsearch/common/logging/LogConfigurator.java b/server/src/main/java/org/elasticsearch/common/logging/LogConfigurator.java index adfdb4b273f56..13e15e0bb0628 100644 --- a/server/src/main/java/org/elasticsearch/common/logging/LogConfigurator.java +++ b/server/src/main/java/org/elasticsearch/common/logging/LogConfigurator.java @@ -62,7 +62,6 @@ import java.util.Objects; import java.util.Properties; import java.util.Set; -import java.util.concurrent.CopyOnWriteArrayList; import java.util.concurrent.atomic.AtomicBoolean; import java.util.stream.StreamSupport; From 7122d0f1757c803c6d246117a5bb47089f9fa262 Mon Sep 17 00:00:00 2001 From: Nik Everett Date: Mon, 23 Jul 2018 15:28:26 -0400 Subject: [PATCH 10/13] Set configuration --- .../authc/esnative/ESNativeRealmMigrateTool.java | 11 ++++++++--- 1 file changed, 8 insertions(+), 3 deletions(-) diff --git a/x-pack/plugin/security/src/main/java/org/elasticsearch/xpack/security/authc/esnative/ESNativeRealmMigrateTool.java b/x-pack/plugin/security/src/main/java/org/elasticsearch/xpack/security/authc/esnative/ESNativeRealmMigrateTool.java index 4226607f192f4..f28fe1c297f5b 100644 --- a/x-pack/plugin/security/src/main/java/org/elasticsearch/xpack/security/authc/esnative/ESNativeRealmMigrateTool.java +++ b/x-pack/plugin/security/src/main/java/org/elasticsearch/xpack/security/authc/esnative/ESNativeRealmMigrateTool.java @@ -363,9 +363,16 @@ static Logger getTerminalLogger(final Terminal terminal) { final Logger logger = ESLoggerFactory.getLogger(ESNativeRealmMigrateTool.class); Loggers.setLevel(logger, Level.ALL); + final LoggerContext ctx = (LoggerContext) LogManager.getContext(false); + final Configuration config = ctx.getConfiguration(); + // create appender final Appender appender = new AbstractAppender(ESNativeRealmMigrateTool.class.getName(), null, - PatternLayout.newBuilder().withPattern("%m").build()) { + PatternLayout.newBuilder() + // Specify the configuration so log4j doesn't re-initialize + .withConfiguration(config) + .withPattern("%m") + .build()) { @Override public void append(LogEvent event) { switch (event.getLevel().getStandardLevel()) { @@ -384,8 +391,6 @@ public void append(LogEvent event) { appender.start(); // get the config, detach from parent, remove appenders, add custom appender - final LoggerContext ctx = (LoggerContext) LogManager.getContext(false); - final Configuration config = ctx.getConfiguration(); final LoggerConfig loggerConfig = config.getLoggerConfig(ESNativeRealmMigrateTool.class.getName()); loggerConfig.setParent(null); loggerConfig.getAppenders().forEach((s, a) -> Loggers.removeAppender(logger, a)); From eaea37b5c3946c6063c8d8cc9bb3d0ef01c2a449 Mon Sep 17 00:00:00 2001 From: Nik Everett Date: Mon, 23 Jul 2018 15:45:25 -0400 Subject: [PATCH 11/13] Test --- .../common/logging/EvilLoggerTests.java | 19 ++++++++++++++ .../logging/no_node_name/log4j2.properties | 25 +++++++++++++++++++ 2 files changed, 44 insertions(+) create mode 100644 qa/evil-tests/src/test/resources/org/elasticsearch/common/logging/no_node_name/log4j2.properties diff --git a/qa/evil-tests/src/test/java/org/elasticsearch/common/logging/EvilLoggerTests.java b/qa/evil-tests/src/test/java/org/elasticsearch/common/logging/EvilLoggerTests.java index 8ff2a185e90bc..9285abad9b9d9 100644 --- a/qa/evil-tests/src/test/java/org/elasticsearch/common/logging/EvilLoggerTests.java +++ b/qa/evil-tests/src/test/java/org/elasticsearch/common/logging/EvilLoggerTests.java @@ -56,6 +56,7 @@ import java.util.stream.Collectors; import java.util.stream.IntStream; +import static org.hamcrest.Matchers.endsWith; import static org.hamcrest.Matchers.equalTo; import static org.hamcrest.Matchers.hasItem; import static org.hamcrest.Matchers.lessThan; @@ -359,6 +360,24 @@ public void testProperties() throws IOException, UserException { } } + public void testNoNodeNameWarning() throws IOException, UserException { + setupLogging("no_node_name"); + + final String path = + System.getProperty("es.logs.base_path") + + System.getProperty("file.separator") + + System.getProperty("es.logs.cluster_name") + ".log"; + final List events = Files.readAllLines(PathUtils.get(path)); + assertThat(events.size(), equalTo(2)); + final String location = "org.elasticsearch.common.logging.LogConfigurator"; + // the first message is a warning for unsupported configuration files + assertLogLine(events.get(0), Level.WARN, location, "\\[null\\] Some logging configurations have %marker but don't " + + "have %node_name. We will automatically add %node_name to the pattern to ease the migration for users " + + "who customize log4j2.properties but will stop this behavior in 7.0. You should manually replace " + + "`%node_name` with `\\[%node_name\\]%marker ` in these locations:"); + assertThat(events.get(1), endsWith("no_node_name/log4j2.properties")); + } + private void setupLogging(final String config) throws IOException, UserException { setupLogging(config, Settings.EMPTY); } diff --git a/qa/evil-tests/src/test/resources/org/elasticsearch/common/logging/no_node_name/log4j2.properties b/qa/evil-tests/src/test/resources/org/elasticsearch/common/logging/no_node_name/log4j2.properties new file mode 100644 index 0000000000000..fd7af2ce73136 --- /dev/null +++ b/qa/evil-tests/src/test/resources/org/elasticsearch/common/logging/no_node_name/log4j2.properties @@ -0,0 +1,25 @@ +appender.console.type = Console +appender.console.name = console +appender.console.layout.type = PatternLayout +appender.console.layout.pattern = [%d{ISO8601}][%-5p][%-25c] %marker%m%n + +appender.file.type = File +appender.file.name = file +appender.file.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}.log +appender.file.layout.type = PatternLayout +appender.file.layout.pattern = [%p][%l] %marker%m%n + +rootLogger.level = info +rootLogger.appenderRef.console.ref = console +rootLogger.appenderRef.file.ref = file + +appender.deprecation_file.type = File +appender.deprecation_file.name = deprecation_file +appender.deprecation_file.fileName = ${sys:es.logs.base_path}${sys:file.separator}${sys:es.logs.cluster_name}_deprecation.log +appender.deprecation_file.layout.type = PatternLayout +appender.deprecation_file.layout.pattern = [%p][%l] %marker%m%n + +logger.deprecation.name = deprecation +logger.deprecation.level = warn +logger.deprecation.appenderRef.deprecation_file.ref = deprecation_file +logger.deprecation.additivity = false From f1ba7c57dbf892101a2d96aa0f10f3d1dc7704ce Mon Sep 17 00:00:00 2001 From: Nik Everett Date: Tue, 24 Jul 2018 10:41:10 -0400 Subject: [PATCH 12/13] Move logger initialization --- .../java/org/elasticsearch/bootstrap/BootstrapForTesting.java | 3 --- .../src/main/java/org/elasticsearch/test/ESTestCase.java | 3 +++ 2 files changed, 3 insertions(+), 3 deletions(-) diff --git a/test/framework/src/main/java/org/elasticsearch/bootstrap/BootstrapForTesting.java b/test/framework/src/main/java/org/elasticsearch/bootstrap/BootstrapForTesting.java index 318b566013ee2..35dac2e99e00d 100644 --- a/test/framework/src/main/java/org/elasticsearch/bootstrap/BootstrapForTesting.java +++ b/test/framework/src/main/java/org/elasticsearch/bootstrap/BootstrapForTesting.java @@ -29,7 +29,6 @@ import org.elasticsearch.common.io.FileSystemUtils; import org.elasticsearch.common.io.PathUtils; import org.elasticsearch.common.logging.ESLoggerFactory; -import org.elasticsearch.common.logging.LogConfigurator; import org.elasticsearch.common.network.IfConfig; import org.elasticsearch.plugins.PluginInfo; import org.elasticsearch.secure_sm.SecureSM; @@ -70,8 +69,6 @@ public class BootstrapForTesting { // without making things complex??? static { - LogConfigurator.loadLog4jPlugins(); - // make sure java.io.tmpdir exists always (in case code uses it in a static initializer) Path javaTmpDir = PathUtils.get(Objects.requireNonNull(System.getProperty("java.io.tmpdir"), "please set ${java.io.tmpdir} in pom.xml")); diff --git a/test/framework/src/main/java/org/elasticsearch/test/ESTestCase.java b/test/framework/src/main/java/org/elasticsearch/test/ESTestCase.java index 30a41a1156fcf..a9f51697e3579 100644 --- a/test/framework/src/main/java/org/elasticsearch/test/ESTestCase.java +++ b/test/framework/src/main/java/org/elasticsearch/test/ESTestCase.java @@ -65,6 +65,7 @@ import org.elasticsearch.common.io.stream.Streamable; import org.elasticsearch.common.io.stream.Writeable; import org.elasticsearch.common.logging.DeprecationLogger; +import org.elasticsearch.common.logging.LogConfigurator; import org.elasticsearch.common.logging.Loggers; import org.elasticsearch.common.settings.Setting; import org.elasticsearch.common.settings.Settings; @@ -199,6 +200,8 @@ public static void resetPortCounter() { System.setProperty("log4j.shutdownHookEnabled", "false"); System.setProperty("log4j2.disable.jmx", "true"); + LogConfigurator.loadLog4jPlugins(); + // Enable Netty leak detection and monitor logger for logged leak errors System.setProperty("io.netty.leakDetection.level", "advanced"); String leakLoggerName = "io.netty.util.ResourceLeakDetector"; From 9dbd4bef77bf6953f8e7280851e9cf03e1c28dce Mon Sep 17 00:00:00 2001 From: Nik Everett Date: Mon, 30 Jul 2018 18:58:09 -0400 Subject: [PATCH 13/13] Fixup --- .../java/org/elasticsearch/common/logging/ESLoggerFactory.java | 2 +- .../java/org/elasticsearch/common/logging/LogConfigurator.java | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/server/src/main/java/org/elasticsearch/common/logging/ESLoggerFactory.java b/server/src/main/java/org/elasticsearch/common/logging/ESLoggerFactory.java index 0f4f6b308ab42..caa922b92cfd1 100644 --- a/server/src/main/java/org/elasticsearch/common/logging/ESLoggerFactory.java +++ b/server/src/main/java/org/elasticsearch/common/logging/ESLoggerFactory.java @@ -50,7 +50,7 @@ public static Logger getLogger(String prefix, Logger logger) { * In a followup we'll throw an exception if prefix is null or empty * redirecting folks to LogManager.getLogger. * - * This and more is tracker in https://github.com/elastic/elasticsearch/issues/32174 + * This and more is tracked in https://github.com/elastic/elasticsearch/issues/32174 */ if (prefix == null || prefix.length() == 0) { return logger; diff --git a/server/src/main/java/org/elasticsearch/common/logging/LogConfigurator.java b/server/src/main/java/org/elasticsearch/common/logging/LogConfigurator.java index 13e15e0bb0628..4e3771f36680d 100644 --- a/server/src/main/java/org/elasticsearch/common/logging/LogConfigurator.java +++ b/server/src/main/java/org/elasticsearch/common/logging/LogConfigurator.java @@ -162,7 +162,7 @@ private static void configure(final Settings settings, final Path configsPath, f /* * Subclass the properties configurator to hack the new pattern in - * place of the so users don't have to change log4j2.properties in + * place so users don't have to change log4j2.properties in * a minor release. In 7.0 we'll remove this and force users to * change log4j2.properties. If they don't customize log4j2.properties * then they won't have to do anything anyway.