理解MySQL间隙锁与死锁：Ranger创建策略失败问题分析及解决方案-优快云博客

【问题现象】

上周，测试环境偶现创建策略失败，查看ranger的日志发现有如下的错误信息：

2022-03-21 20:14:29,685 [http-bio-6080-exec-13] ERROR org.apache.ranger.rest.ServiceREST (ServiceREST.java:1709) - createPolicy(RangerPolicy={id={null} guid={null} isEnabled={true} createdBy={null} updatedBy={null} createTime={null} updateTime={null} version={1} service={default-Hive} name={dcp-desensitize_a162c40cdc0140b1848b98415575be6c-1647864869626} policyType={0} policyPriority={0} description={} resourceSignature={4f15e3de95c81650ad869cb93a8c47a132bbec54bdf5de8c01f5075c19754cd7} isAuditEnabled={true} serviceType={null} resources={database={RangerPolicyResource={values={dcp } isExcludes={false} isRecursive={false} }} column={RangerPolicyResource={values={* } isExcludes={false} isRecursive={false} }} table={RangerPolicyResource={values={desensitize_a162c40cdc0140b1848b98415575be6c } isExcludes={false} isRecursive={false} }} } policyLabels={Consoler } policyConditions={} policyItems={RangerPolicyItem={accessTypes={RangerPolicyItemAccess={type={all} isAllowed={true} }} users={tangbiao2 } groups={} roles={} conditions={} delegateAdmin={false} }} denyPolicyItems={} allowExceptions={} denyExceptions={} dataMaskPolicyItems={} rowFilterPolicyItems={} options={} validitySchedules={, zoneName=null, isDenyAllElse={false} }}) failed
javax.persistence.PersistenceException: Exception [EclipseLink-4002] (Eclipse Persistence Services - 2.5.2.v20140319-9ad6abd): org.eclipse.persistence.exceptions.DatabaseException
Internal Exception: com.mysql.cj.jdbc.exceptions.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction
Error Code: 1213
Call: INSERT INTO x_policy_ref_resource (ADDED_BY_ID, CREATE_TIME, policy_id, resource_def_id, resource_name, UPDATE_TIME, UPD_BY_ID) VALUES (?, ?, ?, ?, ?, ?, ?)
        bind => [7 parameters bound]
Query: ValueReadQuery(name="x_policy_ref_resource_SEQ" sql="SELECT LAST_INSERT_ID()")
        at org.eclipse.persistence.internal.jpa.EntityManagerImpl.flush(EntityManagerImpl.java:868)
        at sun.reflect.GeneratedMethodAccessor98.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at org.springframework.orm.jpa.SharedEntityManagerCreator$SharedEntityManagerInvocationHandler.invoke(SharedEntityManagerCreator.java:301)
        at com.sun.proxy.$Proxy30.flush(Unknown Source)
        at org.apache.ranger.common.db.BaseDao.batchCreate(BaseDao.java:102)
        ...

与测试人员一番沟通，找到了一个有用信息：有并发调用创建策略的接口。

然而光看ranger的日志，即便结合源码也没有什么特别的发现，所以打算从mysql的日志看看有什么发现，果不其然，在mysql的日志中，发现出现了"死锁"的日志，具体如下所示：

------------------------
LATEST DETECTED DEADLOCK
------------------------
2022-03-21 09:47:22 0x7ff3a4859700
*** (1) TRANSACTION:
TRANSACTION 7036760, ACTIVE 0 sec inserting
mysql tables in use 1, locked 1
LOCK WAIT 23 lock struct(s), heap size 1136, 12 row lock(s), undo log entries 2
MySQL thread id 27293, OS thread handle 140684415063808, query id 383930 192.168.0.76 DHCloudBG update
INSERT INTO x_policy_ref_resource (ADDED_BY_ID, CREATE_TIME, policy_id, resource_def_id, resource_name, UPDATE_TIME, UPD_BY_ID) VALUES (1, '2022-03-20 12:47:22.666', 13921, 5, 'database', '2022-03-20 12:47:22.681', 1)
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 531 page no 4 n bits 376 index x_policy_ref_res_UK_polId_resDefId of table `ranger`.`x_policy_ref_resource` trx id 7036760 lock_mode X insert intention waiting
Record lock, heap no 1 PHYSICAL RECORD: n_fields 1; compact format; info bits 0
 0: len 8; hex 73757072656d756d; asc supremum;;
*** (2) TRANSACTION:
TRANSACTION 7036759, ACTIVE 0 sec inserting
mysql tables in use 1, locked 1
23 lock struct(s), heap size 1136, 12 row lock(s), undo log entries 2
MySQL thread id 27295, OS thread handle 140684413998848, query id 383932 192.168.0.76 DHCloudBG update
INSERT INTO x_policy_ref_resource (ADDED_BY_ID, CREATE_TIME, policy_id, resource_def_id, resource_name, UPDATE_TIME, UPD_BY_ID) VALUES (1, '2022-03-20 12:47:22.666', 13920, 5, 'database', '2022-03-20 12:47:22.682', 1)
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 531 page no 4 n bits 376 index x_policy_ref_res_UK_polId_resDefId of table `ranger`.`x_policy_ref_resource` trx id 7036759 lock_mode X
Record lock, heap no 1 PHYSICAL RECORD: n_fields 1; compact format; info bits 0
 0: len 8; hex 73757072656d756d; asc supremum;;
*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 531 page no 4 n bits 376 index x_policy_ref_res_UK_polId_resDefId of table `ranger`.`x_policy_ref_resource` trx id 7036759 lock_mode X insert intention waiting
Record lock, heap no 1 PHYSICAL RECORD: n_fields 1; compact format; info bits 0
 0: len 8; hex 73757072656d756d; asc supremum;;*** WE ROLL BACK TRANSACTION (2)

【问题分析】

为什么会产生死锁，怎样才会出现死锁，结果会怎样？要回答这些问题，还得先来了解下mysql的锁机制。

mysql的innodb有4个隔离级别：

隔离级别	脏读	不可重复读	幻读
未提交读(read-uncommitted)	有	有	有
已提交读(read-committed)	无	有	有
可重复读(repeatable-read)	无	无	有
可串行化(serializable)	无	无	无

实际使用中，一般很少使用未提交读和可串行读，采用最多的则是read-committed（通常也是其他数据库的默认选择）。

然而因为一些历史遗留问题，mysql在5.1.5版本前，binlog的格式只能为statement，在这种格式下若不选择可重复读隔离级别，则主从数据可能会出现不一致的问题。而在5.1.5版本之后，binlog有3种格式可选：statement，row和mixed。

在我们的实际环境中，binlog的格式为mixed，即statement和row格式的混合，目的是为了在保证主从数据一致的前提下精简binlog。隔离级别则是可重复读。

在可重复读隔离级别中存在一个间隙锁，这个正是问题存在的根本原因。

先举例说明下什么是间隙锁，以及间隙锁的效果是怎样的。

仿照ranger的数据库表设计，建立如下表

CREATE TABLE `hncscwc` (
`id` int AUTO_INCREMENT,
`a` int,
`b` int,
`c` int,
PRIMARY KEY (`id`),
UNIQUE KEY `ux_a_b` (`a`, `b`)
) ENGINE=InnoDB;

然后插入如下数据：

mysql> select * from hncscwc;
+----+----+-----+-----+
| id | a  | b   | c   |
+----+----+-----+-----+
|  1 |  1 |  10 | 100 |
|  2 |  3 |  20 |  99 |
|  3 |  5 |  50 |  80 |
+----+----+-----+-----+

然后依次执行如下两个事务（注意执行时序）

其中事务1和事务2的delete语句均会成功；事务1在执行insert语句时会被阻塞，而事务2再次执行insert语句时，会出现报错（ERROR 1213: Deadlock found when trying to get lock;），此后事务2出现回滚，再然后原本事务1中阻塞的insert语句则可以往下成功执行。

如果数据库的隔离级别为可重复读级别，并且delete的where子句的字段不是主键或唯一索引，则delete加锁的类型为间隙锁：数据库会向左扫描扫到第一个比给定参数小的值，向右扫描到第一个比给定参数大的值，然后以此为界（包含这两个值）构成一个区间，并对该区间加锁，这个就是间隙锁。

间隙锁之间是兼容的，所以上面的两个事务执行delete时都能持有间隙锁。

此后，事务1进行insert时，其加锁过程是先在插入的间隙上获取插入意向锁，插入数据后再获取插入行上的排他锁。但是在获取意向锁时与事务2持有的间隙锁冲突，导致阻塞进入等待状态。

同样，事务2在进行insert时也因为获取意向锁与事务1持有的间隙锁冲突，进而陷入循环等待的死锁状态。

【问题解决】

了解了间隙锁后，再来看ranger中的这个问题，两次并发的创建策略的事务过程中，会先对其中一个表的数据进行删除，然后再真正插入数据，两个事务在执行时序上穿插进行导致出现了死锁问题。

原因彻底了解后，剩下的自然就是怎样在改动最小的情况下修复问题了。

这里可行的方案包括：

修改调整数据库的隔离级别
对创建策略过程中的删除与插入不放在一个事务中执行
创建策略不进行删除动作
创建策略的删除动作时，先根据记录查主键，如果存在则按主键进行删除，规避间隙锁的问题。

经过各方面的权衡，最终选择了最后一个方案，因为其他方案要么不能彻底解决问题，要么会引发其他问题。此外还对对相关类似的地方一并进行了修改，详见

https://issues.apache.org/jira/browse/RANGER-3681?jql=project%20%3D%20RANGER

【总结】

通过ranger创建策略失败的偶现问题，了解了msyql中间隙锁的机制，最后并合理运用对其进行了规避处理。

好了，这就是本文的全部内容，如果觉得本文对你有帮助，三（拒）连（绝）走（白）起（嫖），也欢迎加我微信交流～

问题不难，但藏得有点深