码迷，mamicode.com
首页 > 其他好文 > 详细

deadlock-found-when-trying-to-get-lock

时间：2019-10-17 12:05:34      阅读：121      评论：0      收藏：0      [点我收藏+]

标签：bytecode   自动提交   simple   head   intern   factor   iis   win   ioc   

mysql锁机制分为表级锁和行级锁：

共享锁又称为读锁，简称S锁，顾名思义，共享锁就是多个事务对于同一数据可以共享一把锁，都能访问到数据，但是只能读不能修改。

排他锁又称为写锁，简称X锁，顾名思义，排他锁就是不能与其他所并存，如一个事务获取了一个数据行的排他锁，其他事务就不能再获取该行的其他锁，包括共享锁和排他锁，但是获取排他锁的事务是可以对数据就行读取和修改。

对于共享锁大家可能很好理解，就是多个事务只能读数据不能改数据，对于排他锁大家的理解可能就有些差别，我当初就犯了一个错误，以为排他锁锁住一行数据后，其他事务就不能读取和修改该行数据，其实不是这样的。排他锁指的是一个事务在一行数据加上排他锁后，其他事务不能再在其上加其他的锁。mysql InnoDB引擎默认的修改数据语句，update,delete,insert都会自动给涉及到的数据加上排他锁，select语句默认不会加任何锁类型，如果加排他锁可以使用select …for update语句，加共享锁可以使用select … lock in share mode语句。所以加过排他锁的数据行在其他事务种是不能修改数据的，也不能通过for update和lock in share mode锁的方式查询数据，但可以直接通过select …from…查询数据，因为普通查询没有任何锁机制。

技术图片

案发现场

API网关在30ms内收到6次相同请求，错误日志：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
Jul 23 17:12:50 iZ23qpg65e4Z api_qianqian1 2017-07-23 17:12:50.754 [http-apr-8080-exec-1379] INFO  h.a.a.f.AppPlatformRateLimiterFilter - parameter=_appCrypt_=VDzT76Hdrp9QAO4lSbQuJeIaKnQ8VZnqljK+YmN2W1tyBSv1JqIhTrDHrBlWM9K8yg3kcLOUmENr1OUc+6xWSL13Z2jaBhCJDrMYWad/H971ilDd4eQMrakZP84dCbXC&_t_=HBStockWarningIos_3.6.4&ticket=7.BdzpPOeP2_7JV6IYArPBIOC36NO2PoCMhVPHiISIEM_tAo7-unTlp_baBhZ79TZskD-HBIBmSnk-7y_tv24wD2IiSgTHlj7x5DTHEV7CacwVdw9jmTCuVdePd4mUaM11k5XGRSsPzqzQmomKMu7aGm8R48Nq-ECE7WpSNtQmExU&
Jul 23 17:12:50 iZ23qpg65e4Z api_qianqian1 2017-07-23 17:12:50.756 [http-apr-8080-exec-1379] INFO  sky.app.api.filter.RateLimiter - userId:3245964, 在 5s 内第1次 执行操作 http:
Jul 23 17:12:50 iZ23qpg65e4Z api_qianqian1 2017-07-23 17:12:50.756 [http-apr-8080-exec-1319] INFO  sky.app.api.filter.RateLimiter - userId:3245964, 在 5s 内第2次 执行操作 http:
Jul 23 17:12:50 iZ23qpg65e4Z api_qianqian1 2017-07-23 17:12:50.757 [http-apr-8080-exec-1319] DEBUG h.p.commons.web.HbecApiHandleAdapter - param-sha1 : null, appCrypt<1> : VDzT76Hdrp9QAO4lSbQuJeIaKnQ8VZnqljK+YmN2W1tyBSv1JqIhTrDHrBlWM9K8yg3kcLOUmENr1OUc+6xWSL13Z2jaBhCJDrMYWad/H971ilDd4eQMrakZP84dCbXC, dataKey=l7g19q1$g#*o9v-1
Jul 23 17:12:50 iZ23qpg65e4Z api_qianqian1 2017-07-23 17:12:50.755 [http-apr-8080-exec-1414] INFO  h.a.a.f.AppPlatformRateLimiterFilter - http request=http://api.*.com/followStockService.follow
Jul 23 17:12:50 iZ23qpg65e4Z api_qianqian1 2017-07-23 17:12:50.755 [http-apr-8080-exec-1414] INFO  h.a.a.f.AppPlatformRateLimiterFilter - 
Jul 23 17:12:50 iZ23qpg65e4Z api_qianqian1 2017-07-23 17:12:50.757 [http-apr-8080-exec-1414] INFO  sky.app.api.filter.RateLimiter - userId:3245964, 在 5s 内第3次 执行操作 http:
Jul 23 17:12:50 iZ23qpg65e4Z api_qianqian1 2017-07-23 17:12:50.756 [http-apr-8080-exec-1457] INFO  h.a.a.f.AppPlatformRateLimiterFilter - http request=http://api.*.com/followStockService.follow
Jul 23 17:12:50 iZ23qpg65e4Z api_qianqian1 2017-07-23 17:12:50.756 [http-apr-8080-exec-1457] INFO  h.a.a.f.AppPlatformRateLimiterFilter - 
Jul 23 17:12:50 iZ23qpg65e4Z api_qianqian1 2017-07-23 17:12:50.757 [http-apr-8080-exec-1457] INFO  sky.app.api.filter.RateLimiter - userId:3245964, 在 5s 内第4次 执行操作 http:
Jul 23 17:12:50 iZ23qpg65e4Z api_qianqian1 2017-07-23 17:12:50.757 [http-apr-8080-exec-1334] INFO  h.a.a.f.AppPlatformRateLimiterFilter - http request=http://api.*.com/followStockService.follow
Jul 23 17:12:50 iZ23qpg65e4Z api_qianqian1 2017-07-23 17:12:50.757 [http-apr-8080-exec-1334] INFO  h.a.a.f.AppPlatformRateLimiterFilter - parameter=_appCrypt_=VDzT76Hdrp9QAO4lSbQuJeIaKnQ8VZnqljK+YmN2W1tyBSv1JqIhTrDHrBlWM9K8yg3kcLOUmENr1OUc+6xWSL13Z2jaBhCJDrMYWad/H971ilDd4eQMrakZP84dCbXC&_t_=HBStockWarningIos_3.6.4&ticket=7.BdzpPOeP2_7JV6IYArPBIOC36NO2PoCMhVPHiISIEM_tAo7-unTlp_baBhZ79TZskD-HBIBmSnk-7y_tv24wD2IiSgTHlj7x5DTHEV7CacwVdw9jmTCuVdePd4mUaM11k5XGRSsPzqzQmomKMu7aGm8R48Nq-ECE7WpSNtQmExU&
Jul 23 17:12:50 iZ23qpg65e4Z api_qianqian1 2017-07-23 17:12:50.759 [http-apr-8080-exec-1334] INFO  sky.app.api.filter.RateLimiter - userId:3245964, 在 5s 内第5次 执行操作 http:

业务日志

追踪到业务节点后，发现mysql出现死锁问题：Deadlock found when trying to get lock; try restarting transaction

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
Jul 23 17:12:50 iZ2360o6lpyZ warn1 17-07-23 17:12:50.779 ERROR[DubboServerHandler-10.253.17.105:20880-thread-193 DbService.execute:1247] {}
Jul 23 17:12:50 iZ2360o6lpyZ warn1 sky.platform.commons.exceptions.HbecDbServiceException: service=db,message=sky.platform.commons.exceptions.HbecDbServiceException: service=db,message=
Jul 23 17:12:50 iZ2360o6lpyZ warn1 ### Error updating database.  Cause: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction
Jul 23 17:12:50 iZ2360o6lpyZ warn1 ### The error may involve WarnFollowMapper.follow-Inline
Jul 23 17:12:50 iZ2360o6lpyZ warn1 ### The error occurred while setting parameters
Jul 23 17:12:50 iZ2360o6lpyZ warn1 ### SQL: insert into test_follow (user_id, security_type, stock_code, exchange, stock_name, sub_fund_type, sort)         values (?, ?,  ?,                 ?,?, ?,                 (select max(IFNULL(t1.sort,0)) + 1 from test_FOLLOW t1 where t1.user_id = ?) )         on duplicate key update sort= (select max(IFNULL(t2.sort,0)) + 1 from test_follow t2 where t2.user_id= ?)
Jul 23 17:12:50 iZ2360o6lpyZ warn1 ### Cause: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at sky.platform.runtime.DbServiceInterceptor$1.execute(DbServiceInterceptor.java:39) ~[hbec-platform-commons-0.0.32-SNAPSHOT.jar:na]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at sky.platform.runtime.DbService.execute(DbService.java:1242) ~[hbec-platform-commons-0.0.32-SNAPSHOT.jar:na]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at sky.platform.runtime.DbServiceInterceptor.intercept(DbServiceInterceptor.java:33) [hbec-platform-commons-0.0.32-SNAPSHOT.jar:na]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at sky.app.stock.follow.service.impl.WarnFollowServiceImpl$$EnhancerByCGLIB$$41e28e09.follow(<generated>) [spring-core-4.0.2.RELEASE.jar:na]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at sky.app.stock.follow.controller.impl.FollowStockControllerImpl.follow(FollowStockControllerImpl.java:304) [hbec-app-stock-follow-1.0.2-SNAPSHOT.jar:na]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at com.alibaba.dubbo.common.bytecode.Wrapper94.invokeMethod(Wrapper94.java) [na:2.5.3]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at com.alibaba.dubbo.rpc.proxy.javassist.JavassistProxyFactory$1.doInvoke(JavassistProxyFactory.java:46) [dubbo-2.5.3.jar:2.5.3]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at com.alibaba.dubbo.rpc.proxy.AbstractProxyInvoker.invoke(AbstractProxyInvoker.java:72) [dubbo-2.5.3.jar:2.5.3]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at com.alibaba.dubbo.rpc.protocol.InvokerWrapper.invoke(InvokerWrapper.java:53) [dubbo-2.5.3.jar:2.5.3]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at com.alibaba.dubbo.rpc.filter.ExceptionFilter.invoke(ExceptionFilter.java:64) [dubbo-2.5.3.jar:2.5.3]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91) [dubbo-2.5.3.jar:2.5.3]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at com.alibaba.dubbo.rpc.filter.TimeoutFilter.invoke(TimeoutFilter.java:42) [dubbo-2.5.3.jar:2.5.3]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91) [dubbo-2.5.3.jar:2.5.3]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at com.alibaba.dubbo.monitor.support.MonitorFilter.invoke(MonitorFilter.java:75) [dubbo-2.5.3.jar:2.5.3]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91) [dubbo-2.5.3.jar:2.5.3]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at com.alibaba.dubbo.rpc.protocol.dubbo.filter.TraceFilter.invoke(TraceFilter.java:78) [dubbo-2.5.3.jar:2.5.3]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91) [dubbo-2.5.3.jar:2.5.3]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at sky.app.eagleeye.dubbo.EagleeyeFilter.invoke(EagleeyeFilter.java:155) [hbec-platform-runtime-app-0.0.32-SNAPSHOT.jar:na]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91) [dubbo-2.5.3.jar:2.5.3]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at com.alibaba.dubbo.rpc.filter.ContextFilter.invoke(ContextFilter.java:60) [dubbo-2.5.3.jar:2.5.3]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91) [dubbo-2.5.3.jar:2.5.3]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at com.alibaba.dubbo.rpc.filter.GenericFilter.invoke(GenericFilter.java:112) [dubbo-2.5.3.jar:2.5.3]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91) [dubbo-2.5.3.jar:2.5.3]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at com.alibaba.dubbo.rpc.filter.ClassLoaderFilter.invoke(ClassLoaderFilter.java:38) [dubbo-2.5.3.jar:2.5.3]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91) [dubbo-2.5.3.jar:2.5.3]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at com.alibaba.dubbo.rpc.filter.EchoFilter.invoke(EchoFilter.java:38) [dubbo-2.5.3.jar:2.5.3]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at com.alibaba.dubbo.rpc.protocol.ProtocolFilterWrapper$1.invoke(ProtocolFilterWrapper.java:91) [dubbo-2.5.3.jar:2.5.3]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at com.alibaba.dubbo.rpc.protocol.dubbo.DubboProtocol$1.reply(DubboProtocol.java:108) [dubbo-2.5.3.jar:2.5.3]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at com.alibaba.dubbo.remoting.exchange.support.header.HeaderExchangeHandler.handleRequest(HeaderExchangeHandler.java:84) [dubbo-2.5.3.jar:2.5.3]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at com.alibaba.dubbo.remoting.exchange.support.header.HeaderExchangeHandler.received(HeaderExchangeHandler.java:170) [dubbo-2.5.3.jar:2.5.3]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at com.alibaba.dubbo.remoting.transport.DecodeHandler.received(DecodeHandler.java:52) [dubbo-2.5.3.jar:2.5.3]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at com.alibaba.dubbo.remoting.transport.dispatcher.ChannelEventRunnable.run(ChannelEventRunnable.java:82) [dubbo-2.5.3.jar:2.5.3]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [na:1.7.0_55]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [na:1.7.0_55]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at java.lang.Thread.run(Thread.java:745) [na:1.7.0_55]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 Caused by: java.lang.RuntimeException: sky.platform.commons.exceptions.HbecDbServiceException: service=db,message=
Jul 23 17:12:50 iZ2360o6lpyZ warn1 ### Error updating database.  Cause: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction
Jul 23 17:12:50 iZ2360o6lpyZ warn1 ### The error may involve WarnFollowMapper.follow-Inline
Jul 23 17:12:50 iZ2360o6lpyZ warn1 ### The error occurred while setting parameters
Jul 23 17:12:50 iZ2360o6lpyZ warn1 ### SQL: insert into test_follow (user_id, security_type, stock_code, exchange, stock_name, sub_fund_type, sort)         values (?, ?,  ?,                 ?,?, ?,                 (select max(IFNULL(t1.sort,0)) + 1 from test_FOLLOW t1 where t1.user_id = ?) )         on duplicate key update sort= (select max(IFNULL(t2.sort,0)) + 1 from test_follow t2 where t2.user_id= ?)
Jul 23 17:12:50 iZ2360o6lpyZ warn1 ### Cause: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at sky.app.stock.follow.repository.impl.WarnFollowRepository.follow(WarnFollowRepository.java:238) ~[hbec-app-stock-follow-1.0.2-SNAPSHOT.jar:na]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at sky.app.stock.follow.service.impl.WarnFollowServiceImpl.follow(WarnFollowServiceImpl.java:87) ~[hbec-app-stock-follow-1.0.2-SNAPSHOT.jar:na]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at sky.app.stock.follow.service.impl.WarnFollowServiceImpl$$EnhancerByCGLIB$$41e28e09.CGLIB$follow$0(<generated>) [spring-core-4.0.2.RELEASE.jar:na]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at sky.app.stock.follow.service.impl.WarnFollowServiceImpl$$EnhancerByCGLIB$$41e28e09$$FastClassByCGLIB$$cf1f7d1b.invoke(<generated>) ~[spring-core-4.0.2.RELEASE.jar:na]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at org.springframework.cglib.proxy.MethodProxy.invokeSuper(MethodProxy.java:228) ~[spring-core-4.0.2.RELEASE.jar:4.0.2.RELEASE]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at sky.platform. 大专栏  deadlock-found-when-trying-to-get-lockruntime.DbServiceInterceptor$1.execute(DbServiceInterceptor.java:37) ~[hbec-platform-commons-0.0.32-SNAPSHOT.jar:na]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	... 34 common frames omitted
Jul 23 17:12:50 iZ2360o6lpyZ warn1 Caused by: sky.platform.commons.exceptions.HbecDbServiceException: service=db,message=
Jul 23 17:12:50 iZ2360o6lpyZ warn1 ### Error updating database.  Cause: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction
Jul 23 17:12:50 iZ2360o6lpyZ warn1 ### The error may involve WarnFollowMapper.follow-Inline
Jul 23 17:12:50 iZ2360o6lpyZ warn1 ### The error occurred while setting parameters
Jul 23 17:12:50 iZ2360o6lpyZ warn1 ### SQL: insert into test_follow (user_id, security_type, stock_code, exchange, stock_name, sub_fund_type, sort)         values (?, ?,  ?,                 ?,?, ?,                 (select max(IFNULL(t1.sort,0)) + 1 from test_FOLLOW t1 where t1.user_id = ?) )         on duplicate key update sort= (select max(IFNULL(t2.sort,0)) + 1 from test_follow t2 where t2.user_id= ?)
Jul 23 17:12:50 iZ2360o6lpyZ warn1 ### Cause: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at sky.platform.runtime.DbService.myInsert(DbService.java:2345) ~[hbec-platform-commons-0.0.32-SNAPSHOT.jar:na]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at sky.app.stock.follow.repository.impl.WarnFollowRepository.follow(WarnFollowRepository.java:236) ~[hbec-app-stock-follow-1.0.2-SNAPSHOT.jar:na]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	... 39 common frames omitted
Jul 23 17:12:50 iZ2360o6lpyZ warn1 Caused by: org.apache.ibatis.exceptions.PersistenceException: 
Jul 23 17:12:50 iZ2360o6lpyZ warn1 ### Error updating database.  Cause: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction
Jul 23 17:12:50 iZ2360o6lpyZ warn1 ### The error may involve WarnFollowMapper.follow-Inline
Jul 23 17:12:50 iZ2360o6lpyZ warn1 ### The error occurred while setting parameters
Jul 23 17:12:50 iZ2360o6lpyZ warn1 ### SQL: insert into test_follow (user_id, security_type, stock_code, exchange, stock_name, sub_fund_type, sort)         values (?, ?,  ?,                 ?,?, ?,                 (select max(IFNULL(t1.sort,0)) + 1 from test_FOLLOW t1 where t1.user_id = ?) )         on duplicate key update sort= (select max(IFNULL(t2.sort,0)) + 1 from test_follow t2 where t2.user_id= ?)
Jul 23 17:12:50 iZ2360o6lpyZ warn1 ### Cause: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at org.apache.ibatis.exceptions.ExceptionFactory.wrapException(ExceptionFactory.java:26) ~[mybatis-3.2.8.jar:3.2.8]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at org.apache.ibatis.session.defaults.DefaultSqlSession.update(DefaultSqlSession.java:154) ~[mybatis-3.2.8.jar:3.2.8]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at org.apache.ibatis.session.defaults.DefaultSqlSession.insert(DefaultSqlSession.java:141) ~[mybatis-3.2.8.jar:3.2.8]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at sky.platform.runtime.DbService.myInsert(DbService.java:2331) ~[hbec-platform-commons-0.0.32-SNAPSHOT.jar:na]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	... 40 common frames omitted
Jul 23 17:12:50 iZ2360o6lpyZ warn1 Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) ~[na:1.7.0_55]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57) ~[na:1.7.0_55]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) ~[na:1.7.0_55]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at java.lang.reflect.Constructor.newInstance(Constructor.java:526) ~[na:1.7.0_55]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at com.mysql.jdbc.Util.handleNewInstance(Util.java:411) ~[mysql-connector-java-5.1.28.jar:na]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at com.mysql.jdbc.Util.getInstance(Util.java:386) ~[mysql-connector-java-5.1.28.jar:na]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1066) ~[mysql-connector-java-5.1.28.jar:na]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4237) ~[mysql-connector-java-5.1.28.jar:na]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4169) ~[mysql-connector-java-5.1.28.jar:na]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2617) ~[mysql-connector-java-5.1.28.jar:na]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2778) ~[mysql-connector-java-5.1.28.jar:na]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2825) ~[mysql-connector-java-5.1.28.jar:na]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:2156) ~[mysql-connector-java-5.1.28.jar:na]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at com.mysql.jdbc.PreparedStatement.execute(PreparedStatement.java:1379) ~[mysql-connector-java-5.1.28.jar:na]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at sun.reflect.GeneratedMethodAccessor199.invoke(Unknown Source) ~[na:na]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.7.0_55]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at java.lang.reflect.Method.invoke(Method.java:606) ~[na:1.7.0_55]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at org.apache.ibatis.logging.jdbc.PreparedStatementLogger.invoke(PreparedStatementLogger.java:62) ~[mybatis-3.2.8.jar:3.2.8]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at com.sun.proxy.$Proxy28.execute(Unknown Source) ~[na:na]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at org.apache.ibatis.executor.statement.PreparedStatementHandler.update(PreparedStatementHandler.java:44) ~[mybatis-3.2.8.jar:3.2.8]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at org.apache.ibatis.executor.statement.RoutingStatementHandler.update(RoutingStatementHandler.java:69) ~[mybatis-3.2.8.jar:3.2.8]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at org.apache.ibatis.executor.SimpleExecutor.doUpdate(SimpleExecutor.java:48) ~[mybatis-3.2.8.jar:3.2.8]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at org.apache.ibatis.executor.BaseExecutor.update(BaseExecutor.java:105) ~[mybatis-3.2.8.jar:3.2.8]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at org.apache.ibatis.executor.CachingExecutor.update(CachingExecutor.java:71) ~[mybatis-3.2.8.jar:3.2.8]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	at org.apache.ibatis.session.defaults.DefaultSqlSession.update(DefaultSqlSession.java:152) ~[mybatis-3.2.8.jar:3.2.8]
Jul 23 17:12:50 iZ2360o6lpyZ warn1 	... 42 common frames omitted
Jul 23 17:12:50 iZ2360o6lpyZ warn1 17-07-23 17:12:50.780 DEBUG[DubboServerHandler-10.253.17.105:20880-thread-192 follow.debug:139]MYBATIS <==    Updates: 2

查看数据库引擎状态

1
show engine innodb status
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
------------------------
LATEST DETECTED DEADLOCK
------------------------
2017-07-23 17:13:58 2afc664c2700
*** (1) TRANSACTION:
TRANSACTION 730441984, ACTIVE 0.003 sec inserting
mysql tables in use 3, locked 3
LOCK WAIT 8 lock struct(s), heap size 2936, 37 row lock(s), undo log entries 1
LOCK BLOCKING MySQL thread id: 12246957 block 12256080
MySQL thread id 12256080, OS thread handle 0x2afc48c40700, query id 3543571324 10.253.17.105 test_app Sending data
insert into test_follow (user_id, security_type, stock_code, exchange, stock_name, sub_fund_type, sort)
        values (3245964, 4,  '601318',
                'SH','中国平安', null,
                (select max(IFNULL(t1.sort,0)) + 1 from test_FOLLOW t1 where t1.user_id = 3245964) )
        on duplicate key update sort= (select max(IFNULL(t2.sort,0)) + 1 from test_follow t2 where t2.user_id= 3245964)
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 1198 page no 842 n bits 696 index `unique_index` of table `wndb`.`test_follow` trx id 730441984 lock_mode X waiting
Record lock, heap no 624 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
 0: len 4; hex 8031878c; asc  1  ;;
 1: len 1; hex 84; asc  ;;
 2: len 6; hex 363031333138; asc 601318;;
 3: len 4; hex 800399cb; asc     ;;
*** (2) TRANSACTION:
TRANSACTION 730441985, ACTIVE 0.001 sec inserting
mysql tables in use 3, locked 3
8 lock struct(s), heap size 2936, 37 row lock(s), undo log entries 1
MySQL thread id 12246957, OS thread handle 0x2afc664c2700, query id 3543571329 10.253.17.105 test_app Sending data
insert into test_follow (user_id, security_type, stock_code, exchange, stock_name, sub_fund_type, sort)
        values (3245964, 4,  '601318',
                'SH','中国平安', null,
                (select max(IFNULL(t1.sort,0)) + 1 from test_FOLLOW t1 where t1.user_id = 3245964) )
        on duplicate key update sort= (select max(IFNULL(t2.sort,0)) + 1 from test_follow t2 where t2.user_id= 3245964)
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 1198 page no 842 n bits 696 index `unique_index` of table `wndb`.`test_follow` trx id 730441985 lock mode S locks rec but not gap
Record lock, heap no 624 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
 0: len 4; hex 8031878c; asc  1  ;;
 1: len 1; hex 84; asc  ;;
 2: len 6; hex 363031333138; asc 601318;;
 3: len 4; hex 800399cb; asc     ;;
*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 1198 page no 842 n bits 696 index `unique_index` of table `wndb`.`test_follow` trx id 730441985 lock_mode X waiting
Record lock, heap no 624 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
 0: len 4; hex 8031878c; asc  1  ;;
 1: len 1; hex 84; asc  ;;
 2: len 6; hex 363031333138; asc 601318;;
 3: len 4; hex 800399cb; asc     ;;
*** WE ROLL BACK TRANSACTION (2)

从中可以看到两个事务在等待X锁

1
2
3
4
5
6
7
8
9
10
11
WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 1198 page no 842 n bits 696 index `unique_index` of table `wndb`.`test_follow` trx id 730441984 lock_mode X waiting
Record lock
(2) HOLDS THE LOCK(S):
RECORD LOCKS space id 1198 page no 842 n bits 696 index `unique_index` of table `wndb`.`test_follow` trx id 730441985 lock mode S locks rec but not gap
Record lock, heap no 624 PHYSICAL RECORD
(2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 1198 page no 842 n bits 696 index `unique_index` of table `wndb`.`test_follow` trx id 730441985 lock_mode X waiting
Record lock, heap no 624 PHYSICAL RECORD

重现

1.准备工作

  • 同时开启三个command prompt，远程连接mysql服务器：mysql -uroc -proc -h10.0.30.59 wndb
  • 关闭自动提交：set autocommit=0

2.模拟请求

Session A

1
2
3
begin;
insert into test_follow (user_id, security_type, stock_code, exchange, stock_name, sub_fund_type, sort) values (3245964, 4, '600628', 'SH','新世界', null, (select max(IFNULL(t1.sort,0)) + 1 from test_FOLLOW t1 where t1.user_id = 3245964) ) on duplicate key update sort= (select max(IFNULL(t2.sort,0)) + 1 from test_follow t2 where t2.user_id= 3245964);

Session B

1
2
3
begin;
insert into test_follow (user_id, security_type, stock_code, exchange, stock_name, sub_fund_type, sort) values (3245964, 4, '600628', 'SH','新世界', null, (select max(IFNULL(t1.sort,0)) + 1 from test_FOLLOW t1 where t1.user_id = 3245964) ) on duplicate key update sort= (select max(IFNULL(t2.sort,0)) + 1 from test_follow t2 where t2.user_id= 3245964);

Session C

1
2
3
begin;
insert into test_follow (user_id, security_type, stock_code, exchange, stock_name, sub_fund_type, sort) values (3245964, 4, '600628', 'SH','新世界', null, (select max(IFNULL(t1.sort,0)) + 1 from test_FOLLOW t1 where t1.user_id = 3245964) ) on duplicate key update sort= (select max(IFNULL(t2.sort,0)) + 1 from test_follow t2 where t2.user_id= 3245964);

commit Session A，session B与session C竞争X锁，直接报错:

技术图片

解决

首先这是个添加操作，APP端不应该对同一用户、同一只股票执行多次并发添加操作
，APP端需要解决单设备、多并发问题。后台针对同一用户、同一股票的添加操作，需要使用分布式锁控制并发。

deadlock-found-when-trying-to-get-lock

标签：bytecode   自动提交   simple   head   intern   factor   iis   win   ioc   

原文地址：https://www.cnblogs.com/wangziqiang123/p/11691036.html
踩
(0)
赞
(0)
   
举报
评论 一句话评论（0）
登录后才能评论！
分享档案
更多>
2021年07月29日 (22)
2021年07月28日 (40)
2021年07月27日 (32)
2021年07月26日 (79)
2021年07月23日 (29)
2021年07月22日 (30)
2021年07月21日 (42)
2021年07月20日 (16)
2021年07月19日 (90)
2021年07月16日 (35)
周排行
mamicode.com排行更多图片
更多
友情链接
兰亭集智   国之画   百度统计   站长统计   阿里云   chrome插件   新版天听网
关于我们 - 联系我们 - 留言反馈
© 2014 mamicode.com 版权所有  联系我们:gaon5@hotmail.com
迷上了代码！