G1-GC - Full GC [humongous allocation request failed]

Vitaly Davidovich vitalyd at gmail.com
Fri Oct 7 12:48:49 UTC 2016


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.gopal at blackrock.com
<javascript:_e(%7B%7D,'cvml','prasanna.gopal at 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/corpo
> rate/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.
>
>

-- 
Sent from my phone
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mail.openjdk.java.net/pipermail/hotspot-gc-use/attachments/20161007/43f61f19/attachment-0001.html>


More information about the hotspot-gc-use mailing list