G1-GC - Full GC [humongous allocation request failed]
Gopal, Prasanna CWK
prasanna.gopal at blackrock.com
Fri Oct 7 12:00:04 UTC 2016
Hi All
We have one of our application with the following settings
JVM : jdk_7u40_x64 ( we are in process of migrating to latest Jdk 7 family )
-XX:MaxPermSize=512m
-XX:+UseG1GC
-XX:G1ReservePercent=40
-XX:ConcGCThreads=14
-XX:+PrintGCDateStamps
-XX:+PrintTenuringDistribution
-XX:+PrintGCApplicationConcurrentTime
-XX:+PrintGCApplicationStoppedTime
-XX:+PrintAdaptiveSizePolicy
-XX:+PrintHeapAtGC
-XX:+PrintReferenceGC
-Xmx5120M
-Xms5120M
>From our GC logs , we can see our application is going Full GC due to humongous allocation failure. But from the logs we can see
GC logs
=======
2016-10-07T02:37:14.978-0400: 71150.009: Total time for which application threads were stopped: 0.0137870 seconds
71150.399: [G1Ergonomics (Heap Sizing) attempt heap expansion, reason: humongous allocation request failed, allocation request: 75497488 bytes]
71150.399: [G1Ergonomics (Heap Sizing) expand the heap, requested expansion amount: 75497472 bytes, attempted expansion amount: 75497472 bytes]
71150.399: [G1Ergonomics (Heap Sizing) did not expand the heap, reason: heap expansion operation failed]
2016-10-07T02:37:15.367-0400: 71150.399: Application time: 0.3898050 seconds
71150.401: [G1Ergonomics (Heap Sizing) attempt heap expansion, reason: humongous allocation request failed, allocation request: 75497488 bytes]
71150.401: [G1Ergonomics (Heap Sizing) expand the heap, requested expansion amount: 75497472 bytes, attempted expansion amount: 75497472 bytes]
71150.401: [G1Ergonomics (Heap Sizing) did not expand the heap, reason: heap expansion operation failed]
{Heap before GC invocations=55428 (full 4):
garbage-first heap total 5242880K, used 1900903K [0x00000006a0000000, 0x00000007e0000000, 0x00000007e0000000)
region size 2048K, 197 young (403456K), 14 survivors (28672K)
compacting perm gen total 96256K, used 94313K [0x00000007e0000000, 0x00000007e5e00000, 0x0000000800000000)
the space 96256K, 97% used [0x00000007e0000000, 0x00000007e5c1a700, 0x00000007e5c1a800, 0x00000007e5e00000)
No shared spaces configured.
2016-10-07T02:37:15.369-0400: 71150.401: [GC pause (young)
Desired survivor size 108003328 bytes, new threshold 15 (max 15)
- age 1: 2362400 bytes, 2362400 total
- age 2: 393128 bytes, 2755528 total
- age 3: 1086824 bytes, 3842352 total
- age 4: 1086528 bytes, 4928880 total
- age 5: 1075480 bytes, 6004360 total
- age 6: 1126736 bytes, 7131096 total
- age 7: 1153072 bytes, 8284168 total
- age 8: 1145832 bytes, 9430000 total
- age 9: 1217904 bytes, 10647904 total
- age 10: 1188384 bytes, 11836288 total
- age 11: 1212456 bytes, 13048744 total
- age 12: 1263960 bytes, 14312704 total
- age 13: 4816 bytes, 14317520 total
- age 14: 88952 bytes, 14406472 total
- age 15: 7408 bytes, 14413880 total
71150.401: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 149101, predicted base time: 16.35 ms, remaining time: 183.65 ms, target pause time: 200.00 ms]
71150.401: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 183 regions, survivors: 14 regions, predicted young region time: 3.45 ms]
71150.401: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 183 regions, survivors: 14 regions, old: 0 regions, predicted pause time: 19.80 ms, target pause time: 200.00 ms]
2016-10-07T02:37:15.410-0400: 71150.442: [SoftReference, 0 refs, 0.0000460 secs]2016-10-07T02:37:15.410-0400: 71150.442: [WeakReference, 1 refs, 0.0000050 secs]2016-10-07T02:37:15.410-0400: 71150.442: [FinalReference, 4 refs, 0.0000210 secs]2016-10-07T02:37:15.410-0400: 71150.442: [PhantomReference, 0 refs, 0.0000040 secs]2016-10-07T02:37:15.410-0400: 71150.442: [JNI Weak Reference, 0.0000050 secs], 0.0428440 secs]
[Parallel Time: 40.0 ms, GC Workers: 16]
[GC Worker Start (ms): Min: 71150401.6, Avg: 71150401.8, Max: 71150401.9, Diff: 0.4]
[Ext Root Scanning (ms): Min: 3.1, Avg: 3.9, Max: 8.4, Diff: 5.3, Sum: 62.1]
[Update RS (ms): Min: 14.8, Avg: 19.0, Max: 19.8, Diff: 5.0, Sum: 304.3]
[Processed Buffers: Min: 21, Avg: 37.6, Max: 86, Diff: 65, Sum: 601]
[Scan RS (ms): Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.0, Sum: 0.9]
[Object Copy (ms): Min: 16.5, Avg: 16.6, Max: 16.8, Diff: 0.3, Sum: 266.3]
[Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
[GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.7]
[GC Worker Total (ms): Min: 39.5, Avg: 39.6, Max: 39.9, Diff: 0.4, Sum: 634.4]
[GC Worker End (ms): Min: 71150441.4, Avg: 71150441.4, Max: 71150441.5, Diff: 0.1]
[Code Root Fixup: 0.0 ms]
[Clear CT: 0.2 ms]
[Other: 2.7 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 0.3 ms]
[Ref Enq: 0.0 ms]
[Free CSet: 1.3 ms]
[Eden: 366.0M(1616.0M)->0.0B(1384.0M) Survivors: 28.0M->104.0M Heap: 1856.6M(5120.0M)->1568.8M(5120.0M)]
Heap after GC invocations=55429 (full 4):
garbage-first heap total 5242880K, used 1606459K [0x00000006a0000000, 0x00000007e0000000, 0x00000007e0000000)
region size 2048K, 52 young (106496K), 52 survivors (106496K)
compacting perm gen total 96256K, used 94313K [0x00000007e0000000, 0x00000007e5e00000, 0x0000000800000000)
the space 96256K, 97% used [0x00000007e0000000, 0x00000007e5c1a700, 0x00000007e5c1a800, 0x00000007e5e00000)
No shared spaces configured.
}
[Times: user=0.64 sys=0.00, real=0.04 secs]
71150.444: [G1Ergonomics (Heap Sizing) attempt heap expansion, reason: humongous allocation request failed, allocation request: 75497488 bytes]
71150.444: [G1Ergonomics (Heap Sizing) expand the heap, requested expansion amount: 69206016 bytes, attempted expansion amount: 69206016 bytes]
71150.444: [G1Ergonomics (Heap Sizing) did not expand the heap, reason: heap expansion operation failed]
2016-10-07T02:37:15.412-0400: 71150.444: Total time for which application threads were stopped: 0.0448480 seconds
2016-10-07T02:37:15.412-0400: 71150.444: Application time: 0.0000500 seconds
71150.445: [G1Ergonomics (Heap Sizing) attempt heap expansion, reason: humongous allocation request failed, allocation request: 75497488 bytes]
71150.445: [G1Ergonomics (Heap Sizing) expand the heap, requested expansion amount: 69206016 bytes, attempted expansion amount: 69206016 bytes]
71150.445: [G1Ergonomics (Heap Sizing) did not expand the heap, reason: heap expansion operation failed]
71150.445: [G1Ergonomics (Heap Sizing) attempt heap expansion, reason: allocation request failed, allocation request: 75497488 bytes]
71150.445: [G1Ergonomics (Heap Sizing) expand the heap, requested expansion amount: 75497488 bytes, attempted expansion amount: 77594624 bytes]
71150.445: [G1Ergonomics (Heap Sizing) did not expand the heap, reason: heap expansion operation failed]
{Heap before GC invocations=55429 (full 4):
garbage-first heap total 5242880K, used 1606459K [0x00000006a0000000, 0x00000007e0000000, 0x00000007e0000000)
region size 2048K, 53 young (108544K), 52 survivors (106496K)
compacting perm gen total 96256K, used 94313K [0x00000007e0000000, 0x00000007e5e00000, 0x0000000800000000)
the space 96256K, 97% used [0x00000007e0000000, 0x00000007e5c1a700, 0x00000007e5c1a800, 0x00000007e5e00000)
No shared spaces configured.
2016-10-07T02:37:15.414-0400: 71150.445: [Full GC2016-10-07T02:37:16.337-0400: 71151.368: [SoftReference, 86 refs, 0.0000720 secs]2016-10-07T02:37:16.337-0400: 71151.368: [WeakReference, 1760 refs, 0.0002980 secs]2016-10-07T02:37:16.337-0400: 71151.369: [FinalReference, 1201 refs, 0.0002080 secs]2016-10-07T02:37:16.337-0400: 71151.369: [PhantomReference, 0 refs, 0.0000030 secs]2016-10-07T02:37:16.337-0400: 71151.369: [JNI Weak Reference, 0.0000080 secs] 1568M->915M(5120M), 2.6880870 secs]
60 refs, 0.0002980 secs]2016-10-07T02:37:16.337-0400: 71151.369: [FinalReference, 1201 refs, 0.0002080 secs]2016-10-07T02:37:16.337-0400: 71151.369: [PhantomReference, 0 refs, 0.0000030 secs]2016-10-07T02:37:16.337-0400: 71151.369: [JNI Weak Reference, 0.0000080 secs] 1568M->915M(5120M), 2.6880870 secs]
[Eden: 2048.0K(1384.0M)->0.0B(2112.0M) Survivors: 104.0M->0.0B Heap: 1568.8M(5120.0M)->915.2M(5120.0M)]
Heap after GC invocations=55430 (full 5):
garbage-first heap total 5242880K, used 937168K [0x00000006a0000000, 0x00000007e0000000, 0x00000007e0000000)
region size 2048K, 0 young (0K), 0 survivors (0K)
compacting perm gen total 96256K, used 94313K [0x00000007e0000000, 0x00000007e5e00000, 0x0000000800000000)
the space 96256K, 97% used [0x00000007e0000000, 0x00000007e5c1a700, 0x00000007e5c1a800, 0x00000007e5e00000)
No shared spaces configured.
Could you please help me in giving your views on the following queries
1) Humongus allocation request for 72 mb failed, from the logs we can also see we have free space of around 3 GB. Does this means , our application is encountering high amount of fragmentation ?.
2) Does tunning the gc params to make sure Mixed GC happens more , will help in resolving such Full GC’s ?
3) Is there –XX:Print* flag which can tell us how many old gen and humongous regions we have (other than looking at [G1 Ergonomics] output , which sometimes gives old gen region count) ?
Please do let me know , if you need any more information. Appreciate your help.
Thanks and Regards
Prasanna
This message may contain information that is confidential or privileged. If you are not the intended recipient, please advise the sender immediately and delete this message. See http://www.blackrock.com/corporate/en-us/compliance/email-disclaimers for further information. Please refer to http://www.blackrock.com/corporate/en-us/compliance/privacy-policy for more information about BlackRock’s Privacy Policy.
BlackRock Advisors (UK) Limited and BlackRock Investment Management (UK) Limited are authorised and regulated by the Financial Conduct Authority. Registered in England No. 796793 and No. 2020394 respectively. BlackRock Life Limited is authorised by the Prudential Regulation Authority and regulated by the Financial Conduct Authority and the Prudential Regulation Authority. Registered in England No. 2223202. Registered Offices: 12 Throgmorton Avenue, London EC2N 2DL. BlackRock International Limited is authorised and regulated by the Financial Conduct Authority and is a registered investment adviser with the Securities and Exchange Commission (SEC). Registered in Scotland No. SC160821. Registered Office: Exchange Place One, 1 Semple Street, Edinburgh EH3 8BL.
For a list of BlackRock's office addresses worldwide, see http://www.blackrock.com/corporate/en-us/about-us/contacts-locations.
© 2016 BlackRock, Inc. All rights reserved.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mail.openjdk.java.net/pipermail/hotspot-gc-use/attachments/20161007/0ab18661/attachment.html>
More information about the hotspot-gc-use
mailing list