Java虚拟机性能监控与调优实战
本文针对Java虚拟机对程序性能影响,通过设置不同的Java虚拟机参数来提升程序的性能。首先从Java虚拟机各个性能方面来进行监控,找出Java虚拟机中可能对程序性能影响较大的,然后先通过小实验来证明对程序性能的影响,确定了对程序性能影响较大的指标。最后通过一个实际的项目案例来进行调优,给一定的系统资源下,使网站吞吐量达到最大。 JVM的性能监控 监控的指标和工具 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() {
while(true){
try{
}catch (InterruptedException e) {
}
System.out.println("Runnable"+Thread.currentThread().getName());
}
}){
while(true){
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。
jstat:虚拟机运行时信息监控
jstat是用来监控JVM运行时的状态信息的工具,可以查看JVM中类的装载、堆内存的详细信息、垃圾收集等等。我们编写如下测试代码,
import java.util.ArrayList;
import java.util.List;
public class HeapOOM {
staticclass OOMObject {
}
publicstatic void main(String[] args) {
List<OOMObject>list = new ArrayList<OOMObject>();
while(true){
list.add(newOOMObject());
}
}
图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%。说明永久代已经溢出了。
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 定位到有异常的类
JVM垃圾回收对性能的影响
Java虚拟机中的垃圾回收器就是为了识别和回收垃圾对象,从而实现自动回收内存。为了让垃圾收集器正常并且高效的工作,在垃圾回收器工作时候系统会进入一个停顿的状态。系统停顿的目的是终止所有线程的运行,这样系统中就不会有新垃圾产生,垃圾回收器也可以更好的标记垃圾回收对象。在垃圾回收时,应用程序都会发生短暂的停顿,停顿现象发生时,整个应用程序都没有响应,应用程序会卡死。这个停顿现象也称为“Stop-The-World”。我们编写如下测试代码,
import java.util.HashMap;
public class StopWorldTest {
publicstatic class MyThread extends Thread{
HashMapmap = new HashMap();
if(map.size()*512/1024/1024>= 900) {
map.clear();
System.out.println("cleanmap");
byte[]b1;
for(inti = 0; i < 100; i++) {
b1= new byte[512];
map.put(System.nanoTime(),b1);
Thread.sleep(1);
catch (Exception e) {
publicstatic class PrintThread extends Thread {
publicstatic final long starttime = System.currentTimeMillis();
longt = System.currentTimeMillis() - starttime;
System.out.println(t/1000+"."+t%1000);
publicstatic void main(String args[]) {
MyThreadt = new MyThread();
PrintThreadp = new PrintThread();
t.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.5216409secs] [Times: user=1.51 sys=0.00, real=1.52 secs]
在程序打印的28.925秒处发生了1.52秒的停顿,这就能说明GC对运行程序的影响。
JVM的栈溢出
其中Java堆和虚拟机栈是比较容易出现溢出的现象,这部分实验是用来演示Java虚拟机栈出现溢出的现象,实验中我们防止虚拟机自己扩展Java虚拟机栈的大小,通过设置参数Xss=128k来控制Java虚拟机栈所允许的最大深度,本次实验我们设置为128K大小。我们编写如下测试代码:
publicclass JavaVMStackSOF {
private int stackLength = 1;
public void stackLeak() {
stackLength++;
stackLeak();
}
public static void main(String[] args) throwsThrowable {
JavaVMStackSOF oom = newJavaVMStackSOF();
try {
oom.stackLeak();
catch (Throwable e) {
System.out.println("stacklength:"+ oom.stackLength);
throw e;
}
}
图3.10 测试Java虚拟机栈
如图3.10所示,报Java虚拟机栈溢出错误。在Xss为128K大小。同时代码中也输出了线程请求的栈深度最大为2401。
调优案例 实验环境及案例
实验平台基于的操作系统是windowsserver 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发展及重要性的凸显,第三方的可视化监控工具出现了,在本实验中采用可视化的VisualVM工具来监控JVM,方便数据的查看和做实验分析。
图4.1 案例网站的首页
图4.2 系统结构图
实验工具使用
图4.3和图4.4是采用Visual VM监控工具得到的,如图4.3所示我们可以看到CPU使用1%不到,堆的大小,已装载类的总数量为7546,如图4.4所示我们会发现,总共GC次数是214次,共耗时2.751秒,其中MinorGC 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链接
网站吞吐量测试及提高 通过增大Java堆容量提升网站吞吐量
通过在Tomcat中catalina.bat文件中设置虚拟机参数,刚开始设置JVM堆大小为32M,setJAVA_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情况
通过指定垃圾收集器来提升网站的吞吐量
垃圾收集器为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情况
根据垃圾收集器种类和堆内存大小来做整体的优化
堆内存大小设为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情况
参考资料:《深入理解java虚拟机》