mysql dml阻塞online ddl

1.版本

1)操作系统

 cat /etc/issue
cat /etc/issue
CentOS release 6.6 (Final)
Kernel \r on an \m

 cat /proc/version
cat /proc/version
Linux version 2.6.32-504.el6.x86_64 (mockbuild@c6b9.bsys.dev.centos.org) (gcc version 4.4.7 20120313 (Red Hat 4.4.7-11) (GCC) ) #1 SMP Wed Oct 15 04:27:16 UTC 2014

2)mysql数据库版本

MySQL --version

MySQL  Ver 14.14 Distrib 5.6.26, for linux-glibc2.5 (x86_64) using  EditLine wrapper

 

2.问题描述

   一个朋友让我帮忙分析一个问题,他先执行了一个online ddl,如 alter table test engine=innodb(mysql 5.6引入online ddl)。然后在另一个session中开启了一个事物,在事物中对test表执行了dml操作,但是不提交也不回滚。最后他发现先执行的ddl操作,被后面执行的dml操作阻塞。

1)先在我的测试环境还原一下这个问题

按时间顺序,执行如下操作:

 

 
  1. session1

  2. alter table tb_battle_member_bak1 engine=innodb;

  3. session2

  4. mysql> begin;

  5. Query OK, 0 rows affected (0.00 sec)

  6. mysql> delete from tb_battle_member_bak1 where BattleID='CX201605240076';

  7. Query OK, 1 row affected (0.01 sec)

2)在session3 观察session1和session2操作情况

 

 

 
  1. mysql> show processlist;

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

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

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

  5. | 2 | repl | 172.172.178.76:45429 | NULL | Binlog Dump | 2518274 | Master has sent all binlog to slave; waiting for binlog to be updated | NULL |

  6. | 202 | repl | 172.172.178.77:46833 | NULL | Binlog Dump | 1552398 | Master has sent all binlog to slave; waiting for binlog to be updated | NULL |

  7. | 271 | root | 127.0.0.1:22201 | test5 | Query | 177 | altering table | alter table tb_battle_member_bak1 engine=innodb |

  8. | 272 | root | 127.0.0.1:22202 | test5 | Sleep | 161 | | NULL |

  9. | 273 | root | 127.0.0.1:22204 | NULL | Query | 0 | init | show processlist |

  10. +-----+------+----------------------+-------+-------------+---------+-----------------------------------------------------------------------+-------------------------------------------------+

  11. 5 rows in set (0.00 sec)

  12.  
  13. mysql> show processlist;

  14. +-----+------+----------------------+-------+-------------+---------+-----------------------------------------------------------------------+-------------------------------------------------+

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

  16. +-----+------+----------------------+-------+-------------+---------+-----------------------------------------------------------------------+-------------------------------------------------+

  17. | 2 | repl | 172.172.178.76:45429 | NULL | Binlog Dump | 2518275 | Master has sent all binlog to slave; waiting for binlog to be updated | NULL |

  18. | 202 | repl | 172.172.178.77:46833 | NULL | Binlog Dump | 1552399 | Master has sent all binlog to slave; waiting for binlog to be updated | NULL |

  19. | 271 | root | 127.0.0.1:22201 | test5 | Query | 178 | Waiting for table metadata lock | alter table tb_battle_member_bak1 engine=innodb |

  20. | 272 | root | 127.0.0.1:22202 | test5 | Sleep | 162 | | NULL |

  21. | 273 | root | 127.0.0.1:22204 | NULL | Query | 0 | init | show processlist |

  22. +-----+------+----------------------+-------+-------------+---------+-----------------------------------------------------------------------+-------------------------------------------------+

  23. 5 rows in set (0.00 sec)

  24.  

NOTE:我们发现session1的online ddl在altering table这一步花了大概177秒,然后在转入下一步(committing alter table to stor)的时候,发生等待,我们看到的等待信息是Waiting for table metadata lock。

 

3) 回滚session2 的事物,查询session1 中所执行sql的profile(profile需提前开启,请参考http://blog.csdn.net/shaochenshuo/article/details/51580296)

 

 
  1. session1 profile:

  2.  
  3. mysql> show profiles;

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

  5. | Query_ID | Duration | Query |

  6. +----------+--------------+----------------------------------------------------------------------+

  7. | 1 | 0.00120700 | select @@version_comment limit 1 |

  8. | 2 | 0.00086900 | show slave hosts |

  9. | 3 | 0.00203125 | show databases |

  10. | 4 | 0.00065800 | SELECT DATABASE() |

  11. | 5 | 0.00088225 | show tables |

  12. | 6 | 0.00026350 | SELECT DATABASE() |

  13. | 7 | 0.00087025 | show tables |

  14. | 8 | 4.55985575 | select count(1) from tb_battle_member_bak1 |

  15. | 9 | 0.42077325 | truncate table tb_battle_member_bak1 |

  16. | 10 | 260.97370150 | insert into tb_battle_member_bak1 select * from tb_battle_member_bak |

  17. | 11 | 205.00446375 | alter table tb_battle_member_bak1 engine=innodb |

  18. +----------+--------------+----------------------------------------------------------------------+

  19. 11 rows in set, 1 warning (0.00 sec)

  20.  
  21. mysql> show profile for query 11;

  22. +--------------------------------+------------+

  23. | Status | Duration |

  24. +--------------------------------+------------+

  25. | starting | 0.000383 |

  26. | checking permissions | 0.000011 |

  27. | checking permissions | 0.000036 |

  28. | init | 0.000007 |

  29. | Opening tables | 0.000133 |

  30. | setup | 0.000242 |

  31. | creating table | 0.054524 |

  32. | After create | 0.000493 |

  33. | System lock | 0.000019 |

  34. | preparing for alter table | 0.073421 |

  35. | altering table | 177.612401 |

  36. | Waiting for table metadata loc | 1.000169 | >>因为session2 中关于该表的事物未提交,所以产生metadata等待

  37. | altering table | 0.000018 | >>因锁等待无法执行committing alter...,再次转到altering table(因为执行已经执行完,此时执行时间很短)

  38. | Waiting for table metadata loc | 1.000157 |

  39. | altering table | 0.000023 |

  40. | Waiting for table metadata loc | 1.000120 |

  41. | altering table | 0.000019 |

  42. ...........................

  43. ...........................

  44. ...........................

  45. | Waiting for table metadata loc | 0.042325 |

  46. | altering table | 0.000098 |

  47. | committing alter table to stor | 1.205005 | >>此时session2中事物已提交,altering table后顺利转到下一步

  48. | end | 0.000029 |

  49. | query end | 0.010155 |

  50. | closing tables | 0.000050 |

  51. | freeing items | 0.000182 |

  52. | logging slow query | 0.000142 |

  53. | cleaning up | 0.000028 |

  54. +--------------------------------+------------+

  55. 72 rows in set, 1 warning (0.00 sec)

 

 

3. 问题分析,解决

  从上面的分析我们可以看出来,online ddl执行到committing alter table to stor这一步的时候需要获取表的metadata lock(online ddl中最耗时的altering table这一步不需要获取metadata锁,不会阻塞dml)。而这时session2 对该表的dml并未提交(占用该表的metadata 锁),所以session1中的online ddl被session2 中的dml阻塞。

   居然知道了原因,那么修改应用,解决问题就简单了。

 

关于Waiting for table metadata lock 问题可参考:http://blog.csdn.net/shaochenshuo/article/details/51577728

评论
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值