Skip to content

Commit 801da08

Browse files
duncdrumduncdrum
committed
[refactor] better log reporting
1 parent 1b1e373 commit 801da08

4 files changed

Lines changed: 75 additions & 12 deletions

File tree

‎exist-core/src/main/java/org/exist/jetty/JettyStart.java‎

Lines changed: 69 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -99,6 +99,7 @@ public class JettyStart extends Observable implements LifeCycle.Listener {
9999
@GuardedBy("this") private Optional<Thread> shutdownHookThread = Optional.empty();
100100
@GuardedBy("this") private int primaryPort = 8080;
101101
@GuardedBy("this") private boolean webAppStartedSuccessfully = false;
102+
@GuardedBy("this") private String webAppStartupFailureDetail = null;
102103

103104

104105
public static void main(final String[] args) {
@@ -134,6 +135,23 @@ private static void consoleOut(final String msg) {
134135
System.out.println(msg); //NOSONAR this has to go to the console
135136
}
136137

138+
private static void consoleErr(final String msg) {
139+
System.err.println(msg); //NOSONAR surfaced in Surefire output when test log4j root is OFF
140+
}
141+
142+
private synchronized void recordStartupFailure(final String detail, final Throwable cause) {
143+
webAppStartedSuccessfully = false;
144+
webAppStartupFailureDetail = detail;
145+
if (cause != null) {
146+
logger.fatal("Jetty startup failed: {}", detail, cause);
147+
consoleErr("Jetty startup failed: " + detail);
148+
cause.printStackTrace(System.err); //NOSONAR CI diagnostics when log4j is disabled in tests
149+
} else {
150+
logger.fatal("Jetty startup failed: {}", detail);
151+
consoleErr("Jetty startup failed: " + detail);
152+
}
153+
}
154+
137155
public synchronized void run() {
138156
run(true);
139157
}
@@ -246,12 +264,12 @@ public synchronized void run(final String[] args, final Observer observer) {
246264
DatabaseManager.registerDatabase(xmldb);
247265

248266
} catch (final Exception e) {
249-
logger.error("configuration error: {}", e.getMessage(), e);
250-
e.printStackTrace();
267+
recordStartupFailure("configuration error: " + e.getMessage(), e);
251268
return;
252269
}
253270

254271
try {
272+
webAppStartupFailureDetail = null;
255273
webAppStartedSuccessfully = false;
256274
// load jetty configurations
257275
final List<Path> configFiles = getEnabledConfigFiles(jettyConfig);
@@ -349,22 +367,23 @@ public synchronized void run(final String[] args, final Observer observer) {
349367

350368
awaitWebAppContextsStarted(getAllHandlers(server.getHandler()));
351369
webAppStartedSuccessfully = true;
370+
webAppStartupFailureDetail = null;
352371

353372
setChanged();
354373
notifyObservers(SIGNAL_STARTED);
355374

356375
} catch (final SocketException e) {
357-
webAppStartedSuccessfully = false;
358-
logger.error("----------------------------------------------------------");
359-
logger.error("ERROR: Could not bind to port because {}", e.getMessage());
360-
logger.error(e.toString());
361-
logger.error("----------------------------------------------------------");
376+
recordStartupFailure("Could not bind to port: " + e.getMessage(), e);
362377
setChanged();
363378
notifyObservers(SIGNAL_ERROR);
364379

365380
} catch (final Exception e) {
366-
webAppStartedSuccessfully = false;
367-
logger.fatal("An unexpected error occurred, web server can not be started: {}", e.getMessage(), e);
381+
if (webAppStartupFailureDetail == null) {
382+
recordStartupFailure(
383+
e.getMessage() != null ? e.getMessage() : e.getClass().getSimpleName(), e);
384+
} else {
385+
recordStartupFailure(webAppStartupFailureDetail, e);
386+
}
368387
setChanged();
369388
notifyObservers(SIGNAL_ERROR);
370389
}
@@ -558,7 +577,18 @@ private void awaitWebAppContextsStarted(final List<Handler> handlers) throws Int
558577
}
559578
throw new IllegalStateException(
560579
"Web application context did not become ready within " + timeoutMs + "ms: "
561-
+ describePendingWebApps(webApps, distributionLayout));
580+
+ describePendingWebApps(webApps, distributionLayout),
581+
firstUnavailableCause(webApps));
582+
}
583+
584+
private static Throwable firstUnavailableCause(final List<WebAppContext> webApps) {
585+
for (final WebAppContext webApp : webApps) {
586+
final Throwable unavailable = webApp.getUnavailableException();
587+
if (unavailable != null) {
588+
return unavailable;
589+
}
590+
}
591+
return null;
562592
}
563593

564594
private static boolean isDistributionLayout(final List<WebAppContext> webApps) {
@@ -592,12 +622,31 @@ private static String describePendingWebApps(final List<WebAppContext> webApps,
592622
details.append(webApp.getContextPath())
593623
.append(" started=").append(webApp.isStarted())
594624
.append(" available=").append(webApp.isAvailable())
595-
.append(" requireAvailable=").append(requiresAvailability(webApp, distributionLayout));
625+
.append(" requireAvailable=").append(requiresAvailability(webApp, distributionLayout))
626+
.append(" war=").append(describeWebAppWar(webApp));
627+
final Throwable unavailable = webApp.getUnavailableException();
628+
if (unavailable != null) {
629+
details.append(" unavailableCause=").append(unavailable.getClass().getName())
630+
.append(": ").append(unavailable.getMessage());
631+
}
596632
}
597633
}
598634
return details.isEmpty() ? "unknown" : details.toString();
599635
}
600636

637+
private static String describeWebAppWar(final WebAppContext webApp) {
638+
final String war = webApp.getWar();
639+
if (war != null && !war.isBlank()) {
640+
return war;
641+
}
642+
try {
643+
final org.eclipse.jetty.util.resource.Resource baseResource = webApp.getBaseResource();
644+
return baseResource != null ? String.valueOf(baseResource) : "null";
645+
} catch (final Exception e) {
646+
return "unresolved(" + e.getMessage() + ")";
647+
}
648+
}
649+
601650
private static boolean requiresAvailability(final WebAppContext webApp, final boolean distributionLayout) {
602651
return !(distributionLayout && "/".equals(webApp.getContextPath()));
603652
}
@@ -813,4 +862,13 @@ public synchronized int getPrimaryPort() {
813862
public synchronized boolean isWebAppStartedSuccessfully() {
814863
return webAppStartedSuccessfully;
815864
}
865+
866+
/**
867+
* When {@link #isWebAppStartedSuccessfully()} is {@code false}, holds the last startup failure
868+
* message for test diagnostics (also printed to {@code System.err} because module test log4j
869+
* configs often set {@code Root level="OFF"}).
870+
*/
871+
public synchronized Optional<String> getWebAppStartupFailureDetail() {
872+
return Optional.ofNullable(webAppStartupFailureDetail);
873+
}
816874
}

‎exist-core/src/main/java/org/exist/test/ExistWebServer.java‎

Lines changed: 4 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -196,8 +196,11 @@ private void startJettyServer() throws InterruptedException {
196196

197197
private void awaitJettyReadyAfterRun() throws InterruptedException {
198198
if (!server.isWebAppStartedSuccessfully()) {
199+
final String detail = server.getWebAppStartupFailureDetail()
200+
.filter(s -> !s.isBlank())
201+
.orElse("no startup detail recorded");
199202
throw new IllegalStateException(
200-
"Jetty web application context did not start successfully (see server log)");
203+
"Jetty web application context did not start successfully: " + detail);
201204
}
202205
TestUtils.awaitJettyWebAppReady(server.getPrimaryPort(), jettyStandaloneMode);
203206
}

‎exist-jetty-config/src/main/resources/org/exist/jetty/etc/jetty-deploy.xml‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -14,6 +14,7 @@
1414
<Arg>
1515
<New class="org.exist.jetty.WebAppContext">
1616
<Set name="contextPath">/exist</Set>
17+
<Set name="throwUnavailableOnStartupException">true</Set>
1718
<Set name="war"><SystemProperty name="exist.jetty.webapp.dir"><Default><Property name="jetty.home" default="."/>/../../../webapp/</Default></SystemProperty></Set>
1819
<Set name="defaultsDescriptor"><Property name="jetty.home" default="."/>/etc/webdefault.xml</Set>
1920
<Set name="securityHandler">

‎exist-jetty-config/src/main/resources/org/exist/jetty/etc/standalone-jetty-deploy.xml‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -12,6 +12,7 @@
1212
<Arg>
1313
<New class="org.exist.jetty.WebAppContext">
1414
<Set name="contextPath">/</Set>
15+
<Set name="throwUnavailableOnStartupException">true</Set>
1516
<Set name="war"><SystemProperty name="exist.jetty.standalone.webapp.dir"><Default><Property name="jetty.home" default="."/>/../../../standalone-webapp/</Default></SystemProperty></Set>
1617
<Set name="defaultsDescriptor"><Property name="jetty.home" default="."/>/etc/webdefault.xml</Set>
1718
<Set name="securityHandler">

0 commit comments

Comments
 (0)