Translate

2017년 11월 13일 월요일

[MySQL][해결방법] Deadlock found when trying to get lock; try restarting transaction





환경
- MySQL v5.7
- Java (Spring-Boot)




증상

Java Spring 애플리케이션에서 아래와 같이 오류가 발생했다.
1004lucifer



2017-11-13 00:00:23.547 ERROR 19976 --- [TaskScheduler-1] o.s.s.s.TaskUtils$LoggingErrorHandler    : Unexpected error occurred in scheduled task.

org.springframework.dao.DeadlockLoserDataAccessException:
### Error updating database.  Cause: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction
### The error may involve [_PACKAGE_NAME_].[_CLASS_NAME_].[_METHOD_NAME_]-Inline
### The error occurred while setting parameters
### SQL: insert into ~~~~
### Cause: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction
; SQL []; Deadlock found when trying to get lock; try restarting transaction; nested exception is com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction
        at org.springframework.jdbc.support.SQLErrorCodeSQLExceptionTranslator.doTranslate(SQLErrorCodeSQLExceptionTranslator.java:263) ~[spring-jdbc-4.3.7.RELEASE.jar:4.3.7.RELEASE]
        at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:73) ~[spring-jdbc-4.3.7.RELEASE.jar:4.3.7.RELEASE]
        at org.mybatis.spring.MyBatisExceptionTranslator.translateExceptionIfPossible(MyBatisExceptionTranslator.java:73) ~[mybatis-spring-1.3.1.jar:1.3.1]
        at org.mybatis.spring.SqlSessionTemplate$SqlSessionInterceptor.invoke(SqlSessionTemplate.java:446) ~[mybatis-spring-1.3.1.jar:1.3.1]
        at com.sun.proxy.$Proxy254.insert(Unknown Source) ~[na:na]
        at org.mybatis.spring.SqlSessionTemplate.insert(SqlSessionTemplate.java:278) ~[mybatis-spring-1.3.1.jar:1.3.1]
        at org.apache.ibatis.binding.MapperMethod.execute(MapperMethod.java:57) ~[mybatis-3.4.4.jar:3.4.4]
        at org.apache.ibatis.binding.MapperProxy.invoke(MapperProxy.java:59) ~[mybatis-3.4.4.jar:3.4.4]
        at com.sun.proxy.$Proxy259.[_METHOD_NAME_](Unknown Source) ~[na:na]
        at [_PACKAGE_NAME_].[_CLASS_NAME_].[_METHOD_NAME_]([_CLASS_NAME_].java:55) ~[classes/:na]
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_151]
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_151]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_151]
        at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_151]
        at org.springframework.scheduling.support.ScheduledMethodRunnable.run(ScheduledMethodRunnable.java:65) ~[spring-context-4.3.7.RELEASE.jar:4.3.7.RELEASE]
        at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54) ~[spring-context-4.3.7.RELEASE.jar:4.3.7.RELEASE]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [na:1.8.0_151]
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [na:1.8.0_151]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [na:1.8.0_151]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [na:1.8.0_151]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_151]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_151]
        at java.lang.Thread.run(Thread.java:748) [na:1.8.0_151]
Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction
        at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) ~[na:1.8.0_151]
        at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62) ~[na:1.8.0_151]
        at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) ~[na:1.8.0_151]
        at java.lang.reflect.Constructor.newInstance(Constructor.java:423) ~[na:1.8.0_151]
        at com.mysql.jdbc.Util.handleNewInstance(Util.java:425) ~[mysql-connector-java-5.1.42.jar:5.1.42]
        at com.mysql.jdbc.Util.getInstance(Util.java:408) ~[mysql-connector-java-5.1.42.jar:5.1.42]
        at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:951) ~[mysql-connector-java-5.1.42.jar:5.1.42]
        at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3973) ~[mysql-connector-java-5.1.42.jar:5.1.42]
        at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3909) ~[mysql-connector-java-5.1.42.jar:5.1.42]
        at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2527) ~[mysql-connector-java-5.1.42.jar:5.1.42]
        at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2680) ~[mysql-connector-java-5.1.42.jar:5.1.42]
        at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2490) ~[mysql-connector-java-5.1.42.jar:5.1.42]
        at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1858) ~[mysql-connector-java-5.1.42.jar:5.1.42]
        at com.mysql.jdbc.PreparedStatement.execute(PreparedStatement.java:1197) ~[mysql-connector-java-5.1.42.jar:5.1.42]
        at org.apache.ibatis.executor.statement.PreparedStatementHandler.update(PreparedStatementHandler.java:46) ~[mybatis-3.4.4.jar:3.4.4]
        at org.apache.ibatis.executor.statement.RoutingStatementHandler.update(RoutingStatementHandler.java:74) ~[mybatis-3.4.4.jar:3.4.4]
        at org.apache.ibatis.executor.SimpleExecutor.doUpdate(SimpleExecutor.java:50) ~[mybatis-3.4.4.jar:3.4.4]
        at org.apache.ibatis.executor.BaseExecutor.update(BaseExecutor.java:117) ~[mybatis-3.4.4.jar:3.4.4]
        at org.apache.ibatis.executor.CachingExecutor.update(CachingExecutor.java:76) ~[mybatis-3.4.4.jar:3.4.4]
        at org.apache.ibatis.session.defaults.DefaultSqlSession.update(DefaultSqlSession.java:198) ~[mybatis-3.4.4.jar:3.4.4]
        at org.apache.ibatis.session.defaults.DefaultSqlSession.insert(DefaultSqlSession.java:185) ~[mybatis-3.4.4.jar:3.4.4]
        at sun.reflect.GeneratedMethodAccessor306.invoke(Unknown Source) ~[na:na]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_151]
        at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_151]
        at org.mybatis.spring.SqlSessionTemplate$SqlSessionInterceptor.invoke(SqlSessionTemplate.java:433) ~[mybatis-spring-1.3.1.jar:1.3.1]
        ... 19 common frames omitted







원인


 insert into TableA 로직이 수행되는 시점의 직전에
다른 모듈에서 TableA 를 select 하여 다른 테이블에 insert 하는 로직이 수행되었다.

1004lucifer
트랜잭션 관련 이슈로 인해 문제가 발생을 했으며 아래 링크의 글을 읽어보면 해당 이슈에 대해서 이해할 수 있다.
MySQL 트랜잭션 Isolation Level로 인한 장애 사전 예방 법
MySQL 5.7 Reference Manual - SET TRANSACTION Syntax
MySQL 5.7 Reference Manual - Transaction Isolation Levels


해결방안 적용시 아래의 문제가 생길 가능성 있는것 같음.
(binlog 관련 - 추후 문제 발생 시 이 글을 업데이트 예정)
[MySQL] innoDB transaction isolation level과 binlog enable 시 문제점 정리




해결방안
1004lucifer
my.cnf 파일에 아래의 옵션을 추가 후 MySQL, Java 프로그램 재기동
(4가지 옵션이 있으며 '원인' 부분에 제공된 링크를 보고 본인에 맞게 적용하면 된다.)
- READ-UNCOMMITTED
- READ-COMMITTED
- REPEATABLE-READ
- SERIALIZABLE


[mysqld]
transaction-isolation    = READ-COMMITTED




PS.
애플리케이션에서 트랜잭션이 일어나지 않게 설계를 하면 좀 더 좋겠지만 그렇지 않을 수 있다. Oracle 사용할 때는 위와같은 이슈로 고민해본적은 없었는데..
아마 Oracle 에서는 'READ-UNCOMMITTED | READ-COMMITTED' 둘중에 하나의 개념을 기본으로 사용하고 있지 않을까 싶다.



댓글 없음 :

댓글 쓰기