Skip to content

Commit

Permalink
Isolate console appender startup logic (#86243)
Browse files Browse the repository at this point in the history 
When bootstrapping Elasticsearch, the console appender is automatically
added by our log4j config. However, there are some cases where we want
to remove that appender. First, if --quiet is passed, we do not want to
log anything to it. Second, if we are daemonizing, then we want to close
the streams, so we need to remove it if it exists. Third, when huge
guice/startup exceptions occur, we log these only to the ES log file, so
we need to remove the appender temporarily.

This commit moves the logic for mucking with the console appender into
LogConfigurator. In the future this can be better isolated within
logging, perhaps even avoiding creating the console appender to begin
with when using --quiet, but for now this at least gets some log specific
logic out of bootstrap.

relates #85758
  • Loading branch information
@rjernst
rjernst authored Apr 28, 2022
1 parent c082858 commit d742be8
Show file tree
Hide file tree
Showing 5 changed files with 74 additions and 54 deletions.
12 changes: 6 additions & 6 deletions ...il-tests/src/test/java/org/elasticsearch/common/logging/EvilLoggerConfigurationTests.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -52,7 +52,7 @@ public void testResolveMultipleConfigs() throws Exception {
final Path configDir = getDataPath("config");
final Settings settings = Settings.builder().put(Environment.PATH_HOME_SETTING.getKey(), createTempDir().toString()).build();
final Environment environment = new Environment(settings, configDir);
LogConfigurator.configure(environment);
LogConfigurator.configure(environment, true);

{
final LoggerContext ctx = (LoggerContext) LogManager.getContext(false);
Expand Down Expand Up @@ -90,7 +90,7 @@ public void testDefaults() throws IOException, UserException {
.put("logger.level", level)
.build();
final Environment environment = new Environment(settings, configDir);
LogConfigurator.configure(environment);
LogConfigurator.configure(environment, true);

final String loggerName = "test";
final Logger logger = LogManager.getLogger(loggerName);
Expand All @@ -105,7 +105,7 @@ public void testResolveOrder() throws Exception {
.put("logger.test_resolve_order", "TRACE")
.build();
final Environment environment = new Environment(settings, configDir);
LogConfigurator.configure(environment);
LogConfigurator.configure(environment, true);

// args should overwrite whatever is in the config
final String loggerName = "test_resolve_order";
Expand All @@ -117,7 +117,7 @@ public void testHierarchy() throws Exception {
final Path configDir = getDataPath("hierarchy");
final Settings settings = Settings.builder().put(Environment.PATH_HOME_SETTING.getKey(), createTempDir().toString()).build();
final Environment environment = new Environment(settings, configDir);
LogConfigurator.configure(environment);
LogConfigurator.configure(environment, true);

assertThat(LogManager.getLogger("x").getLevel(), equalTo(Level.TRACE));
assertThat(LogManager.getLogger("x.y").getLevel(), equalTo(Level.DEBUG));
Expand All @@ -133,7 +133,7 @@ public void testMissingConfigFile() {
final Path configDir = getDataPath("does_not_exist");
final Settings settings = Settings.builder().put(Environment.PATH_HOME_SETTING.getKey(), createTempDir().toString()).build();
final Environment environment = new Environment(settings, configDir);
UserException e = expectThrows(UserException.class, () -> LogConfigurator.configure(environment));
UserException e = expectThrows(UserException.class, () -> LogConfigurator.configure(environment, true));
assertThat(e, hasToString(containsString("no log4j2.properties found; tried")));
}

Expand All @@ -149,7 +149,7 @@ public void testLoggingLevelsFromSettings() throws IOException, UserException {
.put("logger.bar", barLevel.name())
.build();
final Environment environment = new Environment(settings, configDir);
LogConfigurator.configure(environment);
LogConfigurator.configure(environment, true);

final LoggerContext ctx = (LoggerContext) LogManager.getContext(false);
final Configuration config = ctx.getConfiguration();
Expand Down
2 changes: 1 addition & 1 deletion qa/evil-tests/src/test/java/org/elasticsearch/common/logging/EvilLoggerTests.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -322,7 +322,7 @@ private void setupLogging(final String config, final Settings settings) throws I
.build();
// need to use custom config path so we can use a custom log4j2.properties file for the test
final Environment environment = new Environment(mergedSettings, configDir);
LogConfigurator.configure(environment);
LogConfigurator.configure(environment, true);
}

private void assertLogLine(final String logLine, final Level level, final String location, final String message) {
Expand Down
2 changes: 1 addition & 1 deletion qa/logging-config/src/test/java/org/elasticsearch/common/logging/JsonLoggerTests.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -657,7 +657,7 @@ private void setupLogging(final String config, final Settings settings) throws I
.build();
// need to use custom config path so we can use a custom log4j2.properties file for the test
final Environment environment = new Environment(mergedSettings, configDir);
LogConfigurator.configure(environment);
LogConfigurator.configure(environment, true);
}

private Matcher<JsonLogLine> logLine(String type, Level level, String nodeName, String component, String message) {
Expand Down
62 changes: 19 additions & 43 deletions server/src/main/java/org/elasticsearch/bootstrap/Bootstrap.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -10,9 +10,7 @@

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.config.Configurator;
import org.apache.lucene.util.Constants;
import org.apache.lucene.util.StringHelper;
Expand All @@ -25,7 +23,6 @@
import org.elasticsearch.common.filesystem.FileSystemNatives;
import org.elasticsearch.common.inject.CreationException;
import org.elasticsearch.common.logging.LogConfigurator;
import org.elasticsearch.common.logging.Loggers;
import org.elasticsearch.common.network.IfConfig;
import org.elasticsearch.common.settings.SecureSettings;
import org.elasticsearch.common.settings.Settings;
Expand Down Expand Up @@ -310,7 +307,7 @@ static void init(final boolean foreground, final Path pidFile, final boolean qui

LogConfigurator.setNodeName(Node.NODE_NAME_SETTING.get(environment.settings()));
try {
LogConfigurator.configure(environment);
LogConfigurator.configure(environment, quiet == false);
} catch (IOException e) {
throw new BootstrapException(e);
}
Expand All @@ -323,16 +320,6 @@ static void init(final boolean foreground, final Path pidFile, final boolean qui
}

try {
final boolean closeStandardStreams = (foreground == false) || quiet;
if (closeStandardStreams) {
final Logger rootLogger = LogManager.getRootLogger();
final Appender maybeConsoleAppender = Loggers.findAppender(rootLogger, ConsoleAppender.class);
if (maybeConsoleAppender != null) {
Loggers.removeAppender(rootLogger, maybeConsoleAppender);
}
sysOutCloser.run();
}

// fail if somebody replaced the lucene jars
checkLucene();

Expand Down Expand Up @@ -366,41 +353,30 @@ static void init(final boolean foreground, final Path pidFile, final boolean qui

INSTANCE.start();

// We don't close stderr if `--quiet` is passed, because that
// hides fatal startup errors. For example, if Elasticsearch is
// running via systemd, the init script only specifies
// `--quiet`, not `-d`, so we want users to be able to see
// startup errors via journalctl.
if (foreground == false) {
LogConfigurator.removeConsoleAppender();
sysOutCloser.run();
sysErrorCloser.run();
}

} catch (NodeValidationException | RuntimeException e) {
// disable console logging, so user does not see the exception twice (jvm will show it already)
final Logger rootLogger = LogManager.getRootLogger();
final Appender maybeConsoleAppender = Loggers.findAppender(rootLogger, ConsoleAppender.class);
if (foreground && maybeConsoleAppender != null) {
Loggers.removeAppender(rootLogger, maybeConsoleAppender);
}
Logger logger = LogManager.getLogger(Bootstrap.class);
// HACK, it sucks to do this, but we will run users out of disk space otherwise
if (e instanceof CreationException) {
// guice: log the shortened exc to the log file
ByteArrayOutputStream os = new ByteArrayOutputStream();
PrintStream ps = new PrintStream(os, false, StandardCharsets.UTF_8);
new StartupException(e).printStackTrace(ps);
ps.flush();
logger.error("Guice Exception: {}", os.toString(StandardCharsets.UTF_8));
} else if (e instanceof NodeValidationException) {
logger.error("node validation exception\n{}", e.getMessage());
} else {
// full exception
logger.error("Exception", e);
}
// re-enable it if appropriate, so they can see any logging during the shutdown process
if (foreground && maybeConsoleAppender != null) {
Loggers.addAppender(rootLogger, maybeConsoleAppender);
}
LogConfigurator.logWithoutConsole(Bootstrap.class, logger -> {
// HACK, it sucks to do this, but we will run users out of disk space otherwise
if (e instanceof CreationException) {
// guice: log the shortened exc to the log file
ByteArrayOutputStream os = new ByteArrayOutputStream();
PrintStream ps = new PrintStream(os, false, StandardCharsets.UTF_8);
new StartupException(e).printStackTrace(ps);
ps.flush();
logger.error("Guice Exception: {}", os.toString(StandardCharsets.UTF_8));
} else if (e instanceof NodeValidationException) {
logger.error("node validation exception\n{}", e.getMessage());
} else {
// full exception
logger.error("Exception", e);
}
});

throw e;
}
Expand Down
50 changes: 47 additions & 3 deletions server/src/main/java/org/elasticsearch/common/logging/LogConfigurator.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -10,7 +10,10 @@

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.config.AbstractConfiguration;
import org.apache.logging.log4j.core.config.ConfigurationException;
import org.apache.logging.log4j.core.config.ConfigurationSource;
Expand Down Expand Up @@ -54,6 +57,7 @@
import java.util.Properties;
import java.util.Set;
import java.util.concurrent.atomic.AtomicBoolean;
import java.util.function.Consumer;
import java.util.stream.StreamSupport;

public class LogConfigurator {
Expand All @@ -74,6 +78,8 @@ public void log(StatusData data) {
}
};

private static Appender consoleAppender;

/**
* Registers a listener for status logger errors. This listener should be registered as early as possible to ensure that no errors are
* logged by the status logger before logging is configured.
Expand Down Expand Up @@ -102,11 +108,12 @@ public static void configureWithoutConfig(final Settings settings) {
* directory from the specified environment.
*
* @param environment the environment for reading configs and the logs path
* @param useConsole whether a console appender should exist
* @throws IOException if there is an issue readings any log4j2.properties in the config
* directory
* @throws UserException if there are no log4j2.properties in the specified configs path
*/
public static void configure(final Environment environment) throws IOException, UserException {
public static void configure(final Environment environment, boolean useConsole) throws IOException, UserException {
Objects.requireNonNull(environment);
try {
// we are about to configure logging, check that the status logger did not log any error-level messages
Expand All @@ -115,7 +122,7 @@ public static void configure(final Environment environment) throws IOException,
// whether or not the error listener check failed we can remove the listener now
StatusLogger.getLogger().removeListener(ERROR_LISTENER);
}
configure(environment.settings(), environment.configFile(), environment.logsFile());
configure(environment.settings(), environment.configFile(), environment.logsFile(), useConsole);
}

/**
Expand Down Expand Up @@ -145,7 +152,8 @@ private static boolean errorListenerIsRegistered() {
return StreamSupport.stream(StatusLogger.getLogger().getListeners().spliterator(), false).anyMatch(l -> l == ERROR_LISTENER);
}

private static void configure(final Settings settings, final Path configsPath, final Path logsPath) throws IOException, UserException {
private static void configure(final Settings settings, final Path configsPath, final Path logsPath, boolean useConsole)
throws IOException, UserException {
Objects.requireNonNull(settings);
Objects.requireNonNull(configsPath);
Objects.requireNonNull(logsPath);
Expand Down Expand Up @@ -240,6 +248,42 @@ public FileVisitResult visitFile(final Path file, final BasicFileAttributes attr
// grabbed a handle to the streams and intend to write to it, eg log4j for writing to the console
System.setOut(new PrintStream(new LoggingOutputStream(LogManager.getLogger("stdout"), Level.INFO), false, StandardCharsets.UTF_8));
System.setErr(new PrintStream(new LoggingOutputStream(LogManager.getLogger("stderr"), Level.WARN), false, StandardCharsets.UTF_8));

final Logger rootLogger = LogManager.getRootLogger();
Appender appender = Loggers.findAppender(rootLogger, ConsoleAppender.class);
if (appender != null) {
if (useConsole) {
consoleAppender = appender;
} else {
Loggers.removeAppender(rootLogger, appender);
}
}
}

/**
* Removes the appender for the console, if one exists.
*/
public static Appender removeConsoleAppender() {
Appender appender = consoleAppender;
if (appender != null) {
Loggers.removeAppender(LogManager.getRootLogger(), appender);
consoleAppender = null;
}
return appender;
}

/**
* Temporarily removes the appender for the console, so that log messages go only to the log file.
* @param clazz a class to get a logger for
* @param callback The code to log while the appender is removed
*/
public static void logWithoutConsole(Class<?> clazz, Consumer<Logger> callback) {
Appender appender = removeConsoleAppender();
Logger logger = LogManager.getLogger(clazz);
callback.accept(logger);
if (appender != null) {
Loggers.addAppender(LogManager.getRootLogger(), appender);
}
}

private static void configureStatusLogger() {
Expand Down

0 comments on commit d742be8

Please sign in to comment.