WebSphere性能调优-垃圾收集器

这是一篇非常好的GC 日志Fenix文章，转载过来以防丢失，文章原文地址：https://www.iteye.com/blog/superivan-1727827

 基于WebSphere 构建的企业应用，时常会出现性能问题，在严重的情况下还会提示出内存溢出，这是一件很让人恼怒的事情。在WebSphere Application Server(Was)运行的时候，内存溢出，会生成大量的溢出文件，如Javacore, Heapdump等文件，占用了大量的磁盘空间。在这种情况下，时常会出现一连串的系统问题，如部署在Was的所有应用服务都报错，Was连控制台也无法访问等。

     为解决问题，我们通常会选择重新启动整个Was或者服务器，然后分析运行日志SystemOut.log、ystemErr.log、ative_stdout.log、native_stderr.log 和系统内存溢出的时候产生的Javacore、Heapdump文件来寻找出问题。

    那么，为什么会出现内存溢出呢？

    应用服务器在运行过程中需要创建很多对象，而在应用服务器的堆空间大小有限的情况下，请求进程不断申请空间来创建与存放对象，在达到上限时而服务器又没能释放出空间来处理申请空间的请求就会出现内存溢出情况。这就像吹气球，当气球中的气体到达一定程度时，气球就会被撑爆。（32位的JDK的Jvm堆空间分配最大支持1.5G的大小，超过则无法正常启动。而64位的JDK堆大小分配无限制，其大小受到服务器的内存限制。）通常在投入生产的系统中，出现溢出一般都是对象分配不合理导致的。

    在此，让我们先了解下Java世界里，对象与对象管理是怎么一回事。

    在Java的体系中，所有的类作为一个对象（包括Jdk本身提供的类，应用中由开发人员编写的类），都是直接或者间接继承了Java.lang.object产生的。这些类被创建的时候都会向Jvm堆申请一定的内存空间存放，因此在Jvm堆空间里会存放各式各样的对象，有的是静态类型，有的是私有类型等等，而这些对象都是通过垃圾收集器进行管理的。

     垃圾收集器（Garbage Collection,我们通常称之为GC），它是Java与C++语言的一个显著的不同点。Java语言通过垃圾收集器管理内存中的对象，垃圾收集器是在C++基础上的一种极大进步，使许多编程问题消失于无形中。通过垃圾回收，在Java编程过程中，内存漏洞的情况会少得多。

    虽然垃圾收集器为开发带来了极大的便利，但如果对象分配与使用不合理，也会导致垃圾回收在性能上拖Jvm的后腿。为了解决性能问题，GC则是一个让我们不能忽视的问题。根据不同的应用场景，选择适合的GC策略，可以帮助系统性能在一定程度上得到显著的优化。

    垃圾收集器为了快速清除在JVM堆中不再使用的对象，从而释放出空间来供其他请求创建对象，常见的方法有引用计数方法和对象引用遍历方法等算法，目前主流的方法为对象引用遍历方法。通过这些高效的算法实现的GC策略有许多种，他们都是针对各种应用场景而产生的，我们可以通过在JVM启动参数中设置，来调整GC策略。

    在IBM SDK 5.0提供了四种不同的GC策略优化配置(IBM 在WebSphere 6.1版本开始，IBM JDK 升级到IBM SDK5.0，也就是常说的JDK1.5)，详细如下：
 

序号	策略	选项	描述	备注
1	针对吞吐量进行优化	-Xgcpolicy:optthruput	WAS默认策略。对于吞吐量比短暂的 GC 停顿更重要的应用程序，通常使用这种策略。每当进行垃圾收集时，应用程序都会停顿。
2	针对停顿时间进行优化	-Xgcpolicy:optavgpause	通过并发地执行一部分垃圾收集，在高吞吐量和短 GC 停顿之间进行折中。应用程序停顿的时间更短。
3	分代并发	-Xgcpolicy:gencon	以不同方式处理短期存活的对象和长期存活的对象。采用这种策略时，具有许多短期存活对象的应用程序会表现出更短的停顿时间，同时仍然产生很好的吞吐量。	推荐使用
4	子池	-Xgcpolicy:subpool	采用与默认策略相似的算法，但是采用一种比较适合多处理器计算机的分配策略。建议对于有 16 个或更多处理器的 SMP 计算机使用这种策略。这种策略只能在 IBM pSeries® 和 zSeries® 平台上使用。需要扩展到大型计算机上的应用程序可以从这种策略中受益。

   在Sun Jvm也有自己特色的GC策略，如：

序号	策略	选项	描述	备注
1	并发收集器	-XX:+UseConcMarkSweepGC	并发收集器与应用程序同时运行。这些收集器在某点上（比如压缩时），一般都不得不停止其他操作，以完成特定的任务，但是因为其他应用程序可进行其他的后台操作，所以中断其他处理的实际时间大大降低。
2	并行收集器	-XX:+UseParallelGC	并行收集器使用某种传统的算法，并使用多线程并行地执行它们的工作。在多cpu机器上使用多线程技术可以显著的提高java应用程序区性的可扩展性。
3	串行收集器	-XX:+UseSerialGC	用单线程处理所有垃圾回收工作，因为无需多线程交互，所以效率比较高。但是，也无法使用多处理器的优势，所以此收集器适合单处理器机器。当然，此收集器也可以用在小数据量（100M左右）情况下的多处理器机器上。

  通过以上的列表数据，大家也接触到了各种常见的GC策略，相信到此对GC与GC策略也有了一定程度的了解。那如何衡量GC的性能，如何为何业务应用选择合适的GC策略呢？

      一般来说，衡量GC效率的参数主要有2类，吞吐量和停顿时间。
     

•  
•    
  • 吞吐量是应用程序处理的数据量。衡量吞吐量的标准是与具体应用程序相关的。
  •     
    • 停顿时间是垃圾收集器将所有应用程序线程停下来，从而对堆进行收集所经历的时间。 
         
    
    
          如何分析和选择适合的GC策略呢？我们可以在业务应用系统打开详细垃圾回收，收集系统在运行过程中的GC日志，通过分析GC日志，来判断当前GC策略是否符合当前应用系统。
    
         在实际应用场景中，不是每个应用服务都必须调整GC，如果您寄予厚望希望调了GC策略后，就一定能使系统达到性能上的提升，成效未必尽入人意。因此GC策略调整只是从GC角度去辅助性能优化，而调优的效果需要根据实际情况才能断定。例如：在测试机调整了GC策略，使用压力测试工具进行压力测试，性能优化成效显著；但在生产系统上调整了参数，却未收到让人满意成效，且生产机比测试机配置高,这些问题已经是屡见不鲜了，问题原因有很多方面，通常是因为生产实际使用场景与测试机压力测试场景不一致，系统受到的压力不一样所导致的。
    
          但GC调整在系统能够性能调优上确是一个必不可少的环节，合理的创建使用对象，选择适合的GC策略，往往能让性能有一定的提高，也减少了内存溢出的可能性，或者缩短系统停顿的时间。
    
          以下是一段发生在IBM SDK5.0版本上配置了分代并发策略所产生的GC日志，让我们一起看下如何分析这一段GC：
    Xml代码  
    1. <!—距离上次GC间隔时间为6.787 秒   
    2. <af> 表示本次垃圾回收是因为分配失败而引发的，如果标签开头写着sys，则表示应用中有显示调用GC,如System.gc()。一般情况下不建议显示调用GC,当然也可以通过配置防止显示GC, 在JVM启动参数中加入-Xdisableexplicitgc参数屏蔽显式GC。  
    3. Type=“nursery” ：这次GC的类型是新生代方式,因为新生代的分配失败而进行垃圾回收了。  
    4.  Id=”3365”代表GC发生在新生代，已经重复执行了3365次  
    5. timestamp：GC的执行时间  
    6. -->  
    7. <af type="nursery" id="3365" timestamp="三  1月 06 16:09:03 2010" intervalms="6787.454">  
    8.   
    9. <!—这里记录需要申请的堆大小为710824b 约694KB -->  
    10. <minimum requested_bytes="710824" />  
    11.   
    12.  <!—GC准备开始前 使用时间为 0.224秒 -->  
    13. <time exclusiveaccessms="0.224" />  
    14.   
    15. <!—GC前堆空间使用情况，可以看到剩余567408B，不能满足空间的申请要求了，申请空间是710824B，因此就需要进行GC -->  
    16.   <nursery freebytes="567408" totalbytes="42694656" percent="1" />  
    17.   
    18.   <!--   GC前的堆空间情况，JVM堆大小为1.2左右了，空闲的空间为650mb左右，大致空闲空间为48%  
    19. Tenured：长存（tenured） 区域  
    20. Soa:小对象使用区域；就是 “正常的” 堆。所有对象最初都分配给小对象区域，但是如果小区域已经分配完了，则将大于 64KB 的对象分配给大对象区域。  
    21. Loa：大对象使用区域；大对象区域是堆中保留给大对象分配的一小片区域。如果应用程序不需要大对象区域（也就是应用程序不分配任何大对象），内存管理例程会快速将大对象区域缩减为空，这样，整个堆都可以供 “正常的” 分配使用。  
    22.  -->  
    23.   <tenured freebytes="666933424" totalbytes="1365881856" percent="48" >  
    24.     <soa freebytes="654641328" totalbytes="1353589760" percent="48" />  
    25.     <loa freebytes="12292096" totalbytes="12292096" percent="100" />  
    26.   </tenured>  
    27.   
    28. <!—GC后堆空间使用情况 -->  
    29. <!—详细gc情况   
    30. type="scavenger"：垃圾回收类型为清理过程。  
    31. id="3365": 意为执行力3365次清理，并且没有发生过全局GC，如 <gc type=”global”>。  
    32. <flipped objectcount="15558" bytes="3973128" />：说明将要把15558个存活下来的对象被复制到了幸存区（survivor space）  
    33. <tenured objectcount="14791" bytes="14233400" />：说明将要把14791个对象则经过多次幸存区的复制，被转移到了长存区（tenured）  
    34.    
    35. <scavenger tiltratio="65" />:清理的倾斜比率为65%  
    36. <refs_cleared soft="73" weak="61" phantom="0" />：清理了存在引用对象的数目. 弱引用为61、软引用为73，和虚引用为0. 弱引用、软引用和虚引用允许灵活的缓存，能够改进应用程序的内存特性。如果引用对象过多大于1000，GC停顿时间就会受到影响。因此我们需要检查是否存在过多的应用对象。  
    37. <finalization objectsqueued="40" />：收尾器，存在需要在GC后，要调用的自定义方法的对象。  
    38.    
    39. -->  
    40.   <gc type="scavenger" id="3365" totalid="3709" intervalms="6788.531">  
    41.     <flipped objectcount="15558" bytes="3973128" />  
    42.     <tenured objectcount="14791" bytes="14233400" />  
    43.     <refs_cleared soft="73" weak="61" phantom="0" />  
    44.     <finalization objectsqueued="40" />  
    45. <scavenger tiltratio="65" />  
    46.   
    47. <!—-GC后的情况  
    48. nursery区  
    49. 1、清理了出空闲堆大小为39108112b  约为38191.515625KB，约为37MB  
    50.    2、 总大小为44144640B,约43110KB 约为42MB  
    51. -->  
    52. <nursery freebytes="39108112" totalbytes="44144640" percent="88" tenureage="1" />  
    53.   
    54. <!—-Tenured长存区总大小为1365881856B,约为1.27GB空闲堆大小为 651143448B  620MB-->  
    55.    
    56.     <tenured freebytes="651143448" totalbytes="1365881856" percent="47" >  
    57.       <soa freebytes="638851352" totalbytes="1353589760" percent="47" />  
    58.       <loa freebytes="12292096" totalbytes="12292096" percent="100" />  
    59.     </tenured>  
    60.     <time totalms="25.029" />  
    61.   </gc>  
    62.   
    63. <!--这里再次打印需要申请的堆大小为710824b 约694KB -->  
    64. <minimum requested_bytes="710824" />  
    65.   
    66. <!--通过比较，就可以知道当前次的GC情况，及堆空间的使用率  
    67. <time totalms="26.386" /> 总的GC时间为26.386ms  
    68.  -->  
    69.   <nursery freebytes="38397288" totalbytes="44144640" percent="86" />  
    70.   <tenured freebytes="651143448" totalbytes="1365881856" percent="47" >  
    71.     <soa freebytes="638851352" totalbytes="1353589760" percent="47" />  
    72.     <loa freebytes="12292096" totalbytes="12292096" percent="100" />  
    73.   </tenured>  
    74.   <time totalms="26.386" />  
    75. </af>  
    76.   
    77. <!-- 经过垃圾回收，新生代的空间剩余86%，因为分配失败发生在新生代，进行的是快速的Minor gc，所以长存区的可用空间依然是47%，这次回收的时间为26.386ms。而  
    78. 在长存区发生的是Major gc，回收时间一般要长于Minor gc，一般健康的JVM 环境Minor gc：Minor gc=1：10。   -->  
    
    
         打开详细垃圾回收,我们就可以获得详细垃圾回收情况，根据以上的GC日志的分析，我们则可以了解到系统GC提供了什么样的信息给我们。通过这些信息，我们可以分析得出当前GC策略是否需要调整。(当然这个与您实际生产得出的GC日志分析结果有关)。
    
    
         在分析的过程里，我们需要关注几个点，来分析GC策略是否需要调整：
       GC频率：多长时间执行一次GC，如果GC频繁的话，则需要检查系统现在的运行情况是否合理
       GC类型+GC申请空间大小+新生代空间大小：分析GC是否合理
       各分代区域的大小：检查当前JVM堆的使用是否合理，新生代的空间大小是否符合当前业务场景要求。长存区的空间大小是否合理，再联合JVM配置的堆配置大小分析，堆的使用是否存在问题，因为虽然进行了GC，但堆空间的使用如不能满足要求的话，易导致系统出现全局GC，在压力过大的情况下还会内存溢出。
       重点检查GC过程中长存区的变化：是否存在大对象，如果有的话，可以考虑-Xlp参数优化
       GC过程中是否清理了过多引用对象：如有则需要检查应用
       GC整个过程消耗的时间是否过长：过长的GC会直接影响到系统的性能，当然这个也GC类型有关，全局GC，清理长存区的GC时间相对会长点，但是这些类型的GC不会很频繁。
    
         以上主要是通过详细分析GC日志，从而协助我们进一步了解到JVM堆的使用情况，最后得出当前GC策略是否符合业务应用使用场景，而更换其他GC策略则需要配合当前业务场景与JVM堆使用情况去选择适合的GC策略。
    
         JDK的版本不同，GC的策略配置也有所不同，但这不是重点，如何读懂GC日志，分析JVM堆的使用情况后，更根据问题去寻找适合的JVM选项参数进行设置，从各方面去调整最终达到一个性能调优的目地。
    
         由此可见，垃圾回收的调整在性能调优过程中也是一个十分重要的环节。
    
    其他相关资料
    
    适合IBM JDK 设置参数简单介绍：

    序号	选项	描述
    1	-Xlp	此设置与IBM JVM配合使用，以使用大页16MB来分配堆
    2	-Xlp64k	此参数与IBM JVM配合使用，以使用64K字节页大小来分配堆
    3	-Xnoclassgc	闭类垃圾回收，可以消除由于多次装入和卸载同一个类而造成地开销
    4	-Xnocompactgc	该参数完全关闭压缩。虽然在性能方面有短期的好处，最终应用程序堆将变得支离破碎，即使堆中有足够的自由空间也会导致 OutOfMemory 错误
    5	-Xcompactgc	使用该参数将导致每个垃圾收集周期都执行压缩，无论是否有必要。JVM 在压缩时要做大量的决策，在普通模式下会推迟压缩
    6	-Xgcthreads	该参数控制 JVM 在启动过程中创建的垃圾收集帮助器线程个数。对于 N-处理器机器，默认的线程数为 N-1。这些线程提供并行标记和并行清理模式中的并行机制

    
    
    适合Sun Jvm 辅助配置相关参数简单介绍：
     

    序号	选项	描述
    1	-XX:+PrintGC	输入gc收集概括。输出形式：[GC 118250K->113543K(130112K), 0.0094143 secs][Full GC 121376K->10414K(130112K), 0.0650971 secs]
    2	-XX:+PrintGCDetails	输出Gc明细情况，输出形式：[GC [DefNew: 8614K->781K(9088K), 0.0123035 secs] 118250K->113543K(130112K), 0.0124633 secs][GC [DefNew: 8614K->8614K(9088K), 0.0000665 secs][Tenured: 112761K->10414K(121024K), 0.0433488 secs] 121376K->10414K(130112K), 0.0436268 secs]
    3	-XX:+PrintGCTimeStamps	输出GC时间，输出形式：11.851: [GC 98328K->93620K(130112K), 0.0082960 secs]
    4	-Xloggc:filename	指定输出记录文件
    5	-XX:+PrintGCApplicationConcurrentTime	打印每次垃圾回收前，程序未中断的执行时间, 输出形式：Application time: 0.5291524 seconds
    6	-XX:+PrintGCApplicationStoppedTime	打印垃圾回收期间程序暂停的时间。可与上面混合使用输出形式：Total time for which application threads were stopped: 0.0468229 seconds
    7	-XX:+PrintHeapAtGC	打印GC前后的详细堆栈信息
    8	-verbose:gc	详细垃圾收集信息

    
    
    native_stderr.log实例Xml代码  
    1. <af type="nursery" id="366" timestamp="Fri Nov 16 11:38:09 2012" intervalms="157501.087">  
    2.   <minimum requested_bytes="24" />  
    3.   <time exclusiveaccessms="0.079" />  
    4.   <nursery freebytes="0" totalbytes="483183616" percent="0" />  
    5.   <tenured freebytes="196528288" totalbytes="536870912" percent="36" >  
    6.     <soa freebytes="169876168" totalbytes="510027776" percent="33" />  
    7.     <loa freebytes="26652120" totalbytes="26843136" percent="99" />  
    8.   </tenured>  
    9.   <gc type="scavenger" id="366" totalid="370" intervalms="157501.912">  
    10.     <flipped objectcount="204678" bytes="23822596" />  
    11.     <tenured objectcount="4609" bytes="269968" />  
    12.     <refs_cleared soft="496" weak="848" phantom="442" />  
    13.     <finalization objectsqueued="624" />  
    14.     <scavenger tiltratio="89" />  
    15.     <nursery freebytes="455952320" totalbytes="483183616" percent="94" tenureage="14" />  
    16.     <tenured freebytes="195859400" totalbytes="536870912" percent="36" >  
    17.       <soa freebytes="169207280" totalbytes="510027776" percent="33" />  
    18.       <loa freebytes="26652120" totalbytes="26843136" percent="99" />  
    19.     </tenured>  
    20.     <time totalms="33.759" />  
    21.   </gc>  
    22.   <nursery freebytes="455950272" totalbytes="483183616" percent="94" />  
    23.   <tenured freebytes="195859400" totalbytes="536870912" percent="36" >  
    24.     <soa freebytes="169207280" totalbytes="510027776" percent="33" />  
    25.     <loa freebytes="26652120" totalbytes="26843136" percent="99" />  
    26.   </tenured>  
    27.   <time totalms="41.051" />  
    28. </af>  
    29.   
    30. <sys id="4" timestamp="Fri Nov 16 11:39:08 2012" intervalms="32322626.328">  
    31.   <time exclusiveaccessms="0.084" />  
    32.   <nursery freebytes="268060792" totalbytes="483183616" percent="55" />  
    33.   <tenured freebytes="195857976" totalbytes="536870912" percent="36" >  
    34.     <soa freebytes="169205856" totalbytes="510027776" percent="33" />  
    35.     <loa freebytes="26652120" totalbytes="26843136" percent="99" />  
    36.   </tenured>  
    37.   <gc type="global" id="5" totalid="371" intervalms="1995627.246">  
    38.     <compaction movecount="5045546" movebytes="276838816" reason="compact on aggressive collection" />  
    39.     <classloadersunloaded count="949" timetakenms="3068.520" />  
    40.     <refs_cleared soft="15048" weak="1448" phantom="385" />  
    41.     <finalization objectsqueued="343" />  
    42.     <timesms mark="402.569" sweep="7.332" compact="210.673" total="3689.986" />  
    43.     <nursery freebytes="463111456" totalbytes="483183616" percent="95" />  
    44.     <tenured freebytes="260923064" totalbytes="536870912" percent="48" >  
    45.       <soa freebytes="234079928" totalbytes="510027776" percent="45" />  
    46.       <loa freebytes="26843136" totalbytes="26843136" percent="100" />  
    47.     </tenured>  
    48.   </gc>  
    49.   <nursery freebytes="463111456" totalbytes="483183616" percent="95" />  
    50.   <tenured freebytes="260923064" totalbytes="536870912" percent="48" >  
    51.     <soa freebytes="234079928" totalbytes="510027776" percent="45" />  
    52.     <loa freebytes="26843136" totalbytes="26843136" percent="100" />  
    53.   </tenured>  
    54.   <time totalms="3696.347" />  
    55. </sys>  
    56.   
    57. <af type="nursery" id="367" timestamp="Fri Nov 16 11:41:17 2012" intervalms="187670.091">  
    58.   <minimum requested_bytes="443616" />  
    59.   <time exclusiveaccessms="0.079" />  
    60.   <nursery freebytes="22656" totalbytes="483183616" percent="0" />  
    61.   <tenured freebytes="260921696" totalbytes="536870912" percent="48" >  
    62.     <soa freebytes="234078560" totalbytes="510027776" percent="45" />  
    63.     <loa freebytes="26843136" totalbytes="26843136" percent="100" />  
    64.   </tenured>  
    65.   <gc type="scavenger" id="367" totalid="372" intervalms="187677.253">  
    66.     <flipped objectcount="147223" bytes="21010876" />  
    67.     <tenured objectcount="8855" bytes="401564" />  
    68.     <refs_cleared soft="831" weak="979" phantom="361" />  
    69.     <finalization objectsqueued="846" />  
    70.     <scavenger tiltratio="89" />  
    71.     <nursery freebytes="459584128" totalbytes="483183616" percent="95" tenureage="14" />  
    72.     <tenured freebytes="259742048" totalbytes="536870912" percent="48" >  
    73.       <soa freebytes="232898912" totalbytes="510027776" percent="45" />  
    74.       <loa freebytes="26843136" totalbytes="26843136" percent="100" />  
    75.     </tenured>  
    76.     <time totalms="32.110" />  
    77.   </gc>  
    78.   <nursery freebytes="459140512" totalbytes="483183616" percent="95" />  
    79.   <tenured freebytes="259742048" totalbytes="536870912" percent="48" >  
    80.     <soa freebytes="232898912" totalbytes="510027776" percent="45" />  
    81.     <loa freebytes="26843136" totalbytes="26843136" percent="100" />  
    82.   </tenured>  
    83.   <time totalms="32.950" />  
    84. </af>  

文章末尾加上一个官方提供的非常有用的工具： IBM Support Assistant WorkBench内加载的一个工具（IBM Monitoring and Diagnostic Tools for Java-Garbage Collection and Memory Visualizer for ISAv4.

        此工具会针对分析结果给出调优建议，分析结果的宝盖会给出大概的摘要信息：例如GC的方式，一共GC了多少次，应用重启了多少次，使用了多少内存。分配的堆是多大。还会提供表数据，此表包括非常详细的数据，每次GC的时间，使用的内存，当时的堆大小；并且根据表数据给出一个大概的线图，线图摘取下来完全可以作为报告使用。十分方便的工具。不过此工具是需要license的。