Error Message

could not execute statement; SQL [n/a]; nested exception is org.hibernate.exception.LockAcquisitionException: could not execute statement\
org.springframework.dao.CannotAcquireLockException: could not execute statement; SQL [n/a]; nested exception is 
...
Caused by: org.hibernate.exception.LockAcquisitionException: could not execute statement\
...
Caused by: com.mysql.cj.jdbc.exceptions.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction\
...

---

Error 원인 찾기

주요 Error Message 정리

org.springframework.dao.CannotAcquireLockException
org.hibernate.exception.LockAcquisitionException
com.mysql.cj.jdbc.exceptions.MySQLTransactionRollbackException
Deadlock found when trying to get lock

Error 로그 분석

Error Log를 분석 결과 card table에 row를 insert 하는 시기에 발생하는 것을 알 수 있었다. 참고로 card table은 구매 상품과 맴버에 unique 조건이 걸려 있다.

구글 검색 및 대상 설정

찾아본 자료 중 제일 가능성이 높다고 판단 한 것은 innodb에 insertion하는 상황에서 Deadlock이 발생하는 경우이다.

MySQL, Insertion, Deadlock
출처: innodb-locks-set

가설에 대한 요약

스토리를 요약해 보면
1. session 1은 row에 exclusive lock을 획득한다.
2. session 2, 3은 duplicate-key error가 발생하고 이에 따라서 row에 shared lock을 각각 요청한다.
3. 이때 session 1이 rollback을 하게 되면 exclusive lock이 해제되고 이에 따라 session 2, 3의 shared lock이 요청 대기에서 승인 상태로 변경된다.
4. Deadlock: 이 상황에서 session 2, 3은 서로 shared lock을 획득한 상황이기 때문에 exclusive lock을 획득할 수 없게 된다.

---

가설 검증

Docker로 MySQL 띄우기

참고: MySQL Docker로 띄우기

MySQL docker image download

$ docker pull mysql:latest

Docker container 생성 및 실행

$ docker run --name mysql_53306 -p 53306:3306 -e MYSQL_ROOT_PASSWORD=53306 -e TZ=Asia/Seoul --restart=always -d mysql:latest

Docker container 실행 확인

$ docker ps

테스트하는 동안만 사용하고 지울 예정이기 때문에 port와 비밀번호를 임의로 53306으로 하였음

Data Grip 연결 및 테이블 생성

Schema 생성

create schema s_deadlock_test collate utf8_general_ci;

Table 생성

create table s_deadlock_test.t_card
(
    card_seq int auto_increment,
    mem_seq  int not null,
    sale_seq int not null,
    constraint t_card_pk
        primary key (card_seq)
);

create unique index t_card_mem_seq_sale_seq_uindex
    on s_deadlock_test.t_card (mem_seq, sale_seq);
    
# 나중에 태스트를 위한 
create table s_deadlock_test.t_property
(
    property_seq int auto_increment
        primary key,
    `key`        varchar(255) not null,
    value        varchar(255) not null
);
    

Data grip을 통한 Simulation

session을 3개 준비하고 모두 commit을 manual로 설정해 놓았다.
session 1,2,3 를 차례대로 실행해 본다.

session 1: insert into s_deadlock_test.t_card (mem_seq, sale_seq) values (1, 1);
session 2: insert into s_deadlock_test.t_card (mem_seq, sale_seq) values (1, 1);
session 3: insert into s_deadlock_test.t_card (mem_seq, sale_seq) values (1, 1);

# 나중에 태스트를 위한 
insert into s_deadlock_test.t_property (`key`, value) VALUES ('thread_sleep', 'yes');
insert into s_deadlock_test.t_property (`key`, value) VALUES ('thread_sleep', 'no');

Data에 Lock이 적용된 사항을 확인할 수 있다.

확인용: select * from performance_schema.data_locks;

1. 각 테이블에는 IX(Intent Exclusive) 가 승인된 걸 확인 할 수 있다.
2. X(Exclusive Lock) 이 승인 된 상태이고 S(Shared Lock)은 요청 상태임을 확인할 수 있다.

이제 session 1을 rollback 시킨다.

rollback;

위에서 이야기 했던 Deadlock (session 2, 3이 shared lock을 얻어서 exclusive lock을 얻지 못하는 상황)이 발생하는 것을 확인 할 수 있었다.

프로그램에서 Error message 확인해 보기

Spring boot project 생성

• Name: mysql-deadlock-example
• Location: 원하는 위치에
• Language: Java
• Type: Maven
• Group: me.kevin
• JDK: 17 (8, 11, 17 중 자유롭게 선택)
• Java: 17 (8, 11, 17 중 자유롭게 선택)
• Packaging: Jar

Dependencies

• Spring Boot DevTools
• Spring Web
• Lombok
• Spring Data JPA
• MySQL Driver

소스코드 위치

https://github.com/ashappyasitis/mysql-deadlock-example.git

테스트 Process

1. 프로젝트를 실행 시킨다. (http://localhost:20000)
2. 순서1: 카드 추가 시도 - 10 초후 롤백
   POST /api/v1/cards 호출 ({propertySeq:1, memSeq: 1, saleSeq: 1}) - propertySeq:1 인 경우 - 10 초 후 rollback 예정
3. 순서2: 카드 추가 시도
   POST /api/v1/cards 호출 ({propertySeq:2, memSeq: 1, saleSeq: 1})
4. 순서3: 카드 추가 시도
   POST /api/v1/cards 호출 ({propertySeq:2, memSeq: 1, saleSeq: 1})
5. Exception Error Message 확인

# 순서1: 카드 추가 시도 - 10 초후 롤백
curl --location --request POST 'http://localhost:20000/api/v1/cards' \
--header 'Content-Type: application/json' \
--data-raw '{
    "propertySeq": 1,
    "memSeq": 1,
    "saleSeq": 1
}'

# 순서2: 카드 추가 시도
curl --location --request POST 'http://localhost:20000/api/v1/cards' \
--header 'Content-Type: application/json' \
--data-raw '{
    "propertySeq": 2,
    "memSeq": 1,
    "saleSeq": 1
}'

# 순서3: 카드 추가 시도
curl --location --request POST 'http://localhost:20000/api/v1/cards' \
--header 'Content-Type: application/json' \
--data-raw '{
    "propertySeq": 2,
    "memSeq": 1,
    "saleSeq": 1
}'

Error Message 확인

...
Caused by: org.hibernate.exception.LockAcquisitionException: could not execute statement\
...
Caused by: com.mysql.cj.jdbc.exceptions.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction\
...

검증완료