一次MySQL5.7线上故障分析

一次MySQL5.7线上故障分析

原创 2017-01-03 邹宇 ACMUG

ACMUG征集原创技术文章。详情请添加 A_CMUG或者扫描文末二维码关注我们的微信公众号。有奖征稿，请发送稿件至：acmug@acmug.com。
3306现金有奖征稿说明：知识无价，劳动有偿，ACMUG特约撰稿人有奖回报计划（修订版）

作者简介：邹宇

邹宇，滴滴出行技术专家，数据库团队负责人。

坑都是踩出来的。

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发生写入夯死的坑未填上，速来！^_^