I have a specialized logger class which uses the java.util.logging.Logger class. I want to be able to use this logger in the shutdown hook of another class. However, it doesn't seem to log at shutdown. From what I've read, there may already be a shutdown hook activated for the logger itself which is causing the issue.
How can I get this to work? Ideally, I would like it to be seen in the log file that I did in fact execute the shutdown hook when the process terminated.
Again looking at the source, the solution appears to be to define a system property java.util.logging.manager which is a subclass of LogManager which overrides the reset(); method so the Loggers continue to work on shutdown.
import java.util.logging.LogManager;
import java.util.logging.Logger;
public class Main {
static {
// must be called before any Logger method is used.
System.setProperty("java.util.logging.manager", MyLogManager.class.getName());
}
public static class MyLogManager extends LogManager {
static MyLogManager instance;
public MyLogManager() { instance = this; }
@Override public void reset() { /* don't reset yet. */ }
private void reset0() { super.reset(); }
public static void resetFinally() { instance.reset0(); }
}
public static void main(String... args) {
Logger logger1 = Logger.getLogger("Main1");
logger1.info("Before shutdown");
Runtime.getRuntime().addShutdownHook(new Thread(new Runnable() {
@Override
public void run() {
try {
Logger logger2 = Logger.getLogger("Main2");
logger2.info("Shutting down 2");
} finally {
MyLogManager.resetFinally();
}
}
}));
}
}
prints
Dec 11, 2012 5:56:55 PM Main main
INFO: Before shutdown
Dec 11, 2012 5:56:55 PM Main$1 run
INFO: Shutting down 2
From this code for LogManager, you can see see there is a shutdown hook which dismantles the handlers and closes them. Logger only works in shutdown if it hasn't been used before so this code is not run.
// This private class is used as a shutdown hook.
// It does a "reset" to close all open handlers.
private class Cleaner extends Thread {
private Cleaner() {
/* Set context class loader to null in order to avoid
* keeping a strong reference to an application classloader.
*/
this.setContextClassLoader(null);
}
public void run() {
// This is to ensure the LogManager.<clinit> is completed
// before synchronized block. Otherwise deadlocks are possible.
LogManager mgr = manager;
// If the global handlers haven't been initialized yet, we
// don't want to initialize them just so we can close them!
synchronized (LogManager.this) {
// Note that death is imminent.
deathImminent = true;
initializedGlobalHandlers = true;
}
// Do a reset to close all active handlers.
reset();
}
}
/**
* Protected constructor. This is protected so that container applications
* (such as J2EE containers) can subclass the object. It is non-public as
* it is intended that there only be one LogManager object, whose value is
* retrieved by calling Logmanager.getLogManager.
*/
protected LogManager() {
// Add a shutdown hook to close the global handlers.
try {
Runtime.getRuntime().addShutdownHook(new Cleaner());
} catch (IllegalStateException e) {
// If the VM is already shutting down,
// We do not need to register shutdownHook.
}
}
From my own testing
Runtime.getRuntime().addShutdownHook(new Thread(new Runnable() {
@Override
public void run() {
try {
Logger logger2 = Logger.getLogger("Main2");
logger2.info("Shutting down 2");
} catch (Throwable t) {
t.printStackTrace();
}
}
}));
prints
Dec 11, 2012 5:40:15 PM Main$1 run
INFO: Shutting down 2
but if you add
Logger logger1 = Logger.getLogger("Main1");
outside this block you get nothing.
Does the shutdown hook has any advantage?
You better, add the Log output in the last line in main: The finally block will be executed in all cases, except when the VM crashes but then the shutdown hook will not be executed, too.
static void main(String[] argv) {
try {
startApp();
} finally {
LOGGER.info("shudown");
}
}
