查看mysql数据库的死锁日志_MySQL 死锁与日志二三事

最近线上 MySQL 接连发生了几起数据异常，都是在凌晨爆发，由于业务场景属于典型的数据仓库型应用，白天压力较小无法复现。甚至有些异常还比较诡异，最后 root cause 分析颇费周折。那实际业务当中咱们如何能快速的定位线上 MySQL 问题，修复异常呢？下文我会根据两个实际 case，分享下相关的经验与方法。

1、Case1：部分数据更新失败

某天渠道同学反馈某报表极个别渠道数据为 0，大部分渠道数据正常。这个数据是由一个统计程序每天凌晨例行更新的，按理来说，要么全部正常，要么全部失败，那会是什么原因导致极个别数据异常呢？

首先我们能想到的自然是根据统计任务日志来看了，但是看了统计程序打印的日志没有发现诸如 SQL update 失败的异常描述，那当时的数据库究竟发生了什么呢？在查看 MySQL-server 日志之前，习惯性的看了下数据库状态：

SHOW ENGINE INNODB STATUS\G

恰好看到了凌晨这个 update 发生了死锁：

------------------------

LATEST DETECTED DEADLOCK

------------------------

2017-07-17 04:09:01 0x7f6de03c8700

*** (1) TRANSACTION:

TRANSACTION 215208479, ACTIVE 0 sec fetching rows

mysql tables in use 3, locked 3

LOCK WAIT 5 lock struct(s), heap size 1136, 3 row lock(s)

MySQL thread id 27844824, OS thread handle 140092183037696, query id 412503674 10.126.95.84 zeye Searching rows for update

update t_channel_final_datas set nr_register=133,nr_add_goods=29,nr_order_normal=11,nr_pay_normal=8,nr_order_special=0,nr_pay_special=0,n_add_user_num=16 where count_date='2017-07-16' and channel_id='16' and channel_type='10' and terminal='26'

*** (1) WAITING FOR THIS LOCK TO BE GRANTED:

RECORD LOCKS space id 464 page no 5459 n bits 392 index index_countdate_type_terminal of table `db_zz_flow`.`t_channel_final_datas` trx id 215208479 lock_mode X locks rec but not gap waiting

Record lock, heap no 304 PHYSICAL RECORD: n_fields 4; compact format; info bits 0

0: len 10; hex 323031372d30372d3136; asc 2017-07-16;;

1: len 1; hex 30; asc 0;;

2: len 4; hex 80000010; asc ;;

3: len 4; hex 8009055e; asc ^;;

*** (2) TRANSACTION:

TRANSACTION 215208474, ACTIVE 0 sec fetching rows

mysql tables in use 3, locked 3

6 lock struct(s), heap size 1136, 7 row lock(s)

MySQL thread id 27844825, OS thread handle 140109890225920, query id 412503669 10.135.6.41 zeye Searching rows for update

update t_channel_final_datas set nr_register=24,nr_add_goods=32,nr_order_normal=0,nr_pay_normal=0,nr_order_special=0,nr_pay_special=0,n_add_user_num=11 where count_date='2017-07-16' and channel_id='114' and channel_type='10' and terminal='116'

*** (2) HOLDS THE LOCK(S):

RECORD LOCKS space id 464 page no 5459 n bits 392 index index_countdate_type_terminal of table `db_zz_flow`.`t_channel_final_datas` trx id 215208474 lock_mode X locks rec but not gap

Record lock, heap no 304 PHYSICAL RECORD: n_fields 4; compact format; info bits 0

0: len 10; hex 323031372d30372d3136; asc 2017-07-16;;

1: len 1; hex 30; asc 0;;

2: len 4; hex 80000010; asc ;;

3: len 4; hex 8009055e; asc ^;;

...

*** (2) WAITING FOR THIS LOCK TO BE GRANTED:

RECORD LOCKS space id 464 page no 4743 n bits 264 index PRIMARY of table `db_zz_flow`.`t_channel_final_datas` trx id 215208474 lock_mode X locks rec but not gap waiting

Record lock, heap no 168 PHYSICAL RECORD: n_fields 32; compact format; info bits 0

0: len 4; hex 80090569; asc i;;

1: len 6; hex 00000cd3b9d0; asc ;;

...

*** WE ROLL BACK TRANSACTION (1)

篇幅所限，上下文我这里省略了很多，从这段日志里可以看到，TRANSACTION 1 和 TRANSACTION 2 分别持有一定数量的行锁，然后又等待对方的锁，最后 MySQL 检测到 deadlock ，然后选择回滚了 TRANSACTION 1：Innodb目前处理死锁的方法是将持有最少行级排他锁的事务进行回滚。

那这里就有 3 个问题了：

(1)innodb 行锁不是只锁一行？

因为这张表是 innodb 引擎的，InnoDB 支持行锁和表锁。而InnoDB行锁是通过给索引上的索引项加锁来实现的，这一点MySQL与Oracle不同，后者是通过在数据块中对相应数据行加锁来实现的。InnoDB这种行锁实现特点意味着：只有通过索引条件检索数据，InnoDB才使用行级锁，否则，InnoDB将使用表锁，会把所有扫描过的行都锁定！在实际应用中，要特别注意InnoDB行锁的这一特性，不然的话，可能导致大量的锁冲突，从而影响并发性能。由于MySQL的行锁是针对索引加的锁，不是针对记录加的锁，所以虽然是访问不同行的记录，但是如果是使用相同的索引键，是会出现锁冲突的。当我们用范围条件而不是相等条件检索数据，并请求共享或排他锁时，InnoDB会给符合条件的已有数据记录的索引项加锁；另外间隙锁也会锁多行，InnoDB除了通过范围条件加锁时使用间隙锁外，如果使用相等条件请求给一个不存在的记录加锁，InnoDB也会使用间隙锁！

话都说到这了，那就看下咱们业务表的索引情况：

show INDEX from `db_zz_flow`.`t_channel_final_datas`;

+-----------------------+--------------+-------------------------------+----------------+-------------+----------+--------+--------------+-----------+-----------------+

| Table | Non_unique | Key_name | Seq_in_index | Column_namt | Packed | Null | Index_type | Comment | Index_comment