Mysql死锁分析

日常维护中，经常会碰到线程被阻塞，导致数据库响应非常慢，下面就看看如何获取是哪个线程导致了阻塞的。

blog地址：http://blog.csdn.net/hw_libo/article/details/39080809

1. 环境说明
RHEL 6.4 x86_64 + MySQL 5.6.19
事务隔离级别：RR

2. 测试过程

3. 查看锁阻塞线程信息
这里用几中方法进行分析：

3.1  使用show processlist查看

MySQL [(none)]> show processlist;
+—-+——+———–+——+———+——+————–+——————————————+
| Id | User | Host      | db   | Command | Time | State        | Info                                     |
+—-+——+———–+——+———+——+————–+——————————————+
|  2 | root | localhost | NULL | Query   |    0 | init         | show processlist                         |
|  3 | root | localhost | test | Query   |   70 | Sending data | select count(*) from t3 a,t3 b           |
|  4 | root | localhost | test | Query   |   65 | updating     | delete from emp where empno=7788         |
|  7 | root | localhost | test | Query   |   68 | updating     | update emp set sal=3500 where empno=7788 |
+—-+——+———–+——+———+——+————–+——————————————+
4 rows in set (0.00 sec)

如果数据库存在较多线程的话，这种方法确实不太好确认的。

3.2  直接使用show engine innodb status查看

————
TRANSACTIONS
————
Trx id counter 4131
Purge done for trx’s n:o < 4119 undo n:o < 0 state: running but idle
History list length 126
LIST OF TRANSACTIONS FOR EACH SESSION:
—TRANSACTION 0, not started
MySQL thread id 2, OS thread handle 0x7f953ffff700, query id 115 localhost root init
show engine innodb status
—TRANSACTION 4130, ACTIVE 41 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 2 lock struct(s), heap size 360, 1 row lock(s)
MySQL thread id 4, OS thread handle 0x7f953ff9d700, query id 112 localhost root updating
delete from emp where empno=7788
——- TRX HAS BEEN WAITING 41 SEC FOR THIS LOCK TO BE GRANTED:   ## 等待了41s
RECORD LOCKS space id 16 page no 3 n bits 88 index `PRIMARY` of table `test`.`emp` trx id 4130 lock_mode X locks rec but not gap waiting
Record lock, heap no 9 PHYSICAL RECORD: n_fields 10; compact format; info bits 0  ## 线程4在等待往test.emp中的主键上加X锁，page num=3
0: len 4; hex 80001e6c; asc    l;;
1: len 6; hex 000000001018; asc       ;;
2: len 7; hex 91000001420084; asc     B  ;;
3: len 5; hex 53434f5454; asc SCOTT;;
4: len 7; hex 414e414c595354; asc ANALYST;;
5: len 4; hex 80001d8e; asc     ;;
6: len 4; hex 208794f0; asc     ;;
7: len 4; hex 80000bb8; asc     ;;
8: SQL NULL;
9: len 4; hex 80000014; asc     ;;

——————
—TRANSACTION 4129, ACTIVE 45 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 2 lock struct(s), heap size 360, 1 row lock(s)
MySQL thread id 7, OS thread handle 0x7f953ff6c700, query id 111 localhost root updating
update emp set sal=3500 where empno=7788
——- TRX HAS BEEN WAITING 45 SEC FOR THIS LOCK TO BE GRANTED:   ## 等待了45s
RECORD LOCKS space id 16 page no 3 n bits 88 index `PRIMARY` of table `test`.`emp` trx id 4129 lock_mode X locks rec but not gap waiting
Record lock, heap no 9 PHYSICAL RECORD: n_fields 10; compact format; info bits 0  ## 线程7在等待往test.emp中的主键上加X锁，page num=3
0: len 4; hex 80001e6c; asc    l;;
1: len 6; hex 000000001018; asc       ;;
2: len 7; hex 91000001420084; asc     B  ;;
3: len 5; hex 53434f5454; asc SCOTT;;
4: len 7; hex 414e414c595354; asc ANALYST;;
5: len 4; hex 80001d8e; asc     ;;
6: len 4; hex 208794f0; asc     ;;
7: len 4; hex 80000bb8; asc     ;;
8: SQL NULL;
9: len 4; hex 80000014; asc     ;;

——————
—TRANSACTION 4128, ACTIVE 51 sec
2 lock struct(s), heap size 360, 1 row lock(s)
MySQL thread id 3, OS thread handle 0x7f953ffce700, query id 110 localhost root cleaning up

我们知道，主要根因还是thread=3引起的，但从innodb status中却无法分析得到这个结果。

从上面来看，线程4和线程7都在等待往test.emp中的主键上加X锁，page num=3，但是线程7等待的时间为45s，而线程4等待的时间为41s，是较线程7之后申请的锁，所以可以判断是线程7阻塞了线程4。至于线程7为什么出现等待，这里分析不到根因。

3.3  使用mysqladmin debug查看

# mysqladmin -S /tmp/mysql3306.sock debug

然后在error日志中，会看到：

Thread database.table_name          Locked/Waiting        Lock_type

3       test.t3                     Locked – read         Low priority read lock
7       test.emp                    Locked – write        High priority write lock

这种方法中，能找到线程ID=3和7是阻塞者，但还是不太准确，判断不出来线程7也是被线程ID=3阻塞的。

3.4  使用innodb_lock_monitor来获取阻塞锁线程

MySQL [test]> CREATE TABLE innodb_lock_monitor (a INT) ENGINE=INNODB;  ## 随便在一个数据库中创建这个表，就会打开lock monitor
Query OK, 0 rows affected, 1 warning (0.07 sec)

MySQL [test]> show warnings\G
*************************** 1. row ***************************
Level: Warning
Code: 131
Message: Using the table name innodb_lock_monitor to enable diagnostic output is deprecated and may be removed in future releases. Use INFORMATION_SCHEMA or PERFORMANCE_SCHEMA tables or SET GLOBAL innodb_status_output=ON.
1 row in set (0.00 sec)

说明：这个在5.6中有一个warning，但不影响使用。

然后再使用show engine innodb status查看：

————
TRANSACTIONS
————
Trx id counter 4667
Purge done for trx’s n:o < 4659 undo n:o < 0 state: running but idle
History list length 138
LIST OF TRANSACTIONS FOR EACH SESSION:
—TRANSACTION 0, not started
MySQL thread id 9, OS thread handle 0x7f813c5f7700, query id 152 localhost root init
show engine innodb status
—TRANSACTION 4663, ACTIVE 78 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 2 lock struct(s), heap size 360, 1 row lock(s)
MySQL thread id 4, OS thread handle 0x7f813c628700, query id 149 localhost root updating
delete from emp where empno=7788
——- TRX HAS BEEN WAITING 78 SEC FOR THIS LOCK TO BE GRANTED:   ## 等待了78s
RECORD LOCKS space id 16 page no 3 n bits 88 index `PRIMARY` of table `test`.`emp` trx id 4663 lock_mode X locks rec but not gap waiting
Record lock, heap no 9 PHYSICAL RECORD: n_fields 10; compact format; info bits 0  ## 线程4在等待往test.emp中的主键上加X锁，page num=3
0: len 4; hex 80001e6c; asc    l;;
1: len 6; hex 000000001018; asc       ;;
2: len 7; hex 91000001420084; asc     B  ;;
3: len 5; hex 53434f5454; asc SCOTT;;
4: len 7; hex 414e414c595354; asc ANALYST;;
5: len 4; hex 80001d8e; asc     ;;
6: len 4; hex 208794f0; asc     ;;
7: len 4; hex 80000bb8; asc     ;;
8: SQL NULL;
9: len 4; hex 80000014; asc     ;;

——————
TABLE LOCK table `test`.`emp` trx id 4663 lock mode IX   ## 在给主键行上加X锁之前，先要在表上加意向锁IX
RECORD LOCKS space id 16 page no 3 n bits 88 index `PRIMARY` of table `test`.`emp` trx id 4663 lock_mode X locks rec but not gap waiting
Record lock, heap no 9 PHYSICAL RECORD: n_fields 10; compact format; info bits 0
0: len 4; hex 80001e6c; asc    l;;
1: len 6; hex 000000001018; asc       ;;
2: len 7; hex 91000001420084; asc     B  ;;
3: len 5; hex 53434f5454; asc SCOTT;;
4: len 7; hex 414e414c595354; asc ANALYST;;
5: len 4; hex 80001d8e; asc     ;;
6: len 4; hex 208794f0; asc     ;;
7: len 4; hex 80000bb8; asc     ;;
8: SQL NULL;
9: len 4; hex 80000014; asc     ;;

—TRANSACTION 4662, ACTIVE 81 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 2 lock struct(s), heap size 360, 1 row lock(s)
MySQL thread id 7, OS thread handle 0x7f813c5c6700, query id 148 localhost root updating
update emp set sal=3500 where empno=7788
——- TRX HAS BEEN WAITING 81 SEC FOR THIS LOCK TO BE GRANTED:  ## 等待了81s
RECORD LOCKS space id 16 page no 3 n bits 88 index `PRIMARY` of table `test`.`emp` trx id 4662 lock_mode X locks rec but not gap waiting
Record lock, heap no 9 PHYSICAL RECORD: n_fields 10; compact format; info bits 0  ## 线程7在等待往test.emp中的主键上加X锁，page num=3
0: len 4; hex 80001e6c; asc    l;;
1: len 6; hex 000000001018; asc       ;;
2: len 7; hex 91000001420084; asc     B  ;;
3: len 5; hex 53434f5454; asc SCOTT;;
4: len 7; hex 414e414c595354; asc ANALYST;;
5: len 4; hex 80001d8e; asc     ;;
6: len 4; hex 208794f0; asc     ;;
7: len 4; hex 80000bb8; asc     ;;
8: SQL NULL;
9: len 4; hex 80000014; asc     ;;

——————
TABLE LOCK table `test`.`emp` trx id 4662 lock mode IX   ## 在给主键行上加X锁之前，先要在表上加意向锁IX
RECORD LOCKS space id 16 page no 3 n bits 88 index `PRIMARY` of table `test`.`emp` trx id 4662 lock_mode X locks rec but not gap waiting
Record lock, heap no 9 PHYSICAL RECORD: n_fields 10; compact format; info bits 0
0: len 4; hex 80001e6c; asc    l;;
1: len 6; hex 000000001018; asc       ;;
2: len 7; hex 91000001420084; asc     B  ;;
3: len 5; hex 53434f5454; asc SCOTT;;
4: len 7; hex 414e414c595354; asc ANALYST;;
5: len 4; hex 80001d8e; asc     ;;
6: len 4; hex 208794f0; asc     ;;
7: len 4; hex 80000bb8; asc     ;;
8: SQL NULL;
9: len 4; hex 80000014; asc     ;;

—TRANSACTION 4615, ACTIVE 1579 sec, thread declared inside InnoDB 1222
mysql tables in use 2, locked 0
2 lock struct(s), heap size 360, 1 row lock(s)
MySQL thread id 3, OS thread handle 0x7f813c659700, query id 147 localhost root Sending data
select count(*) from t3 a,t3 b   ## 这是线程3当前正在执行的SQL
Trx read view will not see trx with id >= 4662, sees < 4659
TABLE LOCK table `test`.`emp` trx id 4615 lock mode IX  ## 线程3中正在拥有表上的意向IX锁，并且有test.emp表上主键的行级X锁，page num=3
RECORD LOCKS space id 16 page no 3 n bits 88 index `PRIMARY` of table `test`.`emp` trx id 4615 lock_mode X locks rec but not gap
Record lock, heap no 9 PHYSICAL RECORD: n_fields 10; compact format; info bits 0
0: len 4; hex 80001e6c; asc    l;;
1: len 6; hex 000000001018; asc       ;;
2: len 7; hex 91000001420084; asc     B  ;;
3: len 5; hex 53434f5454; asc SCOTT;;
4: len 7; hex 414e414c595354; asc ANALYST;;
5: len 4; hex 80001d8e; asc     ;;
6: len 4; hex 208794f0; asc     ;;
7: len 4; hex 80000bb8; asc     ;;
8: SQL NULL;
9: len 4; hex 80000014; asc     ;;

为什么线程3当前执行的是一个select t3表操作，但却锁住了test.emp表上page num=3？
有可能是线程3之前对test.emp表的操作事务没有及时提交导致。
所以得出：线程3阻塞了线程7，而线程7又阻塞了线程4，所以根因就是线程3，让线程3尽快提交或是kill掉即可。

在分析innodb中锁阻塞时，几种方法的对比情况：

（1）使用show processlist查看不靠谱；
（2）直接使用show engine innodb status查看，无法判断到问题的根因；
（3）使用mysqladmin debug查看，能看到所有产生锁的线程，但无法判断哪个才是根因；
（4）开启innodb_lock_monitor后，再使用show engine innodb status查看，能够找到锁阻塞的根因。

blog地址：http://blog.csdn.net/hw_libo/article/details/39080809
———————
作者：bosco1986
来源：CSDN
原文：https://blog.csdn.net/hw_libo/article/details/39080809
版权声明：本文为博主原创文章，转载请附上博文链接！