一.事件回放
1月的几天时间里每天会收到1次或者2次死锁的短信告警,死锁日志如下图。
二、检查业务场景和程序处理流程
用户打赏礼物请求处理,涉及到用户余额表和佣金账户表,以下所有操作在一个事务里,事务的隔离级别是read-commited,前一个操作执行成功才会继续下一个步骤否则抛出异常回滚事务:
1.扣除用户余额账户金额
2.增加陪玩佣金账户金额
3.增加公会佣金账户金额
佣金表的结构如下:
CREATE TABLE `tb_commission` (
`accountid` int(10) unsigned NOT NULL COMMENT '主播UID',
`accounttype` tinyint(4) NOT NULL COMMENT '0主播,1频道',
`commission` bigint(20) unsigned NOT NULL DEFAULT '0' COMMENT '当前佣金',
`total_commission` bigint(20) unsigned NOT NULL DEFAULT '0' COMMENT '累计佣金',
`frozen_commission` bigint(20) unsigned NOT NULL DEFAULT '0' COMMENT '冻结佣金',
`status` smallint(3) unsigned NOT NULL DEFAULT '0' COMMENT '佣金状态,0未冻结,1冻结',
`timestamp` timestamp NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP,
PRIMARY KEY (`accountid`,`accounttype`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8
我检查了所有用到佣金账户表的sql和代码处理流程顺序都是一致的,没有发现问题,于是我就去找DBA要了死锁的详细日志.
三.DBA提供的死锁详细日志
注:为保护公司隐私dbname、tb_commission不是生产环境真正的数据名、表名,ip地址也进行了更换。
-01-08 01:53:06 7f25d2fbf700
*** (1) TRANSACTION:
TRANSACTION 30633199182, ACTIVE 0 sec inserting
mysql tables in use 1, locked 1
LOCK WAIT 12 lock struct(s), heap size 2936, 5 row lock(s), undo log entries 13
MySQL thread id 1072389036, OS thread handle 0x7f25c1412700, query id 54551996265 192.168.1.28 abV8hoho update
insert into tb_commission
(accountid,accounttype,commission,total_commission,frozen_commission,status,timestamp)
values (70421152,1,200,200,
0,0,null)
ON DUPLICATE KEY UPDATE
commission=commission+ 200,
total_commission=total_commission + 200
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 347 page no 753 n bits 232 index `PRIMARY` of table `dbname`.`tb_commission` trx id 30633199182 lock_mode X locks rec but not gap waiting
Record lock, heap no 45 PHYSICAL RECORD: n_fields 9; compact format; info bits 0
0: len 4; hex 04328aa0; asc 2 ;;
1: len 1; hex 81; asc ;;
2: len 6; hex 000721e1867a; asc ! z;;
3: len 7; hex 67000040361056; asc g @6 V;;
4: len 8; hex 00000000008726ac; asc & ;;
5: len 8; hex 00000000057c9f48; asc | H;;
6: len 8; hex 0000000000000000; asc;;
7: len 2; hex 0000; asc ;;
8: len 4; hex 5c339202; asc \3 ;;
*** (2) TRANSACTION:
TRANSACTION 30633199226, ACTIVE 0 sec inserting, thread declared inside InnoDB 5000
mysql tables in use 1, locked 1
11 lock struct(s), heap size 1184, 4 row lock(s), undo log entries 12
MySQL thread id 1072335460, OS thread handle 0x7f25d2fbf700, query id 54551996331 192.168.1.29 abV8hoho update
insert into tb_commission
(accountid,accounttype,commission,total_commission,frozen_commission,status,timestamp)
values (2258424137,0,2000,2000,
0,0,null)
ON DUPLICATE KEY UPDATE
commission=commission+ 2000,
total_commission=total_commission + 2000
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 347 page no 753 n bits 232 index `PRIMARY` of table `dbname`.`tb_commission` trx id 30633199226 lock_mode X locks rec but not gap
Record lock, heap no 45 PHYSICAL RECORD: n_fields 9; compact format; info bits 0
0: len 4; hex 04328aa0; asc 2 ;;
1: len 1; hex 81; asc ;;
2: len 6; hex 000721e1867a; asc ! z;;
3: len 7; hex 67000040361056; asc g @6 V;;
4: len 8; hex 00000000008726ac; asc & ;;
5: len 8; hex 00000000057c9f48; asc | H;;
6: len 8; hex 0000000000000000; asc;;
7: len 2; hex 0000; asc ;;
8: len 4; hex 5c339202; asc \3 ;;
*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 347 page no 670 n bits 368 index `PRIMARY` of table `dbname`.`tb_commission` trx id 30633199226 lock_mode X locks rec but not gap waiting
Record lock, heap no 65 PHYSICAL RECORD: n_fields 9; compact format; info bits 0
0: len 4; hex 869cd149; asc I;;
1: len 1; hex 80; asc ;;
2: len 6; hex 000721e1864e; asc ! N;;
3: len 7; hex 620000402d129c; asc b @- ;;
4: len 8; hex 00000000002034d8; asc 4 ;;
5: len 8; hex 00000000008eac10; asc;;
6: len 8; hex 0000000000000000; asc;;
7: len 2; hex 0000; asc ;;
8: len 4; hex 5c339202; asc \3 ;;
*** WE ROLL BACK TRANSACTION (2)
四、死锁原因分析
因为是唯一索引,insert需要做检查,除了申请X锁(排他锁)还需要申请S锁(共享锁),事务1先申请X锁(排他锁)成功, 然后申请S锁, 但是事务2正在申请X锁, 与事务1的S锁冲突, 系统决定回滚事务2。
五、解决方式:
先查询一次账户,如果存在直接update,否则再执行原来的逻辑INSERT INTO ON DUPLICATE KEY UPDATE。我这里的解决方案其实是一种乐观主义的,认为大多数情况下账号是存在的直接执行update语句,修改之后我们的业务没有再发生死锁,如果业务的要求比较高的话,这样处理可能是不够的,并发环境下同时查询到账户不存在,又可能会触发死锁。我目前能想到的就是账户不存在时对该用户的账户加个锁,拿到锁的事务执行完释放;获取不到锁的可以自旋等待直到锁被释放再执行update操作,但是加锁也会增加复杂性,可能带来更多的问题。
这个问题已经解决,并不是之前认为的那样,前段时间又重现了,查看日志发现两台机都出现了同时有对同一个账户打赏的日志,查看日志上下文发现有一个日志很像是循环执行的, 另外一个只有一条打赏日志,然后回去看代码,发现是个用户批量打赏给若干人的请求,里边确实是用for循环调用另外打赏单个用户的一个事务,外面还要一层大事务,打赏单个用户的事务里边才是先扣用户钱、更新陪玩账户余额、更新公会账户余额、写流水等操作,里边的小事务执行完依然持有锁,直到所有的小事务完成才提交,锁持有的时间过长才导致另外一个单个打赏事务等待锁超时,mysql会让占有资源更少的事务回滚。找到原因之后对代码进行了优化,将for循环去掉,改为用map累计打赏金额批量更新的方式,后来再没有重现过。
如果您有幸看到这篇文章,如果有好的见解欢迎留言,我们可以一起讨论。