Do not prematurely shutdown Log4j

When a node closes, we shutdown logging as the last statement. This
statement must be last lest any subsequent attempts to log will blow up
by running into security permissions. Yet, in the case of a tribe node
this isn't enough. The first internal tribe node to close will shutdown
logging, and subsequent node closes will blow up with the aforementioned
problem. This commit migrate the Log4j shutdown to occur as part of the
shutdown hook that closes the node, after all nodes have
closed. Consequently, we can remove a hack in the test infrastructure to
prevent Log4j shutdowns when internal test nodes close and instead just
register a single shutdown hook that runs when the test JVM exits.

Relates #21519
This commit is contained in:
Jason Tedor 2016-11-13 17:27:30 -05:00 committed by GitHub
parent 2a328034ef
commit d273419d00
3 changed files with 15 additions and 34 deletions

View File

@ -19,9 +19,12 @@
package org.elasticsearch.bootstrap;
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.IOUtils;
import org.apache.lucene.util.StringHelper;
@ -167,6 +170,8 @@ final class Bootstrap {
public void run() {
try {
IOUtils.close(node);
LoggerContext context = (LoggerContext) LogManager.getContext(false);
Configurator.shutdown(context);
} catch (IOException ex) {
throw new ElasticsearchException("failed to stop node", ex);
}

View File

@ -19,10 +19,7 @@
package org.elasticsearch.node;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
import org.apache.logging.log4j.core.LoggerContext;
import org.apache.logging.log4j.core.config.Configurator;
import org.apache.lucene.util.Constants;
import org.apache.lucene.util.IOUtils;
import org.elasticsearch.Build;
@ -78,10 +75,8 @@ import org.elasticsearch.common.util.BigArrays;
import org.elasticsearch.discovery.Discovery;
import org.elasticsearch.discovery.DiscoveryModule;
import org.elasticsearch.discovery.DiscoverySettings;
import org.elasticsearch.discovery.NoneDiscovery;
import org.elasticsearch.discovery.zen.UnicastHostsProvider;
import org.elasticsearch.discovery.zen.UnicastZenPing;
import org.elasticsearch.discovery.zen.ZenDiscovery;
import org.elasticsearch.discovery.zen.ZenPing;
import org.elasticsearch.env.Environment;
import org.elasticsearch.env.NodeEnvironment;
@ -157,22 +152,16 @@ import java.util.ArrayList;
import java.util.Arrays;
import java.util.Collection;
import java.util.Collections;
import java.util.HashMap;
import java.util.List;
import java.util.Map;
import java.util.Objects;
import java.util.concurrent.CountDownLatch;
import java.util.concurrent.TimeUnit;
import java.util.function.Consumer;
import java.util.function.Function;
import java.util.function.Supplier;
import java.util.function.UnaryOperator;
import java.util.stream.Collectors;
import java.util.stream.Stream;
import static org.elasticsearch.discovery.DiscoveryModule.DISCOVERY_HOSTS_PROVIDER_SETTING;
import static org.elasticsearch.discovery.DiscoveryModule.DISCOVERY_TYPE_SETTING;
/**
* A node represent a node within a cluster (<tt>cluster.name</tt>). The {@link #client()} can be used
* in order to use a {@link Client} to perform actions/operations against the cluster.
@ -637,7 +626,6 @@ public class Node implements Closeable {
// start nodes now, after the http server, because it may take some time
tribeService.startNodes();
if (WRITE_PORTS_FIELD_SETTING.get(settings)) {
if (NetworkModule.HTTP_ENABLED.get(settings)) {
HttpServerTransport http = injector.getInstance(HttpServerTransport.class);
@ -778,24 +766,6 @@ public class Node implements Closeable {
}
IOUtils.close(toClose);
logger.info("closed");
final String log4jShutdownEnabled = System.getProperty("es.log4j.shutdownEnabled", "true");
final boolean shutdownEnabled;
switch (log4jShutdownEnabled) {
case "true":
shutdownEnabled = true;
break;
case "false":
shutdownEnabled = false;
break;
default:
throw new IllegalArgumentException(
"invalid value for [es.log4j.shutdownEnabled], was [" + log4jShutdownEnabled + "] but must be [true] or [false]");
}
if (shutdownEnabled) {
LoggerContext context = (LoggerContext) LogManager.getContext(false);
Configurator.shutdown(context);
}
}

View File

@ -30,7 +30,10 @@ import com.carrotsearch.randomizedtesting.generators.RandomPicks;
import com.carrotsearch.randomizedtesting.generators.RandomStrings;
import com.carrotsearch.randomizedtesting.rules.TestRuleAdapter;
import org.apache.logging.log4j.Level;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
import org.apache.logging.log4j.core.LoggerContext;
import org.apache.logging.log4j.core.config.Configurator;
import org.apache.logging.log4j.status.StatusConsoleListener;
import org.apache.logging.log4j.status.StatusData;
import org.apache.logging.log4j.status.StatusLogger;
@ -154,12 +157,15 @@ public abstract class ESTestCase extends LuceneTestCase {
static {
System.setProperty("log4j.shutdownHookEnabled", "false");
// we can not shutdown logging when tests are running or the next test that runs within the
// same JVM will try to initialize logging after a security manager has been installed and
// this will fail
System.setProperty("es.log4j.shutdownEnabled", "false");
System.setProperty("log4j2.disable.jmx", "true");
System.setProperty("log4j.skipJansi", "true"); // jython has this crazy shaded Jansi version that log4j2 tries to load
// shutdown hook so that when the test JVM exits, logging is shutdown too
Runtime.getRuntime().addShutdownHook(new Thread(() -> {
LoggerContext context = (LoggerContext) LogManager.getContext(false);
Configurator.shutdown(context);
}));
BootstrapForTesting.ensureInitialized();
}