부하테스트 및 병목 지점 분석 - 100-hours-a-week/KTB4-16th-Cloud GitHub Wiki

M12 부하테스트 진행 및 결과

1. Normal 부하 테스트 결과

Threshold 통과

지표 조건 결과
응답시간 (p95) < 500ms 185.77ms ✅
에러율 < 1% 0.00% ✅

전체 요약

항목 값
총 체크 수 5,832건 (성공률 100%)
총 요청 수 (HTTP) 10,983건
요청 실패율 0.00%
초당 요청 수 (RPS) 26.1 req/s
총 반복(iteration) 687회
최대 VU (가상 사용자) 6

응답시간 (HTTP)

구분 값
평균 83.93ms
최소 37.12ms
중앙값 57.67ms
최대 3.42s
p90 150.46ms
p95 185.77ms

시나리오별 체크 항목

  • ✓ CSRF 발급 (200/204)
  • ✓ 회원가입 (201)
  • ✓ 로그인 (200)
  • ✓ 로그아웃 (2xx)
  • ✓ 사진 업로드 (201)
  • ✓ 자물쇠(record) 생성 (201)

네트워크

구분 값
수신 데이터 9.7 MB (23 kB/s)
송신 데이터 4.5 MB (11 kB/s)

2. Peak 부하 테스트 결과

Threshold 통과

지표 조건 결과
응답시간 (p95) < 800ms 460.9ms ✅
에러율 < 2% 0.00% ✅

전체 요약

항목 값
총 체크 수 17,558건 (성공률 100%)
총 요청 수 (HTTP) 33,180건
요청 실패율 0.00%
초당 요청 수 (RPS) 61.4 req/s
총 반복(iteration) 2,088회
최대 VU (가상 사용자) 18
실행 시간 9분 00.4초

응답시간 (HTTP)

구분 값
평균 115.07ms
최소 5.43ms
중앙값 54.46ms
최대 2.24s
p90 268.14ms
p95 460.9ms

시나리오별 체크 항목

  • ✓ CSRF 발급 (200/204)
  • ✓ 회원가입 (201)
  • ✓ 로그인 (200)
  • ✓ 사진 업로드 (201)
  • ✓ 자물쇠(record) 생성 (201)
  • ✓ 로그아웃 (2xx)

네트워크

구분 값
수신 데이터 30 MB (56 kB/s)
송신 데이터 14 MB (25 kB/s)

3. Stress 부하 테스트 결과

Threshold 통과 (여유 있게)

지표 조건 결과
에러율 < 50% 0.00% (69,622건 중 3건 실패) ✅

Stress 테스트는 "시스템이 터지는 지점"을 찾는 목적이라 p95 임계값은 별도로 없음.

전체 요약

항목 값
총 체크 수 36,888건 (성공률 99.99%)
총 요청 수 (HTTP) 69,622건
요청 실패율 0.00% (3건 타임아웃)
초당 요청 수 (RPS) 64.4 req/s
총 반복(iteration) 4,347회 완료 + 29회 중단(interrupted)
최대 VU (가상 사용자) 200
실행 시간 18분 01.6초

응답시간 (HTTP) — 부하 증가에 따라 크게 악화

구분 값
평균 1.18s
최소 6.27ms
중앙값 254.41ms
최대 30s (타임아웃)
p90 3.52s
p95 5.5s

발견된 이슈

고부하 구간에서 요청 타임아웃 3건 발생:

시점 실패 요청
925초 POST /api/uploads (사진 업로드)
962초 GET /api/places/popular
965초 GET /api/users/me
  • upload 201 체크: 99% 성공 (2,138건 중 1건 실패)
  • 반복(iteration) 29건이 끝까지 못 가고 중단됨 — VU가 200까지 올라간 구간과 겹침

시나리오별 체크 항목

  • ✓ CSRF 발급 (200/204)
  • ✓ 회원가입 (201)
  • ✓ 로그인 (200)
  • ✗ 사진 업로드 (201) — 1건 타임아웃
  • ✓ 자물쇠(record) 생성 (201)
  • ✓ 로그아웃 (2xx)

네트워크

구분 값
수신 데이터 74 MB (68 kB/s)
송신 데이터 29 MB (27 kB/s)

해석

에러율 자체는 임계값(50%) 대비 매우 낮지만, VU 200 근처 구간에서 응답시간이 p95 5.5초까지 늘어나고 타임아웃이 발생하기 시작하는 건 개발서버(e2-medium 단일 VM) 리소스 한계로 보임.

4. Spike 부하 테스트 결과

Threshold 통과

지표 조건 결과
에러율 < 30% 0.00% ✅

전체 요약

항목 값
총 체크 수 8,739건 (성공률 100%)
총 요청 수 (HTTP) 16,339건
요청 실패율 0.00%
초당 요청 수 (RPS) 85.0 req/s
총 반복(iteration) 1,009회 (중단 0건)
최대 VU (가상 사용자) 60
실행 시간 3분 12.3초

응답시간 (HTTP)

구분 값
평균 237.26ms
최소 6.62ms
중앙값 74.72ms
최대 3.09s
p90 701.42ms
p95 911.48ms

시나리오별 체크 항목

  • ✓ CSRF 발급 (200/204)
  • ✓ 회원가입 (201)
  • ✓ 로그인 (200)
  • ✓ 사진 업로드 (201)
  • ✓ 로그아웃 (2xx)
  • ✓ 자물쇠(record) 생성 (201)

네트워크

구분 값
수신 데이터 18 MB (92 kB/s)
송신 데이터 6.8 MB (36 kB/s)

해석

급격한 트래픽 스파이크 상황에서도 실패 없이 전부 처리됨. p95(911ms)는 normal(185ms)·peak(460ms)보다 높지만, 순간적으로 VU가 60까지 튀는 상황을 감안하면 괜찮아 보인다. stress 테스트에서 본 타임아웃(VU 200대)과 달리 여기선 아직 임계점에 도달하지 않은 것으로 보인다.

5. 결과 분석

  • 이번 부하테스트에서는 Normal/Peak/Spike 테스트에서는 문제가 없었다.
  • Stress 테스트에서 나타난 지연의 원인을 분석하기 위해 부하테스트를 진행한 시간 동안의 백엔드 로그를 조회했다.
sudo docker logs backend --since='2026-10-02T13:16:00+09:00' --until='2026-10-02T14:34:00+09:00' 2>&1 | grep -iE 'error|exception|timeout|pool|gc'

출력 결과

2026-10-02T13:56:22.850+09:00  WARN 1 --- [mulo] [o-8080-exec-115] c.k.t.m.r.e.RecordEmbeddingSubmitter     : Record embedding request failed after commit: recordId=2981, failureType=CLIENT_ERROR, httpStatus=null
2026-10-02T13:58:47.361+09:00  WARN 1 --- [mulo] [o-8080-exec-165] org.hibernate.orm.jdbc.error             : HHH000247: ErrorCode: 0, SQLState: null
2026-10-02T13:58:47.362+09:00  WARN 1 --- [mulo] [o-8080-exec-165] org.hibernate.orm.jdbc.error             : HikariPool-1 - Connection is not available, request timed out after 30026ms (total=10, active=10, idle=0, waiting=175)
2026-10-02T13:58:49.346+09:00 ERROR 1 --- [mulo] [o-8080-exec-165] o.a.c.c.C.[.[.[/].[dispatcherServlet]    : Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception
org.springframework.dao.DataAccessResourceFailureException: Unable to acquire JDBC Connection [HikariPool-1 - Connection is not available, request timed out after 30026ms (total=10, active=10, idle=0, waiting=175)] [n/a]
        at org.springframework.orm.jpa.hibernate.HibernateExceptionTranslator.convertHibernateAccessException(HibernateExceptionTranslator.java:153) ~[spring-orm-7.0.9.jar!/:7.0.9]
        at org.springframework.orm.jpa.hibernate.HibernateExceptionTranslator.convertHibernateAccessException(HibernateExceptionTranslator.java:131) ~[spring-orm-7.0.9.jar!/:7.0.9]
        at org.springframework.orm.jpa.hibernate.HibernateExceptionTranslator.translateExceptionIfPossible(HibernateExceptionTranslator.java:105) ~[spring-orm-7.0.9.jar!/:7.0.9]
        at org.springframework.orm.jpa.vendor.HibernateJpaDialect.translateExceptionIfPossible(HibernateJpaDialect.java:223) ~[spring-orm-7.0.9.jar!/:7.0.9]
        at org.springframework.orm.jpa.AbstractEntityManagerFactoryBean.translateExceptionIfPossible(AbstractEntityManagerFactoryBean.java:577) ~[spring-orm-7.0.9.jar!/:7.0.9]
        at org.springframework.dao.support.ChainedPersistenceExceptionTranslator.translateExceptionIfPossible(ChainedPersistenceExceptionTranslator.java:61) ~[spring-tx-7.0.9.jar!/:7.0.9]
        at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:157) ~[spring-tx-7.0.9.jar!/:7.0.9]
        at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:86) ~[tomcat-embed-core-11.0.24.jar!/:na]
        at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:949) ~[tomcat-embed-core-11.0.24.jar!/:na]
        at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:483) ~[tomcat-embed-core-11.0.24.jar!/:na]
Caused by: org.hibernate.exception.JDBCConnectionException: Unable to acquire JDBC Connection [HikariPool-1 - Connection is not available, request timed out after 30026ms (total=10, active=10, idle=0, waiting=175)] [n/a]
        at org.hibernate.exception.internal.SQLExceptionTypeDelegate.convert(SQLExceptionTypeDelegate.java:49) ~[hibernate-core-7.4.5.Final.jar!/:7.4.5.Final]
        at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:34) ~[hibernate-core-7.4.5.Final.jar!/:7.4.5.Final]
        at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:115) ~[hibernate-core-7.4.5.Final.jar!/:7.4.5.Final]
        at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:101) ~[hibernate-core-7.4.5.Final.jar!/:7.4.5.Final]
        at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:135) ~[spring-tx-7.0.9.jar!/:7.0.9]
Caused by: java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30026ms (total=10, active=10, idle=0, waiting=175)
        at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:714) ~[HikariCP-7.0.2.jar!/:na]
        at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:184) ~[HikariCP-7.0.2.jar!/:na]
        at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:142) ~[HikariCP-7.0.2.jar!/:na]
  • 오류 로그를 통해 Hikari CP 고갈로 인한 Timeout 으로 인해 오류가 발생하는 것을 알 수 있었다. 따라서 application.yml의 spring.datasource.hikari.maximum-pool-size 를 수정해서 같은 Stress 테스트를 다시 진행해보고, 타임아웃이 사라지는지 확인할 것이다.
  • 또 다른 문제가 있을 수 있지만 변수를 하나씩 바꿔가며 재현하고 해소하는 것을 비교하는게 가장 확실하고 안전한 방법이라고 생각한다.
  • 우선적으로 Hikari CP 의 최대 연결 수를 결정하기 전에 GCP Cloud SQL에서 최대 연결수를 확인해보았다.
SHOW VARIABLES LIKE "max_connections";

결과 : 1030
  • 하지만 DB 커넥션 연결 수에 Hikari CP 커넥션 수를 맞추게 되면, DB가 처리할 수 있는 한계를 넘어 CPU 컨텍스트 스위칭과 디스크 I/O 병목이 발생하게 된다. 또한 현재 DB의 스펙은 db-g1-small 이기 때문에 성능이 좋지 않다.
  • 따라서 Hikari의 공식 가이드에 따라 적정 커넥션 수를 책정한 후 다시 Stress 부하테스트를 진행했다
    • (디비 코어 수 × 2) + effective_spindle_count
    • 1 x 2 + 1
    • HikariCP 문서에서도 SSD에선 이 공식이 얼마나 맞는지 불명확하다고 해서 0~1로 보수적으로 effective_spindle_count 산정

6. Stress 부하 테스트 결과 (Hikari 최대 풀 3)

Threshold 통과

지표 조건 결과
요청 실패율 < 50% 0.01% ✅

전체 요약

항목 값
총 체크 수 41,416건 (성공률 99.98%, 5건 실패)
총 요청 수 (HTTP) 78,150건
요청 실패율 0.01% (9건)
초당 요청 수 (RPS) 47.7 req/s (실행시간이 늘어 낮게 계산됨)
총 반복(iteration) 4,895회 (중단 13건)
최대 VU (가상 사용자) 200
실행 시간 27분 17.7초 (설정은 18분)

응답시간 (HTTP)

구분 값
평균 1.07s
최소 5.71ms
중앙값 194.62ms
최대 9분 46초
p90 3.22s
p95 5.04s

시나리오별 체크 항목

  • ✓ CSRF 발급 (200/204)
  • ✓ 회원가입 (201)
  • ✗ 로그인 (200) — 1건 실패
  • ✗ 사진 업로드 (201) — 2건 실패
  • ✗ 로그아웃 (2xx) — 1건 실패
  • ✗ 자물쇠(record) 생성 (201) — 1건 실패

네트워크

구분 값
수신 데이터 92 MB (56 kB/s)
송신 데이터 33 MB (20 kB/s)

풀 10 vs 풀 3 (Stress, 200 VU)

지표 풀 10 풀 3
총 요청 수 69,622 78,150
완료된 반복 4,347 4,895
중단된 반복 29 13
요청 실패 3건 9건
평균 1.18s 1.07s
p90 3.52s 3.22s
p95 5.5s 5.04s

해석

VU 200에서도 에러율은 0.01%로 기준치 이하이지만, 풀을 3으로 줄여도 p95가 5.5s에서 5.04s로 오히려 소폭 개선됐다. 풀 크기보다 커넥션을 쥐고 있는 시간(트랜잭션 안의 외부 호출)과 DB 처리 속도가 지연을 좌우하는 것으로 보인다. 다만 두 번 측정한 차이가 작아 오차 범위일 수 있다. 257초 지점에 서로 다른 API 4건이 동시에 connection reset by peer로 끊겼고, 요청 하나가 9분 46초 동안 응답 없이 남아 총 실행시간이 늘었다.

7. 풀 3 결과 추가 분석

풀 10과 비교했을 때 달라진 점

Stress 결과를 풀 10일 때와 비교해봤는데 큰 차이가 없었다.

지표 풀 10 풀 3
처리량 (RPS) 64.4 req/s 약 63 req/s (200 VU 구간 기준 63.2)
p95 5.5s 5.04s

풀이 병목이었다면 커넥션을 10개에서 3개로 줄였을 때 처리량이 눈에 띄게 떨어져야 하는데, 상한이 거의 그대로였다. 그래서 병목은 Hikari 풀 크기가 아니라 풀 뒤쪽(백엔드 CPU나 DB)에 있다고 판단했다. 풀 크기를 바꾸면 요청이 줄 서는 위치만 달라질 뿐이다.

result.json 재집계 결과

실행 전체 평균으로 보면 p95가 5.04s라서 괜찮아 보이지만, VU 단계별로 나눠보면 부하가 늘수록 계속 나빠졌다.

관측 VU 처리량 (RPS) 평균 p95 p99
18 94.45 0.077s 0.212s 0.362s
50 76.98 0.535s 1.707s 2.831s
100 64.21 1.455s 4.534s 6.537s
200 63.23 3.040s 10.395s 15.192s
  • VU가 늘어도 처리량은 오히려 줄고 응답시간만 길어졌다. 더 처리하지 못하고 대기만 늘어나는 포화 상태로 보인다.
  • DB를 조회하지 않는 CSRF는 200 VU에서도 p95가 0.4초인데, PK 조회뿐인 /api/users/me는 11.4초였다. 특정 쿼리 하나가 아니라 DB를 쓰는 요청 전체가 같이 느려졌다.

병목 후보

아직 확정된 것은 아니고, 코드를 보고 의심되는 부분이다.

  1. 백엔드 CPU 경쟁
    • 개발 VM이 e2-medium(2 vCPU) 하나인데 backend, frontend, ai, nginx가 같이 떠 있다.
    • 여기에 회원가입과 로그인의 BCrypt 연산이 더해진다. 풀 크기와 상관없이 처리량이 막히는 현상과 가장 잘 맞는다.
    • 현재 v1 기준으로는 피크 트래픽에서도 문제가 없기 때문에 v2에서 개선할 예정이다.
  2. 트랜잭션 안의 외부 호출
    • 기록 상세 조회의 서명 URL 생성, 기록 생성의 카카오 API 호출, 업로드의 GCS 호출, 회원가입/로그인의 BCrypt가 전부 @Transactional 안에서 실행된다.
    • DB 커넥션을 쥔 채로 CPU나 네트워크를 쓰는 구조라서 커넥션 점유 시간이 길어진다.
    • 풀스택 팀에 전달 후 개선할 예정이다.
  3. 인기 장소 조회
    • 전체 요청의 약 25%인데 매번 같은 지역을 집계한다. 캐시가 없다.
    • v2에서 개선할 예정이다.

8. 운영 서버 공격 분석 (09/29 20:30)

강사님이 의도적으로 서버를 공격했고, 그때의 수치와 로그를 분석해 원인을 찾았다. 장애 시각은 09/29 20:30 쯤이고 당시 active 서버는 muro-vm-1이었다.

공격 내용

nginx 접근 로그(muro-vm-1)로 확인했다.

  • 출처: 211.244.225.164 한 곳
  • 대상: 회원가입 API(POST /api/users/signup) 하나
  • 규모: 20:02~20:29에 7,460건, 가입에 성공한 요청(201)이 1,658건
  • 분당 최대 3,160건 (초당 약 53건)
구간 (KST) 총 요청 (5분) 2xx 4xx 5xx
20:15 125 124 0 0
20:20 1,654 669 903 0
20:25 5,821 859 1,699 3,252
20:30 91 74 9 4

4xx는 대부분 클라이언트가 응답을 기다리다 끊은 499였다.

모니터링 수치

지표 평소 20:25 20:30
muro-vm-1 CPU 11~15% 71.7% 87.3%
muro-vm-1 수신 네트워크 약 1~2 KB/s 14.5 KB/s 180 KB/s
muro-vm-1 송신 네트워크 약 7 KB/s 30.5 KB/s 135.7 KB/s
Cloud SQL 쿼리 수 초당 4~6 33.2 37.3
Cloud SQL CPU 5.2~5.5% 7.2% 7.5%

DB는 CPU 7% 수준으로 여유가 있었다. 병목은 DB가 아니라 백엔드 VM의 CPU와 그 앞단의 nginx였다. 공격이 20:29에 끝난 뒤 별도 조치 없이 20:40쯤 평소 수준으로 돌아왔다.

서버가 다운된 과정

  1. 회원가입은 요청마다 BCrypt 연산을 하고, 이를 DB 트랜잭션 안에서 실행한다. 초당 수십 건이 몰리자 e2-medium 한 대의 CPU가 포화됐다.
  2. 해시를 계산하는 동안 DB 커넥션을 계속 쥐고 있어서 Hikari 풀(10개 → 따로 설정 안 해서 디폴트 값)이 바닥났다. 20:23:44에 첫 고갈 로그가 찍혔고 20:30:49까지 561건, 대기 요청은 최대 190개까지 쌓였다. (부하테스트랑 비슷한 상황)
  3. 백엔드가 느려지고 클라이언트가 먼저 연결을 끊었고, nginx는 응답을 기다리며 연결을 계속 쥐고 있었다.
  4. nginx의 파일 디스크립터(FD)가 고갈됐다. nginx 컨테이너의 ulimit -n이 1024, worker_connections가 1024라서 한도가 낮았다.
    • socket() failed (24: No file descriptors available) while connecting to upstream 3,217건 → 500 응답
    • accept4() failed (24: No file descriptors available) 237건 → 새 연결을 아예 받지 못함
  5. 4번 구간이 일반 사용자에게 서버 다운으로 보인 시간이다.

회원가입 폭주 → CPU와 DB 커넥션 소모 → Hikari 풀 고갈 → 응답 지연 → nginx 연결 누적 → nginx FD 고갈 → 신규 연결 거부 순서이다.

부하테스트 결과와의 연결

  • 부하테스트에서 병목 후보로 의심했던 부분이 실제 공격에서 그대로 나타났다.
  • 풀 크기를 늘리는 것보다 커넥션을 쥐고 있는 시간을 줄이는 것과 앞단에서 요청을 제한하는 것이 효과적이라는 결론이 실제로 확인됐다.

개선 방향

  1. nginx
    • 회원가입, 로그인 같은 인증 API에 IP별 요청 속도 제한(limit_req)과 동시 연결 제한(limit_conn) 적용
    • FD 한도 상향 (worker_rlimit_nofile, 컨테이너 ulimit nofile, worker_connections)
    • 업스트림 타임아웃 단축
    • 접근 로그에 $request_time, $upstream_response_time 추가 (이번 분석에서 요청별 응답시간을 볼 수 없었다)
  2. 애플리케이션
    • 회원가입 API 속도 제한과 봇 방지
    • BCrypt 해시를 트랜잭션 밖에서 계산해서 DB 커넥션 점유 시간 줄이기
    • Hikari maximum-pool-size와 connection-timeout(5초 정도) 명시
  3. 운영
    • 공격으로 생성된 계정이 운영 DB에 최소 1,658개 있어서 정리 필요
    • nginx 5xx 비율, CPU, FD 고갈 에러, Hikari 풀 고갈에 알림 설정 (이번 시간대에는 알림이 하나도 발생하지 않았다)
    • nginx 로그를 Cloud Logging으로 전송 (지금은 VM 안에만 있고 컨테이너가 재생성되면 사라진다)

수치와 로그를 확인한 위치

확인한 것 위치
VM CPU, 네트워크 GCP Monitoring
DB 부하, 연결 수, 쿼리 수 GCP SQL 시스템 통계
nginx 로그 VM에 SSH 접속 후 sudo docker logs nginx
Hikari 풀 고갈 등 백엔드 로그 GCP Logging