一、现象描述
今天查看慢查询日报,发现线上一台MySQL实例慢查询数量达到1w多(线上超过0.05为慢查询),打开发现慢查询几乎都是COMMIT,如图所示
有没有想过为什么会出现这么多不带任何业务SQL的COMMIT慢查询呢?让我们一起拨开云雾吧。文章的数据库版本为腾讯云TDSQL(10.1.9-MariaDB)
二、原因分析
从腾讯云把慢查询日志download下来,然后统计一下COMMIT的具体时间和数量,出于空间原因,已省略部分数据
#grep -i 'commit' -B 5 set_1530599990_1135.1557158400.slow.log.2 | grep -i 'timestamp' | uniq -c | sort -k 3
从图中可以看出COMMIT几乎都出现在2019-05-07 21:03:24到2019-05-07 21:07:58之间,然后我们看一下腾讯云的监控,如下图所示:
1、cpu利用率
2、IO利用率
3、DML
从图中的尖刺可以看出,COMMIT集中出现在SLOW LOG的时间和尖刺完全吻合,结合监控和理论知识,其实我们已经大概知道原因,就是在20:55 - 21:12时间点之间,业务在大批量插入数据,导致MySQL IO很高,TDSQL默认参数innodb_flush_log_at_trx_commit=1、sync_bin=1,每次事务commit,redo log和binlog都要进行刷盘,如果业务并发量很大,对IO的压力会比较大,即便MySQL有Group Commit。
于是询问开发,原来业务在那个时间点在跑任务,会大批量插入数据,而且每个事务同时插入两条数据,由于双1设置,并发大时MySQL IO压力会比较大,容易导致commit记录在SLOW LOG里面,所以如果线上出现大量的COMMIT,大家要关注一下MySQL的压力情况了,防患于未然。
三、原因确认
为了进一步确认是MySQL IO导致,本人编写了一个存储过程并结合使用sysbench在QA环境进行压测,看到了同样的现象,由此我们可以确认是IO不足导致COMMIT出现在SLOW LOG中,压测现象如图所示
四、解决方法
既然已经知道原因,解决就比较简单,将参数innodb_flush_log_at_trx_commit设置为2,sync_binlog设置为0,但是生产不建议,因为数据丢失的后果DBA无法承担。所以要么我们升级TDSQL配置,要么让开发控制并发或者在事务里批量处理数据了,仁者见仁,智者见智,在成本和性能之间找到适合公司的解决方案就是最好的方案。
由于笔者能力有限,有不足之处请多指教。