Logging: Make node name consistent in logger

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

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

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

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

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>

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<String> matcher = containsString(
                 "[es.enforce.bootstrap.checks] must be [true] but was [" + value + "]");
         assertThat(e, hasToString(matcher));

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;
@@ -319,9 +320,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"));
             }
         }
     }
@@ -357,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<String> 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);
     }

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
-

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

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

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

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

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

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

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

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);
 

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<BootstrapCheck> checks,
-        final String nodeName) throws NodeValidationException {
-        check(context, enforceLimits, checks, Loggers.getLogger(BootstrapChecks.class, nodeName));
+        final List<BootstrapCheck> checks) throws NodeValidationException {
+        check(context, enforceLimits, checks, Loggers.getLogger(BootstrapChecks.class));
     }
 
     /**