Zombie FileHandler locks can exhaust all available log file locks.

Daniel Fuchs daniel.fuchs at oracle.com
Mon Jun 23 14:42:33 UTC 2014


Hi,

I wonder whether the following patch would solve the
issue. In the case where the lock file already exists,
we check whether it's writable, and whether its directory
is writable, and if so, we open it for 'write+append',
otherwise, we continue with the next lock name.

I we have manage to open the lock file, then we proceed
with trying to lock it, as before.
If locking succeeds - we use that file.
If locking throws exception - we only fall through
if we actually created the file, otherwise we proceed
with the next lock name.

Would that make sense? It passes the CheckLockLocationTest
that was added for 6244047.
Note: I also added a deleteOnExit() hook for good measure.

-- daniel

--- a/src/share/classes/java/util/logging/FileHandler.java
+++ b/src/share/classes/java/util/logging/FileHandler.java
@@ -25,6 +25,7 @@

  package java.util.logging;

+import static java.nio.file.StandardOpenOption.APPEND;
  import static java.nio.file.StandardOpenOption.CREATE_NEW;
  import static java.nio.file.StandardOpenOption.WRITE;

@@ -35,6 +36,8 @@
  import java.io.OutputStream;
  import java.nio.channels.FileChannel;
  import java.nio.file.FileAlreadyExistsException;
+import java.nio.file.Files;
+import java.nio.file.Path;
  import java.nio.file.Paths;
  import java.security.AccessController;
  import java.security.PrivilegedAction;
@@ -434,24 +437,44 @@
                      continue;
                  }

+                final Path lockFilePath = Paths.get(lockFileName);
+                boolean fileCreated;
                  try {
-                    lockFileChannel = 
FileChannel.open(Paths.get(lockFileName),
+                    lockFileChannel = FileChannel.open(lockFilePath,
                              CREATE_NEW, WRITE);
+                    fileCreated = true;
                  } catch (FileAlreadyExistsException ix) {
+                    // This may be a zombie file left over by a previous
+                    // execution. Reuse it - but since we didn't create
+                    // it we won't delete it either.
+                    if (Files.isRegularFile(lockFilePath)
+                            && Files.isWritable(lockFilePath)
+                            && 
Files.isWritable(lockFilePath.getParent())) {
+                        lockFileChannel = FileChannel.open(lockFilePath,
+                                WRITE, APPEND);
+                        fileCreated = false;
+                    } else {
                      // try the next lock file name in the sequence
                      continue;
                  }
+                }

                  boolean available;
                  try {
                      available = lockFileChannel.tryLock() != null;
+                    if (available) {
+                        // we got the lock - ensure that the lock file
+                        // will be deleted on exit.
+                        lockFilePath.toFile().deleteOnExit();
+                    }
                      // We got the lock OK.
                  } catch (IOException ix) {
                      // We got an IOException while trying to get the lock.
                      // This normally indicates that locking is not 
supported
                      // on the target directory.  We have to proceed 
without
-                    // getting a lock.   Drop through.
-                    available = true;
+                    // getting a lock.   Drop through, but only if we did
+                    // create the file...
+                    available = fileCreated;
                  }
                  if (available) {
                      // We got the lock.  Remember it.



On 6/23/14 3:18 PM, Daniel Fuchs wrote:
> Hi Jason,
>
> On 6/23/14 2:51 PM, Jason Mehrens wrote:
>> Daniel,
>>
>>
>> My understanding is that changing CREATE_NEW to use CREATE would make
>> it work like does in JDK7.  Closing the lock files when the
>> FileHandler is unreferenced I is probably the fix for JDK-6774110:
>> lock file is not deleted when child logger is used.
>
> I'll see if I can dig more info about the reason for the change.
> Thanks for pointing at JDK-6774110 - I'll have a look at that as well.
>
> -- daniel
>
>>
>>
>> If we could prove that system FileLock is mandatory we could use the
>> JDK7 behavior otherwise if they are advisory then use the JDK8
>> behavior.  If we knew the boot time of the JVM host O/S we could
>> delete all lock files older than the boot time + some constant.
>>
>>
>> Jason
>>
>>
>>
>>
>> ----------------------------------------
>>> Date: Mon, 23 Jun 2014 11:48:18 +0200
>>> From: daniel.fuchs at oracle.com
>>> To: jason_mehrens at hotmail.com; core-libs-dev at openjdk.java.net
>>> Subject: Re: Zombie FileHandler locks can exhaust all available log
>>> file locks.
>>>
>>> Hi Jason,
>>>
>>> Looking at the diff for 6244047 - I see that, as you pointed
>>> out, the unwanted behavior described comes from the fact that
>>> the new code is using CREATE_NEW - which prevents the 'zombie
>>> lock files' from being reused.
>>>
>>> I am not an expert in file locks - but I wonder whether we
>>> could revert to using CREATE instead: wouldn't tryLock() later
>>> tell us if the file is used by another entity?
>>>
>>> Another possibility would be to combine CREATE_NEW and
>>> DELETE_ON_CLOSE, which according to StandardOpenOptions will
>>> attempt to delete the file on JVM termination if close()
>>> hasn't been called.
>>> This probably wouldn't help in case on VM crash,
>>> but it would help in the case demonstrated by your test below.
>>> I have however some reluctance because I see that we call
>>> FileChannel.close() in the case were the lock can't be obtained,
>>> and I'm not sure what that would do...
>>> Also StandardOpenOptions has some warning about using
>>> DELETE_ON_CLOSE for files that can be opened concurrently
>>> by other entities - so I'm not sure it would be appropriate.
>>>
>>> The last possibility I see would be to change the lock HashMap to
>>> take instances of a subclass of WeakReference<FileHandler> as
>>> values (instead of String), and add some code that attempts to
>>> close & remove the lock file when the FileHandler is no longer
>>> referenced.
>>> Again - this will probably not help in the case of crash, and also
>>> adds the question on when the weak reference queue should be polled to
>>> ensure that the no longer referenced FileChannel are closed in a
>>> timely fashion.
>>>
>>> All in all - I feel our best options would be to revert to using
>>> CREATE, or use CREATE_NEW + DELETE_ON_CLOSE, or not do anything
>>> and live with the issue.
>>> Hopefully some nio experts will chime in ;-)
>>>
>>> On another track - we could also make MAX configurable - but that
>>> would just be shifting the issue around - wouldn't it?
>>>
>>> best regards,
>>>
>>> -- daniel
>>>
>>> On 6/20/14 10:54 PM, Jason Mehrens wrote:
>>>> Daniel, Jim,
>>>>
>>>>
>>>> In JDK8 the FileHandler file locking was changed to use
>>>> FileChannel.open with CREATE_NEW. If the file exists (locked or not)
>>>> the FileHandler will rotate due to safety concerns about writing to
>>>> the same log file. The FileHandler has an upper bound of 100 as the
>>>> number of file locks that can be attempted to be acquired. Given the
>>>> right pattern, enough time, and enough failures it seems at it is
>>>> possible for a program to end up in a state where the FileHandler is
>>>> surrounded by zombie lock files refuses log or perform a clean up
>>>> action. (A.K.A Farmer Rick Grimes). This means that the lck files
>>>> have to manually be deleted or the FileHandler will just fail with
>>>> an IOException every time it is created.
>>>>
>>>>
>>>> A simple test to emulate crashing is to run (JDK7 vs. JDK8) 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();
>>>> }
>>>> }
>>>>
>>>> }
>>>>
>>>>
>>>> I understand that if you can't trust that the file locking always
>>>> works then there isn't much that can be done. Leaving the number of
>>>> locks as unbounded isn't really an option either. Seems like there
>>>> should be a way to identify zombie lock files (ATOMIC_MOVE) and
>>>> delete them. Any thoughts on this?
>>>>
>>>> The source discussion on this can be found at
>>>> http://stackoverflow.com/questions/24321098/is-java-util-logging-filehandler-in-java-8-broken
>>>>
>>>>
>>>>
>>>> Regards,
>>>>
>>>> Jason
>>>>
>>>
>




More information about the core-libs-dev mailing list