race condition in GC logs

[Bengt Rutisson]

Hi Ramki,

On 2015-08-27 04:16, Srinivas Ramakrishna wrote:
> I've attached a webrev/patch to the ticket. Happy to offer it here for 
> code review if that's a better route.


Thanks for providing the patch! I just had a very quick look at it and I 
think it looks good.

I think you need to publish the webrev on cr.openjdk.java.net and send 
it out for review on this mailing list if we should be able to push it. 
I'm happy to help you if you need any assistance with publishing the 
webrev or so. Just let me know.

Thanks for doing this!
Bengt

>
> thanks!
> -- ramki
>
> On Tue, Aug 25, 2015 at 12:56 PM, Srinivas Ramakrishna 
> <ysr1729 at gmail.com <mailto:ysr1729 at gmail.com>> wrote:
>
>     -bcc/hotspot-dev
>     +cc/hotspot-gc-dev
>
>     I have a patch for JDK-8133818 (on JDK 8): as suggested here
>     earlier, besides splitting out Cleaners, it also reports JNI wk
>     refs by counting them on-the-fly much like for other Reference types.
>
>     I'll attach it to the ticket once my testing completes.
>
>     thanks.
>     -- ramki
>
>     On Wed, Aug 19, 2015 at 3:20 PM, Kirk Pepperdine
>     <kirk at kodewerk.com <mailto:kirk at kodewerk.com>> wrote:
>
>         Hi Bengt,
>
>         Thanks for filing. I really didn’t consider this a bug but it
>         seems reasonable to add clarity in the log.
>
>         — Kirk
>
>         > On Aug 18, 2015, at 8:39 AM, Bengt Rutisson
>         <bengt.rutisson at oracle.com <mailto:bengt.rutisson at oracle.com>>
>         wrote:
>         >
>         >
>         >
>         > On 2015-08-18 12:47, Bengt Rutisson wrote:
>         >>
>         >> Hi Kirk,
>         >>
>         >> On 2015-08-18 12:31, Kirk Pepperdine wrote:
>         >>> Hi all,
>         >>>
>         >>> I found this.. in a few logs. Before I started trolling
>         the source trying to sort out what the second
>         PhantomReferences count was, I pinged Charlie and asked him.
>         He suggested it was a (concurrency??) bug witnessed only once
>         by someone else. I’ve now seen it in several logs where the
>         numbers reported are different. Sorry for being lazy for not
>         trolling the code before asking but is this a bug?
>         >>
>         >> The second ref count is for cleaner references. They used
>         to be treated the same way as phantom references, but a recent
>         improvement was to separate the handling of the cleaners to
>         after all phantom references have been handled. So, the first
>         count is the "real" phantom references and the second count is
>         the cleaner references.
>         >>
>         >> It's confusing logging, I agree.
>         >>
>         >> This came in with this fix:
>         >> http://hg.openjdk.java.net/jdk9/jdk9/hotspot/rev/2194fdf3fbd9
>         >>
>         >> since this adds one more call to
>         preclean_discovered_reflist(), which is the method that prints
>         the refs count.
>         >
>         > Thomas was nice and created a bug report for this :)
>         >
>         > Additional number of processed references printed with
>         -XX:+PrintReferenceGC after JDK-8047125
>         > https://bugs.openjdk.java.net/browse/JDK-8133818
>         >
>         > Bengt
>         >
>         >>
>         >> Thanks,
>         >> Bengt
>         >>
>         >>>
>         >>> Regards,
>         >>> Kirk
>         >>>
>         >>> Java HotSpot(TM) 64-Bit Server VM (25.51-b03) for
>         linux-amd64 JRE (1.8.0_51-b16), built on Jun  8 2015 19:28:07
>         by "java_re" with gcc 4.3.0 20080428 (Red Hat 4.3.0-8)
>         >>> Memory: 4k page, physical 9570132k(9340292k free), swap
>         4095996k(4095996k free)
>         >>> CommandLine flags: -XX:+AggressiveOpts
>         -XX:G1HeapRegionSize=16777216 -XX:InitialHeapSize=3221225472
>         -XX:InitiatingHeapOccupancyPercent=75 -XX:+ManagementServer
>         -XX:MaxGCPauseMillis=250 -XX:MaxHeapSize=3221225472
>         -XX:+ParallelRefProcEnabled -XX:+PerfDisableSharedMem
>         -XX:+PrintAdaptiveSizePolicy -XX:+PrintGC
>         -XX:+PrintGCApplicationStoppedTime -XX:+PrintGCDateStamps
>         -XX:+PrintGCDetails -XX:+PrintGCTimeStamps
>         -XX:+PrintReferenceGC -XX:+PrintTenuringDistribution
>         -XX:+UseCompressedClassPointers -XX:+UseCompressedOops
>         -XX:+UseG1GC -XX:+UseLargePages
>         >>>  0.198: [G1Ergonomics (Heap Sizing) expand the heap,
>         requested expansion amount: 3221225472 bytes, attempted
>         expansion amount: 3221225472 bytes]
>         >>> 2015-08-11T08:23:02.219+0200: 7.630: [GC pause (G1
>         Evacuation Pause) (young)
>         >>> Desired survivor size 16777216 bytes, new threshold 15
>         (max 15)
>         >>>  7.631: [G1Ergonomics (CSet Construction) start choosing
>         CSet, _pending_cards: 0, predicted base time: 10.00 ms,
>         remaining time: 240.00 ms, target pause time: 250.00 ms]
>         >>>  7.631: [G1Ergonomics (CSet Construction) add young
>         regions to CSet, eden: 9 regions, survivors: 0 regions,
>         predicted young region time: 3626.58 ms]
>         >>>  7.631: [G1Ergonomics (CSet Construction) finish choosing
>         CSet, eden: 9 regions, survivors: 0 regions, old: 0 regions,
>         predicted pause time: 3636.58 ms, target pause time: 250.00 ms]
>         >>> 7.642: [SoftReference, 0 refs, 0.0006965 secs]7.643:
>         [WeakReference, 40 refs, 0.0003039 secs]7.643:
>         [FinalReference, 3477 refs, 0.0036191 secs]7.647:
>         [PhantomReference, 0 refs, 0 refs, 0.0006649 secs]7.647: [JNI
>         Weak Reference, 0.0000119 secs], 0.0173298 secs]
>         >>
>         >
>
>
>

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://mail.openjdk.org/pipermail/hotspot-gc-dev/attachments/20150831/f7470b89/attachment.htm>