race condition in GC logs

Kirk Pepperdine kirk at kodewerk.com
Tue Aug 18 17:31:26 UTC 2015

Hi Bengt,

Thanks for the information. I try to read the patches but I don’t get to them all. Indeed the log is confusing but nothing tooling can’t deal with.


> On Aug 18, 2015, at 6:47 AM, Bengt Rutisson <bengt.rutisson at oracle.com> 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.
> 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]

More information about the hotspot-dev mailing list