N+1 문제를 꼼꼼히 점검한다. (EntityGraph 또는 JPQL을 통한 Fetch Join)
필요한 필드만 DTO 직접 반환(Projection)을 효율적으로 사용할 수 있는 경우 사용한다
많은 데이터를 불러오는 경우 페이징을 사용하자
적재적소에 인덱스를 적용한다
OSIV를 꺼준다
그런데, 실제로 적용하려다 보니 여러 가지 의문들이 생기게 되었습니다.
❓프로젝션을 통한 직접반환이 영속성 컨텍스트를 재사용하지 않는 모든 경우에 유리하다면 JPA 기본 메서드들이 대부분의 경우에 비효율적이게 될 텐데 얼마나 더 빨라지는가? 이것이 API 의존적인 매서드를 만들어서 유지보수성을 떨어뜨리는 것과 비교했을 때 유의미할까?
❓EntityGraph와 Fetch Join중 어떤 것이 어떤 상황에 더 유리하며 성능을 어떤가?
❓JPQL와 JPA 레포지토리의 네이밍 기반 메서드들의 성능 차이는 어떤가?
이론적으로 많은 것들을 배울 수 있었지만, 결국 성능을 최적화하기 위한 나만의 기준을 정립하지 못했으며 실전적인 적용이 부족하다는 것을 느꼈습니다.
📌 정확한 성능을 측정하기 위한 시행착오
가장 처음 제가 알고 싶었던 점은 "위에서 배운 기능들이 성능적으로 얼마나 차이가 나는가?"였습니다 (이걸 알아야 적용 기준을 잡을 수 있을 것 같았습니다). 이에 따라서, Repository단에 있는 매서드 하나 단위로 간단히 API를 설계를 했고 여러 가지 상황을 비교해 봤습니다. 더미 데이터를 5만 개 정도 넣고 Jmeter를 이용해서 테스트를 진행해 봤습니다.
(간단한 테스트 API 예시 )
@GetMapping("/findOneMemberById")
@Transactional(readOnly = true)
public void findOneMemberById(@RequestParam Long id) {
memberRepository.findById(id);
}
1️⃣ Jmeter를 사용해서 Repository 매서드 하나하나 측정하는 것은 의미가 없다
결과적으로 여러 가지를 비교를 해보았는데 Result Summary로 확인을 해보았을 때는 정말 유의미한 차이를 확인하지 못해서 혼란스러웠습니다. 조금 더 자세한 결과를 살펴보기 위해서 Result Tree로 각각의 요청에 대한 결과를 보았는데 첫 번째 요청 이후에 급격히 소요시간이 줄어들기 시작하며 특정 지점으로 수렴하게 되며"일종의 캐싱이 일어나고 있지 않을까?"라는 의심을 하게 되었습니다.
Result Tree로 확인한 결과 첫 번째 실행 이후에 급격하게 줄어들게 되며 이 부분은 나중에 로그를 찍어서 확인해 본 결과도 동일했기 때문에 JVM이 warm-up 하는데 걸리는 소모값이라고 생각했습니다. 그리고 지속적으로 줄어들게 되는데 이는 MySQL innoDB에서 인메모리 캐싱이 일어날 수 있다고 판단했습니다. 결론적으로, 제가 깨달은 점은 Jmeter 같은 부하 테스트 도구는 이런 레포지토리의 한 매서드 단위를 테스트 하는 것에 사용하는 것은 적합하지 못하다는 점입니다. 부하 테스트 도구를 사용할 경우 자세한 로그 같은 정보를 확인할 수 없으며, 완성된 API 하나를 기준으로 실제 상황과 비슷한 다양한 입력값과 여러 이용자를 가정한 실험을 하면서 부하량에 대한 테스트를 수행하기 적합한 것이지, 지금과 같이 배우기 위한 실습 용도로도 Repository의 매서드 하나하나를 테스트하는 용도로는 부적합했습니다.
따라서, 이번에는 IntelliJ에서 테스트를 진행하면서 로그와 AOP를 이용해서 매서드 실행 시간을 추적해 보았습니다.
// 간단한 Controller
@GetMapping("/test")
@Transactional(readOnly = true)
public void test() {
long start = System.nanoTime();
List<Member> members = memberRepository.findAll();
long end = System.nanoTime();
log.info("🕒 [findAll] 매서드 처리 시간: {}ms", (end - start) / 1_000_000);
}
@GetMapping("/test2")
@Transactional(readOnly = true)
public void test2() {
long start = System.nanoTime();
List<MemberDTO> memberDTOS = memberRepository.findAllMemberDto();
long end = System.nanoTime();
log.info("🕒 [findAllDTO] 매서드 처리 시간: {}ms", (end - start) / 1_000_000);
}
// findAllMemberDto 구현 매서드
@Query("SELECT new test.performance.MemberDTO(" +
"m.id, m.name, m.email, m.age, m.bio, m.schoolName, m.address, " +
"m.major, m.height, m.country, m.gender) FROM Member m")
List<MemberDTO> findAllMemberDto();
간단히 네이밍 기반 매서드와 모든 필드를 반환하는 DTO 프로젝션을 비교해 보았습니다. 첫 번째 실행은 그 이후와 거의 2배 정도 차이가 나기 때문에 (아마도 JVM warm-up과 쿼리 실행 계획 등 복합적 원인이 있을 것으로 생각됩니다, 이 부분을 통제하는 것은 불가능하다고 판단) 두 번째 실행을 기준으로 결과를 분석했습니다.
전체 HTTP 처리 시간은 위의 예시에서 메서드 처리 시간을 수동적으로 찍었던 로그입니다. 결과적으로 DTO 프로젝션이 소폭 효율적이긴 합니다. 먼저 각각의 로그가 어떤 방식으로 어디까지 찍히는지 확인할 필요가 있었습니다.
HQL 로그는 어느 부분을 측정하는 것일까 또 Session Metric은❓
2025-06-02T14:16:14.606+09:00 DEBUG 37335 --- [nio-8080-exec-5] o.h.stat.internal.StatisticsImpl : HHH000117: HQL: SELECT new test.performance.MemberDTO(m.id, m.name, m.email, m.age, m.bio, m.schoolName, m.address, m.major, m.height, m.country, m.gender) FROM Member m, time: 19ms, rows: 10000
HQL 로그를 찍어보면 다음과 같이 어떤 HQL(Hibernate Query Language)이 나가고 결과의 개수와 시간을 확인할 수 있습니다.
로그 부분에 대해서는 Hiberante의 공식 문서를 아무리 찾아봐도 찾기 쉽지 않아서 꽤나 힘이 들었던 부분입니다(+ 버전이 업그레이드됨에 따라서 조금씩 달라져서...). 이 부분은 결국 Hibernate 코드 자체에서 찾아볼 수 있었습니다.
평소에는 찾아볼 일이 없는..? 의존성 패키지 중에서 hibernate로 들어가 주었습니다.
org>stats>StatisticsImpl 이라는 클래스에서 HQL 로그를 찍는 매서드가 다음과 같이 존재합니다 (버전이 바뀌면 바뀔 수 있음 현재 6.6.13 버전 기준으로 설명)
public void queryExecuted(@UnknownKeyFor @NonNull @Initialized String hql, @UnknownKeyFor @NonNull @Initialized int rows, @UnknownKeyFor @NonNull @Initialized long time) {
LOG.hql(hql, time, (long)rows);
this.queryExecutionCount.increment();
boolean isLongestQuery;
for(long old = this.queryExecutionMaxTime.get(); (isLongestQuery = time > old) && !this.queryExecutionMaxTime.compareAndSet(old, time); old = this.queryExecutionMaxTime.get()) {
}
if (isLongestQuery) {
this.queryExecutionMaxTimeQueryString = hql;
}
if (hql != null) {
this.getQueryStatistics(hql).executed((long)rows, time);
}
}
그리고 이 매서드는 sql/exec/internal/jdbcSelectExecutorStandardImpl 부분에서 사용되면서 로그가 찍히게 됩니다.
바로 로직을 확인해 보겠습니다.
private <T, R> T doExecuteQuery(JdbcOperationQuerySelect jdbcSelect, JdbcParameterBindings jdbcParameterBindings, final ExecutionContext executionContext, RowTransformer<R> rowTransformer, Class<R> domainResultType, int resultCountEstimate, JdbcSelectExecutor.StatementCreator statementCreator, ResultsConsumer<T, R> resultsConsumer) {
DeferredResultSetAccess deferredResultSetAccess = new DeferredResultSetAccess(jdbcSelect, jdbcParameterBindings, executionContext, statementCreator, resultCountEstimate);
JdbcValues jdbcValues = this.resolveJdbcValuesSource(executionContext.getQueryIdentifier(deferredResultSetAccess.getFinalSql()), jdbcSelect, resultsConsumer.canResultsBeCached(), executionContext, deferredResultSetAccess);
if (rowTransformer == null) {
TupleTransformer<R> tupleTransformer = executionContext.getQueryOptions().getTupleTransformer();
if (tupleTransformer == null) {
rowTransformer = RowTransformerStandardImpl.instance();
} else {
List<DomainResult<?>> domainResults = jdbcValues.getValuesMapping().getDomainResults();
String[] aliases = new String[domainResults.size()];
for(int i = 0; i < domainResults.size(); ++i) {
aliases[i] = ((DomainResult)domainResults.get(i)).getResultVariable();
}
rowTransformer = new RowTransformerTupleTransformerAdapter(aliases, tupleTransformer);
}
}
SharedSessionContractImplementor session = executionContext.getSession();
long startTime = 0L;
StatisticsImplementor statistics = session.getFactory().getStatistics();
boolean stats;
if (executionContext.hasQueryExecutionToBeAddedToStatistics() && jdbcValues instanceof JdbcValuesResultSetImpl) {
stats = statistics.isStatisticsEnabled();
if (stats) {
startTime = System.nanoTime();
}
} else {
stats = false;
}
JdbcValuesSourceProcessingOptions processingOptions = new JdbcValuesSourceProcessingOptions() {
public Object getEffectiveOptionalObject() {
return executionContext.getEntityInstance();
}
public String getEffectiveOptionalEntityName() {
return null;
}
public Object getEffectiveOptionalId() {
return executionContext.getEntityId();
}
public boolean shouldReturnProxies() {
return true;
}
};
JdbcValuesSourceProcessingStateStandardImpl valuesProcessingState = new JdbcValuesSourceProcessingStateStandardImpl(executionContext, processingOptions);
RowReader<R> rowReader = ResultsHelper.createRowReader(session.getFactory(), (RowTransformer)rowTransformer, domainResultType, jdbcValues);
RowProcessingStateStandardImpl rowProcessingState = new RowProcessingStateStandardImpl(valuesProcessingState, executionContext, rowReader, jdbcValues);
T result = resultsConsumer.consume(jdbcValues, session, processingOptions, valuesProcessingState, rowProcessingState, rowReader);
if (stats) {
long endTime = System.nanoTime();
long milliseconds = TimeUnit.MILLISECONDS.convert(endTime - startTime, TimeUnit.NANOSECONDS);
statistics.queryExecuted(executionContext.getQueryIdentifier(jdbcSelect.getSqlString()), this.getResultSize(result), milliseconds);
}
return result;
}
이 부분에 모든 정답이 있는데 우선 답을 먼저 말씀드리면 JDBC 쿼리가 수행된 이후에 결과를 받고(일부 Session Metric에 찍힘) -> 변환하는 부분은 HQL에 기록됨. 좀 복잡하니 천천히 설명해 보겠습니다.
public ResultSet getResultSet() {
if (this.resultSet == null) {
this.executeQuery();
}
return this.resultSet;
}
ResultSet이라는 필드가 있고 이를 초기화해주는 메서드가 있습니다. 보시면 executeQuery가 있고... 이는 처음에 생성자와 함께 초기화되지는 않습니다. 이 부분이 어디에서 초기화가 될까요? 제가 위에 첨부한 두 줄 중 첫 번째 줄에서는 DeferredResultSetAccess가 생성만 되고 다음 줄에서 ResultSet이 초기화됩니다.
이 부분에서 query는 실행이 되었고 jdbc 매트릭스에 기록이 되었습니다. jdbc 쿼리가 준비가 되고 sql을 실행하는 부분은 HQL 로그에는 찍히지 않는 것이죠!
⭐ 그럼 HQL 로그는 어떤 부분을 측정을 해주는 것일까요?
JdbcValuesSourceProcessingStateStandardImpl valuesProcessingState = new JdbcValuesSourceProcessingStateStandardImpl(executionContext, processingOptions);
RowReader<R> rowReader = ResultsHelper.createRowReader(session.getFactory(), (RowTransformer)rowTransformer, domainResultType, jdbcValues);
RowProcessingStateStandardImpl rowProcessingState = new RowProcessingStateStandardImpl(valuesProcessingState, executionContext, rowReader, jdbcValues);
T result = resultsConsumer.consume(jdbcValues, session, processingOptions, valuesProcessingState, rowProcessingState, rowReader);
if (stats) {
long endTime = System.nanoTime();
long milliseconds = TimeUnit.MILLISECONDS.convert(endTime - startTime, TimeUnit.NANOSECONDS);
statistics.queryExecuted(executionContext.getQueryIdentifier(jdbcSelect.getSqlString()), this.getResultSize(result), milliseconds);
}
다시 로깅 로직으로 돌아와서 T result를 resultsConsumer.consume을 하고 나면 HQL 로깅이 끝나게 됩니다. 즉, 이미 DB를 찔러서 데이터를 가져온 부분이 끝나고 나서 HQL 로그의 측정을 시작하고 consume 내부에서는 영속성 컨텍스트로 관리, dirty check, 엔티티 매핑을 하는 등의 과정이 이루어지게 됩니다.
정리를 하게 되면, Session Metric에 기록되는 로직(Jdbc 커넥션 얻고 결과 가져오고... 등등 물론 flush는 HQL 로그가 찍힌 이후에 행해지지만)이 끝나고 엔티티 매핑과 영속성 컨텍스트 관리등의 로직은 HQL에 기록이 되며 이 두 개의 시간을 합하게 되면 얼추 전체 시간과 비슷해진다는 뜻 입니다.
살짝 차이가 나는 이유는 JPQL을 SQL로 변환하는 시간과 같이 부수적인 것들이 빠져있기 때문인데 크게 영향을 미치지 않는 것 같으니 두 개의 로그만 보게 되면 전반적인 성능 평가가 가능하다는 결론입니다.
⭐ 트러블 슈팅 기록
지금까지 나온 모든 내용이 사실상 트러블 슈팅이지만, HQL에서 결과에 대해서 영속성 컨텍스트와 관련된 작업을 하게 되는데 저는 당연히 DB에서 바로 가져와서 작업을 한다고 생각을 했고, HQL 시간이 도대체 왜 SQL 실행 시간보다 작은 수치가 나오는지 이해할 수가 없었습니다. 그런데 결과적으로 쿼리가 이미 나간 후에 처리가 되는 과정이었네요. 이 부분에 대해서 공부를 하면서 조금 더 세부적인 CS 지식을 얻을 수 있었습니다.
HQL로그가 찍히는 범위에서 resultsConsumer.consume이 실행되면서 resultSet.next()를 반복하며 데이터를 가져오게 됩니다(resultSet은 이미 DB에서 가져왔던 결과). 처음 DB에서 데이터를 가져올 때 이를 JVM 메모리 내부에 존재하는 jdbc 드라이버의 내부 버퍼에 저장하게 되고 resultSet.next()를 통해서 그곳에서 가져오게 되는 것이고, 저는 이 부분을 DB에서 가져온다고 오해했습니다.
결론적으로 HQL 로그를 통해서는 영속성 컨텍스트와 관련된 소요 시간을, Session Metric을 통해서는 세부적인 SQL 실행 시간을 정확히 볼 수 있었습니다.
지금까지는 모든 열을 함께 반환하는 DTO로 비교했는데 이번에는 2개의 열만 반환하는 예시도 함께 결과를 첨부하겠습니다.
🤫 Q: DTO 직접 반환은 Repository단의 매서드가 API에 의존하게 되는 trade-off가 발생하는데 이걸 감수할만할까?
✅ A: HQL 로그 시간을 보면 영속성 컨텍스트와 관련된 소요시간의 차이가 꽤 나는 것을 알 수 있다, 따라서 성능이 중요한 상황이라면 유의미하다고 생각한다. (findAll 메서드는 프로젝션 메서드에 비해 이 시간이 2.36배가량 길다)
🤫 Q: SQL 실행 시간은 왜 findAllDTO가 더 길 까요?
✅ A: 모든 Column을 매핑하게 될 경우 일반 메서드보다 더 비효율적일 수 있습니다. 따라서, 필요한 Column만 가져오도록 하면 훨씬 좋습니다 (SimpleDTO일 경우 매우 빠름)
이제 정확하게 성능을 비교할 수 있게 되었으니 다른 의문들도 해소해 보겠습니다.
✅ EntityGraph vs FetchJoin
큰 차이가 나지 않지만, Fetch Join이 살짝 더 빠른 결과가 나왔습니다 (실행마다 조금씩 다름). 어떤 것을 선택해도 성능에 큰 차이가 나지 않을 것으로 생각됩니다.
✅ JQPL 메서드 vs JPQ 레포지토리 네이밍 기반 메서드
큰 차이가 나지 않지만, 기본 메서드가 조금 더 빠르고 최적화가 잘 되어 있는 결과가 나왔습니다. 네이밍 메서드를 기반으로 쿼리가 가능하다면 따로 JPQL을 사용할 필요가 없어 보입니다.
📒 최종적인 나의 JPA 최적화 Note
양방향 매핑을 사용하지 않는다
N+1 문제를 꼼꼼히 점검한다. (EntityGraph 또는 JPQL을 통한 Fetch Join)
필요한 필드만 DTO 직접 반환(Projection)을 효율적으로 사용할 수 있는 경우 사용한다.
되도록이면 여러 번의 쿼리를 날리지 않고 한 번의 쿼리로 가져오도록 설계
많은 데이터를 불러오는 경우 페이징을 사용하자
적재적소에 인덱스를 적용한다 (EXPLAIN ANALYZE 쿼리 사용)
OSIV를 꺼놓자
결국 가장 중요한 것은 쿼리 그 자체였습니다. 실무에서는 지금 테스트 상황보다도 더 많은 양의 데이터를 불러오고 조건이 더 복잡한 쿼리를 사용할 일이 많이 있을 것입니다. 결과적으로 쿼리 수행 시간이 꽤 큰 비중을 차지하기 때문에 얼마나 효율적인 쿼리를 작성하고 N+1문제를 해결하는 것이 중요한 부분이었던 것이라고 생각하게 되었습니다.
DTO는 선택에 따라서 너무 많은 데이터를 가져오는 경우 페이징과 함께 적용하면 좋을 것이라고 생각했습니다. 그 이외에는 결국 쿼리 시간을 줄이기 위해서는 EXPLAIN ANALYZE를 통해서 어떤 쿼리가 나가는지 잘 점검하고 Index를 타는지 확인하는 것이 중요하다고 생각했습니다.
📌 성능 최적화 수행하기
양방향 매핑을 사용하지 않는다
✅ 처음부터 사용하지 않음
N+1 문제를 꼼꼼히 점검한다. (EntityGraph 또는 JPQL을 통한 Fetch Join)
✅ 쿼리 로그를 하나씩 확인하면서 점검(수정된 사항 없음 N+1 문제 존재 x).
되도록이면 여러 번의 쿼리를 날리지 않고 한 번의 쿼리로 가져오도록 설계
예를 들어서, 현재 프로젝트에서는 월간 기록을 조회하는 API가 있습니다.
한 유저의 N월의 기록을 불러오고, 기록마다 사진이 여러 개 있을 수 있는데 첫 번째 사진(대표 사진)을 불러오는 로직과 같이 복잡한 로직에서 loop을 돌지 않고 한 번의 요청으로 모두 가져올 수 있도록 설계했습니다.
@Query(value = """
SELECT history_id, image_url
FROM (
SELECT *,
ROW_NUMBER() OVER (PARTITION BY history_id ORDER BY created_at ASC) AS rn
FROM history_image
WHERE history_id IN :historyIds
) sub
WHERE rn = 1
""", nativeQuery = true)
List<Object[]> getFirstImageUrlsWithHistoryId(@Param("historyIds") List<Long> historyIds);
✅ 복잡한 쿼리들을 최적화해서 loop을 돌며 DB에 요청하지 않도록 최적화
필요한 필드만 DTO 직접 반환(Projection)을 효율적으로 사용할 수 있는 경우 사용한다.
많은 데이터를 불러오는 경우 페이징을 사용하자
프로젝션을 사용하면 성능은 올라가지만, 유지 보수성이 떨어지고 코드 간결성이 떨어진다는 단점이 있었습니다. 따라서, 다량의 데이터를 조회하는 경우에 프로젝션과 페이징을 동시에 사용했습니다.
Projection + QueryDSL : 여러 테이블의 필드를 Join 해서 정보를 가져와야 하는 경우 부득이하게 새로운 DTO를 생성했지만, 그렇지 않은 경우 엔티티의 모든 필드를 담은 Projection 전용 DTO를 하나만 만들어놓고 QueryDSL을 이용해 동적으로 필드를 주입했습니다.
다음과 같이 엔티티의 필드를 모두 가지고 있는 Projection용 DTO를 하나만 만들어 놓았고.
@Override
public List<HistoryProjectionDTO> getMonthlyHistoriesByMemberAndYearMonth(Long memberId, String yearMonth) {
QHistory history = QHistory.history;
//입력 YYYY-MM을 기준으로 해당 달의 1일 부터 다음 달의 1일 전까지 범위 쿼리 수행
YearMonth ym = YearMonth.parse(yearMonth);
LocalDate startDate = ym.atDay(1);
LocalDate endDate = ym.plusMonths(1).atDay(1);
return queryFactory
.select(Projections.fields(
HistoryProjectionDTO.class,
history.id.as("id"),
history.historyDate.as("historyDate"),
history.visibility.as("visibility")
))
.from(history)
.where(
history.member.id.eq(memberId),
history.historyDate.goe(startDate),
history.historyDate.lt(endDate)
)
.fetch();
}
필요한 필드만 QueryDSL로 주입하여 여러 개의 DTO를 만들지 않았습니다.
public interface HistoryRepository extends JpaRepository<History, Long>,HistoryProjectionRepository{
✅그리고 이런 Projection 메서드를 다루고 있는 Repository 인터페이스를 HistoryProjectionRepository로 분리하고 HistoryRepository가 HistoryProjectionRepository를 상속받게 구성하여 서비스단에서 추가적으로 프로젝션 전용 Repository를 상속받지 않도록 하여 프로젝션을 이용하면서 유지 보수성과 코드 가독성을 최대한 높였습니다.
적재적소에 인덱스를 적용한다 (EXPLAIN ANALYZE 쿼리 사용)
우선 로그에 찍히는 복잡한 쿼리들의 경우 EXPLAIN ANALYZE를 통해서 효율적으로 잘 나가고 있는지 얼마나 걸리는지 점검했습니다. Primary Key나 Unique 제약조건이 아님에도 불구하고(인덱스가 없음) 조회용으로 많이 사용되며 조회가 수정보다 빈번하게 일어나는 엔티티에는 Table 제약 조건을 통해서 보조 인덱스를 걸어주었습니다.
-> Index range scan on h1_0 using idx_member_date over (member_id = 1 AND '2025-01-01' <= history_date < '2025-02-01'), with index condition: ((h1_0.member_id = 1) and (h1_0.history_date >= DATE'2025-01-01') and (h1_0.history_date < DATE'2025-02-01'))
(cost=1.16 rows=2) (actual time=0.117..0.121 rows=2 loops=1)
✅EXPLAIN ANALYZE를 통해서 쿼리가 인덱스를 타게 되면 Full Table Scan이 일어나지 않았고 쿼리 성능 시간이 매우 빨라졌습니다.
