MySQL中从库延迟状况排查的一则案例

这篇文章主要介绍了MySQL中从库延迟状况排查的一则案例,针对其从库无业务状态下的CPU大量占用情况,需要的朋友可以参考下

今天给一个客户巡检的情况下发从库没有业务的情况mysqld的cpu的一个core占用100%.查主库慢查询也没有关于写的SQL.

可以说是典的单进程复制把一个cpu占满造成的.知道原因了，就好分析了.

分析一下binlog中写的什么，看看有什么地方可以优化或是加速的.利用工具：pasrebinlog

利用show slave status/G; 查当前同步的到节点，然后对日值进行解析.

1. git clone https://github.com/wubx/mysql-binlog-statistic.git 
2. cd mysql-binlog-statistic/bin/ 
3. parsebinlog /u1/mysql/logs/mysql-bin.000806 
4.  
5. ... 
6. ==================================== 
7. Table xx_db.xxtable: 
8. Type DELETE opt： 101246 
9. Type INSERT opt： 103265 
10. ================================ 
11. ... 

以最大的数排序看，　定位到:　xx_db.xxtable，对于一个日值中能删除10几万，写入10几万.是不是这个表写入比较慢了呢.

在从库上查看innodb的相关情况：

1. MySQL> show engine innodb status/G; 
2. ... 
3. ---TRANSACTION 1C0C2DFDF, ACTIVE 3 sec fetching rows 
4. mysql tables in use 1, locked 1 
5. 3361 lock struct(s), heap size 407992, 477888 row lock(s), undo log entries 42 
6. MySQL thread id 43, OS thread handle 0x7fc1800c4700, query id 1908504 Reading event from the relay log 
7. TABLE LOCK table xx_db.xxtable trx id 1C0C2DFDF lock mode IX 
8. RECORD LOCKS space id 1002 page no 1975 n bits 1120 index `AK_movieid` of table xx_db.xxtable trx id 1C0C2DFDF lock_mode X locks rec but not gap 
9. RECORD LOCKS space id 1002 page no 6965 n bits 264 index `GEN_CLUST_INDEX` of table xx_db.xxtable trx id 1C0C2DFDF lock_mode X locks rec but not gap 
10. RECORD LOCKS space id 1002 page no 6967 n bits 256 index `GEN_CLUST_INDEX` of table xx_db.xxtable trx id 1C0C2DFDF lock_mode X locks rec but not gap 
11. RECORD LOCKS space id 1002 page no 6973 n bits 264 index `GEN_CLUST_INDEX` of table xx_db.xxtable trx id 1C0C2DFDF lock_mode X locks rec but not gap 
12. RECORD LOCKS space id 1002 page no 6982 n bits 256 index `GEN_CLUST_INDEX` of table xx_db.xxtable trx id 1C0C2DFDF lock_mode X locks rec but not gap 
13. RECORD LOCKS space id 1002 page no 6983 n bits 256 index `GEN_CLUST_INDEX` of table xx_db.xxtable trx id 1C0C2DFDF lock_mode X locks rec but not gap 
14. RECORD LOCKS space id 1002 page no 6987 n bits 256 index `GEN_CLUST_INDEX` of table xx_db.xxtable trx id 1C0C2DFDF lock_mode X locks rec but not gap 
15. RECORD LOCKS space id 1002 page no 6999 n bits 256 index `GEN_CLUST_INDEX` of table xx_db.xxtable trx id 1C0C2DFDF lock_mode X locks rec but not gap 
16. RECORD LOCKS space id 1002 page no 7000 n bits 256 index `GEN_CLUST_INDEX` of table xx_db.xxtable trx id 1C0C2DFDF lock_mode X locks rec but not gap 
17. TOO MANY LOCKS PRINTED FOR THIS TRX: SUPPRESSING FURTHER PRINTS 
18. ---------------------------- 
19. END OF INNODB MONITOR OUTPUT 
20.  
21. ... 

从Innodb 的monitor output 中也可看到 xx_db.xxtable 这表已经是表级表了，造成并发比较低，而且有大量的：　GEN_CLUST_INDEX　而且属于一个事务.　　GEN_CLUST_INDEX表示没有主建，内部产生一个主建，对于内部产生的主建很很容易造成page拆分的操作.

问题到这里基本上可以得到解决问题的方法了：

给xx_db.xxtable 添加一个主建即可.这里后是给xx_db.xxtable 添加了一个无业务意义的id　int　自增主建.这样立马可以看到mysqld占用的cpu单核降到了3%左右，　同时后续同步一切正常，观查一天没出现同步延迟的问题.