一次tomcat压测调优记录

1. 前言

该tomcat web应用承担集团登录注册页面功能,对性能有一定要求,由于先前没有太多相关经验(只压测过一个dubbo服务),这次调得比较艰辛,便做个记录。

创新互联公司主要为客户提供服务项目涵盖了网页视觉设计、VI标志设计、营销推广、网站程序开发、HTML5响应式网站建设移动网站建设、微商城、网站托管及成都企业网站维护、WEB系统开发、域名注册、国内外服务器租用、视频、平面设计、SEO优化排名。设计、前端、后端三个建站步骤的完善服务体系。一人跟踪测试的建站服务标准。已经为不锈钢雕塑行业客户提供了网站营销推广服务。

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四次挥手断开连接了解了整个过程。 (图片来自网络)
一次tomcat压测调优记录 
比如客户端应用程序发起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的消耗在哪来分析单次请求耗时点。 
一次tomcat压测调优记录 
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,平均响应时间<100ms,错误率<0.01%,稳定运行,CPU<80%,无内存溢出,Full GC间隔时长>30分钟,gc时长<150ms 
配置资源数:各线程池、连接池大小,内存分配大小,tomcat连接数

3.2 制定压测目标 
TPS >= (80% * 单日访问量) / (40% * 24 * 60 * 60),线上80%的请求量几种在40%的时间,根据线上情况进行调整

3.3 如何配置资源数 
根据平均响应时间和TPS计算tomcat线程池大小,TPS/(1/RT),比如TPS>=5000,平均响应时间<=100ms,线程池大小配置5000/10,再往上调整CPU数目的整数比例(这种计算方式不一定好,主要响应时间这个不太好定,上下会相差较大,) 
数据库连接池或其他线程池大小可先设定为tomcat线程大小的一半,根据压测结果再进行调优

3.4 压测指标及对应查看工具 
CPU,top/visualvm 
内存,free查看系统内存使用情况/jmap可查看最大使用的内存对象以及dump全部堆/visualvm/mat查看dump分析内存泄露对象及其引用 
磁盘IO,iostat 
磁盘空间,df -hl 
网络带宽,iptraf 
连接数,netstat 
线程,top -Hp pid/jstack pid/visualvm/tda查看线程dump/jprofile监控实时线程block情况 
FULL GC,-Xloggc:/path/gc.log开启gclog后查看gclog、jstat -gc 
响应时长,jprofile查看耗时较大的函数

3.5 定位瓶颈分三步走 
检查压测端瓶颈,可通过压一个恒定标准测试(比如压空的test.jsp),基本就在压测初期检查一次就差不多 
通过查看压测指标变化情况定位资源瓶颈,再根据资源瓶颈定位程序瓶颈 
比如根据监控显示每次GC后堆内存呈上涨趋势,可在两次GC之后分别查看占用内存较大的对象,对比这些对象的数目和大小,如果有明显上涨较厉害的,可特别查看下 
TODO图片 
在第二步查看问题中,可能出现影响因素较多的情况,这样可通过mock掉部分怀疑的因素或者单压某怀疑因素 
比如系统中使用的外围服务包括数据库、redis,现在怀疑可能是查数据库或者在查redis的时候导致吞吐量上不去,此时可通过mock掉数据库的查询查看下吞吐量是否有提升,如果有提升则说明多半是数据库查询导致

3.6 优化 
在定位到瓶颈点之后,相对来说优化就没那么复杂,无外乎对瓶颈资源的少用、复用和交换资源。 
比如在程序中一个请求下来会查询N次账号信息,可以考虑把该账号信息放置到缓存或者内存之类的。 
可以从业务角度去考虑优化,比如某个扩展业务直接影响到主业务的性能,且该扩展业务本身不是那么重要,可以考虑通过缩减该扩展业务的方式做到优化。


新闻名称:一次tomcat压测调优记录
标题网址:http://scyanting.com/article/poshgc.html