Is java.util.logging.FileHandler in Java 8 broken?

问题:

First, a simple test code:

package javaapplication23;

import java.io.IOException;
import java.util.logging.FileHandler;

public class JavaApplication23 {
    public static void main(String[] args) throws IOException {
        new FileHandler("./test_%u_%g.log", 10000, 100, true);
    }
}

This test code creates with Java 7 only one File "test_0_0.log", no matter, how often I run the program. This is the expected behaviour because the append parameter in the constructor is set to true.

But if I run this sample in Java 8, every run creates a new File (test_0_0.log, test_0_1.log, test_0_2.log,...). I think this is a bug.

Imho, the related change in Java is this one:

@@ -413,18 +428,18 @@
                     // object.  Try again.
                     continue;
                 }
-                FileChannel fc;
+
                 try {
-                    lockStream = new FileOutputStream(lockFileName);
-                    fc = lockStream.getChannel();
-                } catch (IOException ix) {
-                    // We got an IOException while trying to open the file.
-                    // Try the next file.
+                    lockFileChannel = FileChannel.open(Paths.get(lockFileName),
+                            CREATE_NEW, WRITE);
+                } catch (FileAlreadyExistsException ix) {
+                    // try the next lock file name in the sequence
                     continue;
                 }
+
                 boolean available;
                 try {
-                    available = fc.tryLock() != null;
+                    available = lockFileChannel.tryLock() != null;
                     // We got the lock OK.
                 } catch (IOException ix) {
                     // We got an IOException while trying to get the lock.
@@ -440,7 +455,7 @@
                 }

                 // We failed to get the lock.  Try next file.
-                fc.close();
+                lockFileChannel.close();
             }
         }

(In full: OpenJDK changeset 6123:ac22a52a732c)

I know that normally the FileHandler gets closed by the Logmanager, but this is not the case, if the system or the application crashes or the process gets killed. This is why I do not have a "close" statement in the above sample code.

Now I have two questions:

1) What is your opinion? Is this a bug? (Almost answered in the following comments and answers)

2) Do you know a workaround to get the old Java 7 behavior in Java 8? (The more important question...)

Thanks for your answers.

回答1:

Closing of the FileHandler deletes the 'lck' file. If the lock file exists at all under a JDK8 version that is less than update 40 (java.util.logging), the FileHandler is going to rotate. From the OpenJDK discussion, the decision was made to always rotate if the lck file exists in addtion to if the current process can't lock it. The reason given is that it is always safer to rotate when the lock file exists. So this gets really nasty if you have rotating pattern in use with a mix of JDK versions because the JDK7 version will reuse the lock but the JDK8 version will leave it and rotate. Which is what you are doing with your test case.

Using JDK8 if I purge all log and lck files from the working directory and then run:

public static void main(String[] args) throws IOException {
    System.out.println(System.getProperty("java.runtime.version"));
    new FileHandler("./test_%u.log", 10000, 100, true).close();
}

I always see a file named 'test_0.log.0'. I get the same result using JDK7.

Bottom line is that is that you have to ensure your FileHandlers are closed. If it is never garbaged collected or removed from the logger tree then LogManager will close your FileHandler. Otherwise you have to close it. After that is fixed, purge all lock files before running your new patched code. Then be aware that if the JVM process crashed or is killed the lock file won't be deleted. If you have an I/O error on close your lock file won't be deleted. When the next process starts, the FileHandler will rotate.

As you point out, it is possible to use up all of the lock files on JDK8 if the above conditions occur over 100 runs. A simple test for this is to run the following code twice without deleting the log and lck files:

public static void main(String[] args) throws Exception {
    System.out.println(System.getProperty("java.runtime.version"));
    ReferenceQueue<FileHandler> q = new ReferenceQueue<>();
    for (int i=0; i<100; i++) {
        WeakReference<FileHandler> h = new WeakReference<>(
                new FileHandler("./test_%u.log", 10000, 2, true), q);
        while (q.poll() != h) {
            System.runFinalization();
            System.gc();
            System.runFinalization();
            Thread.yield();
        }
    }
}

However, the test case above won't work if JDK-6774110 is fixed correctly. The issue for this can be tracked on the OpenJDK site under RFR: 8048020 - Regression on java.util.logging.FileHandler and FileHandler webrev.