이번 시간에는 MySQL의 1205 Lock wait timeout과 1213 Deadlock을 직접 만들어 보며, 두 오류 뒤에 트랜잭션이 어떤 상태로 남는지, 1205를 받았을 때 무엇을 먼저 해야 하는지 배워가는 시간입니다.
예를 들어서 주문 API 로그에 두 가지 오류가 섞여 찍혀 있다고 해볼게요.
ERROR 1205 (HY000): Lock wait timeout exceeded; try restarting transaction
ERROR 1213 (40001): Deadlock found when trying to get lock; try restarting transaction
두 메시지 모두 try restarting transaction으로 끝나죠. 그러니 같은 재시도 코드로 처리하면 될 것 같아 보입니다.
그런데 두 오류가 난 직후 트랜잭션의 상태는 달라요.
실습 준비
이 글의 명령은 모두 실습 코드의 mysql-lock-wait-timeout/ 디렉터리에서 실행합니다.
compose.yaml: MySQL 8.4 컨테이너 정의(innodb_rollback_on_timeout을 환경 변수로 받음)setup.sql:shop.stock에 keyboard와 mouse 재고를 넣는 SQLwait_one.sql: 잠긴 행을 UPDATE하며 기다린 시간을 재는 SQLtx_a.sql: 두 행을 서로 반대 순서로 바꿔 deadlock을 만드는 SQL(트랜잭션 A)tx_b.sql: 같은 SQL의 트랜잭션 Bset_order.sql: 세트 주문 트랜잭션에서 1205 뒤의 상태를 보는 SQL
먼저 Docker로 MySQL 8.4를 띄울게요(compose.yaml).
innodb_rollback_on_timeout은 서버를 시작할 때만 정할 수 있어요. 그래서 환경 변수로 값을 바꿔 다시 띄울 수 있게 해 두었습니다. 지정하지 않으면 기본값인 OFF로 떠요. 이 글에서는 이 환경 변수를 쓰지 않아요.
name: lwt
services:
mysql:
image: mysql:8.4
command: ["mysqld", "--innodb-rollback-on-timeout=${ROLLBACK_ON_TIMEOUT:-OFF}"]
environment:
MYSQL_ROOT_PASSWORD: root
ports:
- "3391:3306"
setup.sql은 상품 재고 테이블 shop.stock을 만들고 keyboard(1번)와 mouse(2번)의 재고를 10개씩 넣어요.
다음으로 명령을 짧게 쓸 수 있도록 셸 함수 세 개를 만들어 놓을게요.
sql은 컨테이너 안의 mysql 클라이언트를 실행하는 함수예요. MYSQL_PWD 환경 변수로 비밀번호를 넘기는 방식은 실습에서만 써 주세요.
hold는 다른 세션에서 1번 행(keyboard)을 잠근 채 트랜잭션을 열어 두고, 잠금이 실제로 잡힐 때까지 기다려요. release를 부르면 그 세션이 롤백해 잠금을 놓는다고 보시면 됩니다.
아래 블록은 파일로 만들지 말고 실습 디렉터리에서 연 터미널에 그대로 붙여 넣어 주세요. 이후 명령은 모두 이 터미널에서 실행하고, 터미널을 새로 열면 다시 붙여 넣으시면 됩니다.
docker compose up -d
sql() { docker compose exec -T -e MYSQL_PWD=root mysql mysql -uroot "$@"; }
hold() {
rm -f go; mkfifo go
{ echo "BEGIN; UPDATE shop.stock SET qty = qty - 1 WHERE id = 1;"; read -r _ < go; echo "ROLLBACK;"; } | sql &
until sql -N -e "SELECT COUNT(*) FROM performance_schema.data_locks WHERE LOCK_TYPE = 'RECORD';" | grep -qx 1; do sleep 0.2; done
}
release() { echo done > go; wait; rm -f go; }
until sql -e "SELECT 1" > /dev/null 2>&1; do sleep 2; done
sql < setup.sql
관련 설정의 기본값부터 확인해 볼게요.
sql -t -e "SELECT @@innodb_lock_wait_timeout, @@innodb_rollback_on_timeout, @@innodb_deadlock_detect;"
+----------------------------+------------------------------+--------------------------+
| @@innodb_lock_wait_timeout | @@innodb_rollback_on_timeout | @@innodb_deadlock_detect |
+----------------------------+------------------------------+--------------------------+
| 50 | 0 | 1 |
+----------------------------+------------------------------+--------------------------+
innodb_lock_wait_timeout: 행 잠금을 기다리는 최대 시간(초)이에요. 기본값은 50초입니다.innodb_rollback_on_timeout: 1205가 났을 때 트랜잭션 전체를 롤백할지 정해요. 기본값은OFF(0)입니다.innodb_deadlock_detect: deadlock을 바로 감지할지 정해요. 기본값은ON(1)입니다.
실습 1: 1205는 설정한 시간을 다 기다린 뒤에 납니다
50초를 기다리기는 기니까 세션에서만 5초로 줄여 볼게요.
wait_one.sql은 세션의 innodb_lock_wait_timeout을 5로 바꾼 뒤 1번 행의 재고를 1 줄이는 UPDATE를 실행해요. 그리고 그 UPDATE가 기다린 시간을 waited_sec로 찍습니다.
hold로 1번 행을 잠가 둔 채 실행해 주세요. mysql 클라이언트는 오류가 나면 거기서 멈추기 때문에, --force를 붙여 오류가 난 뒤에도 다음 문장을 실행하게 했어요.
hold
sql -t --force < wait_one.sql
release
ERROR 1205 (HY000) at line 3: Lock wait timeout exceeded; try restarting transaction
+------------+
| waited_sec |
+------------+
| 5.0122 |
+------------+
출력을 보면 설정한 5초를 채운 뒤에 1205가 났어요.
이때 잠금을 쥔 세션은 아무 일도 하지 않고 트랜잭션만 열어 두고 있었습니다. 이 세션이 끝나지 않는 한, 몇 번을 다시 시도해도 같은 오류가 나요.
실습 2: 1213은 timeout을 기다리지 않습니다
이번에는 deadlock을 만들어 볼게요.
tx_a.sql(트랜잭션 A)은 트랜잭션 안에서 1번 행을 먼저 바꾸고, DO SLEEP(4) 뒤에 2번 행을 바꾼 다음 ROLLBACK해요. 두 번째 UPDATE가 기다린 시간도 잽니다.
tx_b.sql(트랜잭션 B)은 같은 내용에서 행 순서만 바꿨어요. 2번 행을 먼저, 1번 행을 나중에 바꿉니다. 둘 다 timeout을 5초로 두고 0.5초 차이로 실행해 볼게요.
sql -t --force < tx_a.sql &
sleep 0.5
sql -t --force < tx_b.sql &
wait
ERROR 1213 (40001) at line 6: Deadlock found when trying to get lock; try restarting transaction
+-----+------------+
| trx | waited_sec |
+-----+------------+
| B | 0.0036 |
+-----+------------+
+-----+------------+
| trx | waited_sec |
+-----+------------+
| A | 0.5005 |
+-----+------------+
B는 기다림을 순환으로 만든 순간 1213을 받았어요. 여기서 눈여겨볼 건 timeout을 5초로 줬는데도 기다린 시간이 0.0036초라는 점이에요.
A는 B가 롤백되기까지 0.5초를 기다린 뒤 2번 행을 얻었습니다.
InnoDB가 deadlock을 감지하는 기능(innodb_deadlock_detect)이 켜져 있으면, deadlock에는 innodb_lock_wait_timeout이 적용되지 않는다는 뜻이에요.
실습 3: 1205 뒤에도 트랜잭션은 열려 있습니다
예를 들어서 우리가 키보드와 마우스를 한 세트로 파는 주문을 처리한다고 해볼게요. 두 상품의 재고를 한 트랜잭션에서 하나씩 줄여야 합니다.
set_order.sql은 세션 timeout을 3초로 두고 mouse(2번)를 먼저 줄이고 keyboard(1번)를 줄여요. 그 뒤 오류가 나도 트랜잭션 안에서 재고와 잠금을 확인하고 커밋합니다.
애플리케이션이 예외를 잡고 로그만 남긴 채 다음 코드를 실행하는 상황과 같다고 보시면 됩니다.
hold
sql -t --force < set_order.sql
release
sql -t -e "SELECT * FROM shop.stock;"
ERROR 1205 (HY000) at line 4: Lock wait timeout exceeded; try restarting transaction
+----+----------+------+
| id | item | qty |
+----+----------+------+
| 1 | keyboard | 10 |
| 2 | mouse | 9 |
+----+----------+------+
+-------------+-----------+---------------+-----------+
| OBJECT_NAME | LOCK_TYPE | LOCK_MODE | LOCK_DATA |
+-------------+-----------+---------------+-----------+
| stock | TABLE | IX | NULL |
| stock | RECORD | X,REC_NOT_GAP | 2 |
+-------------+-----------+---------------+-----------+
+----+----------+------+
| id | item | qty |
+----+----------+------+
| 1 | keyboard | 10 |
| 2 | mouse | 9 |
+----+----------+------+
keyboard를 줄이는 4번째 줄에서 1205가 났어요.
그런데 그 뒤 같은 트랜잭션 안에서 보면 mouse 재고는 9로 줄어 있고, 2번 행의 배타 잠금(X,REC_NOT_GAP)도 그대로 쥐고 있습니다. 롤백된 것은 keyboard를 줄이던 문장 하나뿐이에요.
이 상태로 COMMIT하자 mouse만 줄어든 재고가 저장됐어요. 세트 주문이 절반만 처리된 거죠.
트랜잭션이 열려 있는 동안에는 2번 행의 잠금도 풀리지 않아요.
그래서 오류를 받은 뒤 커밋도 롤백도 하지 않고 연결을 붙잡고 있으면, 이번에는 이 트랜잭션이 다른 요청을 기다리게 만듭니다.
정리
범위: MySQL 8.4(mysql:8.4) 단일 서버, 실습 세션의 innodb_lock_wait_timeout은 3~5초.
- 다른 세션이 1번 행을 잠근 채 아무것도 하지 않자 timeout 5초인 UPDATE는 5.0122초를 채운 뒤 1205를 받았어요. 잠금을 쥔 세션이 끝나지 않으면 재시도해도 같은 오류가 나니, 재시도만으로 풀려고 하지 마세요.
- 순환이 생긴 deadlock에서 B는 timeout 5초와 상관없이 0.0036초 만에 1213을 받고 전체가 롤백됐습니다. deadlock을
innodb_lock_wait_timeout값으로 다루려 하지 마세요. - 기본값
innodb_rollback_on_timeout=OFF에서 1205 뒤에도 mouse 재고 9와 2번 행의 배타 잠금이 남았고, 그대로 COMMIT하자 세트 주문이 절반만 저장됐어요. 1205를 받으면 커밋하지 말고 먼저 ROLLBACK해 주세요. - 이 글에 싣지 않은 추가 측정에서는 1205를 받자
rollback()한 뒤 1초 쉬고 처음부터 다시 실행한 pymysql 예제는 두 번째 시도에서 커밋해 두 재고가 함께 9가 됐습니다. 1205를 받으면 ROLLBACK하고, 횟수를 제한해 트랜잭션을 처음부터 다시 실행하세요.