我一个INSERT 还能被你 UPDATE 给卡住?
共 5968字,需浏览 12分钟
·
2022-05-30 13:33
许多语言和工具都通过锁,来保证并发场景下数据和逻辑的正确性,MySQL 也不例外。除了行锁、表锁这种范围粒度外,还有这种针对读和写的 S锁共享锁 和 X锁独占锁。
随着锁定范围的不同,锁与锁之间的互相影响也差异很大,这一点很好理解。比如一个操作加了表锁之后,另一个想加行锁就得等待;而一个行锁一般并不会影响锁另一行的行锁。
除了书本上和八股文,你有没有遇到过这些锁相关的问题呢?
我先来说一个最近遇到的。
现象
某天,项目出现几条监控报警,都是在写库的时候获取锁超时导致。业务会在某种特定的场景下,出现如下的 MySQL 获取锁超时,事务回滚的异常。
org.springframework.dao.CannotAcquireLockException:
### Error updating database.
Cause: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: xxx
Lock wait timeout exceeded; try restarting transaction
看了下错误对应的日志,发现当时 MySQL 要执行一条 INSERT 操作,等了50秒超时事务回滚了。同样的代码时好时坏,那就一定和触发条件有关系了。
对应正在执行的是一个 INSERT 的操作
2022-xx-xx 15:x:x.380 [elapse:50674] [sql:INSERT INTO xxx_table ....]
按照前面的固有思路,即将执行 INSERT 的一行数据,理论上和别人没什么的冲突,为啥会拿不到锁呢?
在代码逻辑里也不能明确定位问题,只能求助 DBA 帮忙 dump 事务日志相关信息。
但内容里也没有死锁信息,事务日志里也仅有 Transaction 在等待锁的信息,像这个样子,大概看了一眼,不像死锁日志里有一个 Hold Locks 信息,这种普通的情况,具体锁在谁手里,还是两眼一抹眼。
------------------
---TRANSACTION 13934594, ACTIVE 41 sec inserting
mysql tables in use 1, locked 1
LOCK WAIT 2 lock struct(s), heap size 360, 1 row lock(s), undo log entries 1
MySQL thread id 6695850, OS thread handle 0x7ef74b2c0700, query id 123 xxx abc update
INSERT INTO xxx_table(col,col1,...)
------- TRX HAS BEEN WAITING 41 SEC FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 1057 page no 3724 n bits 312 index `xxx_id_idx` of table `test`.`xxx_table` trx id 13934594 lock_mode X locks gap before rec insert intention waiting
Record lock, heap no 241 PHYSICAL RECORD: n_fields 5; compact format; info bits 0
0: len 8; hex 800000008d8faf7d; asc };;
1: len 5; hex ....123; asc 12_34;;
2: len 17; hex 111111111111113732333338; asc 111111111111111272338;;
3: len 1; hex 80; asc ;;
4: len 8; hex 8000000000012adf; asc * ;;
------------------
没有其它办法,只好回过来仔细看事务日志。仔细看这里的 WAITING xx FOR THIS LOCK 下面,会提到这个等待锁的类型
RECORD LOCKS index `xxx_id_idx` of table `test`.`xxx_table` lock_mode X locks gap before rec insert intention waiting
期中提到了lock_mode X locks gap before rec insert intention waiting
是 GAP 锁,那这个间隙有多大?
再向后看,提到了索引。是因为表里的这个索引,而后面的 Recod Lock 刚好就是这个索引对应的各个字段,那对应到索引的定义,发现里面有一个字段刚好是某个业务属性的 id。
之前对事务日志不熟悉,这算一个比较重要的发现,根据这个 id 继续去查库时,发现这条记录是在前一刻刚刚写到库里。
一个刚写到库里的字段,和新的要 INSERT 的数据有什么关联呢?
此时仔细回想了一下业务逻辑,想起我们有一个异步的操作,会在数据执行之后,在某些条件下,去做更新这条记录的操作。因为这个更新操作涉及到更新多个表,还加了个事务。只是因为不是用户请求,不曾放在一起统一看过。
而我们前面的 INSERT 这个,也是在一个事务里,先执行 INSERT 再执行一个 UPDATE 的操作,可以这样理解:
会话 1先执行:
BEGIN;
1. UPDATE xxx_table SET update_time='xxx' WHERE id = '123' ;
3.再执行一个其他操作
会话2 执行:
BEGIN;
2.INSERT INTO `xxx_table` (col1,col2)...
4.再执行一个操作
此时,我们看到两个因为锁的交叉使用,导致谁都没法完成,最终直到超时。
为什么?
那为什么一个 INSERT 会受到前面不相关的 UPDATE 操作的影响呢?
这就不得不提 MySQL 里的间隙锁 (GAP Lock)。业务里的 id,就是在索引 里使用到的那个,是通过某个服务生成的。而已经写入到库里的那条,id 要比我们新 INSERT 的这条,要大。GAP Lock 刚好锁定的是新写的 id 到成功写入的这条 ID。而这个写入成功的 ID,在前面正在被 UPDATE,所以两个操作就冲突了。
在线下模拟的话,可以通过 MySQL 自带的几个表,来查看锁的占用信息,可以清晰的看出来,两个操作的 lock data 是同一个数据,不冲突才怪呢。
mysql> SELECT * FROM `information_schema`.INNODB_LOCKS\G;
*************************** 1. row ***************************
lock_id: 225753412:5845:5:253
lock_trx_id: 225753412
lock_mode: X,GAP
lock_type: RECORD
lock_table: `db`.`xxx_table`
lock_index: xxx_id_idx
lock_space: 5845
lock_page: 5
lock_rec: 253
lock_data: 3094360230, 'abc-01', '111623639', 0, 255
*************************** 2. row ***************************
lock_id: 225751488:5845:5:253
lock_trx_id: 225751488
lock_mode: X
lock_type: RECORD
lock_table: `db`.`xxx_table`
lock_index: xxx_id_idx
lock_space: 5845
lock_page: 5
lock_rec: 253
lock_data: 3094360230, 'abc-01', '111623639', 0, 255
2 rows in set (0.04 sec)
mysql> select * from `information_schema`.INNODB_LOCK_WAITS\G;
*************************** 1. row ***************************
requesting_trx_id: 225753412 // 申请资源的事务 ID
requested_lock_id: 225753412:5845:5:253
blocking_trx_id: 225751488 // 阻塞的事务 ID
blocking_lock_id: 225751488:5845:5:253
1 row in set (0.04 sec)
mysql> select * from `information_schema`.INNODB_TRX\G;
*************************** 1. row ***************************
trx_id: 225751488
trx_state: LOCK WAIT
trx_started: 2022-0xxx
trx_requested_lock_id: 225851026:5874:4:1
trx_wait_started: 2022-05-2xxx
trx_weight: 3
trx_mysql_thread_id: 1875826
trx_query: insert into xxx_table values(...)
trx_operation_state: inserting
trx_tables_in_use: 1
trx_tables_locked: 1
trx_lock_structs: 2
trx_lock_memory_bytes: 360
trx_rows_locked: 1
trx_rows_modified: 1
trx_concurrency_tickets: 0
trx_isolation_level: REPEATABLE READ
trx_unique_checks: 1
trx_foreign_key_checks: 1
trx_last_foreign_key_error: NULL
trx_adaptive_hash_latched: 0
trx_adaptive_hash_timeout: 10000
trx_is_read_only: 0
trx_autocommit_non_locking: 0
*************************** 2. row ***************************
trx_id: 225753412
trx_state: RUNNING
trx_started: 2022-0xxx
trx_requested_lock_id: NULL
trx_wait_started: NULL
trx_weight: 4
trx_mysql_thread_id: 1875454
trx_query: NULL
trx_operation_state: NULL
trx_tables_in_use: 0
trx_tables_locked: 0
trx_lock_structs: 3
trx_lock_memory_bytes: 360
trx_rows_locked: 3
trx_rows_modified: 1
trx_concurrency_tickets: 0
trx_isolation_level: REPEATABLE READ
trx_unique_checks: 1
trx_foreign_key_checks: 1
trx_last_foreign_key_error: NULL
trx_adaptive_hash_latched: 0
trx_adaptive_hash_timeout: 10000
trx_is_read_only: 0
trx_autocommit_non_locking: 0
2 rows in set (0.03 sec)
有些时候,我们主观上认为的一个 INSERT ,在新写入数据,理论上除了表锁和别人没啥冲突,毕竟还没写,也没人能更新它。不过这些细节上,间隙锁,Next Key Lock 等等,还是会影响到具体的执行。如果你也遇到类似的情况,有权限的时候,可以通过上面 MySQL `information_schema`.INNODB_自带的
三个表,发现锁的冲突信息。如果没有权限,可以先想办法拿到事务日志,再进一步分析。
事务日志,可以通过 SHOW ENGINE INNODB STATUS 拿到,给迷茫的分析加一点思路。
你有遇过到什么排查问题中的「峰回路转」吗?欢迎分享。
相关阅读
免安装,还原生产环境,运行中切换版本,这不是我认识的MySQL