Skip to Content
← 블로그
개선기

장애가 심해질수록 알람이 조용해졌습니다

INNER JOIN 한 줄이 감시 대상에서 장애 건만 정확히 골라 지웠다

만화로 보는 요약 — 먼저 읽어보세요
만화로 보는 요약 — 먼저 읽어보세요

제가 운영하는 QR 결제 중계 플랫폼에는 결제 장애를 자동으로 알아채는 경로가 딱 하나 있습니다. 30분마다 도는 배치가 최근 거래를 세어보고, 없으면 알람 채널로 쏩니다.

운영 장애가 났습니다. 거래 원장에는 실패 건이 쌓여 있었고, 그중 상당수는 결과 테이블에 행조차 없었습니다. 그런데 배치 로그에는 이렇게 찍혀 있었습니다.

[Payment] DEV Monitoring No Problem

세 줄 요약

  • 집계 쿼리가 거래 원장과 결과 테이블을 INNER JOIN 하고 있었습니다. 결제사 응답을 못 받은 실패 건은 결과 행이 없어 조인에서 탈락합니다. 장애가 심할수록 세어지는 건수가 줄어 더 정상처럼 보이는 역전이 있었습니다.
  • 판정 조건도 건수 == 0 하나뿐이라 승인과 실패를 구분하지 않았습니다. 구간에 어떤 거래든 하나만 있으면 정상입니다. 전 건이 실패하는 장애는 정의상 감지할 수 없었습니다.
  • 시간대를 먼저 의심했지만 집계는 멀쩡했습니다. 대신 알람 메시지 출력 쪽에 진짜 시간대 버그가 따로 있었습니다.

세는 게 줄어들면 건강해 보이는 쿼리

문제의 메서드는 이렇게 생겼습니다.

Long count = jpaQueryFactory
    .select(qp.count())
    .from(qp)
    .innerJoin(qpr).on(qp.id.eq(qpr.payment.id))   // ← 여기
    .where(qpr.createTime.between(to, from))        // ← 그리고 여기
    .fetchOne();

그리고 이걸 쓰는 쪽입니다.

if (result == 0) { /* 알람 */ }
else             { /* No Problem */ }

두 줄에 결함이 하나씩 있습니다.

첫째, state 필터가 없습니다. 승인이든 실패든 만료든 전부 한 덩어리로 셉니다. 이건 장애 감지기가 아니라 거래량 heartbeat입니다. "요청이 들어오고는 있는가"만 봅니다.

둘째, INNER JOIN이 하필 장애 건만 지웁니다. 결제사에 요청은 나갔는데 응답을 못 받은 상태 — 저희 도메인에서는 "1차 QR 수신실패"로 기록됩니다 — 는 결과 행이 만들어질 수가 없습니다. 응답이 없으니 저장할 결과가 없으니까요. INNER JOIN은 이 행들을 결과셋에서 전부 제거합니다.

WHERE 조건도 결과 테이블의 시각을 기준으로 잡고 있어서, 결과가 없는 거래는 구간 판정에서도 한 번 더 빠집니다.

이 둘이 곱해지면 이렇게 됩니다.

장애가 깊어질수록 감지 확률이 떨어집니다. 감시 도구가 가져야 할 성질의 정반대입니다.

시간대를 의심했다가 틀렸습니다

처음 이 현상을 봤을 때 저와 팀이 먼저 떠올린 건 시간대였습니다. 저희 DB는 UTC 기준이고 실제 거래는 KST로 이야기하니, 9시간 어긋나서 엉뚱한 구간을 본 게 아니냐는 것이었습니다. 실제로 코드를 열어보면 의심할 만하게 생겼습니다.

ZonedDateTime now = ZonedDateTime.now(clock);   // clock 은 Asia/Seoul
Instant nowUtc = now.toInstant();
...
qpr.createTime.between(to, from)                // 인자 순서가 뒤집혀 있다?

두 군데 다 결백했습니다.

ZonedDateTime.now(seoulClock).toInstant()Instant.now()완전히 같은 값입니다. Instant는 시간대 개념이 없는 절대시각(epoch)이고, 이걸 UTC 컬럼에 매핑하는 건 정확합니다. 존을 무엇으로 주든 결과가 같습니다.

between(to, from)도 마찬가지였습니다. 파라미터 이름이 의미와 반대라서 읽는 사람을 속이지만, 호출부가 (now, target) 순서로 넘기고 있어서 상쇄되어 동작상 정상이었습니다. 네이밍은 고쳐야 할 결함이지만 이 장애의 원인은 아니었습니다.

여기서 30분쯤 썼습니다. 그럴듯한 가설이 하나 있으면 다른 곳을 안 보게 되는데, 이번엔 그 가설이 코드 생김새로 뒷받침까지 됐습니다. 시간대가 아니라는 걸 확정한 뒤에야 조인을 보기 시작했습니다.

그런데 조사를 마무리할 때쯤 진짜 시간대 버그가 엉뚱한 데서 나왔습니다. 알람 메시지를 만드는 쪽이었습니다.

public static final DateTimeFormatter DATE_TIME_FORMATTER_V2 =
    DateTimeFormatter.ofPattern("yyyy-MM-dd HH:mm:ss")
        .withZone(ZoneId.systemDefault());   // ← 공용 유틸에 박혀 있음

ZonedDateTime에 이 포매터를 물리면, 포매터에 지정된 존으로 변환해서 출력합니다. 서버 JVM 기본 타임존이 UTC면 KST 시각이 UTC로 찍힙니다. 저장과 비교는 멀쩡한데 사람이 읽는 출력만 9시간 어긋나는 구조였습니다.

의심 방향은 맞았고 위치가 틀렸던 셈입니다. 저장 계층을 볼 게 아니라 표현 계층을 봤어야 했습니다.

창이 여섯 겹으로 겹쳐 있었습니다

조인을 고치려고 배치 설정을 다시 읽다가 하나 더 나왔습니다.

- name: "payment-dev"        # 30분 주기
  cron: "0 0/30 9-23,0 * * *"
DEV(3, 0),      // 3시간 0분을 되돌아본다

30분마다 실행하면서 3시간을 봅니다. 창이 여섯 겹으로 겹칩니다. 2시간 50분 전에 승인 한 건이 있으면, 그 뒤 여섯 번의 실행이 전부 "정상"으로 찍힙니다.

조인 결함이 없었더라도 이것만으로 감지가 상당히 무뎌졌을 겁니다. 두 결함이 서로를 가려주고 있었습니다.

판정을 "거래가 있는가"에서 "승인이 났는가"로

고치는 방향은 명확했습니다. 다만 지표를 몇 개로 쪼갤지가 결정 지점이었습니다.

하나로 두는 안을 먼저 생각했습니다. state가 승인 완료인 건만 세고 0이면 알람. 조인만 LEFT로 바꾸면 되니 변경이 가장 적습니다. 하지만 이러면 "승인은 나는데 절반이 실패하는" 상태를 못 봅니다. 승인 1건만 있어도 통과니까요.

둘로 나누는 안은 승인 건수 + 실패율입니다. 여기까지 오면 대부분 잡힙니다. 그런데 이번 장애의 핵심이었던 "결과 행이 없는 거래"는 여전히 지표로 안 드러납니다. 실패율에 섞여 들어갈 뿐입니다.

결국 넷으로 쪼갰습니다.

지표세는 것담당하는 장애
total구간 유입 전체유입 자체
approved승인 완료승인 전면 중단
failed실패·만료승인 처리 장애
orphan결과 행 없음결제사 응답 수신 장애

orphan을 따로 세운 게 이번 설계의 핵심입니다. 앞의 셋으로는 "결제사와의 연결 자체가 끊긴 상태"를 구분할 수 없습니다. 그리고 이 지표를 세려면 결과가 없는 행이 결과셋에 남아야 하므로 LEFT JOIN이 필수가 됩니다. 원인이었던 조인이 이제 지표의 근거가 된 셈입니다.

쿼리는 CASE-WHEN SUM으로 한 번에 뽑습니다. 지표가 넷이라고 스캔을 네 번 할 이유는 없습니다.

NumberExpression<Long> approvedCount = countWhen(
    qp.state.eq(COMPLETED).and(qp.latestStage.in(APPROVED_STAGES)));
NumberExpression<Long> orphanCount = countWhen(qpr.id.isNull());

jpaQueryFactory
    .select(totalCount, approvedCount, failedCount, orphanCount)
    .from(qp)
    .leftJoin(qpr).on(qpr.payment.id.eq(qp.id))
    .where(inWindow(from, to))
    .fetchOne();

그리고 판정 결과와 무관하게 네 지표를 매번 로그에 남기게 했습니다. 이전 코드는 No Problem만 찍고 숫자를 남기지 않아서, 사후에 "왜 정상으로 봤는지" 확인할 방법이 없었습니다. 이번 장애를 분석할 때 제일 답답했던 부분입니다.

between도 반개구간으로 바꿨습니다. 양끝을 포함하면 경계 시각 거래가 인접한 두 구간에 중복 집계됩니다. 30분마다 도는 배치에서는 이게 매 실행마다 발생합니다.

여기까지 하고 단위 테스트 16건을 붙여 커밋했습니다.

요구가 늘자 앞의 설계가 흔들렸습니다

여기서 끝날 줄 알았는데, 감시 항목을 더 넣자는 이야기가 나왔습니다. 승인 건수, 승인성공률, 연속 실패 이렇게 셋을 한 번에 로그로 보고 싶다는 요구였습니다.

단순한 추가 작업이라고 생각했습니다. 그런데 요구를 구체화하는 과정에서 앞서 만든 설계의 결함이 셋 나왔습니다.

1️⃣ 승인 모니터링인데 환불 거래가 섞여 있었습니다

거래 원장에는 승인·취소·환불이 함께 들어갑니다. 그런데 제가 짠 집계에는 거래 유형 필터가 없었습니다.

지표가 total, approved, failed뿐일 때는 이 결함이 잘 안 드러납니다. 환불 거래가 좀 섞여도 "거래가 있긴 하다"는 판단은 크게 안 바뀌니까요. 그런데 승인성공률을 계산하는 순간 치명적이 됩니다.

환불 실패가 승인 실패로 둔갑해서 승인성공률을 끌어내립니다.

승인 모니터링이므로 승인 유형으로 한정해야 합니다. 지표를 하나 추가하려다가 기존 지표 전체의 전제가 틀렸다는 걸 알게 된 경우입니다.

2️⃣ 성공률의 분모를 무엇으로 둘 것인가

처음에는 failed / total로 실패율을 재고 있었습니다. 그런데 total에는 아직 종결되지 않은 거래가 들어갑니다. 대기 상태, 진행 중 상태요.

30분 구간의 끝자락에 들어온 거래는 당연히 아직 진행 중입니다. 이걸 분모에 넣으면 어떻게 되냐면:

승인 8 · 실패 2 · 진행중 10  (전체 20)

전체 기준:  8 / 20      = 40.0%    ← 진행중 10건이 실패처럼 계산됨
종결 기준:  8 / (8+2)   = 80.0%    ← 실제 성공률

저트래픽 구간일수록 왜곡이 커집니다. 유입이 적으면 진행 중 건의 비중이 상대적으로 커지니까요. 하필 알람이 가장 민감해야 할 구간에서 가장 부정확해집니다.

결제 도메인에서 승인성공률은 종결된 거래 기준이어야 합니다. 분모를 approved + failed로 잡고, 로그에도 successRate=83.3%(40/48)처럼 분모를 괄호로 노출하기로 했습니다. 나중에 이 로그를 보는 사람이 "왜 52가 아니지?" 하고 헷갈리지 않도록요.

여기서 표본 하한도 함께 넣었습니다. 종결 2건 중 1건 실패면 성공률 50%지만 통계적으로 아무 의미가 없습니다. 종결 건이 일정 수 미만이면 성공률 판정 자체를 건너뜁니다.

3️⃣ 구간을 정렬해야 했습니다

"연속 실패"를 어떻게 정의할지 논의하다가 나온 건입니다.

저는 처음에 연속 실패 판정용으로 **별도의 긴 조회 창(2시간)**을 제안했습니다. 30분 안에는 표본이 부족해서 판정이 자주 불가능해질 거라고 봤기 때문입니다.

이 제안은 기각됐고, 기각한 쪽이 옳았습니다. 창이 지표마다 다르면 로그 한 줄에 찍힌 숫자들을 서로 대조할 수 없습니다. 검증용 SQL도 두 벌이 됩니다. 표본이 부족한 구간은 어차피 "승인 0건" 판정이 이미 커버합니다 — 저트래픽은 승인 건수가 잡고, 고트래픽은 성공률과 연속 실패가 잡는 식으로 역할이 나뉩니다.

그래서 모든 지표를 하나의 30분 구간으로 통일했는데, 그러면서 더 중요한 문제가 드러났습니다. 구간을 어디에 맞출 것인가입니다.

제 구현은 now - 30분 ~ now였습니다. 배치가 10시 30분 3초에 실행되면 구간이 10:00:03 ~ 10:30:03이 됩니다. 실행이 늦어지면 구간도 밀립니다.

정각 경계에 맞추면 이렇게 됩니다.

정렬 전:  10:00:03 ~ 10:30:03   실행 지연만큼 흔들림, 재실행하면 다른 값
정렬 후:  10:00:00 ~ 10:30:00   항상 같은 구간, 멱등

정렬해야 하는 이유가 실무적입니다. 재실행해도 같은 값이 나와야 로그의 구간을 그대로 SQL에 넣어 검증할 수 있습니다. 구간이 정확히 이어붙어서 빈틈도 겹침도 없다는 것도 덤입니다.

그리고 여기서 파생되는 결정이 하나 더 있었습니다. 10시 30분에 도는 배치는 어느 구간을 봐야 하는가.

직전에 완결된 구간을 봐야 합니다. 진행 중인 구간을 보면 데이터가 몇 초치뿐이라 매번 "승인 0건" 알람이 터집니다. 당연해 보이지만 now - 30분으로 짜면 자동으로 이렇게 되지 않습니다.

대신 대가가 있습니다. 감지가 최대 30분 지연됩니다. 10시 0분 1초에 장애가 시작되면 10시 30분 배치가 잡습니다. 기존 3시간 창보다는 훨씬 낫지만 실시간은 아닙니다. 이건 정렬을 택한 대가로 받아들이기로 했습니다.

부수적으로 하나 더 나왔습니다. 수동 실행 API로 테스트할 때 방금 만든 거래가 안 잡힙니다. 17시 5분에 테스트 거래를 만들고 17시 10분에 API를 때리면 [16:30, 17:00) 구간을 보기 때문입니다. 그래서 수동 호출에는 구간을 직접 지정할 수 있는 선택 파라미터를 두기로 했습니다. 없으면 배치와 동일하게 동작하고, 주면 그 구간을 봅니다. 조회 전용이라 오용해도 데이터가 상하지 않습니다.

인덱스를 어디에 걸어야 하냐는 질문

마무리하면서 인덱스 이야기가 나왔습니다. "거래 원장이랑 결과 테이블 양쪽 생성 시각에 인덱스를 걸어야 하는 거죠?"

절반만 맞습니다.

결과 테이블의 생성 시각 인덱스가 필요했던 건 없앤 옛 쿼리 때문입니다. 종전에는 WHERE 조건이 결과 테이블의 시각이었으니까요. 새 설계는 거래 원장의 시각을 기준으로 옮겼고, 결과 테이블은 조인 키로만 씁니다. 그 컬럼을 조건에 쓰지 않습니다.

테이블필요한 것이유
거래 원장(거래유형, 생성시각) 복합 인덱스구간 조회 + 연속 실패의 역순 정렬까지 커버
결과 테이블조인 키 UNIQUE 제약성능이 아니라 정확성 문제

결과 테이블 쪽은 성능 이슈가 아닙니다. 1:1 관계로 설계해놓고 DB에는 일반 인덱스만 걸어둬서, 중복 행이 생기면 LEFT JOIN이 행을 증식시켜 집계가 부풀 수 있습니다. 제약이 없으면 조용히 틀립니다.

옛 쿼리의 흔적이 요구사항처럼 굳어져 있었던 셈입니다. 쿼리를 바꿀 때 인덱스 요구도 같이 재검토해야 한다는 걸 늦게 알았습니다.

아직 안 끝났습니다

정직하게 적어두겠습니다.

DB에 붙여 돌려본 적이 없습니다. 단위 테스트 16건은 통과했지만, 그 테스트는 저장소 계층을 mock으로 대체합니다. 즉 새로 짠 쿼리가 SQL로 변환되어 실제로 실행된 적이 한 번도 없습니다. 인터넷망에서는 결제 인프라를 띄울 수 없어서 여기까지가 한계였습니다.

특히 걱정하는 지점이 하나 있습니다. 거래 단계 컬럼은 표준 enum 매핑이 아니라 커스텀 컨버터로 매핑되는데, 이번에 IN 절에 처음 써봤습니다. 컨버터가 IN에 적용되지 않으면 승인 건수가 항상 0이 되고, 그러면 배치가 매번 알람을 쏩니다. 조용히 틀리는 게 아니라 시끄럽게 틀리는 쪽이라 금방 드러나긴 할 겁니다.

그래서 이관 문서에 로그와 대조할 SQL을 통째로 넣어뒀습니다. 배치 로그에 찍힌 네 숫자와 손으로 돌린 SQL의 네 숫자가 일치하는지 보면 이 문제가 즉시 판별됩니다.

임계치는 전부 추정값입니다. 성공률 80%, 연속 실패 5건, 결과 미적재 10건. 운영 실패율 통계를 보지 않고 정했습니다. 배포 후 며칠간 어느 사유로 몇 번 울리는지 보고 조정해야 합니다.

알람이 시끄러워질 겁니다. 종전 배치는 사실상 울린 적이 없었고, 그래서 이번 장애를 놓쳤습니다. 승인 기준으로 바꾸면 실제 장애에서 울리기 시작하지만 저트래픽 구간의 오탐도 함께 늡니다. 처음부터 조용하길 기대하면 안 됩니다.

남은 생각

이번 건에서 제일 오래 남는 건 감시 도구의 실패는 조용하다는 사실입니다.

결제 로직이 틀리면 고객이 알려줍니다. CS가 쌓이고 정산이 안 맞습니다. 그런데 감시 도구가 틀리면 "정상"이라는 출력이 계속 나옵니다. 틀렸다는 신호와 정상이라는 신호가 같은 모양입니다.

이번 배치는 몇 달간 No Problem을 찍고 있었고, 그동안 아무도 그게 의미 있는 정상인지 의심하지 않았습니다. 저를 포함해서요.

그래서 판정 결과와 무관하게 지표를 항상 로그에 남기게 한 변경이, 조인을 고친 것만큼 중요하다고 생각합니다. No Problem 옆에 approved=1이 찍혀 있었다면 누군가 한 번쯤 이상하다고 생각했을 겁니다.

한 달 전에 망취소 배치가 거래를 못 본 이야기를 썼습니다. 그때는 배치가 정상 동작하는데 조회 조건에서 거래가 빠진 경우였고, 이번엔 감시 배치 자신의 집계에서 장애 건이 빠진 경우입니다. 층은 다른데 형태가 같습니다. 안전망이 무엇을 못 보고 있는지는, 안전망 자신이 알려주지 않습니다.