抱歉,您的浏览器无法访问本站
本页面需要浏览器支持(启用)JavaScript
了解详情 >

JVM性能调优实战

环境准备

linux环境

测试环境需要1台Linux支持

IP 开放端口 内存 说明
192.168.xx.xx 8080 4GB 运行web项目

jdk安装

jdk使用的版本为jdk8,需要在Linux服务器中安装jdk8

以下全部操作均在root下执行

下载jdk8

JDK下载页面下载JDK,如下:

解压jdk压缩包
1
2
tar -zxvf jdk-8u251-linux-x64.tar.gz #解压jdk压缩包
mv jdk1.8.0_251/ /usr/local/lib #将jdk压缩包放到 /usr/local/lib目录下
生成软连接配置环境变量
1
2
ln -s /usr/local/lib/jdk1.8.0_251/ /usr/local/jdk #使用/usr/local/jdk指向jdk的存放路径
vim /etc/profile #编辑环境变量

文件末尾添加如下内容:

1
2
export JAVA_HOME=/usr/local/jdk
export PATH=$JAVA_HOME/bin:$PATH

激活环境变量配置

1
source /etc/profile #激活环境变量
验证jdk安装成功
1
java -version #查看java版本

安装tomcat

1
2
3
4
cd /use/local/tomcat
wget http://mirrors.tuna.tsinghua.edu.cn/apache/tomcat/tomcat-8/v8.5.34/bin/apache-tomcat-8.5.34.tar.gz
# 解压tomcat
tar -zxvf apache-tomcat-8.5.34.tar.gz

对tomcat进行优化配置

修改server.xml
1
vim server.xml
禁用AJP服务

禁用AJP服务,一般是使用Nginx+tomcat的架构,所以用不着AJP协议,所以把AJP连接器禁用。

1
<!-- <Connector port="8009" protocol="AJP/1.3" redirectPort="8443" />-->
设置线程池

设置线程池,并且调整最大并发线程数

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
<!--将注释打开-->
<Executor name="tomcatThreadPool" namePrefix="catalina-exec-"
maxThreads="500" minSpareThreads="50" prestartminSpareThreads="true" maxQueueSize="500"/>
<!--
参数说明:
maxThreads:最大并发数,默认设置 200,一般建议在 500 ~ 1000,根据硬件设施和业务来判断
minSpareThreads:Tomcat 初始化时创建的线程数,默认设置 25
prestartminSpareThreads: 在 Tomcat 初始化的时候就初始化 minSpareThreads 的参数值,如果不等于
true,minSpareThreads 的值就没啥效果了
maxQueueSize,最大的等待队列数,超过则拒绝请求
-->
<!--在Connector中设置executor属性指向上面的执行器-->
<Connector executor="tomcatThreadPool"  port="8080" protocol="HTTP/1.1"
       connectionTimeout="20000"
       redirectPort="8443" />
使用NIO2

设置tomcat运行模式为nio2,tomcat的运行模式有3种:bio、nio、apr,其中nio2是nio的升级版,在
tomcat8中才支持的,建议采用nio2模式

1
<Connector executor="tomcatThreadPool"  port="8080" protocol="org.apache.coyote.http11.Http11Nio2Protocol" connectionTimeout="20000" redirectPort="8443" />
启动Tomcat测试
1
2
cd /usr/local/test/apache-tomcat-8.5.34/bin
./startup.sh && tail -f ../logs/catalina.out

打开浏览器进行测试访问

http://192.168.xx.xx:8080/

如果访问到首页 就完成了 tomcat优化

部署web项目

将需要测试的war包上传到linux服务器,然后在tomcat上面部署

1
2
3
4
5
6
7
cd /usr/local/apache-tomcat-8.5.34/webapps
rm -rf *
mkdir ROOT
cd ROOT/
mv test.war /usr/local/test/apache-tomcat-8.5.34/webapps
jar -xvf test.war
rm -rf test.war

压力测试

配置TomcatGC参数

配置默认GC 参数,为了效果故意将jvm内存调整小 -Xms64m -Xmx128m

并配置打印GC日志信息

这里使用jdk1.8的默认垃圾回收器

jdk1.8 默认垃圾收集器Parallel Scavenge(新生代)+Parallel Old(老年代)

编辑catalina.sh

tomcat启动执行的是tomcat/bin/startup.sh,startup.sh执行的是catalina.sh,所以要在catalina.sh中进行设置

在catalina.sh 的开头加入如下配置

1
2
3
4
5
6
cd /usr/local/apache-tomcat-8.5.34/bin
#编辑catalina.sh
vi catalina.sh

# 添加jvm参数配置
JAVA_OPTS="-Xms64m -Xmx128m -Xlog:gc*:../logs/gc.log -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps -XX:+PrintHeapAtGC -Xloggc:../logs/gc.log"

参数说明
  • -XX:+PrintGC 输出GC日志
  • -XX:+PrintGCDetails 输出GC的详细日志
  • -XX:+PrintGCTimeStamps 输出GC的时间戳(以基准时间的形式)
  • -XX:+PrintGCDateStamps 输出GC的时间戳(以日期的形式,如 2013-05-04T21:53:59.234+0800)
  • -XX:+PrintHeapAtGC 在进行GC的前后打印出堆的信息
  • -Xloggc:../logs/gc.log 日志文件的输出路径
启动tomcat
1
2
cd /usr/local/apache-tomcat-8.5.34/bin
./startup.sh
查看日志

查看catalina.out的日志检查修改JVM参数是否生效

1
2
cd /usr/local/apache-tomcat-8.5.34/logs
tail -100f catalina.out

出现如下参数说明我们的修改已经生效

jmeter使用

jmeter 使用参考 jmeter 使用

进行压测

创建测试用例

配置线程组

配置线程组使用200的并发进行测试,每个线程执行100次,总数为20000次请求

查看tomcat日志

压测后查看tomcat是否有报错日志

出现GC overhead limit exceeded 错误

​ GC overhead limt exceed检查是Hotspot VM 1.6定义的一个策略,通过统计GC时间来预测是否要OOM了,提前抛出异常,防止OOM发生。Sun 官方对此的定义是:“并行/并发回收器在GC回收时间过长时会抛出OutOfMemroyError。过长的定义是,超过98%的时间用来做GC并且回收了不到2%的堆内存。用来避免内存过小造成应用不能正常工作。

因为我们故意将堆内存调小 所以基本上可以确认是堆内存过小导致垃圾回收频繁

解决办法
  1. 增加heap堆内存。
  2. 增加对内存后错误依旧,获取heap内存快照,使用Eclipse MAT工具,找出内存泄露发生的原因并进行修复。
  3. 优化代码以使用更少的内存或重用对象,而不是创建新的对象,从而减少垃圾收集器运行的次数。如果代码中创建了许多临时对象(例如在循环中),应该尝试重用它们。
  4. 升级JDK到1.8,最起码也是1.7,并使用G1GC垃圾回收算法。
  5. 除了使用命令-xms1g -xmx2g设置堆内存之外,尝试在启动脚本中加入配置:
查看压测结果

查看关键指标

平均响应时间:6418ms
吞吐量:24.7/sec (每秒的请求量)
错误率:1.78%

GC日志解析

GCeasy介绍

官网地址:https://gceasy.io/,GCeasy是一款在线的GC日志分析器,可以通过GC日志分析进行内存泄露检测、GC暂停原因分析、JVM配置建议优化等功能,而且是可以免费使用的(有一些服务是收费的)。

使用

上面我们介绍了各个垃圾收集器的GC日志,我们打开GCeasy的官网,上传我们的GC日志(我这里用的Parallel收集器),点击Analyze进行分析即可得到报告,得到的报告可以进行下载。由于报告内容比较多,我就捡几个主要的截个图简单说明一下,其他的可以自己看一下,而且可以自己试试不同的垃圾收集器的GC日志的分析报告有什么区别。

Problem detected

出现如下界面说明已经检测到了问题,这里面说是内存问题,但是详细信息需要收费

大概意思是:我们的机器学习算法已经识别出内存问题,查看问题和建议的解决方案需要成为我们的付费用户。

JVM memory size

这一部分分别使用了表格和图形界面来展示了JVM堆内存大小。如图所示:

​ 左侧分别展示了年轻代的内存分配分配空间大小(Allocated)和年轻代内存分配空间大小的最大峰值(Peek),然后依次是老年代(Old Generation)、元数据区(Meta Space)、堆区和非堆区(Young + Old + Meta Space)总大小。值得注意的是,每一代的最大内存利用率都会超过分配的大小,但是图中的内存分配利用率已经超过了峰值内存了。

​ 在jvm内存统计中可以看出,年轻代与老年代在高峰时,基本将可用空间都占满了,说明内存空间不足,需要调整内存大小。

Key Performance Indicators

这一部分是关键的性能指标,如图:

关键指标中,吞吐量为95.042%,gc平均停顿时间为165 ms,最大停顿时间为510 ms
可以看出,在初始状态时,吞吐量并不高,最大停顿时间较长,平均停顿时间也比较长。

参数描述
  • Throughput:表示的是吞吐量
  • Latency:表示响应时间
    • Avg Pause GC Time: 平均GC时间
    • Max Pause GC TIme :最大GC时间

Interactive Graphs

这一部分是GC的各种状态的一个图表

Heap After GC

第一部分是Heap after GC,GC后堆的内存图,堆是用来存储对象的,从图中可以看出,随着GC的进行,垃圾回收器把对象都回收掉了,因此堆的大小逐渐增大。

在图表中可以看出,gc之后堆内存的使用基本是在100m左右,红色的三角是Full GC,我们看到有大量的Full GC,也证明了内存不足频繁的Full GC。

Heap before GC

第二部分是Heap before GC,这是GC前堆的使用率,可以看出随着程序的运行,堆使用率越来越高,堆被对象占用的内存越来越大。

在图表中可以看出,gc之前的堆内存的使用在高峰时,将占80m~100m之间。

GC Duration Time

第三部分是GC Duration Time,就是GC持续时间。从图中可以看到,发生Full GC的时间持续的比较端,而Young GC持续的时间比较长。图中横坐标表示GC发生的时间段,纵坐标表示的是GC持续时间。

在gc持续时间统计中,可以看出full gc的时间要远高于younggc的时间,在调优时应当尽量的减少full gc。

Reclaimed Bytes

第四部分表示的是GC回收掉的垃圾对象的内存大小。

​ 从图中可以看出,Full GC仅仅回收不到1M的对象,而Young GC则回收的对象比较多,大部分发生在10m~30m左右。

​ 回收最多的次是发生在full gc可以推断此次是内存即将耗尽,发生了fullgc,释放了大量的内存空间,这也是在前面年轻代对象有部分进入到老年代,在此次fullgc时被清理了。

​ 后面Full GC很频繁并且基本没有什么回收,基本可以确定频繁GC 导致 stw 没有请求能够进来导致回收不了。

Young GC

第五部分表示的是Young Gen,年轻代的内存分配情况。对象都是朝生夕死,年轻代存放的就是刚刚产生的对象,每进行一次GC,都会GC掉很多垃圾对象,剩下的就是右GC Root关联的对象,这些对象会年龄会逐渐增加,达到了一定阈值就会晋升为老年代的对象。

可以看到before GC表示的图线随着时间的进行逐渐增大,也就是年轻代中对象越来越多,而GC事件发生后,年轻代中对象就会减少,也就是after GC图线表示的内存变化趋势。

从年轻代的gc情况来看,gc之前与gc之后差较大,说明垃圾对象在年轻代被清理的比较多,就是说临时性的对象居多。

Old Gen

第六部分是Old Gen,表示的是老年代的内存分配情况。细心的读者会发现,为啥一开始before GC的内存大小比after GC的内存分配要少呢?这里得先知道老年代存放的都是年龄大的对象,意思就是经过了多次GC都没有被GC掉的对象,就会晋升为老年代的对象。所以这就解释了为啥after GC内存要比before GC内存要大,因为每次GC过后,都会有年轻代的对象晋升为老年代对象。

从老年代的gc情况来看,gc之前与之后的差并不大,说明老年代的垃圾对象并不是很多。

Meta Space

第七部分是Meta Space,表示的是元数据区内存分配情况。

Meta Space空间充足,基本没有变化,占用空间40m左右。

A&P

第八部分表示的是堆内存分配和晋升情况。

从该图中看出,晋升到老年代的对象与可以分配对象相比,非常的少,也说明了上面我们看到的,对象主要集中在young区。

GC Statistics

GC 分析数据

左图:表示的是堆内存中Minor GC和Full GC回收垃圾对象的内存。
中图:总计GC时间,包括Minor GC和Full GC,时间单位为ms。
右图:GC平均时间,包括了Minor GC和Full GC。

接下来则分别表示的是总GC统计,MinorGC的统计,FullGC的统计,GC暂停程序的统计。

分析结果

在GC统计中,可以看出:

  • Minor GC清理掉的垃圾对象合计15.28gb,说明产生的临时对象非常的多
  • Minor GC的执行间隔为73ms,说明发生gc的行为是比较频繁的
  • Full GC发生了846次,非常频繁
  • Full GC的平均持续时间为171ms,时间较长
  • GC的暂停次数为690次,暂停次数将影响到服务的响应时间

Object Stats

接下来是对象统计,Total Created Bytes表示的是创建的字节总数,Total promoted bytes表示的是晋升的字节总数,Avg creation rate表示的是平均创建字节率,Avg promotion rate表示平均的晋升率。

在对象的统计中,可以看出对象的平均生成率:81.15m/s,平均的晋升率:5.25mb/s。

Memory Leak

​ 由于记录的程序没有内存泄漏,所以这里就没有内存泄漏的日志信息。此处可以诊断8种OOM中的5种(Java堆内存溢出,超出GC开销限制,请求数组大小超过JVM限制,Permgen空间,元空间)。

GC Causes

CG所花费的时间,也就是停顿线程的时间。

在GC原因统计中可以看出,大部分发生gc的原因都为分配失败,也就说内存不足导致;

需要说明的是虽然发生了4次Metadata GC,并不是Metaspace不足导致,前面我们看到Metaspace空间充足,而是该gc发生在最开始时间,说明初始的Metaspace不足,导致了Metaspace扩容,并发生了GC,可以适当调整Metaspace初始大小以减少Metadata GC次数。

GC 调优

调整内存

根据分析得出 主要是 内存不足导致的,并行临时对象居多,我们先进行内存调整,将内jvm堆内存调整为2G,并且使用默认的垃圾收集器

JVM 配置
1
-Xms2048m -Xmx2048m -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps -XX:+PrintHeapAtGC -Xloggc:../logs/gc.log
压测结果

查看关键指标变化

平均响应时间:6418ms -> 850ms
吞吐量:24.7/sec -> 217.5/sec(每秒的请求量)
错误率:1.78% -> 0.00%

我们发现直接增加内存 性能提升还是很可观的

分析GC日志

上传GC日志继续分析

JVM memory size

我们发现新生代和老年代基本上都有剩余空间,内存应该没有问题

Key Performance Indicators

GC 的 停顿时间以及最大停顿时间有所增加是因为 内存增加的缘故,吞吐量还是不高在82左右

GC Statistics

和原来相比 Minor GC以及Full GC 的次数都有大幅度降低,并且Full GC由原来的864 降低到2次,Full GC回收的数据也很少,说明大量的垃圾在新生代已经被回收了,总的停顿时间由2分钟降低到20秒,优化很不错。

增加年轻代大小

根据方才的优化发现老年代还是晋升了很多垃圾,并且老年代垃圾相对还是比较多,分析得出大部分都是临时对象,将年轻代增加到1G

JVM 配置
1
-Xms2048m -Xmx2048m -XX:NewSize=1024m -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps -XX:+PrintHeapAtGC -Xloggc:../logs/gc.log
压测结果

查看关键指标变化

平均响应时间:850ms -> 638ms
吞吐量: 217.5/sec -> 249.3/sec(每秒的请求量)
错误率:0.00%

我们发现增加年轻代后,响应时间和吞吐量有少许提升

分析GC日志

上传GC日志继续分析

JVM memory size

我们发现新生代垃圾比较多,老年代基本上很少了,说明大部分垃圾在年轻代已经被清理了

Key Performance Indicators

GC 的 停顿时间以及最大停顿时间降低很多,说明大部分在新生代被清理了,老年代没有过多的清理,吞吐量也有了大幅度提升,到了 95左右

GC Statistics

和原来相比Minor GC 的平均响应时间有所降低,停顿时间也有大幅度降低

使用G1 垃圾收集器

选择性能更优的垃圾收集器也是调优的手段之一,在jdk8中,使用率最高的当属G1收集器了,下面我们就尝试切换成G1收集器,来看下它的表现。

JVM 配置

这里XX:MaxGCPauseMillis 是期望GC停顿时间,我们上面压测最好的结果实在160ms左右,这里我们设置为150ms

1
-XX:+UseG1GC -XX:MaxGCPauseMillis=150 -Xms2048m -Xmx2048m -XX:NewSize=1024m -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps -XX:+PrintHeapAtGC -Xloggc:../logs/gc.log
压测结果

查看关键指标变化

平均响应时间:638ms -> 542ms
吞吐量: 249.3/sec -> 331.8/sec(每秒的请求量)
错误率:0.00%

我们发现使用G1垃圾收集器后,响应时间和吞吐量有了大幅度提升

分析GC日志

上传GC日志继续分析

JVM memory size

我们发现新生代垃圾比较多,老年代基本上很少了,说明大部分垃圾在年轻代已经被清理了

Key Performance Indicators

GC 的 停顿时间有所降低,最大停顿时间有所增加,G1在GC停顿时间上优化不多,但是在吞吐量上有所增加,提升到了97以上

Phases Statistics

G1 GC Time

我们G1 停顿时间很少平均停顿时间56.2ms 最大停顿时间5s,总结可以得出G1是一个更加优秀的垃圾收集器。

评论