Hi Prasanna,
First suggestion - move to latest Java 8. G1 saw a lot of
improvements in 8, and 7 is EOL of course.
Humongous allocations require contiguous regions to satisfy the
allocation, and are done directly out of old gen. You're reserving
40% of heap to handle overflow(G1ReservePercent) - why? I believe that
reserve is only for mitigating to-space exhaustion, which is during
evacuation only - they won't be available for humongous allocations
(someone can correct me if that's wrong).
Heap expansion fails because you're already at the limit given 40% is
reserved.
Again, I think you'll get more help here if you move to one of the
latest Java 8 releases.
On Friday, October 7, 2016, Gopal, Prasanna CWK
<prasanna.go...@blackrock.com
<javascript:_e(%7B%7D,'cvml','prasanna.go...@blackrock.com');>> wrote:
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
<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
<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
<http://www.blackrock.com/corporate/en-us/about-us/contacts-locations>.
© 2016 BlackRock, Inc. All rights reserved.
--
Sent from my phone
_______________________________________________
hotspot-gc-use mailing list
hotspot-gc-use@openjdk.java.net
http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
