一次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四次挥手断开连接了解了整个过程。 （图片来自网络）
 
比如客户端应用程序发起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配置

<Connector port="8080" protocol="org.apache.coyote.http11.Http11NioProtocol" connectionTimeout="30000"
        enableLookups="false" maxThreads="2048" minSpareThreads="100" acceptCount="512" URIEncoding="UTF-8"/>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的消耗在哪来分析单次请求耗时点。 
 
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次账号信息，可以考虑把该账号信息放置到缓存或者内存之类的。 
可以从业务角度去考虑优化，比如某个扩展业务直接影响到主业务的性能，且该扩展业务本身不是那么重要，可以考虑通过缩减该扩展业务的方式做到优化。