RE: Zombie FileHandler locks can exhaust all available log file locks.
Daniel, With regard to JDK-4420020, in the original webrev Jim was incorrectly using java.io.File.canWrite() but that webrev was replaced by the current version. The NIO.2 code performs the effective access checks correctly. With regard to JDK-6244047 my concern was that checking the permissions and preconditions up front is a small 'TOCTOU' race and redundant because the next step after that is to open the FileChannel. I would assume both CREATE or CREATE_NEW plus WRITE would perform the effective access checks on open. The use of delete on exit is a deal breaker because you can't undo a registration on close of the FileHandler which can trigger an OOME. See https://bugs.openjdk.java.net/browse/JDK-4872014. I've used custom proxy handlers that generate a file name based off of the LogRecord which results in generating lots of file names and opening and close the FileHandler on demand. If the behavior is reverted to use CREATE instead of CREATE_NEW then we have to deal with JDK-8031438 because any user code can lock a file ahead of opening the FileHandler. Jason Date: Mon, 23 Jun 2014 17:13:04 +0200 From: daniel.fu...@oracle.com To: alan.bate...@oracle.com; jason_mehr...@hotmail.com; core-libs-dev@openjdk.java.net Subject: Re: Zombie FileHandler locks can exhaust all available log file locks. On 6/23/14 4:53 PM, Alan Bateman wrote: On 23/06/2014 10:48, Daniel Fuchs wrote: : 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 ;-) The logging use of FileLock is a bit unusual but looking at it now then I don't see the reason why it needs to use CREATE_NEW. OK - thanks - in the discussion that ended up in the patch where CREATE_NEW was introduced Jason (I think it was Jason) pointed at https://bugs.openjdk.java.net/browse/JDK-4420020 I'm guessing here that maybe it would be wrong to use an already existing lock file if you don't have the rights to write to its directory - and that using CREATE_NEW ensures that you have all necessary access rights all along the path. I don't think DELETE_ON_CLOSE is suitable here as that work is for transient work files which isn't the case here. Instead it could use deleteOnExit to have some chance of removing it on a graceful exit. Right - I suggested a patch in another mail where I just use that. BTW: Do you know why locks is Map? Would a Set do? It certainly looks as if we could use a simple HashSet here. Thanks Alan! -- daniel -Alan.
Re: Zombie FileHandler locks can exhaust all available log file locks.
Hi Jason, Thanks for the feedback! On 6/24/14 7:08 PM, Jason Mehrens wrote: Daniel, With regard to JDK-4420020, in the original webrev Jim was incorrectly using java.io.File.canWrite() but that webrev was replaced by the current version. The NIO.2 code performs the effective access checks correctly. Thanks. With regard to JDK-6244047 my concern was that checking the permissions and preconditions up front is a small 'TOCTOU' race and redundant because the next step after that is to open the FileChannel. I would assume both CREATE or CREATE_NEW plus WRITE would perform the effective access checks on open. OK. The use of delete on exit is a deal breaker because you can't undo a registration on close of the FileHandler which can trigger an OOME. See https://bugs.openjdk.java.net/browse/JDK-4872014. I've used custom proxy handlers that generate a file name based off of the LogRecord which results in generating lots of file names and opening and close the FileHandler on demand. ah. h. I didn't think there would be that many FileHandlers... Well - I guess that if we find a way to reuse the zombie lock files then we don't really need the delete on exit. Someone creating a FileHandler programmatically should be responsible for closing it - so if an application creates FileHandlers without closing them then it's a bug in the application. If the behavior is reverted to use CREATE instead of CREATE_NEW then we have to deal with JDK-8031438 because any user code can lock a file ahead of opening the FileHandler. Yes - I discovered that while writing a test for my suggested fix ;-) Catching OverlappingFileLockException in FileHandler.openFiles and setting available to false when it's thrown fixes the issue. So let's just remove the deleteOnExit add the catch for OverlappingFileLockException to my patch and we should be good. On the other hand we could just use replace CREATE_NEW by CREATE but I have some misgivings about the part that sets available to true when tryLock throws an IOException. I'm not sure we should be doing that if we haven't actually created the lock file. So I think I'd prefer keeping the two steps behavior - first try CREATE_NEW - then attempt to use CREATE if CREATE_NEW failed... I'm not sure CREATE will check the access rights for writing in the directory if the file already exists - so checking the directory for write access in that case is probably the right thing to do. Would you agree? -- daniel Jason Date: Mon, 23 Jun 2014 17:13:04 +0200 From: daniel.fu...@oracle.com To: alan.bate...@oracle.com; jason_mehr...@hotmail.com; core-libs-dev@openjdk.java.net Subject: Re: Zombie FileHandler locks can exhaust all available log file locks. On 6/23/14 4:53 PM, Alan Bateman wrote: On 23/06/2014 10:48, Daniel Fuchs wrote: : 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 ;-) The logging use of FileLock is a bit unusual but looking at it now then I don't see the reason why it needs to use CREATE_NEW. OK - thanks - in the discussion that ended up in the patch where CREATE_NEW was introduced Jason (I think it was Jason) pointed at https://bugs.openjdk.java.net/browse/JDK-4420020 I'm guessing here that maybe it would be wrong to use an already existing lock file if you don't have the rights to write to its directory - and that using CREATE_NEW ensures that you have all necessary access rights all along the path. I don't think DELETE_ON_CLOSE is suitable here as that work is for transient work files which isn't the case here. Instead it could use deleteOnExit to have some chance of removing it on a graceful exit. Right - I suggested a patch in another mail where I just use that. BTW: Do you know why locks is Map? Would a Set do? It certainly looks as if we could use a simple HashSet here. Thanks Alan! -- daniel -Alan.
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 WeakReferenceFileHandler 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));
ReferenceQueueFileHandler q = new ReferenceQueue();
for (int i=0; i100; i++) {
WeakReferenceFileHandler h = new WeakReference(
new FileHandler(./test_%u.log, 1, 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
RE: Zombie FileHandler locks can exhaust all available log file locks.
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.
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.fu...@oracle.com
To: jason_mehr...@hotmail.com; core-libs-dev@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 WeakReferenceFileHandler 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));
ReferenceQueueFileHandler q = new ReferenceQueue();
for (int i=0; i100; i++) {
WeakReferenceFileHandler h = new WeakReference(
new FileHandler(./test_%u.log, 1, 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
Re: Zombie FileHandler locks can exhaust all available log file locks.
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.fu...@oracle.com
To: jason_mehr...@hotmail.com; core-libs-dev@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 WeakReferenceFileHandler 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));
ReferenceQueueFileHandler q = new ReferenceQueue();
for (int i=0; i100; i++) {
WeakReferenceFileHandler h = new WeakReference(
new FileHandler(./test_%u.log, 1, 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
Re: Zombie FileHandler locks can exhaust all available log file locks.
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.fu...@oracle.com
To: jason_mehr...@hotmail.com; core-libs-dev@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
Re: Zombie FileHandler locks can exhaust all available log file locks.
On 23/06/2014 10:48, Daniel Fuchs wrote: : 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 ;-) The logging use of FileLock is a bit unusual but looking at it now then I don't see the reason why it needs to use CREATE_NEW. I don't think DELETE_ON_CLOSE is suitable here as that work is for transient work files which isn't the case here. Instead it could use deleteOnExit to have some chance of removing it on a graceful exit. BTW: Do you know why locks is Map? Would a Set do? -Alan.
Re: Zombie FileHandler locks can exhaust all available log file locks.
On 6/23/14 4:53 PM, Alan Bateman wrote: On 23/06/2014 10:48, Daniel Fuchs wrote: : 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 ;-) The logging use of FileLock is a bit unusual but looking at it now then I don't see the reason why it needs to use CREATE_NEW. OK - thanks - in the discussion that ended up in the patch where CREATE_NEW was introduced Jason (I think it was Jason) pointed at https://bugs.openjdk.java.net/browse/JDK-4420020 I'm guessing here that maybe it would be wrong to use an already existing lock file if you don't have the rights to write to its directory - and that using CREATE_NEW ensures that you have all necessary access rights all along the path. I don't think DELETE_ON_CLOSE is suitable here as that work is for transient work files which isn't the case here. Instead it could use deleteOnExit to have some chance of removing it on a graceful exit. Right - I suggested a patch in another mail where I just use that. BTW: Do you know why locks is Map? Would a Set do? It certainly looks as if we could use a simple HashSet here. Thanks Alan! -- daniel -Alan.
