Logging FileHandler: static locks and hardcoded maximum number
Daniel Fuchs
daniel.fuchs at oracle.com
Fri Feb 20 09:22:54 UTC 2015
On 2/20/15 4:15 AM, Behrooz Nobakht wrote:
> 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.
Hi Behrooz,
I'm glad you were able to pinpoint the issue - and relieved it
wasn't in the JDK after all :-)
> 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.
That makes sense - it's what I would have expected. But since file locking
implementation is essentially platform dependent there was always the
risk that something unusual had happened.
> If it is of interest for you, I can upload the showcase somewhere such
> as GitHub.
Don't bother with that. Thanks for working on this test case and finding
out the actual issue!
best regards,
-- daniel
>
> Thanks,
> Behrooz
>
>
> On Thu, Feb 19, 2015 at 5:18 PM, Daniel Fuchs <daniel.fuchs at oracle.com
> <mailto: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>
> <mailto: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>>
> <mailto:daniel.fuchs at oracle.
> <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
More information about the core-libs-dev
mailing list