From d8475488b8e15df8bce3c07dc6b7fe15d075b41a Mon Sep 17 00:00:00 2001 From: Jason Tedor Date: Fri, 9 Sep 2016 09:15:35 -0400 Subject: [PATCH] Disable console logging Previously we would disable console logging in certain circumstances (for example, if Elasticsearch is not in the foreground, or if Elasticsearch is in the foreground but an exception was thrown during bootstrap). This commit makes this handling work with Log4j 2. This will prevent users from seeing double bootstrap check failure messages. Relates #20387 --- .../elasticsearch/bootstrap/Bootstrap.java | 19 +++++-- .../elasticsearch/common/logging/Loggers.java | 40 +++++++++++++ .../bootstrap/MaxMapCountCheckTests.java | 10 ++-- .../cluster/service/ClusterServiceTests.java | 10 ++-- .../index/engine/InternalEngineTests.java | 9 ++- .../indices/settings/UpdateSettingsIT.java | 9 ++- .../common/logging/EvilLoggerTests.java | 14 +++++ .../common/logging/config/log4j2.properties | 10 ++-- .../common/logging/TestLoggers.java | 57 ------------------- 9 files changed, 92 insertions(+), 86 deletions(-) delete mode 100644 test/framework/src/main/java/org/elasticsearch/common/logging/TestLoggers.java diff --git a/core/src/main/java/org/elasticsearch/bootstrap/Bootstrap.java b/core/src/main/java/org/elasticsearch/bootstrap/Bootstrap.java index 3a3b765daca..d2e22c013b5 100644 --- a/core/src/main/java/org/elasticsearch/bootstrap/Bootstrap.java +++ b/core/src/main/java/org/elasticsearch/bootstrap/Bootstrap.java @@ -20,6 +20,8 @@ package org.elasticsearch.bootstrap; import org.apache.logging.log4j.Logger; +import org.apache.logging.log4j.core.Appender; +import org.apache.logging.log4j.core.appender.ConsoleAppender; import org.apache.lucene.util.Constants; import org.apache.lucene.util.IOUtils; import org.apache.lucene.util.StringHelper; @@ -29,6 +31,7 @@ import org.elasticsearch.cli.Terminal; import org.elasticsearch.common.PidFile; import org.elasticsearch.common.SuppressForbidden; import org.elasticsearch.common.inject.CreationException; +import org.elasticsearch.common.logging.ESLoggerFactory; import org.elasticsearch.common.logging.LogConfigurator; import org.elasticsearch.common.logging.Loggers; import org.elasticsearch.common.settings.Settings; @@ -258,7 +261,11 @@ final class Bootstrap { try { if (!foreground) { - Loggers.disableConsoleLogging(); + final Logger rootLogger = ESLoggerFactory.getRootLogger(); + final Appender maybeConsoleAppender = Loggers.findAppender(rootLogger, ConsoleAppender.class); + if (maybeConsoleAppender != null) { + Loggers.removeAppender(rootLogger, maybeConsoleAppender); + } closeSystOut(); } @@ -283,8 +290,10 @@ final class Bootstrap { } } catch (NodeValidationException | RuntimeException e) { // disable console logging, so user does not see the exception twice (jvm will show it already) - if (foreground) { - Loggers.disableConsoleLogging(); + final Logger rootLogger = ESLoggerFactory.getRootLogger(); + final Appender maybeConsoleAppender = Loggers.findAppender(rootLogger, ConsoleAppender.class); + if (foreground && maybeConsoleAppender != null) { + Loggers.removeAppender(rootLogger, maybeConsoleAppender); } Logger logger = Loggers.getLogger(Bootstrap.class); if (INSTANCE.node != null) { @@ -316,8 +325,8 @@ final class Bootstrap { logger.error("Exception", e); } // re-enable it if appropriate, so they can see any logging during the shutdown process - if (foreground) { - Loggers.enableConsoleLogging(); + if (foreground && maybeConsoleAppender != null) { + Loggers.addAppender(rootLogger, maybeConsoleAppender); } throw e; diff --git a/core/src/main/java/org/elasticsearch/common/logging/Loggers.java b/core/src/main/java/org/elasticsearch/common/logging/Loggers.java index 647ada099ba..31abfb2ec6e 100644 --- a/core/src/main/java/org/elasticsearch/common/logging/Loggers.java +++ b/core/src/main/java/org/elasticsearch/common/logging/Loggers.java @@ -20,7 +20,9 @@ package org.elasticsearch.common.logging; import org.apache.logging.log4j.Level; +import org.apache.logging.log4j.LogManager; import org.apache.logging.log4j.Logger; +import org.apache.logging.log4j.core.Appender; import org.apache.logging.log4j.core.LoggerContext; import org.apache.logging.log4j.core.config.Configuration; import org.apache.logging.log4j.core.config.Configurator; @@ -34,6 +36,7 @@ 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; @@ -171,4 +174,41 @@ public class Loggers { return commonPrefix + name; } + public static void addAppender(final Logger logger, final Appender appender) { + final LoggerContext ctx = (LoggerContext) LogManager.getContext(false); + final Configuration config = ctx.getConfiguration(); + config.addAppender(appender); + LoggerConfig loggerConfig = config.getLoggerConfig(logger.getName()); + if (!logger.getName().equals(loggerConfig.getName())) { + loggerConfig = new LoggerConfig(logger.getName(), logger.getLevel(), true); + config.addLogger(logger.getName(), loggerConfig); + } + loggerConfig.addAppender(appender, null, null); + ctx.updateLoggers(); + } + + public static void removeAppender(final Logger logger, final Appender appender) { + final LoggerContext ctx = (LoggerContext) LogManager.getContext(false); + final Configuration config = ctx.getConfiguration(); + LoggerConfig loggerConfig = config.getLoggerConfig(logger.getName()); + if (!logger.getName().equals(loggerConfig.getName())) { + loggerConfig = new LoggerConfig(logger.getName(), logger.getLevel(), true); + config.addLogger(logger.getName(), loggerConfig); + } + loggerConfig.removeAppender(appender.getName()); + ctx.updateLoggers(); + } + + public static Appender findAppender(final Logger logger, final Class clazz) { + final LoggerContext ctx = (LoggerContext) LogManager.getContext(false); + final Configuration config = ctx.getConfiguration(); + final LoggerConfig loggerConfig = config.getLoggerConfig(logger.getName()); + for (final Map.Entry entry : loggerConfig.getAppenders().entrySet()) { + if (entry.getValue().getClass().equals(clazz)) { + return entry.getValue(); + } + } + return null; + } + } diff --git a/core/src/test/java/org/elasticsearch/bootstrap/MaxMapCountCheckTests.java b/core/src/test/java/org/elasticsearch/bootstrap/MaxMapCountCheckTests.java index 5a2b8a5a143..b3862f5af16 100644 --- a/core/src/test/java/org/elasticsearch/bootstrap/MaxMapCountCheckTests.java +++ b/core/src/test/java/org/elasticsearch/bootstrap/MaxMapCountCheckTests.java @@ -26,7 +26,7 @@ import org.apache.logging.log4j.message.ParameterizedMessage; import org.apache.lucene.util.Constants; import org.elasticsearch.common.io.PathUtils; import org.elasticsearch.common.logging.ESLoggerFactory; -import org.elasticsearch.common.logging.TestLoggers; +import org.elasticsearch.common.logging.Loggers; import org.elasticsearch.test.ESTestCase; import org.elasticsearch.test.MockLogAppender; @@ -82,11 +82,11 @@ public class MaxMapCountCheckTests extends ESTestCase { "I/O exception while trying to read [{}]", new Object[] { procSysVmMaxMapCountPath }, e -> ioException == e)); - TestLoggers.addAppender(logger, appender); + Loggers.addAppender(logger, appender); assertThat(check.getMaxMapCount(logger), equalTo(-1L)); appender.assertAllExpectationsMatched(); verify(reader).close(); - TestLoggers.removeAppender(logger, appender); + Loggers.removeAppender(logger, appender); } { @@ -102,11 +102,11 @@ public class MaxMapCountCheckTests extends ESTestCase { "unable to parse vm.max_map_count [{}]", new Object[] { "eof" }, e -> e instanceof NumberFormatException && e.getMessage().equals("For input string: \"eof\""))); - TestLoggers.addAppender(logger, appender); + Loggers.addAppender(logger, appender); assertThat(check.getMaxMapCount(logger), equalTo(-1L)); appender.assertAllExpectationsMatched(); verify(reader).close(); - TestLoggers.removeAppender(logger, appender); + Loggers.removeAppender(logger, appender); } } diff --git a/core/src/test/java/org/elasticsearch/cluster/service/ClusterServiceTests.java b/core/src/test/java/org/elasticsearch/cluster/service/ClusterServiceTests.java index c4c09275e80..e21d38f6472 100644 --- a/core/src/test/java/org/elasticsearch/cluster/service/ClusterServiceTests.java +++ b/core/src/test/java/org/elasticsearch/cluster/service/ClusterServiceTests.java @@ -38,7 +38,7 @@ import org.elasticsearch.cluster.node.DiscoveryNodes; import org.elasticsearch.common.Priority; import org.elasticsearch.common.collect.Tuple; import org.elasticsearch.common.lease.Releasable; -import org.elasticsearch.common.logging.TestLoggers; +import org.elasticsearch.common.logging.Loggers; import org.elasticsearch.common.settings.ClusterSettings; import org.elasticsearch.common.settings.Settings; import org.elasticsearch.common.transport.LocalTransportAddress; @@ -688,7 +688,7 @@ public class ClusterServiceTests extends ESTestCase { "*processing [test3]: took [3s] done applying updated cluster_state (version: *, uuid: *)")); Logger rootLogger = LogManager.getRootLogger(); - TestLoggers.addAppender(rootLogger, mockAppender); + Loggers.addAppender(rootLogger, mockAppender); try { final CountDownLatch latch = new CountDownLatch(4); clusterService.currentTimeOverride = System.nanoTime(); @@ -763,7 +763,7 @@ public class ClusterServiceTests extends ESTestCase { }); latch.await(); } finally { - TestLoggers.removeAppender(rootLogger, mockAppender); + Loggers.removeAppender(rootLogger, mockAppender); } mockAppender.assertAllExpectationsMatched(); } @@ -781,7 +781,7 @@ public class ClusterServiceTests extends ESTestCase { "*cluster state update task [test4] took [34s] above the warn threshold of *")); Logger rootLogger = LogManager.getRootLogger(); - TestLoggers.addAppender(rootLogger, mockAppender); + Loggers.addAppender(rootLogger, mockAppender); try { final CountDownLatch latch = new CountDownLatch(5); final CountDownLatch processedFirstTask = new CountDownLatch(1); @@ -877,7 +877,7 @@ public class ClusterServiceTests extends ESTestCase { }); latch.await(); } finally { - TestLoggers.removeAppender(rootLogger, mockAppender); + Loggers.removeAppender(rootLogger, mockAppender); } mockAppender.assertAllExpectationsMatched(); } diff --git a/core/src/test/java/org/elasticsearch/index/engine/InternalEngineTests.java b/core/src/test/java/org/elasticsearch/index/engine/InternalEngineTests.java index 7b62966515d..1c35ea1f281 100644 --- a/core/src/test/java/org/elasticsearch/index/engine/InternalEngineTests.java +++ b/core/src/test/java/org/elasticsearch/index/engine/InternalEngineTests.java @@ -62,7 +62,6 @@ import org.elasticsearch.common.bytes.BytesReference; import org.elasticsearch.common.io.FileSystemUtils; import org.elasticsearch.common.logging.Loggers; import org.elasticsearch.common.logging.PrefixMessageFactory; -import org.elasticsearch.common.logging.TestLoggers; import org.elasticsearch.common.lucene.Lucene; import org.elasticsearch.common.lucene.uid.Versions; import org.elasticsearch.common.settings.Settings; @@ -1538,7 +1537,7 @@ public class InternalEngineTests extends ESTestCase { Logger rootLogger = LogManager.getRootLogger(); Level savedLevel = rootLogger.getLevel(); - TestLoggers.addAppender(rootLogger, mockAppender); + Loggers.addAppender(rootLogger, mockAppender); Loggers.setLevel(rootLogger, Level.DEBUG); rootLogger = LogManager.getRootLogger(); @@ -1556,7 +1555,7 @@ public class InternalEngineTests extends ESTestCase { assertTrue(mockAppender.sawIndexWriterMessage); } finally { - TestLoggers.removeAppender(rootLogger, mockAppender); + Loggers.removeAppender(rootLogger, mockAppender); Loggers.setLevel(rootLogger, savedLevel.toString()); } } @@ -1577,7 +1576,7 @@ public class InternalEngineTests extends ESTestCase { iwIFDLogger = LogManager.getLogger("index.engine.lucene.iw.ifd"); } - TestLoggers.addAppender(iwIFDLogger, mockAppender); + Loggers.addAppender(iwIFDLogger, mockAppender); Loggers.setLevel(iwIFDLogger, Level.DEBUG); try { @@ -1596,7 +1595,7 @@ public class InternalEngineTests extends ESTestCase { assertTrue(mockAppender.sawIndexWriterIFDMessage); } finally { - TestLoggers.removeAppender(iwIFDLogger, mockAppender); + Loggers.removeAppender(iwIFDLogger, mockAppender); Loggers.setLevel(iwIFDLogger, (Level) null); } } diff --git a/core/src/test/java/org/elasticsearch/indices/settings/UpdateSettingsIT.java b/core/src/test/java/org/elasticsearch/indices/settings/UpdateSettingsIT.java index 4403b6dc9ce..3c60c209712 100644 --- a/core/src/test/java/org/elasticsearch/indices/settings/UpdateSettingsIT.java +++ b/core/src/test/java/org/elasticsearch/indices/settings/UpdateSettingsIT.java @@ -34,7 +34,6 @@ import org.elasticsearch.action.admin.indices.settings.put.UpdateSettingsRequest import org.elasticsearch.cluster.metadata.IndexMetaData; import org.elasticsearch.common.Priority; import org.elasticsearch.common.logging.Loggers; -import org.elasticsearch.common.logging.TestLoggers; import org.elasticsearch.common.settings.Setting; import org.elasticsearch.common.settings.Settings; import org.elasticsearch.index.IndexModule; @@ -382,7 +381,7 @@ public class UpdateSettingsIT extends ESIntegTestCase { MockAppender mockAppender = new MockAppender("testUpdateAutoThrottleSettings"); Logger rootLogger = LogManager.getRootLogger(); Level savedLevel = rootLogger.getLevel(); - TestLoggers.addAppender(rootLogger, mockAppender); + Loggers.addAppender(rootLogger, mockAppender); Loggers.setLevel(rootLogger, Level.TRACE); try { @@ -414,7 +413,7 @@ public class UpdateSettingsIT extends ESIntegTestCase { GetSettingsResponse getSettingsResponse = client().admin().indices().prepareGetSettings("test").get(); assertThat(getSettingsResponse.getSetting("test", MergeSchedulerConfig.AUTO_THROTTLE_SETTING.getKey()), equalTo("false")); } finally { - TestLoggers.removeAppender(rootLogger, mockAppender); + Loggers.removeAppender(rootLogger, mockAppender); Loggers.setLevel(rootLogger, savedLevel); } } @@ -471,7 +470,7 @@ public class UpdateSettingsIT extends ESIntegTestCase { MockAppender mockAppender = new MockAppender("testUpdateMergeMaxThreadCount"); Logger rootLogger = LogManager.getRootLogger(); Level savedLevel = rootLogger.getLevel(); - TestLoggers.addAppender(rootLogger, mockAppender); + Loggers.addAppender(rootLogger, mockAppender); Loggers.setLevel(rootLogger, Level.TRACE); try { @@ -505,7 +504,7 @@ public class UpdateSettingsIT extends ESIntegTestCase { assertThat(getSettingsResponse.getSetting("test", MergeSchedulerConfig.MAX_THREAD_COUNT_SETTING.getKey()), equalTo("1")); } finally { - TestLoggers.removeAppender(rootLogger, mockAppender); + Loggers.removeAppender(rootLogger, mockAppender); Loggers.setLevel(rootLogger, savedLevel); } } 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 6c7f97feb13..6ceacea2d7f 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 @@ -22,7 +22,10 @@ package org.elasticsearch.common.logging; import org.apache.logging.log4j.Level; import org.apache.logging.log4j.LogManager; import org.apache.logging.log4j.Logger; +import org.apache.logging.log4j.core.Appender; import org.apache.logging.log4j.core.LoggerContext; +import org.apache.logging.log4j.core.appender.ConsoleAppender; +import org.apache.logging.log4j.core.appender.CountingNoOpAppender; import org.apache.logging.log4j.core.config.Configurator; import org.elasticsearch.Version; import org.elasticsearch.common.io.PathUtils; @@ -38,6 +41,7 @@ import java.util.List; import java.util.regex.Matcher; import java.util.regex.Pattern; +import static com.vividsolutions.jts.geom.Dimension.L; import static org.hamcrest.Matchers.equalTo; public class EvilLoggerTests extends ESTestCase { @@ -107,4 +111,14 @@ public class EvilLoggerTests extends ESTestCase { "This is a deprecation message"); } + public void testFindAppender() { + final Appender testLoggerConsoleAppender = Loggers.findAppender(testLogger, ConsoleAppender.class); + assertNotNull(testLoggerConsoleAppender); + assertThat(testLoggerConsoleAppender.getName(), equalTo("console")); + final Logger countingNoOpLogger = ESLoggerFactory.getLogger("counting_no_op"); + assertNull(Loggers.findAppender(countingNoOpLogger, ConsoleAppender.class)); + final Appender countingNoOpAppender = Loggers.findAppender(countingNoOpLogger, CountingNoOpAppender.class); + assertThat(countingNoOpAppender.getName(), equalTo("counting_no_op")); + } + } 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 42fd3f35359..f775453ad03 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 @@ -11,10 +11,6 @@ appender.file.fileName = ${sys:es.logs}.log appender.file.layout.type = PatternLayout appender.file.layout.pattern = [%p][%l] %m%n -rootLogger.level = info -rootLogger.appenderRef.console.ref = console -rootLogger.appenderRef.file.ref = file - logger.test.name = test logger.test.level = trace logger.test.appenderRef.console.ref = console @@ -31,3 +27,9 @@ logger.deprecation.name = deprecation logger.deprecation.level = warn logger.deprecation.appenderRef.deprecation_file.ref = deprecation_file logger.deprecation.additivity = false + +appender.counting_no_op.type = CountingNoOp +appender.counting_no_op.name = counting_no_op + +logger.counting_no_op.name = counting_no_op +logger.counting_no_op.appenderRef.counting_no_op.ref = counting_no_op diff --git a/test/framework/src/main/java/org/elasticsearch/common/logging/TestLoggers.java b/test/framework/src/main/java/org/elasticsearch/common/logging/TestLoggers.java deleted file mode 100644 index 3b6cf7e2c94..00000000000 --- a/test/framework/src/main/java/org/elasticsearch/common/logging/TestLoggers.java +++ /dev/null @@ -1,57 +0,0 @@ -/* - * 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.apache.logging.log4j.LogManager; -import org.apache.logging.log4j.Logger; -import org.apache.logging.log4j.core.Appender; -import org.apache.logging.log4j.core.LoggerContext; -import org.apache.logging.log4j.core.config.AppenderRef; -import org.apache.logging.log4j.core.config.Configuration; -import org.apache.logging.log4j.core.config.LoggerConfig; - -public class TestLoggers { - - public static void addAppender(final Logger logger, final Appender appender) { - final LoggerContext ctx = (LoggerContext) LogManager.getContext(false); - final Configuration config = ctx.getConfiguration(); - config.addAppender(appender); - LoggerConfig loggerConfig = config.getLoggerConfig(logger.getName()); - if (!logger.getName().equals(loggerConfig.getName())) { - loggerConfig = new LoggerConfig(logger.getName(), logger.getLevel(), true); - config.addLogger(logger.getName(), loggerConfig); - } - loggerConfig.addAppender(appender, null, null); - ctx.updateLoggers(); - } - - public static void removeAppender(final Logger logger, final Appender appender) { - final LoggerContext ctx = (LoggerContext) LogManager.getContext(false); - final Configuration config = ctx.getConfiguration(); - LoggerConfig loggerConfig = config.getLoggerConfig(logger.getName()); - if (!logger.getName().equals(loggerConfig.getName())) { - loggerConfig = new LoggerConfig(logger.getName(), logger.getLevel(), true); - config.addLogger(logger.getName(), loggerConfig); - } - loggerConfig.removeAppender(appender.getName()); - ctx.updateLoggers(); - } - -}