Project

[Sansam E-commerce] 6. MVP 이후 리팩토링 #4 : Order 트랜잭션 분리 & DB Indexing을 통한 최적화 & 테스트 툴 변경

👀 들어가기 전에

테스트 코드 작성이 마무리되고, 본격적으로 성능테스트가 시작되었다. "내가 작성한 이 코드가 실제 트래픽 앞에서도 버틸 수 있을까?"를 확인하는 단계였다.

시작된 부하테스트는 E2E 부하테스트로 nGrinder를 활용한 부하테스트였다. 로컬 Mac 환경에서 Docker 위에 서버(Jar)를 띄워두고 그 위로 부하를 주는 방식이었다. 테스트를 진행하면서 지금 구조가 어느 지점에서 병목이 발생하는지 어떤 순서로 개선해야할지를 고민하는 시간이었으며 지금부터 쓰는 글은 그 고민을 담은 글이다.

👀 본론

1. 첫 부하 테스트 : VUser 350, E2E 주문~결제 흐름 테스트

테스트는 주문~결제까지의 흐름을 타는 E2E 시나리오로 구성했다.

VUser 100명부터 테스트를 진행해서 점차 올라갔으며, VUser 350명일때 아래와 같은 결과가 나오며 문제가 발생했다.

테스트 총 350개 중 129개만 성공하고 221개는 에러를 띄우는 상황이었다.

실패 비율 자체가 너무 컸으며 에러의 패턴도 대량의 Timeout 형태였다.

2. 에러 로그를 파기 시작하다 : Read Timeout + HikariPoolConnection Timeout

실패한 요청의 에러 로그를 살펴보면 크게 두 종류가 있었다.

2-1. nGrinder Read time out

2025-09-05 11:25:47,341 ERROR Read timed out
net.grinder.plugin.http.TimeoutException: Read timed out
	at HTTPClient.BufferedInputStream.fillBuff(BufferedInputStream.java:172)
	at HTTPClient.BufferedInputStream.read(BufferedInputStream.java:110)
	at HTTPClient.StreamDemultiplexor.read(StreamDemultiplexor.java:277)
	at HTTPClient.RespInputStream.read(RespInputStream.java:155)
	at HTTPClient.RespInputStream.read(RespInputStream.java:115)
	at HTTPClient.Response.readResponseHeaders(Response.java:980)
	at HTTPClient.Response.getHeaders(Response.java:698)
	at HTTPClient.Response.getVersion(Response.java:290)
	at HTTPClient.HTTPConnection.sendRequest(HTTPConnection.java:3239)
	at HTTPClient.HTTPConnection.handleRequest(HTTPConnection.java:2883)
	at HTTPClient.HTTPConnection.setupRequest(HTTPConnection.java:2675)
	at HTTPClient.HTTPConnection.Post(HTTPConnection.java:1177)
	at net.grinder.plugin.http.HTTPRequest$8.doRequest(HTTPRequest.java:923)
	at net.grinder.plugin.http.HTTPRequest$AbstractRequest.getHTTPResponse(HTTPRequest.java:1276)
	at net.grinder.plugin.http.HTTPRequest.POST(HTTPRequest.java:918)
	at net.grinder.plugin.http.HTTPRequest$POST.call(Unknown Source)
	at E2E_OrderThenConfirm_Smoke.test(OrderToPayScript.groovy:106)
	at jdk.internal.reflect.GeneratedMethodAccessor10.invoke(Unknown Source)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at net.grinder.scriptengine.groovy.junit.GrinderRunner.run(GrinderRunner.java:164)
	at net.grinder.scriptengine.groovy.GroovyScriptEngine$GroovyWorkerRunnable.run(GroovyScriptEngine.java:147)
	at net.grinder.engine.process.GrinderThread.run(GrinderThread.java:118)

클라이언트인 Agent가 30초 안에 응답을 못받고 포기하게 된 케이스이다.

2-2. HikariPool Connection is not available (30초 대기 후 실패)

java.sql.SQLTransientConnectionException: 
HikariPool-1 - Connection is not available, request timed out after 30001ms (total=10, active=10, idle=0, waiting=190) at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:714) 
~[HikariCP-6.3.1.jar!/:na] at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:184) ~[HikariCP-6.3.1.jar!/:na] at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:142) 
~[HikariCP-6.3.1.jar!/:na] at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:127) ~[HikariCP-6.3.1.jar!/:na] at org.hibernate.engine.jdbc.connections.internal.DatasourceConnectionProviderImpl.getConnection(DatasourceConnectionProviderImpl.java:126) ~[hibernate-core-6.6.22.Final.jar!/:6.6.22.Final] at org.hibernate.internal.NonContextualJdbcConnectionAccess.obtainConnection(NonContextualJdbcConnectionAccess.java:46) 
~[hibernate-core-6.6.22.Final.jar!/:6.6.22.Final] at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:126) ~[hibernate-core-6.6.22.Final.jar!/:6.6.22.Final] at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getPhysicalConnection(LogicalConnectionManagedImpl.java:156) 
~[hibernate-core-6.6.22.Final.jar!/:6.6.22.Final] at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getConnectionForTransactionManagement(LogicalConnectionManagedImpl.java:286) 
~[hibernate-core-6.6.22.Final.jar!/:6.6.22.Final]

서버 내부에서는 DB 커넥션을 못 얻어서 30초 대기하다가 실패한 상태였다.

원인 가설에 대한 정리

문제는 분명 느려서 터지는 것이었지만, 어디를 먼저 건드리기 시작할 지는 정해야 했다.

그래서 원인을 아래 3가지로 잡았다.

HikariCP Pool 크기 문제
DB 내부에서 허용 가능한 동시 커넥션/스레드 수 문제
Transaction 내부 처리가 너무 오래 걸리는 문제

당시, Hikari max = 10이었다.(기본 설정 값으로 동작하고 있었기에) 한 요청이 DB connection을 3초 이상 점유한다고 가정하면, 서버의 DB 처리 상한은 대략 10 connections / 3초 ≈ 3 RPS 이다. 그런데 부하가 순간 50RPS로 들어오면, 초당 47건이 대기열로 밀린다. 10초만 지속되면 470건이 대기한다. 결국 뒤쪽 요청은 30초를 초과해 Timeout이 날 수밖에 없다.

그렇기에 여기서 우선순위를 아래와 같이 잡았다.

1순위 : 트랜잭션 / 쿼리 튜닝 (= 한 요청이 DB 커넥션을 잡는 시간 줄이기)
이후 부하 테스트 관찰
그 다음에 Hikari Pool 혹은 DB 튜닝 여부를 결정

이유는 Pool 사이즈를 늘리는 건 대기열을 늘리는 임시방편일 뿐이고 트랜잭션이 길어 커넥션을 오래 점유하면 결국 다시 고갈된다는 판단이었다.

4. 결제 트랜잭션 구조 재검토 : "외부 PG 호출을 트랜잭션에 넣는게 맞나?"

이번 기회에 결제 플로우 전체를 다시 보게 됐다.

결제는 외부 PG API 호출이 포함되는데 기존처럼 하나의 큰 트랜잭션으로 묶는 구조는 위험하다는 판단이었다.

기존 결제 트랜잭션 구조는 아래와 같다.

주문 검증
재고 차감
결제 승인 요청 (외부 PG API)
주문/결제 정보 DB 저장
응답 반환

이 모든 과정이 하나의 트랜잭션 범위 안에 들어가 있었다.

여기서 연쇄적으로 발생하는 문제를 구체적으로 정리해보았다.

외부 API 호출이 지연되면? → 트랜잭션 전체가 길어질 수 밖에 없다.
트랜잭션 하나가 지연되어 끝나는 데에 오래 걸리면? → 트랜잭션 동안의 DB 커넥션 점유 시간이 늘어난다.
(DB를 쓰지도 않는데 길게 잡고 있는 경우도 생기게 되는 것이다.)
실패시 전체 롤백이 발생하는데 결제 실패 보상도 이루어지나? → 이전 포스트에서 봤던 것처럼 따로 취소 API를 호출해주는 방식을 선택하여야 한다.

5. 1차 개선 : 외부 PG API 호출을 트랜잭션 밖으로 분리

(이전 포스트에서 이야기했던 API 호출부가 분리되는 과정을 자세히 다룬다.)

첫 개선은 단순했다.

외부 API 호출의 경우 트랜잭션 외부
결제 결과를 DB로 반영하는 경우 트랜잭션 내부

보상 로직 구성에 많은 큰 도움이 되었다.

여기서 끝이 아니었다. Order 트랜잭션 자체가 여전히 크고 길었다.

6. 2차 개선 : Order 트랜잭션 분리 여정기

기존 Order 트랜잭션은 아래의 모든 작업을 포함하고 있었다.

주문 검증
재고 차감
주문서 DB 저장
응답 데이터 생성 후 반환

이 구조의 문제점은 아래와 같다.

응답 생성 중 에러가 발생해도 전체 주문이 모두 롤백된다.
트랜잭션의 범위가 길어서 점유하는 스레드가 증가하며 DB 커넥션 반납이 지연되고, Pool고갈 위험이 증가한다.

7. DB의 책임별 분리

우선 DB가 수행하는 책임을 기준으로 트랜잭션을 분리하기 시작했다.

기존 Order 트랜잭션에 포함된 작업을 정리해보면 DB 관점에서는 크게 두 가지 책임이 섞여 있었다.

DB를 읽는 작업 (Read)
DB에 상태를 반영하는 작업 (Write)

이 두 책임이 하나의 큰 트랜잭션 안에 묶여있으면서 트랜잭션 범위가 불필요하게 커지고, 그 결과 DB 커넥션 점유 시간이 길어지고 있다고 판단했다.

7-1. 1차 분리 - DB Write 영역 분리

가장 먼저 눈에 들어온 것은 주문 정보 저장이었다.

주문 검증, 재고 확인, 응답 생성 등과 달리 주문 정보 저장은 명확한 DB Write 작업이었기 때문이다.

그래서 초기에는 아래와 같이 주문 정보 저장 (DB Write) 구간만 별도의 트랜잭션으로 분리했다.

딱 DB에 저장하는 부분만 트랜잭션으로 감싸보자

이렇게 분리한 뒤 기존보다 커넥션 점유 시간이 줄어드는 효과는 있었지만 여전히 트랜잭션 범위가 크다는 느낌이 들었다.

아직 더 나눌 수 있는 책임이 남아 있지 않을까?

7-2. 재고 차감도 Write로, 주문 검증은 Read로

재고 차감도 DB에 저장된 객체의 상태를 반영하는 작업이며 명백한 DB Write이다.

주문 검증 과정은 상품 정보 조회나 재고 상태 조회 등 대부분이 DB Read로 이루어져 있다.

즉, 기존 Order 트랜잭션 안에는 Read와 Write가 뒤섞여 있었던 것이다.

이에 따라 구조를 아래와 같이 정리했다.

Read Transaction
- User 검증
- 주문 검증 (상품 검증 / 상품 가격 검증)
- 상태값 불러오기
Write Transaction
- 재고 차감
- 주문 정보 저장
- 주문 / 결제 상태 변경

7-3. Read / Write 분리 이후 트랜잭션의 성격 변화

요청 흐름은 아래와 같다.

Order 요청 진입 (Transaction 없음)
Read Transaction 실행 (검증 및 조회)
Write Transaction 실행 (필요한 상태 변경만 진행)

이 구조에서 가장 큰 변화는 하나의 긴 트랜잭션이 사라지고 여러 개의 짧은 트랜잭션으로 분리되었다는 점이다.

기존에는 Order 요청 하나가 시작되는 순간부터 응답을 반환할 때까지 하나의 트랜잭션이 유지되며 DB 커넥션이 장시간 점유되고 있었다.

반면, Read / Write 분리로 인해 아래와 같은 효과를 기대해볼 수 있었다.

DB 커넥션은 정말 필요한 시점에만 획득
트랜잭션 종료와 동시에 커넥션 즉시 반환

(질문)
왜 최상위 메소드가 트랜잭션이 아닌데 정합성 유지가 되는거에요?

팀원에게 실제로 받았던 질문 중 하나이다.

최상위 메서드는 트랜잭션을 갖지 않지만 각 단계별로 DB의 책임에 맞는 트랜잭션 경계가 명확히 존재한다.

이로 인해 아래와 같은 특성이 생긴다.

Read Transaction
- 검증과 조회만 담당
- 실패 시 Write 단계로 진행되지 않는다
- DB 상태를 변경하지 않으므로 롤백 자체의 부담이 없다.
Write Transaction
- 상태 변경에만 집중이 된다.
- 실패 시 해당 Write 트랜잭션만 롤백을 시키고 재시도 로직 또한 Write만 진행한다.
- 이미 수행된 Read 단계와 명확히 분리된다.

즉, 어디까지 성공했고 어디서 실패했는지가 트랜잭션 경계 기준으로 명확히 구분된다. 단일 트랜잭션으로 진행한 경우 하나의 요청이 실패한 경우 어디가 실패했고, 어디의 어떤 부분이 문제인 것인지에 대해 찾기가 어려웠다면 오히려 더욱 깔끔한 처리가 가능해졌다.

8. 추가 병목 발견 : DB 인덱싱 문제

이후 동일 시나리오, VUser 350명으로 테스트를 돌리게 되었을때의 결과는 아래와 같다.

이후 VUser 수를 늘려가며 테스트를 진행해보았다.

1,000명 부하테스트 부터 느려지는 것이 확연히 보이기 시작했다.

TPS는 오히려 떨어지고 응답 시간은 11초까지 급증하는 것을 확인할 수 있다.

nGrinder 특성상 응답이 느려질수록 요청 발생률은 자동으로 감소시켜주기에 에러는 없지만 TPS가 하락했고 Latency가 폭증했다는 사실을 알 수 있다.

AOP 로그를 토대로 병목 구간을 추적하기 시작했고 아래 구간에서 시간이 비정상적으로 길어지는걸 확인했다.

END : execution(TossPaymentResponse org.example.sansam.payment.service.PaymentService.confirmPayment(TossPaymentRequest)) 7329ms

결제를 confirm하는 과정이 7초나 걸리고 있었다.

아무리 외부 API 대기를 1초를 걸었다고 하더라도 7초는 너무 길다고 판단하였다.

내부 로그를 세부적으로 찍어보았다.

2025-09-05T17:50:45.109+09:00 DEBUG 66321 --- [SanSam] [0-8080-exec-117] o.e.s.payment.service.PaymentService     : orderNumber로 order를 조회해오기 = 2550

orderNumber로 주문 조회하는데만 2.5초가 걸렸다.

원인은 단순했다. 조회 조건인 order_number 컬럼에 인덱스가 없어 Full Table Scan이 발생하고 있었다.

이에, OrderNumber에 유니크 인덱스를 추가하였다.

order_number는 애초에 날짜 + 시간 + UUID 기반으로 생성되며 전역적으로 Unique함이 보장되어있다.

따라서 Unique Index를 추가하는 것을 선택하였다.

ALTER TABLE orders 
ADD UNIQUE KEY uk_orders_order_number (order_number),
ALGORITHM=INPLACE, LOCK=NONE;

적용 후 로그를 다시 확인해보았을 때 결과는 아래와 같았다.

orderNumber로 order를 조회해오기 = 703
confirmPayment 전체 = 3038ms

orderNumber로의 조회는 2.5s에서 0.7s까지 줄어들었으며 결제 승인 전체 처리는 7s대에서 3s대까지 응답시간을 개선할 수 있었다.

9. 부하 테스트 결과 해석과 한계 인식

이후 VUser 3,000 기준 테스트를 진행해보았다. 서버가 돌아가기는 한다.

왜냐면, nGrinder 부하 모델 특성 때문이었다.

앞서 말했듯이 nGrinder는 특성상 응답이 느려질수록 요청 발생률은 자동으로 감소시켜주기에 에러가 발생하지 않는 것이다.

이에 아래와 같은 질문을 하게 되었다.

정말 1,000명, 3,000명이 동시에 지속 요청하는 상황을 재현했나?

내가 생각하기에는 아니었다. 서버가 응답이 느려질수록 요청 발생률이 자동으로 감소되기 떄문이다.

이는 실제 서비스 환경과는 거리가 멀었다. 실제 서비스 환경에서는 고객들이 서버가 느려진다고 요청을 안하지 않기 때문이다.

그럼 결국 이는 서버의 문제로 이어지고 서버가 문제가 생기면 고객의 입장에서 더이상 신뢰하기 어려운 서비스가 되는 것이다.

(추가) nGrinder의 한계와 K6로의 전환

nGrinder의 어떤 구조 때문에 이런 특징이 발생하는지가 궁금했다.

nGrinder는 기본적으로 Closed Model을 사용한다.

요청 → 응답 대기 → 다음 요청

즉, 응답이 느려질수록 자연스럽게 요청 발생률이 자동으로 감소한다.

결과적으로 서버가 느려질수록 부하가 자연스럽게 완화되는 일종의 서버 보호 시나리오에 가까운 테스트가 진행된다.

하지만 이번 테스트 목적은 동시에 지속적으로 요청이 유입되는 Open Model의 환경 재현이었다.

그래서 K6로의 테스트 툴 전환을 이어갔다.

👀 결론

어떻게 보면 블로그 글이 시간 순서가 아니기에 보시는 분들로 하여금 '왜 순서가 이렇지?'라는 의문이 들 수도 있다는 점을 충분히 인지하고 있었다. 그럼에도 이 구조를 고집한 이유는 명확하다. 테스트 코드는 테스트 코드대로 보상로직은 보상 로직대로 부하 테스트는 부하 테스트끼리 각 주제를 하나의 이야기로 온전히 다루고 싶었기 때문이다. 시간의 순서로 나열하는 것보다 의사결정의 맥락과 고민의 깊이를 전달하는 데 더 적합한 방식이라고 판단했다.

이번 글에서 다룬내용도 이번 글 내용과 유사한 흐름을 가질 예정이다.

지금부터는 테스트 → 관찰 → 고민 → 수정 → 재검증의 반복이다.

다음 글부터는 nGrinder가 아닌 K6 기반 Open Model 테스트를 통해 동시 요청 환경을 보다 현실적으로 재현하며 지속적으로 구조를 개선해 나간 과정을 정리해볼 계획이다. 한 번 리팩토링을 거쳤다고 끝이 아니라 계속해서 문제가 생기는 부분을 파고 고민하고 수정해나간 과정이 작성될 것이다.

'Project' 카테고리의 다른 글

[Sansam E-commerce] 8. MVP 이후 리팩토링 #6 : 캐싱 (캐싱에 대한 고찰) (0)	2025.12.29
[Sansam E-commerce] 7. MVP 이후 리팩토링 #5 : HikariCP 튜닝 (0)	2025.12.29
[Sansam E-commerce] 5. MVP 이후 리팩토링 #3 : 테스트 코드 작성과 Outbox 패턴 구현기 (0)	2025.12.24
[Sansam E-commerce] 4. MVP 이후 리팩토링 #2 : 재고 관리는 어떻게 할 것인가? (0)	2025.12.24
[Sansam E-commerce] 3. MVP 이후 리팩토링 #1 : 재고 도메인 ERD 분리 과정 (0)	2025.12.22

Contents

새소식