1. 问题的现象
此前抢购时段,系统响应速度很慢。起初查了一下数据库的慢查询,做了很多SQL优化。
渐渐的,当数据库的慢查询降低了一大批之后,主库0.3s的阀值基本都没剩多少。请求响应的平均时段已经降低到500ms。
突然,新的现象发生了,Jedis连接池开始报错。
所有的错误都是这一个:
Could not get a resource from the pool
2. 初步尝试
仔细看了一下源码,就是连接池拿不到连接。配置已经写了最大50个线程,最大等待50ms。
起初把连接数增加到100个,看了一下有缓和,报错少了一点,但是总体响应时间没什么提升。
后来怀疑是不是TCP建立连接导致瞬时网络请求过多,然后把最大等待时间改到100ms,最大连接数改到50个,报错数量没什么变化,总体响应时间略微延长。
整体感觉好像跟连接池没啥关系,就重新去分析整体链路。
2. 问题的排查
2.1 系统的链路
nginx -> tomcat --连接池--> twemproxy --单线程--> redis
2.2 定位瓶颈
仔细分析了一下整个系统的链路,观察链路上每台机器的表现。
tomcat应用:CPU偏高,峰值可以去到80%多,均值也在40%
twemproxy:机器资源使用比较正常
redis:机器资源很低,独占物理机
起初怀疑是不是tomcat所在机器的CPU问题导致,但是通过机器调整,发现有的机器原来表现好的,加入了更高配的机器,表现会变差。总体没有改观,表现更像是一个公共资源的竞争,谁能抢到谁就快。
2.3 可能存在的问题
起初怀疑有两种可能:
- 公用宿主机的资源抢占
a. 符合的现象:在比较空闲的宿主机上,表现会比机器资源少的VM要好
b. 不符合的现象:为什么机器配置那么好,还是会报错 - 公共网络带宽的抢占
a. 符合的现象:一个远程机房比本地机房错误数量多很多
b. 不符合的现象:起初两边差别很明显,后来两边问题出现数量又差不多了(中间出现了一次twemproxy ip的飘移,变到另外一个代理上去了,可能是这个引起的,未深究,但最后的现象排除了网络问题的可能)
所以,我初步判断可能问题在twemproxy上,它也是公共资源。
3.4 twemproxy的分析
3.4.1 验证假设
直接先在上面用tcprstat进行抓包,看看实际tcp的耗时
timestamp count max min avg med stddev 95_max 95_avg 95_std 99_max 99_avg 99_std
1553220001 13183 268863 75 3101 510 10735 13837 1187 2256 54200 2325 6474
1553220002 13472 820293 650 17587 14331 33983 47133 12710 6322 114430 14874 12630
1553220003 29429 715253 376 4797 2874 9475 12935 3681 2933 21747 4174 3777
1553220004 27724 799628 181 7645 6302 10045 17490 6759 4598 23827 7266 5148
1553220005 27296 424576 151 4586 2652 6692 17075 3693 3300 20673 4294 4367
刚好与我们看到的现象完全一致,每次都是第2秒开始到第3秒集中报错,这个响应延迟也刚好出现在那一秒。
3.4.2 问题分析
redis是一个对网卡敏感的应用,查了一下是万兆网卡,整机流量并不高。
然后,为了最大程度减少网络和网卡的干扰,直接把twemproxy和redis部署在同一台物理机上。结果一测性能飙升,整体表现极其完美。
进一步追查,运维同学告知系统采用的CentOS 6.8版本,其网卡驱动采用的是单队列模式,在极端高并发的情况下,性能会急剧下降。将系统升级至CentOS 7.3版本,采用多队列模式可以解决问题。
3.4.3 插曲
中间也怀疑过,是不是twemproxy的配置不合理,毕竟只配置了一个线程。后来找到作者对这个解释,结合一些性能分析。
如果配置了多线程会带来一个问题,如果使用了pipeline,到twemproxy可能就会被分到不同的线程去执行,因而导致执行并非是按预期的,所以结果可能会出错。
但是,twemproxy自己为了提升的性能,做了两个重要的工作,一个是采用了“zero copy”技术,另一个是把命令也打包成一个pipeline批量执行。因此,他的性能损耗有人测试也就大约10%。
4 后记
这个问题处理完,抢标的性能问题告一段落。峰值响应速度从原来最坏去到2s降低到不足100ms,而且从zabbix监控上都快看不出来抢购的峰值了。