podivne se chovajici GC

Ladislav Thon ladicek na gmail.com
Úterý Listopad 9 23:01:23 CET 2010


Já bych se dneska, při neznámých hláškách v logu GC, obrátil na
hotspot-gc-use na openjdk.java.net. Tady bych asi pomoc nečekal.

That said: taky bych se nejdřív poohlížel v aplikaci. 7 giga pro young gen
mi přijde docela šílené, ale zdá se, že to GC zvládá docela v pohodě. Já
bych nejdřív zkusil ParNewGC a CMS
(-XX:+UseParallelGC, -XX:+UseConcMarkSweepGC a příbuzné), ale to prostě
proto, že se mi s nimi podařilo vyřešit pár problémů, nechci tvrdit, že jsou
univerzálně nejlepší.

Jo a pro ladění paměťových problémů doporučuju

-XX:+HeapDumpOnOutOfMemoryError
-XX:HeapDumpPath=/home/.../dumps

(resp. jmap -dump) a Eclipse Memory Analyzer (http://eclipse.org/mat/).

LT

Dne 9. listopadu 2010 16:09 "Zdeněk Troníček" <tronicek na fit.cvut.cz>napsal(a):

> Ahoj,
>
> vypadá to, že hned po GC-- následuje vždy Full GC. I časy souhlasí, takže
> to vypadá, že GC-- by mohla být hláška "nepodařilo se mi uvolnit pamět
> pomocí Minor GC, spouštím Full GC".
>
> Kde došlo ke snížení na 8 GB? Já tam vidím pořád 12 GB:
>
> > 2010-11-09T14:08:17.470+0100: 71707.559: [GC [PSYoungGen:
> > 4001888K->167105K(4019968K)] 10396311K->6561528K(12408576K), 0.1618780
>                                                    ^^^^^^^^^ tady
>
> Jinak to, že Full GC neuvolní paměť je smutné, zvlášť při takovýchto
> hodnotách. Na důvod bych se ptal v aplikaci :).
> Doporučit můžu Memory profiler v NetBeans.
>
> Z.
> --
> Zdenek Tronicek
> FIT CTU in Prague
>
>
> Tomas Bezdek napsal(a):
> > 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ší část ---------------
HTML příloha byla odstraněna...
URL: <http://amaio.cz/pipermail/konference/attachments/20101109/94f04aa4/attachment.htm>


Další informace o konferenci Konference