[성능 테스트] 4. 결과 분석과 병목 진단

벤치마크를 실행하면 숫자가 나온다. "245ms vs 18ms니까 13배 빠르다"에서 끝내면 벤치마크를 돌린 의미가 절반이다. 왜 그 차이가 나는지를 설명할 수 있어야 하고, Error 값이 의미하는 신뢰 구간, p99 레이턴시의 실무적 의미, EXPLAIN ANALYZE와 연결하는 방법까지 알아야 벤치마크 결과를 제대로 활용할 수 있다.

JMH 결과 읽기

기본 출력 형태

Benchmark                          Mode  Cnt    Score    Error  Units
FeedBenchmark.n1Query              avgt   10  245.312 ± 12.456  ms/op
FeedBenchmark.batchQuery           avgt   10   18.734 ±  2.103  ms/op
FeedBenchmark.elasticsearchQuery   avgt   10   12.891 ±  1.567  ms/op

각 컬럼의 의미를 정확히 이해해야 한다.

• Mode — avgt는 Average Time. 한 번 실행하는 데 걸린 평균 시간이다.
• Cnt — 측정 횟수. Fork 2 × Iteration 5 = 10회.
• Score — 측정된 평균값. 245.312 ms/op은 "한 번 호출에 평균 245ms"다.
• Error — 95% 신뢰 구간의 반폭. ± 12.456이면 진짜 평균이 232.856 ~ 257.768ms 사이에 있을 확률이 95%라는 뜻이다.

Error 비율과 신뢰도

Error / Score 비율이 10%를 넘으면 측정이 불안정하다는 신호다.

Score	Error	비율	판단
245.3	±12.4	5%	안정적
245.3	±45.0	18%	불안정 — 측정 횟수 증가 필요
245.3	±120.0	49%	무의미 — 환경 문제 의심

Error가 큰 원인은 대부분 외부 요인이다. GC가 측정 구간에 침범했거나, 컨테이너 DB의 캐시 상태가 Iteration마다 달랐거나, 호스트 머신의 CPU가 다른 프로세스에 점유당한 경우다.

백분위수 분석 — SampleTime

AverageTime은 평균만 보여준다. 평균이 18ms여도 p99가 200ms면 100번 중 1번은 사용자가 0.2초를 기다린다. SampleTime 모드를 사용하면 분포를 확인할 수 있다.

@BenchmarkMode(Mode.SampleTime)
@OutputTimeUnit(TimeUnit.MILLISECONDS)

결과에 백분위수가 추가된다.

Benchmark                                    Mode  Cnt    Score   Error  Units
FeedBenchmark.batchQuery                   sample  500   18.734 ± 2.103  ms/op
FeedBenchmark.batchQuery:p0.50            sample        16.121          ms/op
FeedBenchmark.batchQuery:p0.90            sample        22.456          ms/op
FeedBenchmark.batchQuery:p0.95            sample        28.789          ms/op
FeedBenchmark.batchQuery:p0.99            sample        45.123          ms/op
FeedBenchmark.batchQuery:p0.999           sample       112.456          ms/op
FeedBenchmark.batchQuery:p1.00            sample       187.654          ms/op

각 백분위수의 실무적 의미

• p50 (중앙값) — 절반의 요청이 이보다 빠르게 처리된다. 평균보다 중앙값이 "체감 성능"에 가깝다.
• p90 — 10번 중 9번은 이 시간 안에 처리된다.
• p99 — 100번 중 99번. SLA 기준으로 자주 사용된다. "API 응답 시간 p99 < 100ms" 같은 형태.
• p99.9 — 1000번 중 999번. GC 스파이크나 커넥션 풀 대기 같은 간헐적 지연이 여기서 드러난다.
• p100 (최대값) — 최악의 경우. 아웃라이어 하나에 좌우되므로 이것만으로 판단하면 안 된다.

p50과 p99의 차이가 크다면(위 예시에서 16ms vs 45ms, 약 3배), 간헐적 성능 저하 원인을 추적할 필요가 있다. DB 커넥션 풀 경합, GC pause, 디스크 I/O 스파이크 등이 원인이 될 수 있다.

EXPLAIN ANALYZE로 쿼리 플랜 확인

JMH가 "얼마나 걸리는지"를 알려준다면, EXPLAIN ANALYZE는 "왜 그만큼 걸리는지"를 알려준다. 벤치마크 결과에서 차이가 확인되면, 해당 쿼리의 실행 계획을 반드시 확인해야 한다.

기본 사용법

EXPLAIN ANALYZE
SELECT f.*
FROM feeds f
WHERE f.created_at < '2026-04-14T00:00:00Z'
ORDER BY f.created_at DESC
LIMIT 21;

결과는 이런 형태다.

Limit  (cost=0.42..1.85 rows=21 width=456)
       (actual time=0.032..0.045 rows=21 loops=1)
  ->  Index Scan Backward using idx_feeds_created_at on feeds
        (cost=0.42..68234.42 rows=1000000 width=456)
        (actual time=0.031..0.042 rows=21 loops=1)
Planning Time: 0.089 ms
Execution Time: 0.058 ms

읽는 순서

실행 계획은 안쪽(들여쓰기가 깊은 곳)에서 바깥쪽으로 읽는다.

• cost — 플래너가 추정한 비용. 첫 번째 값은 첫 행을 반환하는 비용, 두 번째 값은 전체 비용.
• actual time — 실제 소요 시간 (ms). 이것이 진짜 측정값이다.
• rows — 처리한 행 수. 추정(rows)과 실제(actual rows)가 크게 차이나면 통계가 부정확한 것이다.
• loops — 이 노드가 몇 번 실행됐는지.

N+1 vs 배치의 쿼리 플랜 차이

N+1 방식의 좋아요 카운트

-- 이 쿼리가 피드 20건마다 반복
EXPLAIN ANALYZE
SELECT COUNT(*) FROM feed_likes WHERE feed_id = '특정-uuid';

Aggregate  (cost=8.30..8.31 rows=1 width=8)
           (actual time=0.025..0.025 rows=1 loops=1)
  ->  Index Only Scan using idx_feed_likes_feed_id on feed_likes
        (cost=0.43..8.29 rows=5 width=0)
        (actual time=0.018..0.021 rows=5 loops=1)

한 번에 0.025ms. 가볍다. 하지만 20번 반복하면 0.5ms + 네트워크 RTT 20회다.

배치 방식의 좋아요 카운트

EXPLAIN ANALYZE
SELECT fl.feed_id, COUNT(fl)
FROM feed_likes fl
WHERE fl.feed_id IN ('uuid-1', 'uuid-2', ..., 'uuid-20')
GROUP BY fl.feed_id;

HashAggregate  (cost=12.45..12.65 rows=20 width=24)
               (actual time=0.089..0.095 rows=20 loops=1)
  ->  Index Scan using idx_feed_likes_feed_id on feed_likes
        (cost=0.43..12.20 rows=100 width=16)
        (actual time=0.012..0.065 rows=100 loops=1)

한 번에 0.095ms로 20건의 카운트를 모두 가져온다. 개별 쿼리(0.025ms × 20 = 0.5ms)보다 빠르고, 네트워크 왕복도 1회다.

쿼리 자체의 실행 시간 차이보다 네트워크 왕복 횟수 차이가 더 큰 영향을 미친다. TestContainers 환경에서도 localhost 소켓 통신이므로 RTT가 0.1~0.5ms 정도인데, 이것이 쿼리 수에 곱해지면 무시할 수 없는 차이가 된다.

병목 구간 식별

JMH 결과에서 "느리다"는 것을 확인한 후, 어디가 느린지를 좁혀야 한다. 쿼리 성능 벤치마크에서 병목은 대체로 세 곳 중 하나에 있다.

DB 쿼리 실행 시간

EXPLAIN ANALYZE의 Execution Time이 길면 DB 내부 처리가 병목이다. 원인은 보통 세 가지다.

• Seq Scan — 인덱스를 안 타고 전체 테이블을 스캔. 100만 건 테이블에서 Seq Scan이면 수백 ms가 걸린다.
• Nested Loop — 조인 전략이 Nested Loop인데 내부 테이블이 크면 O(N × M)이 된다.
• Sort — ORDER BY에 인덱스를 못 쓰면 메모리나 디스크에서 정렬. Sort Method: external merge 가 보이면 디스크 정렬이다.

네트워크 왕복

DB 쿼리 하나하나는 빠른데 벤치마크 결과가 느리면, 쿼리 횟수가 문제다. N+1이 대표적이다. p6spy나 spring.jpa.show-sql=true로 실제 발생하는 쿼리 수를 세어 확인한다.

애플리케이션 레이어 처리

DB에서 가져온 데이터를 DTO로 변환하는 과정에서 시간이 걸릴 수 있다. S3 URL 생성, JSON 직렬화, 컬렉션 변환 등이 여기에 해당한다. JMH에서 DB 조회 부분과 DTO 변환 부분을 분리해서 측정하면 구간을 좁힐 수 있다.

결과 시각화

JSON 결과 활용

JMH의 resultFormat = 'JSON' 설정으로 결과를 JSON 파일로 저장하면, 시각화 도구로 그래프를 그릴 수 있다.

JMH Visual Chart

JMH JSON 결과를 웹에서 그래프로 변환해주는 도구들이 있다.

• JMH Visualizer — JSON 파일을 업로드하면 막대 그래프를 생성한다
• jmh-result-processor — 여러 실행 결과를 비교하는 차트를 만든다

직접 정리

단순 비교라면 표 하나로 충분하다.

| 방식 | 평균 (ms) | p99 (ms) | 쿼리 수 | 비고 |
|------|-----------|----------|---------|------|
| N+1 | 245.3 | 312.4 | 81 | 피드당 4쿼리 |
| 배치 | 18.7 | 45.1 | 5 | IN절 일괄 조회 |
| ES | 12.9 | 32.8 | 1+4 | 검색 1 + DTO 변환 4 |

숫자만 나열하지 말고, 왜 그 차이가 나는지를 쿼리 수와 실행 계획으로 설명하는 것이 핵심이다.

벤치마크 결과의 한계

그 외에도 벤치마크에서 재현하기 어려운 요소들이 있다.

• 동시 접속 — JMH 단일 스레드 벤치마크는 커넥션 풀 경합, 락 대기를 반영하지 않는다
• 캐시 히트율 — 프로덕션에서는 자주 조회되는 데이터가 DB 버퍼 캐시에 올라가 있다
• 네트워크 지연 — 로컬 Docker vs 원격 RDS의 RTT 차이
• 데이터 업데이트 부하 — INSERT/UPDATE/DELETE가 동시에 발생하면 쿼리 성능이 달라진다

이런 한계를 인지하면서도, 벤치마크는 구조적 차이를 수치로 확인하는 데 충분한 가치가 있다. "N+1이 배치보다 느리다"는 감이 아닌, "13배 느리고, 그 원인은 쿼리 수 81 vs 5의 차이다"라고 말할 수 있게 된다.

자주 하는 실수

면접 Q&A

---