Need help about CMS Failure and ParNew failure
Erwin
tanman12345 at yahoo.com
Thu Apr 12 09:27:13 PDT 2012
Hello,
I'm not an expert when it comes to analyzing GC output and was wondering if you guys could assist? We're using Solaris 10 10/08 s10s_u6wos_07b SPARC, with WAS NDE 7.0.0.9. After a restart of our JVMs, GC seems to be fine. However, after about a week, we start seeing failures in GC log. We're getting ParNew and Concurrent mod failures. Our JVM configurations are below:
Min heap - 4096
Max heap - 6016
JVM Arguments
-server -Xmn1000m -XX:PermSize=512m -XX:+UseConcMarkSweepGC -XX:+HeapDumpOnOutOfMemoryError -DUseSunHttpHandler=true -Djavax.xml.soap.MessageFactory=weblogic.xml.saaj.MessageFactoryImpl -Doracle.jdbc.V8Compatible=true -XX:CMSInitiatingOccupancyFraction=70 -XX:+CMSClassUnloadingEnabled -verbose:gc -XX:+PrintGCTimeStamps -XX:+PrintGCDetails -XX:-TraceClassUnloading -XX:+PrintHeapAtGC -XX:MaxPermSize=694m -XX:+DisableExplicitGC -XX:+CMSParallelRemarkEnabled
I'm attaching the ParNew failure as well as CMS failure files. Hope it attaches.Total of 2 files. In case they don't see below. !st same if ParNew, 2nd is CMS failure. - Thanks, Erwin
ParNew failure sample:
{Heap before GC invocations=7800 (full 529):
par new generation total 921600K, used 530694K [0xfffffffdd0000000, 0xfffffffe0e800000, 0xfffffffe0e800000)
eden space 819200K, 52% used [0xfffffffdd0000000, 0xfffffffdea241bb8, 0xfffffffe02000000)
from space 102400K, 100% used [0xfffffffe02000000, 0xfffffffe08400000, 0xfffffffe08400000)
to space 102400K, 0% used [0xfffffffe08400000, 0xfffffffe08400000, 0xfffffffe0e800000)
concurrent mark-sweep generation total 4902464K, used 2682365K [0xfffffffe0e800000, 0xffffffff39b90000, 0xffffffff48000000)
concurrent-mark-sweep perm gen total 524288K, used 238782K [0xffffffff48000000, 0xffffffff68000000, 0xffffffff73800000)
552370.958: [GC 552370.958: [ParNew: 530694K->93237K(921600K), 0.1858500 secs] 3213060K->2832744K(5824064K), 0.1862466 secs] [Times: user=1.21 sys=0.08, real=0.19 secs]
Heap after GC invocations=7801 (full 529):
par new generation total 921600K, used 93237K [0xfffffffdd0000000, 0xfffffffe0e800000, 0xfffffffe0e800000)
eden space 819200K, 0% used [0xfffffffdd0000000, 0xfffffffdd0000000, 0xfffffffe02000000)
from space 102400K, 91% used [0xfffffffe08400000, 0xfffffffe0df0d498, 0xfffffffe0e800000)
to space 102400K, 0% used [0xfffffffe02000000, 0xfffffffe02000000, 0xfffffffe08400000)
concurrent mark-sweep generation total 4902464K, used 2739507K [0xfffffffe0e800000, 0xffffffff39b90000, 0xffffffff48000000)
concurrent-mark-sweep perm gen total 524288K, used 238782K [0xffffffff48000000, 0xffffffff68000000, 0xffffffff73800000)
}
{Heap before GC invocations=7801 (full 529):
par new generation total 921600K, used 912377K [0xfffffffdd0000000, 0xfffffffe0e800000, 0xfffffffe0e800000)
eden space 819200K, 99% used [0xfffffffdd0000000, 0xfffffffe01ff1320, 0xfffffffe02000000)
from space 102400K, 91% used [0xfffffffe08400000, 0xfffffffe0df0d498, 0xfffffffe0e800000)
to space 102400K, 0% used [0xfffffffe02000000, 0xfffffffe02000000, 0xfffffffe08400000)
concurrent mark-sweep generation total 4902464K, used 2739507K [0xfffffffe0e800000, 0xffffffff39b90000, 0xffffffff48000000)
concurrent-mark-sweep perm gen total 524288K, used 238795K [0xffffffff48000000, 0xffffffff68000000, 0xffffffff73800000)
552372.849: [GC 552372.849: [ParNew (promotion failed): 912377K->869343K(921600K), 0.2641392 secs]552373.113: [CMS: 2791714K->3203612K(4902464K), 29.1902704 secs] 3651885K->3203612K(5824064K), [CMS Perm : 238795K->238246K(524288K)], 29.4609781 secs] [Times: user=30.05 sys=0.13, real=29.46 secs]
Heap after GC invocations=7802 (full 530):
par new generation total 921600K, used 0K [0xfffffffdd0000000, 0xfffffffe0e800000, 0xfffffffe0e800000)
eden space 819200K, 0% used [0xfffffffdd0000000, 0xfffffffdd0000000, 0xfffffffe02000000)
from space 102400K, 0% used [0xfffffffe02000000, 0xfffffffe02000000, 0xfffffffe08400000)
to space 102400K, 0% used [0xfffffffe08400000, 0xfffffffe08400000, 0xfffffffe0e800000)
concurrent mark-sweep generation total 5136384K, used 3203612K [0xfffffffe0e800000, 0xffffffff48000000, 0xffffffff48000000)
concurrent-mark-sweep perm gen total 524288K, used 238246K [0xffffffff48000000, 0xffffffff68000000, 0xffffffff73800000)
}
{Heap before GC invocations=12696 (full 809):
par new generation total 921600K, used 908565K [0xfffffffdd0000000, 0xfffffffe0e800000, 0xfffffffe0e800000)
eden space 819200K, 100% used [0xfffffffdd0000000, 0xfffffffe02000000, 0xfffffffe02000000)
from space 102400K, 87% used [0xfffffffe02000000, 0xfffffffe07745510, 0xfffffffe08400000)
to space 102400K, 0% used [0xfffffffe08400000, 0xfffffffe08400000, 0xfffffffe0e800000)
concurrent mark-sweep generation total 5136384K, used 2696786K [0xfffffffe0e800000, 0xffffffff48000000, 0xffffffff48000000)
concurrent-mark-sweep perm gen total 524288K, used 241380K [0xffffffff48000000, 0xffffffff68000000, 0xffffffff73800000)
980120.502: [GC 980120.502: [ParNew: 908565K->73974K(921600K), 0.1519646 secs] 3605352K->2817972K(6057984K), 0.1523927 secs] [Times: user=1.07 sys=0.03, real=0.15 secs]
Heap after GC invocations=12697 (full 809):
par new generation total 921600K, used 73974K [0xfffffffdd0000000, 0xfffffffe0e800000, 0xfffffffe0e800000)
eden space 819200K, 0% used [0xfffffffdd0000000, 0xfffffffdd0000000, 0xfffffffe02000000)
from space 102400K, 72% used [0xfffffffe08400000, 0xfffffffe0cc3d928, 0xfffffffe0e800000)
to space 102400K, 0% used [0xfffffffe02000000, 0xfffffffe02000000, 0xfffffffe08400000)
concurrent mark-sweep generation total 5136384K, used 2743998K [0xfffffffe0e800000, 0xffffffff48000000, 0xffffffff48000000)
concurrent-mark-sweep perm gen total 524288K, used 241380K [0xffffffff48000000, 0xffffffff68000000, 0xffffffff73800000)
}
{Heap before GC invocations=12697 (full 809):
par new generation total 921600K, used 893174K [0xfffffffdd0000000, 0xfffffffe0e800000, 0xfffffffe0e800000)
eden space 819200K, 100% used [0xfffffffdd0000000, 0xfffffffe02000000, 0xfffffffe02000000)
from space 102400K, 72% used [0xfffffffe08400000, 0xfffffffe0cc3d928, 0xfffffffe0e800000)
to space 102400K, 0% used [0xfffffffe02000000, 0xfffffffe02000000, 0xfffffffe08400000)
concurrent mark-sweep generation total 5136384K, used 2743998K [0xfffffffe0e800000, 0xffffffff48000000, 0xffffffff48000000)
concurrent-mark-sweep perm gen total 524288K, used 241411K [0xffffffff48000000, 0xffffffff68000000, 0xffffffff73800000)
980130.777: [GC 980130.777: [ParNew (promotion failed): 893174K->913391K(921600K), 0.5914616 secs]980131.368: [CMS: 2778416K->2710999K(5136384K), 27.7981960 secs] 3637172K->2710999K(6057984K), [CMS Perm : 241411K->240494K(524288K)], 28.3902578 secs] [Times: user=29.37 sys=0.08, real=28.39 secs]
Heap after GC invocations=12698 (full 810):
par new generation total 921600K, used 0K [0xfffffffdd0000000, 0xfffffffe0e800000, 0xfffffffe0e800000)
eden space 819200K, 0% used [0xfffffffdd0000000, 0xfffffffdd0000000, 0xfffffffe02000000)
from space 102400K, 0% used [0xfffffffe02000000, 0xfffffffe02000000, 0xfffffffe08400000)
to space 102400K, 0% used [0xfffffffe08400000, 0xfffffffe08400000, 0xfffffffe0e800000)
concurrent mark-sweep generation total 5136384K, used 2710999K [0xfffffffe0e800000, 0xffffffff48000000, 0xffffffff48000000)
concurrent-mark-sweep perm gen total 524288K, used 240494K [0xffffffff48000000, 0xffffffff68000000, 0xffffffff73800000)
}
{Heap before GC invocations=12698 (full 810):
par new generation total 921600K, used 819200K [0xfffffffdd0000000, 0xfffffffe0e800000, 0xfffffffe0e800000)
eden space 819200K, 100% used [0xfffffffdd0000000, 0xfffffffe02000000, 0xfffffffe02000000)
from space 102400K, 0% used [0xfffffffe02000000, 0xfffffffe02000000, 0xfffffffe08400000)
to space 102400K, 0% used [0xfffffffe08400000, 0xfffffffe08400000, 0xfffffffe0e800000)
concurrent mark-sweep generation total 5136384K, used 2710999K [0xfffffffe0e800000, 0xffffffff48000000, 0xffffffff48000000)
concurrent-mark-sweep perm gen total 524288K, used 240523K [0xffffffff48000000, 0xffffffff68000000, 0xffffffff73800000)
980171.033: [GC 980171.033: [ParNew: 819200K->102400K(921600K), 0.2144047 secs] 3530199K->2857892K(6057984K), 0.2149864 secs] [Times: user=0.99 sys=0.03, real=0.22 secs]
Heap after GC invocations=12699 (full 810):
par new generation total 921600K, used 102400K [0xfffffffdd0000000, 0xfffffffe0e800000, 0xfffffffe0e800000)
eden space 819200K, 0% used [0xfffffffdd0000000, 0xfffffffdd0000000, 0xfffffffe02000000)
from space 102400K, 100% used [0xfffffffe08400000, 0xfffffffe0e800000, 0xfffffffe0e800000)
to space 102400K, 0% used [0xfffffffe02000000, 0xfffffffe02000000, 0xfffffffe08400000)
concurrent mark-sweep generation total 5136384K, used 2755492K [0xfffffffe0e800000, 0xffffffff48000000, 0xffffffff48000000)
concurrent-mark-sweep perm gen total 524288K, used 240523K [0xffffffff48000000, 0xffffffff68000000, 0xffffffff73800000)
}
CMS Failure:
{Heap before GC invocations=23856 (full 1462):
par new generation total 921600K, used 921600K [0xfffffffdd0000000, 0xfffffffe0e800000, 0xfffffffe0e800000)
eden space 819200K, 100% used [0xfffffffdd0000000, 0xfffffffe02000000, 0xfffffffe02000000)
from space 102400K, 100% used [0xfffffffe02000000, 0xfffffffe08400000, 0xfffffffe08400000)
to space 102400K, 0% used [0xfffffffe08400000, 0xfffffffe08400000, 0xfffffffe0e800000)
concurrent mark-sweep generation total 5136384K, used 3496920K [0xfffffffe0e800000, 0xffffffff48000000, 0xffffffff48000000)
concurrent-mark-sweep perm gen total 524288K, used 243562K [0xffffffff48000000, 0xffffffff68000000, 0xffffffff73800000)
1761014.981: [GC 1761014.981: [ParNew: 921600K->102400K(921600K), 0.3004508 secs] 4418520K->3667695K(6057984K), 0.3008667 secs] [Times: user=1.69 sys=0.10, real=0.30 secs]
Heap after GC invocations=23857 (full 1462):
par new generation total 921600K, used 102400K [0xfffffffdd0000000, 0xfffffffe0e800000, 0xfffffffe0e800000)
eden space 819200K, 0% used [0xfffffffdd0000000, 0xfffffffdd0000000, 0xfffffffe02000000)
from space 102400K, 100% used [0xfffffffe08400000, 0xfffffffe0e800000, 0xfffffffe0e800000)
to space 102400K, 0% used [0xfffffffe02000000, 0xfffffffe02000000, 0xfffffffe08400000)
concurrent mark-sweep generation total 5136384K, used 3565295K [0xfffffffe0e800000, 0xffffffff48000000, 0xffffffff48000000)
concurrent-mark-sweep perm gen total 524288K, used 243562K [0xffffffff48000000, 0xffffffff68000000, 0xffffffff73800000)
}
{Heap before GC invocations=23857 (full 1462):
par new generation total 921600K, used 921600K [0xfffffffdd0000000, 0xfffffffe0e800000, 0xfffffffe0e800000)
eden space 819200K, 100% used [0xfffffffdd0000000, 0xfffffffe02000000, 0xfffffffe02000000)
from space 102400K, 100% used [0xfffffffe08400000, 0xfffffffe0e800000, 0xfffffffe0e800000)
to space 102400K, 0% used [0xfffffffe02000000, 0xfffffffe02000000, 0xfffffffe08400000)
concurrent mark-sweep generation total 5136384K, used 3565295K [0xfffffffe0e800000, 0xffffffff48000000, 0xffffffff48000000)
concurrent-mark-sweep perm gen total 524288K, used 243773K [0xffffffff48000000, 0xffffffff68000000, 0xffffffff73800000)
1761036.997: [GC 1761036.998: [ParNew: 921600K->102400K(921600K), 0.4075457 secs] 4486895K->3763683K(6057984K), 0.4079591 secs] [Times: user=3.57 sys=0.80, real=0.41 secs]
Heap after GC invocations=23858 (full 1462):
par new generation total 921600K, used 102400K [0xfffffffdd0000000, 0xfffffffe0e800000, 0xfffffffe0e800000)
eden space 819200K, 0% used [0xfffffffdd0000000, 0xfffffffdd0000000, 0xfffffffe02000000)
from space 102400K, 100% used [0xfffffffe02000000, 0xfffffffe08400000, 0xfffffffe08400000)
to space 102400K, 0% used [0xfffffffe08400000, 0xfffffffe08400000, 0xfffffffe0e800000)
concurrent mark-sweep generation total 5136384K, used 3661283K [0xfffffffe0e800000, 0xffffffff48000000, 0xffffffff48000000)
concurrent-mark-sweep perm gen total 524288K, used 243773K [0xffffffff48000000, 0xffffffff68000000, 0xffffffff73800000)
}
1761037.410: [GC [1 CMS-initial-mark: 3661283K(5136384K)] 3763683K(6057984K), 0.0883369 secs] [Times: user=0.09 sys=0.00, real=0.09 secs]
1761037.499: [CMS-concurrent-mark-start]
1761041.447: [CMS-concurrent-mark: 3.906/3.948 secs] [Times: user=25.81 sys=1.06, real=3.95 secs]
1761041.448: [CMS-concurrent-preclean-start]
1761041.763: [CMS-concurrent-preclean: 0.312/0.315 secs] [Times: user=0.50 sys=0.02, real=0.32 secs]
1761041.763: [CMS-concurrent-abortable-preclean-start]
CMS: abort preclean due to time 1761046.800: [CMS-concurrent-abortable-preclean: 4.720/5.036 secs] [Times: user=6.68 sys=0.18, real=5.04 secs]
1761046.808: [GC[YG occupancy: 464701 K (921600 K)]1761046.808: [Rescan (parallel) , 0.3034664 secs]1761047.112: [weak refs processing, 0.0152564 secs]1761047.128: [class unloading, 0.1518160 secs]1761047.280: [scrub symbol & string tables, 0.1332523 secs] [1 CMS-remark: 3661283K(5136384K)] 4125985K(6057984K), 0.6980401 secs] [Times: user=1.34 sys=0.70, real=0.70 secs]
1761047.507: [CMS-concurrent-sweep-start]
1761051.779: [CMS-concurrent-sweep: 4.252/4.271 secs] [Times: user=6.30 sys=0.19, real=4.27 secs]
1761051.779: [CMS-concurrent-reset-start]
1761051.837: [CMS-concurrent-reset: 0.058/0.058 secs] [Times: user=0.07 sys=0.00, real=0.06 secs]
{Heap before GC invocations=23858 (full 1463):
par new generation total 921600K, used 921600K [0xfffffffdd0000000, 0xfffffffe0e800000, 0xfffffffe0e800000)
eden space 819200K, 100% used [0xfffffffdd0000000, 0xfffffffe02000000, 0xfffffffe02000000)
from space 102400K, 100% used [0xfffffffe02000000, 0xfffffffe08400000, 0xfffffffe08400000)
to space 102400K, 0% used [0xfffffffe08400000, 0xfffffffe08400000, 0xfffffffe0e800000)
concurrent mark-sweep generation total 5136384K, used 3514703K [0xfffffffe0e800000, 0xffffffff48000000, 0xffffffff48000000)
concurrent-mark-sweep perm gen total 524288K, used 243613K [0xffffffff48000000, 0xffffffff68000000, 0xffffffff73800000)
1761061.144: [GC 1761061.145: [ParNew: 921600K->102400K(921600K), 0.4124278 secs] 4436303K->3717736K(6057984K), 0.4128777 secs] [Times: user=1.98 sys=0.19, real=0.41 secs]
Heap after GC invocations=23859 (full 1463):
par new generation total 921600K, used 102400K [0xfffffffdd0000000, 0xfffffffe0e800000, 0xfffffffe0e800000)
eden space 819200K, 0% used [0xfffffffdd0000000, 0xfffffffdd0000000, 0xfffffffe02000000)
from space 102400K, 100% used [0xfffffffe08400000, 0xfffffffe0e800000, 0xfffffffe0e800000)
to space 102400K, 0% used [0xfffffffe02000000, 0xfffffffe02000000, 0xfffffffe08400000)
concurrent mark-sweep generation total 5136384K, used 3615336K [0xfffffffe0e800000, 0xffffffff48000000, 0xffffffff48000000)
concurrent-mark-sweep perm gen total 524288K, used 243613K [0xffffffff48000000, 0xffffffff68000000, 0xffffffff73800000)
}
1761061.562: [GC [1 CMS-initial-mark: 3615336K(5136384K)] 3718604K(6057984K), 0.0660086 secs] [Times: user=0.07 sys=0.00, real=0.07 secs]
1761061.629: [CMS-concurrent-mark-start]
1761065.589: [CMS-concurrent-mark: 3.920/3.960 secs] [Times: user=26.20 sys=1.05, real=3.96 secs]
1761065.590: [CMS-concurrent-preclean-start]
1761065.883: [CMS-concurrent-preclean: 0.290/0.293 secs] [Times: user=0.54 sys=0.02, real=0.29 secs]
1761065.883: [CMS-concurrent-abortable-preclean-start]
CMS: abort preclean due to time 1761070.950: [CMS-concurrent-abortable-preclean: 5.035/5.067 secs] [Times: user=10.70 sys=0.36, real=5.07 secs]
1761070.958: [GC[YG occupancy: 656197 K (921600 K)]1761070.959: [Rescan (parallel) , 0.5056315 secs]1761071.465: [weak refs processing, 0.0107058 secs]1761071.476: [class unloading, 0.1500832 secs]1761071.626: [scrub symbol & string tables, 0.1278517 secs] [1 CMS-remark: 3615336K(5136384K)] 4271533K(6057984K), 0.8857121 secs] [Times: user=1.77 sys=1.08, real=0.89 secs]
1761071.845: [CMS-concurrent-sweep-start]
1761075.956: [CMS-concurrent-sweep: 4.094/4.111 secs] [Times: user=7.97 sys=0.27, real=4.11 secs]
1761075.957: [CMS-concurrent-reset-start]
1761076.031: [CMS-concurrent-reset: 0.063/0.074 secs] [Times: user=0.13 sys=0.01, real=0.07 secs]
{Heap before GC invocations=23859 (full 1464):
par new generation total 921600K, used 921600K [0xfffffffdd0000000, 0xfffffffe0e800000, 0xfffffffe0e800000)
eden space 819200K, 100% used [0xfffffffdd0000000, 0xfffffffe02000000, 0xfffffffe02000000)
from space 102400K, 100% used [0xfffffffe08400000, 0xfffffffe0e800000, 0xfffffffe0e800000)
to space 102400K, 0% used [0xfffffffe02000000, 0xfffffffe02000000, 0xfffffffe08400000)
concurrent mark-sweep generation total 5136384K, used 3544377K [0xfffffffe0e800000, 0xffffffff48000000, 0xffffffff48000000)
concurrent-mark-sweep perm gen total 524288K, used 243474K [0xffffffff48000000, 0xffffffff68000000, 0xffffffff73800000)
1761077.540: [GC 1761077.540: [ParNew: 921600K->102400K(921600K), 0.4030394 secs] 4465977K->3740399K(6057984K), 0.4034742 secs] [Times: user=3.14 sys=0.55, real=0.40 secs]
Heap after GC invocations=23860 (full 1464):
par new generation total 921600K, used 102400K [0xfffffffdd0000000, 0xfffffffe0e800000, 0xfffffffe0e800000)
eden space 819200K, 0% used [0xfffffffdd0000000, 0xfffffffdd0000000, 0xfffffffe02000000)
from space 102400K, 100% used [0xfffffffe02000000, 0xfffffffe08400000, 0xfffffffe08400000)
to space 102400K, 0% used [0xfffffffe08400000, 0xfffffffe08400000, 0xfffffffe0e800000)
concurrent mark-sweep generation total 5136384K, used 3637999K [0xfffffffe0e800000, 0xffffffff48000000, 0xffffffff48000000)
concurrent-mark-sweep perm gen total 524288K, used 243474K [0xffffffff48000000, 0xffffffff68000000, 0xffffffff73800000)
}
1761077.948: [GC [1 CMS-initial-mark: 3637999K(5136384K)] 3740403K(6057984K), 0.0664402 secs] [Times: user=0.06 sys=0.00, real=0.07 secs]
1761078.015: [CMS-concurrent-mark-start]
1761082.141: [CMS-concurrent-mark: 4.076/4.126 secs] [Times: user=25.56 sys=1.24, real=4.13 secs]
1761082.142: [CMS-concurrent-preclean-start]
1761082.435: [CMS-concurrent-preclean: 0.290/0.293 secs] [Times: user=0.56 sys=0.03, real=0.29 secs]
1761082.435: [CMS-concurrent-abortable-preclean-start]
CMS: abort preclean due to time 1761087.544: [CMS-concurrent-abortable-preclean: 4.166/5.108 secs] [Times: user=6.79 sys=0.38, real=5.11 secs]
1761087.554: [GC[YG occupancy: 612230 K (921600 K)]1761087.555: [Rescan (parallel) , 0.3453344 secs]1761087.900: [weak refs processing, 0.0033384 secs]1761087.904: [class unloading, 0.1515234 secs]1761088.055: [scrub symbol & string tables, 0.1280533 secs] [1 CMS-remark: 3637999K(5136384K)] 4250230K(6057984K), 0.7189376 secs] [Times: user=1.29 sys=0.76, real=0.72 secs]
1761088.274: [CMS-concurrent-sweep-start]
1761092.543: [CMS-concurrent-sweep: 4.268/4.268 secs] [Times: user=6.72 sys=0.26, real=4.27 secs]
1761092.543: [CMS-concurrent-reset-start]
1761092.606: [CMS-concurrent-reset: 0.063/0.063 secs] [Times: user=0.11 sys=0.01, real=0.06 secs]
{Heap before GC invocations=23860 (full 1465):
par new generation total 921600K, used 921600K [0xfffffffdd0000000, 0xfffffffe0e800000, 0xfffffffe0e800000)
eden space 819200K, 100% used [0xfffffffdd0000000, 0xfffffffe02000000, 0xfffffffe02000000)
from space 102400K, 100% used [0xfffffffe02000000, 0xfffffffe08400000, 0xfffffffe08400000)
to space 102400K, 0% used [0xfffffffe08400000, 0xfffffffe08400000, 0xfffffffe0e800000)
concurrent mark-sweep generation total 5136384K, used 3582457K [0xfffffffe0e800000, 0xffffffff48000000, 0xffffffff48000000)
concurrent-mark-sweep perm gen total 524288K, used 243634K [0xffffffff48000000, 0xffffffff68000000, 0xffffffff73800000)
1761096.682: [GC 1761096.682: [ParNew: 921600K->102400K(921600K), 0.2843209 secs] 4504057K->3786219K(6057984K), 0.2847419 secs] [Times: user=1.81 sys=0.10, real=0.29 secs]
Heap after GC invocations=23861 (full 1465):
par new generation total 921600K, used 102400K [0xfffffffdd0000000, 0xfffffffe0e800000, 0xfffffffe0e800000)
eden space 819200K, 0% used [0xfffffffdd0000000, 0xfffffffdd0000000, 0xfffffffe02000000)
from space 102400K, 100% used [0xfffffffe08400000, 0xfffffffe0e800000, 0xfffffffe0e800000)
to space 102400K, 0% used [0xfffffffe02000000, 0xfffffffe02000000, 0xfffffffe08400000)
concurrent mark-sweep generation total 5136384K, used 3683819K [0xfffffffe0e800000, 0xffffffff48000000, 0xffffffff48000000)
concurrent-mark-sweep perm gen total 524288K, used 243634K [0xffffffff48000000, 0xffffffff68000000, 0xffffffff73800000)
}
1761096.971: [GC [1 CMS-initial-mark: 3683819K(5136384K)] 3786817K(6057984K), 0.0480239 secs] [Times: user=0.05 sys=0.00, real=0.05 secs]
1761097.020: [CMS-concurrent-mark-start]
1761101.145: [CMS-concurrent-mark: 4.104/4.124 secs] [Times: user=24.60 sys=1.09, real=4.13 secs]
1761101.145: [CMS-concurrent-preclean-start]
1761101.438: [CMS-concurrent-preclean: 0.290/0.292 secs] [Times: user=0.41 sys=0.02, real=0.29 secs]
1761101.438: [CMS-concurrent-abortable-preclean-start]
CMS: abort preclean due to time 1761106.478: [CMS-concurrent-abortable-preclean: 4.694/5.040 secs] [Times: user=7.32 sys=0.23, real=5.04 secs]
1761106.486: [GC[YG occupancy: 497634 K (921600 K)]1761106.487: [Rescan (parallel) , 0.3384965 secs]1761106.825: [weak refs processing, 0.0030734 secs]1761106.829: [class unloading, 0.1503426 secs]1761106.979: [scrub symbol & string tables, 0.1273150 secs] [1 CMS-remark: 3683819K(5136384K)] 4181454K(6057984K), 0.7055549 secs] [Times: user=1.25 sys=0.64, real=0.71 secs]
1761107.193: [CMS-concurrent-sweep-start]
1761111.281: [CMS-concurrent-sweep: 4.088/4.088 secs] [Times: user=5.81 sys=0.15, real=4.09 secs]
1761111.282: [CMS-concurrent-reset-start]
1761111.349: [CMS-concurrent-reset: 0.068/0.068 secs] [Times: user=0.08 sys=0.00, real=0.07 secs]
1761111.961: [GC [1 CMS-initial-mark: 3633902K(5136384K)] 4261007K(6057984K), 0.5015835 secs] [Times: user=0.50 sys=0.00, real=0.50 secs]
1761112.463: [CMS-concurrent-mark-start]
1761116.550: [CMS-concurrent-mark: 4.036/4.087 secs] [Times: user=24.85 sys=1.09, real=4.09 secs]
1761116.551: [CMS-concurrent-preclean-start]
1761116.901: [CMS-concurrent-preclean: 0.344/0.350 secs] [Times: user=0.54 sys=0.01, real=0.35 secs]
1761116.901: [CMS-concurrent-abortable-preclean-start]
{Heap before GC invocations=23861 (full 1467):
par new generation total 921600K, used 921600K [0xfffffffdd0000000, 0xfffffffe0e800000, 0xfffffffe0e800000)
eden space 819200K, 100% used [0xfffffffdd0000000, 0xfffffffe02000000, 0xfffffffe02000000)
from space 102400K, 100% used [0xfffffffe08400000, 0xfffffffe0e800000, 0xfffffffe0e800000)
to space 102400K, 0% used [0xfffffffe02000000, 0xfffffffe02000000, 0xfffffffe08400000)
concurrent mark-sweep generation total 5136384K, used 3633902K [0xfffffffe0e800000, 0xffffffff48000000, 0xffffffff48000000)
concurrent-mark-sweep perm gen total 524288K, used 243740K [0xffffffff48000000, 0xffffffff68000000, 0xffffffff73800000)
1761120.554: [GC 1761120.554: [ParNew: 921600K->102400K(921600K), 0.4726199 secs] 4555502K->3819626K(6057984K), 0.4732486 secs] [Times: user=3.31 sys=0.69, real=0.47 secs]
Heap after GC invocations=23862 (full 1467):
par new generation total 921600K, used 102400K [0xfffffffdd0000000, 0xfffffffe0e800000, 0xfffffffe0e800000)
eden space 819200K, 0% used [0xfffffffdd0000000, 0xfffffffdd0000000, 0xfffffffe02000000)
from space 102400K, 100% used [0xfffffffe02000000, 0xfffffffe08400000, 0xfffffffe08400000)
to space 102400K, 0% used [0xfffffffe08400000, 0xfffffffe08400000, 0xfffffffe0e800000)
concurrent mark-sweep generation total 5136384K, used 3717226K [0xfffffffe0e800000, 0xffffffff48000000, 0xffffffff48000000)
concurrent-mark-sweep perm gen total 524288K, used 243740K [0xffffffff48000000, 0xffffffff68000000, 0xffffffff73800000)
}
CMS: abort preclean due to time 1761122.392: [CMS-concurrent-abortable-preclean: 4.729/5.490 secs] [Times: user=11.71 sys=0.97, real=5.49 secs]
1761122.401: [GC[YG occupancy: 177317 K (921600 K)]1761122.401: [Rescan (parallel) , 0.0250334 secs]1761122.427: [weak refs processing, 0.0002699 secs]1761122.427: [class unloading, 0.0817179 secs]1761122.509: [scrub symbol & string tables, 0.1383120 secs] [1 CMS-remark: 3717226K(5136384K)] 3894544K(6057984K), 0.3327016 secs] [Times: user=0.55 sys=0.04, real=0.33 secs]
1761122.735: [CMS-concurrent-sweep-start]
1761126.843: [CMS-concurrent-sweep: 4.042/4.108 secs] [Times: user=6.70 sys=0.39, real=4.11 secs]
1761126.844: [CMS-concurrent-reset-start]
1761126.907: [CMS-concurrent-reset: 0.063/0.063 secs] [Times: user=0.11 sys=0.00, real=0.06 secs]
1761127.142: [GC [1 CMS-initial-mark: 3701154K(5136384K)] 4056638K(6057984K), 0.2853309 secs] [Times: user=0.29 sys=0.00, real=0.29 secs]
1761127.428: [CMS-concurrent-mark-start]
1761131.876: [CMS-concurrent-mark: 4.398/4.448 secs] [Times: user=28.46 sys=1.55, real=4.45 secs]
1761131.877: [CMS-concurrent-preclean-start]
1761132.185: [CMS-concurrent-preclean: 0.305/0.308 secs] [Times: user=0.60 sys=0.05, real=0.31 secs]
1761132.186: [CMS-concurrent-abortable-preclean-start]
CMS: abort preclean due to time 1761137.243: [CMS-concurrent-abortable-preclean: 5.029/5.058 secs] [Times: user=9.88 sys=0.42, real=5.06 secs]
1761137.248: [GC[YG occupancy: 783876 K (921600 K)]1761137.248: [Rescan (parallel) , 0.5402015 secs]1761137.789: [weak refs processing, 0.0022809 secs]1761137.791: [class unloading, 0.1556933 secs]1761137.947: [scrub symbol & string tables, 0.1291759 secs] [1 CMS-remark: 3701154K(5136384K)] 4485030K(6057984K), 0.9154842 secs] [Times: user=1.67 sys=0.97, real=0.92 secs]
1761138.164: [CMS-concurrent-sweep-start]
{Heap before GC invocations=23862 (full 1468):
par new generation total 921600K, used 920346K [0xfffffffdd0000000, 0xfffffffe0e800000, 0xfffffffe0e800000)
eden space 819200K, 99% used [0xfffffffdd0000000, 0xfffffffe01ec6a48, 0xfffffffe02000000)
from space 102400K, 100% used [0xfffffffe02000000, 0xfffffffe08400000, 0xfffffffe08400000)
to space 102400K, 0% used [0xfffffffe08400000, 0xfffffffe08400000, 0xfffffffe0e800000)
concurrent mark-sweep generation total 5136384K, used 3694838K [0xfffffffe0e800000, 0xffffffff48000000, 0xffffffff48000000)
concurrent-mark-sweep perm gen total 524288K, used 243810K [0xffffffff48000000, 0xffffffff68000000, 0xffffffff73800000)
1761140.028: [GC 1761140.028: [ParNew: 920346K->102400K(921600K), 0.4882607 secs] 4615185K->4017461K(6057984K), 0.4886748 secs] [Times: user=2.71 sys=0.20, real=0.49 secs]
Heap after GC invocations=23863 (full 1468):
par new generation total 921600K, used 102400K [0xfffffffdd0000000, 0xfffffffe0e800000, 0xfffffffe0e800000)
eden space 819200K, 0% used [0xfffffffdd0000000, 0xfffffffdd0000000, 0xfffffffe02000000)
from space 102400K, 100% used [0xfffffffe08400000, 0xfffffffe0e800000, 0xfffffffe0e800000)
to space 102400K, 0% used [0xfffffffe02000000, 0xfffffffe02000000, 0xfffffffe08400000)
concurrent mark-sweep generation total 5136384K, used 3915061K [0xfffffffe0e800000, 0xffffffff48000000, 0xffffffff48000000)
concurrent-mark-sweep perm gen total 524288K, used 243810K [0xffffffff48000000, 0xffffffff68000000, 0xffffffff73800000)
}
1761142.726: [CMS-concurrent-sweep: 4.011/4.562 secs] [Times: user=12.54 sys=0.74, real=4.56 secs]
1761142.727: [CMS-concurrent-reset-start]
1761142.791: [CMS-concurrent-reset: 0.064/0.064 secs] [Times: user=0.16 sys=0.01, real=0.06 secs]
1761143.233: [GC [1 CMS-initial-mark: 3852859K(5136384K)] 4152461K(6057984K), 0.2340877 secs] [Times: user=0.23 sys=0.00, real=0.23 secs]
1761143.467: [CMS-concurrent-mark-start]
1761147.673: [CMS-concurrent-mark: 4.182/4.205 secs] [Times: user=26.19 sys=1.27, real=4.21 secs]
1761147.673: [CMS-concurrent-preclean-start]
1761147.978: [CMS-concurrent-preclean: 0.300/0.304 secs] [Times: user=0.44 sys=0.02, real=0.30 secs]
1761147.978: [CMS-concurrent-abortable-preclean-start]
{Heap before GC invocations=23863 (full 1469):
par new generation total 921600K, used 602663K [0xfffffffdd0000000, 0xfffffffe0e800000, 0xfffffffe0e800000)
eden space 819200K, 61% used [0xfffffffdd0000000, 0xfffffffdee889c90, 0xfffffffe02000000)
from space 102400K, 100% used [0xfffffffe08400000, 0xfffffffe0e800000, 0xfffffffe0e800000)
to space 102400K, 0% used [0xfffffffe02000000, 0xfffffffe02000000, 0xfffffffe08400000)
concurrent mark-sweep generation total 5136384K, used 3852859K [0xfffffffe0e800000, 0xffffffff48000000, 0xffffffff48000000)
concurrent-mark-sweep perm gen total 524288K, used 243656K [0xffffffff48000000, 0xffffffff68000000, 0xffffffff73800000)
1761152.969: [GC 1761152.969: [ParNew: 602663K->102400K(921600K), 0.4710031 secs]1761153.440: [CMS CMS: abort preclean due to time 1761155.705: [CMS-concurrent-abortable-preclean: 6.957/7.726 secs] [Times: user=13.02 sys=0.48, real=7.73 secs]
(concurrent mode failure): 4005428K->3905404K(5136384K), 32.6670849 secs] 4455522K->3905404K(6057984K), [CMS Perm : 243656K->243327K(524288K)], 33.1389061 secs] [Times: user=35.38 sys=0.26, real=33.14 secs]
Heap after GC invocations=23864 (full 1470):
par new generation total 921600K, used 0K [0xfffffffdd0000000, 0xfffffffe0e800000, 0xfffffffe0e800000)
eden space 819200K, 0% used [0xfffffffdd0000000, 0xfffffffdd0000000, 0xfffffffe02000000)
from space 102400K, 0% used [0xfffffffe02000000, 0xfffffffe02000000, 0xfffffffe08400000)
to space 102400K, 0% used [0xfffffffe08400000, 0xfffffffe08400000, 0xfffffffe0e800000)
concurrent mark-sweep generation total 5136384K, used 3905404K [0xfffffffe0e800000, 0xffffffff48000000, 0xffffffff48000000)
concurrent-mark-sweep perm gen total 524288K, used 243327K [0xffffffff48000000, 0xffffffff68000000, 0xffffffff73800000)
}
1761187.694: [GC [1 CMS-initial-mark: 4953978K(5136384K)] 4965714K(6057984K), 0.0131890 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
1761187.708: [CMS-concurrent-mark-start]
1761191.965: [CMS-concurrent-mark: 3.634/4.257 secs] [Times: user=32.76 sys=1.91, real=4.26 secs]
1761191.966: [CMS-concurrent-preclean-start]
1761192.543: [CMS-concurrent-preclean: 0.553/0.577 secs] [Times: user=1.56 sys=0.12, real=0.58 secs]
1761192.544: [CMS-concurrent-abortable-preclean-start]
CMS: abort preclean due to time 1761197.612: [CMS-concurrent-abortable-preclean: 2.079/5.068 secs] [Times: user=9.11 sys=0.60, real=5.07 secs]
1761197.617: [GC[YG occupancy: 813510 K (921600 K)]1761197.618: [Rescan (parallel) , 0.7500635 secs]1761198.368: [weak refs processing, 0.0020064 secs]1761198.370: [class unloading, 0.0823783 secs]1761198.453: [scrub symbol & string tables, 0.1278387 secs] [1 CMS-remark: 4953978K(5136384K)] 5767489K(6057984K), 1.0496971 secs] [Times: user=2.69 sys=1.79, real=1.05 secs]
1761198.668: [CMS-concurrent-sweep-start]
{Heap before GC invocations=23864 (full 1471):
par new generation total 921600K, used 819200K [0xfffffffdd0000000, 0xfffffffe0e800000, 0xfffffffe0e800000)
eden space 819200K, 100% used [0xfffffffdd0000000, 0xfffffffe02000000, 0xfffffffe02000000)
from space 102400K, 0% used [0xfffffffe02000000, 0xfffffffe02000000, 0xfffffffe08400000)
to space 102400K, 0% used [0xfffffffe08400000, 0xfffffffe08400000, 0xfffffffe0e800000)
concurrent mark-sweep generation total 5136384K, used 4953976K [0xfffffffe0e800000, 0xffffffff48000000, 0xffffffff48000000)
concurrent-mark-sweep perm gen total 524288K, used 243422K [0xffffffff48000000, 0xffffffff68000000, 0xffffffff73800000)
1761198.700: [GC 1761198.700: [ParNew: 819200K->819200K(921600K), 0.0000919 secs]1761198.700: [CMS1761202.072: [CMS-concurrent-sweep: 3.389/3.404 secs] [Times: user=3.60 sys=0.04, real=3.40 secs]
(concurrent mode failure): 4953976K->3789438K(5136384K), 32.6623615 secs] 5773176K->3789438K(6057984K), [CMS Perm : 243422K->243328K(524288K)], 32.6632802 secs] [Times: user=32.58 sys=0.03, real=32.66 secs]
Heap after GC invocations=23865 (full 1472):
par new generation total 921600K, used 0K [0xfffffffdd0000000, 0xfffffffe0e800000, 0xfffffffe0e800000)
eden space 819200K, 0% used [0xfffffffdd0000000, 0xfffffffdd0000000, 0xfffffffe02000000)
from space 102400K, 0% used [0xfffffffe02000000, 0xfffffffe02000000, 0xfffffffe08400000)
to space 102400K, 0% used [0xfffffffe08400000, 0xfffffffe08400000, 0xfffffffe0e800000)
concurrent mark-sweep generation total 5136384K, used 3789438K [0xfffffffe0e800000, 0xffffffff48000000, 0xffffffff48000000)
concurrent-mark-sweep perm gen total 524288K, used 243328K [0xffffffff48000000, 0xffffffff68000000, 0xffffffff73800000)
}
1761231.418: [GC [1 CMS-initial-mark: 3789438K(5136384K)] 3883471K(6057984K), 0.0609784 secs] [Times: user=0.06 sys=0.01, real=0.06 secs]
1761231.480: [CMS-concurrent-mark-start]
1761236.061: [CMS-concurrent-mark: 3.752/4.580 secs] [Times: user=34.48 sys=2.81, real=4.58 secs]
1761236.061: [CMS-concurrent-preclean-start]
1761236.428: [CMS-concurrent-preclean: 0.358/0.367 secs] [Times: user=0.46 sys=0.01, real=0.37 secs]
1761236.429: [CMS-concurrent-abortable-preclean-start]
CMS: abort preclean due to time 1761241.488: [CMS-concurrent-abortable-preclean: 2.384/5.059 secs] [Times: user=5.30 sys=0.75, real=5.06 secs]
1761241.497: [GC[YG occupancy: 787969 K (921600 K)]1761241.497: [Rescan (parallel) , 0.5938799 secs]1761242.091: [weak refs processing, 0.0067469 secs]1761242.098: [class unloading, 0.0826078 secs]1761242.181: [scrub symbol & string tables, 0.1308434 secs] [1 CMS-remark: 3789438K(5136384K)] 4577408K(6057984K), 0.9017583 secs] [Times: user=2.66 sys=2.07, real=0.90 secs]
1761242.400: [CMS-concurrent-sweep-start]
{Heap before GC invocations=23865 (full 1473):
par new generation total 921600K, used 819200K [0xfffffffdd0000000, 0xfffffffe0e800000, 0xfffffffe0e800000)
eden space 819200K, 100% used [0xfffffffdd0000000, 0xfffffffe02000000, 0xfffffffe02000000)
from space 102400K, 0% used [0xfffffffe02000000, 0xfffffffe02000000, 0xfffffffe08400000)
to space 102400K, 0% used [0xfffffffe08400000, 0xfffffffe08400000, 0xfffffffe0e800000)
concurrent mark-sweep generation total 5136384K, used 3789391K [0xfffffffe0e800000, 0xffffffff48000000, 0xffffffff48000000)
concurrent-mark-sweep perm gen total 524288K, used 243406K [0xffffffff48000000, 0xffffffff68000000, 0xffffffff73800000)
1761242.586: [GC 1761242.586: [ParNew: 819200K->102400K(921600K), 0.1871926 secs] 4608591K->3940305K(6057984K), 0.1879045 secs] [Times: user=0.93 sys=0.05, real=0.19 secs]
Heap after GC invocations=23866 (full 1473):
par new generation total 921600K, used 102400K [0xfffffffdd0000000, 0xfffffffe0e800000, 0xfffffffe0e800000)
eden space 819200K, 0% used [0xfffffffdd0000000, 0xfffffffdd0000000, 0xfffffffe02000000)
from space 102400K, 100% used [0xfffffffe08400000, 0xfffffffe0e800000, 0xfffffffe0e800000)
to space 102400K, 0% used [0xfffffffe02000000, 0xfffffffe02000000, 0xfffffffe08400000)
concurrent mark-sweep generation total 5136384K, used 3837905K [0xfffffffe0e800000, 0xffffffff48000000, 0xffffffff48000000)
concurrent-mark-sweep perm gen total 524288K, used 243406K [0xffffffff48000000, 0xffffffff68000000, 0xffffffff73800000)
}
1761245.857: [CMS-concurrent-sweep: 3.225/3.457 secs] [Times: user=6.21 sys=0.52, real=3.46 secs]
1761245.858: [CMS-concurrent-reset-start]
1761245.922: [CMS-concurrent-reset: 0.064/0.064 secs] [Times: user=0.08 sys=0.01, real=0.06 secs]
1761247.301: [GC [1 CMS-initial-mark: 3676150K(5136384K)] 3952072K(6057984K), 0.2229528 secs] [Times: user=0.22 sys=0.00, real=0.22 secs]
1761247.525: [CMS-concurrent-mark-start]
1761251.076: [CMS-concurrent-mark: 3.510/3.551 secs] [Times: user=23.68 sys=0.85, real=3.55 secs]
1761251.076: [CMS-concurrent-preclean-start]
1761251.375: [CMS-concurrent-preclean: 0.295/0.298 secs] [Times: user=0.72 sys=0.04, real=0.30 secs]
1761251.375: [CMS-concurrent-abortable-preclean-start]
CMS: abort preclean due to time 1761256.460: [CMS-concurrent-abortable-preclean: 5.012/5.085 secs] [Times: user=9.93 sys=0.99, real=5.09 secs]
1761256.469: [GC[YG occupancy: 720909 K (921600 K)]1761256.469: [Rescan (parallel) , 0.4663462 secs]1761256.936: [weak refs processing, 0.0153453 secs]1761256.951: [class unloading, 0.0833874 secs]1761257.035: [scrub symbol & string tables, 0.1289153 secs] [1 CMS-remark: 3676150K(5136384K)] 4397060K(6057984K), 0.7879219 secs] [Times: user=1.55 sys=0.96, real=0.79 secs]
1761257.258: [CMS-concurrent-sweep-start]
{Heap before GC invocations=23866 (full 1474):
par new generation total 921600K, used 921600K [0xfffffffdd0000000, 0xfffffffe0e800000, 0xfffffffe0e800000)
eden space 819200K, 100% used [0xfffffffdd0000000, 0xfffffffe02000000, 0xfffffffe02000000)
from space 102400K, 100% used [0xfffffffe08400000, 0xfffffffe0e800000, 0xfffffffe0e800000)
to space 102400K, 0% used [0xfffffffe02000000, 0xfffffffe02000000, 0xfffffffe08400000)
concurrent mark-sweep generation total 5136384K, used 3669509K [0xfffffffe0e800000, 0xffffffff48000000, 0xffffffff48000000)
concurrent-mark-sweep perm gen total 524288K, used 243414K [0xffffffff48000000, 0xffffffff68000000, 0xffffffff73800000)
1761259.137: [GC 1761259.138: [ParNew: 921600K->102400K(921600K), 0.3975686 secs] 4591109K->3894075K(6057984K), 0.3981608 secs] [Times: user=1.65 sys=0.15, real=0.40 secs]
Heap after GC invocations=23867 (full 1474):
par new generation total 921600K, used 102400K [0xfffffffdd0000000, 0xfffffffe0e800000, 0xfffffffe0e800000)
eden space 819200K, 0% used [0xfffffffdd0000000, 0xfffffffdd0000000, 0xfffffffe02000000)
from space 102400K, 100% used [0xfffffffe02000000, 0xfffffffe08400000, 0xfffffffe08400000)
to space 102400K, 0% used [0xfffffffe08400000, 0xfffffffe08400000, 0xfffffffe0e800000)
concurrent mark-sweep generation total 5136384K, used 3791675K [0xfffffffe0e800000, 0xffffffff48000000, 0xffffffff48000000)
concurrent-mark-sweep perm gen total 524288K, used 243414K [0xffffffff48000000, 0xffffffff68000000, 0xffffffff73800000)
}
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://mail.openjdk.java.net/pipermail/hotspot-gc-use/attachments/20120412/16cc56a7/attachment-0001.html
-------------- next part --------------
An embedded and charset-unspecified text was scrubbed...
Name: CMS Failure.txt
Url: http://mail.openjdk.java.net/pipermail/hotspot-gc-use/attachments/20120412/16cc56a7/CMSFailure-0001.txt
-------------- next part --------------
An embedded and charset-unspecified text was scrubbed...
Name: PARNEW Failure.txt
Url: http://mail.openjdk.java.net/pipermail/hotspot-gc-use/attachments/20120412/16cc56a7/PARNEWFailure-0001.txt
More information about the hotspot-gc-use
mailing list