调优案例

一个15万PV/天左右的在线文档类型网站最近更换了硬件系统，新的硬件为4个CPU、16GB物理内存,操作系统为64位CentOS 5.4，Resin作为Web服务器。整个服务器暂时没有部署别的应用，所有硬件资源都可以提供给这访问量并不算太大的网站使用。管理员为了尽量利用硬件资源选用了64位的JDK1.5，并通过 -Xmx 和 -Xms 参数将Java堆固定在12GB。使用一段时间后发现使用效果并不理想，网站经常不定期出现长时间失去响应的情况

监控服务器运行状况后发现网站失去响应是由 GC停顿 导致的，虚拟机运行在Server模式，默认使用 吞吐量优先收集器 回收12GB的堆，一次Full GC的停顿时间高达14秒。并且由于程序设计的关系，访问文档时要把文档从磁盘提取到内存中，导致内存中出现很多由文档序列化产生的大对象，这些大对象很多都进入了老年代，没有在Minor GC中清理掉。这种情况下即使有12GB的堆，内存也很快被消耗殆尽，由此导致每隔十几分钟出现十几秒的停顿，令网站开发人员和管理员感到很沮丧

程序部署上的主要问题显然是过大的堆内存进行回收时带来的长时间的停顿。硬件升级前使用32位系统1.5GB的堆，用户只感觉到使用网站比较缓慢，但不会发生十分明显的停顿,因此才考虑升级硬件以提升程序效能，如果重新缩小给Java堆分配的内存，那么硬件上的投资就显得很浪费

在高性能硬件上部署程序，目前主要有两种方式：

• 通过64位JDK来使用大内存
• 使用若干个32位虚拟机建立逻辑集群来利用硬件资源

有一个基于B/S的MIS系统，硬件为两台2个CPU、8GB内存的HP小型机，服务器是WebLogic 9.2，每台机器启动了3个WebLogic实例，构成一个6个节点的亲合式集群。由于是亲合式集群，节点之间没有进行Session同步，但是有一些需求要实现部分数据在各个节点间共享。开始这些数据存放在数据库中，但由于读写频繁竞争很激烈，性能影响较大，后面使用JBossCache构建了一个全局缓存。全局缓存启用后，服务正常使用了一段较长的时间， 但最近却不定期地出现了多次的内存溢出问题

在内存溢出异常不出现的时候，服务内存回收状况一直正常，每次内存回收后都能恢复到一个稳定的可用空间，开始怀疑是程序某些不常用的代码路径中存在内存泄漏，但管理员反映最近程序并 未更新、升级过，也没有进行什么特别操作。只好让服务带着 -XX:+HeapDumpOnOutOfMemoryError 參数运行了一段时间。在最近一次溢出之后，管理员发回了heapdump文件，发现里面存在着大量的 org.jgroups.protocols.pbcast.NAKACK 对象

JBossCache是基于自家的JGroups进行集群间的数据通信，JGroups使用协议栈的方式来实现收发数据包的各种所需特性自由组合，数据包接收和发送时要经过每层协议栈的up()和down()方法，其中的NAKACK栈用于保障各个包的有效顺序及重发

由于信息有传输失败需要重发的可能性，在确认所有注册在GMS(Group Membership Service)的节点都收到正确的信息前，发送的信息必须在内存中保留。而此MIS的服务端中有一个负责安全校验的全局Filter，每当接收到请求时，均会更新一次最后操作时间，并且将这个时间同步到所有的节点去，使得一个用户在一段时间内不能在多台机器上登录。在服务使用过程中，往往一个页面会产生数次乃至数十次的请求，因此这个过滤器导致集群各个节点之间网络交互非常频繁。当网络情况不能满足传输要求时，重发数据在内存中不断堆积，很快就产生了内存溢出

这个案例中的问题，既有JBossCache的缺陷，也有MIS系统实现方式上缺陷。 JBossCache官方的maillist中讨论过很多次类似的内存溢出异常问题，据说后续版本也有了改进。而更重要的缺陷是这一类被集群共享的数据要使用类似JBossCache这种集群缓存来同步的话，可以允许读操作频繁，因为数据在本地内存有一份副本，读取的动作不会耗费多少资源 ，但不应当有过于频繁的写操作，那样会带来很大的网络同步的开销

一个学校的小型项目：基于B/S的电子考试系统，为了实现客户端能实时地从服务器端接收考试数据，系统使用了逆向AJAX技术(也称为Server Side Push)，选用CometD 1.1.1作为服务端推送框架，服务器是Jetty7.1.4，硬件为一台普通PC机，Core i5 CPU，4GB内存，运行32位Windows操作系统

测试期间发现服务端不定时拋出内存溢出异常，服务器不一定每次都会出现异常，但假如正式考试时崩溃一次，那估计整场电子考试都会乱套，网站管理员尝试过把堆开到最大，而32位系统最多到1.6GB就基本无法再加大了，而且开大了基本没效果，拋出内存溢出异常好像还更加频繁了。加入 -XX :+HeapDumpOnOutOfMemoryError ，居然也没有任何反应，拋出内存溢出异常时什么文件都没有产生。无奈之下只好挂着jstat并一直紧盯屏幕，发现GC并不频繁，Eden区、Survivor区、老年代以及永久代内存全部都表示情绪稳定，压力不大， 但就是照样不停地拋出内存溢出异常，管理员压力很大。最后，在内存溢出后从系统日志中找到异常堆栈：

[org.eclipse.jetty.util.log]handle failed java.lang.OutOfMemoryError:null at sun.raise.Unsafe.allocateMemory (Native Method )
at java.nio.DirectByteBuffer.<init> (DirectByteBuffer.java :99 )
at java.nio.ByteBuffer.allocateDirect (ByteBuffer.java :288 )
at org.eclipse.jetty.io.nio.DirectNIOBuffer.<init>
...

操作系统对每个进程能管理的内存是有限制的，这台服务器使用的32位Windows平台的限制是2GB，其中划了1.6GB给Java堆，而Direct Memory内存并不算入1.6GB的堆之内，因此它最大也只能在剩余的0.4GB空间中分出一部分。在此应用中导致溢出的关键是: 垃圾收集进行时，虚拟机虽然会对Direct Memory进行回收，但是 Direct Memory却不能像新生代、老年代那样，发现空间不足了就通知收集器进行垃圾回收，它只能等待老年代满了后Full GC，然后顺便地帮它清理掉内存的废弃对象 。否则它只能一直等到拋出内存溢出异常时，先catch掉 ，再在catch块里面大喊声: System.gc() 。要是虚拟机还是不听 (譬如打开了 -XX:+DisableExplicitGC 开关)，那就只能眼睁睁地看着堆中还有许多空闲内存，自己却不得不拋出内存溢出异常了。而CometD 1.1.1框架，正好有大量的NIO操作需要使用到Direct Memory内存

除了Java堆和永久代之外，注意到下面这些区域还会占用较多的内存，这里所有的内存总和受到操作系统进程最大内存的限制。

• Direct Memory : 通过 -XX:MaxDirectMemorySize 调整大小，内存不足时拋出 OutOfMemoryError 或者 OutOfMemoryError:Direct buffer memory
• 线程堆栈 : 通过 -Xss 调整大小，内存不足时拋出 StackOverflowError (即无法分配新的栈帧)或者 OutOfMemoryError:unable to create new native thread (无法建立新的线程)
• Socket缓存区 : 每个Socket连接都Receive和Send两个缓存区，分别占大约37KB和25KB内存，连接多的话这块内存占用也比较可观。如果无法分配，则可能会拋出 IOException: Too many open files 异常
• JNI代码 : 如果代码中使用JNI调用本地库，那本地库使用的内存也不在堆中
• 虚拟机和GC : 虚拟机、GC的代码执行也要消耗一定的内存

一个数字校园应用系统，运行在一台4个CPU的Solaris 10操作系统上，中间件为GlassFish服务器。系统在做大并发压力测试的时候，发现请求响应时间比较慢，通过操作系统的mpstat工具发现 CPU使用率很高，并且系统占用绝大多数的CPU资源的程序并不是应用系统本身 。这是个不正常的现象，通常情况下用户应用的CPU占用率应该占主要地位，才能说明系统是正常工作的

通过Solaris 10的Dtrace脚本可以查看当前情况下哪些系统调用花费了最多的CPU资源，Dtrace运行后发现最消耗CPU资源的竟然是 fork系统调用 。众所周知， fork系统调用是来产生新进程的，在Java虚拟机中，用户编写的Java代码最多只有线程的概念，不应当有进程的产生

这是个非常异常的现象。通过本系统的开发人员，最终找到了答案: 每个用户请求的处理都需要执行一个外部shell脚本来获得系统的一些信息。执行这个shell脚本是通过Java的 Runtime.getRuntime().exec() 方法来调用的。这种调用方式可以达到目的，但是它在Java虚拟机中是非常消耗资源的操作，即使外部命令本身能很快执行完毕，频繁调用时创建进程的开销也非常可观。Java虚拟机执行这个命令的过程是: 首先克隆一个和当前虚拟机拥有一样环境变量的进程，再用这个新的进程去执行外部命令，最后再退出这个进程 。如果频繁执行这个操作，系统的消耗会很大，不仅是CPU，内存负担也很重

用户根据建议去掉这个Shell脚本执行的语句，改为使用Java的API去获取这些信息后，系统很快恢复了正常

一个基于B/S的MIS系统，硬件为两台2个CRJ、8GB内存的HP系统，服务器是WebLogic 9.2 。正常运行一段时间后，最近发现在运行期间频繁出现集群节点的虚拟机进程自动关闭的现象，留下了一个hs_errpid###.log文件后，进程就消失了，两台物理机器里的每个节点都出现过进程崩溃的现象。从系统日志中可以看出，每个节点的虚拟机进程在崩溃前不久，都发生过大量相同的异常：

java.net.SocketException :Connection reset
at java.net.SocketInputStream.read(SocketInputStream.java:168)
at java.io.BufferedlnputStream. fill (BufferedlnputStream. java :218 )
at java.io.BufferedlnputStream.read(BufferedlnputStream.java:235)
at org.apache.axis.transport.http.HTTPSender.readHeadersFromSocket (HTTPSender.java :583 ) at org.apache,axis.transport.http.HTTPSender.invoke(HTTPSender.java:143)
...99 more

这是一个远端断开连接的异常，通过系统管理员了解到系统最近与一个OA门户做了集成，在MIS系统工作流的待办事项变化时，要通过Web服务通知0A门户系统，把待办事项的变化同步到OA门户之中。通过SoapU测试了一下同步待办事项的几个Web服务，发现调用后竟然需要长达3分钟才能返回，并且返回结果都是连接中断。

由于MS系统的用户多，待办事项变化很快，为了不被OA系统速度拖累，使用了异步的方式调用Web服务，但由于两边服务速度的完全不对等，时间越长就累积了越多Web服务没有调用完成，导致在 等待的线程和Socket连接越来越多，最终在超过虚拟机的承受能力后使得虚拟机进程崩溃

解决方法:

1. 通知OA门户方修复无法使用的集成接口
2. 将 异步调用改为生产者/消费者模式的消息队列

一个后台RPC服务器，使用64位虚拟机，内存配置为 -Xms4g -Xmx8g -Xmnlg ， 使用 ParNew+CMS 的收集器组合。平时对外服务的Minor GC时间约在30毫秒以内，完全可以接受。但业务上需要每10分钟加载一个约80MB的数据文件到内存进行数据分析，这些数据会在内存中形成超过100万个 HashMap<Long，Long>Entry ，在这段时间里面Minor GC就会造成超过500毫秒的停顿，对于这个停顿时间就接受不了了，具体情况如下面GC日志所示：

观察这个案例，发现平时的Minor GC时间很短，原因是新生代的绝大部分对象都是可清除的， 在Minor GC之后Eden和Survivor基本上处于完全空闲的状态。而在分析数据文件期间，800MB的Eden空间很快被填满从而引发GC ，但Minor GC之后，新生代中绝大部分对象依然是存活的。ParNew收集器使用的是复制算法，这个算法的高效是建立在大部分对象都 朝生夕灭 的特性上的，如果存活对象过多，把这些对象复制到Survivor并维持这些对象引用的正确就成为一个沉重的负担，因此导致GC暂停时间明显变长

如果不修改程序，仅从GC调优的角度去解决这个问题，可以考虑将Survivor空间去掉(加入参数 -XX:SurvivorRatio=65536 、 -XX:MaxTenuringThreshold=0 或者 -XX :+AlwaysTenure ) ， 让新生代中存活的对象在第一次Minor GC后立即进入老年代，等到Major GC的时候再清理它们。这种措施可以治标，但也有很大副作用，治本的方案需要修改程序 ，因为这里的问题产生的根本原因是用 HashMap<Long，Long> 结构来存储数据文件空间效率太低

   在 HashMap<Long，Long> 结构中，只有Key和Value所存放的两个长整型数据是有效数据，共16B(2x8B)
   
   这两个长整型数据包装成java.lang.Long对象之后，就分别具有8B的MarkWord、8B的Klass指针，在加8B存储数据的long值
   
   在这两个Long队组成Map.Entry之后 ，又多了16B的对象头, 一个8B的next字段和4B的int型的hash字段 ，为了对齐，还必须添加4B的空白填充
   
   最后HashMap中对这个Entry的8B的引用 ，这样增加两个长整型数字。实际耗费的内存为(Long(24B)x2)+Entry(32B)+HashMap Ref(8B)=88B
   
   空间效率为16B/88B=18%，实在太低了

有一个带心跳检测功能的GUI桌面程序，每15秒会发送一次心跳检测信号，如果对方30秒以内都没有信号返回，那就认为和对方程序的连接已经断开。程序上线后发现心跳检测有误报的概率，查询日志发现误报的原因是程序会偶尔出现间隔约一分钟左右的时间完全无日志输出，处于停顿状态

因为是桌面程序，所需的内存并不大( -Xmx256m )， 所以开始并没有想到是GC导致的程序停顿，但是加入參数 -XX:+PrintGCApplicationStoppedTime -XX:+PrintGCDateStamps -Xloggc:gclog.log 后 ，从GC日志文件中确认了停顿确实是由GC导致的，大部分GC时间都控制在100毫秒以内，但偶尔就会出现一次接近1分钟的GC

从GC日志中找到长时间停顿的具体日志信息(添加了 -XX:+PrintReferenceGC 参数)，找到的日志片段如下所示。从日志中可以看出，真正执行GC动作的时间不是很长，但从 准备开始GC 到真正开始GC之间所消耗的时间却占了绝大部分

除GC日志之外，还观察到这个GUI程序内存变化的一个特点， 当它最小化的时候，资源管理中显示的占用内存大幅度减小，但是虚拟内存则没有变化 ，因此怀疑 程序在最小化时它的工作内存被自动交换到磁盘的页面文件之中了，这样发生GC时就有可能因为恢复页面文件的操作而导致不正常的GC停顿

在MSDN上查证后确认了这种猜想，因此，在Java的GUI程序中要避免这种现象，可以加入参数 -Dsun.awt.keepWorkingSetOnMinimize=true 来解决。这个参数在许多AWT的程序上都有应用，例如JDK自带的Visual VM，用于保证程序在恢复最小化时能够立即响应。在这个案例中加入该参数后，问题得到解决

测试机器的Eclipse运行平台是32位Windows 7系统，虚拟机为HotSpot VM 1.5b64。硬件为ThinkPad X201， Intel i5 CPU， 4GB物理内存。在初始的配置文件eclipse.ini中，除了指定JDK的路径、设置最大堆为512MB以及开启了JMX管理(需要在VisualVM中收集原始数据)外，未做其他任何改动

为了要与调优后的结果进行量化对比，调优开始前先做了一次初始数据测试。测试用例很简单，就是收集从Eclipse启动开始，直到所有插件加载完成为止的总耗时以及运行状态数据，虚拟机的运行数据通过VisualVM及其扩展插件VisualGC进行采集。测试过程中反复启动数次Eclipse直到测试结果稳定后，取最后一次运行的结果作为数据样本(为了避免操作系统未能及时进行磁盘缓存而产生的影响)，数据样本如图5-2所示：

Eclipse启动的总耗时没有办法从监控工具中直接获得，因为VisualVM不可能知道Eclipse运行到什么阶段算是启动完成。为了测试的准确性，写了一个简单插件 ，用于统计Eclipse的启动耗时。反复启动几次后，插件显示的平均时间稳定在15秒左右：

根据VisualGC和Eclipse插件收集到的信息，总结原始配置下的测试结果如下：

• 整个启动过程平均耗时约15秒
• 最后一次启动的数据样本中，垃圾收集总耗时4.149秒，其中:
  • Full GC被触发了19次，共耗时3.166秒
  • Minor GC被触发了378次 ，共耗时0.983秒
• 加载类9115个 ，耗时4.114秒
• JIT编译时间为1.999秒
• 虚拟机512MB的堆内存被分配为40MB的新生代(31.5的Eden空间和两个4MB的Surviver空间)以及472MB的老年代

客观地说，由于机器硬件还不错(请以2010年普通PC机的标准来衡量)，15秒的启动时间其实还在可接受范围以内，但是从VisualGC中反映的数据来看，主要问题是非用户程序时间(Compile Time、 Class Load Time、 GC Time)非常之高，占了整个启动过程耗时的一半以上(这里存在少许夸张成分)。虚拟机后台占用太多时间也直接导致Eclipse在启动后的使用过程中经常有不时停顿的感觉，所以进行调优有较大的价值

对Eclipse进行调优的第一步就是先把虚拟机的版本进行升级，希望能先从虚拟机版本身上得到一些免费的性能提升

每次JDK的大版本发布时，开发商肯定都会宣称虚拟机的运行速度比上一版本有了很大的提高，这虽然是个广告性质的宣言，经常被人从升级列表或者技术白皮书中直接忽略过去，但从国内外的第三方评测数据来看，版本升级至少某些方面确实带来了一定的性能改善，以下是一个第三方网站对JDK 1.5、1.6、1.7三个版本做的性能评测，分别测试了以下4个用例:

• 生成500万个的字符串
• 500万次 ArrayList<String> 数据插入，使用第一点生成的数据
• 生成500万个 HashMap<String，Integer> ， 每个键-值对通过并发线程计算，测试并发能力
• 打印500万个 ArrayList<String> 中的值到文件，并重读回内存

三个版本的JDK分别运行这3个用例的测试程序，测试结果如图所示：

从这4个用例的测试结果来看，JDK1.6比JDK1.5有大约15%的性能提升，尽管对JDK仅测试这4个用例并不能说明什么问题，需要通过测试数据来量化描述一个JDK比旧版提升了多少是很难做到非常科学和准确的(要做稍微靠谱一点的测试，可以使用SPEQjvm200来完成，或者把相应版本的TCP中数万个测试用例的性能数据对比一下可能更有说服力)， 但我还是选择相信这次“软广告”性质的测试，把JDK版本升级到1.6 Update 21

这次升级到JDK1.6之后，性能有什么变化先暂且不谈，在使用几分钟之后，发生了内存溢出，如图所示：

打开VisualVM，监视页签中的内存曲线部分如图所示：

在Java堆中监视曲线中， 堆大小 的曲线与 使用的堆 的曲线一直都有很大的间隔距离 ，每当两条曲线开始有互相靠近的趋势时， 最大堆 的曲线就会快速向上转向，而 使用的堆 的曲线会向下转向。 最大堆 的曲线向上是虚拟机内部在进行堆扩容，运行参数中并没有指定最小堆( -Xms ) 的值与最大堆( -Xmx ) 相等，所以堆容量一开始并没有扩展到最大值，而是根据使用情况进行伸缩扩展。 使用的堆 的曲线向下是因为虚拟机内部触发了一次垃圾收集，一些废弃对象的空间被回收后，内存用量相应减少，从图形上看，Java堆运作是完全正常的。但永久代的监视曲线就有问题了， PermGen大小 的曲线与 使用的PermGen 的曲线几乎完全重合在一起，这说明永久代中没有可回收的资源，所以 使用的PermGen 的曲线不会向下发展，永久代中也没有空间可以扩展，所以 PermGen大小 的曲线不能向上扩展。这次内存溢出很明显是 永久代导致的内存溢出

再注意到中永久代的最大容量: 67,108,864个字节 ，也就是64MB，这恰好是JDK在未使用 -XX:MaxPermSize 参数明确指定永久代最大容量时的默认值，无论JDK1.5还是JDK1.6，这个默认值都是64MB。对于Eclipse这种规模的Java程序来说，64MB的永久代内存空间显然是不够的，溢出很正常，那为何在JDK 1.5中没有发生过溢出呢

在VisualVM的 概述-JVM参数 页签中，分别检查使用JDK1.5和JDK1.6运行Eclipse时的JVM参数，发现使用JDK 1.6时，只有以下3个JVM参数

-Dcom.sun.management.jmxremote
-Dosgi.javaRequredVersion=1.5
-Xmx512M

而使用JDK1.5运行时，就有4条JVM参数，其中多出来的一条正好就是设置永久代最大容量的 -XX:MaxPermSize=256M

-Dcom.sun.management.jmxremote
-Dosgi.javaRequredVersion=1.5
-Xmx512M
-XX:MaxPermSize=256M

从Eclipse的Bug List网站上找到了答案:使用JDK1.5时之所以有永久代容量这个参数，是因为在eclipse.ini中存在 -launcher.XXMaxPermSize 256M 这项设置 ，当launcher也就是Windows下的可执行程序eclipse.exe，检测到假如是Eclipse运行在Sun公司的虚拟机上的话，就会把参数值转化为 -XX:MaxPermSize 传递给虚拟机进程，因为三大商用虚拟机中只有Sun系列的虚拟机才有永久代的概念，也就是只有HotSpot虚拟机需要设置这个参数，JRockit虚拟机和IBM J9虚拟机都不需要设置

在2009年4月20日，Oracle公司正式完成了对Sun公司的收购，此后无论是网页还是具体程序产品，提供商都从Sun变为了Oracle，而eclipse.exe就是根据程序提供商判断是否为Sun的虚拟机，当JDK1.6 Update 21中java.exe、javaw.exe的 Company 属性从 Sun Microsystems Inc. 变为 Oracle Corporation 之后，Eclipse就完全不认识这个虚拟机了，因此没有把最大永久代的参数传递过去

解决方法就简单了，launcher不认识就只好由人来告诉它，即在eclipse.ini中明确指定 -XX: MaxPermSize=256M 这个参数就可以了

从Eclipse启动时间上来看，升级到JDK1.6所带来的性能提升是……嗯?基本上没有提升?多次测试的平均值与JDK1.5的差距完全在实验误差范围之内

Sun JDK1.6性能白皮书描述的众多相对于JDK1.5的提升不至于全部是广告，虽然总启动时间没有减少，但在查看运行细节的时候，却发现了一件很值得注意的事情:在JDK1.6中启动完Eclipse所消耗的类加载时间比JDK1.5长了接近一倍，不要看反了，这里写的是JDK1.6的类加载比JDK1.5慢一倍，测试结果如下图所示，反复测试多次仍然是相似的结果：

在本例中，类加载时间上的差距并不能作为一个具有普遍性的测试结果去说明JDK1.6的类加载必然比JDK1.5慢，测试了自己机器上的Tomcat和GlassFish启动过程，并未没有出现类似的差距

多次试验后，发现在机器上两个JDK进行类加载时，字节码验证部分耗时差距尤其严重。考虑到实际情况:Eclipse使用者甚多，它的编译代码可以认为是可靠的，不需要在加载的时候再进行字节码验证，因此通过参数 -Xverify:none 禁止掉字节码验证过程也可作为一项优化措施。加入这个参数后，两个版本的JDK类加载速度都有所提高，JDK1.6的类加载速度仍然比JDK1.5慢，但是两者的耗时已经接近了许多，测试结果：

在取消字节码验证之后，JDK1.5的平均启动下降到了13秒，而JDK1.6的测试数据平均比JDK1.5快1秒，下降到平均12秒左右，在类加载时间仍然落后的情况下，依然可以看到JDK1.6在性能上比JDK1.5稍有优势，说明至少在Eclipse启动这个测试用例上，升级JDK版本确实能带来一些 免费的 性能提升

除了类加载时间以外，在VisualGC的监视曲线中显示了两项很大的非用户程序耗时:编译时间( Compile Time )和垃圾收集时间( GCTime )。垃圾收集时间读该非常清楚了，编译时间是指 虚拟机的JIT编译器 ( Just In Time Compiler )编译热点代码( Hot Spot Code )的耗时。Java语言为了实现跨平台的特性，Java代码编译出来后形成的Class文件中存储的是字节码( Byte Code )，虚拟机通过解释方式执行字节码命令，比起C/C++编译成本地二进制代码来说，速度要慢不少。为了解决程序解释执行的速度问题JDK1.2以后，虚拟机内置了两个运行时编译器，如果一段Java方法被调用次数达到一定程度，就会被判定为热代码交给JIT编译器即时编译为本地代码，提高运行速度(这就是Hot Spot虚拟机名字的由来)。甚至有可能在运行期动态编译比C/C++的编译期静态译编出来的代码更优秀，因为运行期可以收集很多编译器无法知道的信息，甚至可以采用一些很激进的优化手段，在优化条件不成立的时候再逆优化退回来。所以Java程序只要代码没有问题(主要是泄漏问题，如内存泄漏、连接泄漏)，随着代码被编译得越来越彻底，运行速度应当是越运行越快的。Java的运行期编译最大的缺点就是它进行编译需要消耗程序正常的运行时间，这也就是上面所说的 编译时间

虛拟机提供了一个参数 -Xint 禁止编译器运作，强制虚拟机对字节码采用纯解释方式执行。如果想使用这个参数省下Eclipse启动中那2秒的编译时间获得一个 更好看 的成绩的话，那恐怕要失望了，加上这个参数之后，虽然编译时间确实下降到0，但Eclipse启动的总时间剧增到27秒。看来这个参数现在最大的作用似乎就是让用户怀念一下JDK1.2之前那令人心酸和心碎的运行速度

与解释执行相对应的另一方面，虚拟机还有力度更强的编译器:

• 当虚拟机运行在 -client 模式的时候，使用的是一个代号为 C1 的轻量级编译器
• 一个代号为 C2 的相对重量级的编译器能提供更多的优化，如果使用 -server 模式的虚拟机启动Eclipse将会使用到C2编译器，这时从VisualGC可以看到启动过程中虚拟机使用了超过15秒的时间去进行代码编译

如果工作习惯是长时间不关闭Eclipse的话，C2编译器所消耗的额外编译时间最终还是会在运行速度的提升之中赚回来，这样使用-server模式也是一个不错的选择。不过至少在本次实战中，还是继续选用-cllent虚拟机来运行Eclipse

三大块非用户程序时间中，还剩下GC时间没有调整，而GC时间却又是其中最重要的一块，并不只是因为它是耗时最长的一块，更因为它是一个稳定持续的过程。由于做的测试是在测程序的启动时间，所以类加载和编译时间在这项测试中的影响力被大幅度放大了。在绝大多数的应用中，不可能出现持续不断的类被加载和卸载。在程序运行一段时间后，热点方法被不断编译，新的热点方法数量也总会下降，但是垃圾收集则是随着程序运行而不断运作的，所以它对性能的影响才显得尤为重要

在Eclipse启动的原始数据样本中，短短15秒，类共发生了19次FullGC和378次MinorGC，一共397次GC共造成了超过4秒的停顿，也就是超过1/4的时间都是在做垃圾收集，这个运行数据看起来实在太糟糕了

首先来解决新生代中的MinorGC，虽然GC的总时间只有不到1秒，但却发生了378次之多。从VisualGC的线程监视中看到，Eclipse启动期间一共发起了超过70条线程，同时在运行的线程数超过25条，每当发生一次垃圾收集动作，所有用户线程都必须跑到最近的一个安全点(SafePoint)然后挂起线程等待垃圾回收。这样过于频繁的GC就会导致很多没有必要的安全点检测、线程挂起及恢复操作

新生代GC频繁发生，很明显是由于虚拟机分配给新生代的空间太小而导致的，Eden区加上一个Survivor区还不到35MB。因此很有必要使用 -Xmn 参数调整新生代的大小

再来看一看那19次Full GC，看起来19次并“不多”(相对于378次Minor GC来说)，但总耗时为3.166秒，占了GC时间的绝大部分，降低GC时间的主要目标就要降低这部分时间。从Visual GC的曲线图上可能看得不够精确，这次直接从GC日志中分析一下这些Full GC是如何产生的，下面是启动最开始的2.5秒内发生的10次Full GC记录：

括号中加粗的数字代表老年代的容量，这组GC日志显示了10次Full GC发生的原因全部都是老年代空间耗尽， 每发生一次Full GC都伴随着一次老年代空间扩容 :1536KB->1664KB->2684KB……42056KB->46828KB，10次GC以后老年代容量从起始的1536KB扩大到46828KB，当15秒后Eclipse启动完成时，老年代容量扩大到了103428KB，代码编译开始后，老年代容量到达顶峰473MB，整个Java堆到达最大容量512MB

日志还显示有些时候内存回收状况很不理想，空间扩容成为获取可用内存的最主要手段，譬如语句 Tenured:25092K->24656K(25108K)，0.1112429secs ，代表老年代当前容量为25108KB，内存使用到25092KB的时候发生Full GC，花费0.11秒把内存使用降低到24656KB，只回收了不到500KB的内存，这次GC基本没有什么回收效果，仅仅做了扩容，扩容过程相比起回收过程可以看做是基本不需要花费时间的，所以说这0.11秒几乎是白白浪费了

由上述分析可以得出结论:Eclipse启动时， Full GC大多数是由于老年代容量扩展而导致的，由永久代空间扩展而导致的也有一部分 。为了避免这些扩展所带来的性能浪费， 可以把 -Xms 和 -XX:PermSize 参数值设置为 -Xmx 和 -XX:MaxPermSize 参数值一样，这样就强制虚拟机在启动的时候就把老年代和永久代的容量固定下来， 避免运行时自动扩展

根据分析，优化计划确定为:

1. 把新生代容量提升到128MB，避免新生代频繁GC
2. 把Java堆、永久代的容量分别固定为512MB和96MB，避免内存扩展

这几个数值都是根据机器硬件、Eclipse插件和工程数量来决定的，实践的时候应根据Visual GC中收集到的实际数据进行设置

现在这个配置之下，GC次数已经大幅度降低，下图是Eclipse启动后1分钟的监视曲线，只发生了8次Minor GC和4次Full GC，总耗时为1.928秒

这个结果已经算是基本正常，但是还存在一点瑕疵:从OldGen的曲线上看，老年代直接固定在384MB，而内存使用量只有66MB，并且一直很平滑，完全不应该发生Full GC才对，那4次Full GC是怎么来的?使用jstat-gccause查询一下最近一次GC的原因：

从LGCC(Last GC Cause)中看到，原来是代码调用 System.gc() 显式触发的GC，在内存设置调整后，这种显式GC已不符合期望，因此在eclipse.ini中加入参数 -XX:+DisableExplicitGC 屏蔽掉System.gc()。再次测试发现启动期间的Full GC已经完全没有了，只有6次Minor GC，耗时417毫秒，与调优前4.149秒的测试样本相比，正好是十分之一。进行GC调优后Eclipse的启动时间下降非常明显，比整个GC时间降低的绝对值还大，现在启动只需要7秒多：