Review quest for JDK-7067973: test/java/lang/management/MemoryMXBean/CollectionUsageThreshold.java hanging intermittently

Tue Dec 3 19:01:33 PST 2013

Hi Mandy,

Thanks for investigation, I agree with you that the -Xmx2m looks tricky, 
I have updated the webrev below based on your suggestion. Can you please 
review it?
http://cr.openjdk.java.net/~ewang/JDK-7067973/webrev.01/ 
<http://cr.openjdk.java.net/%7Eewang/JDK-7067973/webrev.01/>

If serviceability team also agree with it, I'll file another bug for the 
combination of "-XX:+UseG1GC and -XX:+ExplicitGCInvokesConcurrent"

Thanks,
Eric
On 2013/12/4 5:19, Mandy Chung wrote:
> Hi Eric,
>
> What I tried to point out is that I'm not seeing the Full GC happened 
> when running with
> -XX:+UseG1GC -XX:+ExplicitGCInvokesConcurrent
> The test hangs if I launch the test with the java launcher on windows 
> jdk8-b117.
> $ java -XX:+PrintGCDetails -Xmx2m -XX:+UseG1GC -XX:+ExplicitGCInvokesConcurrent CollectionUsageThresho
> ld
> Collection usage threshold of G1 Old Gen set to 10
> Calling System.gc()
> [GC pause (System.gc()) (young) (initial-mark), 0.0017152 secs]
>     [Parallel Time: 1.4 ms, GC Workers: 4]
>        [GC Worker Start (ms): Min: 97.9, Avg: 97.9, Max: 97.9, Diff: 0.0]
>        [Ext Root Scanning (ms): Min: 0.1, Avg: 0.7, Max: 1.2, Diff: 1.1, Sum: 2.7]
>        [Code Root Marking (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
>        [Update RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
>           [Processed Buffers: Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0]
>        [Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
>        [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
>        [Object Copy (ms): Min: 0.0, Avg: 0.4, Max: 0.8, Diff: 0.8, Sum: 1.7]
>        [Termination (ms): Min: 0.0, Avg: 0.2, Max: 0.4, Diff: 0.4, Sum: 1.0]
>        [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
>        [GC Worker Total (ms): Min: 1.3, Avg: 1.3, Max: 1.4, Diff: 0.0, Sum: 5.4]
>        [GC Worker End (ms): Min: 99.2, Avg: 99.2, Max: 99.2, Diff: 0.0]
>     [Code Root Fixup: 0.0 ms]
>     [Code Root Migration: 0.0 ms]
>     [Clear CT: 0.0 ms]
>     [Other: 0.3 ms]
>        [Choose CSet: 0.0 ms]
>        [Ref Proc: 0.2 ms]
>        [Ref Enq: 0.0 ms]
>        [Free CSet: 0.0 ms]
>     [Eden: 1024.0K(1024.0K)->0.0B(1024.0K) Survivors: 0.0B->1024.0K Heap: 991.9K(2048.0K)->782.7K(204
> 8.0K)]
>   [Times: user=0.00 sys=0.00, real=0.00 secs]
> [GC concurrent-root-region-scan-start]
> [GC concurrent-root-region-scan-end, 0.0004602 secs]
> [GC concurrent-mark-start]
> [GC concurrent-mark-end, 0.0000895 secs]
> [GC remark [GC ref-proc, 0.0001248 secs], 0.0008436 secs]
>   [Times: user=0.00 sys=0.00, real=0.00 secs]
> [GC cleanup 803K->803K(2048K), 0.0001712 secs]
>   [Times: user=0.00 sys=0.00, real=0.00 secs]
>
> If I ran the test with jtreg, it passes but if you looked at the log, 
> you will find that the Full GC happens when it fails to allocate an 
> object (this explains why you need to set -Xmx2m to make the test passes).
>
> [Full GC (Allocation Failure)  894K->484K(2048K), 0.0020662 secs]
> [Full GC (Allocation Failure)  863K->525K(2048K), 0.0029365 secs]
> [Full GC (Allocation Failure)  842K->525K(2048K), 0.0023650 secs]
>
> There is some mystery with -XX:+UseG1GC and 
> -XX:+ExplicitGCInvokesConcurrent that we will need to consult with the 
> GC team.  -Xmx2m would mask the problem.  I suggest to take out line 
> 38 and 39 and file a bug for further investigation.
>
> If the serviceability team doesn't object this patch, I can sponsor it 
> and push it for you.
>
> Mandy
>
> On 11/27/2013 9:21 PM, Eric Wang wrote:
>> Hi Mandy,
>>
>> Yes, I have tested and all settings are passed, as you mentioned the 
>> test hangs with -XX:+UseG1GC -XX:+ExplicitGCInvokesConcurrent and 
>> default heap size as no GC happens on Old Gen. That is why to add 
>> -Xmx2m and big object to make sure GC happens.
>>
>> I didn't realized the -Xconcgc is same as -XX:+UseConcMarkSweepGC, i 
>> have updated the webrev:
>> http://cr.openjdk.java.net/~ewang/JDK-7067973/webrev.00/ 
>> <http://cr.openjdk.java.net/%7Eewang/JDK-7067973/webrev.00/>
>>
>> Thanks,
>> Eric
>> On 2013/11/27 10:17, Mandy Chung wrote:
>>> Hi Eric,
>>>
>>> I'll defer this to the serviceability team to sponsor it and also 
>>> get one more review.
>>>
>>> I don't think you need all 7 @runs.  -Xconcgc is equivalent to 
>>> setting -XX:+UseConcMarkSweepGC. For G1 and CMS, you should use 
>>> -XX:+ExplicitGCInvokesConcurrent so that System.gc will force a GC 
>>> in foreground that you can count the GC reliably. The test wants to 
>>> get notified for each System.gc and if there is any GC caused by 
>>> allocation failure, the test would fail due to the unexpected GC 
>>> count.  It seems that you may run into this issue setting -Xmx2m.
>>>
>>> Have you got the test passed in all settings?   I'm seeing that the 
>>> test hangs with -XX:+UseG1GC -XX:+ExplicitGCInvokesConcurrent 
>>> without -Xmx2m.  Looks like there is no GC in the old gen - I'm not 
>>> familiar with G1 if it allocates the big object in the old gen.  
>>> Jarolsav - can you help Eric diagnose this issue?  I recalled you 
>>> ran into something like that before - maybe Staffan?
>>>
>>> thanks
>>> Mandy
>>>
>>> On 11/25/2013 8:53 PM, Eric Wang wrote:
>>>> Hi Mandy,
>>>>
>>>> 1. for L34-40, executing tests with 7 settings is trying to cover 
>>>> more cases (normal cases and special cases), especially last 3 
>>>> settings, as found that the test hung if using vm option 
>>>> "-XX:+ExplicitGCInvokesConcurrent" with one of 3 options 
>>>> -XX:+UseG1GC, -XX:+UseConcMarkSweepGC or -Xconcgc
>>>>
>>>> 2. for L61, that is right, the test has been updated. please review.
>>>> http://cr.openjdk.java.net/~ewang/JDK-7067973/webrev.00/ 
>>>> <http://cr.openjdk.java.net/%7Eewang/JDK-7067973/webrev.00/>
>>>>
>>>> Thanks,
>>>> Eric
>>>> On 2013/11/26 8:37, Mandy Chung wrote:
>>>>> Hi Eric,
>>>>>
>>>>> On 11/24/2013 7:41 PM, Eric Wang wrote:
>>>>>> Hi Mandy & All,
>>>>>>
>>>>>> Sorry for late!
>>>>>> The webrev below is just finished based on the comments from 
>>>>>> peers, please help to review.
>>>>>> http://cr.openjdk.java.net/~ewang/JDK-7067973/webrev.00/ 
>>>>>> <http://cr.openjdk.java.net/%7Eewang/JDK-7067973/webrev.00/>
>>>>>>
>>>>>
>>>>> Thanks for the patch that looks okay.  Some comments:
>>>>>
>>>>> L34-40: can you explain why you want to run all 7 settings?  I 
>>>>> would expect one for each collector.
>>>>> L61: I think the static checker variable is meant to be a local 
>>>>> variable (and looks like "pools" and "managers" don't need to be 
>>>>> static variable).
>>>>>
>>>>> Mandy
>>>>>
>>>>>> Thanks,
>>>>>> Eric
>>>>>> On 2013/11/15 10:55, Mandy Chung wrote:
>>>>>>> Hi Eric,
>>>>>>>
>>>>>>> On 11/14/2013 6:16 PM, Eric Wang wrote:
>>>>>>>> Hi Everyone,
>>>>>>>>
>>>>>>>> I'm working on the bug 
>>>>>>>> https://bugs.openjdk.java.net/browse/JDK-7067973.
>>>>>>>>
>>>>>>>> It is a test bug as the test doesn't guarantee memory allocated 
>>>>>>>> from the Old Gen, if the used memory is zero and doesn't cross 
>>>>>>>> the threshold, no notification is sent, so both the main thread 
>>>>>>>> and Checker thread are blocked to wait for the GC notification.
>>>>>>>>
>>>>>>>> so the suggested fix is similar as the fix 
>>>>>>>> ResetPeakMemoryUsage.java 
>>>>>>>> <http://hg.openjdk.java.net/jdk8/tl/jdk/rev/a0896634ab46> to 
>>>>>>>> create big object to make sure the old gen usage crosses the 
>>>>>>>> threshold and run test with different GC vmoptions.
>>>>>>>
>>>>>>> What are you looking for specifically?  I have provided the 
>>>>>>> above information.  I need to see the webrev to provide further 
>>>>>>> feedback.
>>>>>>>
>>>>>>> Mandy
>>>>>>
>>>>>
>>>>
>>>
>>
>

-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://mail.openjdk.java.net/pipermail/serviceability-dev/attachments/20131204/af188817/attachment-0001.html 