写在前面
在负责一功能优化改造后，测试运行过程中极少几率会出现如下错误，而其他环境却没出现过此错误：
1 | org.springframework.dao.DeadlockLoserDataAccessException: |
因为该处程序逻辑复杂，遇到这种没有头绪的报错，需经过漫长的查阅资料、对比数据、场景还原，终于找到了原因。
排查过程中涉及了：innodb的事务隔离别、innodb的锁、事务的加锁机制等
正文
排查过程
通过一行一行阅读日志，未发现前置异常。
而且该异常属于偶发，经观察，一天发生2-3次，所以初步怀疑是多线程运行到某一特定场景才会发生该异常，所以使用junit测试，按照真实场景进行了多次并发测试，也没有发现问题
观察数据库引擎日志，
1
show engine innodb status;
发现类似如下的死锁日志
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106LATEST DETECTED DEADLOCK
------------------------
15:09:16 0x7ffac5155700
*** (1) TRANSACTION:
TRANSACTION 46420280, ACTIVE 6 sec inserting
mysql tables in use 1, locked 1
LOCK WAIT 3 lock struct(s), heap size 1136, 2 row lock(s), undo log entries 1
MySQL thread id 272511, OS thread handle 140715073451776, query id 13981494 10.11.33.169 root update
INSERT INTO schema_sys_publish_ifttt_detail_redo (
created_by,
updated_by,
created_time,
updated_time,
deleted,
project_id,
schema_id,
publish_id,
ifttt_id,
detail_id,
data_type,
release_type,
do_status,
detail_content
)
VALUES
(
'227369843e647450.709447184398311425',
'227369843e647450.709447184398311425',
'10:20:12.796',
'10:20:12.796',
0,
'pj.734852916810883072',
'sc.765951479278145536',
'pub2.766243991602593792',
'AL.7662440293513297926',
'A01766244029628153856',
2,
1,
1,
'
'
)
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 1526 page no 24 n bits 304 index idx_iot_ifttt_id of table `aiot_iiap_luoshu`.`schema_sys_publish_ifttt_detail_redo` trx id 46420280 lock_mode X locks gap before rec insert intention waiting
Record lock, heap no 237 PHYSICAL RECORD: n_fields 3; compact format; info bits 0
0: len 23; hex 707562322e373636323433393931363032353933373932; asc pub2.766243991602593792;;
1: len 22; hex 414c2e37363632343430323933353133323937393330; asc AL.7662440293513297930;;
2: len 8; hex 8000000000000b09; asc ;;
*** (2) TRANSACTION:
TRANSACTION 46420279, ACTIVE 7 sec inserting
mysql tables in use 1, locked 1
4 lock struct(s), heap size 1136, 3 row lock(s), undo log entries 1
MySQL thread id 272509, OS thread handle 140715025061632, query id 13981425 10.11.33.169 root update
INSERT INTO schema_sys_publish_ifttt_detail_redo (
created_by,
updated_by,
created_time,
updated_time,
deleted,
project_id,
schema_id,
publish_id,
ifttt_id,
detail_id,
data_type,
release_type,
do_status,
detail_content
)
VALUES
(
'227369843e647450.709447184398311425',
'227369843e647450.709447184398311425',
'10:20:12.796',
'10:20:12.796',
0,
'pj.734852916810883072',
'sc.765951479278145536',
'pub2.766243991602593792',
'AL.7662440293513297922',
'A01766244029628153856',
2,
1,
1,
''
)
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 1526 page no 24 n bits 304 index idx_iot_ifttt_id of table `aiot_iiap_luoshu`.`schema_sys_publish_ifttt_detail_redo` trx id 46420279 lock_mode X locks gap before rec
Record lock, heap no 237 PHYSICAL RECORD: n_fields 3; compact format; info bits 0
0: len 23; hex 707562322e373636323433393931363032353933373932; asc pub2.766243991602593792;;
1: len 22; hex 414c2e37363632343430323933353133323937393330; asc AL.7662440293513297930;;
2: len 8; hex 8000000000000b09; asc ;;
*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 1526 page no 24 n bits 304 index idx_iot_ifttt_id of table `aiot_iiap_luoshu`.`schema_sys_publish_ifttt_detail_redo` trx id 46420279 lock_mode X locks gap before rec insert intention waiting
Record lock, heap no 237 PHYSICAL RECORD: n_fields 3; compact format; info bits 0
0: len 23; hex 707562322e373636323433393931363032353933373932; asc pub2.766243991602593792;;
1: len 22; hex 414c2e37363632343430323933353133323937393330; asc AL.7662440293513297930;;
2: len 8; hex 8000000000000b09; asc ;;
*** WE ROLL BACK TRANSACTION (1)
------------找到具体的错误信息，然后细读该错误信息，查阅相关资料，经过多次测试，终找到了原因，现在大概记录下排查过程和总结分析。
原因解析
- 首先从mysql的锁触发，首先需要明白mysql四个事务隔离级别以及他们为了解决什么问题：数据库事务的隔离级别有4个，由低到高依次为Read uncommitted(读未提交)、Read committed（读提交）、Repeatable read（可重复读）、Serializable（序列化），这四个级别可以逐个解决脏读、不可重复读、幻象读这几类问题
- Read uncommitted
- 简称RU，读未提交，如果一个事务已经开始写数据，则另外一个事务则不允许同时进行写操作，但允许其他事务读此行数据。该隔离级别可以通过“排他写锁”实现。这样就避免了更新丢失，却可能出现脏读。也就是说事务B读取到了事务A未提交的数据。
- Read committed
- 简称RC，读提交，读取数据的事务允许其他事务继续访问该行数据，但是未提交的写事务将会禁止其他事务访问该行。该隔离级别避免了脏读，但是却可能出现不可重复读。事务A事先读取了数据，事务B紧接了更新了数据，并提交了事务，而事务A再次读取该数据时，数据已经发生了改变。
- Repeatable read
- 简称RR，可重复读，可重复读是指在一个事务内，多次读同一数据。在这个事务还没有结束时，另外一个事务也访问该同一数据。那么，在第一个事务中的两次读数据之间，即使第二个事务对数据进行修改，第一个事务两次读到的的数据是一样的。这样就发生了在一个事务内两次读到的数据是一样的，因此称为是可重复读。写事务则禁止任何其他事务，再通过GAP锁或next-key锁进行区间保障可重复读。这样避免了不可重复读取和脏读，但是极个别情况下有时可能出现幻象读。（读取数据的事务）这可以通过“共享读锁”和“排他写锁”实现。
- Serializable
- 简称S，序列化，提供严格的事务隔离。它要求事务序列化执行，事务只能一个接着一个地执行，但不能并发执行。如果仅仅通过“行级锁”是无法实现事务序列化的，必须通过其他机制保证新插入的数据不会被刚执行查询操作的事务访问到。序列化是最高的事务隔离级别，同时代价也花费最高，性能很低，一般很少使用，在该级别下，事务顺序执行，不仅可以避免脏读、不可重复读，还避免了幻像读。
- 上面简单说了下概念类的东西，比较虚，更详细的网上很多。
- Read uncommitted
- 未完待续……
- 首先从mysql的锁触发，首先需要明白mysql四个事务隔离级别以及他们为了解决什么问题：数据库事务的隔离级别有4个，由低到高依次为Read uncommitted(读未提交)、Read committed（读提交）、Repeatable read（可重复读）、Serializable（序列化），这四个级别可以逐个解决脏读、不可重复读、幻象读这几类问题