Our Windchill 9.1 M060 system is performing excessive full garbage collections (making the server unresponsive to client requests.) I have already read the Windchill Performance Tuning Guide and tried to follow it. We also use many of the default settings given by the Windchill Configuration Assistant. Any tips would be appreciated.
Our server is Windows Server 2003 64bit edition with 3.33GHz CPU and 16GB of ram. It has has four cores.
We have 1 background and 1 foreground method server. Both are running 64 bit java and executeQueues is false. The db is on the same server. There is 1 GB of ram free when the server is running. We average 30 concurrent users. It is a virtual server (with a 6+1 Raid) with a total of 64 sata2 hard drives.
This is the only revelant snippet from wttomcat_start.bat.
set JAVA_OPTS=-XX:+AggressiveHeap -XX:+UseParallelGC -XX:ParallelGCThreads=4 -XX:TargetSurvivorRatio=90 -XX:MaxTenuringThreshold=31 -verbose:gc -XX:+PrintGCTimeStamps -XX:+PrintGCDetails -server -XX:NewSize=532M -XX:MaxNewSize=532M -XX:SurvivorRatio=8 -XX:PermSize=1024M -XX:MaxPermSize=1024M -Xms2048M -Xmx2048M -Xmn1024M -Djava.awt.headless=true -Dwt.context.defaultLocalResourcesOnly=true
This is the only revelant snippet from wt.properties.
wt.manager.maxHeap=320
wt.manager.minHeap=320
wt.method.maxHeap=2407
wt.method.minHeap=2407
wt.manager.cmd.ServerManager.nonibm.java.args=\ -XX\:NewSize\=64m -XX\:MaxNewSize\=64m -XX\:SurvivorRatio\=8 -XX\:PermSize\=64m -XX\:MaxPermSize\=64m -Xloggc\:$(wt.logs.dir)$(dir.sep){1}-{2,date,yyMMddHHmmssSSS}-{0}-GC.log -XX\:+PrintGCDetails -XX\:+PrintGCTimeStamps
wt.manager.cmd.MethodServer.nonibm.java.args=-XX\:ReservedCodeCacheSize\=512m -XX\:NewSize\=963m -XX\:MaxNewSize\=963m -XX\:SurvivorRatio\=4 -XX\:PermSize\=512m -XX\:MaxPermSize\=512m -Xloggc\:$(wt.logs.dir)$(dir.sep){1}-{2,date,yyMMddHHmmssSSS}-{0}-GC.log -XX\:+PrintGCDetails -XX\:+PrintGCTimeStamps -XX\:ParallelGCThreads\=4
This is a snippet from our MethodServer-GC.log
209496.593: [Full GC (System) [PSYoungGen: 3170K->0K(953664K)] [PSOldGen: 215745K->210794K(1479680K)] 218915K->210794K(2433344K) [PSPermGen: 187942K->187247K(524288K)], 1.8174989 secs] [Times: user=1.16 sys=0.08, real=1.83 secs]
209614.943: [GC [PSYoungGen: 717826K->2976K(956800K)] 928620K->213770K(2436480K), 0.0185485 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]
209614.961: [Full GC (System) [PSYoungGen: 2976K->0K(956800K)] [PSOldGen: 210794K->213616K(1479680K)] 213770K->213616K(2436480K) [PSPermGen: 187328K->187328K(524288K)], 0.8626971 secs] [Times: user=0.83 sys=0.02, real=0.86 secs]
209796.386: [GC [PSYoungGen: 925254K->4194K(955712K)] 1138871K->217811K(2435392K), 0.0066067 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
209958.437: [GC [PSYoungGen: 930341K->3161K(959296K)] 1143958K->217459K(2438976K), 0.3222172 secs] [Times: user=0.08 sys=0.03, real=0.33 secs]
210180.255: [GC [PSYoungGen: 933209K->16121K(947456K)] 1147508K->231023K(2427136K), 0.0632779 secs] [Times: user=0.01 sys=0.03, real=0.08 secs]
210214.942: [GC [PSYoungGen: 343650K->575K(958656K)] 558552K->216878K(2438336K), 0.0025942 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
210214.945: [Full GC (System) [PSYoungGen: 575K->0K(958656K)] [PSOldGen: 216302K->216822K(1479680K)] 216878K->216822K(2438336K) [PSPermGen: 187512K->187512K(524288K)], 0.8245276 secs] [Times: user=0.81 sys=0.00, real=0.81 secs]
210401.730: [GC [PSYoungGen: 930501K->13866K(958080K)] 1147324K->230688K(2437760K), 0.0058652 secs] [Times: user=0.03 sys=0.00, real=0.02 secs]
210572.984: [GC [PSYoungGen: 943243K->24337K(950400K)] 1160066K->242380K(2430080K), 0.1350911 secs] [Times: user=0.03 sys=0.05, real=0.14 secs]
210707.562: [GC [PSYoungGen: 946157K->4926K(954368K)] 1164200K->224001K(2434048K), 0.1824766 secs] [Times: user=0.05 sys=0.00, real=0.19 secs]
210805.703: [GC [PSYoungGen: 927209K->1463K(956480K)] 1146284K->221982K(2436160K), 0.0042142 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
210814.945: [GC [PSYoungGen: 220777K->415K(955712K)] 441297K->221339K(2435392K), 0.0023439 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
210814.947: [Full GC (System) [PSYoungGen: 415K->0K(955712K)] [PSOldGen: 220923K->221217K(1479680K)] 221339K->221217K(2435392K) [PSPermGen: 187858K->187858K(524288K)], 1.2382922 secs] [Times: user=1.08 sys=0.14, real=1.24 secs]
This is a snippet from our BackgroundMethodServer-GC.log
291984.875: [GC [PSYoungGen: 944512K->15553K(960128K)] 1072845K->143886K(2438784K), 0.0087641 secs] [Times: user=0.05 sys=0.00, real=0.02 secs]
291994.789: [GC [PSYoungGen: 960065K->9257K(964096K)] 1088398K->138558K(2442752K), 0.0062853 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
292008.938: [GC [PSYoungGen: 950697K->11710K(963456K)] 1079998K->141164K(2442112K), 0.0064588 secs] [Times: user=0.01 sys=0.00, real=0.02 secs]
292147.506: [GC [PSYoungGen: 953150K->19111K(958208K)] 1082604K->148732K(2436864K), 0.0119563 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
292253.744: [GC [PSYoungGen: 954608K->2099K(961024K)] 1084229K->131928K(2439680K), 0.0033110 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
292373.756: [GC [PSYoungGen: 38898K->1396K(962112K)] 168727K->132689K(2440768K), 0.0040471 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
292373.761: [Full GC (System) [PSYoungGen: 1396K->0K(962112K)] [PSOldGen: 131292K->114528K(1478656K)] 132689K->114528K(2440768K) [PSPermGen: 114274K->113964K(524288K)], 0.5771953 secs] [Times: user=0.58 sys=0.00, real=0.58 secs]
292382.306: [GC [PSYoungGen: 937536K->23971K(961536K)] 1052064K->140263K(2440192K), 0.0093908 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
292474.242: [GC [PSYoungGen: 961507K->2008K(953984K)] 1077799K->118524K(2432640K), 0.0040420 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
292531.808: [GC [PSYoungGen: 931416K->15518K(944960K)] 1047932K->132266K(2423616K), 0.0068716 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
292578.298: [GC [PSYoungGen: 944926K->10605K(958528K)] 1061674K->127726K(2437184K), 0.0128209 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]
292603.189: [GC [PSYoungGen: 940141K->17932K(957120K)] 1057262K->135353K(2435776K), 0.0364587 secs] [Times: user=0.05 sys=0.00, real=0.05 secs]
292631.829: [GC [PSYoungGen: 947191K->28332K(947456K)] 1064611K->145920K(2426112K), 0.0111846 secs] [Times: user=0.06 sys=0.00, real=0.02 secs]
292684.382: [GC [PSYoungGen: 946860K->11808K(952320K)] 1064448K->129508K(2430976K), 0.0140484 secs] [Times: user=0.00 sys=0.00, real=0.02 secs]
292818.659: [GC [PSYoungGen: 930309K->25870K(948096K)] 1048009K->143610K(2426752K), 0.0149712 secs] [Times: user=0.03 sys=0.00, real=0.02 secs]
292973.756: [GC [PSYoungGen: 146404K->1023K(951296K)] 264145K->119088K(2429952K), 0.0152813 secs] [Times: user=0.00 sys=0.00, real=0.02 secs]
292973.771: [Full GC (System) [PSYoungGen: 1023K->0K(951296K)] [PSOldGen: 118064K->118982K(1478656K)] 119088K->118982K(2429952K) [PSPermGen: 114043K->114043K(524288K)], 0.4887900 secs]
