Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

Log messages lost in few specific situations

I am using java.util.logging to do all the logging of my application.

Until recently, I was using the logging facility without any specific configuration. Everything worked as expected, all the logs were visible in the console (stderr)

Now, I wanted to customize the configuration for my logs. I want the logs to be displayed on the console, but I want them to be written in a file, too. I came up with the following solution :

public static void main(String[] args) {
    System.setProperty("java.util.logging.config.file", "log.config");
    Logger defLogger = Logger.getLogger("fr.def"); // all loggers I use begin by "fr.def"
    defLogger.setLevel(Level.ALL);
    defLogger.addHandler(new ConsoleHandler());
    defLogger.addHandler(new FileHandler());
    // real code here ...

Here is the content of the log.config file :

java.util.logging.FileHandler.formatter=java.util.logging.SimpleFormatter
java.util.logging.FileHandler.count=10
java.util.logging.FileHandler.pattern=logs/visiodef2.%g.log

This solution mostly works : I can see the logs in the console, and in the files too. Except that, in some situations, some log messages are simply lost (for both the console and the file). Examples of situations where logs are lost :

  • on a shutdown hook of the JVM
  • on the default uncaught exception handler
  • on the EDT's exception handler
  • on the windowClosing event of the main JFrame (configured with the default close operation EXIT_ON_CLOSE)

There is no other configuration than what is described above. The log level is not involved : I can see some INFO logs, but some of the lost logs are SEVERE.

I also tried to add a shutdown hook to flush all the Handlers, but with no success.

So, the question : is it safe to configure my logging the way I do ? Can you see any reason why some logs can be lost ?

like image 936
barjak Avatar asked Oct 29 '10 09:10

barjak


1 Answers

I found the problem. And this is weird.

Actually, my problem is not related at all with the fact that the log happens in an exception handler or in a Frame event. The problem is that the garbage collector destroys the "fr.def" logger a few seconds after it is created ! Thus, the FileHandler is destroyed too. The GC can do it because the LogManager only keeps weak references to the Loggers it creates.

The javadoc of Logger.getLogger doesn't tell anything about that, but the javadoc of LogManager.addLogger, which is called by the former, explicitly says that :

The application should retain its own reference to the Logger object to avoid it being garbage collected. The LogManager may only retain a weak reference.

So, the workaround was to keep a reference to the object returned by Logger.getLogger("fr.def").

Edit

It seems that the choice of using weak references came from this bug report.

like image 156
barjak Avatar answered Sep 21 '22 00:09

barjak