isdnetworks
Go back

만드는 쪽과 처리하는 쪽이 떨어져 있었다

보상 지급이 안 됐다는 문의를 확인했다. 게임 서버 로그에는 지급 요청 등록이 있고 거기서 끝이라 실제로 지급됐는지가 안 나온다.

Table of contents

Open Table of contents

두 프로세스로 나뉘어 있었다

구조가 이랬다.

게임 서버 → (큐에 넣음) → 지급 처리기 → 데이터베이스

사이에 Redis 리스트가 있어서 게임 서버가 RPUSH 하고 지급 처리기가 꺼내 간다. 게임 서버는 큐에 넣고 끝나므로 그 뒤가 안 남는다.

로그도 각자 남는다.

game-server.log    지급 요청 등록 uid=***
reward-worker.log  (여기를 봐야 한다)

처리기 로그를 보니 그 시각에 아무것도 없었다. 프로세스가 죽어 있었다.

원인 — 나눈 뒤를 안 봤다

왜 나눴는지 확인했다. 지급 처리가 외부 API 를 부르는데 그것이 느리거나 실패하면 게임 응답이 같이 느려지므로 분리한 것이었다.

분리 자체는 맞았고 문제는 그 뒤를 안 본 것이다.

이 구조에서는 한쪽 로그만 봐서는 아무것도 결론 낼 수 없다. 요청이 있고 처리가 없으면 아직 안 꺼낸 것이거나 처리하다 죽은 것이고 둘 다 있으면 정상인데 양쪽을 함께 봐야 어느 경우인지가 갈린다.

잇는 식별자를 넣었다

요청할 때 식별자를 만들어 양쪽 로그에 남겼다.

$reqId = uniqid('rw', true);
$this->redis->rpush('reward:queue', json_encode([
    'req_id' => $reqId,
    'uid'    => $uid,
    'item'   => $itemId,
    'at'     => time(),
]));
log_message('info', "[{$reqId}] 지급 요청 등록 uid={$uid}");

uniqid 로 만든 req_id 를 페이로드에 함께 넣는다. 처리기 쪽도 같은 값을 찍는다.

// 처리기
$job = json_decode($raw, true);
log_message('info', "[{$job['req_id']}] 지급 처리 시작");
...
log_message('info', "[{$job['req_id']}] 지급 완료");

식별자로 두 로그를 이을 수 있다.

$ grep "rw56a1f" game-server.log reward-worker.log

한 요청이 어디까지 갔는지 grep 한 번에 나온다. 나눠진 구조에서는 이렇게 잇는 값이 없으면 추적 자체가 안 된다.

큐 길이와 처리기의 생존

큐가 쌓이는 것도 알아야 했다.

$len = $this->redis->llen('reward:queue');

LLEN 값을 1분마다 기록하고 일정 값을 넘으면 알렸다. 기준을 정하는 것이 문제라 평소 값을 며칠 재 봤다.

평소     0~3
피크     10~20
장애 시  계속 증가

절대값보다 계속 증가하는지가 중요했다. 100이어도 처리되고 있으면 괜찮고 20이어도 10분째 안 줄면 문제다.

큐 길이만으로는 부족하기도 했다. 요청이 없으면 LLEN 이 0이고 처리기가 죽어도 0이라 둘이 겉으로 같다.

$this->redis->setex('reward:worker:alive', 60, time());

SETEX 로 60초짜리 키를 두면 살아 있는 동안은 계속 갱신하니 안 사라진다.

if (!$this->redis->exists('reward:worker:alive')) {
    alert('지급 처리기 응답 없음');
}

감시하는 쪽에서 이 키가 없으면 죽은 것이다. 큐가 빈 것과 처리기가 죽은 것을 구분할 수 있게 됐다.

실패한 작업의 보존

처리하다 실패하면 그 작업이 사라지고 있었다.

$raw = $this->redis->lpop('reward:queue');

LPOP 은 꺼내는 순간 큐에서 없어져서 처리 중에 프로세스가 죽으면 그 작업은 어디에도 없다. 매뉴얼도 이 형태의 큐를 신뢰할 수 없다고 적어 두고 있다.

처리 중 목록으로 옮기는 방식으로 바꿨다.

$raw = $this->redis->rpoplpush('reward:queue', 'reward:processing');

RPOPLPUSH 는 꺼내는 것과 처리 중 목록에 넣는 것이 한 번에 일어난다. 처리가 끝나면 그 목록에서 지우고 안 지워진 것이 남아 있으면 처리 중에 죽은 것이다.

while ($raw = $this->redis->lpop('reward:processing')) {
    $this->redis->rpush('reward:queue', $raw);
    log_message('warning', '미완료 작업 복구');
}

시작할 때 reward:processing 을 확인해서 되돌리게 했다. 매뉴얼이 안내하는 형태가 그것이었다.

정리

Share this post on:
Share this post via WhatsApp Share this post on Facebook Share this post on X Share this post via Telegram Share this post on Pinterest Share this post via email
Previous Post
게임 서버에 루프가 둘이었다
Next Post
파일 하나에 프로세스 하나를 띄우고 있었다