转自:http://blog.csdn.net/hw_libo/article/details/39080809


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

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


1. 环境说明

RHEL 6.4 x86_64 + MySQL 5.6.19
事务隔离级别:RR

2. 测试过程


MySQL锁阻塞分析_innodb阻塞分析



3. 查看锁阻塞线程信息

这里用几中方法进行分析:


3.1  使用show processlist查看


[sql] view plaincopyprint?

  1. MySQL [(none)]> show processlist;  

  2. +----+------+-----------+------+---------+------+--------------+------------------------------------------+  

  3. | Id | User | Host      | db   | Command | Time | State        | Info                                     |  

  4. +----+------+-----------+------+---------+------+--------------+------------------------------------------+  

  5. |  2 | root | localhost | NULL | Query   |    0 | init         | show processlist                         |  

  6. |  3 | root | localhost | test | Query   |   70 | Sending data | select count(*) from t3 a,t3 b           |  

  7. |  4 | root | localhost | test | Query   |   65 | updating     | delete from emp where empno=7788         |  

  8. |  7 | root | localhost | test | Query   |   68 | updating     | update emp set sal=3500 where empno=7788 |  

  9. +----+------+-----------+------+---------+------+--------------+------------------------------------------+  

  10. rows in set (0.00 sec)  


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



3.2  直接使用show engine innodb status查看


[html] view plaincopyprint?

  1. ------------  

  2. TRANSACTIONS  

  3. ------------  

  4. Trx id counter 4131  

  5. Purge done for trx's n:o < 4119 undo n:o < 0 state: running but idle  

  6. History list length 126  

  7. LIST OF TRANSACTIONS FOR EACH SESSION:  

  8. ---TRANSACTION 0, not started  

  9. MySQL thread id 2, OS thread handle 0x7f953ffff700, query id 115 localhost root init  

  10. show engine innodb status  

  11. ---TRANSACTION 4130, ACTIVE 41 sec starting index read  

  12. mysql tables in use 1, locked 1  

  13. LOCK WAIT 2 lock struct(s), heap size 360, 1 row lock(s)  

  14. MySQL thread id 4, OS thread handle 0x7f953ff9d700, query id 112 localhost root updating  

  15. delete from emp where empno=7788  

  16. ------- TRX HAS BEEN WAITING 41 SEC FOR THIS LOCK TO BE GRANTED:   ## 等待了41s  

  17. 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  

  18. Record lock, heap no 9 PHYSICAL RECORD: n_fields 10; compact format; info bits 0  ## 线程4在等待往test.emp中的主键上加X锁,page num=3  

  19.  0: len 4; hex 80001e6c; asc    l;;  

  20.  1: len 6; hex 000000001018; asc       ;;  

  21.  2: len 7; hex 91000001420084; asc     B  ;;  

  22.  3: len 5; hex 53434f5454; asc SCOTT;;  

  23.  4: len 7; hex 414e414c595354; asc ANALYST;;  

  24.  5: len 4; hex 80001d8e; asc     ;;  

  25.  6: len 4; hex 208794f0; asc     ;;  

  26.  7: len 4; hex 80000bb8; asc     ;;  

  27.  8: SQL NULL;  

  28.  9: len 4; hex 80000014; asc     ;;  

  29.   

  30. ------------------  

  31. ---TRANSACTION 4129, ACTIVE 45 sec starting index read  

  32. mysql tables in use 1, locked 1  

  33. LOCK WAIT 2 lock struct(s), heap size 360, 1 row lock(s)  

  34. MySQL thread id 7, OS thread handle 0x7f953ff6c700, query id 111 localhost root updating  

  35. update emp set sal=3500 where empno=7788  

  36. ------- TRX HAS BEEN WAITING 45 SEC FOR THIS LOCK TO BE GRANTED:   ## 等待了45s  

  37. 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  

  38. Record lock, heap no 9 PHYSICAL RECORD: n_fields 10; compact format; info bits 0  ## 线程7在等待往test.emp中的主键上加X锁,page num=3  

  39.  0: len 4; hex 80001e6c; asc    l;;  

  40.  1: len 6; hex 000000001018; asc       ;;  

  41.  2: len 7; hex 91000001420084; asc     B  ;;  

  42.  3: len 5; hex 53434f5454; asc SCOTT;;  

  43.  4: len 7; hex 414e414c595354; asc ANALYST;;  

  44.  5: len 4; hex 80001d8e; asc     ;;  

  45.  6: len 4; hex 208794f0; asc     ;;  

  46.  7: len 4; hex 80000bb8; asc     ;;  

  47.  8: SQL NULL;  

  48.  9: len 4; hex 80000014; asc     ;;  

  49.   

  50. ------------------  

  51. ---TRANSACTION 4128, ACTIVE 51 sec  

  52. 2 lock struct(s), heap size 360, 1 row lock(s)  

  53. 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日志中,会看到:


[html] view plaincopyprint?

  1. Thread database.table_name          Locked/Waiting        Lock_type  

  2.   

  3.   

  4. 3       test.t3                     Locked - read         Low priority read lock  

  5. 7       test.emp                    Locked - write        High priority write lock  


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



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


[sql] view plaincopyprint?

  1. MySQL [test]> CREATE TABLE innodb_lock_monitor (a INT) ENGINE=INNODB;  ## 随便在一个数据库中创建这个表,就会打开lock monitor  

  2. Query OK, 0 rows affected, 1 warning (0.07 sec)  

  3.   

  4. MySQL [test]> show warnings\G  

  5. *************************** 1. row ***************************  

  6.   Level: Warning  

  7.    Code: 131  

  8. 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.  

  9. 1 row in set (0.00 sec)  


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

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



[html] view plaincopyprint?

  1. ------------  

  2. TRANSACTIONS  

  3. ------------  

  4. Trx id counter 4667  

  5. Purge done for trx's n:o < 4659 undo n:o < 0 state: running but idle  

  6. History list length 138  

  7. LIST OF TRANSACTIONS FOR EACH SESSION:  

  8. ---TRANSACTION 0, not started  

  9. MySQL thread id 9, OS thread handle 0x7f813c5f7700, query id 152 localhost root init  

  10. show engine innodb status  

  11. ---TRANSACTION 4663, ACTIVE 78 sec starting index read  

  12. mysql tables in use 1, locked 1  

  13. LOCK WAIT 2 lock struct(s), heap size 360, 1 row lock(s)  

  14. MySQL thread id 4, OS thread handle 0x7f813c628700, query id 149 localhost root updating  

  15. delete from emp where empno=7788  

  16. ------- TRX HAS BEEN WAITING 78 SEC FOR THIS LOCK TO BE GRANTED:   ## 等待了78s  

  17. 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  

  18. Record lock, heap no 9 PHYSICAL RECORD: n_fields 10; compact format; info bits 0  ## 线程4在等待往test.emp中的主键上加X锁,page num=3  

  19.  0: len 4; hex 80001e6c; asc    l;;  

  20.  1: len 6; hex 000000001018; asc       ;;  

  21.  2: len 7; hex 91000001420084; asc     B  ;;  

  22.  3: len 5; hex 53434f5454; asc SCOTT;;  

  23.  4: len 7; hex 414e414c595354; asc ANALYST;;  

  24.  5: len 4; hex 80001d8e; asc     ;;  

  25.  6: len 4; hex 208794f0; asc     ;;  

  26.  7: len 4; hex 80000bb8; asc     ;;  

  27.  8: SQL NULL;  

  28.  9: len 4; hex 80000014; asc     ;;  

  29.   

  30. ------------------  

  31. TABLE LOCK table `test`.`emp` trx id 4663 lock mode IX   ## 在给主键行上加X锁之前,先要在表上加意向锁IX  

  32. 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  

  33. Record lock, heap no 9 PHYSICAL RECORD: n_fields 10; compact format; info bits 0  

  34.  0: len 4; hex 80001e6c; asc    l;;  

  35.  1: len 6; hex 000000001018; asc       ;;  

  36.  2: len 7; hex 91000001420084; asc     B  ;;  

  37.  3: len 5; hex 53434f5454; asc SCOTT;;  

  38.  4: len 7; hex 414e414c595354; asc ANALYST;;  

  39.  5: len 4; hex 80001d8e; asc     ;;  

  40.  6: len 4; hex 208794f0; asc     ;;  

  41.  7: len 4; hex 80000bb8; asc     ;;  

  42.  8: SQL NULL;  

  43.  9: len 4; hex 80000014; asc     ;;  

  44.   

  45. ---TRANSACTION 4662, ACTIVE 81 sec starting index read  

  46. mysql tables in use 1, locked 1  

  47. LOCK WAIT 2 lock struct(s), heap size 360, 1 row lock(s)  

  48. MySQL thread id 7, OS thread handle 0x7f813c5c6700, query id 148 localhost root updating  

  49. update emp set sal=3500 where empno=7788  

  50. ------- TRX HAS BEEN WAITING 81 SEC FOR THIS LOCK TO BE GRANTED:  ## 等待了81s  

  51. 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  

  52. Record lock, heap no 9 PHYSICAL RECORD: n_fields 10; compact format; info bits 0  ## 线程7在等待往test.emp中的主键上加X锁,page num=3  

  53.  0: len 4; hex 80001e6c; asc    l;;  

  54.  1: len 6; hex 000000001018; asc       ;;  

  55.  2: len 7; hex 91000001420084; asc     B  ;;  

  56.  3: len 5; hex 53434f5454; asc SCOTT;;  

  57.  4: len 7; hex 414e414c595354; asc ANALYST;;  

  58.  5: len 4; hex 80001d8e; asc     ;;  

  59.  6: len 4; hex 208794f0; asc     ;;  

  60.  7: len 4; hex 80000bb8; asc     ;;  

  61.  8: SQL NULL;  

  62.  9: len 4; hex 80000014; asc     ;;  

  63.   

  64. ------------------  

  65. TABLE LOCK table `test`.`emp` trx id 4662 lock mode IX   ## 在给主键行上加X锁之前,先要在表上加意向锁IX  

  66. 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  

  67. Record lock, heap no 9 PHYSICAL RECORD: n_fields 10; compact format; info bits 0  

  68.  0: len 4; hex 80001e6c; asc    l;;  

  69.  1: len 6; hex 000000001018; asc       ;;  

  70.  2: len 7; hex 91000001420084; asc     B  ;;  

  71.  3: len 5; hex 53434f5454; asc SCOTT;;  

  72.  4: len 7; hex 414e414c595354; asc ANALYST;;  

  73.  5: len 4; hex 80001d8e; asc     ;;  

  74.  6: len 4; hex 208794f0; asc     ;;  

  75.  7: len 4; hex 80000bb8; asc     ;;  

  76.  8: SQL NULL;  

  77.  9: len 4; hex 80000014; asc     ;;  

  78.   

  79. ---TRANSACTION 4615, ACTIVE 1579 sec, thread declared inside InnoDB 1222  

  80. mysql tables in use 2, locked 0  

  81. 2 lock struct(s), heap size 360, 1 row lock(s)  

  82. MySQL thread id 3, OS thread handle 0x7f813c659700, query id 147 localhost root Sending data  

  83. select count(*) from t3 a,t3 b   ## 这是线程3当前正在执行的SQL  

  84. Trx read view will not see trx with id >= 4662, sees < 4659  

  85. TABLE LOCK table `test`.`emp` trx id 4615 lock mode IX  ## 线程3中正在拥有表上的意向IX锁,并且有test.emp表上主键的行级X锁,page num=3  

  86. 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  

  87. Record lock, heap no 9 PHYSICAL RECORD: n_fields 10; compact format; info bits 0  

  88.  0: len 4; hex 80001e6c; asc    l;;  

  89.  1: len 6; hex 000000001018; asc       ;;  

  90.  2: len 7; hex 91000001420084; asc     B  ;;  

  91.  3: len 5; hex 53434f5454; asc SCOTT;;  

  92.  4: len 7; hex 414e414c595354; asc ANALYST;;  

  93.  5: len 4; hex 80001d8e; asc     ;;  

  94.  6: len 4; hex 208794f0; asc     ;;  

  95.  7: len 4; hex 80000bb8; asc     ;;  

  96.  8: SQL NULL;  

  97.  9: len 4; hex 80000014; asc     ;;  


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



4. 结论

在分析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

-- Bosco  QQ:375612082
---- END ----
-------------------------------------------------------------------------------------------------------
版权所有,文章允许转载,但必须以链接方式注明源地址,否则追究法律责任!

  • 2