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

今天给一个客户巡检的情况下发从库没有业务的情况mysqld的cpu的一个core占用100％.查主库慢查询也没有关于写的SQL.
可以说是典的单进程复制把一个cpu占满造成的．知道原因了，就好分析了．
分析一下binlog中写的什么，看看有什么地方可以优化或是加速的．利用工具：pasrebinlog
利用show slave status\G; 查当前同步的到节点，然后对日值进行解析．

git clone https://github.com/wubx/mysql-binlog-statistic.git
cd mysql-binlog-statistic/bin/
parsebinlog /u1/mysql/logs/mysql-bin.000806

...
====================================
Table xx_db.xxtable:
Type DELETE opt： 101246
Type INSERT opt： 103265
================================
...

以最大的数排序看，定位到:xx_db.xxtable，对于一个日值中能删除10几万，写入10几万．是不是这个表写入比较慢了呢．
在从库上查看innodb的相关情况：

MySQL> show engine innodb status\G;
...
---TRANSACTION 1C0C2DFDF, ACTIVE 3 sec fetching rows
mysql tables in use 1, locked 1
3361 lock struct(s), heap size 407992, 477888 row lock(s), undo log entries 42
MySQL thread id 43, OS thread handle 0x7fc1800c4700, query id 1908504 Reading event from the relay log
TABLE LOCK table xx_db.xxtable trx id 1C0C2DFDF lock mode IX
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
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
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
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
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
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
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
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
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
TOO MANY LOCKS PRINTED FOR THIS TRX: SUPPRESSING FURTHER PRINTS
----------------------------
END OF INNODB MONITOR OUTPUT

...

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

问题到这里基本上可以得到解决问题的方法了：
给xx_db.xxtable 添加一个主建即可．这里后是给xx_db.xxtable 添加了一个无业务意义的idint自增主建．这样立马可以看到mysqld占用的cpu单核降到了3％左右，同时后续同步一切正常，观查一天没出现同步延迟的问题．