podivne se chovajici GC

Tomas Bezdek bezdek na studentagency.cz
Úterý Listopad 9 15:10:04 CET 2010


zdravim. v posledni dobe se mi v systemu zacala objevovat podivna
anomalie v gc, kterou jsem nikdy predtim nevidel. cas od casu se mi logu
objevi takovyto vypis


2010-11-09T14:08:17.470+0100: 71707.559: [GC [PSYoungGen:
4001888K->167105K(4019968K)] 10396311K->6561528K(12408576K), 0.1618780
secs] [Times: user=1.01 sys=0.01, real=0.16 secs]
2010-11-09T14:08:29.344+0100: 71719.433: [GC [PSYoungGen:
4019905K->174304K(3936000K)] 10414328K->6637297K(12324608K), 0.2540640
secs] [Times: user=1.98 sys=0.05, real=0.26 secs]
2010-11-09T14:08:38.085+0100: 71728.174: [GC [PSYoungGen:
3935968K->216309K(3977984K)] 10398961K->7073312K(12366592K), 0.9376000
secs] [Times: user=6.71 sys=0.27, real=0.94 secs]
2010-11-09T14:08:47.290+0100: 71737.379: [GC-- [PSYoungGen:
3490172K->3490172K(3977984K)] 10347175K->11414768K(12366592K), 2.6286760
secs] [Times: user=12.73 sys=0.60, real=2.62 secs]
2010-11-09T14:08:49.919+0100: 71740.008: [Full GC [PSYoungGen:
3490172K->0K(3977984K)] [ParOldGen: 7924595K->5428016K(8388608K)]
11414768K->5428016K(12366592K) [PSPermGen: 158384K->158307K(524288K)],
5.9359450 secs] [Times: user=26.03 sys=0.27, real=5.94 secs]
2010-11-09T14:08:58.415+0100: 71748.504: [GC [PSYoungGen:
3761664K->35611K(3632768K)] 9189680K->6512203K(12021376K), 2.8117950
secs] [Times: user=16.94 sys=0.97, real=2.81 secs]
2010-11-09T14:09:02.484+0100: 71752.573: [GC-- [PSYoungGen:
1940458K->1940458K(3632768K)] 8417050K->9465626K(12021376K), 1.3446770
secs] [Times: user=2.66 sys=0.02, real=1.34 secs]
2010-11-09T14:09:03.829+0100: 71753.917: [Full GC [PSYoungGen:
1940458K->0K(3632768K)] [ParOldGen: 7525168K->6743187K(8388608K)]
9465626K->6743187K(12021376K) [PSPermGen: 158321K->158307K(524288K)],
6.6371020 secs] [Times: user=31.12 sys=0.08, real=6.64 secs]
2010-11-09T14:09:12.190+0100: 71762.279: [GC-- [PSYoungGen:
2886758K->2886758K(3632768K)] 9629945K->9629945K(12021376K), 0.9702900
secs] [Times: user=1.21 sys=0.01, real=0.97 secs]
2010-11-09T14:09:13.160+0100: 71763.249: [Full GC [PSYoungGen:
2886758K->0K(3632768K)] [ParOldGen: 6743187K->6740932K(8388608K)]
9629945K->6740932K(12021376K) [PSPermGen: 158316K->158313K(524288K)],
5.4642480 secs] [Times: user=24.14 sys=0.15, real=5.47 secs]
2010-11-09T14:09:19.504+0100: 71769.593: [GC-- [PSYoungGen:
2182958K->2182958K(3632768K)] 8923890K->8923890K(12021376K), 0.6984480
secs] [Times: user=0.85 sys=0.01, real=0.69 secs]
2010-11-09T14:09:20.203+0100: 71770.292: [Full GC [PSYoungGen:
2182958K->2101063K(3632768K)] [ParOldGen: 6740932K->6727072K(8388608K)]
8923890K->8828136K(12021376K) [PSPermGen: 158318K->158318K(524288K)],
7.3179200 secs] [Times: user=32.31 sys=0.13, real=7.32 secs]
2010-11-09T14:09:27.521+0100: 71777.610: [GC-- [PSYoungGen:
2101063K->2101063K(3632768K)] 8828136K->8828136K(12021376K), 2.0094710
secs] [Times: user=5.70 sys=0.15, real=2.01 secs]
2010-11-09T14:09:29.531+0100: 71779.620: [Full GC [PSYoungGen:
2101063K->2100251K(3632768K)] [ParOldGen: 6727072K->6630428K(8388608K)]
8828136K->8730679K(12021376K) [PSPermGen: 158318K->153210K(524288K)],
6.3846660 secs] [Times: user=26.55 sys=0.01, real=6.38 secs]
2010-11-09T14:09:36.070+0100: 71786.159: [GC-- [PSYoungGen:
2207414K->2207414K(3632768K)] 8837843K->8837843K(12021376K), 1.9895860
secs] [Times: user=5.51 sys=0.13, real=1.99 secs]
2010-11-09T14:09:38.060+0100: 71788.149: [Full GC [PSYoungGen:
2207414K->0K(3632768K)] [ParOldGen: 6630428K->6637245K(8388608K)]
8837843K->6637245K(12021376K) [PSPermGen: 153478K->153473K(524288K)],
6.0174620 secs] [Times: user=28.16 sys=0.01, real=6.01 secs]
2010-11-09T14:09:45.053+0100: 71795.142: [GC-- [PSYoungGen:
2300992K->2300992K(3632768K)] 8938237K->8938237K(12021376K), 0.7588920
secs] [Times: user=0.99 sys=0.00, real=0.76 secs]
2010-11-09T14:09:45.813+0100: 71795.901: [Full GC [PSYoungGen:
2300992K->2120752K(3632768K)] [ParOldGen: 6637245K->6632816K(8388608K)]
8938237K->8753569K(12021376K) [PSPermGen: 154701K->154674K(524288K)],
7.6588520 secs] [Times: user=35.22 sys=1.10, real=7.66 secs]
2010-11-09T14:09:53.472+0100: 71803.560: [GC-- [PSYoungGen:
2120752K->2120752K(3632768K)] 8753569K->8753569K(12021376K), 1.7112710
secs] [Times: user=7.15 sys=0.16, real=1.71 secs]
2010-11-09T14:09:55.183+0100: 71805.272: [Full GC [PSYoungGen:
2120752K->2119123K(3632768K)] [ParOldGen: 6632816K->6632165K(8388608K)]
8753569K->8751288K(12021376K) [PSPermGen: 154674K->154169K(524288K)],
7.1219080 secs] [Times: user=28.40 sys=5.46, real=7.12 secs]
2010-11-09T14:10:02.501+0100: 71812.590: [GC-- [PSYoungGen:
2328236K->2328236K(3632768K)] 8960401K->8960401K(12021376K), 1.7660600
secs] [Times: user=6.96 sys=0.02, real=1.76 secs]
2010-11-09T14:10:04.268+0100: 71814.356: [Full GC [PSYoungGen:
2328236K->0K(3632768K)] [ParOldGen: 6632165K->6648195K(8388608K)]
8960401K->6648195K(12021376K) [PSPermGen: 154756K->154753K(524288K)],
5.1246850 secs] [Times: user=25.13 sys=0.00, real=5.13 secs]
2010-11-09T14:10:10.590+0100: 71820.679: [GC-- [PSYoungGen:
2815877K->2815877K(3632768K)] 9464072K->9464072K(12021376K), 0.9640850
secs] [Times: user=1.31 sys=0.01, real=0.97 secs]
2010-11-09T14:10:11.554+0100: 71821.643: [Full GC [PSYoungGen:
2815877K->2132916K(3632768K)] [ParOldGen: 6648195K->6614435K(8388608K)]
9464072K->8747352K(12021376K) [PSPermGen: 155534K->155427K(524288K)],
10.9547060 secs] [Times: user=31.66 sys=0.92, real=10.95 secs]
2010-11-09T14:10:22.509+0100: 71832.598: [GC-- [PSYoungGen:
2132916K->2132916K(3632768K)] 8747352K->8747352K(12021376K), 1.7138770
secs] [Times: user=6.77 sys=0.02, real=1.71 secs]
2010-11-09T14:10:24.223+0100: 71834.312: [Full GC [PSYoungGen:
2132916K->2125305K(3632768K)] [ParOldGen: 6614435K->6609793K(8388608K)]
8747352K->8735099K(12021376K) [PSPermGen: 155427K->153174K(524288K)],
6.3822970 secs] [Times: user=29.15 sys=0.07, real=6.39 secs]
2010-11-09T14:10:31.605+0100: 71841.694: [GC-- [PSYoungGen:
3416424K->3416424K(3632768K)] 10026218K->10026218K(12021376K), 2.2010180
secs] [Times: user=7.18 sys=0.10, real=2.20 secs]
2010-11-09T14:10:33.807+0100: 71843.895: [Full GC [PSYoungGen:
3416424K->0K(3632768K)] [ParOldGen: 6609793K->6660035K(8388608K)]
10026218K->6660035K(12021376K) [PSPermGen: 155413K->155283K(524288K)],
4.9529220 secs] [Times: user=23.47 sys=0.02, real=4.95 secs]
2010-11-09T14:10:41.503+0100: 71851.592: [GC [PSYoungGen:
3416448K->103097K(3805376K)] 10076483K->6763132K(12193984K), 0.1046010
secs] [Times: user=0.65 sys=0.00, real=0.11 secs]
2010-11-09T14:10:44.076+0100: 71854.165: [GC [PSYoungGen:
3519545K->153084K(3833088K)] 10179580K->6813120K(12221696K), 0.1352450
secs] [Times: user=0.88 sys=0.01, real=0.14 secs]
2010-11-09T14:10:47.349+0100: 71857.438: [GC [PSYoungGen:
3606332K->218657K(3814464K)] 10266368K->6878692K(12203072K), 0.1683720
secs] [Times: user=1.02 sys=0.00, real=0.16 secs]


neni mi uplne jasne proc se FullGC nekolikrat po sobe nepodari uvolnit
zadnou pamet, proc mi snizi velikost pameti z 12 na 8 gb a uz vubec
netusim co znamena GC--. nesetkal se nekdo z vas s podobnym problemem?

konfiguraci jvm mam nasledujici:

JAVA_OPTS="\
-verbose:gc \
-XX:+PrintGC \
-XX:+PrintGCTimeStamps \
-XX:+PrintGCDateStamps \
-XX:+PrintGCDetails \
-XX:+PrintTenuringDistribution \
-Xloggc:$CATALINA_HOME/logs/catalina.gc \
\
-Dcom.sun.management.jmxremote \
-Dcom.sun.management.jmxremote.port=9000 \
-Dcom.sun.management.jmxremote.ssl=false \
-Dcom.sun.management.jmxremote.authenticate=false \
\
-Xms14g \
-Xmx14g \
-XX:NewSize=7g \
-XX:PermSize=512m \
-XX:MaxPermSize=1024m \
-XX:+UseParallelOldGC \
-XX:+DisableExplicitGC \
\
-Djava.rmi.server.hostname=localhost \
-Djava.net.preferIPv4Stack=true \
-Djava.awt.headless=true \
"

diky za jakoukoliv pomoc

--tb


Další informace o konferenci Konference