위의 글들과 이어지는 내용입니다.
현재 그라운드 플립이라는 게이미피케이션 걷기 앱을 런칭하여 운영 중이다.
https://apps.apple.com/kr/app/ground-flip/id6550922550
성공적으로 MVP를 개발 후 앱을 런칭했지만, 얼마 지나지 않아 중대한 버그를 발견했다.
원인 분석 결과 익히 듣던 '동시성'과 관련된 문제였고 이를 기록하고자 글을 작성한다.
개요
그라운드 플립에선 아래와 같이 지도를 작은 단위로 나눈 '픽셀'이라는 것이 존재하고, 사용자들은 이 픽셀을 걸어다니며 차지할 수 있다.
또한, 현재 차지 중인 픽셀 수를 기준으로 유저 간 랭킹 또한 제공한다.
 |  |
|---|
해당 랭킹 기능은 Redis의 Sorted Set을 사용하여 구현하였으며, 픽셀의 소유권 변화가 일어날 때마다 값을 증감하는 로직을 따른다.
그림과 코드로 정리하자면 다음과 같다.
@Transactional
public void occupyPixel(PixelOccupyRequest pixelOccupyRequest) {
Long communityId = Optional.ofNullable(pixelOccupyRequest.getCommunityId()).orElse(-1L);
Long occupyingUserId = pixelOccupyRequest.getUserId();
Pixel targetPixel = pixelRepository.findByXAndY(pixelOccupyRequest.getX(), pixelOccupyRequest.getY())
.orElseThrow(() -> new AppException(ErrorCode.PIXEL_NOT_FOUND));
updatePixelAddress(targetPixel);
updatePixelOwnerUser(targetPixel, occupyingUserId);
PixelUser pixelUser = PixelUser.builder()
.pixel(targetPixel)
.community(communityRepository.getReferenceById(communityId))
.user(userRepository.getReferenceById(occupyingUserId))
.build();
pixelUserRepository.save(pixelUser);
}
private void updatePixelAddress(Pixel targetPixel) {
if (targetPixel.getAddress() == null) {
String address = reverseGeoCodingService.getAddressFromCoordinates(targetPixel.getCoordinate().getX(),
targetPixel.getCoordinate().getY());
targetPixel.updateAddress(address);
}
}
private void updatePixelOwnerUser(Pixel targetPixel, Long occupyingUserId) {
Long originalOwnerUserId = targetPixel.getUserId();
if (Objects.equals(originalOwnerUserId, occupyingUserId)) {
return;
}
targetPixel.updateUserId(occupyingUserId);
if (originalOwnerUserId == null) {
rankingService.increaseCurrentPixelCount(occupyingUserId);
} else {
rankingService.updateRankingAfterOccupy(occupyingUserId, originalOwnerUserId);
}
}앱 런칭 8시간 후...![]()
위에 설명했다시피 '현재 소유 중인 픽셀'을 기준으로 하는 랭킹에서 -1이라는 값이 표시됐다.
비즈니스 로직 상 절대 나올 수 없는 로직인데, 심히 당황스러웠다.
분석
우선 로그를 뒤져봤다.
다행히, 문제의 유저(김구민)은 한 개의 픽셀만을 방문했었고 빠르게 원인이 되는 로그를 찾을 수 있었다.
무슨 이유인지는 모르겠지만 624번 유저에게서 픽셀 방문에 대한 요청이 동시에 두 번 들어왔고, 이로 인해 문제가 생긴 것으로 추정했다.
내가 생각한 버그 발생 흐름은 다음과 같다.
1. 624번 유저가 픽셀을 차지한다.
이 과정 후 해당 픽셀의 소유주는 624번 유저가 되며, Redis에서 해당 유저의 '현재 소유 중인 픽셀'의 수는 1이 된다.
- 623번 유저가 같은 픽셀을 차지한다.
단, 이 때는 같은 요청이 두 번 들어왔으므로 아래와 같은 일이 벌어진다.
- 각 요청을 처리하는 두 개의 스레드가 DB에 "거의 동시에" 접근하여 픽셀을 find 한다.
- 이 때, 두 스레드 모두 픽셀의 소유주는 623이라는 결과를 받게 된다.
- 소유주가 자신이 아니므로 623번 유저의 랭킹 값을 . 각 1씩 감소시킨다.
- 따라서 최종적으로 623번 유저는 -1 이라는 값을 가지게 된다.
검증
가능한 비슷한 상황을 만들기 위해 테스트 툴인 Jmeter 를 사용했다.
10개의 스레드가 동시에 같은 요청을 보내는 테스트를 작성했다.
만약 위에서 추측한대로, 여러 개의 스레드가 동시에 디비에 요청을 보낸 것이 원인이라면 테스트 후 redis에 저장된 16번 유저의 점수는 2 이상이어야 한다.
결과는?
찾았다.
테스트에서 10개중 4개의 스레드가 DB에서 픽셀 소유주의 아이디를 null로 가져왔고, 레디스에서 zincrby 연산을 실행해 총 4가 저장되었다.
해결 방법
이 글에선 해결 방법까진 다루지 않겠다.
하지만 고려한 해결 방법으론 아래의 방법들이 있다.
1. 분산락
2. synchronized
3. db lock
