Tuning advice
Y Srinivas Ramakrishna
Y.S.Ramakrishna at Sun.COM
Wed Mar 5 19:48:44 UTC 2008
Also have you tried -server (instead of the client jvm you are using) to
see if & by how much it improves performance of the application? (once
you've eliminated the RMI-induced GC's as stated below).
-- ramki
----- Original Message -----
From: Tony Printezis <tony.printezis at sun.com>
Date: Wednesday, March 5, 2008 11:41 am
Subject: Re: Tuning advice
To: Jon Masamitsu <Jon.Masamitsu at Sun.COM>
Cc: hotspot-gc-use at openjdk.java.net, "Shaffer, Kurt" <Kurt_Shaffer at steris.com>
> Kurt,
>
> Do you use RMI? By default, RMI calls Full GC every 60 seconds for the
>
> correct operation of its distributed GC algorithm. The default
> behavior
> has been changed in 6.0 to be something less frequent (once an hour I
>
> believe...).
>
> Tony
>
> Jon Masamitsu wrote:
> > Kurt,
> >
> > The full GC's in the log fragment that you sent are at
> > very regular intervals so there might be something
> > in the system that is invoking System.gc(). Full
> > GC's normally happen when the heap is full and
> > the logs show that the heap is not yet full when
> > the full GC's happen. If the frequency of the full
> > GC's is a problem, you can use -XX:+DisableExplicitGC
> > to effectively turn off System.gc().
> >
> > Other than that, it does not look like GC is a problem. The
> > full GC's are all under 6 seconds and are about 60 seconds
> > apart so I don't see how that can be causing the rendering
> > of a page to take 40 seconds. Are there other parts of the
> > gc log that show longer and/or more frequent GC pauses?
> >
> > Jon
> >
> > Shaffer, Kurt wrote:
> >
> >> Hello,
> >>
> >>
> >>
> >> We are looking for some tuning recommendations for the following
> >> environment. I am not very familiar with Java so I am seeking any
> help.
> >>
> >>
> >>
> >>
> >>> 4 cpus (Ultra Sparc III 900MHz) / 8GB memory
> >>>
> >>> java version "1.4.2_13"
> >>>
> >>> Java(TM) 2 Runtime Environment, Standard Edition (build 1.4.2_13-b06)
> >>>
> >>> Java HotSpot(TM) Client VM (build 1.4.2_13-b06, mixed mode)
> >>>
> >>> <Property name="wt.manager.cmd.MethodServer.java.command"
> >>>
> >>> overridable="true" value="$(wt.java.cmd.quoted) -server -classpath
> >>>
> >>> $(wt.java.clas
> >>>
> >>> spath.quoted) -Djava.protocol.handler.pkgs\=HTTPClient
> >>>
> >>> -DHTTPClient.disableKeepAlives\=true
> >>>
> >>> -DHTTPClient.dontChunkRequests\=true -Xss2M -Xms51
> >>>
> >>> 2m -Xmx1024m -noverify -verbose:gc -XX:+UseParallelGC
> >>>
> >>> -XX:ParallelGCThreads=20 -XX:+PrintGCTimeStamps -XX:+PrintGCDetails
> >>>
> >>> -Xloggc:$(wt.logs.di
> >>>
> >>> r)$(dir.sep)ms_gc.log wt.method.MethodServerMain"/>
> >>>
> >>> Application is PTC Windchill
> >>>
> >>> We have seen very slow response times from the users standpoint,
> when
> >>>
> >>> they login it takes up to 15 seconds to render the display, when
> they
> >>>
> >>> are navigating through different views in their browser it can
> take 40
> >>>
> >>> seconds or longer to display pages.
> >>>
> >> 63153.891: [GC 314184K->242537K(470016K), 0.5394510 secs]
> >>
> >> 63154.431: [Full GC 242537K->222908K(470464K), 4.3961010 secs]
> >>
> >> 63218.867: [GC 237602K->265484K(470464K), 0.4835425 secs]
> >>
> >> 63219.351: [Full GC 265484K->219722K(468800K), 4.0777246 secs]
> >>
> >> 63229.962: [GC 283466K->275130K(470016K), 0.9633742 secs]
> >>
> >> 63246.178: [GC 296442K->232743K(470016K), 0.2712703 secs]
> >>
> >> 63250.526: [GC 298919K->284345K(474432K), 0.6691910 secs]
> >>
> >> 63253.376: [GC 307833K->234235K(474432K), 0.7393747 secs]
> >>
> >> 63259.981: [GC 309243K->288777K(475584K), 0.7275010 secs]
> >>
> >> 63262.366: [GC 324297K->243675K(475584K), 0.5750282 secs]
> >>
> >> 63267.115: [GC 320987K->275409K(475712K), 1.0370391 secs]
> >>
> >> 63270.833: [GC 331025K->248161K(475712K), 0.8789762 secs]
> >>
> >> 63274.475: [GC 325729K->263489K(500032K), 1.6077160 secs]
> >>
> >> 63280.994: [GC 341057K->263713K(500032K), 0.9178316 secs]
> >>
> >> 63283.436: [GC 280071K->256830K(534464K), 0.6641916 secs]
> >>
> >> 63284.101: [Full GC 256830K->214330K(542528K), 4.6351180 secs]
> >>
> >> 63305.164: [GC 349882K->281490K(542528K), 0.6127869 secs]
> >>
> >> 63316.432: [GC 376658K->251450K(539136K), 1.0353315 secs]
> >>
> >> 63348.746: [GC 309133K->310170K(539136K), 0.3874349 secs]
> >>
> >> 63349.134: [Full GC 310170K->194499K(470208K), 4.9789538 secs]
> >>
> >> 63370.780: [GC 261059K->241509K(470784K), 0.4214626 secs]
> >>
> >> 63374.528: [GC 276453K->215817K(470784K), 0.8574863 secs]
> >>
> >> 63381.942: [GC 283529K->246533K(474816K), 0.6949210 secs]
> >>
> >> 63389.788: [GC 285893K->216402K(474816K), 1.3839849 secs]
> >>
> >> 63414.126: [GC 237126K->244639K(477696K), 0.6417762 secs]
> >>
> >> 63414.768: [Full GC 244639K->212594K(477696K), 4.6969125 secs]
> >>
> >> 63437.799: [GC 294130K->269346K(477760K), 0.5160500 secs]
> >>
> >> 63441.657: [GC 306082K->225578K(477760K), 0.3883250 secs]
> >>
> >> 63454.008: [GC 307242K->279893K(480256K), 0.4979514 secs]
> >>
> >> 63458.126: [GC 314261K->232665K(480256K), 0.5394576 secs]
> >>
> >> 63470.586: [GC 319321K->283449K(484096K), 0.6432362 secs]
> >>
> >> 63473.498: [GC 320953K->237395K(484096K), 0.2825034 secs]
> >>
> >> 63479.613: [GC 299104K->294563K(484096K), 0.5962983 secs]
> >>
> >> 63480.210: [Full GC 294563K->220268K(483584K), 5.8936777 secs]
> >>
> >> 63524.720: [GC 313580K->295967K(483904K), 0.7195508 secs]
> >>
> >>
> >>
> >> PrintGCStats output
> >>
> >> what count total mean max stddev
> >>
> >> gen0(s) 1282 776.553 0.60574 3.605 0.3765
> >>
> >> gen1t(s) 823 1643.837 1.99737 11.139 1.0934
> >>
> >> GC(s) 2105 2420.391 1.14983 11.139 1.0074
> >>
> >> alloc(MB) 1282 -84202.223 -65.68036 169.752 101.4710
> >>
> >> promo(MB) 1230 -86070.940 -69.97637 333.249 103.2167
> >>
> >>
> >>
> >> alloc/elapsed_time = -84202.223 MB / 56876.807 s = -1.480 MB/s
> >>
> >> alloc/tot_cpu_time = -84202.223 MB / 227507.228 s = -0.370 MB/s
> >>
> >> alloc/mut_cpu_time = -84202.223 MB / 217825.665 s = -0.387 MB/s
> >>
> >> promo/elapsed_time = -86070.940 MB / 56876.807 s = -1.513 MB/s
> >>
> >> promo/gc0_time = -86070.940 MB / 0.000 s = 0.000 MB/s
> >>
> >> gc_seq_load = 9681.563 s / 227507.228 s = 4.255%
> >>
> >> gc_conc_load = 0.000 s / 227507.228 s = 0.000%
> >>
> >> gc_tot_load = 9681.563 s / 227507.228 s = 4.255%
> >>
> >>
> >>> Thankx
> >>>
> >>
> >>
> >> /Kurt Shaffer/
> >> UNIX Architect
> >> IT Enterprise Operations
> >> STERIS Corporation <
> >> 440-392-7089
> >>
> >> Internal Sites
> >>
> >> * UNIX Operations
> >> <
> >> * STERIS Blogs <
> >> * STERIS Wiki <
> >> * STERIS Java Instant Messanger <
> >>
> >>
> >>
> >>
> >> ------------------------------------------------------------------------
> >>
> >> _______________________________________________
> >> hotspot-gc-use mailing list
> >> hotspot-gc-use at openjdk.java.net
> >> http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
> >>
> > _______________________________________________
> > hotspot-gc-use mailing list
> > hotspot-gc-use at openjdk.java.net
> > http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
> >
>
> --
> ----------------------------------------------------------------------
> | Tony Printezis, Staff Engineer | Sun Microsystems Inc. |
> | | MS BUR02-311 |
> | e-mail: tony.printezis at sun.com | 35 Network Drive |
> | office: +1 781 442 0998 (x20998) | Burlington, MA01803-0902, USA |
> ----------------------------------------------------------------------
> e-mail client: Thunderbird (Solaris)
>
>
> _______________________________________________
> hotspot-gc-use mailing list
> hotspot-gc-use at openjdk.java.net
> http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
_______________________________________________
hotspot-gc-use mailing list
hotspot-gc-use at openjdk.java.net
http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
More information about the hotspot-gc-dev
mailing list