基于 Yii 2 的 ActiveRecord,在运行期间,Redis的CPU使用率为100%的分析、解决

1、在2017-06-18 19:36:00,即比赛开始的时候,应用的响应时间为51.8ms,响应时间正常,如图1

图1

2、在整个足球比赛期间,响应时间呈线性不断增加,在2017-06-18 20:30:00 至 2017-06-18 20:40:00,响应时间下降,是因为此时比赛处于中场休息期间,基本上发送至服务器的比赛数据无变化,因此处理逻辑简单,如图2

图2

3、在2017-06-18 21:25:00,即比赛即将结束的时候,应用的响应时间为2320ms,业务目标所要求的平均响应时间为150ms,因此性能无法满足业务要求,如图3

图3

4、在APM的Transaction trace中,可以发现在一次响应时间为5710 ms的请求中,Redis相关的操作就消耗了4390 ms,占用的比例为77%,httpclient是调用了另一个接口,其接口中也使用了Redis的,因此,分析结果为Redis为性能瓶颈所在,如图4

图4

5、在APM的Transaction trace的 Trace details中,发现 shujujiexi\models\redis\GamePlayerData::gamePlayerDataByShuJuJieXi 所消耗时间占用的比例为 57.25%,如图5

图5

6、继续展开,直到无法展开为止,发现 yii\redis\Connection::parseResponse ,需要分析其运行机制,如图6

图6

7、在阿里云监控中,在2017-06-18 19:36:00,即比赛开始的时候,Redis的CPU使用率为1.9%,如图7

图7

8、在整个足球比赛期间,在阿里云监控中,Redis的CPU使用率呈线性不断增加,在2017-06-18 20:30:00 至 2017-06-18 20:40:00,Redis的CPU使用率下降,是因为此时比赛处于中场休息期间,基本上发送至服务器的比赛数据无变化,因此处理逻辑简单,整个曲线与响应时间完全成正比关系,如图8

图8

9、在阿里云监控中,在2017-06-18 21:27:00,即比赛即将结束的时候,Redis的CPU使用率为100%,如图9

图9

10、在阿里云监控中,在2017-06-18 21:28:00,即比赛即将结束的时候,Redis的已用连接数为54个,达到峰值,如图10

图10

11、现在需要分析究竟是何原因导致Redis的CPU使用率为100%了,在APM的Transaction trace中,发现 yii\redis\ActiveRecord::deleteAll 所消耗时间占用的比例为 78%,如图11

图11

12、在APM的Transaction trace的 Trace details中,发现 Application code (in yii\redis\ActiveRecord::deleteAll) 最为消耗时间,基本上可以确定ActiveRecord相关的操作为导致Redis的CPU使用率为100%的根本原因了,如图12

图12

13、在pro环境,准备实现一个典型请求的2个版本,第1个版本的ActiveRecord相关的操作基本上为查询、修改,第2个版本的ActiveRecord相关的操作基本上为查询、插入,以便于确认当某个ActiveRecord模型中的key数量过多时,是否会提升Redis的CPU使用率,先清空Redis,之后定时任务所生成的Redis数据,key的数量为3170,如图13

图13

14、在pro环境,请求的第1个版本运行2个小时之后,Redis数据,key的数量为3220,仅增加了50个key,如图14

图14

15、在pro环境,在整个典型请求的运行期间,在阿里云监控中,Redis的CPU使用率最高为2.6%,在 2017-06-27 16:50:00 之后,Redis的CPU使用率维持在0.6%,是因为此时,基本上发送至服务器的比赛数据无变化,因此处理逻辑简单,如图15

图15

16、在pro环境,在整个典型请求的运行期间,响应时间基本上保持稳定,最大响应时间为266ms,此请求的业务目标在生产环境上所要求的平均响应时间为200ms,因此性能满足业务要求,在 2017-06-27 16:50:00 之后,响应时间下降,是因为此时,基本上发送至服务器的比赛数据无变化,因此处理逻辑简单,如图16

图16

17、先清空Redis,之后定时任务所生成的Redis数据,key的数量为2909,如图17

图17

18、在pro环境,请求的第2个版本运行2个小时之后,Redis数据,key的数量为89840,增加了86931个key,如图18

图18

19、请求的第2个版本所操作的Redis模型的key的数量为79527,如图19

图19

20、在pro环境,请求的第2个版本,在整个典型请求的运行期间,在阿里云监控中,Redis的CPU使用率最高为66.8%,如图20

图20

21、基于当前分析结果,已经可以确定当ActiveRecord操作的某个模型的key的数量过大时,Redis的CPU使用率会大幅度提升,不过是由于查询还是插入导致的,需要进一步确认,代码,如图21

图21

22、修改查询方案,将count(‘id’)调整为exists(),即查询模型中满足条件的所有key调整为查询模型中满足条件的1个key,代码,如图22

图22

23、不清空Redis,在pro环境,请求的第3个版本所操作的Redis模型的key的数量为81277,如图23

图23

24、在pro环境,请求的第3个版本,在整个典型请求的运行期间,在阿里云监控中,Redis的CPU使用率最高为11.8%,如图24

图24

25、基于当前分析结果,已经可以确定当ActiveRecord操作的某个模型的key的数量过大时,Redis的CPU使用率会大幅度提升,并且是与查询的关联性最大,不过查询与插入的性能对比,需要进一步确认,代码,注释掉查询,只保留插入操作,如图25

图25

26、不清空Redis,在pro环境,请求的第4个版本所操作的Redis模型的key的数量为81947,如图26

图26

27、在pro环境,请求的第4个版本,在整个典型请求的运行期间,在阿里云监控中,Redis的CPU使用率最高为2.2%,如图27

图27

28、将count()调整为exists()以提升查询性能,如图28

图28

29、将一些ActiveRecord实现重构为Redis原生命令实现,在整个足球比赛期间,在阿里云监控中,Redis的CPU使用率最高为21.1%,因此响应时间正常,如图29

图29

30、总结:Yii 2 的 ActiveRecord,相关方法对于Redis的CPU计算压力排行:insert() < one()/exists() < count()/all(),当某个Redis模型的key的数量超出10000后,如果要执行查询(有where条件)操作,建议不要使用ActiveRecord,如图30

图30

永夜