记录排查一次线上的死锁问题

 

死锁问题出现

    某天下午突然接到报警说是出现了死锁，当时的日志是这样的

问题排查 

  我们先来回顾一下死锁出现的条件

  1、循环等待

  2、互斥

    此时看了下发布记录最近并没有什么功能上线，首先排除是上线代码质量问题引起的死锁。

    之后查看当时日志定位死锁发生在业务线同步请求的后处理环节，后处理环节涉及到该张表操作的一共有三个环节：同步请求环节，合作方通知结果环节，定时任务查询合作方环节。

    同步请求为串行执行并且没有开启异步操作这张表，定时任务会在同步请求入表之的一分钟后去扫描这张表，如果这张表中的记录没有到达终态便会拿到条记录的流水去查询合作方的结果，通知环节是由合作方触发

    经查看日志发现这条请求完成的时间一共是5秒左右，此时不会触发定时，那么可以判定该死所发生的原因就是合作方与同步任务同时更新该条记录引起的死锁 。

    接下来使用命令 show engine innodb status 查看当时死锁的信息，主要内容如下

(1)
SELECT

        id, user_id, sys_id, serv_id, loan_provide_id, gw_loan_provide_id, serv_loan_provide_id,
        serv_loan_provide_return_id, loan_verify_id, loan_type, request_date, finish_date, loan_amount, loan_status, serv_finish_date,
        loan_rate, loan_term, busi_type, total_repay_amount, total_refund_amount, total_refund_principal, error_code, error_info,
        serv_merchant_id, qunar_trade_no, fund_supplier, remark, start_interest_date, end_date, busi_type_id, loan_source,
        original_loan_provide_id, channel_code, product_no, product_subtype, bank_code, card_no_index, first_payment_date

        FROM tbl_loan_provide_info
        WHERE sys_id = '123'
        AND loan_provide_id = '123123'
        FOR UPDATE

wait: 
index `PRIMARY` of table `pay_fgateway`.`tbl_loan_provide_info` trx id 62679813597 lock_mode X locks rec but not gap waiting
Record lock
hold:
index `uniq_sys_provide_id` of table `pay_fgateway`.`tbl_loan_provide_info` trx id 62679813593 lock_mode X locks rec but not gap waiting


(2)
hold:
index `PRIMARY` of table `pay_fgateway`.`tbl_loan_provide_info` trx id 62679813593 lock_mode X locks rec but not gap
Record lock
wait:
index `uniq_sys_provide_id` of table `pay_fgateway`.`tbl_loan_provide_info` trx id 62679813593 lock_mode X locks rec but not gap waiting

update tbl_loan_provide_info
         SET user_id = '123',


                sys_id = '123',


                serv_id = 'abc',


                loan_provide_id = '123123',


                gw_loan_provide_id = '123123',


                serv_loan_provide_id = '123123',


                serv_loan_provide_return_id = '123123',


                loan_verify_id = '123123',


                loan_type = 1,


                finish_date = '2019-06-19 11:28:10',


                loan_amount = 1111,

    可以理解该日志大体的意思，A线程使用sys_id + loan_provide_id对该条记录加了排它锁并且等待该条记录的主键释放锁，B线程持有该条记录的主键锁等待释放该条记录的唯一键锁，接着我们区代码中看些处理该记录的逻辑

同步请求的处理逻辑

//使用 sysId 和 loanProvideId 对该条记录进行加锁        
TblLoanProvideInfo dbTblLoanProvideInfo = provideInfoServiceProxy.queryBySysIdAndLoanProvideIdForUpdate(bankProvideRespVo.getSysId(), bankProvideRespVo.getLoanProvideId());

//中间赋值操作

//使用 sysId + loanProvideId 更新数据库
provideInfoServiceProxy.updateByLoanProvideId(dbTblLoanProvideInfo);

对合作方通知的处理逻辑

//使用 servId + servLoanProvideId 唯一键锁该条记录        
TblLoanProvideInfo tblLoanProvideInfo = provideInfoServiceProxy.queryByServIdAndServLoanProvideIdForUpdate(loanTransNoticeBo.getServId(), loanTransNoticeBo.getServLoanProvideId());

//中间操作

//使用唯一键 sysId + loanProvideId 更新记录
provideInfoServiceProxy.updateByLoanProvideId(tblLoanProvideInfo)

    其实这时候可以大致看出死锁的原因了：通知线程使用唯一键servId + servLoanProvideId 对该记录的唯一键加锁，之后对主键加锁，该记录锁定成功，之后同步线程尝试使用sysId + loanProvideId对该条记录进行加锁，先对唯一键进行加锁，加锁成功，但是对主键加锁的时候发现主键已经被锁定，于是便等待通知线程释放主键锁，此时通知线程做完一系列操作之后准备使用sysId + loanProvideId更新记录的时候发现该唯一键已经被锁定，于是进入等待状态，最终发生死锁。同步操作事务回滚，通知操作更新成功。

通知线程	同步线程
拿到 servId + servLoanProvideId 锁
拿到主键锁
	拿到 sysId + loanProvideId 锁
	等待主键锁
使用 sysId + loanProvideId 更新记录
等待 sysId + loanProvideId 锁

 

结论

1、排查线上死锁过程的时候要明确死锁发生的条件

2、更新时尽量使用主键更新

 

如有不足之处请指正，转载请注明出处，谢谢