Java虚拟机的性能监控与调优

3 JVM的性能监控
3.1 监控的指标和工具
3.1.2  jps：虚拟机进程状况工具
利用jps工具可以显示当前虚拟机中运行的java进程，并且jps后面可以跟参数，-l是输出主类名，-v可以输出JVM启动时候的参数配置。写了如下一段java代码做了个测试。
package com.ctgu.chenjun;


public class TraditionalThread {

public static void main(String[] args) {
Thread thread = new Thread() {
public void run() {
while(true) {

try {
Thread.sleep(1000);
} catch (InterruptedException e) {
e.printStackTrace();
}

System.out.println("1:"+Thread.currentThread().getName());
}
}
};
thread.start();

Thread thread2 = new Thread(new Runnable() {

@Override
public void run() {
while(true) {

try {
Thread.sleep(1000);
} catch (InterruptedException e) {
e.printStackTrace();
}

System.out.println("2:"+Thread.currentThread().getName());
}
}
});
thread2.start();
new Thread(new Runnable() {
@Override
public void run() {
while(true) {

try {
Thread.sleep(1000);
} catch (InterruptedException e) {
e.printStackTrace();
}

System.out.println("Runnable"+Thread.currentThread().getName());
}

}
}){
public void run() {
while(true) {

try {
Thread.sleep(1000);
} catch (InterruptedException e) {
e.printStackTrace();
}

System.out.println("3:"+Thread.currentThread().getName());
}
}
}.start();
}
}

 

图3.1 jsp监控java运行进程

 
图3.2 jsp输出JVM启动时参数
如图3.1所示有个TraditionalThread进程在运行，显示主类的全名，进程号为3396，jps工具本身也是一个java程序，进程号为5424，进程号3584就是main函数所在的进程了。一共有3个进程在运行。如图3.2所示，jsp –v输出了JVM启动加载jdk里面内置的tools.jar等等，JVM的参数配置，堆内存最小为40M，堆内存最大为512M，永久代最大为256M。

3.1.2  jstat：虚拟机运行时信息监控

jstat是用来监控JVM运行时的状态信息的工具，可以查看JVM中类的装载、堆内存的详细信息、垃圾收集等等。我们编写如下测试代码，
package com.ctgu.chenjun;
import java.util.ArrayList;
import java.util.List;




public class HeapOOM {
static class OOMObject {
}


public static void main(String[] args) {
List<OOMObject> list = new ArrayList<OOMObject>();
while(true) {
list.add(new OOMObject());
}
}


}

 

图3.3 JVM运行时类装载

 

图3.4 JMV运行时堆内存信息

如图3.3所示，Loaded表示加载了15944个类，Bytes表示载入类的合计大小，Unloaded表示卸载类数量为50个，第2个Bytes表示卸载类的大小，Time表示在加载类和卸载类上所花费的时间。如图3.4所示，S0C表示是s0的大小为6144字节，S0C表示是s1的大小为6144字节，S0U表示是s0区已使用大小为0，S1U表示是s1区已使用大小为0，Eden大小为49728字节，Eden：S1 ：S0 = 8:1:1，满足之前的分代内存模型。EU表示Eden已使用4463.3字节，OC表示老年代大小为123908个字节，OU表示老年代已使用55962.2字节。PC表示永久代大小为61952字节，PU表示已使用61746.6字节。YGC表示新生代发生GC的次数为25次，YGCT表示新生代GC的耗时为0.504秒，FGC表示Full GC的次数为60次，FGCT耗时为17.268秒，GCT表示GC的总耗时为17.772秒。

 

图3.5 显示堆内存各区域使用百分比

如图3.5所示s0区域使用百分比为0，s1区域使用百分比为0，Eden区域使用大小2.45%，老年代区域使用大小为46.42%，永久代区域使用大小为99.88%。说明永久代已经溢出了。


3.1.3  jmap：导出堆文件分析
我们继续用3.1.2中代码做测试，并且通过设置参数-Xms20m -Xmx20m设置堆内存大小为20M，通过设置参数-XX:+HeapDumpOnOutOfMemoryError让虚拟机在发生内存溢出时将当前的堆内存转存为快照，方面后面对堆内存做分析，甚至可以找出堆内存泄露的原因。还需要用到一款内存分析工具MAT(Memory Analyzer Tool)，是一个功能强大、可视化的Java heap内存分析工具，它可以帮助我们分析Java堆内存泄漏和内存消耗的情况。使用MAT内存分析工具对堆内存的使用情况进行分析，堆内存中各个对象的占用内存大小及各个对象的数量一清二楚的，看看是哪个存活的对象阻止了垃圾收集器的回收工作，并可以通过报表直观的查看到可能造成内存泄露的对象，从而再去找出内存泄露的代码。

 

图3.6 MAT分析堆快照

如图3.6所示利用MAT工具对堆内存的快照进行分析，堆内存剩余空间为369.5kb，说明堆内存空间不足；如图3.7所示，图片表明这个OOMObject类的实例最多，达到了1215488个，那么很明显这个数据是有异常的，程序怎么会调用一个类的这么多实例呢。接下来对这个类进一步观察和分析，如图3.8所示，有这么多个Object类的实例，接着去代码中排查，找到可能出现Object类的局部代码，那就是List<OOMObject> list = new ArrayList<OOMObject>()一直死循环；因为OOMObject的实例对象放入ArrayList中会被转成Object数据类型。通过MAT堆内存分析工具找到了内存泄露的原因了，然后对局部代码做修改，避免内存泄露。
 
图3.7 MAT分析进一步分析堆快照
 
图3.8 定位到有异常的类


3.2 JVM垃圾回收对性能的影响
Java虚拟机中的垃圾回收器就是为了识别和回收垃圾对象，从而实现自动回收内存。为了让垃圾收集器正常并且高效的工作，在垃圾回收器工作时候系统会进入一个停顿的状态。系统停顿的目的是终止所有线程的运行，这样系统中就不会有新垃圾产生，垃圾回收器也可以更好的标记垃圾回收对象。在垃圾回收时，应用程序都会发生短暂的停顿，停顿现象发生时，整个应用程序都没有响应，应用程序会卡死。这个停顿现象也称为“Stop-The-World”。我们编写如下测试代码，
package com.ctgu.chenjun;


import java.util.HashMap;


public class StopWorldTest {
public static class MyThread extends Thread{
HashMap map = new HashMap();
public void run() {
try {
while(true) {
if(map.size()*512/1024/1024 >= 900) {
map.clear();
System.out.println("clean map");
}
byte[] b1;
for(int i = 0; i < 100; i++) {
b1 = new byte[512];
map.put(System.nanoTime(), b1);
}
Thread.sleep(1);
}
} catch (Exception e) {

}
}
}
public static class PrintThread extends Thread {
public static final long starttime = System.currentTimeMillis();
public void run() {
try {
while(true) {
long t = System.currentTimeMillis() - starttime;
System.out.println(t/1000+"."+t%1000);
Thread.sleep(100);
}
} catch (Exception e) {

}
}
}
public static void main(String args[]) {
MyThread t = new MyThread();
PrintThread p = new PrintThread();
t.start();
p.start();
}
}
在上面代码中开启了两个线程，PrintThread线程是每0.1秒在控制台上进行一次时间戳的输出，MyThread则不停地消耗堆内存资源，从而引发GC的运行。并且设置了一个临界值，当内存消耗大于900M时，清空内存，防止堆内存溢出。
并且通过参数指定虚拟机堆内存大小为1G,新生代大小为512k，指定使用Serial垃圾回收器，并且输出GC日志。程序运行的部分结果如图3.9所示，
 
图3.9 程序运行的部分结果
大约是每隔0.1秒就会有次输出，但是从28.572秒到30.173秒有着1.601秒的时间间隔。
28.925: [GC28.925: [DefNew: 448K->448K(448K), 0.0000472 secs]28.925: [Tenured: 1047926K->1040159K(1048064K), 1.5213508 secs] 1048374K->1040159K(1048512K), [Perm : 1655K->1655K(12288K)], 1.5216409 secs] [Times: user=1.51 sys=0.00, real=1.52 secs]
在程序打印的28.925秒处发生了1.52秒的停顿，这就能说明GC对运行程序的影响。


3.3 JVM的栈溢出
其中Java堆和虚拟机栈是比较容易出现溢出的现象，这部分实验是用来演示Java虚拟机栈出现溢出的现象，实验中我们防止虚拟机自己扩展Java虚拟机栈的大小，通过设置参数Xss=128k来控制Java虚拟机栈所允许的最大深度，本次实验我们设置为128K大小。我们编写如下测试代码：
public class JavaVMStackSOF {

private int stackLength = 1;

public void stackLeak() {
stackLength++;
stackLeak();
}

public static void main(String[] args) throws Throwable {
JavaVMStackSOF oom = new JavaVMStackSOF();
try {
oom.stackLeak();
} catch (Throwable e) {
System.out.println("stack length:"+ oom.stackLength);
throw e;
}
}


}

 

图3.10 测试Java虚拟机栈

如图3.10所示，报Java虚拟机栈溢出错误。在Xss为128K大小。同时代码中也输出了线程请求的栈深度最大为2401。


4 调优案例
4.1 实验环境及案例
实验平台基于的操作系统是windows server 2008，JDK是1.7版本，tomcat是7.0版本。硬件的推荐配置如表4-1所示：
表4-1 系统硬件配置
名称 规格和数量
CPU AMD10 4核
内存 8G DDR3 内存
本实验中调优所用案例是一个Javaweb的网站如图4.1所示，网站所采用的主要技术是Spring加上Hibernate框架，数据库采用的是主流的Mysql数据库。实验原理：选择不同的垃圾回收器和堆大小对Java应用程序的性能有一定的影响；本实验将配置不同的虚拟机参数启动Tomcat服务器，通过压力测试，获得虚拟机的主要性能指标，体验不同的参数对系统性能的影响。通过JMeter对Tomcat增加压力测试，设置不同的虚拟机参数Tomcat服务器将会有不同的性能表现，Tomcat的性能表现就体现在网站的吞吐量，通过观察不同参数配置对吞吐量的影响。系统结构如图4.2所示为防止JMeter对Tomcat产生影响，测试时使用两台独立的计算机，通过局域网相连。文中第三节对JVM监控采用的工具都是JDK自带的控制台工具，随着JVM发展及重要性的凸显，第三方的可视化监控工具出现了，在本实验中采用可视化的Visual VM工具来监控JVM，方便数据的查看和做实验分析。

 

图4.1 案例网站的首页

 

图4.2 系统结构图

4.2 实验工具使用
图4.3和图4.4是采用Visual VM监控工具得到的，如图4.3所示我们可以看到CPU使用1%不到，堆的大小，已装载类的总数量为7546，如图4.4所示我们会发现，总共GC次数是214次，共耗时2.751秒，其中Minor GC 201次，耗时1.325秒，Full GC 13次，耗时1.426秒，这就说明我们堆内存不够大，导致GC频繁发生。

 

图 4.3 Tomcat运行时情况

 

图 4.4 Tomcat运行时JVM堆内存及GC的情况

Jmeter软件是Apache组织开发的，是对Java编程语言做的压力测试工具，在本实验中将采用Jmeter来对web网站做压力测试，通过Jmeter提供的聚合报告来查看网站的吞吐量，最终的目的是让网站吞吐量达到最大。压力测试的线程组是固定的，为了做对比分析，如图4.3所示，开启了10个线程，在一秒内启动，每个线程访问500次，总的访问量就是5000.服务器IP、端口及资源路径配置如图4.6所示，前提是网站拦截器要注销掉，因为这样不用登陆就可以访问网站首页资源了。然后通过聚合报告得到网站吞吐量的数据。 

图 4.5 压力测试的线程组

 

图4.6 http请求配置

4.3 网站吞吐量测试及提高
4.3.1  通过增大Java堆容量提升网站吞吐量
通过在Tomcat中catalina.bat文件中设置虚拟机参数，刚开始设置JVM堆大小为32M，set JAVA_OPTS=”-Xloggc:gc.log -XX:+PrintGCDetails –Xmx32M –Xms32M”,如下图4.7所示，直接堆内存溢出，说明设置堆内存过小。

 

图 4.7 堆内存溢出

于是将堆内存改为64M，set JAVA_OPTS=”-Xloggc:gc.log -XX:+PrintGCDetails -Xmx64M -Xms64M”，可以正常运行，并通过Jmeter来进行压力测试，通过聚合报告来看网站吞吐量，VisualVM观察堆的内存使用的情况来优化网站吞吐量。图4.8是聚合报告，吞吐量是462.1/s.图4.9分别是堆内存GC的情况。如图所示GC所用时间为1.036秒，其中Minor GC 71次，用时613.172毫秒，Full GC 4次用时423.062毫秒，说明给的堆内存大小还比较合适，因为Full GC的次数较少。但是Minor GC次数有点多，说明年轻代空间偏小。

 

图 4.8 堆为64M的聚合报告

 

图 4.9 堆为64M的GC情况

于是将堆内存改为128M，set JAVA_OPTS=”-Xloggc:gc.log -XX:+PrintGCDetails –Xmx128M –Xms128M”， 可以正常运行，并通过Jmeter来进行压力测试，通过聚合报告来看网站吞吐量，VisualVM观察堆的内存使用的情况来优化网站吞吐量。图4.10是聚合报告，吞吐量是921.5/s.图4.11分别是堆内存GC的情况。如图所示GC总次数为37次，所用时间为690.028毫秒，其中Minor GC35次，用时226.35毫秒，Full GC 2次用时240.984毫秒，这就说明给的堆内存大小还比较大，因为Full GC的次数很少。Minor GC次数正常，其中垃圾回收占用时长很小，所以堆内存为128M比64M的吞吐量高很多。

 

图 4.10 堆为128M的聚合报告

图 4.11 堆为128M的GC情况

4.2.2 通过指定垃圾收集器来提升网站的吞吐量
垃圾收集器为CMS，堆内存大小为64M，set JAVA_OPTS=” -Xloggc:gc.log -XX:+PrintGCDetails -Xmx64M -Xms64M -XX:+UseConcMarkSweepGC”。 并通过Jmeter来进行压力测试，通过聚合报告来看网站吞吐量，VisualVM观察堆的内存使用的情况来优化网站吞吐量。图4.12是聚合报告，吞吐量是1035.6/s。图4.13分别是堆内存GC的情况。如图所示GC所用时间为868.786毫秒，其中Minor GC 71次，用时472.29毫秒，Full GC 21次用时396.496毫秒。那是因为CMS收集器优点就是：并发收集、低停顿。是一种以获取最短回收停顿时间为目标的收集器，很适合B/S系统的服务端，希望系统停顿短暂，给用户较好的体验。但是还是有缺点，缺点是对CPU资源敏感，当CPU资源不是很充足时，反而会降低吞吐量。 

 

图 4.12 堆为64M、CMS垃圾收集器的聚合报告

 

图 4.13 堆为64M、CMS垃圾收集器的GC情况

另外一个缺点是CMS会产生大量空间碎片，因为CMS是基于标记-清除算法实现的垃圾收集器，所以Full GC的次数会到达21次。
垃圾收集器为G1，堆内存大小为64M不变，set JAVA_OPTS=” -Xloggc:gc.log -XX:+PrintGCDetails -Xmx64M -Xms64M -XX:+UseG1GC”。 并通过Jmeter来进行压力测试，通过聚合报告来看网站吞吐量，VisualVM观察堆的内存使用的情况来优化网站吞吐量。图4.14是聚合报告，吞吐量是655.6/s。图4.15分别是堆内存GC的情况。如图所示GC所用时间为1.584秒，其中Minor GC102次，用时1.584秒，Full GC 0次用时0。G1垃圾收集器是最前沿的成果，有并发收集、分代收集、整理碎片功能，所以Full GC次数为0，但是G1是应用到整个堆上，虽然有分代的概念，但是老年代和年轻代不再是物理隔离的，而是一块不连续的区域，G1会在后台维护一个优先列表，根据回收的空间和时间来确定回收哪一块空间。这样来说对于新生代老说不是太好，因为新生代空间小，本来会频繁发生GC，所以对整体吞吐量提升不是太高，期待JDK团队研究出更高级版本的G1。

 

图4.14 堆为64M、G1垃圾收集器的聚合报告

 

图4.15 堆为64M、G1垃圾收集器的GC情况

4.4 根据垃圾收集器种类和堆内存大小来做整体的优化
堆内存大小设为1024M，垃圾收集器用CMS，永久区大小设为512M，set JAVA_OPTS=” -Xloggc:gc.log -XX:+PrintGCDetails -Xmx1024M -Xms1024M -XX:+UseConcMarkSweepGC -XX:PermSize=512M”。 并通过Jmeter来进行压力测试，通过聚合报告来看网站吞吐量，VisualVM观察堆的内存使用的情况来优化网站吞吐量。图4.16是聚合报告，吞吐量是1455.2/s。图4.17分别是堆内存GC的情况。如图所示GC所用时间为311.244毫秒，其中Minor GC6次，用时311.244毫秒，Full GC 0次用时0。这次实验中，同时增加了永久区的大小，是因为从之前的日志里发现永久代也触发了GC，虽然次数很少。和前面实验对比，这次实验的吞吐量最高，吞吐量也提升了很多。

 

图4.16 堆为1024M、垃圾收集器为CMS、永久区为512M的聚合报告

 图4.17 堆为1024M、垃圾收集器为CMS、永久区为512M的GC情况