一次MySQL5.7线上故障分析
坑都是踩出来的。
MySQL 5.7 GA已经有很长一段时间了,经过测试评估,在5.7.16版本release之后,我们开始在生产线上规模部署,一个多月相安无事,心中窃喜,在部署了大约200+实例之后,天有不测风云,故障开始接二连三。
某日,一个从库报OOM。该实例的innodb_buffer_pool_size = 40G,而系统内存是64G,怎么就能OOM了呢,先下线该实例,再看情况:
1、机器内存: 基本快要跪了
total used free shared buffers cached Mem: 65808000 65492564 315436 0 1648 247284 -/+ buffers/cache: 65243632 564368 Swap: 2088952 2087852 1100
2、看谁是元凶:确认是mysqld
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 28086 mysql 20 0 87.3g 61g 5192 S 21.2 97.7 28226:23 mysqld
3、看MySQL监控:
com_delete/innodb_rows_deleted : 29/9340 com_update/innodb_rows_updated : 155/9740 com_select/innodb_rows_selected : 299/39400
该业务正常情况下是不可能出现这么大的innodb_rows值的,先stop slave,com_delete/com_update/com_select的值变0,但是innodb_rows值并没有降低,什么!!!现在已经没有任何写入了,怎么可能,诡异了。
4、再看看LSN: 还在涨?
5、再看看是否有事务在回滚(此处感谢@张远 ^_^):
确实有线程在rollback,但是该实例也没有什么大事务,stop slave都已经好久了,为什么还在回滚呢?
6、pstack $mysqldpid看看线程都在干什么:
从下图能看出都是在compress_gtid_table()里,难道短网址和gtid compress有关系?
插入一段关于gtid compress的介绍: MySQL 5.7中新增了一个mysql.gtid_executed表,用于记录当前执行过的gtid,在binlog开启的情况下,当binlog retation的时候会唤醒一个内部线程对这个表的数据进行压缩合并。
7、看下mysql.gtid_executed表的情况:
果然是没有压缩,看来是在压缩这个表数据的时候出错了,然后产生了回滚操作。
8、经过对比,最后确认是这个参数引起的:
我们为了防止有DBA不小心在从库上执行SQL,给gtid_mode=on的复制模式留下隐患,将super_read_only设置成了on,为此,还特意修改了MHA的源码,以便检测和支持短网址的这个设置,结果人算不如天算,踩上了这个坑。将super_read_only 设置成0,当binlog retation后可以看到mysql.gtid_executed的compress恢复正常了,innodb_rows也正常了:
9、写在最后也是最重要的:
a) 参数的调整尽管已经解决了这个问题,但是更深层次的原因还没去找,希望有MySQL源码基础的同学,有兴趣来帮忙填坑的,请将简历砸过来: zouyu@didichuxing.com;
b) 还有一个MySQL5.7.16发生写入夯死的坑未填上,速来!^_^