Skip to content

Commit

Permalink
8303198: System and Runtime.exit() resilience to logging errors
Browse files Browse the repository at this point in the history
Reviewed-by: dholmes, jpai, alanb
  • Loading branch information
Roger Riggs committed Mar 3, 2023
1 parent 80739e1 commit 379f206
Show file tree
Hide file tree
Showing 2 changed files with 67 additions and 27 deletions.
31 changes: 17 additions & 14 deletions src/java.base/share/classes/java/lang/Shutdown.java
Original file line number Diff line number Diff line change
Expand Up @@ -157,37 +157,40 @@ static void halt(int status) {
* which should pass a nonzero status code.
*/
static void exit(int status) {
System.Logger log = getRuntimeExitLogger(); // Locate the logger without holding the lock;
logRuntimeExit(status); // Log without holding the lock;

synchronized (Shutdown.class) {
/* Synchronize on the class object, causing any other thread
* that attempts to initiate shutdown to stall indefinitely
*/
if (log != null) {
Throwable throwable = new Throwable("Runtime.exit(" + status + ")");
log.log(System.Logger.Level.DEBUG, "Runtime.exit() called with status: " + status,
throwable);
}
beforeHalt();
runHooks();
halt(status);
}
}

/* Locate and return the logger for Shutdown.exit, if it is functional and DEBUG enabled.
* Exceptions should not prevent System.exit; the exception is printed and otherwise ignored.
/* Locate the logger and log the Runtime.exit(status).
* Catch and ignore any and all exceptions.
*/
private static System.Logger getRuntimeExitLogger() {
private static void logRuntimeExit(int status) {
try {
System.Logger log = System.getLogger("java.lang.Runtime");
return (log.isLoggable(System.Logger.Level.DEBUG)) ? log : null;
if (log.isLoggable(System.Logger.Level.DEBUG)) {
Throwable throwable = new Throwable("Runtime.exit(" + status + ")");
log.log(System.Logger.Level.DEBUG, "Runtime.exit() called with status: " + status,
throwable);
}
} catch (Throwable throwable) {
// Exceptions from locating the Logger are printed but do not prevent exit
System.err.println("Runtime.exit() log finder failed with: " + throwable.getMessage());
try {
// Exceptions from the Logger are printed but do not prevent exit
System.err.println("Runtime.exit(" + status + ") logging failed: " +
throwable.getMessage());
} catch (Throwable throwable2) {
// Ignore
}
}
return null;
}


/* Invoked by the JNI DestroyJavaVM procedure when the last non-daemon
* thread has finished. Unlike the exit method, this method does not
* actually halt the VM.
Expand Down
63 changes: 50 additions & 13 deletions test/jdk/java/lang/RuntimeTests/RuntimeExitLogTest.java
Original file line number Diff line number Diff line change
Expand Up @@ -26,7 +26,9 @@
import java.io.IOException;
import java.nio.file.Path;
import java.util.List;
import java.util.Optional;
import java.util.logging.LogRecord;
import java.util.logging.Logger;
import java.util.logging.StreamHandler;
import java.util.stream.Stream;


Expand All @@ -47,12 +49,17 @@ public class RuntimeExitLogTest {
private static final String TEST_JDK = System.getProperty("test.jdk");
private static final String TEST_SRC = System.getProperty("test.src");

private static Object HOLD_LOGGER;

/**
* Call System.exit() with the parameter (or zero if not supplied).
* @param args zero or 1 argument, an exit status
*/
public static void main(String[] args) throws InterruptedException {
int status = args.length > 0 ? Integer.parseInt(args[0]) : 0;
if (System.getProperty("ThrowingHandler") != null) {
HOLD_LOGGER = ThrowingHandler.installHandler();
}
System.exit(status);
}

Expand All @@ -64,27 +71,35 @@ private static Stream<Arguments> logParamProvider() {
return Stream.of(
// Logging enabled with level DEBUG
Arguments.of(List.of("-Djava.util.logging.config.file=" +
Path.of(TEST_SRC, "ExitLogging-FINE.properties").toString()), 1, true),
Path.of(TEST_SRC, "ExitLogging-FINE.properties").toString()), 1,
"Runtime.exit() called with status: 1"),
// Logging disabled due to level
Arguments.of(List.of("-Djava.util.logging.config.file=" +
Path.of(TEST_SRC, "ExitLogging-INFO.properties").toString()), 2, false),
Path.of(TEST_SRC, "ExitLogging-INFO.properties").toString()), 2,
""),
// Console logger
Arguments.of(List.of("--limit-modules", "java.base",
"-Djdk.system.logger.level=DEBUG"), 3, true),
"-Djdk.system.logger.level=DEBUG"), 3,
"Runtime.exit() called with status: 3"),
// Console logger
Arguments.of(List.of(), 4, false)
);
Arguments.of(List.of(), 4, ""),
// Throwing Handler
Arguments.of(List.of("-DThrowingHandler",
"-Djava.util.logging.config.file=" +
Path.of(TEST_SRC, "ExitLogging-FINE.properties").toString()), 5,
"Runtime.exit(5) logging failed: Exception in publish")
);
}

/**
* Check that the logger output of a launched process contains the expected message.
* @param logProps The name of the log.properties file to set on the command line
* @param status the expected exit status of the process
* @param shouldLog true if the log should contain the message expected from Runtime.exit(status)
* @param expectMessage log should contain the message
*/
@ParameterizedTest
@MethodSource("logParamProvider")
public void checkLogger(List<String> logProps, int status, boolean shouldLog) {
public void checkLogger(List<String> logProps, int status, String expectMessage) {
ProcessBuilder pb = new ProcessBuilder();
pb.redirectErrorStream(true);

Expand All @@ -98,12 +113,15 @@ public void checkLogger(List<String> logProps, int status, boolean shouldLog) {
Process process = pb.start();
try (BufferedReader reader = process.inputReader()) {
List<String> lines = reader.lines().toList();
final String expected = "Runtime.exit() called with status: " + status;
Optional<String> found = lines.stream().filter(s -> s.contains(expected)).findFirst();
if (found.isPresent() != shouldLog) {
System.err.println("---- Process output begin");
boolean match = (expectMessage.isEmpty())
? lines.size() == 0
: lines.stream().filter(s -> s.contains(expectMessage)).findFirst().isPresent();
if (!match) {
// Output lines for debug
System.err.println("Expected: \"" + expectMessage + "\"");
System.err.println("---- Actual output begin");
lines.forEach(l -> System.err.println(l));
System.err.println("---- Process output end");
System.err.println("---- Actual output end");
fail("Unexpected log contents");
}
}
Expand All @@ -113,4 +131,23 @@ public void checkLogger(List<String> logProps, int status, boolean shouldLog) {
fail(ex);
}
}

/**
* A LoggingHandler that throws an Exception.
*/
public static class ThrowingHandler extends StreamHandler {

// Install this handler for java.lang.Runtime
public static Logger installHandler() {
Logger logger = Logger.getLogger("java.lang.Runtime");
logger.addHandler(new ThrowingHandler());
return logger;
}

@Override
public synchronized void publish(LogRecord record) {
super.publish(record);
throw new RuntimeException("Exception in publish");
}
}
}

1 comment on commit 379f206

@openjdk-notifier
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Please sign in to comment.