Logging FileHandler: static locks and hardcoded maximum number

[Behrooz Nobakht]

Hi,

The following describes my situation:

1. I have a long running JVM process (p1).
2. The long running process instantiate another JVM process (p2).
3. On every instantiation of p2, p1 prepares an instance of FileHandler for
p2
 (used through a redirect thread of logging) as:
new FileHandler("/path/to/log/app.stdouterr.%u.%g.log"
4. p2 is short-lived and on its JVM exit, it closes FileHandler
5. p1 can start p2 an arbitrary number of times

Our observation started with the following exception:

Caused by: java.io.IOException: Couldn't get lock for
/path/to/log/app.stdouterr.%u.%g.log
        at java.util.logging.FileHandler.openFiles(FileHandler.java:422)
        at java.util.logging.FileHandler.<init>(FileHandler.java:318)
        (...)

Then, I tried to understand why, and I used the following on the running
server:

$ lsof -uappuser | grep -E "\/path\/to\/log"

It's interesting that I see 100 files as ".lck" in generation 0
as the following shows (the results are trimmed):

===
java    14515 appuser  182wW  REG              252,0        0 109052248
/path/to/log/app.stdouterr.0.0.log.lck (deleted)
java    14515 appuser  183wW  REG              252,0        0  92274968
/path/to/log/app.stdouterr.1.0.log.lck (deleted)
java    14515 appuser  184wW  REG              252,0        0 125829396
/path/to/log/app.stdouterr.2.0.log.lck (deleted)
.
.
.
java    14515 appuser  206wW  REG              252,0        0 109052253
/path/to/log/app.stdouterr.98.0.log.lck (deleted)
java    14515 appuser  207wW  REG              252,0        0 125829401
/path/to/log/app.stdouterr.99.0.log.lck (deleted)
java    14515 appuser  168wW  REG              252,0        0   8388893
/path/to/log/app.stdouterr.100.0.log.lck
java    14515 appuser  176w   REG              252,0      367   8388894
/path/to/log/app.stdouterr.100.0.log
===

Please note that except the last two, all the *.lck files are marked as
(deleted),
which means they are not available in the file system (confirmed)
but a process has an open handle on the path.

Simply, based on (3) and (4), when p1 would reach the 100th time it wants
to
instantiate p2, we start to observe the exception.

As far as I can see the source for FileHandler:

- a static field is used to hold the lock files
- in our setup, the JVM in p1 initiates the above static field as part of
the first time preparing p2
- the (deleted) in the above, means that FileHandler#close has been called
with success.

Questions/Suggestions:

(a) The above (deleted) handles would not be released until p1 JVM goes
down, correct?
(b) If (a) is correct, is there way to ask JVM to do so on FileHandler? If
yes, where should I look into?
(c) If (b) is no, is there a chance FileHandler could introduce a new API
method to be able to perform such clean-up without having to exit p1 JVM?

Thanks,
Behrooz