1 事务不设置超时时间,长时间不提交。
@Override
@Transactional
public void addUser06(){
User user=new User();
user.setName("测试"+1);
user.setPassword("123");
userDao.insertSelective(user);
try {
Thread.sleep(1000*60*10);
} catch (InterruptedException e) {
e.printStackTrace();
}
}
executorService.submit(new Runnable() {
@Override
public void run() {
userService.addUser06();
}
});
executorService.shutdown();
while(true){
if(executorService.isTerminated()){
break;
}
}
logger.info("执行完成");
总结:事务长时间不提交,不会超时,就算设置timeout的值也无用,参考:
https://blog.csdn.net/qq_18860653/article/details/79907984
https://blog.csdn.net/educast/article/details/78824028
2 Lock wait timeout exceeded; try restarting transaction
代码模拟事锁等待超时
先将MySQL锁等待的时间改为10秒,方便测试
查看锁等待超时的时间
SHOW GLOBAL VARIABLES LIKE 'innodb_lock_wait_timeout';
设置锁等待超时时间为10秒
SET GLOBAL innodb_lock_wait_timeout=10;
代码:
//创建固定线程数为6的线程池
ExecutorService executorService = Executors.newFixedThreadPool(6);
/**
* 锁获取超时
*/
@Test
public void testAddUser06(){
executorService.execute(new Runnable() {
@Override
public void run() {
userService.addUser06(20);
}
});
try {
Thread.sleep(2000);
} catch (InterruptedException e) {
e.printStackTrace();
}
executorService.execute(new Runnable() {
@Override
public void run() {
userService.addUser06(0);
}
});
executorService.shutdown();
while(true){
if(executorService.isTerminated()){
break;
}
}
logger.info("执行完成");
}
Service实现类
@Override
@Transactional()
public void addUser06(int sleepTime){
User updateUser=new User();
updateUser.setId(413);
updateUser.setPassword("1");
logger.info("线程【{}】",Thread.currentThread().getName());
userDao.updateByPrimaryKeySelective(updateUser);
try {
Thread.sleep(sleepTime*1000);
} catch (InterruptedException e) {
e.printStackTrace();
}
}
通过如下sql得到当前没提交的sql
select sql_text from performance_schema.events_statements_current
where sql_text like "%update%" and sql_text not like "%select%"
然后查询锁竞争逻辑即可。
参考文章:
https://www.cnblogs.com/xiluhua/p/9063660.html
https://blog.csdn.net/wanderlustLee/article/details/79235005
https://blog.csdn.net/java__project/article/details/100137526
https://cloud.tencent.com/developer/article/1607249
3 死锁
1)事务操作锁定的行数较少(更精确的索引条件)。
2)保证事务较短的执行时间,完成后马上提交。
3)加锁的顺序要统一。
场景一:等待相互占用的锁,案例中第一个事务update锁住了id为1的记录,而事务二锁住了id为2 的记录,后续都需要获取对方占用的排他锁,最终导致死锁。
测试,需要开启mybatis的日志:
#日志配置
logging.level.root=DEBUG
logging.level.org.springframework=DEBUG
logging.level.org.org.mybatis=DEBUG
public static ExecutorService executorService = Executors.newFixedThreadPool(6);
@Autowired
private UserService userService;
@Test
public void deadLockTest(){
executorService.submit(new Runnable() {
@Override
public void run() {
userService.lockUserInfo(1,2);
}
});
executorService.submit(new Runnable() {
@Override
public void run() {
userService.lockUserInfo(2,1);
}
});
executorService.shutdown();
while(true) {
if(executorService.isTerminated()) {
logger.info("===========run over================");
break;
}
}
}
接口实现类:
@Transactional
@Override
public void lockUserInfo(int firstUserId, int secondUserId) {
logger.info("开始锁住id为【{}】",firstUserId);
User firstUser=new User();
firstUser.setId(firstUserId);
firstUser.setName("id"+firstUserId);
userDao.updateByPrimaryKey(firstUser);
//开始睡眠
logger.info("===========开始中途睡眠已经锁住id【{}】==============",firstUserId);
try {
Thread.sleep(2000);
} catch (InterruptedException e) {
e.printStackTrace();
}
logger.info("开始锁住id为【{}】",secondUserId);
User secondUser=new User();
secondUser.setId(secondUserId);
secondUser.setName("id"+secondUserId);
userDao.updateByPrimaryKey(secondUser);
logger.info("====================延迟提交事务=================");
try {
Thread.sleep(5000);
} catch (InterruptedException e) {
e.printStackTrace();
}
}
异常栈信息:
03-24 15:16:23.934 INFO 12868 --- [pool-1-thread-1] o.s.jdbc.support.SQLErrorCodesFactory : SQLErrorCodes loaded: [DB2, Derby, H2, HSQL, Informix, MS-SQL, MySQL, Oracle, PostgreSQL, Sybase, Hana]
2019-03-24 15:16:23.934 DEBUG 12868 --- [pool-1-thread-1] o.s.jdbc.support.SQLErrorCodesFactory : Looking up default SQLErrorCodes for DataSource [org.apache.tomcat.jdbc.pool.DataSource@a897587]
2019-03-24 15:16:23.938 DEBUG 12868 --- [pool-1-thread-1] o.s.jdbc.support.SQLErrorCodesFactory : SQL error codes for 'MySQL' found
2019-03-24 15:16:23.938 DEBUG 12868 --- [pool-1-thread-1] o.s.jdbc.support.SQLErrorCodesFactory : Caching SQL error codes for DataSource [org.apache.tomcat.jdbc.pool.DataSource@a897587]: database product name is 'MySQL'
2019-03-24 15:16:23.938 DEBUG 12868 --- [pool-1-thread-1] s.j.s.SQLErrorCodeSQLExceptionTranslator : Translating SQLException with SQL state '40001', error code '1213', message [Deadlock found when trying to get lock; try restarting transaction]; SQL was [] for task [
### Error updating database. Cause: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction
### The error may involve com.test.dao.UserDao.updateByPrimaryKey-Inline
### The error occurred while setting parameters
### SQL: update user set `name` = ?, `password` = ? where id = ?
### Cause: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction
]
参考文章:
https://www.cnblogs.com/zejin2008/p/5262751.html
发生死锁后Innodb会检测到死锁,会使一方事务回滚放弃锁,另外一方继续执行。
查看最后一次发生死锁的日志
show engine innodb status
=====================================
2021-09-22 17:48:50 0x7f96ac09a700 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 44 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 62 srv_active, 0 srv_shutdown, 12853 srv_idle
srv_master_thread log flush and writes: 12915
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 71
OS WAIT ARRAY INFO: signal count 71
RW-shared spins 0, rounds 142, OS waits 71
RW-excl spins 0, rounds 0, OS waits 0
RW-sx spins 0, rounds 0, OS waits 0
Spin rounds per wait: 142.00 RW-shared, 0.00 RW-excl, 0.00 RW-sx
------------------------
LATEST DETECTED DEADLOCK
------------------------
2021-09-22 17:48:36 0x7f96a40db700
*** (1) TRANSACTION:
TRANSACTION 120630, ACTIVE 22 sec starting index read
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 4, OS thread handle 140284974454528, query id 383 192.168.209.1 root updating
update a set count=count+3 where id=2
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 787 page no 3 n bits 72 index PRIMARY of table `lock`.`a` trx id 120630 lock_mode X locks rec but not gap waiting
Record lock, heap no 3 PHYSICAL RECORD: n_fields 6; compact format; info bits 0
0: len 4; hex 80000002; asc ;;
1: len 6; hex 00000001d737; asc 7;;
2: len 7; hex 210000c0072dbb; asc ! - ;;
3: len 4; hex 80000002; asc ;;
4: len 5; hex 99aaacde33; asc 3;;
5: len 5; hex 99aaad1c14; asc ;;
*** (2) TRANSACTION:
TRANSACTION 120631, ACTIVE 16 sec starting index read
mysql tables in use 1, locked 1
3 lock struct(s), heap size 1136, 2 row lock(s), undo log entries 1
MySQL thread id 5, OS thread handle 140284974184192, query id 384 192.168.209.1 root updating
update a set count=count+4 where id=1
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 787 page no 3 n bits 72 index PRIMARY of table `lock`.`a` trx id 120631 lock_mode X locks rec but not gap
Record lock, heap no 3 PHYSICAL RECORD: n_fields 6; compact format; info bits 0
0: len 4; hex 80000002; asc ;;
1: len 6; hex 00000001d737; asc 7;;
2: len 7; hex 210000c0072dbb; asc ! - ;;
3: len 4; hex 80000002; asc ;;
4: len 5; hex 99aaacde33; asc 3;;
5: len 5; hex 99aaad1c14; asc ;;
*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 787 page no 3 n bits 72 index PRIMARY of table `lock`.`a` trx id 120631 lock_mode X locks rec but not gap waiting
Record lock, heap no 2 PHYSICAL RECORD: n_fields 6; compact format; info bits 0
0: len 4; hex 80000001; asc ;;
1: len 6; hex 00000001d736; asc 6;;
2: len 7; hex 400000401502f4; asc @ @ ;;
3: len 4; hex 80000001; asc ;;
4: len 5; hex 99aaacde23; asc #;;
5: len 5; hex 99aaad1c0e; asc ;;
*** WE ROLL BACK TRANSACTION (2)
------------
TRANSACTIONS
------------
Trx id counter 120633
Purge done for trx's n:o < 120633 undo n:o < 0 state: running but idle
History list length 2
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 421760376654112, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421760376652288, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421760376650464, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421760376649552, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 120630, ACTIVE 36 sec
3 lock struct(s), heap size 1136, 2 row lock(s), undo log entries 2
MySQL thread id 4, OS thread handle 140284974454528, query id 383 192.168.209.1 root
--------
FILE I/O
--------
I/O thread 0 state: waiting for completed aio requests (insert buffer thread)
I/O thread 1 state: waiting for completed aio requests (log thread)
I/O thread 2 state: waiting for completed aio requests (read thread)
I/O thread 3 state: waiting for completed aio requests (read thread)
I/O thread 4 state: waiting for completed aio requests (read thread)
I/O thread 5 state: waiting for completed aio requests (read thread)
I/O thread 6 state: waiting for completed aio requests (write thread)
I/O thread 7 state: waiting for completed aio requests (write thread)
I/O thread 8 state: waiting for completed aio requests (write thread)
I/O thread 9 state: waiting for completed aio requests (write thread)
Pending normal aio reads: [0, 0, 0, 0] , aio writes: [0, 0, 0, 0] ,
ibuf aio reads:, log i/o's:, sync i/o's:
Pending flushes (fsync) log: 0; buffer pool: 0
392 OS file reads, 509 OS file writes, 294 OS fsyncs
0.00 reads/s, 0 avg bytes/read, 0.73 writes/s, 0.61 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 2586, seg size 2588, 0 merges
merged operations:
insert 0, delete mark 0, delete 0
discarded operations:
insert 0, delete mark 0, delete 0
Hash table size 34673, node heap has 0 buffer(s)
Hash table size 34673, node heap has 0 buffer(s)
Hash table size 34673, node heap has 0 buffer(s)
Hash table size 34673, node heap has 0 buffer(s)
Hash table size 34673, node heap has 0 buffer(s)
Hash table size 34673, node heap has 0 buffer(s)
Hash table size 34673, node heap has 0 buffer(s)
Hash table size 34673, node heap has 0 buffer(s)
0.00 hash searches/s, 0.11 non-hash searches/s
---
LOG
---
Log sequence number 53042390379
Log flushed up to 53042390379
Pages flushed up to 53042390379
Last checkpoint at 53042390370
0 pending log flushes, 0 pending chkp writes
192 log i/o's done, 0.42 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total large memory allocated 137428992
Dictionary memory allocated 111548
Buffer pool size 8191
Free buffers 7794
Database pages 397
Old database pages 0
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 362, created 35, written 272
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 397, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
0 read views open inside InnoDB
Process ID=57091, Main thread ID=140285031999232, state: sleeping
Number of rows inserted 132, updated 32, deleted 0, read 262
0.00 inserts/s, 0.07 updates/s, 0.00 deletes/s, 0.07 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================
显示第一个事务等待的锁,第二个事务获取到的锁,需要等待的锁,日志显示回滚了第二个事务。
参考:
https://blog.csdn.net/alviss_kdd/article/details/83376894
https://blog.csdn.net/loophome/article/details/79867174