为了快速同步数据的需要,我分段执行了两次python脚本,即开启了两个进程同步数据,结果服务器不时报出数据库死锁异常,通过排查代码和数据库日志发现,是由长事务并发引起的。代码中有入账和出账两个方法,里面涉及操作较多,都为其加了事务,抛出异常时可自动回滚,采用数据库(mysql)默认的隔离级别(Repeatable read)。提到并发,一般就会想到用同步代码块的方法的处理,但是由于项目是分布式的,共用一个主库,单单在代码加锁是不能保证数据的准确的,那就只能在数据库层面去考虑加锁了。由于数据量暂时不大,一开始我的解决方法是将隔离级别调整为最高(Serializable),这样虽然代价较大,但是能保证数据的准确性,数据库的锁也会相互等待,但当我再重新同步数据时,还是报出了大量死锁异常(com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction),仔细追踪数据库日志,发现有两个锁在两条update语句上互相等待(操作的是一张统计表),但这两条update语句不是落到同一行上的,因为查询条件并不一样。那就奇怪了,一般来说是行锁的问题,最后排查发现,是该表未加索引的原因,造成了事务锁住了这张表,而由于多个事务是同时执行到这里,造成了锁的互相等待,最终数据库选择回滚了其中一个事务。发现问题后,我将表加了索引,再运行时,已经没报这个错误了(子查询也是会导致锁表的)。为了保证代码的运行效率,我将数据库级别设置为Repeatable read,但随之而来发现了一些数据出现了幻读,最后我是在update语句那里加了一个beforeMoney的过滤(update wallet_stat set money = afterMoney where id = xxx and money = beforeMoney),这样就能保证数据的准确性了,不过这里不足的是,虽保证了数据的正确,但并发的那个事务却必须回滚。这里也可以考虑借助队列或者乐观锁等方式来解决这个问题,就不一一详述了。
以上就是我处理这个问题的全过程,为了查找解决方案,我在查找了很多文章,获益良多。以下是我认为比较好的资料:
什么是事务:
数据库事务的隔离级别有4个,由低到高依次为Read uncommitted、Read committed、Repeatable read、Serializable,这四个级别可以逐个解决脏读、不可重复读、幻读这几类问题。
注意:我们讨论隔离级别的场景,主要是在多个事务并发的情况下,因此,接下来的讲解都围绕事务并发。
Read uncommitted 读未提交
公司发工资了,领导把5000元打到singo的账号上,但是该事务并未提交,而singo正好去查看账户,发现工资已经到账,是5000元整,非常高兴。可是不幸的是,领导发现发给singo的工资金额不对,是2000元,于是迅速回滚了事务,修改金额后,将事务提交,最后singo实际的工资只有2000元,singo空欢喜一场。
出现上述情况,即我们所说的脏读,两个并发的事务,“事务A:领导给singo发工资”、“事务B:singo查询工资账户”,事务B读取了事务A尚未提交的数据。
当隔离级别设置为Read uncommitted时,就可能出现脏读,如何避免脏读,请看下一个隔离级别。
Read committed 读提交
singo拿着工资卡去消费,系统读取到卡里确实有2000元,而此时她的老婆也正好在网上转账,把singo工资卡的2000元转到另一账户,并在singo之前提交了事务,当singo扣款时,系统检查到singo的工资卡已经没有钱,扣款失败,singo十分纳闷,明明卡里有钱,为何......
出现上述情况,即我们所说的不可重复读,两个并发的事务,“事务A:singo消费”、“事务B:singo的老婆网上转账”,事务A事先读取了数据,事务B紧接了更新了数据,并提交了事务,而事务A再次读取该数据时,数据已经发生了改变。
当隔离级别设置为Read committed时,避免了脏读,但是可能会造成不可重复读。
大多数数据库的默认级别就是Read committed,比如Sql Server , Oracle。如何解决不可重复读这一问题,请看下一个隔离级别。
Repeatable read 重复读
当隔离级别设置为Repeatable read时,可以避免不可重复读。当singo拿着工资卡去消费时,一旦系统开始读取工资卡信息(即事务开始),singo的老婆就不可能对该记录进行修改,也就是singo的老婆不能在此时转账。
虽然Repeatable read避免了不可重复读,但还有可能出现幻读。
singo的老婆工作在银行部门,她时常通过银行内部系统查看singo的信用卡消费记录。有一天,她正在查询到singo当月信用卡的总消费金额(select sum(amount) from transaction where month = 本月)为80元,而singo此时正好在外面胡吃海塞后在收银台买单,消费1000元,即新增了一条1000元的消费记录(insert transaction ... ),并提交了事务,随后singo的老婆将singo当月信用卡消费的明细打印到A4纸上,却发现消费总额为1080元,singo的老婆很诧异,以为出现了幻觉,幻读就这样产生了。
注:mysql的默认隔离级别就是Repeatable read。
Serializable 序列化
Serializable是最高的事务隔离级别,同时代价也花费最高,性能很低,一般很少使用,在该级别下,事务顺序执行,不仅可以避免脏读、不可重复读,还避免了幻像读。
mysql锁阻塞分析:
查看锁阻塞线程信息
这里用几中方法进行分析:
使用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)
如果数据库存在较多线程的话,这种方法确实不太好确认的。
直接使用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为什么出现等待,这里分析不到根因。
使用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阻塞的。
使用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查看,能够找到锁阻塞的根因。
注:文章出自