SERIALIZABLE을 사용할 경우 데드락이 발생하는 이유가 뭘까?

Database/SQL

SERIALIZABLE을 사용할 경우 데드락이 발생하는 이유가 뭘까?

챔🐻 2024. 2. 9. 20:37

아래는 저의 삽질 과정이 적혀져있으니 결론이 궁금하신 분들은 위 목차에서 ‘결론’으로 가시면 됩니다.

👀의문점

성능 테스트를 위해 Isolation Level Serializable을 적용하고 재고 499개 상태에서 100개의 쓰레드를 사용하여 동일한 5개 상품에 대한 총 500개의 주문을 시도를 해보려고 했으나 데드락이 발생하였다.

나는 Serializable의 단점으로 모든 걸 순차적으로 실행하기 때문에 속도가 느리다는 것 말고는 몰랐었는데.. 이 테스트로 Serializable 격리 수준에서 데드락이 발생할 수 있다는 걸 처음 알았다.

내가 생각한 serializable 데드락 시나리오

아래가 일반적인 데드락이 발생하는 시나리오라는데 왜 데드락이 발생하는지 전혀 이해가 되지 않았다.

	트랜잭션 A	트랜잭션 B
1	select ~ where id = 1 for share;
2		select ~ where id = 1 for share;
3	update ~ where id = 1
4		update ~ where id = 1;
5	DEAD LOCK	DEAD LOCK
6		ROLL BACK
7	배타 락 획득 후 업데이트 쿼리 실행
8	COMMIT [ 배타락 반환 ]

나는 트랜잭션 B가 2번에서 조회가 끝나고 S-Lock을 반납하면, 트랜잭션 A가 X-Lock을 얻어서 update를 수행할 수 있을 줄 알았다. 그런데 왜 데드락이 발생하는 건지가 의문이었다.

그리고 S-Lock(공유 락)을 보유한 트랜잭션이 데이터를 변경하기 위해 X-Lock(배타 락)으로 전환하려면, 기존의 모든 S-Lock이 해제된 상태여야 한다고 알고 있다. 나는 S-Lock이 트랜잭션이 종료되지 않아도 조회가 끝나면 Lock이 자동으로 반환된다고 생각했기 때문에(잘못된 지식 ㅎㅎ,,,,), 트랜잭션B의 2번 조회 완료 후 S-Lock이 해제되고, 이후 트랜잭션A가 X-Lock을 획득하여 업데이트를 원활하게 진행할 것으로 예상했다.

데드락 MySQL 로그

=====================================
2024-02-04 10:56:13 0x179f3b000 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 4 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 380 srv_active, 0 srv_shutdown, 213480 srv_idle
srv_master_thread log flush and writes: 0
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 7025
OS WAIT ARRAY INFO: signal count 6733
RW-shared spins 0, rounds 0, OS waits 0
RW-excl spins 0, rounds 0, OS waits 0
RW-sx spins 0, rounds 0, OS waits 0
Spin rounds per wait: 0.00 RW-shared, 0.00 RW-excl, 0.00 RW-sx
------------------------
LATEST DETECTED DEADLOCK
------------------------
2024-02-04 10:56:11 0x178a5f000
*** (1) TRANSACTION:
TRANSACTION 801177, ACTIVE 0 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 4 lock struct(s), heap size 1128, 2 row lock(s)
MySQL thread id 13761, OS thread handle 6338752512, query id 556491 localhost 127.0.0.1 root updating
UPDATE prod_opt
        SET INV_QTY = INV_QTY - 1
        WHERE OPT_COMB_NO = 1

*** (1) HOLDS THE LOCK(S):
RECORD LOCKS space id 214 page no 9 n bits 408 index PRIMARY of table `syusyu`.`prod_opt` trx id 801177 lock mode S locks rec but not gap
Record lock, heap no 2 PHYSICAL RECORD: n_fields 13; compact format; info bits 0
 0: len 4; hex 80000001; asc     ;;
 1: len 6; hex 0000000c3997; asc     9 ;;
 2: len 7; hex 02000001a02cbc; asc      , ;;
 3: len 4; hex 80002711; asc   ' ;;
 4: len 4; hex 80000000; asc     ;;
 5: len 4; hex 8000000a; asc     ;;
 6: len 4; hex 649d3e1a; asc d > ;;
 7: len 4; hex 80013880; asc   8 ;;
 8: SQL NULL;
 9: SQL NULL;
 10: SQL NULL;
 11: SQL NULL;
 12: len 1; hex 4e; asc N;;


*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 214 page no 9 n bits 408 index PRIMARY of table `syusyu`.`prod_opt` trx id 801177 lock_mode X locks rec but not gap waiting
Record lock, heap no 2 PHYSICAL RECORD: n_fields 13; compact format; info bits 0
 0: len 4; hex 80000001; asc     ;;
 1: len 6; hex 0000000c3997; asc     9 ;;
 2: len 7; hex 02000001a02cbc; asc      , ;;
 3: len 4; hex 80002711; asc   ' ;;
 4: len 4; hex 80000000; asc     ;;
 5: len 4; hex 8000000a; asc     ;;
 6: len 4; hex 649d3e1a; asc d > ;;
 7: len 4; hex 80013880; asc   8 ;;
 8: SQL NULL;
 9: SQL NULL;
 10: SQL NULL;
 11: SQL NULL;
 12: len 1; hex 4e; asc N;;


*** (2) TRANSACTION:
TRANSACTION 801178, ACTIVE 0 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 4 lock struct(s), heap size 1128, 2 row lock(s)
MySQL thread id 13762, OS thread handle 6344323072, query id 556490 localhost 127.0.0.1 root updating
UPDATE prod_opt
        SET INV_QTY = INV_QTY - 1
        WHERE OPT_COMB_NO = 1

*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 214 page no 9 n bits 408 index PRIMARY of table `syusyu`.`prod_opt` trx id 801178 lock mode S locks rec but not gap
Record lock, heap no 2 PHYSICAL RECORD: n_fields 13; compact format; info bits 0
 0: len 4; hex 80000001; asc     ;;
 1: len 6; hex 0000000c3997; asc     9 ;;
 2: len 7; hex 02000001a02cbc; asc      , ;;
 3: len 4; hex 80002711; asc   ' ;;
 4: len 4; hex 80000000; asc     ;;
 5: len 4; hex 8000000a; asc     ;;
 6: len 4; hex 649d3e1a; asc d > ;;
 7: len 4; hex 80013880; asc   8 ;;
 8: SQL NULL;
 9: SQL NULL;
 10: SQL NULL;
 11: SQL NULL;
 12: len 1; hex 4e; asc N;;


*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 214 page no 9 n bits 408 index PRIMARY of table `syusyu`.`prod_opt` trx id 801178 lock_mode X locks rec but not gap waiting
Record lock, heap no 2 PHYSICAL RECORD: n_fields 13; compact format; info bits 0
 0: len 4; hex 80000001; asc     ;;
 1: len 6; hex 0000000c3997; asc     9 ;;
 2: len 7; hex 02000001a02cbc; asc      , ;;
 3: len 4; hex 80002711; asc   ' ;;
 4: len 4; hex 80000000; asc     ;;
 5: len 4; hex 8000000a; asc     ;;
 6: len 4; hex 649d3e1a; asc d > ;;
 7: len 4; hex 80013880; asc   8 ;;
 8: SQL NULL;
 9: SQL NULL;
 10: SQL NULL;
 11: SQL NULL;
 12: len 1; hex 4e; asc N;;

*** WE ROLL BACK TRANSACTION (2)
------------
TRANSACTIONS
------------
Trx id counter 801188
Purge done for trx's n:o < 801188 undo n:o < 0 state: running but idle
History list length 12
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 281480386120832, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 281480386120040, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 281480386119248, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
--------
FILE I/O
--------
I/O thread 0 state: waiting for i/o request ((null))
I/O thread 1 state: waiting for i/o request (insert buffer thread)
I/O thread 2 state: waiting for i/o request (read thread)
I/O thread 3 state: waiting for i/o request (read thread)
I/O thread 4 state: waiting for i/o request (read thread)
I/O thread 5 state: waiting for i/o request (read thread)
I/O thread 6 state: waiting for i/o request (write thread)
I/O thread 7 state: waiting for i/o request (write thread)
I/O thread 8 state: waiting for i/o request (write thread)
Pending normal aio reads: [0, 0, 0, 0] , aio writes: [0, 0, 0, 0] ,
 ibuf aio reads:
Pending flushes (fsync) log: 0; buffer pool: 0
1181 OS file reads, 137311 OS file writes, 89120 OS fsyncs
0.00 reads/s, 0 avg bytes/read, 20.93 writes/s, 15.42 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 0, seg size 2, 0 merges
merged operations:
 insert 0, delete mark 0, delete 0
discarded operations:
 insert 0, delete mark 0, delete 0
Hash table size 34679, node heap has 2 buffer(s)
Hash table size 34679, node heap has 1 buffer(s)
Hash table size 34679, node heap has 1 buffer(s)
Hash table size 34679, node heap has 4 buffer(s)
Hash table size 34679, node heap has 2 buffer(s)
Hash table size 34679, node heap has 2 buffer(s)
Hash table size 34679, node heap has 1 buffer(s)
Hash table size 34679, node heap has 1 buffer(s)
38.24 hash searches/s, 11.50 non-hash searches/s
---
LOG
---
Log sequence number          907910858
Log buffer assigned up to    907910858
Log buffer completed up to   907910858
Log written up to            907910858
Log flushed up to            907910858
Added dirty pages up to      907910858
Pages flushed up to          907899930
Last checkpoint at           907899930
Log minimum file id is       268
Log maximum file id is       277
98399 log i/o's done, 12.25 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total large memory allocated 0
Dictionary memory allocated 851227
Buffer pool size   8191
Free buffers       6027
Database pages     2150
Old database pages 773
Modified db pages  21
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 2, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 1133, created 1017, written 30485
0.00 reads/s, 0.22 creates/s, 7.93 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 2150, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
0 read views open inside InnoDB
Process ID=2301, Main thread ID=0x178c8f000 , state=sleeping
Number of rows inserted 81505, updated 13637, deleted 0, read 122549
7.50 inserts/s, 1.50 updates/s, 0.00 deletes/s, 12.00 reads/s
Number of system rows inserted 39, updated 374, deleted 16, read 68564
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================

❓ 원인 추론 & 해결책 시도

데드락이 대체 왜 발생하는 건지 알고 싶어서 로그를 살펴보았다. 하지만 로그를 봐도 이해가 될리가 없었다.. 왜냐..? 애초에 락 개념을 잘못 알고있었으니까..

트랜잭션 간의 lock 반환 및 획득 과정에 대한 잘못 알고 있었던 게 원인이었다.
알고보니.. 나는 조회를 할 때 S-Lock을 걸었으면 트랜잭션이 종료되지 않아도 그 문장의 실행이 끝나면 락이 반환되는 줄 알았다. 하지만 S-Lock이어도 그 Lock은 트랜잭션 단위로 관리되고, 트랜잭션이 종료되어야 Lock이 반환된다고 한다.

💡S-Lock이나 X-Lock은 획득 시 트랜잭션이 커밋되거나 롤백될 때까지 유지된다.

⇒ 트랜잭션 단위로 락이 관리됨.

✔결론(Serializable에서 데드락이 발생하는 이유)

교착상태(Deadlock, 데드락)이란?

데드락은 두 세션이 서로 접근하려는 리소스에 대해 잠금을 설정하고, 양측 모두 상대방의 잠금이 해제될 때까지 진행을 멈춘 상태를 의미한다. 이 상황은 어느 한 쪽이 물러나지 않는 이상 해결될 수 없으며, 좁은 골목에서 마주친 두 대의 차량이 서로 지나갈 수 없는 상태에 비유할 수 있다.

데이터베이스에서 교착상태가 발생하면, 이를 먼저 인지한 세션은 문제를 일으킨 특정 명령문에 대해 롤백을 수행하고 에러 메시지를 발생시킨다. 한 세션의 잠금이 해제되면, 이로 인해 나머지 세션도 원활하게 진행될 수 있게 되어 문제가 해결된다.

S-Lock과 X-Lock

공유락(Shared Lock / 읽기 락 / S-Lock)
- 여러 트랜잭션이 동시에 데이터를 읽을 수 있도록 허용하는 락
- 트랜잭션이 객체를 읽기 원한다면 먼저 독점 모드로 잠금을 획득해야 한다. 동시에 여러 트랜잭션이 공유 모드로 잠금을 획득하는 것은 허용되지만 만약 그 객체에 이미 독점 모드로 잠금을 획득한 트랜잭션이 있으면 이 트랜잭션이 완료될 때까지 기다려야 한다.

배타락(Exclusive Lock / 쓰기 락 / X-Lock)
- 배타락은 데이터를 수정할 때 사용되는 락으로, 한 번에 하나의 트랜잭션만 데이터에 접근할 수 있게 한다.
- 트랜잭션이 객체에 쓰기를 원한다면 먼저 독점 모드로 잠금을 획득해야 한다. 다른 어떤 트랜잭션도 동시에 잠금을 획득할 수 없으므로(공유 모드든지 독점 모드든지) 그 객체에 잠금이 존재한다면 트랜잭션은 대기해야 한다.

Serializable 격리 수준에서의 데드락 발생 시나리오

	트랜잭션 A	트랜잭션 B	설명
1	select ~ where id = 1 for share;		트랜잭션 A가 id = 1 row에 대한 S-Lock 획득
2		select ~ where id = 1 for share;	트랜잭션 B가 id = 1 row에 대한 S-Lock 획득
3	update ~ where id = 1		트랜잭션 A가 업데이트를 위해 X-Lock을 요청하지만, 트랜잭션 B가 S-Lock을 보유 중이기 때문에 락을 반환할 때까지 기다린다.
4		update ~ where id = 1;	트랜잭션 B도 업데이트를 위해 X-Lock을 요청하지만, 트랜잭션 A가 S-Lock을 보유 중이기 때문에 락을 반환할 때까지 기다린다.
5	DEAD LOCK	DEAD LOCK	이제 두 트랜잭션 모두 서로 S-Lock을 반환할 때까지 계속 대기하게된다 → 데드락
6		ROLL BACK	DBMS가 데드락을 감지하고 해결하기 위해 트랜잭션 B를 강제로 롤백시킨다. 이때 S-Lock이 반환된다.
7	[ acquires a exclusive lock → execute update query ]		트랜잭션 B가 롤백되어 X-Lock을 얻을 수 있게 되었다. 트랜잭션 A는 락을 얻어 업데이트를 수행한다.
8	COMMIT [ release exclusive lock ]		작업이 완료되고 커밋한다. 트랜잭션 A가 보유하고 있던 X-Lock이 해제된다.

🔜 나가며

직접 테스트를 통해 Serializable 격리 수준이 왜 동시성 측면에서 최악인지 바로 알 수 있었다. 데드락이 발생하고 트랜잭션이 계속 롤백되기 때문에, 이 격리 수준에서는 한 번에 하나의 작업만 처리할 수 있고 병렬 처리가 불가능하다는 걸 직접 경험할 수 있었다.

데드락에 대한 사전정의는 알고 있었지만, 실제로 누군가에게 이 개념을 설명해야 할 때 명확하게 설명하지 못했었다. 실제로 겪어본적도 없고 이론으로만 대충 알고 있었으니 당연했다 이번 경험을 통해 역시 직접 겪어보는 게 이론적으로만 배운 지식의 이해도가 깊어지고, 기억에도 더 오래 남는다는 것을 새삼 또 깨달았다.

왜 많은 선배 개발자들이 에러를 많이 내보라고하는 조언을 많이 해주시는지 이번 경험을 통해 뼈저리게 느꼈다. 에러를 많이 내본 사람이 왜 폭발적인 성장을하는지도 알 것 같다. 이전의 나는 오류를 피하려고만 하고, 빠른 해결 하려고 효율성만을 추구했었다. 동료들이 겪는 기상천외한 오류들을 보며 어떻게하면 저런 에러가 날 수 있는거지..? 싶은 상황이 많았었다 ㅋㅋㅋ 에러를 마주하고, 그 문제를 어떻게 해결할지 고민하고 접근하는 과정을 반복하면서 나만의 문제 해결 프로세스를 정립하는데 많이 도움이 되었다. 그리고 이런 경험들이 쌓이면서 앞으로 더 어려운 문제를 만나게 되었을 때 두려워하지 않고 즐기면서 해결할 수 있는 힘이 될 것이다.

마지막으로, 책을 통한 학습만으로는 한계가 있다는 것도 깨달았다. 실제로 적용해보고 오류를 경험하며, 예상치 못한 상황에 직면해보는 것이 제대로된 학습인 것 같다는 생각을 많이 했다.

실제로 테스트 해보지 않았다면 나는 앞으로 계속 잘못된 지식을 가지고 있었겠지..?

Ref

Uploaded by N2T