QQ叫紫珊 发表于 2018-12-3 10:45:15

一次tomcat压测调优记录

1. 前言
该tomcat web应用承担集团登录注册页面功能,对性能有一定要求,由于先前没有太多相关经验(只压测过一个dubbo服务),这次调得比较艰辛,便做个记录。
2. 调优过程
起初没有给运维任何tomcat配置要求,同时也没留意去确认tomcat配置,这个导致了后续压测过程各种诡异的问题。
a.在压测初期,持续请求10分钟左右出现无请求进来,netstat查看的tomcat所在服务器存在大量CLOSE_WAIT的连接。
CLOSE_WAIT的连接一般是自己程序中缺少关闭连接等引起,但是查看程序也没发现哪里没有关闭,而且大多CLOSE_WAIT是与浏览器端的http协议下的tcp连接。后经运维排查是centos自身的BUG引起,升级到centos-release-6-6.el6.centos.12.2.x86_64后解决。
其中对于CLOSE_WAIT和TIME_WAIT的TCP连接起初一直不太理解是怎么出现,怎么解决,后详细查看TCP四次挥手断开连接了解了整个过程。 (图片来自网络)
http://img.blog.csdn.net/20151024103749050
比如客户端应用程序发起CLOSE信息,服务端接收到后进入CLOSE_WAIT状态并做ACK,之后服务端程序发起CLOSE信息,客户端接收到之后进入TIME_WAIT,服务端收到客户端的ACK之后进入CLOSED状态,客户端TIME_WAIT需要等待到超时才进入CLOSED状态。
基于此,服务器端出现大量CLOSE_WAIT不是一个正常的状态,首先需要确认CLOSE_WAIT状态对方的IP,再查看这个IP对应的代码是否缺少关闭连接。
但是如果出现大量TIME_WAIT,不是太要紧,只要不占满句柄就行,如果真的占满了可以尝试修改内核TCP超时时间和TCP的TIME_WAIT重用。
b.然后压测500个并发出现connection timeout和read timeout,这种情况基本是在请求数超过了配置的最大值,一开始找运维排除nginx和vm的限流,然后再查看tomcat的限制,发现tomcat未配置最大线程数,默认情况最大线程数是200,最大等待队列100,然后修改tomcat的server.xml配置
12调整protocol使用nio的,调整最大线程(maxThreads)为2048用于压测,最小空闲线程数(minSpareThreads)100,接收请求队列最大(acceptCount)为512
,到这里压1000或者2000并发都不会出现拒绝请求的情况。
这里再细化下connection timeout和read timeout,connection timeout处于连接还没建立就超时的状态,如果不是网络问题,多半是maxThreads+acceptCount不够处理并发请求,可以尝试增加这两个值;read timeout是建立连接后,一种是等待在队列太久没处理导致超时、一种是程序自身执行时间太久,可通过access log记录请求执行时长排查。
c.再压一段时间后,出现请求响应慢,请求进不来,此时大多是connection refused(由于先前调整的线程池,一直还在排查线程池问题),后来查看gc日志发现一直在做full gc并且老年代内存无法释放,由于没有指定过gc方式,当时以为是gc引起,所以先调整了gc配置为cms
记录gc日志和服务挂掉时dump内存配置
-XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/vol/logs/heap.bin -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -Xloggc:/vol/logs/gc.log1修改为cms的gc方式的配置
-XX:+UseConcMarkSweepGC -XX:+UseParNewGC -XX:+UseCMSCompactAtFullCollection -XX:CMSFullGCsBeforeCompaction=10 -XX:+CMSClassUnloadingEnabled -XX:+CMSParallelRemarkEnabled -XX:MaxTenuringThreshold=15 -XX:CMSInitiatingOccupancyFraction=70 1对CMS的GC理解不深,大致知道默认的gc方式是阻塞应用,CMS采用并发标记清理的方式,后续再翻书学习下。TODO
d.通过修改gc方式得到了一定的缓解,在压测不到30分钟左右时发现又出现吞吐量降低,响应非常慢的问题;
大致知道是有很多对象没释放,通过jmap查看前20个占用最大的对象(./jmap -histo pid | head -n 20 ),好像都还好,最大的是session不过也才300多M(估计是当时刚好不在压力期间已经被释放完了);
然后在出现慢的时候dump了全部内存下来,但是实在太大了(5G),下载太久;
之后把堆内存调整为1G并压到出现慢,查看dump也是session最大,占百分之八十左右,这时候还没意识到是session的问题,以为1G太小看不出根本问题;
再把堆内存调整为2G并压到出现慢,查看dump发现session占了1.5G,突然灵光一闪,我这边request session是封装放到redis的,本地的tomcat session占这么大是不对的。。。(闪得也太迟了点吧),然后把tomcat的session超时时间设置成一分钟果然不会再出现频繁FULL GC的问题。再查看代码,原来是封装的session的地方脑抽的写了个super.getSession(true)。默认配置下每次请求来都会生成新的session,并且超时时间是30分钟,在内存中占30分钟才被销毁!!
看起来上面的问题都非常明显。。。但是在一个压测环境下去找这些问题源头是什么真是麻烦死了。。
e.好了,最后一步,光明就在不远的前方。压测结果不算太理想,tps在4800左右,不过最起码长时间压下来算是稳定了。之后通过jprofile工具查看cpu的消耗在哪来分析单次请求耗时点。
http://img.blog.csdn.net/20150927214704344
jprofile去连接远程机器时需要在远程机器开启agent,执行bin/jpenable后选择是给gui访问然后填写端口即可。
f.这里再记录下稳定压测后想做一些优化遇到的问题:
这边在尝试提高TPS的时候,发现查看所有的压测指标资源貌似都未被占满,但是吞吐量始终上不去(应该是哪个未留意到的资源被占满了),tomcat线程池一半不到,cpu百分之70左右浮动,堆内存1G不到,磁盘IO在百分之八左右,带宽占用很低(速度在80k/s)tcp连接数在1W+
排查这个问题时首先怀疑到可能是使用到的一个后端http服务跟不上,通过mock掉该服务后无明显提升
后怀疑是tomcat没配置正确,然后空压一个test.jsp,tps在2W+
再怀疑是redis没使用正确,在空test.jsp前使用一个redis session filter,相当于只压redis,tps也在1W8到2W+
这个时候已排除了所有的外围服务,确认了是自身程序的问题,通过jprofile去查看耗时较大的一个函数,发现ua解析较慢,通过将解析结果放到threadlocal,tps得到小幅增长,从4800到5000+
然后发现log4j的block较多,通过将log4j的级别调整到ERROR后,tps一下能到7000+,但是还是不能理解,后有同事说可能是磁盘IO次数的限制,这个当时没有关注到的点,但是环境已被撤除。
3. tips
3.1 压测开始前准备
设定压测业务场景:比如用户从加载登录页面到使用账号密码登录完成
准备压测环境:与线上同等配置的服务器以及数据量,资源无共享的纯净环境
根据线上需求制定压测目标:比如TPS>1000,平均响应时间
页: [1]
查看完整版本: 一次tomcat压测调优记录