1、死鎖日志

2018-10-23T07:16:23.919555+08:00 478808 [Note] InnoDB: Transactions deadlock detected, dumping detailed information.

2018-10-23T07:16:23.919573+08:00 478808 [Note] InnoDB:?

*** (1) TRANSACTION:

TRANSACTION 638350242, ACTIVE 0 sec starting index read

mysql tables in use 1, locked 1

LOCK WAIT 18 lock struct(s), heap size 1136, 6 row lock(s), undo log entries 2

MySQL thread id 482727, OS thread handle 139949379430144, query id 1038382163 10.205.72.161 ucp updating

update ccp_order_info_1 set bill_push_status = 1 where partner_id = '80640511' and ?order_code in

? ? ?( ?'UCP181023071619030500' , 'UCP181023071613030491', 'UCP181023071604030490', 'UCP181023071558030489' )

2018-10-23T07:16:23.919607+08:00 478808 [Note] InnoDB: *** (1) WAITING FOR THIS LOCK TO BE GRANTED:

RECORD LOCKS space id 383 page no 9655 n bits 104 index PRIMARY of table `ccp`.`ccp_order_info_1` /* Partition `p201810` */ trx id 638350242 lock_mode X locks rec but not gap waiting

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

?0: len 8; hex fd67828666135000; asc ?g ?f P ;;

?1: len 4; hex 5bce5a3d; asc [ Z=;;

?2: len 6; hex 0000260c73a3; asc ? & s ;;

?3: len 7; hex 28000000230937; asc ( ? # 7;;

?4: len 21; hex 554350313831303233303731363133303330343931; asc UCP181023071613030491;;

? ... // 省略后續(xù)82個字段的信息

TRANSACTION 638350243, ACTIVE 0 sec fetching rows

mysql tables in use 1, locked 1

14 lock struct(s), heap size 1136, 2 row lock(s), undo log entries 1

MySQL thread id 478808, OS thread handle 139949392209664, query id 1038382165 10.205.72.157 ucp updating

UPDATE ccp_order_info_1 SET order_Status=1,error_Flag='1',push_time='2018-10-23 07:16:23.91' ?WHERE partner_id = '80640511' And ORDER_ID = ? ? ? ??

9036334691091959808

2018-10-23T07:16:23.921748+08:00 478808 [Note] InnoDB: *** (2) HOLDS THE LOCK(S):

RECORD LOCKS space id 383 page no 9655 n bits 112 index PRIMARY of table `ccp`.`ccp_order_info_1` /* Partition `p201810` */ trx id 638350243 lock_mode X locks rec but not gap

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

?0: len 8; hex fd67828666135000; asc ?g ?f P ;;

?1: len 4; hex 5bce5a3d; asc [ Z=;;

?2: len 6; hex 0000260c73a3; asc ? & s ;;

?3: len 7; hex 28000000230937; asc ( ? # 7;;

?4: len 21; hex 554350313831303233303731363133303330343931; asc UCP181023071613030491;;

?... 省略后面82個字段的信息

2018-10-23T07:16:23.923431+08:00 478808 [Note] InnoDB: *** (2) WAITING FOR THIS LOCK TO BE GRANTED:

RECORD LOCKS space id 383 page no 9655 n bits 104 index PRIMARY of table `ccp`.`ccp_order_info_1` /* Partition `p201810` */ trx id 638350243 lock_mode X locks rec but not gap waiting

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

?0: len 8; hex fd67a62566135000; asc ?g %f P ;;

?1: len 4; hex 5bce5a34; asc [ Z4;;

?2: len 6; hex 0000260c73a2; asc ? & s ;;

?3: len 7; hex 27000040030785; asc ' ?@ ? ;;

?4: len 21; hex 554350313831303233303731363034303330343930; asc UCP181023071604030490;;

?... 省略后面82個字段的信息

2018-10-23T07:16:23.925041+08:00 478808 [Note] InnoDB: *** WE ROLL BACK TRANSACTION (2)

上面是兩個事物發(fā)生死鎖的日志剪返，關(guān)鍵日志行分析如下：

1废累、*** (1) TRANSACTION:第一個事務(wù)消息開始。

2脱盲、LOCK WAIT 18 lock struct(s), heap size 1136, 6 row lock(s), undo log entries 2

18個鎖等待結(jié)構(gòu)體邑滨，6行被鎖定，事務(wù)內(nèi)已經(jīng)生成了 2個undo項钱反。

3掖看、MySQL thread id 482727, OS thread handle 139949379430144, query id 1038382163 10.205.72.161 ucp updating

mysql中對應(yīng)的線程ID為482727、操作系統(tǒng)的線程ID為139949379430144面哥，查詢id1038382163 ,線程狀態(tài)：更新中哎壳。

4、update ccp_order_info_1 set bill_push_status = 1 where partner_id = '80640511' and ?order_code in? ( ?'UCP181023071619030500' , 'UCP181023071613030491', 'UCP181023071604030490', 'UCP181023071558030489' )

當(dāng)前事務(wù)SQL尚卫，后文也得該語句執(zhí)行需申請鎖而被阻塞归榕。

5、2018-10-23T07:16:23.919607+08:00 478808 [Note] InnoDB: *** (1) WAITING FOR THIS LOCK TO BE GRANTED:

SQL語句中吱涉，需要申請的鎖（無法立即獲取鎖信息）

6刹泄、RECORD LOCKS space id 383 page no 9655 n bits 112 index PRIMARY of table `ccp`.`ccp_order_info_1` /* Partition `p201810` */ trx id 638350243 lock_mode X locks rec but not gap

需要申請的行鎖信息：表空間ID為383，頁為9655怎爵，在112個字節(jié)開始特石，需要鎖定的索引名為(ccp_order_info_1)的主鍵索引，事務(wù)ID為638350243鳖链，鎖的類型為lock_mode X locks rec but not gap waiting(行級別的排他鎖县匠，并不是間隙鎖)。

7撒轮、Record lock, heap no 32 PHYSICAL RECORD: n_fields 86; compact format; info bits 0

?0: len 8; hex fd67828666135000; asc ?g ?f P ;;

?1: len 4; hex 5bce5a3d; asc [ Z=;;

?2: len 6; hex 0000260c73a3; asc ? & s ;;

?3: len 7; hex 28000000230937; asc ( ? # 7;;

?4: len 21; hex 554350313831303233303731363133303330343931; asc UCP181023071613030491;;

?... 省略后面82個字段的信息

請求行鎖所對應(yīng)的物理數(shù)據(jù)（真實(shí)的行數(shù)據(jù)），從這里也開以看出贼穆，這里申請order_no='UCP181023071613030491' 該行數(shù)據(jù)的行鎖题山。

8、2018-10-23T07:16:23.921701+08:00 478808 [Note] InnoDB: *** (2) TRANSACTION:

接下來看第二個事務(wù)的信息故痊，根據(jù)上文的分析顶瞳，事務(wù)二在執(zhí)行的SQL語句為：UPDATE ccp_order_info_1 SET order_Status=1,error_Flag='1',push_time='2018-10-23 07:16:23.91' ?WHERE partner_id = '80640511' And ORDER_ID = ? ? ? ? 9036334691091959808 根據(jù)order_id更新1條數(shù)據(jù)。

9、2018-10-23T07:16:23.921748+08:00 478808 [Note] InnoDB: *** (2) HOLDS THE LOCK(S):

記錄事務(wù)二已持有的鎖信息：

10慨菱、2018-10-23T07:16:23.921748+08:00 478808 [Note] InnoDB: *** (2) HOLDS THE LOCK(S):

RECORD LOCKS space id 383 page no 9655 n bits 112 index PRIMARY of table `ccp`.`ccp_order_info_1` /* Partition `p201810` */ trx id 638350243 lock_mode X locks rec but not gap

發(fā)現(xiàn)事務(wù)二持有的鎖 焰络，正是事務(wù)一急切響應(yīng)的鎖，即order_no=''UCP181023071613030491'的主鍵索引符喝，即該索引對應(yīng)的行數(shù)據(jù)闪彼。

11、2018-10-23T07:16:23.923431+08:00 478808 [Note] InnoDB: *** (2) WAITING FOR THIS LOCK TO BE GRANTED:

顯示事務(wù)二需要申請的鎖协饲。

其主要是申請記錄UCP181023071604030490的主鍵索引畏腕，然后mysql立馬檢測到發(fā)生了索引，因?yàn)樵撴i已經(jīng)被事務(wù)1所持有茉稠，innodb會選擇回滾一個事務(wù)描馅，解除死鎖，從日志看出而线，innodb選擇將事務(wù)二進(jìn)行回滾铭污。

為什么事務(wù)二會去申請記錄UCP181023071604030490行鎖呢？從哪里可以看出事務(wù)1已經(jīng)持有記錄UCP181023071604030490的行鎖呢膀篮？

死鎖日志中嘹狞，沒有事務(wù)一中輸出事務(wù)1當(dāng)前所持有的行鎖，故我們只能從如下信息進(jìn)行推論：

LOCK WAIT 18 lock struct(s), heap size 1136, 6 row lock(s), undo log entries 2

MySQL thread id 482727, OS thread handle 139949379430144, query id 1038382163 10.205.72.161 ucp updating

update ccp_order_info_1 set bill_push_status = 1 where partner_id = '80640511' and ?order_code in

? ? ?( ?'UCP181023071619030500' , 'UCP181023071613030491', 'UCP181023071604030490', 'UCP181023071558030489' )

undo log entries 2各拷，創(chuàng)建了2個undo條目刁绒，猜測兩條update，與in中最后兩個條目吻合烤黍，故認(rèn)為上述推論可信知市。第二個問題，為什么事務(wù)二會去申請UCP181023071604030490的行鎖速蕊，應(yīng)該是事務(wù)2中還會有根據(jù)order_id去更新UCP181023071604030490該行的SQL語句嫂丙，與項目組確認(rèn)代碼后分析，確實(shí)是有for循環(huán)對多條數(shù)據(jù)進(jìn)行更新规哲，符合推論跟啤，死鎖問題得到完成分析。

死鎖原因分析：

1唉锌、事務(wù)1根據(jù)order_no(二級索引)更新多條記錄隅肥，其加鎖順序：?

UCP181023071558030489行：先申請 order_no_index , 再申請 primary_index (主鍵索引) ? 申請成功

UCP181023071604030490行：先申請 order_no_index, 再申請 primary_index (主鍵索引) ?申請成功

UCP181023071613030491行：先申請 order_no_index, 再申請 primary_index(主鍵索引) ? ? ? order_no_index 申請成功，primary_index 排隊等待

UCP181023071619030500行：先申請 order_no_index, 再申請 primary_index(主鍵索引)

2袄简、事務(wù)2是根據(jù)主鍵ID循環(huán)來更新多條記錄腥放，其加鎖順序?yàn)椋?/p>

UCP181023071613030491行：申請 primary_index（主鍵索引），然后再申請UCP181023071604030490 的主鍵索引绿语，事務(wù)一秃症，二相互持有各自需要鎖候址，死鎖發(fā)生。

解決方案：

1种柑、同表更新岗仑，用唯一字段更新， 要么order_id 聚请，要么order_no?

2荠雕、事務(wù)對多個數(shù)據(jù)更新操作，先集合排序良漱，順序加鎖舞虱，避免死鎖。

Mysql 數(shù)據(jù)庫加鎖母市，可以看看何登成http://hedengcheng.com/?p=771