[PUBG Analyzer] 배그 Telemetry 분석 기능 구현 문제 해결

개인 토이 프로젝트로 진행 중인 PUBG Analyzer를 진행하면서 발생한 문제를 해결한 내용을 정리했다.

 

PUBG Analyzer는 배틀그라운드 매치 결과와 매치 로그를 분석하는 프로젝트이다.

 

Telemetry 분석 기능

---

PUBG에서 매치 결과나 매치 로그(telemtry)를 조회할 수 있도록 API를 제공해 준다.

PUBG API 공식문서

현재 개발 중인 telemetry 분석 기능은 나의 킬 로그, 킬에 대한 데미지 로그를 조회하여 보여주는 기능이다.

 

기대하는 동작은 이렇다.

1. 최근에 조회되어 캐싱되어 있는 경우, 캐싱된 데이터를 반환한다.

2. 캐시가 만료되었지만, 이미 DB에 저장되어 있는 경우, DB 조회 결과를 반환한다.

3. 만약 DB에도 데이터가 없다면 API 호출 후 결과를 DB에 저장(비동기)하고 반환한다.

 

 

현재 친구들과 함께 실제 사용을 하고 있었고 게임이 끝나면 다같이 동시에 조회하는 일이 많았다.

그래서, telemetry 조회 기능을 구현할 때는 동시요청에 대한 테스트도 진행했다.

혹시나가 역시나, 조회 결과 데미지 합계가 비정상적으로 출력되는 것을 확인하였다.

DB를 조회해 보니 같은 매치의 telemetry가 두 세트 저장된 상태였다.

 

 

문제

---

문제가 발생하는 경우에 대한 흐름을 그림으로 정리해 보았다.

 

 

두 번째 그림은 좀 복잡하지만 두 가지 경우의 공통점이 있다.

1. 조회가 한 번 도 이루어지지 않아 DB에 데이터가 없어 API를 호출한다는 점.
2. 늦게 발생한 요청(빨간색)이 먼저 들어온 요청(하늘색)의 결과 반환 전에 발생한다는 점.

따라서, 두 요청 모두 캐싱된 데이터가 없고 DB에 저장된 데이터가 없기 때문에 API 요청을 한다. 그다음 DB에 저장하게 되는데 이 부분이 문제였다.

 

해결과정

---

# 1 Unique 컬럼 설정

여러 컬럼들을 하나로 묶어 unique로 설정해 주고 같은 로그가 저장될 경우 예외가 발생하도록 하는 방법.

 

LogPlayerTakeDamage 스키마

create table if not exists `pubg-analyzer`.log_player_take_damage
(
    id                   int auto_increment primary key,
    attack_id            int          null,
    attacker_account_id  varchar(255) null,
    attacker_health      float        null,
    attacker_name        varchar(255) null,
    attacker_ranking     int          null,
    attacker_team_id     int          null,
    damage               float        null,
    damage_causer_name   varchar(255) null,
    damage_reason        varchar(255) null,
    damage_type_category varchar(255) null,
    match_id             varchar(255) null,
    timestamp            datetime(6)  null,
    victim_account_id    varchar(255) null,
    victim_health        float        null,
    victim_name          varchar(255) null,
    victim_ranking       int          null,
    victim_team_id       int          null
);

attack_id, victim_name, attacker_name, damage, timestamp를 묶어 unique로 설정해 줬다.

놀랍게도 이 5가지 컬럼이 겹치는 로그가 존재했다. 혹시나 싶어서 timestamp까지 넣었는데…

 

실패

 

 

# 2 락 (메소드)

telemetry 조회 메소드에 synchronized를 붙여 오직 한 스레드만 접근하도록 하는 방법.

@Service
public class AnalyzerService {
  // ...
  @Cacheable(value = "analyze", key = "#match.id + '_' + #team.teamId")
  public synchronized Analyzer findLogs(Match match, Roster team) {
      String matchId = match.getId();
      Set<String> memberNames = team.extractParticipantName();
      // db 조회
      if (existTelemetry(matchId)) return findTelemetry(matchId, memberNames);

      // API 요청
      return requestTelemetry(match, memberNames);
  }
  // ...
}

 

기대하는 동작

 

실제 동작

@Cacheable 어노테이션은 프록시 객체를 사용해서 AOP로 구현된다.

따라서, 캐시 확인은 동시에 (락 없이) 진행되고 그다음 로직에만 락이 걸리게 된다.

 

개선 방법 (예시)

@Service
public class AnalyzerServiceProxy {
  private final AnalyzerService analyzerService;

  public synchronized Analyzer findLogs(Match match, Roster team) {
      return analyzerService.findLogs(match, team);
  }
  // ...
}

public class AnalyzerService {
  // ...
  @Cacheable(value = "analyze", key = "#match.id + '_' + #team.teamId")
  public Analyzer findLogs(Match match, Roster team) {
      String matchId = match.getId();
      Set<String> memberNames = team.extractParticipantName();
      // db 조회
      if (existTelemetry(matchId)) return findTelemetry(matchId, memberNames);

      // API 요청
      return requestTelemetry(match, memberNames);
  }
  // ...
}

기존 Service를 감싸 @Cacheable이 동작하기 전에 synchronized를 동작하는 방법이다.

하지만, 앞선 요청의 비즈니스 로직이 모두 완료될 때까지 캐시데이터도 읽어오지 못하고 대기해, 성능 저하가 우려되었다.

 

실패

 

# 3 락 (DB)

DB에 저장된 데이터가 확인할 때부터 락을 걸고 조회하는 방법.

 

1. S-Lock으로 조회데드락 발생 가능성 존재.

2. X-Lock으로 조회

역시 성능 저하 우려.

 

실패

 

# 4 트랜잭션 Isolation Level 설정

MySQL의 Isolation Level 기본값은 Repeatable Read이다.

이것을 Read Uncommitted로 설정해 더티리드 활용했다.

 

보통 Read Uncommited의 격리수준은 권장되지 않는다고 한다.

 

그 이유로는 더티 리드, 팬텀 리드 넌리피티드 리드 등의 무결성, 일관성에 문제가 생기기 때문이다.

 

하지만, 나의 경우 데이터는 PUBG에서 제공해주고 나는 그것을 DB에 저장하고 서빙하는 것 뿐이다.

따라서, 수정 중 롤백되거나, 같은 쿼리를 날렸을 때 서로 다른 결과가 나올 우려가 없었다.

 

코드 예시

public class AnalyzerService {
  // ...
  public Analyzer findLogs(Match match, Roster team) {
      String matchId = match.getId();
      Set<String> memberNames = team.extractParticipantName();
      // db 조회
      if (existTelemetry(matchId)) return findTelemetry(matchId, memberNames);

      // API 요청
      return requestTelemetry(match, memberNames);
  }

  private Analyzer requestTelemetry(Match match, Set<String> memberNames) {
      // ...

      List<TelemetryResponse> telemetryResponses = pubgAPI.telemetry(match.getAsset().getUrl());

      // ...

      saveTelemetry(telemetryResponses);

      return Analyzer.analyzeOf(memberNames, telemetryResponses);
  }

  @Async("sqlExecutor")
  @Transactional(isolation = Isolation.READ_UNCOMMITTED)
  public void saveTelemetry(List<TelemetryResponse> telemetry) {

      if (existsTelemetry(telemetry)) { // 저장하기 직전 더블 체크
          return;
      }

      telemetry.saveAll(telemetry);
  }
}

 

저장하기 직전에 혹시 저장되고 있는 데이터가 있는지 확인한다.

이때 더티리드를 오히려 활용해서, 저장 중인 데이터가 있는지 확인 후 있으면 저장하지 않고 종료하도록 하였다.

 

만에 하나 저장하기 직전 확인이 동시에 일어난다면 두 세트 이상 로그가 저장되는 문제가 발생할 것 같다.

그러나, Isolation Level을 Serializable로 하자니 데드락이 발생할 가능성이 있을 것 같았다.

 

불필요한 대기 없이 캐싱된 데이터를 가져온다는 점, 데드락이 발생하지 않는다는 점, 가장 중요한 DB에 두 세트 이상 중복 저장될 수 있는 가능성을 줄였다는 점에서 완벽하진 않지만 문제를 어느 정도 해결하게 되었다.