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/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
_______________________________________________
hotspot-gc-use mailing list
hotspot-gc-use@openjdk.java.net
http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
