이주호 · 개발 블로그

2. p99가 튀는데 아무도 안 던졌다 — 지연·에러비율은 증상이지 원인이 아니다

10 min read

핵심 한 줄

p99가 솟고 5xx가 쏟아져도 아무 예외도 던지지 않았다. 원인이 수십 가지인 증상이어서 국소화가 원천적으로 불가능하다 — LatencySaturation·ErrorRatioNoTrace는 차별 신호가 아니라 진단의 입구다.

시리즈 — 장애를 '구별 가능'하게 만든 카오스 벤치

0.서문 · 1.스택트레이스가 곧 원인인 유일한 순간 · 2.p99가 튀는데 아무도 안 던졌다 · 3.200 OK인데 답이 틀렸다 · 4.top frame은 표면이지 원인이 아니다 · 5.느린 쿼리의 진짜 범인은 인덱스 · 6.커넥션을 안 돌려줬다 · 7.CPU가 남는데 스로틀당했다 · 8.컨슈머가 못 따라잡았다 · 9.멈춘 건 GC였다 · 10.다 멈췄는데 데드락은 아니다 · 11.요청 하나에 쿼리 1+N · 12.캐시 만료에 떼로 몰렸다

1. 배경 — 알림이 왔다, 그런데 범인이 없다

운영 채널에 두 알림이 거의 동시에 날아왔다. LatencySaturation — owner 검색의 p99가 1초 임계를 넘었다. ErrorRatioNoTrace — vet 목록의 5xx 비율이 10%를 돌파했다. 온콜 담당자는 화면을 열었지만 예외 트레이스가 없다. 스택도, NPE도, SQL 오류도 — 아무것도.

이것이 W2의 출발점이다. 지연과 에러비율은 운영에서 가장 자주 뜨는 알림 유형이다. 그리고 가장 진단하기 어렵다. 원인이 N+1 쿼리일 수도, GC 폭주일 수도, 커넥션풀 고갈일 수도, 락 경합일 수도 있다. 전부 같은 숫자로 도착한다.

W1과 대비된다. 거기선 스택트레이스가 예외 클래스·파일·라인을 직접 가리켰다 — 알림이 곧 원인이었다. 여기선 아무것도 던지지 않는다. 신호의 성격이 근본적으로 다르다.

2. 무엇을 망가뜨렸나 — N+1 지연과 투명한 5xx

두 개의 chaos fault를 심었다.

지연 fault — ownerListLatency: OwnerController.processFindForm에 N+1 루프를 삽입한다. amplifyOwnerReads()가 true를 반환하면 검색 결과의 각 행마다 findById를 한 번 더 날린다. k6가 50 VUs로 GET /owners?lastName=을 60초 동안 두드리면, 추가 쿼리와 커넥션풀 경합이 합쳐져 p99가 임계를 돌파한다.

에러비율 fault — vetListError: VetController.showVetList 진입부에서 maybeFailVetList()를 호출한다. armed 상태면 ResponseStatusException(500, "vet directory upstream unavailable")을 던진다. 앱 코드에 실제 결함은 없다 — 그냥 프레임워크가 5xx를 내뱉는다. 20 VUs가 GET /vets.html을 45초 두드리면 SERVER_ERROR 비율이 10% 임계를 넘는다.

// OwnerController.processFindForm — 지연 seam (chaos profile에서만 활성화)
if (this.chaosFaults.amplifyOwnerReads()) {
    // N+1: 각 행마다 findById 한 번 더 — 예외 없이, 그냥 쿼리만 더 나간다
    for (Owner each : ownersResults) {
        this.owners.findById(each.getId());
    }
}
 
// VetController.showVetList — 에러비율 seam
this.chaosFaults.maybeFailVetList();
// armed이면 ResponseStatusException(500) 투척 → 앱 내부 결함은 없음

두 seam 모두 ChaosFaults 인터페이스를 통해 주입되며, chaos 프로파일 밖에선 NoOpChaosFaults가 no-op으로 대체한다. ./gradlew test는 항상 green이다.

3. 증상 — p99↑, 5xx↑, 그런데 스택트레이스 없음

scripts/smoke/latency-to-slack.sh가 ownerListLatency를 arm하고 k6를 붙이면 LatencySaturation 규칙이 발화한다.

histogram_quantile(0.99,
  sum by (le) (
    rate(http_server_requests_seconds_bucket{uri="/owners"}[1m])
  )
) > 1

scripts/smoke/error-ratio-to-slack.sh가 vetListError를 arm하고 k6를 붙이면 ErrorRatioNoTrace가 발화한다.

sum(rate(http_server_requests_seconds_count{outcome="SERVER_ERROR"}[1m]))
  / sum(rate(http_server_requests_seconds_count[1m]))
> 0.1

Slack에 알림이 오고 대시보드에 빨간 선이 그어진다. 하지만 Loki를 뒤져도, 앱 로그를 훑어도 원인을 가리키는 예외가 없다. ResponseStatusException은 프레임워크가 내는 것이지 특정 비즈니스 로직을 가리키지 않는다. N+1 루프는 예외를 전혀 내지 않는다 — 그냥 쿼리를 더 날릴 뿐이다.

4. 판별 신호 — 왜 이건 원인이 아니라 증상인가

지연과 에러비율이 증상인 이유는 하나다: 국소화 불가능하다.

W1의 ClassAOwnerSearchNPE 알림은 스택트레이스 한 줄이 원인의 위치를 특정했다. 판별 신호가 유일했다. 반면 지연과 5xx는 아래처럼 수십 가지 원인이 동일한 알림을 낸다.

원인LatencySaturationErrorRatioNoTrace스택트레이스
N+1 쿼리 (W2)예—없음
opaque 5xx (W2)—예없음
커넥션풀 고갈 (W6)예예(타임아웃 후)없음/있음 혼재
GC 폭주 (W9)예—없음
락 경합 (W10)예—없음
캐시 스탬피드 (W12)예—없음

같은 알림이 이 많은 원인에서 올 수 있다면, 그 알림 자체는 원인을 특정하지 못한다. 이것이 Class C — 증상 알림의 정의다. 국소화를 위한 추가 신호(쿼리 수·BLOCKED 스레드·GC pause 빈도·커넥션 대기)가 반드시 뒤따라야 한다.

5. 그래서 무엇을 하나 — 차별 진단의 입구로만 쓴다

LatencySaturation과 ErrorRatioNoTrace를 없애야 할까? 아니다. 이 알림들은 *“지금 뭔가 잘못됐다”*는 신호로서 필수다. 다만 기대치를 조정해야 한다.

이 알림이 발화했을 때 해야 할 일은 원인을 여기서 결론 내리는 것이 아니라, 차별 진단을 시작하는 것이다. 후보를 나열하고 각 후보의 판별 신호를 조회한다.

각각의 판별 신호는 해당 편에서 다룬다. W2의 역할은 그 진단 트리의 루트 노드 — “지금 지연 또는 에러가 발생했다. 원인 탐색을 시작하라.”

6. 교훈

증상 알림은 진단의 끝이 아니라 시작이다

LatencySaturation·ErrorRatioNoTrace는 *“무언가 잘못됐다”*는 사실만 알려준다. 원인은 수십 가지이고, 알림 자체엔 국소화 정보가 없다. 이 알림을 받고 “어디가 문제지?”를 바로 결론 내리면 반드시 오진한다. 먼저 “어떤 원인의 판별 신호를 다음에 볼 것인가?”를 물어야 한다. 증상 알림의 가치는 진단을 촉발하는 것이지 진단을 완결하는 것이 아니다.

관련 글

그래프 뷰

백링크