〇、经验总结:

  • 在关注业务接口的TPS时,也要关注数据库服务器的QPS。如果一个业务流程里包含多条查询,那么业务接口TPS的上升对数据库服务器QPS的放大效应会很明显。
  • 如果查询结果集不大,尽量使用一条查询语句,通过子查询返回多个结果集,避免将多个结果集拆分成多次数据库查询,否则会造成过多的数据库连接/查询操作,消耗IO资源,降低TPS,提高CPU占用率。
  • 在业务代码中,尽量避免在循环语句里写数据库查询。
  • 依据SQL语句的使用频率来建立索引,查询条件字段顺序按照联合索引的字段顺序来写(从左到右的匹配顺序)
  • 关注慢查日志

一、背景说明

接着上一篇Grpc性能调优的文章继续写,我们这次压测的是一个查询用户群组列表信息的接口,该接口里需要查询某个用户的所有群组信息,包括每个群组的名称、成员数量等。
经过之前对业务机器的JVM参数等进行优化后,现在已经不存在业务机器的频繁GC、CPU占用率过高、TPS上不去等问题了。但是我们遇到了两个新问题:在业务接口并发50、TPS600左右时,压测接口出现了超时错误,而且数据库服务器CPU占用率超过了93%

二、测试过程

数据准备:

  • t_info_group群组表:
    压力测试过程中MySQL服务CPU占用率过高的问题排查思路

  • t_info_group_member群组成员表:
    压力测试过程中MySQL服务CPU占用率过高的问题排查思路

数据约定:测试数据中,每个群组里面有3000个成员;每个成员有20个群组。

1、第一次压测

我们首先进行一次摸底测试,使用两台压测机器共同发起300个并发,持续压测2分钟。(如果只用一台压测机发起300个并发,会由于机器端口受限,TPS超过5W后不能发起新请求,压测机将报错)
(1)数据库连接池配置
c3p0.initialPoolSize=15
c3p0.minPoolSize=15
c3p0.acquireIncrement=10
c3p0.maxPoolSize=32
(2)数据库慢查日志、数据库服务器监控指标
压力测试过程中MySQL服务CPU占用率过高的问题排查思路

top命令显示CPU使用率超过了91%,而且慢查日志一直在刷!
通过分析慢查日志里面的SQL语句,以及对应的数据库表,发现查询语句中有“where a=.. and b=.. and c=..”,但是有一个联合索引的字段是“a, c"。根据联合索引的匹配规则,这条sql用不了索引,导致慢查。经过将索引更换成"a, b, c",单条sql查询效率提高一倍。

2、第二次压测

使用两台压测机器共同发起50个并发,持续压测2分钟。
(1)其他配置均不做改变。
(2)数据库慢查日志、数据库服务器监控指标
经过上述调整,慢查日志没有了,但是CPU使用率依然还是超过了90%。这是一个不能容忍的数据,如果并发继续提高,数据库服务器很快将被撑爆。
压力测试过程中MySQL服务CPU占用率过高的问题排查思路

压力测试过程中MySQL服务CPU占用率过高的问题排查思路

由于其他涉及到sql查询的接口在压测时都没有出现过CPU占用率这么高的情况,所以我们排除了数据库服务器安装配置的问题。
我们开始思考出现问题的可能原因:

  • 数据库连接池等参数配置有缺陷,导致连接池不够用,一直在建立新的连接。
  • 业务代码逻辑可能存在缺陷,导致查询语句消耗过多IO或内存资源。
  • 并发数量高,数据库服务器CPU正常就需要占用这么多。(这是最无奈最不想接受的结局)
    我们先查看show processlist; 的结果,发现有很多连接其实是空闲的,也就是说目前的连接池已经够用了。
    而当我们把连接池尝试放大,配置改为:
    c3p0.initialPoolSize=20
    c3p0.minPoolSize=20
    c3p0.acquireIncrement=20
    c3p0.maxPoolSize=128
    在这个配置下,对CPU的占用率没有丝毫影响。那么排除连接池配置的问题。
    那有没有可能是在当前并发量条件下,就需要消耗这么多的CPU呢?
    我们对比了另一个涉及到SQL查询的接口,在60个并发下,那个接口的TPS达到了1100,而现在压测的接口,TPS只有600。那么在同等并发下,相同的查询语句复杂度和查询结果数据量条件下,现在压测的接口不仅TPS低,还占用了过多的CPU,可能就不是数据库的问题。这就排除了因并发量高而必然导致CPU占用率超过90%的假设。
    我们继续看数据库服务器的监控指标,使用阿里的orzdba脚本监控MySQL服务器。
    当前压测接口的MySQL服务器指标数据:
    压力测试过程中MySQL服务CPU占用率过高的问题排查思路

对照接口的指标数据:
压力测试过程中MySQL服务CPU占用率过高的问题排查思路

从上述两个对比图可以看到,当前压测接口的数据库QPS高达3000。对比数据汇总一下,可以看出一些问题:
当前接口:
并发:60,TPS:600,数据库CPU:92%,数据库QPS:3000
对照接口:
并发60,TPS:1000,数据库CPU:20%,数据库QPS:1400
当前压测接口处理更耗时,可能原因是一次接口业务里涉及到了多次数据库操作。
那么接下来就是排查业务代码里的数据库操作了。进行code review!
核心业务伪代码:
//查询用户的群组列表
List<Dto> groupList = groupDao.selectGroups(userId);
for(Dto dto:groupList){
//查询每个群组的用户数,会循环20次!
int userNumber = groupDao.getGroupNumber(dto.getAsIong(groupId));
}

这段代码怎么这么别扭?第一个查询已经去查询群组信息了,还要用for循环去遍历20次统计每个群组用户数??
这样操作的话,一次接口请求将操作很多次的数据库查询,并带来更多网络、IO操作。那么CPU占用率过高的问题很可能是这个情况导致的。
我们的优化措施是优化groupDao.selectGroups(userId)对应的查询语句,使用子查询返回用户的群组列表和每个群组的用户数,去掉for循环。

3、第三次压测

使用两台压测机器共同发起50个并发,持续压测2分钟。
(1)其他配置均不做改变。
(2)数据库慢查日志、数据库服务器监控指标
数据库慢查日志没有提示慢查SQL语句,数据库服务器CPU占用率稳定在80%以下,数据库QPS提高到了近7000!这个优化效果可以说是非常的明显了。

压力测试过程中MySQL服务CPU占用率过高的问题排查思路

4、留给我的疑问

也许有人会问:代码优化后数据库的QPS比之前更高了,那CPU使用应该更多啊,但是为什么数据库的CPU占用率反而降下来了呢?这是为什么呢?这个问题,其实我也没有想明白,有知道原因的朋友欢迎留言讨论。

  • 接口优化前:
    并发:60,TPS:600,数据库CPU:92%,数据库QPS:3000
    压力测试过程中MySQL服务CPU占用率过高的问题排查思路
    压力测试过程中MySQL服务CPU占用率过高的问题排查思路

  • 接口优化后:
    并发:60,TPS:1100,数据库CPU:低于80%,数据库QPS:6000
    压力测试过程中MySQL服务CPU占用率过高的问题排查思路