Don't close stderr under `--quiet` #47208

pugnascotia · 2019-09-27T11:15:47Z

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.

Closes elastic#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.

elasticmachine · 2019-09-27T11:15:49Z

Pinging @elastic/es-core-infra

pugnascotia · 2019-09-29T11:26:46Z

@elasticmachine run elasticsearch-ci/packaging-sample as it appears to have timed out.

jasontedor

I left an observation that I think requires following up on.

jasontedor · 2019-09-29T21:47:44Z

server/src/main/java/org/elasticsearch/bootstrap/Elasticsearch.java

@@ -91,6 +91,12 @@ public void checkPermission(Permission perm) {
        final Elasticsearch elasticsearch = new Elasticsearch();
        int status = main(args, elasticsearch, Terminal.DEFAULT);
        if (status != ExitCodes.OK) {
+            Terminal.DEFAULT.errorPrintln("ERROR: Elasticsearch did not exit normally - check the logs at " +


I think it's possible that we can fail before these system properties have been set.

The problem here is that we can fail before we’ve configured logging, and so those system properties would not be set giving an empty error message to the user. The guarantee that we have here though is that if logging is not yet been configured, then no log messages will have been written (we have a check that ensures we don't touch logging before it's configured, and we fail startup if it is). That means that we should skip these message if the logging properties are not set, because we know from our guarantees that there won't be anything in the logs to look at.

@jasontedor I've added guards around both places where I'm printing the log file location.

alpar-t · 2019-09-30T10:29:14Z

Packaging tests will block reading from streams until they close when starting ES.
The changes in #46924 will help with this, switching to redirect outputs to files instead and implementing process based timeouts so it's easier to see if something hangs.
Not sure if it's something similar with the bats tests failing here

pugnascotia · 2019-10-04T08:16:50Z

@elasticmachine update branch

pugnascotia · 2019-10-08T11:17:55Z

@elasticmachine update branch

pugnascotia · 2019-10-09T15:33:56Z

BATS tests are still hanging. I'll need to dig into what's going on here.

pugnascotia · 2019-10-10T11:05:07Z

I ssh'd into a VM while the BATS tests were running, and only some of them are hanging. By 'sudo kill'ing the rogue ones, the test run was able to proceed (though failed overall, naturally). I'll see what I can find out.

pugnascotia · 2019-10-10T11:58:31Z

I think I know what's going on. BATS has a run() helper, which executes a command like so:

output="$("$@" 2>&1)"

So while a process' stdout or stderr is open, bash will be stuck waiting. Since stderr isn't closed with -d in this PR...that's a problem.

…-print-logs-location

The previous change never closed stderr, either when `--quiet` or when `-d` is passed. However, this broken the BATS tests, which expected to be able to quickly consume all output when passing `-d`. Thinking about it some more, it's reasonable (if perhaps still debatable) to leave stderr open under `--quiet`, which fixes the systemd case, but close stderr under `-d`.

pugnascotia · 2019-10-11T14:41:54Z

@elasticmachine run elasticsearch-ci/packaging-sample-matrix as it was killed by some mysterious outside force.

…-print-logs-location

There's no point telling the user to go and check the logs if we haven't configured logging yet.

jasontedor

I left a question, a nit. I also wonder if we can add a packaging test here, to ensure that future behavior maintains this? It would look something like forcing Elasticsearch to die at startup, and then checking standard error for the expected output (which might have been redirected to the journal, for example).

jasontedor · 2019-10-31T12:13:43Z

libs/cli/src/main/java/org/elasticsearch/cli/Terminal.java

@@ -151,6 +151,10 @@ public final boolean promptYesNo(String prompt, boolean defaultYes) {
        }
    }

+    public void flush() {
+        this.getErrorWriter().flush();


It's puzzling to me that flush only flushes the error stream but not the output stream?

jasontedor · 2019-10-31T12:14:12Z

server/src/main/java/org/elasticsearch/bootstrap/Elasticsearch.java

@@ -91,6 +91,17 @@ public void checkPermission(Permission perm) {
        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
+            // suggested that the user look in the log file.


suggested -> suggesting

…-print-logs-location

pugnascotia · 2019-11-05T11:01:38Z

@jasontedor I addressed your feedback in 4091c55.

pugnascotia · 2019-11-11T13:24:47Z

@jasontedor is this PR good for an approval now?

jasontedor · 2019-11-11T15:06:08Z

@pugnascotia Did you see my previous comment about testing?

I also wonder if we can add a packaging test here, to ensure that future behavior maintains this? It would look something like forcing Elasticsearch to die at startup, and then checking standard error for the expected output (which might have been redirected to the journal, for example).

pugnascotia · 2019-11-11T15:50:14Z

Gyah, I did...and didn’t do it. Sorry, I’ll get that sorted out before I ping you again

Refactor PackageTests so that the logic for preparing a custom config is extracted to a helper method that takes a closure. Add a test that configures two GC types, and check that the bootstrap checks fail. Also some other misc cleanups.

…-print-logs-location

pugnascotia · 2019-11-13T13:06:25Z

@jasontedor I've added a test now, where I configure two GC strategies and check the systemd journal for the error message.

pugnascotia · 2019-11-13T15:36:12Z

@elasticmachine run elasticsearch-ci/packaging-sample-matrix

jasontedor

I left a comment about the test. We're testing JVM behavior with what is proposed, not Elasticsearch behavior.

jasontedor · 2019-11-13T23:00:10Z

qa/os/src/test/java/org/elasticsearch/packaging/test/PackageTests.java

@@ -374,4 +340,58 @@ public void test83serviceFileSetsLimits() throws Exception {

        stopElasticsearch(sh);
    }
+
+    public void test90DoNotCloseStderrWhenQuiet() throws Exception {


I don't think this tests what we want to test since the JVM never starts here (i.e., Elasticsearch code never runs). Instead, you could create an invalid elasticsearch.yml.

I know how this happened 😅 I was trying to trigger the bootstrap check about using the serial collector, and got in a muddle. I'll rework it.

Take 2 ready for a look @jasontedor.

The new test for checking stderr output was actually checking what Java emits when multiple GC strategies are configured. Now the test configures a broken YAML config, and check that ES reports this to stderr.

jasontedor

LGTM.

pugnascotia · 2019-11-15T08:57:21Z

@elasticmachine run elasticsearch-ci/2 due to docker / overlay issues.

DaveCTurner · 2019-11-15T15:11:52Z

It'd be super if this was back ported to 7.x - I've added labels to that effect so we don't lose track of it.

pugnascotia · 2019-11-15T15:15:30Z

Yep, I'll definitely do that 👍

Closes elastic#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.

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.

ywelsch · 2020-02-27T09:04:00Z

The backport PR seems to have been merged. I'm therefore removing the backport pending label here. Please shout if this is incorrect

pugnascotia added :Core/Infra/Core Core issues without another label v8.0.0 v7.5.0 labels Sep 27, 2019

pugnascotia requested a review from jasontedor September 27, 2019 11:15

jasontedor reviewed Sep 29, 2019

View reviewed changes

Merge branch 'master' into 46900-stderr-open-print-logs-location

ca2bc1f

Merge branch 'master' into 46900-stderr-open-print-logs-location

fcdada1

pugnascotia added 2 commits October 10, 2019 13:06

Merge remote-tracking branch 'upstream/master' into 46900-stderr-open…

5e74b75

…-print-logs-location

pugnascotia added 2 commits October 23, 2019 11:44

Merge remote-tracking branch 'upstream/master' into 46900-stderr-open…

950cfc0

…-print-logs-location

Guard against logging not being configured yet

fad0948

There's no point telling the user to go and check the logs if we haven't configured logging yet.

jasontedor self-requested a review October 28, 2019 14:49

jasontedor reviewed Oct 31, 2019

View reviewed changes

pugnascotia added 3 commits October 31, 2019 15:34

Merge remote-tracking branch 'upstream/master' into 46900-stderr-open…

9513f7f

…-print-logs-location

Address review feedback

4091c55

Merge remote-tracking branch 'upstream/master' into 46900-stderr-open…

de27e70

…-print-logs-location

pugnascotia removed the v7.5.0 label Nov 11, 2019

pugnascotia added 3 commits November 13, 2019 10:58

Merge remote-tracking branch 'upstream/master' into 46900-stderr-open…

41d71f2

…-print-logs-location

Remove unnecessary interfaces

1a255ae

Fix compile problem

52bb829

jasontedor requested changes Nov 13, 2019

View reviewed changes

pugnascotia added 2 commits November 14, 2019 10:13

Rework new packaging test

5fabb63

The new test for checking stderr output was actually checking what Java emits when multiple GC strategies are configured. Now the test configures a broken YAML config, and check that ES reports this to stderr.

Checkstyle

8850f14

jasontedor approved these changes Nov 14, 2019

View reviewed changes

pugnascotia changed the title ~~Don't close stderr and print the logs directory on fatal error~~ Don't close stderr under --quiet Nov 15, 2019

pugnascotia merged commit 090859b into elastic:master Nov 15, 2019

pugnascotia deleted the 46900-stderr-open-print-logs-location branch November 15, 2019 13:58

DaveCTurner added backport pending v7.6.0 labels Nov 15, 2019

pugnascotia mentioned this pull request Nov 21, 2019

Don't close stderr under --quiet #49431

Merged

$@polyfractal$ polyfractal added the >enhancement label Jan 15, 2020

This was referenced Feb 3, 2020

[meta] 7.6 release elastic/elasticsearch-net#4340

Closed

[meta] 7.6 release elastic/elasticsearch-net#4341

Closed

ywelsch removed the backport pending label Feb 27, 2020

jasontedor mentioned this pull request Sep 2, 2020

Provide a hint to check the logs if the service does not start #61767

Closed

jakelandis added v8.0.0-alpha1 and removed v8.0.0 labels Jul 26, 2021

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Don't close stderr under `--quiet` #47208

Don't close stderr under `--quiet` #47208

pugnascotia commented Sep 27, 2019 •

edited

Loading

elasticmachine commented Sep 27, 2019

pugnascotia commented Sep 29, 2019

jasontedor left a comment

jasontedor Sep 29, 2019

jasontedor Oct 13, 2019 •

edited

Loading

pugnascotia Oct 23, 2019

alpar-t commented Sep 30, 2019

pugnascotia commented Oct 4, 2019

pugnascotia commented Oct 8, 2019

pugnascotia commented Oct 9, 2019

pugnascotia commented Oct 10, 2019

pugnascotia commented Oct 10, 2019

pugnascotia commented Oct 11, 2019

jasontedor left a comment

jasontedor Oct 31, 2019

jasontedor Oct 31, 2019

pugnascotia commented Nov 5, 2019

pugnascotia commented Nov 11, 2019

jasontedor commented Nov 11, 2019

pugnascotia commented Nov 11, 2019

pugnascotia commented Nov 13, 2019

pugnascotia commented Nov 13, 2019

jasontedor left a comment

jasontedor Nov 13, 2019

pugnascotia Nov 14, 2019

pugnascotia Nov 14, 2019

jasontedor left a comment

pugnascotia commented Nov 15, 2019

DaveCTurner commented Nov 15, 2019

pugnascotia commented Nov 15, 2019

ywelsch commented Feb 27, 2020

Don't close stderr under --quiet #47208

Don't close stderr under --quiet #47208

Conversation

pugnascotia commented Sep 27, 2019 • edited Loading

elasticmachine commented Sep 27, 2019

pugnascotia commented Sep 29, 2019

jasontedor left a comment

Choose a reason for hiding this comment

jasontedor Sep 29, 2019

Choose a reason for hiding this comment

jasontedor Oct 13, 2019 • edited Loading

Choose a reason for hiding this comment

pugnascotia Oct 23, 2019

Choose a reason for hiding this comment

alpar-t commented Sep 30, 2019

pugnascotia commented Oct 4, 2019

pugnascotia commented Oct 8, 2019

pugnascotia commented Oct 9, 2019

pugnascotia commented Oct 10, 2019

pugnascotia commented Oct 10, 2019

pugnascotia commented Oct 11, 2019

jasontedor left a comment

Choose a reason for hiding this comment

jasontedor Oct 31, 2019

Choose a reason for hiding this comment

jasontedor Oct 31, 2019

Choose a reason for hiding this comment

pugnascotia commented Nov 5, 2019

pugnascotia commented Nov 11, 2019

jasontedor commented Nov 11, 2019

pugnascotia commented Nov 11, 2019

pugnascotia commented Nov 13, 2019

pugnascotia commented Nov 13, 2019

jasontedor left a comment

Choose a reason for hiding this comment

jasontedor Nov 13, 2019

Choose a reason for hiding this comment

pugnascotia Nov 14, 2019

Choose a reason for hiding this comment

pugnascotia Nov 14, 2019

Choose a reason for hiding this comment

jasontedor left a comment

Choose a reason for hiding this comment

pugnascotia commented Nov 15, 2019

DaveCTurner commented Nov 15, 2019

pugnascotia commented Nov 15, 2019

ywelsch commented Feb 27, 2020

Don't close stderr under `--quiet` #47208

Don't close stderr under `--quiet` #47208

pugnascotia commented Sep 27, 2019 •

edited

Loading

jasontedor Oct 13, 2019 •

edited

Loading