This discussion is archived
0 Replies Latest reply: Jul 17, 2012 12:58 AM by 893864 RSS

Promotion failed

893864 Newbie
Currently Being Moderated
Hello,

After a lot of days working ok, I've seen this promotion failed:

355821.664: [GC 355821.665: [ParNew: 2017609K->19241K(2047232K), 0.0541990 secs] 7533629K->5535624K(12532992K), 0.0546670 secs] [Times: user=0.40 sys=0.00, real=0.05 secs]
355847.360: [GC 355847.361: [ParNew: 2016553K->15729K(2047232K), 0.0541380 secs] 7532936K->5532534K(12532992K), 0.0546180 secs] [Times: user=0.41 sys=0.00, real=0.06 secs]
355879.990: [GC 355879.990: [ParNew: 2013024K->16255K(2047232K), 0.0537110 secs] 7529830K->5533457K(12532992K), 0.0541620 secs] [Times: user=0.40 sys=0.00, real=0.05 secs]
355911.510: [GC 355911.510: [ParNew: 2013567K->20668K(2047232K), 0.0538160 secs] 7530769K->5538238K(12532992K), 0.0542650 secs] [Times: user=0.41 sys=0.01, real=0.06 secs]
355948.513: [GC 355948.514: [ParNew: 2017979K->15701K(2047232K), 0.0534070 secs] 7535549K->5533648K(12532992K), 0.0538740 secs] [Times: user=0.40 sys=0.00, real=0.06 secs]
355972.468: [GC 355972.468: [ParNew: 2012618K->16463K(2047232K), 0.0526980 secs] 7530565K->5534781K(12532992K), 0.0531620 secs] [Times: user=0.41 sys=0.01, real=0.06 secs]
356002.569: [GC 356002.570: [ParNew: 2009982K->24253K(2047232K), 0.0563880 secs] 7528300K->5542936K(12532992K), 0.0569110 secs] [Times: user=0.43 sys=0.00, real=0.06 secs]
356007.367: [GC 356007.367: [ParNew: 2021565K->46741K(2047232K), 0.0430610 secs] 7540248K->5565714K(12532992K), 0.0434700 secs] [Times: user=0.33 sys=0.00, real=0.04 secs]
356008.774: [GC 356008.774: [ParNew: 2044053K->20575K(2047232K), 0.0774320 secs] 7563026K->5550673K(12532992K), 0.0778920 secs] [Times: user=0.45 sys=0.01, real=0.07 secs]
356010.787: [GC 356010.788: [ParNew: 2017887K->45796K(2047232K), 0.0406320 secs] 7547985K->5587984K(12532992K), 0.0410570 secs] [Times: user=0.30 sys=0.00, real=0.04 secs]
356013.900: [GC 356013.900: [ParNew: 2043108K->40552K(2047232K), 0.0493420 secs] 7585296K->5619581K(12532992K), 0.0498020 secs] [Times: user=0.33 sys=0.00, real=0.05 secs]
356016.255: [GC 356016.255: [ParNew (promotion failed): 2037864K->2046281K(2047232K), 0.2680270 secs]356016.523: [CMS: 5610248K->5483489K(10485760K), 30.7884210 secs] 7616893K->5483489K(12532992K), [CMS Perm : 52153K->50877K(98304K)], 31.0568940 secs] [Times: user=30.90 sys=0.43, real=31.05 secs]
356055.881: [GC 356055.881: [ParNew: 1997114K->30063K(2047232K), 0.0327400 secs] 7480603K->5513552K(12532992K), 0.0331740 secs] [Times: user=0.20 sys=0.00, real=0.03 secs]
356076.412: [GC 356076.412: [ParNew: 2027375K->12345K(2047232K), 0.0280200 secs] 7510864K->5509050K(12532992K), 0.0284990 secs] [Times: user=0.21 sys=0.00, real=0.03 secs]
356103.129: [GC 356103.129: [ParNew: 2009656K->9398K(2047232K), 0.0271940 secs] 7506361K->5506103K(12532992K), 0.0276490 secs] [Times: user=0.20 sys=0.01, real=0.02 secs]
356126.264: [GC 356126.265: [ParNew: 2006710K->8625K(2047232K), 0.0259800 secs] 7503415K->5505330K(12532992K), 0.0264220 secs] [Times: user=0.19 sys=0.00, real=0.03 secs]
356160.262: [GC 356160.262: [ParNew: 2005937K->8004K(2047232K), 0.0252930 secs] 7502642K->5504709K(12532992K), 0.0257600 secs] [Times: user=0.19 sys=0.00, real=0.03 secs]
356188.401: [GC 356188.401: [ParNew: 2005316K->9038K(2047232K), 0.0252850 secs] 7502021K->5505743K(12532992K), 0.0257410 secs] [Times: user=0.18 sys=0.00, real=0.02 secs]
356214.384: [GC 356214.384: [ParNew: 2006350K->11535K(2047232K), 0.0253460 secs] 7503055K->5508240K(12532992K), 0.0257810 secs] [Times: user=0.19 sys=0.00, real=0.02 secs]

My configuration is:
JAVA_OPTS="$JAVA_OPTS ""-Xms12G -Xmx12G -Xss128K -server -XX:PermSize=96m -XX:MaxPermSize=128m -XX:NewSize=2048m -XX:SurvivorRatio=40 -XX:+UseConcMarkSweepGC -XX:+UseParNewGC -XX:CMSWaitDuration=10000 -XX:CMSMaxAbor
tablePrecleanTime=10000 -XX:MaxTenuringThreshold=15 -XX:+ExplicitGCInvokesConcurrent -Xloggc:/home/ventus/logs/gc.log -XX:+PrintGCDetails"

Before promotion, young generation were started every 30 seconds (more or less). Near to promotion, young generations were started very closed:
356002.569: [GC 356002.570: [ParNew: 2009982K->24253K(2047232K), 0.0563880 secs] 7528300K->5542936K(12532992K), 0.0569110 secs] [Times: user=0.43 sys=0.00, real=0.06 secs]
356007.367: [GC 356007.367: [ParNew: 2021565K->46741K(2047232K), 0.0430610 secs] 7540248K->5565714K(12532992K), 0.0434700 secs] [Times: user=0.33 sys=0.00, real=0.04 secs]
356008.774: [GC 356008.774: [ParNew: 2044053K->20575K(2047232K), 0.0774320 secs] 7563026K->5550673K(12532992K), 0.0778920 secs] [Times: user=0.45 sys=0.01, real=0.07 secs]
356010.787: [GC 356010.788: [ParNew: 2017887K->45796K(2047232K), 0.0406320 secs] 7547985K->5587984K(12532992K), 0.0410570 secs] [Times: user=0.30 sys=0.00, real=0.04 secs]
356013.900: [GC 356013.900: [ParNew: 2043108K->40552K(2047232K), 0.0493420 secs] 7585296K->5619581K(12532992K), 0.0498020 secs] [Times: user=0.33 sys=0.00, real=0.05 secs]
356016.255: [GC 356016.255: [ParNew (promotion failed): 2037864K->2046281K(2047232K), 0.2680270 secs]356016.523: [CMS: 5610248K->5483489K(10485760K), 30.7884210 secs] 7616893K->5483489K(12532992K), [CMS Perm : 52153K->50877K(98304K)], 31.0568940

Looking at logs, is it possible to see any reason for this promotion?

Thanks,
Joan.

Legend

  • Correct Answers - 10 points
  • Helpful Answers - 5 points