Logger / ShutdownHook

[Roy Pozarelli]

I have created a Logger,

private static Logger log = Logger.getLogger("p1"); 
static {
        FileHandler myFileHandler = null;
        try {
            myFileHandler = new FileHandler("error.log");
            myFileHandler.setFormatter(new SimpleFormatter());
            log.addHandler(myFileHandler);
            log.setLevel(Level.FINEST);
        } catch (IOException ex) {
	    log.severe("There was a problem that prohibits continuation of the program.");
	    Runtime.getRuntime().exit(1);
	}
}

In using this log in ALL my methods the log.entering("...") and log.exiting("..."); work as expected until a get to a close method in which case nothing is logged. I call setUpHook() in the constructor of the class.

void setUpHook() {
	
	log.entering("DataAccess", "setUpHook");
	
	Runtime.getRuntime().addShutdownHook(new Thread() {
	    public void run() {
                close();
	    }
	});
	
	log.exiting("DataAccess", "setUpHook");
    }

What am I missing?

[Ireneusz Kordal]

Hi,

read carefully this:
http://download.oracle.com/docs/cd/E17409_01/javase/6/docs/api/java/lang/Runtime.html#addShutdownHook%28java.lang.Thread%29

Shutdown hooks .... should also not rely blindly upon services that may have registered their own shutdown hooks and therefore may themselves in the process of shutting down.

then check source code of LogManager here:
http://kickjava.com/src/java/util/logging/LogManager.java.htm

line 224:

224    protected  LogManager() {
225     // Add a shutdown hook to close the global handlers.
226 try {
227         Runtime.getRuntime().addShutdownHook(new Cleaner());
228         } catch (IllegalStateException JavaDoc e) {
229             // If the VM is already shutting down,
230 // We do not need to register shutdownHook.
231 }

Evidently LogManager registers it's own shutdown hook.
JVM runs shutdown hooks in randomly order, and probably LogManager's hook is called before your program's hook,
and logging subsystem has been probably closed when your program tries to write event log in close() method.

[Roy Pozarelli]

I've read over the source code for LogManager that you referenced and in particular the protected default constructor that adds the a shutdown hook for a new Cleaner() and the comment about if we are already shutting down then we don't have to register the shutdown hook. So in thinking about this I changed from using a static private Logger log = ... to the following:

    void setUpHook() {
		
	Runtime.getRuntime().addShutdownHook(new Thread() {
	    public void run() {
		Logger myLog = Logger.getLogger("pl");
	        FileHandler myFH = null;
	        
	        try {
	            myFH = new FileHandler("CloseError.log", 8192, 5);
	            myFH.setFormatter(new SimpleFormatter());
	            myLog.addHandler(myFH);
	            myLog.setLevel(Level.SEVERE);
	        } catch (Exception ex) {
		    log.severe("There was a problem that prohibits " +
			    "continuation of the program.");
		    System.out.println("Halting the program.");
		    Runtime.getRuntime().halt(1);
	        }
	        
                close(myLog);
                myFH.flush();
                myFH.close();
	    }
	});
    }

So that I was creating a new log while in shutdown. The program now seems to work as expected and is consistent. Am I correct in thinking that because this new log was not "registered" it will not be interfered with by the LogManager's thread. Or do I still have potential conflicting issues?

[Roy Pozarelli]

I just read the real solution, to make it an anonymous logger - these are not registered with the LogManager and hence a clean of any interference.