Logging: Make node name consistent in logger

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

@@ -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"));
             }
         }
     }

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/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));
     }
 
     /**

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<String> loggingPrefixSupplier;
-
-    ElasticsearchUncaughtExceptionHandler(final Supplier<String> 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);
     }
 

server/src/main/java/org/elasticsearch/common/logging/ESLoggerFactory.java

@@ -46,6 +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.
+         *
+         * This and more is tracker in https://github.com/elastic/elasticsearch/issues/32174
+         */
+        if (prefix == null || prefix.length() == 0) {
+            return logger;
+        }
         return new PrefixLogger((ExtendedLogger)logger, logger.getName(), prefix);
     }
 

server/src/main/java/org/elasticsearch/common/logging/LogConfigurator.java

@@ -23,12 +23,16 @@
 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;
 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.PropertiesConfigurationBuilder;
 import org.apache.logging.log4j.core.config.properties.PropertiesConfigurationFactory;
 import org.apache.logging.log4j.status.StatusConsoleListener;
 import org.apache.logging.log4j.status.StatusData;
@@ -43,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;
@@ -53,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;
@@ -119,6 +125,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 loadLog4jPlugins() {
+        PluginManager.addPackage(LogConfigurator.class.getPackage().getName());
+    }
+
     private static void checkErrorListener() {
         assert errorListenerIsRegistered() : "expected error listener to be registered";
         if (error.get()) {
@@ -135,14 +148,52 @@ private static void configure(final Settings settings, final Path configsPath, f
         Objects.requireNonNull(configsPath);
         Objects.requireNonNull(logsPath);
 
+        loadLog4jPlugins();
+
         setLogConfigurationSystemProperty(logsPath, settings);
         // we initialize the status logger immediately otherwise Log4j will complain when we try to get the context
         configureStatusLogger();
 
         final LoggerContext context = (LoggerContext) LogManager.getContext(false);
 
         final List<AbstractConfiguration> 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<FileVisitOption> options = EnumSet.of(FileVisitOption.FOLLOW_LINKS);
         Files.walkFileTree(configsPath, options, Integer.MAX_VALUE, new SimpleFileVisitor<Path>() {
             @Override