<!DOCTYPE html PUBLIC "-//W3C//DTD HTML 4.01 Transitional//EN">
<html>
<head>
<meta content="text/html;charset=ISO-8859-1" http-equiv="Content-Type">
</head>
<body bgcolor="#ffffff" text="#000000">
Shaun,<br>
<br>
I'm going to answer over several replies. Here are<br>
the first 2 answers.<br>
<br>
On 04/14/10 13:29, Shaun Hennessy wrote:
<blockquote cite="mid:4BC62595.2000002@alcatel-lucent.com" type="cite">
<meta content="text/html;charset=ISO-8859-1" http-equiv="Content-Type">
Still working on log output w/ different releases / log options, <br>
but a few other follow up questions on the substance<br>
<br>
<blockquote cite="mid:148A7A57-B616-4CA4-9571-0F0216B0F650@oracle.com"
type="cite">
<div>
<div>
<div>
<blockquote cite="mid:4BB20B1C.4020608@alcatel-lucent.com"
type="cite"><tt> <br>
- Promotion Failure<br>
4896.478: [GC 4896.478: [ParNew: 4894353K->587864K(5017600K),
0.4789909 secs] 8473688K->4268560K(13619200K), 0.4791812 secs]
[Times: user=1.00 sys=0.61, real=0.48 secs]<br>
4897.812: [GC 4897.812: [ParNew: 4888664K->545903K(5017600K),
0.4105613 secs] 8569360K->4326583K(13619200K), 0.4107560 secs]
[Times: user=1.06 sys=0.55, real=0.41 secs]<br>
4899.057: [GC 4899.058: [ParNew: 4846703K->638966K(5017600K),
0.2759734 secs] 8627383K->4496987K(13619200K), 0.2761637 secs]
[Times: user=1.13 sys=0.36, real=0.28 secs]<br>
4900.101: [GC 4900.101: [ParNew: 4939768K->630721K(5017600K),
0.5117751 secs] 8797789K->4607020K(13619200K), 0.5119662 secs]
[Times: user=0.84 sys=0.66, real=0.51 secs]<br>
4900.615: [GC 4900.615: [ParNew: 651487K->487288K(5017600K),
0.0780183 secs] 4627786K->4463587K(13619200K), 0.0781687 secs]
[Times: user=0.96 sys=0.00, real=0.08 secs]<br>
<b>4901.581: [GC 4901.581: [ParNew (promotion failed):
4788088K->4780999K(5017600K), 2.8947499 secs]4904.476: [CMS:
4003090K->1530872K(8601600K), 7.5122451 secs]
8764387K->1530872K(13619200K), [CMS Perm :
671102K->671102K(819200K)], 10.4072102 secs] [Times: user=11.03
sys=1.09, real=10.41 secs]</b><br>
4913.024: [GC 4913.024: [ParNew: 4300800K->316807K(5017600K),
0.0615917 secs] 5831672K->1847679K(13619200K), 0.0617857 secs]
[Times: user=0.74 sys=0.00, real=0.06 secs]<br>
4914.015: [GC 4914.015: [ParNew: 4617607K->475077K(5017600K),
0.0771389 secs] 6148479K->2005949K(13619200K), 0.0773290 secs]
[Times: user=0.95 sys=0.00, real=0.08 secs]<br>
4914.908: [GC 4914.908: [ParNew: 4775877K->586339K(5017600K),
0.0857102 secs] 6306749K->2117211K(13619200K), 0.0859046 secs]
[Times: user=1.06 sys=0.00, real=0.09 secs]<br>
4915.816: [GC 4915.816: [ParNew: 4887139K->476398K(5017600K),
0.1841627 secs] 6418011K->2152868K(13619200K), 0.1843556 secs]
[Times: user=1.32 sys=0.07, real=0.18 secs]<br>
</tt></blockquote>
<br>
<blockquote cite="mid:4BB20B1C.4020608@alcatel-lucent.com"
type="cite"><tt>8)
What exactly is occurring during this promotion failed collection?
Based on the next example I assume<br>
it's a (successful) scavenge. What exactly is this - which thread(s)
serial / ParallelGCThreads?, <br>
STW?, are we simply compacting the tenured gen or are we can actually
GC the tenured?<br>
</tt></blockquote>
<div><br>
</div>
A promotion failure is a scavenge that does not succeed because there
is not enough</div>
<div>space in the old gen to do all the needed promotions. The
scavenge is in essence</div>
<div>unwound and then a full STW compaction of the entire heap is
done.</div>
</div>
</div>
</blockquote>
1) Just so I am clear "compaction" is compacting of the heap (making a
contiguous heap) AND<br>
garbage collection at the same time? -- the <tt>"CMS:
4003090K->1530872K(8601600K)"<br>
shows me my total heap is 1.5GB following this action, whereas the <br>
previous ParNew showed total heap was at 4.4GB.<br>
</tt></blockquote>
"compaction" is a feature of some garbage collectors and in this case,
a garbage<br>
collection with compaction is happening.<br>
<blockquote cite="mid:4BC62595.2000002@alcatel-lucent.com" type="cite"><tt><br>
</tt><tt><br>
2) Also just noticed this, what is the reason for the previous minor
collection ?<br>
</tt><tt>4900.615 </tt><tt>[ParNew: 651487K->487288K(5017600K)
--> Normally the minors are <br>
at 4.8GB and get reduced to about 600K, whereas this one started at
650K. <br>
Using survivor isn't impacting/changing anything is it?<br>
<br>
Maybe it's because at </tt><tt>
4900.615 we finished at 487K and than less than <br>
1 second later at </tt><tt>4901.581 we have a another ParNew (the
failure) and the<br>
</tt><tt>4788088K->4780999K entry --- so in less than 1 second we
allocated 4GB.<br>
So perhaps does this answer my previous question about why a minor comes<br>
along at only 651K - we're trying to allocate a 4GB object / 4GB worth
of large objects?<br>
I guess this explains why I had a promotion failure / confirms
fragmentation<br>
despite having more than 4GB free in tenured I probably didn't 4GB
contiguous.<br>
</tt></blockquote>
<br>
Hard to say why the collection with only 651487k used. You're using
JNI critical sections which<br>
affects garbage collection so something could be going wrong with that
interaction.<br>
<br>
</body>
</html>