플로깅 활동 참여하기 api 구현기 - 2탄 with 데드락 이슈

최지환·2023년 8월 24일
0

졸업작품-동네줍깅

목록 보기
9/11
post-thumbnail

이전에 낙관적 락 방식을 사용하여 플로깅 참여하기 api 를 구현해 보았다.

플로깅 구인 게시판에 참여 인원을 카운트 하는 필드에 대해서 동시성 이슈가 발생하는 부분에 대한 해결법으로 낙관적 락을 사용하였다. 하지만 이 해결법 만으로는 주어진 문제를 완벽하게 해결하진 못했다. 참여 인원을 카운트 하는 것은 성공적 이었다. 하지만 궁극적으로는 참여 인원 카운트 + 참여 인원 목록을 DB에 저장을 해야했다.

따라서 참여 를 관리하는 엔티티를 생성하여 연관관계를 걸어 두었으나, 참여하기 api 에 대해 테스트 해본 결과 데드락 문제가 발생하였다.

지난 이야기는 플로깅 활동 참여하기 api 구현기 with 동시성 이슈 를 확인 해보자.

아래 코드가 데드락이 발생하는 테스트 코드이다.


package mokindang.jubging.project_backend.recruitment_board.service;

import mokindang.jubging.project_backend.recruitment_board.domain.RecruitmentBoard;
import mokindang.jubging.project_backend.recruitment_board.repository.RecruitmentBoardRepository;
import mokindang.jubging.project_backend.recruitment_board.service.facade.OptimisticLockRecruitmentBoardResolver;
import org.junit.jupiter.api.DisplayName;
import org.junit.jupiter.api.Test;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.boot.test.context.SpringBootTest;

import java.util.concurrent.CountDownLatch;
import java.util.concurrent.ExecutorService;
import java.util.concurrent.Executors;

import static org.assertj.core.api.Assertions.assertThat;

@SpringBootTest
class RecruitmentBoardConcurrencyTest {

    //...

    @Test
    @DisplayName("동시성 문제 - 7명이 동시에 요청한 경우 게시글 카운트가 8이됨")
    void SuccessCountUp() throws InterruptedException {
        int threadCount = 7;
        ExecutorService executorService = Executors.newFixedThreadPool(32);

        CountDownLatch latch = new CountDownLatch(threadCount);

        for (int i = 0; i < threadCount; i++) {
            int memberId = i + 2;
            executorService.submit(() -> {
                try {
                    recruitmentBoardService.participate((long) memberId, 1L);
                } catch (final Exception e) {
                    System.out.println(e.getMessage());
                } finally {
                    latch.countDown(); // 카운트
                }
            });
        }
        latch.await();
        RecruitmentBoard recruitmentBoard = recruitmentBoardRepository.findById(1L).get();
        assertThat(recruitmentBoard.getParticipationCount().getCount()).isEqualTo(8);
    }
}
//...

구현은 다음과 같이 하였다.

OptimisticLockRecruitmentBoardResolver (낙관적 락 업데이트 실패 시 재시도를 하기 위한 부분)

@Component
@RequiredArgsConstructor
public class OptimisticLockRecruitmentBoardResolver {

    private final RecruitmentBoardService recruitmentBoardService;

    public RecruitmentBoardIdResponse participate(final Long memberId, final Long boardId) {
        RecruitmentBoardIdResponse recruitmentBoardIdResponse;
        while (true) {
            try {
                recruitmentBoardIdResponse = recruitmentBoardService.participate(memberId, boardId);
                break;
            } catch (final ObjectOptimisticLockingFailureException e) {
                sleep();
            }
        }
        return recruitmentBoardIdResponse;
    }

    private void sleep() {
        try {
            Thread.sleep(50);
        } catch (final InterruptedException ex) {
            throw new RuntimeException(ex);
        }
    }
}

RecruitmentBoardService

@Service
@Transactional(readOnly = true)
@RequiredArgsConstructor
public class RecruitmentBoardService {

    private final MemberService memberService;
    private final RecruitmentBoardRepository recruitmentBoardRepository;
		
		//...  
    @Transactional
    public RecruitmentBoardIdResponse participate(final Long memberId, final Long boardId) {
        RecruitmentBoard board = findByIdWithOptimisticLock(boardId);
        Member member = memberService.findByMemberId(memberId);
        **board.addParticipationMember(member);**
        return new RecruitmentBoardIdResponse(board.getId());
    }
}

RecruitmentBoard - 게시글 엔티티


@Entity
@NoArgsConstructor(access = AccessLevel.PROTECTED)
public class RecruitmentBoard {

    @Id
    @GeneratedValue(strategy = GenerationType.IDENTITY)
    @Column(name = "recruitment_board_id", nullable = false)
    private Long id;

    @ManyToOne(fetch = FetchType.LAZY)
    @JoinColumn(name = "member_id")
    private Member writer;

    @Embedded
    private Title title;

    @Embedded
    private ContentBody contentBody;

    @OneToMany(mappedBy = "recruitmentBoard", cascade = CascadeType.ALL)
    private List<Participation> participationList = new ArrayList<>();

    @Version
    private Long version;

    public void **addParticipationMember**(final Member member) {
        Participation participation = new Participation(this, member);
        validateAlreadyParticipatingMember(member.getId());
        if (onRecruitment) {
            participationCount = participationCount.countUp();
            participationList.add(participation);
            return;
        }
        throw new IllegalArgumentException("모집이 마감된 게시글 입니다.");
    }

    private void validateAlreadyParticipatingMember(final Long memberId) {
        if (isParticipatedIn(memberId)) {
            throw new IllegalArgumentException("이미 참여가 된 상태입니다.");
        }
    }

    public boolean isParticipatedIn(final Long memberId) {
        return participationList.stream()
                .anyMatch(participation -> participation.isParticipatedIn(memberId));
    }

    @Override
    public boolean equals(final Object o) {
        if (this == o) return true;
        if (o == null || getClass() != o.getClass()) return false;
        final RecruitmentBoard recruitmentBoard = (RecruitmentBoard) o;
        return Objects.equals(id, recruitmentBoard.id);
    }

    @Override
    public int hashCode() {
        return id != null ? id.hashCode() : 0;
    }
}

Participation - 게시글과 회원의 참여 정보를 담은 엔티티

@IdClass(ParticipationId.class)
@Entity
@Getter
@NoArgsConstructor(access = AccessLevel.PROTECTED)
public class Participation {

    @Id
    @ManyToOne(fetch = FetchType.LAZY)
    @JoinColumn(name = "recruitment_board_id")
    private RecruitmentBoard recruitmentBoard;

    @Id
    @ManyToOne(fetch = FetchType.LAZY)
    @JoinColumn(name = "member_id")
    private Member member;

    public boolean isParticipatedIn(final Long memberId) {
        return this.member
                .getId()
                .equals(memberId);
    }

    @Override
    public boolean equals(Object o) {
        if (this == o) return true;
        if (o == null || getClass() != o.getClass()) return false;
        Participation that = (Participation) o;
        return Objects.equals(recruitmentBoard.getId(), that.recruitmentBoard.getId()) && Objects.equals(member.getId(), that.member.getId());
    }

    @Override
    public int hashCode() {
        return Objects.hash(recruitmentBoard, member);
    }
}

결과

초기값 1 에서 1만 올라감 → 요청이 하나만 처리되고 나머지는 처리가 되지 않음.

로그를 다시 살펴보니

총 7번의 요청을 보냈으나, 데드락이 6번 발생 하였고 이후 요청을 재시도 하였으나 락을 흭득하지 못해서 요청을 처리하지 못하는 것을 확인 할 수 있음

예외 범위를 RuntimeException 을 캐치하도록 하면 데드락으로 인해 실패한 트랜잭션을 재실행하여 요청을 처리 할 수 있지만, 결국 데드락이 발생하는 것이 문제이기 때문에 데드락이 발생하지 않도록 하기로 함.


문제 상황

  • 참여 회원 카운트 까지는 테스트 통과.
  • 참여 회원 정보를 DB에 반영하도록 하면서 문제 발생
    • 변경 내용
    • 게시글에 새로운 참여인원이 생긴 경우, 게시글과 회원의 정보를 담은 Participation 엔티티를 생성하여 게시글의 participation 리스트에 add 함
    • 게시글과 참여(paticipation) 의 영속성을 동일하게 관리하기 위해, 게시글에서 참여로 CascadeType.ALL 설정하여 영속성을 전이함.
  • 이후 동일한 테스트 코드를 실행 했을 때 데드락이 발생하여, api 가 정상적으로 실행 되지 않음.
  • 참여인원이 8이어야 하고, 게시글에 참여 정보가 있어야하지만 1개의 요청만이 실행되고, 나머지 요청은 데드락으로 인해 실패함.

원인 찾기

일단 데드락에 대한 정보를 자세히 보기 위해 알아본 결과 데이터베이스의 로그를 확인

SHOW ENGINE Innodb STATUS\G;

쿼리를 작성하면 아래와 같이 최근에 발생한 데드락 문제에 대한 로그를 확인 할 수 있음 - 실제론 매우 길기에 편의를 위해 필요한 내용만 가져옴.


*************************** 1. row ***************************
  Type: InnoDB
  Name:
Status:
=====================================
2023-08-16 14:21:52 140134116689664 INNODB MONITOR OUTPUT
=====================================

------------------------
LATEST DETECTED DEADLOCK
------------------------
2023-08-16 14:21:39 140134708143872
***** (1) TRANSACTION:**
TRANSACTION 652670, ACTIVE 0 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 7 lock struct(s), heap size 1128, 3 row lock(s), undo log entries 1
MySQL thread id 562, OS thread handle 140134653564672, query id 12475 172.17.0.1 root updating
update recruitment_board set activity_category='RUNNING', content_body=x'ebb3b8ebacb8eb82b4ec9aa9', creating_date_time='2023-03-09 12:00:00', address='??? ??? ??? 1-1', latitude_point=1.2, longitude_point=1.1, on_recruitment=1, count_of_participation=2, max_count_of_participation=8, starting_date='2023-03-15', title='??', version=2, member_id=1, region='???' where recruitment_board_id=1 and version=1

***** (1) HOLDS THE LOCK(S):**
RECORD LOCKS space id 22084 page no 4 n bits 72 index PRIMARY of table `mokindangdb`.`recruitment_board` trx id 652670 lock mode S locks rec but not gap
Record lock, heap no 2 PHYSICAL RECORD: n_fields 17; compact format; info bits 0
 
***** (1) WAITING FOR THIS LOCK TO BE GRANTED:**
RECORD LOCKS space id 22084 page no 4 n bits 72 index PRIMARY of table `mokindangdb`.`recruitment_board` trx id 652670 lock_mode X locks rec but not gap waiting
Record lock, heap no 2 PHYSICAL RECORD: n_fields 17; compact format; info bits 0

***** (2) TRANSACTION:**
TRANSACTION 652675, ACTIVE 0 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 7 lock struct(s), heap size 1128, 3 row lock(s), undo log entries 1
MySQL thread id 565, OS thread handle 140134142924544, query id 12477 172.17.0.1 root updating
update recruitment_board set activity_category='RUNNING', content_body=x'ebb3b8ebacb8eb82b4ec9aa9', creating_date_time='2023-03-09 12:00:00', address='??? ??? ??? 1-1', latitude_point=1.2, longitude_point=1.1, on_recruitment=1, count_of_participation=2, max_count_of_participation=8, starting_date='2023-03-15', title='??', version=2, member_id=1, region='???' where recruitment_board_id=1 and version=1

***** (2) HOLDS THE LOCK(S):**
RECORD LOCKS space id 22084 page no 4 n bits 72 index PRIMARY of table `mokindangdb`.`recruitment_board` trx id 652675 lock mode S locks rec but not gap
Record lock, heap no 2 PHYSICAL RECORD: n_fields 17; compact format; info bits 0

***** (2) WAITING FOR THIS LOCK TO BE GRANTED:**
RECORD LOCKS space id 22084 page no 4 n bits 72 index PRIMARY of table `mokindangdb`.`recruitment_board` trx id 652675 lock_mode X locks rec but not gap waiting
Record lock, heap no 2 PHYSICAL RECORD: n_fields 17; compact format; info bits 0

***** WE ROLL BACK TRANSACTION (2)**
------------
TRANSACTIONS
------------
Trx id counter 652683
Purge done for trx's n:o < 652683 undo n:o < 0 state: running but idle
History list length 5
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 421610242315856, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 421610242315048, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 421610242314240, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 421610242312624, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
---TRANSACTION 421610242311816, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
//... 

에러 내용은 다음과 같다.

  1. 트랜잭션A(652670) 가 인덱스를 읽기 시작함
  2. 트랜잭션A(652670) 가 S락을 흭득함
  3. 트랜잭션A(652670) 가 X 락을 흭득하기 위해 대기 중
  4. 트랜잭션B(652675) 가 인덱스를 읽기 시작함
  5. 트랜잭션B(652675) 가 S락을 흭득함
  6. 트랜잭션B(652675) 가 X 락을 흭득하기 위해 대기중

데드락이 발생하는 원인을 보면 3번6번에 있다. 서로 다른 트랜잭션에서 같은 레코드(특정 게시글 row)에 대해서 X락을 흭득하기 위해 경쟁 상태에 있는 것이 원인이라고 추측되었다.

그런데 왜 Participation 엔티티를 추가한 후 이런 데드락 상황이 발생하지? 그리고 X락과 S락이 무엇이지? 그리고 왜 X 락을 흭득하려고 하지? 등의 생각이 들어서 우선 S락과 X락이 무엇인지 찾아보았다.


Exclusive lock (배타적 잠금) - X 락

  • 트랜잭션에서 데이터를 변경하고자 할 때 해당 트랜잭션이 완료 될 때 까지 해당 테이블 혹은 레코드(row)를 다른 트랜잭션에서 읽거나 쓰지 못하게 함
  • exclusive lock 이 걸려있으면 shared lock을 걸 수 없음
  • exclusive lock 에 걸린 테이블, 레코드 등에 대해 다른 트랜잭션이 exclusive lock 을 걸 수 없음.

Shared lock (공유 장금) - S 락

  • 어떤 트랜잭션에서 데이터를 읽고자 할 때 다른 shared lock 은 허용되지만 exclusive lock 은 불가함.
  • shared lock 을 트랜잭션에서 잡고 있는경우 다른 트랜잭션에서 shared lock 을 걸어 데이터를 읽는 것은 허용되지만 변경을 할 수는 없음
  • 테이블이나 데이터에 shared lock 은 여러 트랜잭션에서 적용 가능
  • 한 트랜잭션에서 shared lock 이 걸려있는 경우 다른 트랜잭션에서 exclusive lock 은 걸 수 없음 → 변경 불가하게 하기 위함.

추가적으로 Intention lock

  • IS 락 - 트랜잭션이 테이블의 개별 row 에 S 락을 설정하려고 한다는 ‘의도’를 나타냄
  • IX 락 - 트랜잭션 테이블의 개별 row 에 X 락을 설정하려고 한다는 ‘의도’를 나타냄
    • IS, IX 락은 여러 트랜잭션에서 동시에 접근이 가능하다.
XIXSIS
X충돌충돌충돌충돌
IX충돌호환충돌호환
S충돌충돌호환호환
IS충돌호환호환호환

현재 문제가 되는 상황은 두개의 트랜잭션에서 서로 같은 데이터 (특정 게시글 row)에 대해 X락을 흭득하는 것이 문제이다.

사실 이 로그만을 보고는 락 흭득 과정이 이해가 되지 않았다. 또한 구현코드에서 Dirty Checking 을 통해 데이터를 변경하였고, DB Lock 을 사용하지 않았기 때문에 왜 lock 관련 로그가 찍힌는지 이해가 되지 않았다.

그래서 우선 테스트코드를 통해서 1번의 api 을 실행 시켜보았고, mysql 의 쿼리 로그를 확인하여 어떤 쿼리가 실행 되었는지 확인 하였다.

DB 의 쿼리 로그를 확인해본결과 3번의 select 쿼리, insert 쿼리 1번, update 쿼리 1번이 발생하는 것을 확인했다.

2023-08-18T07:32:28.326388Z	  161 Query	select recruitmen0_.recruitment_board_id as recruitm1_5_, recruitmen0_.activity_category as activity2_5_, recruitmen0_.content_body as content_3_5_, recruitmen0_.creating_date_time as creating4_5_, recruitmen0_.address as address5_5_, recruitmen0_.latitude_point as latitude6_5_, recruitmen0_.longitude_point as longitud7_5_, recruitmen0_.on_recruitment as on_recru8_5_, recruitmen0_.count_of_participation as count_of9_5_, recruitmen0_.max_count_of_participation as max_cou10_5_, recruitmen0_.starting_date as startin11_5_, recruitmen0_.title as title12_5_, recruitmen0_.version as version13_5_, recruitmen0_.member_id as member_15_5_, recruitmen0_.region as region14_5_ from recruitment_board recruitmen0_ where recruitmen0_.recruitment_board_id=1
2023-08-18T07:32:28.426594Z	  161 Query	select member0_.member_id as member_i1_3_0_, member0_.alias as alias2_3_0_, member0_.email as email3_3_0_, member0_.profile_image_url as profile_4_3_0_, member0_.region as region5_3_0_ from member member0_ where member0_.member_id in (2, 1)
2023-08-18T07:32:28.437056Z	  161 Query	select participat0_.recruitment_board_id as recruitm2_4_1_, participat0_.member_id as member_i1_4_1_, participat0_.member_id as member_i1_4_0_, participat0_.recruitment_board_id as recruitm2_4_0_ from participation participat0_ where participat0_.recruitment_board_id=1
2023-08-18T07:32:28.496118Z	  161 Query	insert into participation (member_id, recruitment_board_id) values (2, 1)
2023-08-18T07:32:28.514308Z	  161 Query	update recruitment_board set activity_category='RUNNING', content_body=x'ebb3b8ebacb8eb82b4ec9aa9', creating_date_time='2023-03-09 12:00:00', address='서울시 동작구 상도동 1-1', latitude_point=1.2, longitude_point=1.1, on_recruitment=1, count_of_participation=2, max_count_of_participation=8, starting_date='2023-03-15', title='제목', version=2, member_id=1, region='동작구' where recruitment_board_id=1 and version=1
2023-08-18T07:32:28.524376Z	  161 Query	commit

서로 다른 트랜잭션에서 해당 쿼리를 각각 했을 때를 가정하여, 터미널에 mysql console 을 2개 띄워놓고 이 쿼리들을 순차적으로 직접 실행해보았다. → 락 흭득 상황을 보기 위해서 콘솔에 직접 쿼리를 날렸다.

A 트랜잭션

(1) START TRANSACTION;
(3) select * from recruitment_board where recruitment_board_id = 1;
(5) select * from member where member_id = 2;
(7) select recruitment_board_id from participation where recruitment_board_id = 1;
(9) insert into participation (member_id, recruitment_board_id) values (2, 1);
(11)update recruitment_board set count_of_participation =2 where recruitment_board_id =1 and version = 1;
(13) COMMIT;

B 트랜잭션

(2) START TRANSACTION;
(4) select * from recruitment_board where recruitment_board_id = 1;
(6) select * from member where member_id = 3;
(8) select recruitment_board_id from participation where recruitment_board_id = 1;
(10) insert into participation (member_id, recruitment_board_id) values (3, 1);
(12) update recruitment_board set count_of_participation =2 where recruitment_board_id =1 and version = 1;
(14) COMMIT;

각 쿼리 실행 단계마다 현재 데이터 베이스의 락 흭득 상황을 보기 위해 아래의 쿼리를 작성했다.

SELECT * FROM performance_schema.data_locks\G;

트랜잭션을 시작하고 각 트랜잭션에서 select 쿼리를 3번씩 날리는 8번 까지 실행해본 결과

조회된 락은 없다.

이후 9번 - A 트랜잭션에서 Insert 쿼리 를 실행한 결과 총 5개의 lock 이 잡히는 것을 확인 할 수 있었다.

  mysql> SELECT * FROM performance_schema.data_locks\G;
*************************** 1. row ***************************
               ENGINE: INNODB
       ENGINE_LOCK_ID: 139953264869376:23780:139953187122000
ENGINE_TRANSACTION_ID: 672496
            THREAD_ID: 48
             EVENT_ID: 102
        OBJECT_SCHEMA: mokindangdb
          OBJECT_NAME: recruitment_board
       PARTITION_NAME: NULL
    SUBPARTITION_NAME: NULL
           INDEX_NAME: NULL
OBJECT_INSTANCE_BEGIN: 139953187122000
            LOCK_TYPE: TABLE
            LOCK_MODE: IS
          LOCK_STATUS: GRANTED
            LOCK_DATA: NULL
*************************** 2. row ***************************
               ENGINE: INNODB
       ENGINE_LOCK_ID: 139953264869376:23768:139953187121912
ENGINE_TRANSACTION_ID: 672496
            THREAD_ID: 48
             EVENT_ID: 102
        OBJECT_SCHEMA: mokindangdb
          OBJECT_NAME: member
       PARTITION_NAME: NULL
    SUBPARTITION_NAME: NULL
           INDEX_NAME: NULL
OBJECT_INSTANCE_BEGIN: 139953187121912
            LOCK_TYPE: TABLE
            LOCK_MODE: IS
          LOCK_STATUS: GRANTED
            LOCK_DATA: NULL
*************************** 3. row ***************************
               ENGINE: INNODB
       ENGINE_LOCK_ID: 139953264869376:23779:139953187121824
ENGINE_TRANSACTION_ID: 672496
            THREAD_ID: 48
             EVENT_ID: 102
        OBJECT_SCHEMA: mokindangdb
          OBJECT_NAME: participation
       PARTITION_NAME: NULL
    SUBPARTITION_NAME: NULL
           INDEX_NAME: NULL
OBJECT_INSTANCE_BEGIN: 139953187121824
            LOCK_TYPE: TABLE
            LOCK_MODE: IX
          LOCK_STATUS: GRANTED
            LOCK_DATA: NULL
*************************** 4. row ***************************
               ENGINE: INNODB
       ENGINE_LOCK_ID: 139953264869376:22702:4:3:139953187118912
ENGINE_TRANSACTION_ID: 672496
            THREAD_ID: 48
             EVENT_ID: 102
        OBJECT_SCHEMA: mokindangdb
          OBJECT_NAME: member
       PARTITION_NAME: NULL
    SUBPARTITION_NAME: NULL
           INDEX_NAME: PRIMARY
OBJECT_INSTANCE_BEGIN: 139953187118912
            LOCK_TYPE: RECORD
            LOCK_MODE: S,REC_NOT_GAP
          LOCK_STATUS: GRANTED
            LOCK_DATA: 2
*************************** 5. row ***************************
               ENGINE: INNODB
       ENGINE_LOCK_ID: 139953264869376:22714:4:2:139953187119256
ENGINE_TRANSACTION_ID: 672496
            THREAD_ID: 48
             EVENT_ID: 102
        OBJECT_SCHEMA: mokindangdb
          OBJECT_NAME: recruitment_board
       PARTITION_NAME: NULL
    SUBPARTITION_NAME: NULL
           INDEX_NAME: PRIMARY
OBJECT_INSTANCE_BEGIN: 139953187119256
            LOCK_TYPE: RECORD
            LOCK_MODE: S,REC_NOT_GAP
          LOCK_STATUS: GRANTED
            LOCK_DATA: 1
5 rows in set (0.00 sec)

정리해보면 A 트랜잭션에서 insert into participation (member_id, recruitment_board_id) values (2, 1); 쿼리 실행 시

순서대로 로그를 확인 해보면

  • recruitment_board - IS락, table
  • member - IS락, table
  • participation - IX 락, table
  • member - S락, record(member 의 인덱스)
  • recruitment_board - S락, record(recruitment_board의 인덱스)

이렇게 5개의 락이 잡혀있는 것을 확인 할 수 있다. 현 상황을 그림으로 보자면 아래와 같다.

S,X 는 락 종류를 의미하고, 그다음으로는 락으로 잡고 있는 데이터와 범위를 의미한다.

participationinsert 쿼리를 날렸을 때 X 락을 잡는 것은 이해가 되지만 board 와 member에 까지 S 락이 걸리는 것이 이해가 되지 않았다. 찾아본 결과 그 이유는 외래키 잠금 전파 때문이었다.


외래키 잠금 전파

외래키 칼럼의 변경(INSERT, UPDATE) 시 부모 테이블이나 자식 테이블에 데이터가 존재하는 지 확인 절차가 필요하다. 이때 잠금이 연관 관계를 맺고 있는 여러 테이블로 잠금이 전파된다. 해당 변경 작업을 위해 외래키 컬럼에 S-Lock 이 걸리게 되고 그로 인해 데드락이 발생 할 수 있다.

내 상황에서는 participation 엔티티는 recruitment_boardidmemberid 를 복합키로 사용하고 있다.

아래는 participation 테이블의 스키마이다. 복합키로 사용된 recruitment_board_idmember_id외래키로 걸려있는 것을 볼 수 있다.

정리해보자면 insert into participation (member_id, recruitment_board_id) values (2, 1); 실행 시, participation 테이블에 IX 락이 걸리게 되고 외래키로 걸려있는 id 가 1인 member와 id 가 1인 recruitment_board 에 대해 존재 여부를 확인하면서 S 락이 전파가 된다.


이제 S 락이 걸리는 이유를 확인 했으니 데드락 발생 원인을 찾는 본론으로 돌아가자.

이제 10 번 쿼리(B 에서 insert participation 에 쿼리)를 날려보면

*************************** 1. row ***************************
               ENGINE: INNODB
       ENGINE_LOCK_ID: 139953264868568:23780:139953187115904
ENGINE_TRANSACTION_ID: 672501
            THREAD_ID: 49
             EVENT_ID: 101
        OBJECT_SCHEMA: mokindangdb
          OBJECT_NAME: recruitment_board
       PARTITION_NAME: NULL
    SUBPARTITION_NAME: NULL
           INDEX_NAME: NULL
OBJECT_INSTANCE_BEGIN: 139953187115904
            LOCK_TYPE: TABLE
            LOCK_MODE: IS
          LOCK_STATUS: GRANTED
            LOCK_DATA: NULL
*************************** 2. row ***************************
               ENGINE: INNODB
       ENGINE_LOCK_ID: 139953264868568:23768:139953187115816
ENGINE_TRANSACTION_ID: 672501
            THREAD_ID: 49
             EVENT_ID: 101
        OBJECT_SCHEMA: mokindangdb
          OBJECT_NAME: member
       PARTITION_NAME: NULL
    SUBPARTITION_NAME: NULL
           INDEX_NAME: NULL
OBJECT_INSTANCE_BEGIN: 139953187115816
            LOCK_TYPE: TABLE
            LOCK_MODE: IS
          LOCK_STATUS: GRANTED
            LOCK_DATA: NULL
*************************** 3. row ***************************
               ENGINE: INNODB
       ENGINE_LOCK_ID: 139953264868568:23779:139953187115728
ENGINE_TRANSACTION_ID: 672501
            THREAD_ID: 49
             EVENT_ID: 101
        OBJECT_SCHEMA: mokindangdb
          OBJECT_NAME: participation
       PARTITION_NAME: NULL
    SUBPARTITION_NAME: NULL
           INDEX_NAME: NULL
OBJECT_INSTANCE_BEGIN: 139953187115728
            LOCK_TYPE: TABLE
            LOCK_MODE: IX
          LOCK_STATUS: GRANTED
            LOCK_DATA: NULL
*************************** 4. row ***************************
               ENGINE: INNODB
       ENGINE_LOCK_ID: 139953264868568:22702:4:4:139953187112736
ENGINE_TRANSACTION_ID: 672501
            THREAD_ID: 49
             EVENT_ID: 101
        OBJECT_SCHEMA: mokindangdb
          OBJECT_NAME: member
       PARTITION_NAME: NULL
    SUBPARTITION_NAME: NULL
           INDEX_NAME: PRIMARY
OBJECT_INSTANCE_BEGIN: 139953187112736
            LOCK_TYPE: RECORD
            LOCK_MODE: S,REC_NOT_GAP
          LOCK_STATUS: GRANTED
            LOCK_DATA: 3
*************************** 5. row ***************************
               ENGINE: INNODB
       ENGINE_LOCK_ID: 139953264868568:22714:4:2:139953187113080
ENGINE_TRANSACTION_ID: 672501
            THREAD_ID: 49
             EVENT_ID: 101
        OBJECT_SCHEMA: mokindangdb
          OBJECT_NAME: recruitment_board
       PARTITION_NAME: NULL
    SUBPARTITION_NAME: NULL
           INDEX_NAME: PRIMARY
OBJECT_INSTANCE_BEGIN: 139953187113080
            LOCK_TYPE: RECORD
            LOCK_MODE: S,REC_NOT_GAP
          LOCK_STATUS: GRANTED
            LOCK_DATA: 1
*************************** 6. row ***************************
               ENGINE: INNODB
       ENGINE_LOCK_ID: 139953264869376:23780:139953187122000
ENGINE_TRANSACTION_ID: 672496
            THREAD_ID: 48
             EVENT_ID: 102
        OBJECT_SCHEMA: mokindangdb
          OBJECT_NAME: recruitment_board
       PARTITION_NAME: NULL
    SUBPARTITION_NAME: NULL
           INDEX_NAME: NULL
OBJECT_INSTANCE_BEGIN: 139953187122000
            LOCK_TYPE: TABLE
            LOCK_MODE: IS
          LOCK_STATUS: GRANTED
            LOCK_DATA: NULL
*************************** 7. row ***************************
               ENGINE: INNODB
       ENGINE_LOCK_ID: 139953264869376:23768:139953187121912
ENGINE_TRANSACTION_ID: 672496
            THREAD_ID: 48
             EVENT_ID: 102
        OBJECT_SCHEMA: mokindangdb
          OBJECT_NAME: member
       PARTITION_NAME: NULL
    SUBPARTITION_NAME: NULL
           INDEX_NAME: NULL
OBJECT_INSTANCE_BEGIN: 139953187121912
            LOCK_TYPE: TABLE
            LOCK_MODE: IS
          LOCK_STATUS: GRANTED
            LOCK_DATA: NULL
*************************** 8. row ***************************
               ENGINE: INNODB
       ENGINE_LOCK_ID: 139953264869376:23779:139953187121824
ENGINE_TRANSACTION_ID: 672496
            THREAD_ID: 48
             EVENT_ID: 102
        OBJECT_SCHEMA: mokindangdb
          OBJECT_NAME: participation
       PARTITION_NAME: NULL
    SUBPARTITION_NAME: NULL
           INDEX_NAME: NULL
OBJECT_INSTANCE_BEGIN: 139953187121824
            LOCK_TYPE: TABLE
            LOCK_MODE: IX
          LOCK_STATUS: GRANTED
            LOCK_DATA: NULL
*************************** 9. row ***************************
               ENGINE: INNODB
       ENGINE_LOCK_ID: 139953264869376:22702:4:3:139953187118912
ENGINE_TRANSACTION_ID: 672496
            THREAD_ID: 48
             EVENT_ID: 102
        OBJECT_SCHEMA: mokindangdb
          OBJECT_NAME: member
       PARTITION_NAME: NULL
    SUBPARTITION_NAME: NULL
           INDEX_NAME: PRIMARY
OBJECT_INSTANCE_BEGIN: 139953187118912
            LOCK_TYPE: RECORD
            LOCK_MODE: S,REC_NOT_GAP
          LOCK_STATUS: GRANTED
            LOCK_DATA: 2
*************************** 10. row ***************************
               ENGINE: INNODB
       ENGINE_LOCK_ID: 139953264869376:22714:4:2:139953187119256
ENGINE_TRANSACTION_ID: 672496
            THREAD_ID: 48
             EVENT_ID: 102
        OBJECT_SCHEMA: mokindangdb
          OBJECT_NAME: recruitment_board
       PARTITION_NAME: NULL
    SUBPARTITION_NAME: NULL
           INDEX_NAME: PRIMARY
OBJECT_INSTANCE_BEGIN: 139953187119256
            LOCK_TYPE: RECORD
            LOCK_MODE: S,REC_NOT_GAP
          LOCK_STATUS: GRANTED
            LOCK_DATA: 1
10 rows in set (0.00 sec)

기존 트랜잭션 A 에서 확인했던 락 상태와 동일하게 트랜잭션 B에서 락이 추가된 것을 볼 수 있다. 로그를 보기 어려우니 그림으로 간단하게 표현하자면 아래와 같은 상태이다.

현재까진 데드락이 발생하지 않는 상황이다.

이후 다음으로 트랜잭션 A 에서 (11)update recruitment_board set count_of_participation =2 where recruitment_board_id =1 and version = 1; 를 실행 시켜 보았으나, 아래 처럼 트랜잭션 B 에서 락을 쥐고 있는 것으로 확인이 되어 결과가 반환 되지 않고있다.

트랜잭션 A 에서 update 쿼리 실행

트랜잭션 A 에서 update 쿼리 실행

이후 락 로그를 확인 해보면 2개의 로그가 추가 되었다.

*************************** 11. row ***************************
               ENGINE: INNODB
       ENGINE_LOCK_ID: 139953264869376:22714:4:2:139953187119256
ENGINE_TRANSACTION_ID: 672496
            THREAD_ID: 48
             EVENT_ID: 102
        OBJECT_SCHEMA: mokindangdb
          OBJECT_NAME: recruitment_board
       PARTITION_NAME: NULL
    SUBPARTITION_NAME: NULL
           INDEX_NAME: PRIMARY
OBJECT_INSTANCE_BEGIN: 139953187119256
            LOCK_TYPE: RECORD
            LOCK_MODE: S,REC_NOT_GAP
          LOCK_STATUS: GRANTED
            LOCK_DATA: 1
*************************** 12. row ***************************
               ENGINE: INNODB
       ENGINE_LOCK_ID: 139953264869376:22714:4:2:139953187119600
ENGINE_TRANSACTION_ID: 672496
            THREAD_ID: 48
             EVENT_ID: 103
        OBJECT_SCHEMA: mokindangdb
          OBJECT_NAME: recruitment_board
       PARTITION_NAME: NULL
    SUBPARTITION_NAME: NULL
           INDEX_NAME: PRIMARY
OBJECT_INSTANCE_BEGIN: 139953187119600
            LOCK_TYPE: RECORD
            LOCK_MODE: X,REC_NOT_GAP
          LOCK_STATUS: WAITING
            LOCK_DATA: 1
12 rows in set (0.00 sec)

이 상황을 그림으로 그려보면 아래와 같은 상황이다.

다시 트랜잭션 B에서 (12)update recruitment_board set count_of_participation =2 where recruitment_board_id =1 and version = 1; 를 실행하면 데드락이 발생하는 것을 확인 할 수 이다.

트랜잭션 B에서 데드락이 발생하기전 과정을 생각해보면 트랜잭션 A 의 update 쿼리에서와 동일하게 아래 그림처럼 락을 잡을 것이다.

이 때 데드락이 발생 할 수 있다.

트랜잭션 B 에서 update recruitment_board set count_of_participation =2 where recruitment_board_id =1 and version = 1; 쿼리 실행 시 board id 가 1인 인덱스 레코드에 x 락을 걸려고 할 것이다. 트랜잭션 A 에서 Board (Index) 에 대해 이미 S 락을 걸어두었다. 따라서 X 락을 걸수가 없다. → S 락이 걸린 경우 X 락을 걸 수 없음.

반대로 트랜잭션 A 에서 Board id 가 1인 인덱스 레코드에 X 락을 걸 경우 이미 트랜잭션 B 에서 S 락이 걸려 있기 때문에 서로 교착 상태가 발생한다. 그림으로 보면 아래와 같다.

정리하자면

  • 양쪽 트랜잭션에서 insert into participation 실행
  • 이때 participation 의 pk 인 복합키는 외래키로 설정되어 각각로 board id 가 1 인 레코드에 와 member 에 대해 S 락이 전파 됨
  • 이후 update 실행 시 X 락을 흭득하려고 하는데 다른 트랜잭션에서 S 락을 잡고 놔주지 않기 때문에 서로 기다림
  • 데드락 발생.

문제 해결

1. 쿼리 순서 바꾸기

insert 후 update 를 해서 문제가 된다면 해당 쿼리 순서를 바꿔서 실행해보는건 어떨까 라는 접근으로 해결책을 찾아보았다.

그래서 update 쿼리 먼저 강제로 flush 하는 방법도 고려했으나 좋은 방법이라는 생각이 들지 않았다.

하이버네이트 쿼리 실행 순서를 보면 Insert, update, 컬렉션 요소 삭제, 컬렉션 요소 추가, 삭제 순서로 쿼리가 실행된다고 하는데, 외래 키 제약 조건을 위배하지 않고 데이터의 일관성을 유지할 수 있도록 하는게 목적이라고 한다.

또한 도메인 레벨에서 DB 에서 처리할 수행 하는 역할까지 맡는다는 생각이 들었다.

2. FK 설정 풀어버리기

Fk 때문에 문제가 된거라면 FK 를 안쓰면 된다. 그럼 외래키 잠금 전파 또한 일어나지 않는다. 하지만 외래키 잠금 전파가 데이터의 무결성을 지키기 위해서 이루어지는 것이기 때문에 FK 가 걸려있지 않으면 데이터 무결성을 해칠 가능성이있다고 한다.

3. Insert 시점에 아예 Participation 테이블에 X 락 걸어 버리기

현재 문제가 되는 포인트는 insert 시 양쪽에서 게시글 레코드에 대해 S 락을 건 후 update 시 게시글 레코드 X 락을 흭득하지 못하는 상황이다.

따라서 한트랜잭션에서 insert 할 때 X 락을 걸어버리면 다른 트랜잭션에서는 insert 를 하지 못한다. 그럼 insert 시 X 락을 잡은 트랜잭션이 update 까지 완료 후 커밋을 실행하면 다른 트랜잭션에서 insert, update 를 순차적으로 진행 할 수 있을 것이다.

→ 하지만 테이블에 X 락을 걸어버리면 해당 테이블에 데이터를 모두 조회를 하지 못하기 때문에, 변경 보다 조회가 매우 많은 게시판 서비스 특성상 좋지 않다고 생각했다.

4. 그냥 데드락 나게 하기

데드락이 발생한 경우 mysql 은 트랜잭션 중 하나를 롤백시킨다. 이때 서버에서 해당 요청을 재시도하게 되면 순차적으로 api 가 실행될 것이다.

실제 서비스에서 이렇게 동시성 문제가 발생하는 경우는 정말 희박하다. 따라서 데드락이 발생했을 때는 그냥 다시 트랜잭션을 시작하여 DB 에 반영하는 것 또한 방법이라고 생각했다.

하지만 재시도 하는 과정에서 요청을 다시 보내는 비용이 든다.

5. Pessimistic lock

**2023-08-18T07:32:28.326388Z	  161 Query	select recruitmen0_.recruitment_board_id as recruitm1_5_, recruitmen0_.activity_category as activity2_5_, recruitmen0_.content_body as content_3_5_, recruitmen0_.creating_date_time as creating4_5_, recruitmen0_.address as address5_5_, recruitmen0_.latitude_point as latitude6_5_, recruitmen0_.longitude_point as longitud7_5_, recruitmen0_.on_recruitment as on_recru8_5_, recruitmen0_.count_of_participation as count_of9_5_, recruitmen0_.max_count_of_participation as max_cou10_5_, recruitmen0_.starting_date as startin11_5_, recruitmen0_.title as title12_5_, recruitmen0_.version as version13_5_, recruitmen0_.member_id as member_15_5_, recruitmen0_.region as region14_5_ from recruitment_board recruitmen0_ where recruitmen0_.recruitment_board_id=1**
2023-08-18T07:32:28.426594Z	  161 Query	select member0_.member_id as member_i1_3_0_, member0_.alias as alias2_3_0_, member0_.email as email3_3_0_, member0_.profile_image_url as profile_4_3_0_, member0_.region as region5_3_0_ from member member0_ where member0_.member_id in (2, 1)
2023-08-18T07:32:28.437056Z	  161 Query	select participat0_.recruitment_board_id as recruitm2_4_1_, participat0_.member_id as member_i1_4_1_, participat0_.member_id as member_i1_4_0_, participat0_.recruitment_board_id as recruitm2_4_0_ from participation participat0_ where participat0_.recruitment_board_id=1
2023-08-18T07:32:28.496118Z	  161 Query	insert into participation (member_id, recruitment_board_id) values (2, 1)
2023-08-18T07:32:28.514308Z	  161 Query	update recruitment_board set activity_category='RUNNING', content_body=x'ebb3b8ebacb8eb82b4ec9aa9', creating_date_time='2023-03-09 12:00:00', address='서울시 동작구 상도동 1-1', latitude_point=1.2, longitude_point=1.1, on_recruitment=1, count_of_participation=2, max_count_of_participation=8, starting_date='2023-03-15', title='제목', version=2, member_id=1, region='동작구' where recruitment_board_id=1 and version=1
2023-08-18T07:32:28.524376Z	  161 Query	commit

트랜잭션 처음에 게시글에 대한 select 시점에서 pessimistic lock 을 걸어 한트랜잭션이 커밋될 때 까지 다른 트랜잭션에서 대기하도록 할 수 는 있지만, 현재 서비스상 이처럼 동시성 문제가 발생하는 경우가 너무 희박하기 때문에 비용적인 측면에서 불필요하다고 생각되어 좋지 방법이라고 생각했다.

하지만 참여하기 api 에 대해 동시 요청이 들어온 상황에서 게시글에 대해서 Pessimistic lock 을 잡아버리면 이후 insert, update 에 대해 락 흭득 대기를 할 필요가 없다. 따라서 트랜잭션간에 데드락이 발생하지 않을 것이다.


결론

2 번과 5번 방법에서 고민을 해보았다. 2번 같은 경우에는 외래키 전파로 인해 발생하는 현 문제 상황을 가장 직관적으로 해결 할 수 있는 방법이다. 하지만 데이터 무결성은 어플리케이션 로직에서 처리를 해야한다.

반대로 5번 같은 경우 한 트랜잭션이 게시글에 락을 잡고 있는 상황에서 다른 트랜잭션에서 락 놓을 때 까지 대기를 해야하지만 외래키 제약 조건을 DB에서 지킬 수 있게해준다.

고민 해봤을 때 동시에 참여하기 api 를 보내는 상황자체가 서비스 특성상 발생할 확률이 너무 낮기에 Pessimistic Lock 을 거는 것은 락이라는 비용이 필요 이상으로 들게 된다. 따라서 2번 방법을 채택했다.

알게된 점

  • 외래키를 갖고 있는 데이터를 추가 하거나 변경 할 때는 해당 fk 에 해당하는 데이터에 외래키 잠금 점파가 일어난다. 따라서 외래키 제약을 걸 때는 신중히.
  • 외래키 제약을 푼다면, 이로 인해 발생할 사이드 이펙트를 신경 써야한다.
    • 현 상황에서는 게시글이 삭제가 된다면 participation 의 데이터와 데이터 정합성이 깨질 우려가 있다.

0개의 댓글