一次MySQL数据库生产事故以及问题定位
概要
本文记录了作者最近遇到的一次MySQL数据库生产事故，以及怎么定位BUG的整个过程。
事故描述
随着业务发展，数据库的表会出现爆炸式增长。最近根据一个客户反映，我们的一个业务接口，响应返回的速度越来越慢，随后两天，其他客户也相继反映同样的问题。终于在第三天，DBA反映我们的MySQL数据库“爆了”，CPU的使用率达到2000%，最后这个接口瘫痪了。
问题定位
添加日志
先收窄范围。收到BUG的报告时，我们团队就通过StopWatch在业务接口的关键代码里，增加了耗时的监控。很明显地，在入口处的selectLog性能很低，初步锁定问题。
:02:34.437 | [http-nio-8080-exec-163] | [INFO] |:StopWatch 'xxxxxxx':= 7406-----------------------------------------ms % Task name-----------------------------------------07401 100% selectLog00000 000% redisOper00002 000% updateLog00001 000% select100001 000% select200001 000% AsyncOper00000 000% MqOper
分析问题
系统主要采用了继承tk.mybatis.mapper.common.Mapper的方式，来实现对数据库的操作。对于表tb_m_log，字段number（手机号码）和t_id（事务ID）可以确定一个业务日志。因此初步方案是建立组合唯一索引来优化这个查询。
public interface MLogMapper extends Mapper<MLogDO> {MLogDO selectLog( Long number, String trancationId);}
后续观察
在压力测试环境（用于模拟生产环境，测试系统性能），通过JMETER做了压测，查看结果和数据库的执行计划，都证明增加索引的方案是没问题的。但是由于这日志表已经达到了500w的数据量，最后选择了在业务量低的深夜执行了创建索引的操作。
随后生产执行了创建索引的脚本，再次观察日志如下，效果不明显。开发团队陷入了沉思……
:02:34.437 | [http-nio-8080-exec-161] | [INFO] |MServiceImpl | doUpdate:StopWatch 'xxxxxxx':running time (millis) = 6406-----------------------------------------ms % Task name-----------------------------------------06401 100% selectLog00000 000% redisOper00002 000% updateLog00001 000% select100001 000% select200001 000% AsyncOper00000 000% MqOper
DBA介入
后面根据DBA的报告，我们的数据库CPU使用率飙升到2000% 事态变得越来越严重。我们把涉及的SQL都提交给DBA，等待DBA的建议。最后DBA在慢查询日志里，找到了这些SQL。DBA通过查看这些SQL的执行计划，发现根本没有用到索引……
SELECT * FROM tb_m_log where number = 13800000001 andt_id = 'do^Hd%';SELECT * FROM tb_m_log where number = 13800200001 andt_id = '1d*kd0';……
揭开真相
团队决定复盘一下生产的数据库表结构，跟其他环境的对比一下。最后发现生产上的number字段竟然是varchar类型的，然而测试库的是bigint，代码维护的number是java.lang.Long 导致传入参数的时候，没有加上单引号，从而导致两侧的环境表现不一致，引起索引失效。
CREATE TABLE `tb_m_log ` (`id` bigint(20) unsigned NOT NULL,`job_code` varchar(50) NOT NULL,`number` varchar(50) NOT NULL,`t_id ` varchar(50) NOT NULL,……省略PRIMARY KEY (`id`)) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4;-- 生产CREATE TABLE `tb_m_log ` (`id` bigint(20) unsigned NOT NULL,`job_code` varchar(50) NOT NULL,`number` bigint(20) unsigned NOT NULL,`t_id ` varchar(50) NOT NULL,……省略PRIMARY KEY (`id`)) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4;-- 测试
修复后性能如下
:02:34.437 | [http-nio-8080-exec-61] | [INFO] |MServiceImpl | doUpdate:StopWatch 'xxxxxxx':running time (millis) = 6-----------------------------------------ms % Task name-----------------------------------------00001 100% selectLog00000 000% redisOper00002 000% updateLog00001 000% select100001 000% select200001 000% AsyncOper00000 000% MqOper
小结
通过这次问题追踪，我们发现了团队的管理漏洞，SQL脚本的管理也是顺利上线的前提保障，不容忽视。另外使用Docker等容器化技术也可以作为后续优化方向。希望本文能帮忙大家在以后遇到生产问题时，能快速定位以及解决。
关注我