<html xmlns:v="urn:schemas-microsoft-com:vml" xmlns:o="urn:schemas-microsoft-com:office:office" xmlns:w="urn:schemas-microsoft-com:office:word" xmlns:m="http://schemas.microsoft.com/office/2004/12/omml" xmlns="http://www.w3.org/TR/REC-html40">
<head>
<meta http-equiv="Content-Type" content="text/html; charset=us-ascii">
<meta name="Generator" content="Microsoft Word 15 (filtered medium)">
<style><!--
/* Font Definitions */
@font-face
{font-family:SimSun;
panose-1:2 1 6 0 3 1 1 1 1 1;}
@font-face
{font-family:"Cambria Math";
panose-1:2 4 5 3 5 4 6 3 2 4;}
@font-face
{font-family:Calibri;
panose-1:2 15 5 2 2 2 4 3 2 4;}
@font-face
{font-family:"\@SimSun";
panose-1:2 1 6 0 3 1 1 1 1 1;}
@font-face
{font-family:"Lucida Console";
panose-1:2 11 6 9 4 5 4 2 2 4;}
/* Style Definitions */
p.MsoNormal, li.MsoNormal, div.MsoNormal
{margin:0in;
margin-bottom:.0001pt;
font-size:11.0pt;
font-family:"Calibri",sans-serif;}
a:link, span.MsoHyperlink
{mso-style-priority:99;
color:#0563C1;
text-decoration:underline;}
a:visited, span.MsoHyperlinkFollowed
{mso-style-priority:99;
color:#954F72;
text-decoration:underline;}
span.EmailStyle17
{mso-style-type:personal-compose;
font-family:"Calibri",sans-serif;
color:windowtext;}
.MsoChpDefault
{mso-style-type:export-only;
font-family:"Calibri",sans-serif;}
@page WordSection1
{size:8.5in 11.0in;
margin:1.0in 1.0in 1.0in 1.0in;}
div.WordSection1
{page:WordSection1;}
--></style><!--[if gte mso 9]><xml>
<o:shapedefaults v:ext="edit" spidmax="1026" />
</xml><![endif]--><!--[if gte mso 9]><xml>
<o:shapelayout v:ext="edit">
<o:idmap v:ext="edit" data="1" />
</o:shapelayout></xml><![endif]-->
</head>
<body lang="EN-US" link="#0563C1" vlink="#954F72">
<div class="WordSection1">
<p class="MsoNormal">Hi,<o:p></o:p></p>
<p class="MsoNormal"><o:p> </o:p></p>
<p class="MsoNormal">I have a GC log from 8 nodes cluster running 90% write and 10% Read YCSB to test HBase performance.
<o:p></o:p></p>
<p class="MsoNormal">JVM version: Java HotSpot(TM) 64-Bit Server VM (25.40-b25) for linux-amd64 JRE (1.8.0_40-b25), built on Feb 10 2015 21:29:53 by "java_re" with gcc 4.3.0 20080428 (Red Hat 4.3.0-8)<o:p></o:p></p>
<p class="MsoNormal"><o:p> </o:p></p>
<p class="MsoNormal">Command Line flags: -XX:+UseG1GC –Xms80g –Xmx80g -XX:+AlwaysPreTouch -XX:G1HeapWastePercent=20 -XX:MaxGCPauseMillis=100 -XX:ParallelGCThreads=48 -XX:ConcGCThreads=32 -XX:+ParallelRefProcEnabled
<o:p></o:p></p>
<p class="MsoNormal"><o:p> </o:p></p>
<p class="MsoNormal">The run had 2 Full GCs with GC pause 27 seconds and 23 seconds, which is pretty bad for latency sensitive HBase.<o:p></o:p></p>
<p class="MsoNormal">I looked at the log and found: before both Full GCs, there were Mixed GC did some sort of size promotion, regardless heap usage was already over 90%.<o:p></o:p></p>
<p class="MsoNormal">See attached one of the case below, this Mixed GC pause only took 0.57 seconds, but heap got 75.8G(80.0G)->78.5G(80.0G)]<o:p></o:p></p>
<p class="MsoNormal">After that, the next Mixed GC hit “to-space exhausted” with 19 seconds pause, followed by Full GC that took 23 seconds.<o:p></o:p></p>
<p class="MsoNormal"><o:p> </o:p></p>
<p class="MsoNormal">I am wondering why G1 still decided to promote size up from 75.8G with 80GB heap? Is it possible to decide don’t promote if heap occupancy is already over 85%? Or 90%?<o:p></o:p></p>
<p class="MsoNormal"><o:p> </o:p></p>
<p class="MsoNormal">=======================================================<o:p></o:p></p>
<p class="MsoNormal"><o:p> </o:p></p>
<p class="MsoNormal">2015-03-12T21:12:51.326-0700: 17283.305: [GC pause (G1 Evacuation Pause) (mixed) 17283.305: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 65985, predicted base time: 51.83 ms, remaining time: 48.17 ms, target pause
time: 100.00 ms]<o:p></o:p></p>
<p class="MsoNormal">17283.305: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 112 regions, survivors: 16 regions, predicted young region time: 60.86 ms]<o:p></o:p></p>
<p class="MsoNormal">17283.307: [G1Ergonomics (CSet Construction) finish adding old regions to CSet, reason: predicted time is too high, predicted time: 0.97 ms, remaining time: 0.00 ms, old: 242 regions, min: 242 regions]<o:p></o:p></p>
<p class="MsoNormal">17283.307: [G1Ergonomics (CSet Construction) added expensive regions to CSet, reason: old CSet region num not reached min, old: 242 regions, expensive: 242 regions, min: 242 regions, remaining time: 0.00 ms]<o:p></o:p></p>
<p class="MsoNormal">17283.307: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 112 regions, survivors: 16 regions, old: 242 regions, predicted pause time: 249.13 ms, target pause time: 100.00 ms]<o:p></o:p></p>
<p class="MsoNormal">17283.500: [G1Ergonomics (Heap Sizing) attempt heap expansion, reason: region allocation request failed, allocation request: 8870968 bytes]<o:p></o:p></p>
<p class="MsoNormal">17283.501: [G1Ergonomics (Heap Sizing) expand the heap, requested expansion amount: 8870968 bytes, attempted expansion amount: 33554432 bytes]<o:p></o:p></p>
<p class="MsoNormal">17283.501: [G1Ergonomics (Heap Sizing) did not expand the heap, reason: heap already fully expanded]<o:p></o:p></p>
<p class="MsoNormal">17283.723: [SoftReference, 0 refs, 0.0029074 secs]17283.726: [WeakReference, 53 refs, 0.0013187 secs]17283.727: [FinalReference, 2758 refs, 0.0186603 secs]17283.746: [PhantomReference, 0 refs, 20 refs, 0.0054745 secs]17283.752: [JNI Weak
Reference, 0.0000076 secs] 17283.880: [G1Ergonomics (Concurrent Cycles) do not request concurrent cycle initiation, reason: still doing mixed collections, occupancy: 84087406592 bytes, allocation request: 0 bytes, threshold: 38654705655 bytes (45.00 %), source:
end of GC]<o:p></o:p></p>
<p class="MsoNormal">17283.881: [G1Ergonomics (Mixed GCs) continue mixed GCs, reason: candidate old regions available, candidate old regions: 1692 regions, reclaimable: 21320699264 bytes (24.82 %), threshold: 20.00 %]<o:p></o:p></p>
<p class="MsoNormal">(to-space exhausted), 0.5759340 secs]<o:p></o:p></p>
<p class="MsoNormal"> [Parallel Time: 414.1 ms, GC Workers: 48]<o:p></o:p></p>
<p class="MsoNormal"> [GC Worker Start (ms): Min: 17283307.7, Avg: 17283309.1, Max: 17283309.9, Diff: 2.2]<o:p></o:p></p>
<p class="MsoNormal"> [Ext Root Scanning (ms): Min: 0.0, Avg: 0.4, Max: 1.7, Diff: 1.7, Sum: 18.4]<o:p></o:p></p>
<p class="MsoNormal"> [Update RS (ms): Min: 9.2, Avg: 9.9, Max: 11.7, Diff: 2.5, Sum: 474.6]<o:p></o:p></p>
<p class="MsoNormal"> [Processed Buffers: Min: 5, Avg: 8.1, Max: 15, Diff: 10, Sum: 391]<o:p></o:p></p>
<p class="MsoNormal"> [Scan RS (ms): Min: 62.5, Avg: 64.8, Max: 72.5, Diff: 9.9, Sum: 3111.1]<o:p></o:p></p>
<p class="MsoNormal"> [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]<o:p></o:p></p>
<p class="MsoNormal"> [Object Copy (ms): Min: 328.9, Avg: 336.6, Max: 337.9, Diff: 9.0, Sum: 16156.0]<o:p></o:p></p>
<p class="MsoNormal"> [Termination (ms): Min: 0.0, Avg: 0.4, Max: 0.7, Diff: 0.7, Sum: 19.6]<o:p></o:p></p>
<p class="MsoNormal"> [GC Worker Other (ms): Min: 0.0, Avg: 0.1, Max: 0.2, Diff: 0.2, Sum: 3.2]<o:p></o:p></p>
<p class="MsoNormal"> [GC Worker Total (ms): Min: 411.2, Avg: 412.1, Max: 413.5, Diff: 2.2, Sum: 19782.8]<o:p></o:p></p>
<p class="MsoNormal"> [GC Worker End (ms): Min: 17283721.2, Avg: 17283721.2, Max: 17283721.3, Diff: 0.2]<o:p></o:p></p>
<p class="MsoNormal"> [Code Root Fixup: 0.2 ms]<o:p></o:p></p>
<p class="MsoNormal"> [Code Root Purge: 0.0 ms]<o:p></o:p></p>
<p class="MsoNormal"> [Clear CT: 5.6 ms]<o:p></o:p></p>
<p class="MsoNormal"> [Other: 156.1 ms]<o:p></o:p></p>
<p class="MsoNormal"> [Evacuation Failure: 108.7 ms]<o:p></o:p></p>
<p class="MsoNormal"> [Choose CSet: 2.5 ms]<o:p></o:p></p>
<p class="MsoNormal"> [Ref Proc: 29.6 ms]<o:p></o:p></p>
<p class="MsoNormal"> [Ref Enq: 2.2 ms]<o:p></o:p></p>
<p class="MsoNormal"> [Redirty Cards: 9.0 ms]<o:p></o:p></p>
<p class="MsoNormal"> [Humongous Reclaim: 0.0 ms]<o:p></o:p></p>
<p class="MsoNormal"> [Free CSet: 3.4 ms]<o:p></o:p></p>
<p class="MsoNormal"> [Eden: 3584.0M(3584.0M)->0.0B(3584.0M) Survivors: 512.0M->512.0M Heap: 75.8G(80.0G)->78.5G(80.0G)]<o:p></o:p></p>
<p class="MsoNormal">[Times: user=14.41 sys=0.16, real=0.57 secs]<o:p></o:p></p>
<p class="MsoNormal"><o:p> </o:p></p>
<p class="MsoNormal">====================================================<o:p></o:p></p>
<p class="MsoNormal"><o:p> </o:p></p>
<p class="MsoNormal">Thanks<o:p></o:p></p>
<p class="MsoNormal">-yanping<o:p></o:p></p>
<p class="MsoNormal"><o:p> </o:p></p>
</div>
</body>
</html>