![数据库CPU因一次压力测试而飙升 第1张 数据库CPU因一次压力测试而飙升 第1张](https://www.yuneu.com/zb_users/upload/2024/06/20240621203026171897302675842.jpg)
这是2024年的第43篇文章
( 本文阅读时间:15分钟 )
一次压测过程中,当数据库的qps和tps都正常时,如果cpu利用率异常的高,应该如何排查?希望通过这篇文章,给你一些启发...
01
业务背景
业务需要控制频道内兑换现金的数量,于是在产品设计上给兑换现金增加了库存限制。
在此基础上形成了秒杀场景,峰值时核心接口qps上涨了近600倍(几十到几万) ,因此需要进行压测来对系统和DB水位摸一下高。
02
压测准备
大致分为下面几个步骤:
1)压测流量评估:就是定一下每个接口大致压测多少qps,以及压测时到各个下游系统的流量估计。
2)压测改造:因为压测都是用的压测账户,在频道里没有历史痕迹,很多逻辑是走不到的,并且这些逻辑的不同,会直接影响到数据库和下游的流量,因此我们需要根据频道的现有数据进行链路的mock(包括上述的流量评估也得基于这些不同链路的比例去算),举例如下:
![数据库CPU因一次压力测试而飙升 第2张 数据库CPU因一次压力测试而飙升 第2张](https://www.yuneu.com/zb_users/upload/2024/06/20240621203026171897302615606.jpg)
3)测试&发布:既然改了代码,还是得交给可爱的测试同学回归下线上链路的,当然压测的链路就可以自己测一测了,看看改造是否符合预期,hsf控制台可以很方便的模拟影子链路:
![数据库CPU因一次压力测试而飙升 第3张 数据库CPU因一次压力测试而飙升 第3张](https://www.yuneu.com/zb_users/upload/2024/06/20240621203026171897302612369.jpg)
4)下游流量报备:当然还是得跟各个下游系统知会一声的,切勿悄悄滴进村,打枪滴不要。
5)压测数据准备:主要是压测平台上的各种接口和压测流量配置(注意减去压测时的背景流量),以及压测账号申请等等(这一步也是交给测试同学)。
6)小流量预跑:在正式压测之前,大概用1%的流量先跑一下,看看本身系统以及下游是否有异常(这一步很有必要,有时候下游系统比较复杂,可能部分场景并不能支持压测流量,提前跑一下能发现很多问题,避免正式压测的时候下游报警,然后就是忙乱)。
03
问题出现
好了,万事具备,经过上面一系列步骤,想必本次压测一定是顺顺利利吧!
压测,启动!
====== 10%压测流量,cpu利用率11% ====== 挺正常
====== 30%压测流量,cpu利用率20% ====== 稳中向好
====== 50%压测流量,cpu利用率30% ====== 符合预期
====== 80%压测流量,cpu利用率50% ====== 感觉有点问题,但是说不出来哪里有问题!
====== 100%压测流量,cpu利用率80% ===== 嗯?好像不对劲?有点高
====== 100%压测流量,稳定几分钟后,突然飙到100% ===== .....,肯定有问题,暂停压测!
唉,还是太年轻了。
赶紧排查,先拉了压测时间段的cpu曲线图:
![数据库CPU因一次压力测试而飙升 第4张 数据库CPU因一次压力测试而飙升 第4张](https://www.yuneu.com/zb_users/upload/2024/06/20240621203027171897302756718.png)
看着cpu的监控图,我的脑海里浮现了三个疑问:
1.同等流量下,压测时的cpu利用率为什么高于线上实际值(线上约等于压测80%流量时,cpu利用率实际40%不到,压测时已经到60%了)?
2.流量80%时,为什么压测流量持续不动,cpu利用率会缓慢上涨呢?
3.流量100%时,分明一开始cpu利用率还维持在80%以下,然后突然就飙到100%了?
总体来说,就是CPU高于预期。
04
问题排查
第一时间我猜测是我的压测改造不符合预期,导致打到db的qps和tps过高导致。
急了,开始看代码,然后挑了几个压测trace在鹰眼上看调用,没找到问题。
然后发现我好蠢呐(主要是有点慌张),dbservice本身就有tps和qps的监控:
![数据库CPU因一次压力测试而飙升 第5张 数据库CPU因一次压力测试而飙升 第5张](https://www.yuneu.com/zb_users/upload/2024/06/20240621203027171897302752328.jpg)
看了一下,有两点,一是持续压测的时候,qps并没有持续上涨,二是差不多同流量下qps的值确实略高于线上实际值,但远远没有cpu差值这么多,所以基本可以排除一开始的猜测。
陷入了瓶颈.....
这时候我知道今天的压测指定是不行了,所以很干脆地摆了,开始安心的找问题~
4.1 发现疑点
这时候拉了DBA同学一起帮我们看问题,DBA同学表示,一,数据库在长时间高压下会发生性能劣化,这也是cpu从80%突然暴涨到100%的原因(解答了第三个问题),至于CPU利用率异常是表象,qps和tps只是其中一个影响因素,建议我们看看其他指标。
于是挨个查看数据库性能指标(带宽、慢sql、RT....),然后终于发现了一个疑点:
![数据库CPU因一次压力测试而飙升 第6张 数据库CPU因一次压力测试而飙升 第6张](https://www.yuneu.com/zb_users/upload/2024/06/20240621203027171897302775383.png)
这个缓慢升高的行读,非常符合压测流量80%时cpu曲线的变化,很可能是问题二的原因...
那是不是也有可能是问题一的原因呢?
4.2 确认疑点
对比正常峰值流量下的行读指标
![数据库CPU因一次压力测试而飙升 第7张 数据库CPU因一次压力测试而飙升 第7张](https://www.yuneu.com/zb_users/upload/2024/06/20240621203028171897302839725.png)
好吧,这都差了一个数量级了,基本可以确定问题出在行读异常上了
开始思考为什么行读这么多还在持续上涨,难道是同一个sql查出来的行数会变多?
4.3 定位sql
其实这时候心里已经隐隐约约猜到问题在哪了,但还是顺着这个行读异常排查下去
通过对比定位到了有问题的sql
压测时:
![数据库CPU因一次压力测试而飙升 第8张 数据库CPU因一次压力测试而飙升 第8张](https://www.yuneu.com/zb_users/upload/2024/06/20240621203028171897302820972.jpg)
正常时:
![数据库CPU因一次压力测试而飙升 第9张 数据库CPU因一次压力测试而飙升 第9张](https://www.yuneu.com/zb_users/upload/2024/06/20240621203028171897302869744.jpg)
点进去也能看到具体的sql信息:
![数据库CPU因一次压力测试而飙升 第10张 数据库CPU因一次压力测试而飙升 第10张](https://www.yuneu.com/zb_users/upload/2024/06/20240621203028171897302824585.jpg)
好吧,和我猜的一样,这下悬着的心终于死了。
4.4 代码分析
至于为什么同一条sql压测的平均行读会高这么多,还是得从代码层面来分析。
首先先看下改造逻辑和逻辑推导:
![数据库CPU因一次压力测试而飙升 第11张 数据库CPU因一次压力测试而飙升 第11张](https://www.yuneu.com/zb_users/upload/2024/06/20240621203028171897302826521.jpg)
这么压测改造的原因是压测的账号是有限的(同一批压测账号重复的去轮询),如果所有账号都调过一遍接口,那后面的每次查询都能查到任务,不会再有DB写,为了更好的模拟线上实际情况,因此通过这种方法去让账号重新路由到注册逻辑。
然后看下任务的查询逻辑,如下:
PRivate TaskInstanceParam createQueryParamByEffectiveTime(TaskQueryParam queryParam) { final TaskInstanceParam dbQueryParam = new TaskInstanceParam(); Date now = TimeTravelManager.getCurrentTime(queryParam.getUserId()); dbQueryParam.createCriteria() .andUserIdEqualTo(queryParam.getUserId()) .andBizTyPEEqualTo(queryParam.getBizType()) .andTemplateIdEqualTo(queryParam.getSubBizType()) .andEffectiveStartTimeLessThanOrEqualTo(now) .andEffectiveEndTimeGreaterThan(now); dbQueryParam.appendOrderByClause(OrderCondition.EFFECTIVESTARTTIME, SortType.DESC); dbQueryParam.setPagination(1, 1); return dbQueryParam; }
其实就是查询符合 effectiveStartTime <= now < effectiveEndTime 的最新一条任务, 所以每次注册插入的任务,都会在下次同一账号查询时,为sql多加一条符合条件的行记录。
至此原因已经很清晰了:随着压测的持续进行,每一个账户注册的任务条数会越来越多,因此同一条sql查询到的符合条件的行数会越来越多,CPU就会花费越来越多的资源逐行处理。
后续的解法:
1)查询的时候mock到数据的userId(提前准备好的线上实际来访userId,随机取一个);
2)因为不影响查询了,所以插入逻辑不变。
05
原理刨析
接下来请ChatGpt老师上台,为我们普及下相关原理:
我 :什么是行读,行读高cpu利用率就高嘛?
![数据库CPU因一次压力测试而飙升 第12张 数据库CPU因一次压力测试而飙升 第12张](https://www.yuneu.com/zb_users/upload/2024/06/20240621203029171897302971676.jpg)
我 :哦,听起来行读是比较笼统的概念,那什么是逻辑读和物理读呢,区别在哪里?
![数据库CPU因一次压力测试而飙升 第13张 数据库CPU因一次压力测试而飙升 第13张](https://www.yuneu.com/zb_users/upload/2024/06/20240621203029171897302970691.jpg)
我:嗯哼,原理解释有点干燥,画个关系图(挑衅)?
![数据库CPU因一次压力测试而飙升 第14张 数据库CPU因一次压力测试而飙升 第14张](https://www.yuneu.com/zb_users/upload/2024/06/20240621203029171897302989854.jpg)
我:啊?阿珍你来真的啊?
我:那总结一下,其实就是行读包括逻辑读和物理读两种,前者优于后者,平时的开发中,应该注意合理建立索引和优化sql,来减少扫描整体行读数以及物理读的次数呗,说的对就夸一下我?
![数据库CPU因一次压力测试而飙升 第15张 数据库CPU因一次压力测试而飙升 第15张](https://www.yuneu.com/zb_users/upload/2024/06/20240621203029171897302973260.jpg)
06
反思
1.压测流量80%时,就应该敏感地关注到cpu是高于日常水位的,其实可以避免压测调到100%的cpu飙升;
2.对于DB的性能指标,压测时只关注了最表层的cpu利用率,其他的性能指标监控没有关注到位;
3.对于我们的任务场景下,查询的是有效期内的最新一条任务,实际上不太适合反复注册的压测mock,所以在压测改造时,还需要关注改造方式与场景的匹配程度。
作者:昀鹤
来源-微信公众号:阿里技术
出处:https://mp.weixin.qq.com/s/n0U3g-R0KmZ97RhH9dzWiw
发表评论