Logging: Configure the node name when we have it (elastic#32983)

Change the logging infrastructure to handle when the node name isn't available in `elasticsearch.yml`. In that case the node name is not available until long after logging is configured. The biggest change is that the node name logging no longer fixed at pattern build time. Instead it is read from a `SetOnce` on every print. If it is unset it is printed as `unknown` so we have something that fits in the pattern. On normal startup we don't log anything until the node name is available so we never see the `unknown`s.
nik9000 · Sep 7, 2018 · 190ea9a · 190ea9a
1 parent 8d61457
commit 190ea9a
Show file tree

Hide file tree

Showing 21 changed files with 363 additions and 79 deletions.
diff --git a/buildSrc/src/main/groovy/org/elasticsearch/gradle/test/ClusterFormationTasks.groovy b/buildSrc/src/main/groovy/org/elasticsearch/gradle/test/ClusterFormationTasks.groovy
@@ -337,7 +337,13 @@ class ClusterFormationTasks {
         if (node.nodeVersion.major >= 7) {
             esConfig['indices.breaker.total.use_real_memory'] = false
         }
-        esConfig.putAll(node.config.settings)
+        for (Map.Entry<String, Object> setting : node.config.settings) {
+            if (setting.value == null) {
+                esConfig.remove(setting.key)
+            } else {
+                esConfig.put(setting.key, setting.value)
+            }
+        }
 
         Task writeConfig = project.tasks.create(name: name, type: DefaultTask, dependsOn: setup)
         writeConfig.doFirst {

diff --git a/distribution/archives/integ-test-zip/build.gradle b/distribution/archives/integ-test-zip/build.gradle
@@ -1,2 +1,23 @@
-// This file is intentionally blank. All configuration of the
-// distribution is done in the parent project.
+/*
+ * 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.
+ */
+
+integTestRunner {
+  systemProperty 'tests.logfile',
+    "${ -> integTest.nodes[0].homeDir}/logs/${ -> integTest.nodes[0].clusterName }.log"
+}
diff --git a/...n/archives/integ-test-zip/src/test/java/org/elasticsearch/test/rest/NodeNameInLogsIT.java b/...n/archives/integ-test-zip/src/test/java/org/elasticsearch/test/rest/NodeNameInLogsIT.java
@@ -0,0 +1,43 @@
+/*
+ * 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.unconfigurednodename;
+
+import org.elasticsearch.common.logging.NodeNameInLogsIntegTestCase;
+
+import java.io.IOException;
+import java.io.BufferedReader;
+import java.nio.charset.StandardCharsets;
+import java.nio.file.Files;
+import java.nio.file.Path;
+import java.security.AccessController;
+import java.security.PrivilegedAction;
+
+public class NodeNameInLogsIT extends NodeNameInLogsIntegTestCase {
+    @Override
+    protected BufferedReader openReader(Path logFile) throws IOException {
+        return AccessController.doPrivileged((PrivilegedAction<BufferedReader>) () -> {
+            try {
+                return Files.newBufferedReader(logFile, StandardCharsets.UTF_8);
+            } catch (IOException e) {
+                throw new RuntimeException(e);
+            }
+        });
+    }
+}
diff --git a/distribution/archives/integ-test-zip/src/test/resources/plugin-security.policy b/distribution/archives/integ-test-zip/src/test/resources/plugin-security.policy
@@ -0,0 +1,4 @@
+grant {
+  // Needed to read the log file
+  permission java.io.FilePermission "${tests.logfile}", "read";
+};
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
@@ -357,7 +357,7 @@ public void testProperties() throws IOException, UserException {
         }
     }
 
-    public void testNoNodeNameWarning() throws IOException, UserException {
+    public void testNoNodeNameInPatternWarning() throws IOException, UserException {
         setupLogging("no_node_name");
 
         final String path =
@@ -368,7 +368,7 @@ public void testNoNodeNameWarning() throws IOException, UserException {
         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 "
+        assertLogLine(events.get(0), Level.WARN, location, "\\[unknown\\] 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:");

diff --git a/qa/evil-tests/src/test/java/org/elasticsearch/env/NodeEnvironmentEvilTests.java b/qa/evil-tests/src/test/java/org/elasticsearch/env/NodeEnvironmentEvilTests.java
@@ -52,7 +52,7 @@ public void testMissingWritePermission() throws IOException {
                     .put(Environment.PATH_HOME_SETTING.getKey(), createTempDir().toAbsolutePath().toString())
                     .putList(Environment.PATH_DATA_SETTING.getKey(), tempPaths).build();
             IOException ioException = expectThrows(IOException.class, () -> {
-                new NodeEnvironment(build, TestEnvironment.newEnvironment(build));
+                new NodeEnvironment(build, TestEnvironment.newEnvironment(build), nodeId -> {});
             });
             assertTrue(ioException.getMessage(), ioException.getMessage().startsWith(path.toString()));
         }
@@ -72,7 +72,7 @@ public void testMissingWritePermissionOnIndex() throws IOException {
                 .put(Environment.PATH_HOME_SETTING.getKey(), createTempDir().toAbsolutePath().toString())
                 .putList(Environment.PATH_DATA_SETTING.getKey(), tempPaths).build();
             IOException ioException = expectThrows(IOException.class, () -> {
-                new NodeEnvironment(build, TestEnvironment.newEnvironment(build));
+                new NodeEnvironment(build, TestEnvironment.newEnvironment(build), nodeId -> {});
             });
             assertTrue(ioException.getMessage(), ioException.getMessage().startsWith("failed to test writes in data directory"));
         }
@@ -97,7 +97,7 @@ public void testMissingWritePermissionOnShard() throws IOException {
                 .put(Environment.PATH_HOME_SETTING.getKey(), createTempDir().toAbsolutePath().toString())
                 .putList(Environment.PATH_DATA_SETTING.getKey(), tempPaths).build();
             IOException ioException = expectThrows(IOException.class, () -> {
-                new NodeEnvironment(build, TestEnvironment.newEnvironment(build));
+                new NodeEnvironment(build, TestEnvironment.newEnvironment(build), nodeId -> {});
             });
             assertTrue(ioException.getMessage(), ioException.getMessage().startsWith("failed to test writes in data directory"));
         }

diff --git a/qa/unconfigured-node-name/build.gradle b/qa/unconfigured-node-name/build.gradle
@@ -0,0 +1,30 @@
+/*
+ * 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.
+ */
+
+apply plugin: 'elasticsearch.standalone-rest-test'
+apply plugin: 'elasticsearch.rest-test'
+
+integTestCluster {
+  setting 'node.name', null
+}
+
+integTestRunner {
+  systemProperty 'tests.logfile',
+    "${ -> integTest.nodes[0].homeDir}/logs/${ -> integTest.nodes[0].clusterName }.log"
+}
diff --git a/...ed-node-name/src/test/java/org/elasticsearch/unconfigured_node_name/NodeNameInLogsIT.java b/...ed-node-name/src/test/java/org/elasticsearch/unconfigured_node_name/NodeNameInLogsIT.java
@@ -0,0 +1,43 @@
+/*
+ * 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.unconfigured_node_name;
+
+import org.elasticsearch.common.logging.NodeNameInLogsIntegTestCase;
+
+import java.io.IOException;
+import java.io.BufferedReader;
+import java.nio.charset.StandardCharsets;
+import java.nio.file.Files;
+import java.nio.file.Path;
+import java.security.AccessController;
+import java.security.PrivilegedAction;
+
+public class NodeNameInLogsIT extends NodeNameInLogsIntegTestCase {
+    @Override
+    protected BufferedReader openReader(Path logFile) throws IOException {
+        return AccessController.doPrivileged((PrivilegedAction<BufferedReader>) () -> {
+            try {
+                return Files.newBufferedReader(logFile, StandardCharsets.UTF_8);
+            } catch (IOException e) {
+                throw new RuntimeException(e);
+            }
+        });
+    }
+}
diff --git a/qa/unconfigured-node-name/src/test/resources/plugin-security.policy b/qa/unconfigured-node-name/src/test/resources/plugin-security.policy
@@ -0,0 +1,4 @@
+grant {
+  // Needed to read the log file
+  permission java.io.FilePermission "${tests.logfile}", "read";
+};
diff --git a/server/src/main/java/org/elasticsearch/bootstrap/Bootstrap.java b/server/src/main/java/org/elasticsearch/bootstrap/Bootstrap.java
@@ -37,7 +37,6 @@
 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;
@@ -217,6 +216,11 @@ protected void validateNodeBeforeAcceptingRequests(
                 final BoundTransportAddress boundTransportAddress, List<BootstrapCheck> checks) throws NodeValidationException {
                 BootstrapChecks.check(context, boundTransportAddress, checks);
             }
+
+            @Override
+            protected void registerDerivedNodeNameWithLogger(String nodeName) {
+                LogConfigurator.setNodeName(nodeName);
+            }
         };
     }
 
@@ -289,9 +293,9 @@ 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);
-
+        if (Node.NODE_NAME_SETTING.exists(environment.settings())) {
+            LogConfigurator.setNodeName(Node.NODE_NAME_SETTING.get(environment.settings()));
+        }
         try {
             LogConfigurator.configure(environment);
         } catch (IOException e) {

diff --git a/server/src/main/java/org/elasticsearch/common/logging/LogConfigurator.java b/server/src/main/java/org/elasticsearch/common/logging/LogConfigurator.java
@@ -134,6 +134,15 @@ public static void loadLog4jPlugins() {
         PluginManager.addPackage(LogConfigurator.class.getPackage().getName());
     }
 
+    /**
+     * Sets the node name. This is called before logging is configured if the
+     * node name is set in elasticsearch.yml. Otherwise it is called as soon
+     * as the node id is available.
+     */
+    public static void setNodeName(String nodeName) {
+        NodeNamePatternConverter.setNodeName(nodeName);
+    }
+
     private static void checkErrorListener() {
         assert errorListenerIsRegistered() : "expected error listener to be registered";
         if (error.get()) {
@@ -158,8 +167,8 @@ private static void configure(final Settings settings, final Path configsPath, f
 
         final LoggerContext context = (LoggerContext) LogManager.getContext(false);
 
+        final Set<String> locationsWithDeprecatedPatterns = Collections.synchronizedSet(new HashSet<>());
         final List<AbstractConfiguration> configurations = new ArrayList<>();
-
         /*
          * Subclass the properties configurator to hack the new pattern in
          * place so users don't have to change log4j2.properties in
@@ -170,7 +179,6 @@ 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<String> locationsWithDeprecatedPatterns = Collections.synchronizedSet(new HashSet<>());
         final PropertiesConfigurationFactory factory = new PropertiesConfigurationFactory() {
             @Override
             public PropertiesConfiguration getConfiguration(final LoggerContext loggerContext, final ConfigurationSource source) {

diff --git a/server/src/main/java/org/elasticsearch/common/logging/NodeNamePatternConverter.java b/server/src/main/java/org/elasticsearch/common/logging/NodeNamePatternConverter.java
@@ -30,20 +30,22 @@
 
 /**
  * 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.
+ * We can't use a system property for this because the node name system
+ * property is only set if the node name is explicitly defined in
+ * elasticsearch.yml.
  */
 @Plugin(category = PatternConverter.CATEGORY, name = "NodeNamePatternConverter")
 @ConverterKeys({"node_name"})
-public class NodeNamePatternConverter extends LogEventPatternConverter {
+public final class NodeNamePatternConverter extends LogEventPatternConverter {
+    /**
+     * The name of this node.
+     */
     private static final SetOnce<String> NODE_NAME = new SetOnce<>();
 
     /**
      * Set the name of this node.
      */
-    public static void setNodeName(String nodeName) {
+    static void setNodeName(String nodeName) {
         NODE_NAME.set(nodeName);
     }
 
@@ -55,18 +57,21 @@ public static NodeNamePatternConverter newInstance(final String[] options) {
             throw new IllegalArgumentException("no options supported but options provided: "
                     + Arrays.toString(options));
         }
-        return new NodeNamePatternConverter(NODE_NAME.get());
+        return new NodeNamePatternConverter();
     }
 
-    private final String nodeName;
-
-    private NodeNamePatternConverter(String nodeName) {
+    private NodeNamePatternConverter() {
         super("NodeName", "node_name");
-        this.nodeName = nodeName;
     }
 
     @Override
     public void format(LogEvent event, StringBuilder toAppendTo) {
-        toAppendTo.append(nodeName);
+        /*
+         * We're not thrilled about this volatile read on every line logged but
+         * the alternatives are slightly terrifying and/or don't work with the
+         * security manager.
+         */
+        String nodeName = NODE_NAME.get();
+        toAppendTo.append(nodeName == null ? "unknown" : nodeName);
     }
 }