Logging FileHandler: static locks and hardcoded maximum number

Fri Feb 20 03:15:10 UTC 2015

Hi Daniel,

Starting to create a minimal reproduction case for the
observations and the discussion, I think I have been
able to pin point a bug in our application. Basically,
it is a corner case for *properly* closing the FileHandler
instance in the end of p2 process. I have a minimal example,
with which actually I can confirm that all 8u25, 8u31, and 8u40ea
are working as expected. In this minimal example, if the FileHandler#close
is not properly used, then the same observations exist in regards with p1
and p2. If it is of interest for you, I can upload the showcase somewhere
such as GitHub.

Thanks,
Behrooz

On Thu, Feb 19, 2015 at 5:18 PM, Daniel Fuchs <daniel.fuchs at oracle.com>
wrote:

> Hi,
>
> On 19/02/15 16:30, Behrooz Nobakht wrote:
>
>> I'd be very happy to introduce an issue. But,
>> I've always failed to be able to create an account on
>> https://bugs.openjdk.java.net/secure/Dashboard.jspa
>> so, for me, the starting point is where I should do this?!
>>
>
> If you are not an OpenJDK member then I guess you should
> use http://bugs.java.com/ - and at some point this issue will
> be transferred to https://bugs.openjdk.java.net/
> where it (hopefully) will come in my inbox :-)
>
> You might want to refer to this email thread in your issue
> description.
> http://mail.openjdk.java.net/pipermail/core-libs-dev/2015-
> February/031624.html
>
>
> best regards,
>
> -- daniel
>
>
>> On Thu, Feb 19, 2015 at 3:56 PM, Daniel Fuchs <daniel.fuchs at oracle.com
>> <mailto:daniel.fuchs at oracle.com>> wrote:
>>
>>     Thanks Behrooz.
>>
>>     Could you log an issue for this then?
>>     If you can attach a small reproducer it will be helpful.
>>
>>     There are a bunch of unit tests in the JDK that verify
>>     that FileHandler .lck files are correctly deleted - but
>>     these tests are all mono-process. I would like to make
>>     sure to chase down the real issue - so a small isolated
>>     reproducer would definitely help.
>>
>>     best regards,
>>
>>     -- daniel
>>
>>
>>     On 19/02/15 15:29, Behrooz Nobakht wrote:
>>
>>         Hi Daniel,
>>
>>         Thanks for referring to this ticket.
>>         Here is what I did.
>>
>>         My Java version:
>>
>>         java version "1.8.0_40-ea"
>>         Java(TM) SE Runtime Environment (build 1.8.0_40-ea-b21)
>>         Java HotSpot(TM) 64-Bit Server VM (build 25.40-b24, mixed mode)
>>
>>         So, to make this more observable.
>>         The p1 process invokes a command with p2: start and stop.
>>         So, with 50 pairs of start and stop, we should be able to see the
>>         problem again.
>>
>>         I ran a script that invokes start from p1, gets the status of
>>         p2, stops
>>         p2 and confirms its status again.
>>         Here's the output from run 49:
>>
>>         ===
>>         run 49
>>         Invoking Start
>>         RUNNING
>>         Invoking Stop
>>         STOPPED
>>         run 49 - Done
>>         run 50
>>         Invoking Start
>>         RUNNING
>>         Invoking Stop
>>         STOPPED
>>         run 50 - Done
>>         run 51
>>         Invoking Start
>>         RUNNING
>>         Invoking Stop
>>         RUNNING
>>         run 51 - Done
>>         run 52
>>         Invoking Start
>>         STOPPED
>>         Invoking Stop
>>         STOPPED
>>         run 52 - Done
>>         run 53
>>         Invoking Start
>>         STOPPED
>>         Invoking Stop
>>         STOPPED
>>         run 53 - Done
>>         run 54
>>         Invoking Start
>>         STOPPED
>>         Invoking Stop
>>         STOPPED
>>         run 54 - Done
>>         ===
>>
>>         As the above shows, starting run 51, the expected status is
>>         violated.
>>         And, here is what I get a lsof of the log directory on the
>>         application:
>>
>>         ===
>>         -rw-rw-r-- 1 appuser appuser    0 Feb 19 15:19
>>         app.stdouterr.100.0.log.lck
>>         -rw-rw-r-- 1 appuser appuser 3.0K Feb 19 15:19
>>         app.stdouterr.100.0.log
>>         -rw-rw-r-- 1 appuser appuser    0 Feb 19 15:16
>>         app.stdouterr.0.0.log.lck
>>         -rw-rw-r-- 1 appuser appuser  366 Feb 19 15:16
>> app.stdouterr.0.0.log
>>         ===
>>
>>         Thanks for your time on this,
>>         Behrooz
>>
>>
>>
>>
>>
>>         On Thu, Feb 19, 2015 at 3:01 PM, Daniel Fuchs
>>         <daniel.fuchs at oracle.com <mailto:daniel.fuchs at oracle.com>
>>         <mailto:daniel.fuchs at oracle.__com
>>         <mailto:daniel.fuchs at oracle.com>>> wrote:
>>
>>              Hi Behrooz,
>>
>>              On 19/02/15 13:46, Behrooz Nobakht wrote:
>>
>>                  The version of Java is irrelevant. We have tested our
>> setup
>>                  on Java 7 and Java 8 u25/31. We observe the same
>> exception.
>>
>>
>>              Ok - then the version is indeed relevant ;-)
>>
>>              What you are observing may be a symptom of
>>         https://bugs.openjdk.java.net/____browse/JDK-8048020
>>         <https://bugs.openjdk.java.net/__browse/JDK-8048020>
>>              <https://bugs.openjdk.java.__net/browse/JDK-8048020
>>         <https://bugs.openjdk.java.net/browse/JDK-8048020>>
>>              which was fixed in 8u40 build 6.
>>
>>              If you would like to verify that this bug is indeed
>>              what is causing your issue, you may want to try out
>>              your setup with an early access build of 8u40, and
>>              see if the problem disappears.
>>
>>              Early access of 8u40 may be downloaded from there:
>>         https://jdk8.java.net/____download.html
>>         <https://jdk8.java.net/__download.html>
>>              <https://jdk8.java.net/__download.html
>>         <https://jdk8.java.net/download.html>>
>>
>>
>>              best regards,
>>
>>              -- daniel
>>
>>
>>
>>
>>         --
>>         -- Behrooz Nobakht
>>
>>
>>
>>
>>
>> --
>> -- Behrooz Nobakht
>>
>
>

-- 
-- Behrooz Nobakht