聚沙成塔-小哈的记事薄

Tools and Tips to Diagnose Performance Issues

分析性能问题的一些工具和建议

内存泄漏是比较常见的一种应用程序性能问题，一旦发生，则系统的可用内存和性能持续下降；最终将导致内存不足(OutOfMemory)，系统彻底宕掉，不能响应任何请求，其危害相当严重。同时，Java堆(Heap)中大量的对象以及对象间之复杂关系，导致内存泄漏问题的探测和分析均比较困难，采用相应的辅助工具是很必要的。

我使用的比较多的是Memory Dump Diagnostic for Java (MDD4J)和IBM HeapAnalyzer，这两个工具都能支持几乎所有JDK版本所生成的堆转储文件，使用前可以在两者的帮助文件中查看一下支持列表。

先说一下IBM HeapAnalyzer，下载之后首先阅读一下readme，这上面详细写了HeapAnalyzer的使用方法。对于我用的2.6版本（最新为3.8），可以在命令行中输入<Java path>java –Xmx[heapsize] –jar ha26.jar <heapdump file>来启动工具并加载heapdump文件。对于比较大的heapdump，将-Xmx设置一个较大的值（大于heapdump的大小），来避免加载过程中的OOM。对于64位机器上产生的超大heapdump，个人机器上分析就不大可能了。

打开heapdump文件后，我一般点击“Analysis”里的“Tree View”，以树的形式从根节点展示内存对象分配的信息

第一行java.lang.ref.Refenrence这个class及它的76个children占用了67%的已用堆大小（31M/46M），它本身仅占用了76bits。双击java.lang.ref.Refenrence，我们可以看到它所引用的两个子节点。其中一个子节点java.lang.ref.Finalizer后的67%指引我们内存泄漏的问题应该在它的引用上。

阅读全文…

上次介绍了IBM的两款分析gc log的工具（GCMV和PMAT），这次讲讲HP推出的HPjmeter。HPjmeter集成了以前的HPjtune功能，可以分析在HP机器上产生的垃圾回收日志文件。你可以到Hewlett-Packard Java website免费下载最新的4.0版本，当然会让你填一些信息。

接下来我将分析一个实际生产环境下的日志文件，这个生产系统在启用新的功能后应用访问速度变慢，每个操作都要耗时10s左右，通过对比前后不同的gc信息，希望能从JVM的层面来优化当前的性能。

HP小机（Pa-Risc和安腾平台）使用HP的JDK后，使用-Xloggc:filename或者-Xverbosegc:file=filename参数会生成形如

的日志，这种格式人肉分析就别想了，它可以在PMAT中以Xverbosegc/hpux文件格式打开，但是图象功能我这里没法使用，只好求助于HP自家的工具——HPjmeter了。

分析过程

用HPjmeter加载日志文件后，会自动打开HPjtune的窗口。首先会看到Heap Usage After GC标签页，这是四月份正常的情况（请先忽略systemgc，这点留待后面分析）

阅读全文…

前两篇说到IBM JDK和Sun的HotSpot JDK的调优策略，当中一直提到的重要一点是需要根据GC详细日志来调整参数的设置，那么当我们收集到日志后如何分析，如何根据日志的情况来调整参数？这就是本文所要阐述的。

使用IBM的JDK的Windows平台和AIX平台，我们只要在WebSphere管理控制台的java进程属性里勾选“详细垃圾回收”，那么就会在native_stdout.log中生成如下的信息。

这幅图很形象的给出了gc日志的主要关注点：垃圾回收的原因、垃圾回收的间隔、垃圾回收前后的剩余空间、垃圾回收持续的时间……

“nursery”表示这次分配失败（Allocation Failure）发生在新生代（nursery），是第44次（id=44）因为新生代的分配失败而进行垃圾回收了（开启GC日志以来），离上一次发生GC的间隔是12746ms，无法分配的空间大小是8216Byte，而进行垃圾回收前，新生代的可用空间为1776Byte，小于8216Byte，虽然年老区还剩余45%的空间，但是新的内存空间是无法直接在年老区分配的，由此引发了一次清理过程（scavenger）。

GC type表明了这次垃圾回收是一个清理过程，也是第44次scavenger过程，同时恰是第44个gc过程，说明没有发生过诸如<gc type=”global”>的垃圾回收过程。flipped objectcount说明将要把4523143个存活下来的对象被复制到了幸存区（survivor space），而73768个对象则经过多次幸存区的复制，有幸熬出头，被转移到了长存区（tenured space）。我们看到清理的倾斜比率（scavenger tiltratio）为89%，而不是对半开，说明经过多次复制清理，JVM已经意识到每次只有很少的对象能存活下来，于是它自动增大了年轻代中Eden区的大小，以使得为新对象可以腾出更多的内存。

接下来的就比较简单，经过垃圾回收，新生代的空间剩余89%，因为分配失败发生在新生代，进行的是快速的Minor gc，所以长存区的可用空间依然是45%，这次回收的时间为384.469ms。在长存区发生的是Major gc，回收时间一般要长于Minor gc，所以健康的JVM 环境Minor gc：Minor gc=1：10（也不用太在意）。

在垃圾回收准备开始的那一段时间（time exclusiveaccessms），以及回收的过程中，另一个线程发现内存无法分配了，于是也要求一次gc过程，这时候就产生了gc队列（会有<warning details=”exclusive access time includes previous garbage collections” />显示）。一般前一次垃圾回收就会释放出足够这两次分配需要的空间，于是第二次gc过程就终止了，当然要是无法足够分配的话，马上就会再进行一次垃圾回收。不过这种情况下，估计要进行Full GC了。

Full GC的gc type就是global，这是stop the world的最耗费时间的回收方式，所以需要通过尽量调整参数来避免。如果发现不是由AF引起的，而是在开头写着SYS标签，那么就要好好问问开发，有没有使用System.gc()的必要？可以的话使用-Xdisableexplicitgc来禁止（Sun等JDK下为-XX:+DisableExplicitGC）。

以上所说的都是IBM JDK下垃圾回收日志的情况。在Sun和HP的JDK下情况相似，不过需要使用-XX:PrintHeapAtGC:参数来打印GC前后的详细堆栈信息。另外我建议加上-Xloggc:filename或者-Xverbosegclog:file_name（方便用工具分析）输出到特定文件，因为不知为何有时候会输出到native_stderr.log，或者在native_stdout.log中和thread dump夹杂在一起，不方便分析。

{Heap before GC invocations=116:
Heap
def new generation   total 157376K, used 139904K [63400000, 6dec0000, 78950000)
eden space 139904K, 100% used [63400000, 6bca0000, 6bca0000)
from space 17472K,   0% used [6bca0000, 6bca0000, 6cdb0000)
to   space 17472K,   0% used [6cdb0000, 6cdb0000, 6dec0000)
tenured generation   total 349568K, used 79067K [38800000, 4dd60000, 632b0000)
the space 349568K,  22% used [38800000, 3d536ce0, 3d536e00, 4dd60000)
compacting perm gen  total 132096K, used 132023K [28800000, 30900000, 38800000)
the space 132096K,  99% used [28800000, 308edf50, 308ee000, 30900000)
[GC 218971K->83116K(506944K), 0.0976948 secs]
Heap after GC invocations=117:
Heap
def new generation   total 157376K, used 4049K [63400000, 6dec0000, 78950000)
eden space 139904K,   0% used [63400000, 63400000, 6bca0000)
from space 17472K,  23% used [6cdb0000, 6d1a4628, 6dec0000)
to   space 17472K,   0% used [6bca0000, 6bca0000, 6cdb0000)
tenured generation   total 349568K, used 79067K [38800000, 4dd60000, 632b0000)
the space 349568K,  22% used [38800000, 3d536ce0, 3d536e00, 4dd60000)
compacting perm gen  total 132096K, used 132023K [28800000, 30900000, 38800000)
the space 132096K,  99% used [28800000, 308edf50, 308ee000, 30900000)
}

这是一个在使用HPJDK输出的实例，基本和IBM JDK没啥区别，可以加上-XX:+PrintGCTimeStamps显示每次回收的间隔。

这些“人肉”分析可以让我们清楚JVM运行的情况，但是还是不够直观，所以下次会介绍分析JVM日志的工具，尽情期待。现已完成，欢迎访问

在JAVA性能优化—IBM JDK JVM参数设置和JAVA性能优化—Sun’s Hostspot JVM参数设置两篇文章中我介绍了针对JDK进行优化的方法，这些参数上的改变也许会带来50%甚至100%的性能提升，但是如果从程序入手，可能提升的空间是一个数量级的，而且往往很多时候性能问题光靠调整参数无法解决。接下来分享两篇文档，指点你写出更符合JVM GC“胃口”的代码。

javaProgrammingPerformanceTips

1. Primitive and Objects
2. Abuse of the String class
3. Creating intermediate objects
4. Mutable return types
5. Using the wrong collections
6. Array copy

         GCFriendlyProgramming

1. Garbage Collection
2. Programming Tips
3. Problems With Finalization
4. Using Reference Objects
5. Conclusions

          详细内容各位自己看吧，对于编程我也是门外汉。

本文主要根据这篇PDF（GCTuningGuidelines）写成。

首先是JDK1.5引入的新功能 Ergonomic Settings（自动优化的参数）

对于有2块CPU和2GB内存及更佳配置的服务器，Sun的hotspot jdk默认设置了如下参数：

• -server ：服务器模式编译
• -XX:+UseParallelGC 并行收集
• -Xms设置为服务器物理内存的1/64
• -Xmx设置为服务器物理内存的1/4（最大为1G）

我在网上发现了这篇文章，也是根据那篇PDF写的，基本都翻译过来了，那我就不再做造轮子的过程了。有些自己的想法会用红色标出。

摘自         http://unixboy.javaeye.com/

原文链接 JVM调优总结 -Xms -Xmx -Xmn -Xss

1. 堆大小设置 JVM 中最大堆大小有三方面限制：相关操作系统的数据模型（32-bt还是64-bit）限制；系统的可用虚拟内存限制；系统的可用物理内存限制。32位系统 下，一般限制在1.5G~2G；64为操作系统对内存无限制。我在Windows Server 2003 系统，3.5G物理内存，JDK5.0下测试，最大可设置为1478m。

   典型设置（例子中的堆分配的都比较大，注意自己平台的限制，下文同）：

   • java -Xmx3550m -Xms3550m -Xmn2g -Xss128k-Xmx3550m：设置JVM最大可用内存为3550M。

     -Xms3550m：设置JVM促使内存为3550m。此值可以设置与-Xmx相同，以避免每次垃圾回收完成后JVM重新分配内存（就是收缩和扩张，分代回收加上Sun内存分配的算法，避免了IBM JDK最小堆和最大堆一样上的缺陷，但是这对-Xms和-Xmx的设置有了更高的要求，应该是多次试验确定一个合适的大小）。

     -Xmn2g：设置年轻代大小为2G。整个堆大小=年轻代大小 + 年老代大小 + 持久代大小。持久代一般固定大小为64m，所以增大年轻代后，将会减小年老代大小。此值对系统性能影响较大，Sun官方推荐配置为整个堆的3/8。从下图，应该可以看到整个堆大小=年轻代大小 + 年老代大小，Xms和Xmx不包括Perm Size。

   阅读全文…