本文共 3738 字，大约阅读时间需要 12 分钟。

数据库性能问题的排查与解决过程

某天下班回家开发给我打电话，反馈MySQL中的一张表被锁了，让我帮他解锁。我一想，肯定是某个业务没有及时提交或者有人做了修改没提交。于是我让他把表名以及SQL发给我，好排除。

处理过程

收到应用发过来的SQL，查看后发现是一条update语句。于是，我去查看MySQL中是否有相关的锁等待：

select trx_mysql_thread_id from information_schema.innodb_trxwhere trx_id in (select blocking_trx_id from information_schema.innodb_lock_waits)\G

没有发现被堵塞的会话。接着，我将innodb的status和process输出到文件中：

mysql -e "show engine innodb status\G" > /tmp/innodb.logmysql -e "show processlist" > /tmp/processlist

查看innodb status的时候发现最近也没有死锁。拉到最后面，不看不知道，一看吓一跳。

ROW OPERATIONS

8个查询在InnoDB内部，934个查询在队列中。

63个读取操作在InnoDB内部。

主线程进程号9045，状态：睡眠。

插入1405689533次，更新2174378506次，删除1850571936次，读取4780412837263次。

我们发现934个查询在队列中，说明大量的SQL在等待进入InnoDB引擎。

查看innodb status中各个事务的状态：

grep TRANSACTION /tmp/innodb.log | awk -F "," '{print $2}' | sort | uniq -c | sort -n

结果显示，事务状态主要集中在睡眠前进入InnoDB、执行读操作等等。

此时，我去检查Linux系统的io和cpu，发现io没有等待，cpu使用率在50%左右，尚未构成瓶颈。

该机器为24个CPU，查看innodb_thread_concurrency参数，发现该参数为8。本来该机器是作为备端的，后来该虚机扩过CPU，但是该参数还是原来的8。和应用说明需要修改参数，看能不能重启。应用反馈说该业务不是核心业务，可以重启，时间在5分钟内。于是立马着手准备开干，修改参数，然后重启。重启完成后，应用反馈正常，我一边观察，一边继续分析问题。

innodb_thread_concurrency:

InnoDB tries to keep the number of operating system threads concurrently inside InnoDB less than or equal to the limit given by this variable

过了一会儿，又出现大量的队列等待进去innodb，和应用沟通反馈业务响应又变慢了，立马杀了一把连接：

mysql -e "show processlist" | awk '{print $1}' | grep -i -v id | awk '{print "kill "$1";}' | mysql

业务反馈已经正常，赶紧快马加鞭的分析问题。

虽然已经扩大了能够进入innodb的阀值，但是还是发生堵塞，说明根源还没有解决。

A thread is placed in a queue when it tries to enter InnoDB if the number of threads has already reached the concurrency limit.

With a large innodb_concurrency_tickets value, large transactions spend less time waiting for a position at the end of the queue (controlled by innodb_thread_concurrency) and more time retrieving rows

从官方文档中，我们可以发现，一旦innodb内部的线程达到了innodb_thread_concurrency的设置，其他的线程就会在队列中等待。

对于线程来说，如果没有ticket，那么将需要在队列中等待，一旦能够进入innodb，他将拿到innodb_concurrency_tickets张数的票，此后进入将不需要再排队，除非内部线程数量已经达到了innodb_thread_concurrency的值。

所以，对于线程来说，他如果已经拿到了ticket，且已经进入了innodb内部，那么SQL执行越慢，在innodb内部呆的时间越久，那么其他本来执行时间是几毫秒的SQL都需要等待漫长的时间，然后才能进入innodb内部去执行。

我们通过一个图来理解下这个过程：

原先的环境中innodb_thread_concurrency为8，所以在innodb内部一共有8个位置，可以并发执行8个线程，如果8个位置中都有线程正在执行，那么其他线程需要在后面的FIFO队列中等待。

打个比方，医院有总共有8个手术室，各个手术室可以自己独立做手术，彼此不干扰。一个手术室一个时间点只能对一个人做手术，除了手术室，其他地方不能做手术。

如果8个手术室都有人在做手术，那么其他在该医院需要等待做手术的人就需要等待，并且需要遵守先来先做的规则（我们不考虑特别紧急的手术）

有的手术做的比较快，有的做的比较慢。

如果一个手术室手术完毕，那么后面排的第一个人可以进入做手术。

如果8个手术室都在做时间很久的手术，那么即使后面只需要1个小时的手术，也是要等待前面有手术室空出来。

理解了这一点，我们就好理解为什么有那么多长的线程在等待在队列上了，很明显，肯定是那些慢SQL嘛！

我们继续分析当时的session 快照：

cat /tmp/process.log | sed '2,$p' | awk -F "\t" '{print $7"\t"$8}' | grep -v NULL | sort | uniq -c | sort -n

我们发现在session中，存在大量的select类型的SQL，其中一条SQL出现频率较高，存在怀疑：

SELECT b.hostid, a.regionid, c.itemid, d.host, d.name FROM xx a, xx b, xx c, xxx d WHERE = b.dtr_id AND c.hostid = b.hostid AND d.hostid = b.hostid AND b.hostid in (select DISTINCT(a.hostid) from items a,items_score b where a.itemid=b.itemid and a.status=0 and b.is_score=0) AND c.eventstatus < 0 AND a.regionid =11

但是我们也无法确定根源是这条SQL，因为就目前的情况来看，如果存在执行频率较高，且效率很高的SQL，那么也是会被堵塞在进入innodb的队列中。

同时在session中，竟然发现hearbeat表的更新，这张表示是pt-hearbeat用来监控主备延迟用的，每秒更新一次，表里面就只有一条记录，按理说更新应该非常快。多次check processlist，发现该更新hearbeat表的SQL执行了将近10秒，可见，该MySQL数据库的响应是多么的缓慢。

我们要从innodb status中去分析到底哪个SQL占据了innodb内部，导致其他SQL无法进入。

awk 'BEGIN{RS="—TRANSACTION";ORS="—TRANSACTION";}{if(!match($0,“BACKGROUND THREAD”)&&match($0,“inside InnoDB”))print $0}’ /tmp/innodb.log | more

我们可以发现，innodb内都是我们刚刚怀疑的那个SQL。取出该SQL，我们查看其执行计划：

发现该SQL在执行计划的一步中扫描了90w行的记录。

我们去抓取了慢日志，利用pt-query-digest 分析2017-01-22日从19:00:00开始的慢日志：

我们发现在1个半小时不到的时间内，该SQL执行了600多次，扫描的行特别多，数据量较大，执行时长分布在10秒以上，95%的SQL执行时长达到了285秒。

赶紧将SQL发给应用查看，让他优化逻辑，减少扫描行数，观察了一会儿，数据库恢复稳定。

总结

其实很多情况下，数据库出现问题都是出现了劣质SQL，我们需要准备好相应的脚本，在关键时刻，快而准的找到那条致命的SQL。

转载地址：http://bdxk.baihongyu.com/