Don't close stderr under `--quiet` (#49431)

Backport of #47208.

Closes #46900. When running ES with `--quiet`, if ES then exits abnormally, a
user has to go hunting in the logs for the error. Instead, never close
System.err, and print more information to it if ES encounters a fatal error
e.g. config validation, or some fatal runtime exception. This is useful when
running under e.g. systemd, since the error will go into the journal.

Note that stderr is still closed in daemon (`-d`) mode.
This commit is contained in:
Rory Hunter 2019-11-22 14:58:17 +00:00 committed by GitHub
parent ed787d06e8
commit 4fae2bb3b1
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
8 changed files with 156 additions and 68 deletions

View File

@ -151,6 +151,11 @@ public abstract class Terminal {
}
}
public void flush() {
this.getWriter().flush();
this.getErrorWriter().flush();
}
private static class ConsoleTerminal extends Terminal {
private static final Console CONSOLE = System.console();

View File

@ -23,7 +23,6 @@ import com.carrotsearch.randomizedtesting.generators.RandomStrings;
import org.apache.http.client.fluent.Request;
import org.elasticsearch.packaging.util.FileUtils;
import org.elasticsearch.packaging.util.Shell.Result;
import org.hamcrest.CoreMatchers;
import org.junit.BeforeClass;
import java.nio.charset.StandardCharsets;
@ -47,10 +46,12 @@ import static org.elasticsearch.packaging.util.FileUtils.slurp;
import static org.elasticsearch.packaging.util.Packages.SYSTEMD_SERVICE;
import static org.elasticsearch.packaging.util.Packages.assertInstalled;
import static org.elasticsearch.packaging.util.Packages.assertRemoved;
import static org.elasticsearch.packaging.util.Packages.clearJournal;
import static org.elasticsearch.packaging.util.Packages.installPackage;
import static org.elasticsearch.packaging.util.Packages.remove;
import static org.elasticsearch.packaging.util.Packages.restartElasticsearch;
import static org.elasticsearch.packaging.util.Packages.startElasticsearch;
import static org.elasticsearch.packaging.util.Packages.startElasticsearchIgnoringFailure;
import static org.elasticsearch.packaging.util.Packages.stopElasticsearch;
import static org.elasticsearch.packaging.util.Packages.verifyPackageInstallation;
import static org.elasticsearch.packaging.util.Platforms.getOsRelease;
@ -60,7 +61,7 @@ import static org.elasticsearch.packaging.util.ServerUtils.runElasticsearchTests
import static org.hamcrest.CoreMatchers.equalTo;
import static org.hamcrest.CoreMatchers.not;
import static org.hamcrest.Matchers.containsString;
import static org.hamcrest.Matchers.isEmptyString;
import static org.hamcrest.Matchers.emptyString;
import static org.hamcrest.core.Is.is;
import static org.junit.Assume.assumeThat;
import static org.junit.Assume.assumeTrue;
@ -79,8 +80,8 @@ public class PackageTests extends PackagingTestCase {
verifyPackageInstallation(installation, distribution(), sh);
}
public void test20PluginsCommandWhenNoPlugins() throws Exception {
assertThat(sh.run(installation.bin("elasticsearch-plugin") + " list").stdout, isEmptyString());
public void test20PluginsCommandWhenNoPlugins() {
assertThat(sh.run(installation.bin("elasticsearch-plugin") + " list").stdout, is(emptyString()));
}
public void test30DaemonIsNotEnabledOnRestart() {
@ -95,7 +96,7 @@ public class PackageTests extends PackagingTestCase {
assertThat(sh.run("ps aux").stdout, not(containsString("org.elasticsearch.bootstrap.Elasticsearch")));
}
public void assertRunsWithJavaHome() throws Exception {
private void assertRunsWithJavaHome() throws Exception {
byte[] originalEnvFile = Files.readAllBytes(installation.envFile);
try {
Files.write(installation.envFile, ("JAVA_HOME=" + systemJavaHome + "\n").getBytes(StandardCharsets.UTF_8),
@ -287,53 +288,17 @@ public class PackageTests extends PackagingTestCase {
}
public void test81CustomPathConfAndJvmOptions() throws Exception {
assumeTrue(isSystemd());
assertPathsExist(installation.envFile);
stopElasticsearch(sh);
// The custom config directory is not under /tmp or /var/tmp because
// systemd's private temp directory functionally means different
// processes can have different views of what's in these directories
String randomName = RandomStrings.randomAsciiAlphanumOfLength(getRandom(), 10);
sh.run("mkdir /etc/"+randomName);
final Path tempConf = Paths.get("/etc/"+randomName);
try {
mkdir(tempConf);
cp(installation.config("elasticsearch.yml"), tempConf.resolve("elasticsearch.yml"));
cp(installation.config("log4j2.properties"), tempConf.resolve("log4j2.properties"));
// we have to disable Log4j from using JMX lest it will hit a security
// manager exception before we have configured logging; this will fail
// startup since we detect usages of logging before it is configured
final String jvmOptions =
"-Xms512m\n" +
"-Xmx512m\n" +
"-Dlog4j2.disable.jmx=true\n";
append(tempConf.resolve("jvm.options"), jvmOptions);
sh.runIgnoreExitCode("chown -R elasticsearch:elasticsearch " + tempConf);
cp(installation.envFile, tempConf.resolve("elasticsearch.bk"));//backup
append(installation.envFile, "ES_PATH_CONF=" + tempConf + "\n");
withCustomConfig(tempConf -> {
append(installation.envFile, "ES_JAVA_OPTS=-XX:-UseCompressedOops");
startElasticsearch(sh, installation);
final String nodesResponse = makeRequest(Request.Get("http://localhost:9200/_nodes"));
assertThat(nodesResponse, CoreMatchers.containsString("\"heap_init_in_bytes\":536870912"));
assertThat(nodesResponse, CoreMatchers.containsString("\"using_compressed_ordinary_object_pointers\":\"false\""));
assertThat(nodesResponse, containsString("\"heap_init_in_bytes\":536870912"));
assertThat(nodesResponse, containsString("\"using_compressed_ordinary_object_pointers\":\"false\""));
stopElasticsearch(sh);
} finally {
rm(installation.envFile);
cp(tempConf.resolve("elasticsearch.bk"), installation.envFile);
rm(tempConf);
cleanup();
}
});
}
public void test82SystemdMask() throws Exception {
@ -375,4 +340,63 @@ public class PackageTests extends PackagingTestCase {
stopElasticsearch(sh);
}
public void test90DoNotCloseStderrWhenQuiet() throws Exception {
withCustomConfig(tempConf -> {
// Create a startup problem by adding an invalid YAML line to the config
append(tempConf.resolve("elasticsearch.yml"), "discovery.zen.ping.unicast.hosts:15172.30.5.3416172.30.5.35, 172.30.5.17]\n");
// Make sure we don't pick up the journal entries for previous ES instances.
clearJournal(sh);
startElasticsearchIgnoringFailure(sh);
final Result logs = sh.run("journalctl -u elasticsearch.service");
assertThat(logs.stdout, containsString("Failed to load settings from [elasticsearch.yml]"));
});
}
@FunctionalInterface
private interface CustomConfigConsumer {
void accept(Path path) throws Exception;
}
private void withCustomConfig(CustomConfigConsumer pathConsumer) throws Exception {
assumeTrue(isSystemd());
assertPathsExist(installation.envFile);
stopElasticsearch(sh);
// The custom config directory is not under /tmp or /var/tmp because
// systemd's private temp directory functionally means different
// processes can have different views of what's in these directories
String randomName = RandomStrings.randomAsciiAlphanumOfLength(getRandom(), 10);
sh.run("mkdir /etc/" + randomName);
final Path tempConf = Paths.get("/etc/" + randomName);
try {
mkdir(tempConf);
cp(installation.config("elasticsearch.yml"), tempConf.resolve("elasticsearch.yml"));
cp(installation.config("log4j2.properties"), tempConf.resolve("log4j2.properties"));
// we have to disable Log4j from using JMX lest it will hit a security
// manager exception before we have configured logging; this will fail
// startup since we detect usages of logging before it is configured
final String jvmOptions = "-Xms512m\n-Xmx512m\n-Dlog4j2.disable.jmx=true\n";
append(tempConf.resolve("jvm.options"), jvmOptions);
sh.runIgnoreExitCode("chown -R elasticsearch:elasticsearch " + tempConf);
cp(installation.envFile, tempConf.resolve("elasticsearch.bk"));// backup
append(installation.envFile, "ES_PATH_CONF=" + tempConf + "\n");
pathConsumer.accept(tempConf);
} finally {
rm(installation.envFile);
cp(tempConf.resolve("elasticsearch.bk"), installation.envFile);
rm(tempConf);
cleanup();
}
}
}

View File

@ -21,6 +21,7 @@ package org.elasticsearch.packaging.util;
import org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;
import org.elasticsearch.common.CheckedRunnable;
import java.nio.file.Path;
import java.nio.file.attribute.PosixFilePermission;
@ -409,7 +410,7 @@ public class Docker {
withLogging(() -> ServerUtils.waitForElasticsearch(status, index, installation, username, password));
}
private static void withLogging(ThrowingRunnable r) throws Exception {
private static <E extends Exception> void withLogging(CheckedRunnable<E> r) throws Exception {
try {
r.run();
} catch (Exception e) {
@ -418,8 +419,4 @@ public class Docker {
throw e;
}
}
private interface ThrowingRunnable {
void run() throws Exception;
}
}

View File

@ -52,7 +52,7 @@ import static org.junit.Assert.assertTrue;
public class Packages {
protected static final Logger logger = LogManager.getLogger(Packages.class);
private static final Logger logger = LogManager.getLogger(Packages.class);
public static final Path SYSVINIT_SCRIPT = Paths.get("/etc/init.d/elasticsearch");
public static final Path SYSTEMD_SERVICE = Paths.get("/usr/lib/systemd/system/elasticsearch.service");
@ -114,7 +114,7 @@ public class Packages {
return installation;
}
public static Result runInstallCommand(Distribution distribution, Shell sh) {
private static Result runInstallCommand(Distribution distribution, Shell sh) {
final Path distributionFile = distribution.path;
if (Platforms.isRPM()) {
@ -281,7 +281,33 @@ public class Packages {
assertElasticsearchStarted(sh, installation);
}
public static void assertElasticsearchStarted(Shell sh, Installation installation) throws IOException {
/**
* Starts Elasticsearch, without checking that startup is successful. To also check
* that Elasticsearch has started, call {@link #startElasticsearch(Shell, Installation)}.
*/
public static void startElasticsearchIgnoringFailure(Shell sh) {
if (isSystemd()) {
sh.runIgnoreExitCode("systemctl daemon-reload");
sh.runIgnoreExitCode("systemctl enable elasticsearch.service");
sh.runIgnoreExitCode("systemctl is-enabled elasticsearch.service");
sh.runIgnoreExitCode("systemctl start elasticsearch.service");
} else {
sh.runIgnoreExitCode("service elasticsearch start");
}
}
/**
* Clears the systemd journal. This is intended to clear the <code>journalctl</code> output
* before a test that checks the journal output.
*/
public static void clearJournal(Shell sh) {
if (isSystemd()) {
sh.run("rm -rf /run/log/journal/");
sh.run("systemctl restart systemd-journald");
}
}
private static void assertElasticsearchStarted(Shell sh, Installation installation) throws IOException {
waitForElasticsearch(installation);
if (isSystemd()) {
@ -292,7 +318,7 @@ public class Packages {
}
}
public static void stopElasticsearch(Shell sh) throws IOException {
public static void stopElasticsearch(Shell sh) {
if (isSystemd()) {
sh.run("systemctl stop elasticsearch.service");
} else {

View File

@ -357,7 +357,12 @@ final class Bootstrap {
INSTANCE.start();
if (closeStandardStreams) {
// 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) {
closeSysError();
}
} catch (NodeValidationException | RuntimeException e) {

View File

@ -91,6 +91,17 @@ class Elasticsearch extends EnvironmentAwareCommand {
final Elasticsearch elasticsearch = new Elasticsearch();
int status = main(args, elasticsearch, Terminal.DEFAULT);
if (status != ExitCodes.OK) {
final String basePath = System.getProperty("es.logs.base_path");
// It's possible to fail before logging has been configured, in which case there's no point
// suggesting that the user look in the log file.
if (basePath != null) {
Terminal.DEFAULT.errorPrintln(
"ERROR: Elasticsearch did not exit normally - check the logs at "
+ basePath
+ System.getProperty("file.separator")
+ System.getProperty("es.logs.cluster_name") + ".log"
);
}
exit(status);
}
}

View File

@ -21,7 +21,7 @@ package org.elasticsearch.bootstrap;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
import org.apache.logging.log4j.message.ParameterizedMessage;
import org.elasticsearch.cli.Terminal;
import org.elasticsearch.common.SuppressForbidden;
import java.io.IOError;
@ -32,29 +32,29 @@ class ElasticsearchUncaughtExceptionHandler implements Thread.UncaughtExceptionH
private static final Logger logger = LogManager.getLogger(ElasticsearchUncaughtExceptionHandler.class);
@Override
public void uncaughtException(Thread t, Throwable e) {
if (isFatalUncaught(e)) {
public void uncaughtException(Thread thread, Throwable t) {
if (isFatalUncaught(t)) {
try {
onFatalUncaught(t.getName(), e);
onFatalUncaught(thread.getName(), t);
} finally {
// we use specific error codes in case the above notification failed, at least we
// will have some indication of the error bringing us down
if (e instanceof InternalError) {
if (t instanceof InternalError) {
halt(128);
} else if (e instanceof OutOfMemoryError) {
} else if (t instanceof OutOfMemoryError) {
halt(127);
} else if (e instanceof StackOverflowError) {
} else if (t instanceof StackOverflowError) {
halt(126);
} else if (e instanceof UnknownError) {
} else if (t instanceof UnknownError) {
halt(125);
} else if (e instanceof IOError) {
} else if (t instanceof IOError) {
halt(124);
} else {
halt(1);
}
}
} else {
onNonFatalUncaught(t.getName(), e);
onNonFatalUncaught(thread.getName(), t);
}
}
@ -63,11 +63,21 @@ class ElasticsearchUncaughtExceptionHandler implements Thread.UncaughtExceptionH
}
void onFatalUncaught(final String threadName, final Throwable t) {
logger.error(() -> new ParameterizedMessage("fatal error in thread [{}], exiting", threadName), t);
final String message = "fatal error in thread [" + threadName + "], exiting";
logger.error(message, t);
Terminal.DEFAULT.errorPrintln(message);
t.printStackTrace(Terminal.DEFAULT.getErrorWriter());
// Without a final flush, the stacktrace may not be shown before ES exits
Terminal.DEFAULT.flush();
}
void onNonFatalUncaught(final String threadName, final Throwable t) {
logger.warn(() -> new ParameterizedMessage("uncaught exception in thread [{}]", threadName), t);
final String message = "uncaught exception in thread [" + threadName + "]";
logger.error(message, t);
Terminal.DEFAULT.errorPrintln(message);
t.printStackTrace(Terminal.DEFAULT.getErrorWriter());
// Without a final flush, the stacktrace may not be shown if ES goes on to exit
Terminal.DEFAULT.flush();
}
void halt(int status) {

View File

@ -111,7 +111,17 @@ final class StartupException extends RuntimeException {
// if its a guice exception, the whole thing really will not be in the log, its megabytes.
// refer to the hack in bootstrap, where we don't log it
if (originalCause instanceof CreationException == false) {
consumer.accept("Refer to the log for complete error details.");
final String basePath = System.getProperty("es.logs.base_path");
// It's possible to fail before logging has been configured, in which case there's no point
// suggested that the user look in the log file.
if (basePath != null) {
final String logPath = System.getProperty("es.logs.base_path")
+ System.getProperty("file.separator")
+ System.getProperty("es.logs.cluster_name")
+ ".log";
consumer.accept("For complete error details, refer to the log at " + logPath);
}
}
}