[Mysql] Deadlock found when trying to get lock

서비스 운영 중 다음과 같은 에러가 발생되었다.

AWS CloudWatch Error Log:

2020-04-16 12:38:00.373 ERROR 1 --- [pool-1-thread-1] o.s.s.s.TaskUtils$LoggingErrorHandler : Unexpected error occurred in scheduled task
org.springframework.dao.DeadlockLoserDataAccessException: PreparedStatementCallback; SQL [DELETE FROM SPRING_SESSION WHERE EXPIRY_TIME < ?]; Deadlock found when trying to get lock; try restarting transaction; nested exception is com.mysql.cj.jdbc.exceptions.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction
at org.springframework.jdbc.support.SQLErrorCodeSQLExceptionTranslator.doTranslate(SQLErrorCodeSQLExceptionTranslator.java:267) ~[spring-jdbc-5.2.3.RELEASE.jar!/:5.2.3.RELEASE]
at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:72) ~[spring-jdbc-5.2.3.RELEASE.jar!/:5.2.3.RELEASE]
at org.springframework.jdbc.core.JdbcTemplate.translateException(JdbcTemplate.java:1443) ~[spring-jdbc-5.2.3.RELEASE.jar!/:5.2.3.RELEASE]
at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:633) ~[spring-jdbc-5.2.3.RELEASE.jar!/:5.2.3.RELEASE]
at org.springframework.jdbc.core.JdbcTemplate.update(JdbcTemplate.java:862) ~[spring-jdbc-5.2.3.RELEASE.jar!/:5.2.3.RELEASE]
at org.springframework.jdbc.core.JdbcTemplate.update(JdbcTemplate.java:917) ~[spring-jdbc-5.2.3.RELEASE.jar!/:5.2.3.RELEASE]
at org.springframework.jdbc.core.JdbcTemplate.update(JdbcTemplate.java:927) ~[spring-jdbc-5.2.3.RELEASE.jar!/:5.2.3.RELEASE]
at org.springframework.session.jdbc.JdbcIndexedSessionRepository.lambda$cleanUpExpiredSessions$8(JdbcIndexedSessionRepository.java:553) ~[spring-session-jdbc-2.2.0.RELEASE.jar!/:2.2.0.RELEASE]
at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:140) ~[spring-tx-5.2.3.RELEASE.jar!/:5.2.3.RELEASE]
at org.springframework.session.jdbc.JdbcIndexedSessionRepository.cleanUpExpiredSessions(JdbcIndexedSessionRepository.java:553) ~[spring-session-jdbc-2.2.0.RELEASE.jar!/:2.2.0.RELEASE]
at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54) ~[spring-context-5.2.3.RELEASE.jar!/:5.2.3.RELEASE]
at org.springframework.scheduling.concurrent.ReschedulingRunnable.run(ReschedulingRunnable.java:93) [spring-context-5.2.3.RELEASE.jar!/:5.2.3.RELEASE]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [na:1.8.0_151]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [na:1.8.0_151]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [na:1.8.0_151]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [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.cj.jdbc.exceptions.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction
at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:123) ~[mysql-connector-java-8.0.19.jar!/:8.0.19]
at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:97) ~[mysql-connector-java-8.0.19.jar!/:8.0.19]
at com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:122) ~[mysql-connector-java-8.0.19.jar!/:8.0.19]
at com.mysql.cj.jdbc.ClientPreparedStatement.executeInternal(ClientPreparedStatement.java:953) ~[mysql-connector-java-8.0.19.jar!/:8.0.19]
at com.mysql.cj.jdbc.ClientPreparedStatement.executeUpdateInternal(ClientPreparedStatement.java:1092) ~[mysql-connector-java-8.0.19.jar!/:8.0.19]
at com.mysql.cj.jdbc.ClientPreparedStatement.executeUpdateInternal(ClientPreparedStatement.java:1040) ~[mysql-connector-java-8.0.19.jar!/:8.0.19]
at com.mysql.cj.jdbc.ClientPreparedStatement.executeLargeUpdate(ClientPreparedStatement.java:1347) ~[mysql-connector-java-8.0.19.jar!/:8.0.19]
at com.mysql.cj.jdbc.ClientPreparedStatement.executeUpdate(ClientPreparedStatement.java:1025) ~[mysql-connector-java-8.0.19.jar!/:8.0.19]
at com.zaxxer.hikari.pool.ProxyPreparedStatement.executeUpdate(ProxyPreparedStatement.java:61) ~[HikariCP-3.4.2.jar!/:na]
at com.zaxxer.hikari.pool.HikariProxyPreparedStatement.executeUpdate(HikariProxyPreparedStatement.java) ~[HikariCP-3.4.2.jar!/:na]
at org.springframework.jdbc.core.JdbcTemplate.lambda$update$0(JdbcTemplate.java:867) ~[spring-jdbc-5.2.3.RELEASE.jar!/:5.2.3.RELEASE]
at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:617) ~[spring-jdbc-5.2.3.RELEASE.jar!/:5.2.3.RELEASE]

Mysql 에서 자신의 Transaction Isolation Level을 확인하려면 다음과 같은 명령어를 사용한다

show variables like 'tx_isolation';

위의 에러는 REPEATABLE READ 라는 상태일 때 나타나게 된다.

참고 문서에 아래와 같이 나와있다.

REPEATABLE-READ에서는 현재 Select 버전을 보장하기 위해 Snapshot을 이용하는데, 
이 경우 해당 데이터에 관해서 암묵적으로 Lock과 비슷한 효과가 나타납니다.

즉, Select 작업이 종료될 때까지 해당 데이터 변경 작업이 불가합니다.

tx_isolation 변수의 상태는 4가지가 있다.

• READ UNCOMMITTED
  다른 트랜잭션이 Commit 전 상태를 볼 수 있음Binary Log가 자동으로 Row Based로 기록됨 (Statement설정 불가, Mixed 설정 시 자동 변환)
• READ-COMMITTED
  Commit된 내역을 읽을 수 있는 상태로, 트랜잭션이 다르더라도 특정 타 트랜잭션이 Commit을 수행하면 해당 데이터를 Read할 수 있음Binary Log가 자동으로 Row Based로 기록됨 (Statement설정 불가, Mixed 설정 시 자동 변환)
• REPEATABLE READ
  MySQL InnoDB 스토리지 엔진의 Default Isolation LevelSelect 시 현재 데이터 버전의 Snapshot을 만들고, 그 Snapshot으로부터 데이터를 조회동일 트랜잭션 내에서 데이터 일관성을 보장하고 데이터를 다시 읽기 위해서는 트랜잭션을 다시 시작해야 함
• SERIALIZABLE
  가장 높은 Isolation Level로 트랜잭션이 완료될 때까지 SELECT 문장이 사용하는 모든 데이터에 Shared Lock이 걸림다른 트랜잭션에서는 해당 영역에 관한 데이터 변경 뿐만 아니라 입력도 불가

Oracle 에서는 READ-COMMITTED 상태가 Default 상태여서 해당 에러가 나타나지 않는다.

Mysql 의 tx_isolation변수값을 READ-COMMITTED 값으로 변경해야지 해당 에러가 발생하지 않는다.

참고 :

1. https://gywn.net/2012/05/mysql-transaction-isolation-level/