픽 태그 리스트 수정 시 발생했던 데드락 문제 해결기

[sangwonsheep]

개요

• [bug] pick tag 추가 시에 500 Internal Server Error #510

픽에 태그 추가, 삭제 시 에러가 발생했다는 이슈입니다.
왜 에러가 발생했는지 알아보기 위해 로그를 확인하였더니 데드락 문제임을 확인할 수 있었습니다.

[2024-11-21 10:02:44:50096524][http-nio-8080-exec-3] ERROR t.core.exception.level.ErrorLevel[38] - could not execute statement 
[Deadlock found when trying to get lock; try restarting transaction] 
[update pick set link_id=?,parent_folder_id=?,tag_order=?,title=?,updated_at=?,user_id=? where id=?]; 
SQL [update pick set link_id=?,parent_folder_id=?,tag_order=?,title=?,updated_at=?,user_id=? where id=?]

org.springframework.dao.CannotAcquireLockException: could not execute statement 
[Deadlock found when trying to get lock; try restarting transaction] 
[update pick set link_id=?,parent_folder_id=?,tag_order=?,title=?,updated_at=?,user_id=? where id=?]; 
SQL [update pick set link_id=?,parent_folder_id=?,tag_order=?,title=?,updated_at=?,user_id=? where id=?]

이를 어떻게 해결했는지에 대한 과정을 설명하도록 하겠습니다.

---

1차 수정

PickService의 updatePick 메서드에 있는 트랜잭션 제거

• [BUG] 픽 태그 리스트 수정 시 데드락 문제 수정 #514
  트랜잭션의 범위를 줄이면, 데드락 문제가 해결될 것이라 예상하여 트랜잭션 제거

public PickResult.Pick updatePick(PickCommand.Update command) {
    validatePickAccess(command.userId(), command.id());
    validateFolderAccess(command.userId(), command.parentFolderId());
    validateTagListAccess(command.userId(), command.tagIdOrderedList());
    return pickMapper.toPickResult(pickDataHandler.updatePick(command));
}

@Transactional
public Pick updatePick(PickCommand.Update command) {
    Pick pick = getPick(command.id());
    pick.updateTitle(command.title());
    
    if (command.parentFolderId() != null) {
	    Folder parentFolder = pick.getParentFolder();
	    Folder destinationFolder = folderRepository.findById(command.parentFolderId())
		    .orElseThrow(ApiFolderException::FOLDER_NOT_FOUND);
    
	    detachPickFromParentFolder(pick, parentFolder);
	    attachPickToParentFolder(pick, destinationFolder);
	    updatePickParentFolder(pick, destinationFolder);
    }
    if (command.tagIdOrderedList() != null) {
	    updateNewTagIdList(pick, command.tagIdOrderedList());
    }
    return pick;
}

데드락 문제 해결될 것이라 예상하였으나, LazyInitializationException 예외 발생

2024-11-21 12:27:50.427 ERROR 48154 --- [nio-8080-exec-1] t.core.exception.level.ErrorLevel        
: could not initialize proxy [techpick.core.model.link.Link#1] - no Session

org.hibernate.LazyInitializationException: could not initialize proxy [techpick.core.model.link.Link#1] - no Session

원인

1. Pick -> Link에 대해 지연 로딩으로 연관 관계를 지어놓은 상태
2. PickService의 updatePick에 있는 pickDataHandler.updatePick(command)의 반환 타입은 Pick Entity
3. 트랜잭션, 세션 종료 이후 PickService에서 Pick Entity를 dto로 변환할 때, Link에 접근하려고 하여 지연 로딩 예외가 발생한 것

해결 방안

1. 트랜잭션 범위 내에 있는 PickDataHandler에서 dto로 변환해서 넘겨준다.
2. Fetch join 사용
3. Link 연관 관계 Lazy -> Eager로 변경

1차 시도한 방법

• Link 연관 관계 Lazy -> Eager로 변경
• 1a70e86

결론

• 트랜잭션을 제거하였지만, 데드락 문제는 해결하지 못함.

---

2차 수정

픽의 태그를 삭제할 때 버그 발생 - ObjectOptimisticLockingFailureException

[2024-11-21 13:00:36:105156][http-nio-8080-exec-2] ERROR t.core.exception.level.ErrorLevel[38] 
Row was updated or deleted by another transaction (or unsaved-value mapping was incorrect) : [techpick.core.model.pick.PickTag#183]

org.springframework.orm.ObjectOptimisticLockingFailureException: 
Row was updated or deleted by another transaction (or unsaved-value mapping was incorrect) : [techpick.core.model.pick.PickTag#183]

---

원인

• 낙관적 락을 사용하지 않은 상태
• Pick 수정 시 PickTag 테이블의 row를 삭제할 때 문제 발생
• ObjectOptimisticLockingFailureException 예외 발생

낙관적 락(@Version)을 사용해야만 해당 예외가 발생할 것으로 예상하였다.
이 예외는 낙관적 락이 충돌하거나 버전 불일치하는 경우에 발생한다.

낙관적 락을 사용하지 않았는데 예외가 발생한 이유는 무엇일까?

1. 업데이트나 삭제 작업을 수행할 때, Hibernate는 적어도 한 개의 행에 영향을 미칠 것을 기대한다.
   작업이 0개의 행에 영향을 미치면, 예외가 발생한다.
2. 서로 다른 트랜잭션이 같은 row를 삭제할 때 발생할 수 있다.

예측되는 예외 발생 시나리오

1. 트랜잭션 A가 PickTag 엔티티를 읽는다.
2. 트랜잭션 B가 동일한 PickTag 엔티티를 삭제한다.
3. 트랜잭션 A가 PickTag 엔티티를 삭제하려고 하지만, 이미 트랜잭션 B에 의해 삭제되었음.
   삭제 작업은 0개의 행에 영향을 미치게 된다.
4. Hibernate는 영향받은 행이 없음을 감지하고 예외 발생

---

해결 방안

동시에 여러 트랜잭션이 같은 엔티티를 수정하거나 삭제해서는 안된다.
하나의 트랜잭션이 엔티티에 접근했으면 다른 트랜잭션은 접근해서는 안된다.

이 문제를 해결하기 위해 낙관적 락을 사용할까? 비관적 락을 사용할까?
위와 같은 상황에 비관적 락이 적합하다고 볼 수 있다.
다만 충돌이 많이 일어나지 않는 경우에는 오히려 낙관적 락이 더 좋다고 볼 수 있다.

update가 아닌 delete이기 때문에 충돌이 많이 발생할 것 같지 않다는 생각이다.
그 이유로 낙관적 락을 선택하였다.
또 다른 이유로는 비관적 락은 실제 DB row에 락을 걸기 때문에 낙관적 락에 비해 무겁고 성능에 영향을 미칠 수 있다.

---

해결 과정

낙관적 락을 선택한 것은 알겠지만, 낙관적 락으로 이 문제를 어떻게 해결해야 할까?
아래와 같은 순서로 진행하였다.

• PickTag 엔티티 - 낙관적 락 설정

@Version
private Integer version;

• PickDataHandler 수정 메서드 - 재시도 로직

@Retryable(
    value = {ObjectOptimisticLockingFailureException.class},
    maxAttempts = 3,
    backoff = @Backoff(delay = 100)
)
@Transactional
public Pick updatePick(PickCommand.Update command) {

낙관적 락을 설정하고 재시도 로직을 추가하지 않으면 ObjectOptimisticLockingFailureException 예외를 발생시키는 문제가 동일해진다.
해당 예외가 발생했을 때 재시도를 통해 다른 트랜잭션이 완료될 때까지 기다렸다가 작업을 재시도한다.
3번의 재시도에도 버전이 맞지 않지 않으면 예외를 던진다.

낙관적 락, 재시도를 적용했을 때 동작 과정

1. 트랜잭션 A가 PickTag를 삭제한다.
2. 트랜잭션 B가 동일한 PickTag를 삭제하려고 하면 버전이 불일치하게 되어 예외가 발생
3. Spring Retry가 동작하여 작업을 재시도한다.
4. 재시도 시, 트랜잭션 B는 최신 상태를 다시 읽고 삭제 작업을 수행한다.
5. 트랜잭션 B는 아래에 있는 메서드를 수행하게 되면서 최종적으로 아무런 예외도 발생시키지 않게 된다.
6. 결과적으로 하나의 PickTag만 삭제된다.

• PickDataHandler PickTag 삭제 메서드 수정

@Transactional
public void detachTagFromPickTag(Pick pick, Long tagId) {
    pickTagRepository.findByPickAndTagId(pick, tagId)
	    .ifPresent(pickTagRepository::delete);
}

PickTag 테이블에서 데이터를 가져온 엔티티를 가지고 삭제하도록 변경
why? 낙관적 락 version을 이용하려면 엔티티가 필요함.

결론

• 픽에 있는 태그 삭제 시 발생하는 예외 낙관적 락과 재시도 로직을 통해 해결

참고

https://www.inflearn.com/community/questions/228082/%EA%B8%B0%EB%B3%B8%ED%82%A4-%EC%A0%84%EB%9E%B5-max-1-%EB%AC%B8%EC%9D%98
https://developer-nyong.tistory.com/74

---

3차 수정

원인

첫 번째 시도였던 트랜잭션 범위를 좁혔지만 데드락 문제를 해결하지 못했음.
데드락 문제를 해결하기 이전에 데드락이 왜 발생했고, 어느 테이블에서 발생하는지 분석이 필요했다.
MySQL 콘솔에 들어가서 데드락을 분석했다.

-- InnoDB 상태
SHOW ENGINE INNODB STATUS;

해당 쿼리로 어느 테이블에서 데드락이 발생했는지 확인할 수 있다.
해당 테이블에 걸린 잠금이 왜 데드락을 유발했는지 시스템을 분석해서 해결해야 한다.

-- 현재 LOCK이 걸려 대기중인 정보
SELECT * FROM information_schema.INNODB_LOCK_WAITS;

-- LOCK을 건 정보
SELECT * FROM information_schema.INNODB_LOCKS;

-- LOCK을 걸고 있는 프로세스 정보
SELECT * FROM information_schema.INNODB_TRX;

해당 쿼리는 데드락 분석하는데 도움이 되는 쿼리이다.

------------------------
LATEST DETECTED DEADLOCK
------------------------
2024-11-21 16:50:17 132600714757696
*** (1) TRANSACTION:
TRANSACTION 44587, 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), undo log entries 1
MySQL thread id 22638, OS thread handle 132601078568512, query id 7258406 172.18.0.6 root updating
delete from pick_tag where id=28 and version=0

*** (1) HOLDS THE LOCK(S):
RECORD LOCKS space id 294 page no 4 n bits 88 index PRIMARY of table `techpick_db_v2`.`pick` trx id 44587 lock_mode X locks rec but not gap
Record lock, heap no 15 PHYSICAL RECORD: n_fields 10; compact format; info bits 0
 0: len 8; hex 8000000000000001; asc         ;;
 1: len 6; hex 00000000ae2b; asc      +;;
 2: len 7; hex 01000001b80151; asc       Q;;
 3: len 8; hex 99b4eb07930b3b08; asc       ; ;;
 4: len 8; hex 8000000000000001; asc         ;;
 5: len 8; hex 8000000000000003; asc         ;;
 6: len 8; hex 99b4eb0c910c8426; asc        &;;
 7: len 8; hex 8000000000000001; asc         ;;
 8: len 1; hex 31; asc 1;;
 9: len 5; hex 4e41564552; asc NAVER;;


*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 295 page no 4 n bits 88 index PRIMARY of table `techpick_db_v2`.`pick_tag` trx id 44587 lock_mode X locks rec but not gap waiting
Record lock, heap no 6 PHYSICAL RECORD: n_fields 6; compact format; info bits 32
 0: len 8; hex 800000000000001c; asc         ;;
 1: len 6; hex 00000000ae2a; asc      *;;
 2: len 7; hex 02000001b00151; asc       Q;;
 3: len 8; hex 8000000000000001; asc         ;;
 4: len 8; hex 8000000000000002; asc         ;;
 5: len 4; hex 80000000; asc     ;;


*** (2) TRANSACTION:
TRANSACTION 44586, 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), undo log entries 1
MySQL thread id 22639, OS thread handle 132601080682048, query id 7258407 172.18.0.6 root updating
update pick set link_id=1,parent_folder_id=3,tag_order='',title='NAVER',updated_at='2024-11-21 16:50:17.821708',user_id=1 where id=1

*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 295 page no 4 n bits 88 index PRIMARY of table `techpick_db_v2`.`pick_tag` trx id 44586 lock_mode X locks rec but not gap
Record lock, heap no 6 PHYSICAL RECORD: n_fields 6; compact format; info bits 32
 0: len 8; hex 800000000000001c; asc         ;;
 1: len 6; hex 00000000ae2a; asc      *;;
 2: len 7; hex 02000001b00151; asc       Q;;
 3: len 8; hex 8000000000000001; asc         ;;
 4: len 8; hex 8000000000000002; asc         ;;
 5: len 4; hex 80000000; asc     ;;


*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 294 page no 4 n bits 88 index PRIMARY of table `techpick_db_v2`.`pick` trx id 44586 lock_mode X locks rec but not gap waiting
Record lock, heap no 15 PHYSICAL RECORD: n_fields 10; compact format; info bits 0
 0: len 8; hex 8000000000000001; asc         ;;
 1: len 6; hex 00000000ae2b; asc      +;;
 2: len 7; hex 01000001b80151; asc       Q;;
 3: len 8; hex 99b4eb07930b3b08; asc       ; ;;
 4: len 8; hex 8000000000000001; asc         ;;
 5: len 8; hex 8000000000000003; asc         ;;
 6: len 8; hex 99b4eb0c910c8426; asc        &;;
 7: len 8; hex 8000000000000001; asc         ;;
 8: len 1; hex 31; asc 1;;
 9: len 5; hex 4e41564552; asc NAVER;;

*** WE ROLL BACK TRANSACTION (2)

해당 로그는 SHOW ENGINE INNODB STATUS 결과다.

• 데드락 : 두 개 이상의 트랜잭션이 서로의 자원을 기다리면서 발생하는 상태
• S Lock(Shared Lock) : 다른 트랜잭션이 해당 레코드에 대해 읽기 작업 허용, 쓰기 작업은 허용되지 않음.
• X Lock(Exclusive Lock) : 다른 트랜잭션이 해당 레코드에 대해 읽기, 쓰기 작업 모두 허용되지 않음.

데드락 상황

트랜잭션 1

1. 트랜잭션 (1)은 pick 테이블의 PRIMARY 인덱스에서 특정 레코드(heap no 15)에 대해 X Lock 보유
2. 트랜잭션 (1)은 pick_tag 테이블의 PRIMARY 인덱스에서 특정 레코드(heap no 6)에 대해 X Lock 획득 대기

트랜잭션 2

1. 트랜잭션 (2)는 pick_tag 테이블의 PRIMARY 인덱스에서 특정 레코드(heap no 6)에 대해 X Lock 보유
2. 트랜잭션 (2)는 pick 테이블의 PRIMARY 인덱스에서 특정 레코드(heap no 15)에 대해 X Lock 획득 대기

교착 상태

• 트랜잭션 (1)은 트랜잭션 (2)의 잠금 해제를 기다린다.
• 트랜잭션 (2)는 트랜잭션 (1)의 잠금 해제를 기다린다.

데드락 발생 이유

• 서로 잠금이 해제되기를 기다리면서 무한 대기에 걸리게 되어 데드락이 발생한 것
  

---

해결

비관적 락

참고

https://m.blog.naver.com/PostView.naver?isHttpsRedirect=true&blogId=cmw1728&logNo=220942833368