Tuning advice

Tony Printezis tony.printezis at sun.com
Wed Mar 5 19:37:59 UTC 2008 

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 <http://www.steris.com>
>> 440-392-7089
>>
>> Internal Sites
>>
>>     * UNIX Operations
>>       <http://bis.steris.com/sites/EnterpriseOps/UNIX/default.aspx>
>>     * STERIS Blogs  <http://blogs.steris.com/roller>
>>     * STERIS Wiki <http://wikis.steris.com>
>>     * STERIS Java Instant Messanger <http://crystal.steris.com/im>
>>
>>  
>>
>>
>> ------------------------------------------------------------------------
>>
>> _______________________________________________
>> 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

More information about the hotspot-gc-dev mailing list