+-
记录一次生产环境MySQL出现Deadlock

下午同事找到我,生产环境跑批日志出现了deadlock,什么?又是死锁。

查看MySQL死锁地址

LATEST DETECTED DEADLOCK
------------------------
2021-05-13 15:51:01 0x2b0b05a40700
*** (1) TRANSACTION:
TRANSACTION 4538725016, ACTIVE 0 sec inserting, thread declared inside InnoDB 4958
mysql tables in use 1, locked 1
LOCK WAIT 8 lock struct(s), heap size 1136, 41 row lock(s), undo log entries 1
MySQL thread id 14214779, OS thread handle 47326383310592, query id 61020879671 10.1.8.196 hlj_merchant_service_w update
insert into shop_give_info (redis_key, give_count,update_time, create_time)
values

('shop_give_like_7051c140a3134b8c8f52ee67870f2cd5', 3, now(), now())
,
('shop_give_like_0dd0a5df32c349f6966d50a03932c988', 2, now(), now())
,
('shop_give_like_c7672b0d75e342f0a857cd47e1e9e3e4', 1, now(), now())
,
('shop_give_like_327a5043eabf4aa7bf02c95db37a9311', 1, now(), now())
,
('shop_give_like_e4e2d71c12ae46bb928cfa4853845992', 13, now(), now())
,
('shop_give_like_835ac73c1f374ac78dacca5c653aa461', 1, now(), now())
,
('shop_give_like_1f33e9dee6244ba7b632d6d6bbb16f84', 4, now(), now())
,
('shop_give_like_d2099b5e65824381a7691221b95350f9', 12, now(), now())
,
('shop_give_like_bd0b99b8223441ca8f99aeb69900e8ee', 6, now(), now())
,
('shop_give_like_a38ec7d20b06433db33f5d63c762034a', 22, now(), now())

*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 271 page no 13 n bits 328 index idx_redis_key of table `hlj_merchant`.`shop_give_info` trx id 4538725016 lock_mode X waiting
Record lock, heap no 78 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
0: len 30; hex 73686f705f676976655f6c696b655f653337386162316563353861346264; asc shop_give_like_e378ab1ec58a4bd; (total 47 bytes);
1: len 4; hex 0000b631; asc    1;;

*** (2) TRANSACTION:
TRANSACTION 4538725015, ACTIVE 0 sec inserting, thread declared inside InnoDB 4804
mysql tables in use 1, locked 1
9 lock struct(s), heap size 1136, 179 row lock(s), undo log entries 1
MySQL thread id 14214716, OS thread handle 47326339270400, query id 61020879654 10.1.8.196 hlj_merchant_service_w update
insert into shop_give_info (redis_key, give_count,update_time, create_time)
values

('shop_give_like_32568c83f65e4495a52cc886959c4563', 1, now(), now())
,
('shop_give_like_5fd7b192a13242d8b6862cea48cdcc8c', 1, now(), now())
,
('shop_give_like_c1d3f493ad544caea3d1cd5372f4279a', 2, now(), now())
,
('shop_give_like_a69512e1c4f046f7a6862b3a37bfb3f4', 1, now(), now())
,
('shop_give_like_e9671bc6f8fa4029a3c2a7d6a38f49e2', 1, now(), now())
,
('shop_give_like_c4d207cf3fb04da9a67607adbbd33147', 4, now(), now())
,
('shop_give_like_094d0b182ba54f728dbaa46481aaa3f5', 2, now(), now())
,
('shop_give_like_80cfeae362ad4fe8b7724d5b0f1689c6', 3, now(), now())
,
('shop_give_like_afee10504ce247e7a5fc41b657dd1332', 6, now(), now())
,
('shop_give_like_1fce3be3efd74aceba7fe3af83c2e963', 1, now(), now())
,
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 271 page no 13 n bits 328 index idx_redis_key of table `hlj_merchant`.`shop_give_info` trx id 4538725015 lock_mode X
Record lock, heap no 4 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
0: len 30; hex 73686f705f676976655f6c696b655f633330613630633233636239346262; asc shop_give_like_c30a60c23cb94bb; (total 47 bytes);
1: len 4; hex 0000c9ce; asc     ;;

Record lock, heap no 7 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
0: len 30; hex 73686f705f676976655f6c696b655f633464323037636633666230346461; asc shop_give_like_c4d207cf3fb04da; (total 47 bytes);
1: len 4; hex 0000b52f; asc    /;;

Record lock, heap no 10 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
0: len 30; hex 73686f705f676976655f6c696b655f633564616637646366396266346130; asc shop_give_like_c5daf7dcf9bf4a0; (total 47 bytes);
1: len 4; hex 0000c077; asc    w;;

Record lock, heap no 12 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
0: len 30; hex 73686f705f676976655f6c696b655f633661666666616635303534343566; asc shop_give_like_c6afffaf505445f; (total 47 bytes);
1: len 4; hex 0000c749; asc    I;;

Record lock, heap no 24 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
0: len 30; hex 73686f705f676976655f6c696b655f636239363730623262616162343361; asc shop_give_like_cb9670b2baab43a; (total 47 bytes);
1: len 4; hex 0000c1b5; asc     ;;

Record lock, heap no 26 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
0: len 30; hex 73686f705f676976655f6c696b655f636432663131346636393537346534; asc shop_give_like_cd2f114f69574e4; (total 47 bytes);
1: len 4; hex 0000c3ef; asc     ;;

Record lock, heap no 36 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
0: len 30; hex 73686f705f676976655f6c696b655f643139376336666337623438343938; asc shop_give_like_d197c6fc7b48498; (total 47 bytes);
1: len 4; hex 0000c281; asc     ;;

Record lock, heap no 42 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
0: len 30; hex 73686f705f676976655f6c696b655f643433376433313162633630343732; asc shop_give_like_d437d311bc60472; (total 47 bytes);
1: len 4; hex 0000bdc8; asc     ;;

Record lock, heap no 47 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
0: len 30; hex 73686f705f676976655f6c696b655f643735663437613530396637346237; asc shop_give_like_d75f47a509f74b7; (total 47 bytes);
1: len 4; hex 0000c0ff; asc     ;;

Record lock, heap no 62 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
0: len 30; hex 73686f705f676976655f6c696b655f646365336563346333656561346232; asc shop_give_like_dce3ec4c3eea4b2; (total 47 bytes);
1: len 4; hex 0000bd2a; asc    *;;

Record lock, heap no 64 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
0: len 30; hex 73686f705f676976655f6c696b655f646663643636613266623463343364; asc shop_give_like_dfcd66a2fb4c43d; (total 47 bytes);
1: len 4; hex 0000ba0e; asc     ;;

Record lock, heap no 78 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
0: len 30; hex 73686f705f676976655f6c696b655f653337386162316563353861346264; asc shop_give_like_e378ab1ec58a4bd; (total 47 bytes);
1: len 4; hex 0000b631; asc    1;;

Record lock, heap no 92 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
0: len 30; hex 73686f705f676976655f6c696b655f653936373162633666386661343032; asc shop_give_like_e9671bc6f8fa402; (total 47 bytes);
1: len 4; hex 0000b52a; asc    *;;

Record lock, heap no 100 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
0: len 30; hex 73686f705f676976655f6c696b655f656331613130366233393735343438; asc shop_give_like_ec1a106b3975448; (total 47 bytes);
1: len 4; hex 0000bbdf; asc     ;;

Record lock, heap no 103 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
0: len 30; hex 73686f705f676976655f6c696b655f656430396432633362373631346339; asc shop_give_like_ed09d2c3b7614c9; (total 47 bytes);
1: len 4; hex 0000bb6e; asc    n;;

Record lock, heap no 112 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
0: len 30; hex 73686f705f676976655f6c696b655f663338326137633165303431343866; asc shop_give_like_f382a7c1e04148f; (total 47 bytes);
1: len 4; hex 0000c549; asc    I;;

Record lock, heap no 127 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
0: len 30; hex 73686f705f676976655f6c696b655f663764616535343938643032343534; asc shop_give_like_f7dae5498d02454; (total 47 bytes);
1: len 4; hex 0000bff1; asc     ;;

Record lock, heap no 142 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
0: len 30; hex 73686f705f676976655f6c696b655f666639653335303562303731346261; asc shop_give_like_ff9e3505b0714ba; (total 47 bytes);
1: len 4; hex 0000c647; asc    G;;

Record lock, heap no 143 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
0: len 30; hex 73686f705f676976655f6c696b655f643432323664343839663338343862; asc shop_give_like_d4226d489f3848b; (total 47 bytes);
1: len 4; hex 0000ca82; asc     ;;

Record lock, heap no 144 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
0: len 30; hex 73686f705f676976655f6c696b655f636434663939666630386363343762; asc shop_give_like_cd4f99ff08cc47b; (total 47 bytes);
1: len 4; hex 0000cb76; asc    v;;

Record lock, heap no 145 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
0: len 30; hex 73686f705f676976655f6c696b655f643063646431386462366163346435; asc shop_give_like_d0cdd18db6ac4d5; (total 47 bytes);
1: len 4; hex 0000ccfb; asc     ;;

*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 271 page no 9 n bits 344 index idx_redis_key of table `hlj_merchant`.`shop_give_info` trx id 4538725015 lock_mode X waiting
Record lock, heap no 156 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
0: len 30; hex 73686f705f676976655f6c696b655f373035316331343061333133346238; asc shop_give_like_7051c140a3134b8; (total 47 bytes);
1: len 4; hex 0000d365; asc    e;;

*** WE ROLL BACK TRANSACTION (1)

这个SQL的逻辑是有数据则update,无数据则做insert。
通过日志可以看出,出现了行级锁,两个线程id为14214779和14214716。

查看SQL审计日志

在死锁时间点,两个线程:


问题分析

从上边图片可以看出是两个线程由于交叉insert(实际是update)而出现了死锁,由于日志显示不全,猜测是两个线程更新的数据有重复的行。
查看跑批代码如下:

ShopRankQuery query = new ShopRankQuery();
query.setRankVersion(Long.valueOf(versionKey));
query.setPage(1);
query.setItemsPerPage(500);

List<ShopRankModel> rankModels = shopRankMapper.queryShopRankByQuery(query);

while (CollectionUtils.isNotEmpty(rankModels)){
logger.info(String.format("page:%s,itemPerPage:%s query shop rank", query.getPage(),query.getItemsPerPage()));
List<ShopGiveInfoModel> giveInfoModelList = new ArrayList<>();
for (ShopRankModel shopRank : rankModels) {

String key = getRedisKey(SHOP_GIVE_LIKE, shopRank.getShopId());

String str = redisService.get(key);

if (StringUtils.isBlank(str)){
continue;
}
ShopGiveInfoModel shopGiveInfoModel = new ShopGiveInfoModel();
shopGiveInfoModel.setRedisKey(key);
shopGiveInfoModel.setGiveCount(Integer.valueOf(str));
giveInfoModelList.add(shopGiveInfoModel);
shopGiveInfoMapper.insertGiveInfo(giveInfoModelList);
}
query.setPage(query.getPage() + 1);
rankModels = shopRankMapper.queryShopRankByQuery(query);
}

每次循环跑完,下一次循环会覆盖前一次的更新,也就是每次更新都包含前一次的数据,显然这串代码是有问题的。
但是同事并不认可两个线程的说法,他坚持说自己没有开启多线程。可是日志不会说谎。
经过查看任务调度工具的源码,发现默认是以多线程的方式调取任务,到此,问题原因已经找到:

本身跑批代码存在问题 采用多线程update