최근 배치 관련 작업을 위해 Spring Batch를 통해 개발하고 있는데 예상치 못한 오류를 맞이했다.
com.mysql.cj.jdbc.exceptions.MySQLTransactionRollbackException: Deadlock found when trying to get
lock;
try restarting transaction : PreparedStatementCallback; SQL [INSERT INTO BATCH_JOB_INSTANCE(JOB_INSTANCE_ID, JOB_NAME, JOB_KEY, VERSION) VALUES (?, ?, ?, ?) ];
Deadlock found when trying to get lock;
try restarting transaction in class org.springframework.dao.CannotAcquireLockException
학부시절에도 머리가 지끈했던 데드락이라는 키워드를 보니 정신이 혼미해졌다.
우선 해당 오류를 그대로 구글링해보며 나와 비슷한 문제를 직면한 포스트를 봤다.
Spring batch job 동시 등록 Deadlock 문제 직면 ( Deadlock accessing creating a job on sqlserver when multiple jobs start
Spring batch job 동시 등록 Deadlock 문제 직면 ( Deadlock accessing creating a job on sqlserver when multiple jobs start at once. )
velog.io
해당 오류를 깊게 파악하시고 여러 해결방법까지 제시한 훌륭한 위 글을 보며 나의 문제도 쉽게 해결될 것이라고 생각했다.
그러나 글을 자세히 보니 해당 문제는 이미 내가 사용하고 있는 Spring Batch 버전에선 해결되어 릴리즈 된 상태였고, 오류 메시지도 자세히 보니 좀 달랐다.
그럼 우리 서비스에서 발생한 이 데드락은 도대체 정체가 뭘까? 하루를 삽질했다..
우선 로그에 BATCH_JOB_INSTANCE 테이블에 INSERT를 시도하다가 에러가 났다고 친절하게 써있으므로 이를 단서로 이용했다.
Spring Batch의 Job을 주기적으로 실행 시키기 위해 여러 방법이 존재하지만, 우리는 편의성을 위해 Spring이 제공하는 스케쥴링 서비스를 이용한다. 또한, 작업의 효율성을 위해 스프링 내에서 스케쥴링을 전담하는 쓰레드를 단일(기본)에서 커스텀하게 멀티쓰레딩 방식으로 변경했다.
@Bean
public ThreadPoolTaskScheduler taskExecutor() {
ThreadPoolTaskScheduler scheduler = new ThreadPoolTaskScheduler();
scheduler.setPoolSize(THREAD_POOL_SIZE);
scheduler.setThreadNamePrefix("s-thread-");
scheduler.initialize();
return scheduler;
}
위 이유로 인해 특정 시간에 여러 Job이 몰리는 상황이 생기는데, 문제는 여기서 발생했다.
외부에서 주기적 콜을 하는 것이 아닌 Spring 프레임워크 내에서 스케쥴링을 하는 만큼 같은 시간에 스케쥴링 되어있는 Job들은 정확히 동시에 실행된다.
Spring Batch는 Bean으로 등록된 Job을 실행할때, 메타 테이블중 하나인 BATCH_JOB_INSTANCE에 우선 Job 인스턴스 정보를 적재한다.
그렇다면 여러 JOB들이 시작될 때 BATCH_JOB_INSTANCE 테이블에 ROW를 저장하려는 찰나에 데드락이 발생했음을 알 수 있다.
이 테이블에는 ID(PK), VERSION, JOB_NAME, JOB_KEY 의 조합으로 ROW를 저장하는데, 동시에 실행되는 여러 JOB들은 서로 다른 JOB_NAME을 가지고 있으므로 같은 ROW에 대한 LOCK을 획득하는 과정에서 발생했을리는 없다.
MySQL은 최근 발생했던 데드락 정보를 알 수 있는데, 원인을 찾기 위해 이를 이용했다.
SHOW ENGINE INNODB STATUS;
위 명령어를 이용하면 현재 DB 엔진의 상태를 보여주고, 가장 최근 발생한 데드락의 정보도 보여준다.
------------------------
LATEST DETECTED DEADLOCK
------------------------
2024-05-24 09:38:33 70373387276160
*** (1) TRANSACTION:
TRANSACTION 51745814, ACTIVE 30 sec inserting
mysql tables in use 1, locked 1
LOCK WAIT 4 lock struct(s), heap size 1128, 2 row lock(s), undo log entries 1
MySQL thread id 569, OS thread handle 70369816903552, query id 53610 10.197.58.70 admin update
INSERT INTO BATCH_JOB_INSTANCE(JOB_INSTANCE_ID, JOB_NAME, JOB_KEY, VERSION)
VALUES (21009, 'testJob4', 'f7b4a6d6209aeb0de6ee81d5e63a4076', 0)
*** (1) HOLDS THE LOCK(S):
RECORD LOCKS space id 1485 page no 206 n bits 360 index JOB_INST_UN of table `batch`.`batch_job_instance` trx id 51745814 lock mode S locks gap before rec
Record lock, heap no 182 PHYSICAL RECORD: n_fields 3; compact format; info bits 0
0: len 8; hex 746573744a6f6235; asc testJob5;;
1: len 30; hex 326235363866323135373661386532386239623463306335326630353366; asc 2b568f21576a8e28b9b4c0c52f053f; (total 32 bytes);
2: len 8; hex 80000000000051db; asc Q ;;
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 1485 page no 206 n bits 360 index JOB_INST_UN of table `batch`.`batch_job_instance` trx id 51745814 lock_mode X locks gap before rec insert intention waiting
Record lock, heap no 182 PHYSICAL RECORD: n_fields 3; compact format; info bits 0
0: len 8; hex 746573744a6f6235; asc testJob5;;
1: len 30; hex 326235363866323135373661386532386239623463306335326630353366; asc 2b568f21576a8e28b9b4c0c52f053f; (total 32 bytes);
2: len 8; hex 80000000000051db; asc Q ;;
*** (2) TRANSACTION:
TRANSACTION 51745820, ACTIVE 30 sec inserting
mysql tables in use 1, locked 1
LOCK WAIT 4 lock struct(s), heap size 1128, 2 row lock(s), undo log entries 1
MySQL thread id 568, OS thread handle 70369817444224, query id 53650 10.197.58.70 admin update
INSERT INTO BATCH_JOB_INSTANCE(JOB_INSTANCE_ID, JOB_NAME, JOB_KEY, VERSION)
VALUES (21010, 'testJob5', '177dc3597b0bfe9b3c303b356b01b846', 0)
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 1485 page no 206 n bits 360 index JOB_INST_UN of table `batch`.`batch_job_instance` trx id 51745820 lock mode S locks gap before rec
Record lock, heap no 182 PHYSICAL RECORD: n_fields 3; compact format; info bits 0
0: len 8; hex 746573744a6f6235; asc testJob5;;
1: len 30; hex 326235363866323135373661386532386239623463306335326630353366; asc 2b568f21576a8e28b9b4c0c52f053f; (total 32 bytes);
2: len 8; hex 80000000000051db; asc Q ;;
*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 1485 page no 206 n bits 360 index JOB_INST_UN of table `batch`.`batch_job_instance` trx id 51745820 lock_mode X locks gap before rec insert intention waiting
Record lock, heap no 182 PHYSICAL RECORD: n_fields 3; compact format; info bits 0
0: len 8; hex 746573744a6f6235; asc testJob5;;
1: len 30; hex 326235363866323135373661386532386239623463306335326630353366; asc 2b568f21576a8e28b9b4c0c52f053f; (total 32 bytes);
2: len 8; hex 80000000000051db; asc Q ;;
*** WE ROLL BACK TRANSACTION (2)
------------
TRANSACTIONS
------------
Trx id counter 51752951
해당 테이블에는 JOB_INST_UN이라는 인덱스가 존재하는데 이게 문제였다.
독립된 두개의 트랜잭션이 하나의 자원을 바라보게 되어 데드락이 발생했다.
| 트랜잭션 A | 트랜잭션 B | |
| (1) | JOB_INST_UN에 대한 공유락(S) 획득 | |
| (2) | JOB_INST_UN에 대한 공유락(S) 획득 | |
| (3) | ROW 삽입을 위한 배타락(X) 획득 시도 | |
| (4) | ROW 삽입을 위한 배타락(X) 획득 시도 |
(3)에서 A는 B의 공유락 소유(2)로 인해 행이 걸렸고, (4)에서 B는 A의 공유락 소유(1)로 인해 행이 걸렸다.
데드락 로그를 보면 한가지 눈에 띄는 것이 있는데, LOCK의 종류가 GAP이라는 것이다.
MySQL의 GAP LOCK에 대한 설명은 당근 테크블로그의 해당 포스팅을 참고했다.
https://medium.com/daangn/mysql-gap-lock-%EB%8B%A4%EC%8B%9C%EB%B3%B4%EA%B8%B0-7f47ea3f68bc
MySQL Gap Lock 다시보기
우리가 일반적으로 알고 있는 데이터베이스 서버의 잠금(Lock)은 레코드 자체에 대한 잠금(Record Lock)이에요. 어떤 트랜잭션에서 레코드를 변경하기 위해서는 그 레코드를 잠그고, 그 동안은 다른
medium.com
해당 인덱스 ROW에 대한 GAP LOCK을 소유하는 과정에서 데드락이 발생한 것이다.
그런데 한가지 이상한 점이 있었다.
MySQL의 GAP LOCK은 4단계의 격리수준 중 아래 두가지 케이스에 대해서만 적용된다고 알려져있다.
REPEATABLE-READ
SERIALIZABLE
그러나 우리가 사용하는 DB는 READ-COMMITTED 격리수준을 사용하고 있었다. (MySQL의 기본 격리수준은 REPEATABLE-READ이지만 격리수준을 한 단계 낮춤)
그러니까 GAP LOCK에 대해서 데드락이 걸릴 수 없는 격리수준을 사용하고 있는데 데드락이 발생한 것이다.
애플리케이션 내 설정에서도 격리수준을 따로 지정하지 않았기 때문에 DB의 기본 설정을 따라갈 것 같았는데 실제로는 그렇지 않았다.
현재 우리가 사용하는 Spring Batch에서 제공하는 라이브러리 중 org.springframework.batch.core.configuration.support 의 DefaultBatchConfiguration 클래스를 확인해보면 메타 정보에 사용되는 JobRepository의 초기화 코드가 다음과 같음을 알 수 있다.
@Bean
public JobRepository jobRepository() throws BatchConfigurationException {
JobRepositoryFactoryBean jobRepositoryFactoryBean = new JobRepositoryFactoryBean();
try {
jobRepositoryFactoryBean.setDataSource(getDataSource());
jobRepositoryFactoryBean.setTransactionManager(getTransactionManager());
jobRepositoryFactoryBean.setDatabaseType(getDatabaseType());
jobRepositoryFactoryBean.setIncrementerFactory(getIncrementerFactory());
jobRepositoryFactoryBean.setClobType(getClobType());
jobRepositoryFactoryBean.setTablePrefix(getTablePrefix());
jobRepositoryFactoryBean.setSerializer(getExecutionContextSerializer());
jobRepositoryFactoryBean.setConversionService(getConversionService());
jobRepositoryFactoryBean.setJdbcOperations(getJdbcOperations());
jobRepositoryFactoryBean.setLobHandler(getLobHandler());
jobRepositoryFactoryBean.setCharset(getCharset());
jobRepositoryFactoryBean.setMaxVarCharLength(getMaxVarCharLength());
jobRepositoryFactoryBean.setIsolationLevelForCreateEnum(getIsolationLevelForCreate());
jobRepositoryFactoryBean.setValidateTransactionState(getValidateTransactionState());
jobRepositoryFactoryBean.afterPropertiesSet();
return jobRepositoryFactoryBean.getObject();
}
catch (Exception e) {
throw new BatchConfigurationException("Unable to configure the default job repository", e);
}
}
/**
* Return the transaction isolation level when creating job executions. Defaults to
* {@link Isolation#SERIALIZABLE}.
* @return the transaction isolation level when creating job executions
*/
protected Isolation getIsolationLevelForCreate() {
return Isolation.SERIALIZABLE;
}
jobRepositoryFactoryBean의 격리수준을 SERIALIZABLE로 고정하고 있었다.
이로써 모든 원인 파악이 끝났다.
원인을 모두 파악했고, 생각난 해결방법은 세 가지 였다.
1. 데드락이 발생하지 않는 쓰레드 수의 임계값을 찾은 뒤, 해당 값보다 적은 수의 쓰레드 운영
2. 쓰레드 커넥션 풀을 유지한 채로, 동시에 실행되는 JOB의 개수 조정
3. jobRepository에 사용되는 격리 수준을 낮춰서 사용
일단 가장 쉬운 1번으로 해결하기 위해 스케쥴링 쓰레드 풀도 조정해보고 여러 격리수준에서 테스트를 해봤는데, 생각보다 똑같은 현상을 재현하기가 힘들었다.
아직 이 원인을 찾지는 못했는데, 아마도 각 트랜잭션이 서로 GAP LOCK 충돌이 발생할 때가 있고, 그러지 않을 때가 있는 것 같다. 인덱스의 키가 JobName과 JobKey를 기반으로 생성되어있어서 이를 정확히 트레이싱 하는게 매우 힘들다
MySQL Gap Lock (두번째 이야기)
Why ?
medium.com
위 이유때문에 적절한 임계값을 찾을 수 없었다. 또한 APP과 DB의 네트워크 지연 및 DB의 다른 문제들로 인해 설정한 임계값이 제대로 작동하지 않을 수 있음에 이 방법을 선택할 수 없었다.
2번은 1번과 해결방법이 비슷한데, 문제점도 비슷했다.
이 또한 데드락이 발생하지 않는 JOB 개수의 임계값을 적당히 설정해야 하는데, 1번과 같은 이유로 정확히 판단할 수가 없어서 선택하지 못했다.
최종적으로는 3번 방법을 사용했다.
기존 라이브러리에서 제공하는 jobRepository 생성 함수를 오버라이드 해서 사용할 수 있다.
@Configuration
public class BatchConfig extends DefaultBatchConfiguration {
private final DataSource dataSource;
private final PlatformTransactionManager platformTransactionManager;
public BatchConfig(
@Qualifier(value = "metaDataSource") DataSource dataSource,
@Qualifier(value = "metaTransactionManager") PlatformTransactionManager platformTransactionManager) {
this.dataSource = dataSource;
this.platformTransactionManager = platformTransactionManager;
}
@Override
public JobRepository jobRepository() {
JobRepositoryFactoryBean jobRepositoryFactoryBean = new JobRepositoryFactoryBean();
try {
jobRepositoryFactoryBean.setDataSource(dataSource);
jobRepositoryFactoryBean.setTransactionManager(platformTransactionManager);
jobRepositoryFactoryBean.setDatabaseType(DatabaseType.fromMetaData(dataSource).name());
jobRepositoryFactoryBean.setIncrementerFactory(new DefaultDataFieldMaxValueIncrementerFactory(dataSource));
jobRepositoryFactoryBean.setClobType(getClobType());
jobRepositoryFactoryBean.setTablePrefix(getTablePrefix());
jobRepositoryFactoryBean.setSerializer(getExecutionContextSerializer());
jobRepositoryFactoryBean.setConversionService(getConversionService());
jobRepositoryFactoryBean.setJdbcOperations( new JdbcTemplate(dataSource));
jobRepositoryFactoryBean.setLobHandler(getLobHandler());
jobRepositoryFactoryBean.setCharset(getCharset());
jobRepositoryFactoryBean.setMaxVarCharLength(getMaxVarCharLength());
jobRepositoryFactoryBean.setIsolationLevelForCreateEnum(Isolation.READ_COMMITTED);
jobRepositoryFactoryBean.setValidateTransactionState(getValidateTransactionState());
jobRepositoryFactoryBean.afterPropertiesSet();
return jobRepositoryFactoryBean.getObject();
}
catch (Exception e) {
throw new BatchConfigurationException("Unable to configure the default job repository", e);
}
}
}
격리수준만 GAP_LOCK을 피할 수 있게 READ_COMMITTED로 바꿨다.
기본 라이브러리에서 SERIALIZABLE를 사용하는 만큼 바꾸기가 두려웠는데, 아무리 생각해도 메타테이블에 접근하는 여러 트랜잭션들의 격리수준을 READ_COMMITTED로 바꿔도 문제가 없을 것 같다고 판단했다.
아직 프로덕션 환경에 적용하기 까지는 시간이 좀 남아서 일단 지켜보기로 결정했다. 테스트 환경에서 문제가 없다면 프로덕션에 배포해도 괜찮겠죠!..!...............
테스트 환경에서 모니터링을 해보고 문제가 있다면 1또는 2방법을 적용한 내용을 다시 추가해야겠다. (없다면 성공한걸로)
'내가 잊어버리기 싫어서 적는 개발 지식' 카테고리의 다른 글
| [Spring + Kafka] 대용량 스트림 메시지 구독 설계 (1) | 2024.11.01 |
|---|---|
| [MySQL] DB 재시작과 auto_increment의 관계성 (0) | 2024.01.30 |
| [Spring JPA] 한 트랜잭션 내부에서의 외부 API 콜과 엮인 영속성 문제 (3) | 2024.01.12 |
