记一次mysql磁盘io高的问题排查

现象是，系统里的java连接mysql超时了，

于是去mysql的机器，查看/var/log/messages日志，查对应的时间点的情况

发现mysql被阻塞了blocked for more than 120 seconds，mysql的io非常之高，用top查看系统的负载也到达了50的样子

用mpstat查看cpu情况

好明显，都在等io

用iostat查看io情况，%util的值，一直在80%，99%之间变化

以为磁盘有问题，用dd测下速看看

从上面的结果看，也还好，没问题

以为可能磁盘有坏道，用下面命令也扫了一遍，没问题

结果也没有坏的块，这个过程，很耗时。

用show processlist命令查看mysql正在忙着什么，一看，也没什么任务在执行的

想看看mysql，研究写哪个文件时，最耗时的

从上面结果来看，xxl_job是最耗时的。知道点眉目了，因为公司的定时任务是用的xxljob，定时任务里，有每几秒执行的任务，我猜它的日志记录一定很大，于是查看一下

我的天，这个表的记录有千万！！！这些记录，没做定时任务来清理，由于都是一些没用的记录，所以这个表的数据我全清了

清了之后，再用iostat查看

%util一下子就降下来了，用iotop查看mysql进程的io也下降了

cpu的iowait也下降了

定义一个事件，让mysql定时清理30天前的日志记录

记录一下，希望对有需要的朋友也起一点提示

CPU占用过高诊断思路

mpstat -P ALL 1，查看cpu使用情况，主要消耗在sys即os系统调用上

perf top，cpu主要消耗在_spin_lock

生成perf report查看详细情况

CPU主要消耗在mutex争用上，说明有锁热点。

采用pt-pmp跟踪mysqld执行情况，热点主要集中在mem_heap_alloc和mem_heap_free上。

Pstack提供更详细的API调用栈

Innodb在读取数据记录时的API路径为

row_search_for_mysql --》row_vers_build_for_consistent_read --》mem_heap_create_block_func --》mem_area_alloc --》malloc --》  _L_unlock_10151 --》__lll_unlock_wait_private

row_vers_build_for_consistent_read会陷入一个死循环，跳出条件是该条记录不需要快照读或者已经从undo中找出对应的快照版本，每次循环都会调用mem_heap_alloc/free。

而该表的记录更改很频繁，导致其undo history list比较长，搜索快照版本的代价更大，就会频繁的申请和释放堆内存。

Linux原生的内存库函数为ptmalloc，malloc/free调用过多时很容易产生锁热点。

当多条 SQL 并发执行时，会最终触发os层面的spinlock，导致上述情形。

解决方案

将mysqld的内存库函数替换成tcmalloc，相比ptmalloc，tcmalloc可以更好的支持高并发调用。

修改my.cnf，添加如下参数并重启

[mysqld_safe]malloc-lib=tcmalloc

上周五早上7点执行的 *** 作，到现在超过72小时，期间该实例没有再出现cpu长期飙高的情形。

以下是修改前后cpu使用率对比

---