병목 분석 실전 — APM·프로파일러로 계층 짚기

개념

병목은 "느린 것"이 아니라 "가장 먼저 포화되는 것"

부하를 걸었더니 p95가 레슨 2에서 잡은 예산 800 ms를 넘어 2,230 ms가 나왔다. 이때 "느린 곳을 찾는" 일은 도움이 안 된다. 부하를 받으면 거의 모든 구간이 조금씩 느려지므로 "여기도 저기도 느리네요"로는 아무것도 결정하지 못한다. 찾아야 하는 것은 가장 먼저 한계에 닿아 뒤쪽 전체를 기다리게 만드는 단 하나의 지점 이고, 그래서 병목 분석은 절대값이 아니라 부하 대비 증가율 을 본다.

부하 3단계에서 계층별 p95 (ms)
             19 rps   60 rps   121 rps   증가율
  네트워크      120      125       130     ×1.08
  앱 로직       180      195       240     ×1.33
  DB 조회       240      610     1,420     ×5.92   ← 병목
  외부 결제     420      430       440     ×1.05
  전체 p95      960    1,360     2,230

절대값 1위는 외부 결제(420 ms)지만 병목은 DB다. 외부 결제는 느리지만 부하에 반응하지 않는다 — 포화되지 않은 것이다. 절대값으로 병목을 고르면 손댈 수 없는 외부 API를 붙잡고 몇 주를 보낸다.

계층을 좁히는 순서 — 밖에서 안으로

바깥 계층을 먼저 배제해야 안쪽 숫자를 믿을 수 있다. 앱 로그의 처리 시간이 200 ms인데 사용자가 4초를 기다린다면, 앱을 아무리 프로파일링해도 원인이 안 나온다.

실무에서는 계층별 측정값을 계단으로 늘어놓고 차를 본다. 부하 도구 p95 2,230 → LB의 upstream_response_time 2,080(밖에서 150) → 앱 액세스 로그 2,010(프록시 70) → APM 스팬 합계 1,860(DB 1,420 + 외부 440) → 순수 앱 CPU 150. 64%가 DB 스팬이므로 조사를 4번 계층으로 내린다. 이 계단 없이 프로파일러를 켜는 것이 가장 흔한 시간 낭비다. 각 계층의 측정 지점은 레슨 2의 응답 시간 예산 표에 이미 적혀 있다.

USE 와 RED — 자원 축과 요청 축

지표를 아무렇게나 늘어놓으면 장애 중에 아무도 못 읽는 그래프 벽이 된다. USE 방법(Brendan Gregg)은 자원 관점으로 모든 자원에 대해 사용률(Utilization)·포화(Saturation)·오류(Errors)를 본다. RED 방법(Tom Wilkie)은 요청 관점으로 모든 서비스에 대해 비율(Rate)·오류(Errors)·지속시간(Duration)을 본다. Google SRE 책의 네 가지 골든 시그널(지연·트래픽·오류·포화)은 RED 셋에 USE의 포화를 더한 형태로 읽으면 된다.

RED는 "어느 서비스가 아픈가", USE는 "그 서비스 안의 어느 자원이 막혔는가" 를 가리킨다. RED 축은 서비스·엔드포인트마다 rps / 5xx·타임아웃·업무실패율 / p50·p95·p99 를 깔고, USE 축은 자원마다 세 칸을 채운다.

핵심은 포화 칸이다. 사용률은 상한이 100%라 더 올라가지 않지만 포화는 무한히 커지므로 부하를 올릴 때 가장 먼저 급격히 튀는 지표가 포화다. CPU 사용률 60%인데 run queue가 계속 4 이상이면 이미 줄이 서 있다는 뜻이다. 그런데 대부분의 대시보드에는 사용률만 있고, 큐 길이·큐 대기 시간이 없으면 스레드 풀 포화와 커넥션 풀 고갈을 부하 시험 중에 볼 수 없다.

경보 임계값과 오류 예산 소진율은 모듈 37 레슨 9, SLI·SLO 정의는 모듈 14 레슨 7이 담당한다. 여기서는 같은 지표를 부하 시험 중 원인을 좁히는 용도 로만 쓴다 — 운영 경보는 "지금 아픈가"를, 병목 분석은 "왜 아픈가"를 묻는다.

APM 트레이스 읽기 — 시간이 어디로 갔는가

읽는 법은 셋이다. 자기 시간(self time) — 부모 총 시간에서 자식 합계를 뺀 값, 즉 그 계층 자신이 쓴 시간. 스팬 개수 — 시간보다 개수가 먼저 튀는 병목이 있다. 모양 — 폭포(waterfall)의 실루엣만으로 유형이 갈린다.

(A) N+1 쿼리 — 짧은 스팬이 계단처럼 수십~수백 개
  GET /api/orders                        1,430ms
    └ OrderService.list                   1,410ms
        ├ SELECT * FROM orders LIMIT 20  8ms
        ├ SELECT * FROM users WHERE id=? 6ms  × 20회
        ├ SELECT * FROM items WHERE oid=?5ms  × 20회
  스팬 41개, 개별 최대 8ms. 쿼리는 빠르고 개수가 문제다 —
  임계값 100ms 슬로우 쿼리 로그에는 한 줄도 안 걸린다.
 
(B) 직렬 호출 — 긴 스팬이 계단 없이 옆으로 이어붙음
  GET /api/product/{id}                  1,180ms
    ├ HTTP GET review-service            310ms
    ├ HTTP GET recommend-service         380ms
    ├ HTTP GET inventory-service         290ms
  서로 기다릴 필요가 없는데 순서대로 돌았다(980 → 380ms).
  판정 근거: 스팬 시작 시각이 앞 스팬 종료 시각에 붙어 있다.
 
(C) 대기(락·자원 획득) — 앞이 비어 있는 스팬
  POST /api/orders                       2,050ms
    └ OrderService.create                 2,040ms
        ├ [대기] getConnection            1,700ms
        ├ UPDATE stock SET qty=qty-1 ... 280ms
  실제 DB 작업은 320ms뿐, 1,700ms를 "얻는 데" 썼다.
  판정 근거: 자기 시간이 크고 자식 스팬 합계가 작다 —
  커넥션 풀 고갈 또는 행 잠금 경합의 트레이스 지문이다.

(A)와 (C)를 구분하는 습관이 특히 중요하다. 둘 다 "DB 때문에 느림"으로 보고되지만 처방이 반대다. (A)는 쿼리를 줄이는 일(조인·일괄 조회·프리페치), (C)는 풀 크기나 트랜잭션 범위를 조정하는 일이고, (A)에 풀 크기를 늘리면 쿼리를 더 빨리 쏘게 되어 악화된다.

그리고 p99 구간의 트레이스를 골라 본다. 무작위로 열면 대개 빠른 요청이 나오지만, 느린 꼬리만 모으면 빠른 요청에는 없는 스팬(재시도, 캐시 미스, 리밸런싱)이 드러난다. 제품 화면 이름은 자주 바뀌므로 "지연 상위 구간의 트레이스 표본을 추출한다" 는 절차로 기억한다.

프로파일러와 플레임그래프

APM 스팬은 계측한 경계까지만 보여 준다. "앱 로직 240 ms" 안에서 어느 함수가 그 시간을 썼는지는 프로파일러의 일이다. CPU(on-CPU) 는 어느 스택이 CPU를 쓰는지, 할당·힙 은 어디서 객체를 많이 만드는지(GC 부담의 원인), 락·블로킹(off-CPU) 은 어느 스택이 기다리는지 를 보여 준다.

CPU 사용률이 낮은데 느리면 CPU 프로파일러는 아무것도 못 찾는다. 이 선택을 못 해 "프로파일링했는데 원인이 없습니다"로 끝나는 조사가 많다. 판단은 한 줄이다 — CPU가 바쁘면 on-CPU, 한가하면 off-CPU. 프로파일러는 부하가 걸린 상태에서 짧게, 스테이징에서 켠다. 샘플링 방식은 오버헤드가 작지만 모든 메서드 진입·종료를 기록하는 계측 방식은 결과를 왜곡할 만큼 느려진다 — 관측이 관측 대상을 바꾸는 것(observer effect) 을 늘 의심한다.

플레임그래프(Brendan Gregg 고안)는 샘플링된 스택을 집계한 그림이다. 처음 보면 반드시 오해하는 세 가지를 먼저 고정한다.

• x축은 시간이 아니다. 좌우 위치에 의미가 없고(보통 이름 순 병합·정렬) 왼쪽이 먼저 실행된 것도 아니다. 시간 순서를 보려면 플레임차트(flame chart)라는 다른 그림이 필요하다.
• 폭이 전부다. 프레임 폭은 그 스택이 표본에서 차지한 비율이다 — CPU 프로파일이면 CPU 시간의 몇 %, 할당 프로파일이면 할당량의 몇 %.
• y축은 스택 깊이다. 위로 갈수록 호출된 쪽이고, 위아래를 뒤집은 아이스클(icicle) 그래프도 내용은 같다.

읽는 절차는 셋이다. 첫째, 맨 위의 넓고 평평한 고원(plateau)을 찾는다. handleRequest 62% → loadOrders 51% → toEntity 46% → String.format 44% 로 좁혀지다 더 위가 없으면 String.format 이 고원이고, 거기서 실제로 일하거나 기다리는 것이다. 아래쪽 넓은 프레임은 모든 것의 부모라서 넓으므로 원인이 아니다. 둘째, 예상 밖의 프레임을 찾는다 — gcWorker 21% 처럼 업무 로직과 무관한 프레임이 두 자릿수면 그 자체가 결론이다. 셋째, 두 그림의 차이를 색으로 표시하는 차분 플레임그래프(differential flame graph) 로 개선 전후를 겹쳐 "고친 것이 실제로 줄었는가"를 확인한다.

전형적 병목 여섯 가지 — 무엇이 먼저 튀는가

각각 가장 먼저 움직이는 지표 가 다르고, 그것이 판별의 핵심이다.

N+1은 "시간"이 아니라 "개수"로 잡힌다. 6 ms 쿼리는 어떤 슬로우 쿼리 임계값에도 안 걸리므로 DB 모니터링만 보는 팀은 영원히 못 찾는다. 요청당 쿼리 개수를 지표로 만들면 "주문 목록 1회당 쿼리 수 ≤ 5" 처럼 응답 시간보다 안정적인 판정 기준이 된다. 커넥션 풀 고갈과 DB 느림은 자원 사용률 교차 확인으로 구분한다 — 풀 고갈이면 DB 서버 CPU·디스크가 한가하고 앱 쪽 획득 대기만 크다.

GC 정지와 스레드 풀 포화는 평균에 거의 안 나타난다. 200 ms 정지가 30초에 한 번이면 평균에는 몇 ms 영향이지만 그 순간의 요청은 전부 200 ms를 더 쓴다. p99에서만 보이고, 응답 시간 그래프의 주기적 스파이크와 GC 이벤트 타임스탬프를 겹쳐 보면 즉시 확인된다. 원인은 대개 GC 설정이 아니라 과도한 할당이므로 할당 프로파일러로 내려간다. 스레드 풀도 큐에서 1.5초 기다리고 실제 처리가 80 ms인데 큐 대기를 계측하지 않으면 "앱 처리 1.58초"로 뭉뚱그려진다 — 큐 길이 ÷ 처리율이 대기 시간이라는 레슨 2의 리틀의 법칙이 다시 쓰인다.

가설을 세우고 한 번에 하나만 바꾼다

1. 반증 가능한 가설 + 예측을 먼저 쓴다
   나쁨 : "DB가 느린 것 같다"
   좋음 : "주문 목록이 주문 20건마다 users 를 20회 조회해(N+1) 121 rps 에서
           DB QPS 가 2,400 까지 올라 커넥션 획득 대기가 생긴다.
           → 참이면 요청당 쿼리 수 41, 커넥션 대기 p95 300ms 이상"
2. 관측으로 예측 검증 (아직 코드를 고치지 않는다) — 41 ✓ / 410ms ✓
3. 변수 하나만 바꾼다 — users 를 일괄 조회로. 풀·인덱스·캐시는 그대로
4. 같은 조건으로 재측정 — 같은 워크로드·데이터·환경·워밍업·반복 횟수
   (이 조건을 지키는 방법은 레슨 4에서 다룬다)
5. 예측과 대조 — 쿼리 41 → 3, DB 스팬 p95 1,420 → 180, 전체 2,230 → 810
   ※ 병목이 사라지면 다음 병목이 드러난다 — 이번엔 앱 CPU 가 1위
6. 기록 (가설 / 근거 지표 / 변경 1개 / 전후 숫자 / 다음 용의자)

3번을 어기는 것이 압도적으로 흔한 실패다. 쿼리도 고치고 풀도 늘리고 인덱스도 추가한 뒤 빨라지면 무엇이 효과였는지 알 수 없고, 셋 중 하나가 악영향 을 줘도 전체 개선에 가려 안 보인다 — 그 설정이 다음 릴리스에서 장애를 만든다. 이미 여러 변경을 섞었다면 되돌리면서 하나씩 빼는 방향으로 같은 실험을 한다. 어느 쪽이든 변경 1개 ↔ 숫자 1개 의 대응이 남아야 한다. 병목은 하나를 고치면 반드시 다음 것이 나오므로 "몇 바퀴 돌고 멈출 것인가"가 다음 레슨의 주제다.

실무에서 왜 필요한가

성능 결함 보고서의 품질이 QA의 신뢰도를 결정한다. "주문 화면이 느립니다, p95 2.2초"로는 개발팀이 처음부터 다시 조사해야 한다. "p95 2,230 ms 중 1,420 ms가 DB 스팬이고 트레이스에 SELECT ... FROM users WHERE id=? 가 요청당 20회 반복됩니다(트레이스 ID 첨부). DB 서버 CPU는 18%로 한가하므로 쿼리 성능이 아니라 호출 횟수 문제로 보입니다" 라고 보고하면 그날 수정된다.

계층을 좁히는 능력은 책임 공방을 끝내는 도구 이기도 하다. 프런트엔드는 서버가, 백엔드는 DB가 느리다고 하고 DBA는 쿼리를 그렇게 보낸 쪽이 문제라고 한다 — 계단식 차분은 이 논쟁을 숫자 다섯 줄로 종결시킨다. 또 레슨 2에서 요청당 CPU를 40 ms에서 25 ms로 줄이면 인스턴스가 4대에서 2대가 됐는데, 그 15 ms를 어느 함수에서 줄일지 플레임그래프로 지목할 수 있으면 그 개선은 추정이 아니라 견적이 된다.

채용시장에서의 위치

공고의 "병목 구간 분석 및 튜닝 협업"이 이 레슨의 범위다. 면접 단골 질문은 "응답이 느린데 CPU는 한가합니다"(락·블로킹 프로파일, 풀 대기, 외부 호출 대기)와 "평균은 정상인데 p99만 튑니다"(GC 정지, 캐시 미스, 재시도, 데이터 왜곡) 둘이다. USE·RED는 SRE·플랫폼 엔지니어링과 공유하는 언어이고, 이 말을 쓸 수 있는지가 성능 QA와 "부하 도구 실행자"를 가른다.

실습 과제

과제 1 — 계층 차분으로 병목 계층 판정 (30분)

부하를 3단계(평시·2배·피크)로 걸고 계층별 소요를 수집한다. 로컬 샘플 앱이나 팀 스테이징을 쓰고, APM이 없으면 앱 로그에 구간 타임스탬프를 남긴다.

1. 사용자 체감 → LB → 앱 처리 → 스팬 합계 → 순수 CPU 구간의 계단을 만든다
2. 각 계층 p95를 3단계에 대해 정리하고 증가율 을 계산한다
3. 절대값 1위와 증가율 1위가 다르면 왜 다른지 한 문단으로 쓴다
4. 병목 계층을 한 문장으로 판정하고, 그 판정을 반증할 관측 하나를 적는다

과제 2 — 병목 세 가지를 재현하고 지표 지문 수집 (40분)

샘플 앱에 아래를 의도적으로 만들고 각각에서 가장 먼저 튀는 지표 를 기록한다.

A) N+1        : ORM 지연 로딩으로 목록 조회 시 연관 엔티티를 건별 조회
B) 풀 고갈     : DB 커넥션 풀을 2로 줄이고 동시 요청 50건 투입
C) 스레드 포화  : 앱 스레드 풀을 4로 줄이고 처리 200ms 핸들러에 부하

1. p50·p95·p99, 요청당 쿼리 개수, 커넥션 획득 대기 시간, 스레드 풀 큐 길이·큐 대기 시간, DB 서버 CPU와 앱 CPU 사용률을 표로 모은다
2. 세 상황을 자원 사용률 교차 확인만으로 구분할 수 있는지 판단하고, 못 하면 어떤 지표를 추가해야 하는지 적는다

과제 3 — 가설 검증 사이클 1회 (30분)

과제 2의 A 상황에 본문 6단계를 적용한다.

1. 반증 가능한 가설과 예측 지표값 을 먼저 쓰고, 코드를 고치지 않고 관측으로 검증한다
2. 변수 하나만 바꾸고 같은 조건으로 재측정해 예측과 대조한다
3. 병목이 사라진 뒤 새로 1위가 된 계층(다음 사이클의 입력)을 적고, 가설 / 근거 / 변경 1개 / 전후 숫자 / 다음 용의자 다섯 줄로 기록한다

자가 체크리스트

• 병목을 부하 대비 증가율로 판정하는 이유를 설명하고, 다섯 계층을 밖에서 안으로 배제하는 계단식 차분을 만들 수 있다
• USE(사용률·포화·오류)와 RED(비율·오류·지속시간)의 출처와 적용 대상 차이를 말할 수 있다
• 사용률만 보면 병목을 놓치는 이유를 설명하고, 자원별로 포화 칸까지 채운 배치표를 쓸 수 있다
• 트레이스 모양으로 N+1·직렬 호출·대기 병목을 구분하고, 자기 시간과 자식 합계의 의미 차이를 안다
• CPU가 한가한데 느릴 때 off-CPU·락 프로파일러를 고르고, 플레임그래프의 x축이 시간이 아니고 폭이 표본 비율임을 알고 맨 위의 고원을 찾을 수 있다
• 여섯 가지 전형적 병목에서 먼저 튀는 지표를 각각 댈 수 있다
• 반증 가능한 가설을 쓰고 한 번에 하나만 바꿔 재측정하는 절차를 따를 수 있다

흔한 실수

• 가장 느린 구간을 병목으로 고른다. 부하와 무관하게 일정한 외부 API는 느리지만 포화가 아니다. 3개 부하 수준의 증가율로 고른다.
• 바깥 계층을 배제하지 않고 프로파일러를 켠다. 앱 처리 200 ms인데 사용자가 4초를 기다리면 앱 프로파일은 아무것도 알려 주지 않는다.
• 사용률만 대시보드에 올린다. 큐 길이·큐 대기 시간이 없으면 스레드 풀 포화와 커넥션 풀 고갈이 "앱이 느림"으로 뭉뚱그려지고, 그 상태로 DB 성능 문제라며 티켓을 넘기면(DB CPU가 한가한지 확인하지 않고) 왕복만 늘어난다.
• N+1을 슬로우 쿼리 로그에서 찾는다. 6 ms 쿼리는 임계값에 안 걸린다. 요청당 쿼리 개수를 지표로 만든다.
• CPU가 한가한데 CPU 프로파일러만 돌리고, 트레이스를 무작위로 열어 본다. off-CPU·락 프로파일로 바꿔야 대기 스택이 보이고, 트레이스는 지연 상위 표본을 뽑아야 한다.
• 한 번에 여러 개를 바꾼다. 빨라져도 원인을 모르고, 그중 하나가 악영향을 줘도 가려진다. 변경 1개 ↔ 숫자 1개로 대응시킨다.

참고 자료

• Brendan Gregg — The USE Method — 사용률·포화·오류를 자원마다 배치하는 원 정의와 자원별 점검 목록
• Brendan Gregg — Flame Graphs — 축의 의미, CPU·off-CPU·할당 변종, 차분 플레임그래프
• Grafana Labs — The RED Method — Tom Wilkie가 정리한 Rate·Errors·Duration 배치
• Google SRE Book — Monitoring Distributed Systems — 네 가지 골든 시그널, OpenTelemetry — Traces — 스팬 표준 정의
• Brendan Gregg, Systems Performance(2nd ed.) — USE 방법과 off-CPU 분석의 원전. 도서 원문 확인
• ISTQB CT-PT 실러버스 — 성능 결과 분석 학습 목표. 인증 페이지에서 원문 확인
• 레슨 s5-m51-l02(응답 시간 예산·서비스 수요 프로파일) · s2-m37-l09(경보 설계와 오류 예산 소진율) · s4-m14-l07(SLI·SLO 정의) · s7-m21-l01(부하 도구 조작)