Intellij Profiler와 함께하는 POI 대용량 엑셀 다운로드 성능 개선기 (2)

date

Jan 26, 2025

slug

optimize-large-excel-poi-performance-with-intellij-profiler-2

status

Published

들어가며

지난 글(링크)에서는 인텔리제이 프로파일러에 대한 사용 방법과, Apache POI에서 SXSSF 방식 및 커서 기반 페이지네이션를 사용한 엑셀 로직을 해당 프로파일러를 사용하여 최적화하는 과정에 대해 다루었습니다. 여기서 FETCH_SIZE 값을 변화시켜가면서 최적 지점을 찾을 수 있었습니다.

플레임 그래프를 분석하면서 병목 지점으로 의심되는 부분을 찾았고, 이를 통해 페치 조인이 적용되지 않았다는 것을 알게 되었습니다. 페치 조인을 적용한 후에는 추가 쿼리가 발생하지 않기에 성능이 개선될 것으로 예상했지만, 실행 시간은 크게 줄지 않았고, 오히려 힙 메모리만 증가하는 문제가 발생했습니다.

페치 조인이 해결책이 아닌 이유

플레임 그래프 분석하기

플레임 그래프 (좌: 페치 조인, 우: 지연 로딩) 를 가져왔습니다. 우 → 좌 순으로 보면서 변화가 있었던 부분을 찾아보겠습니다.

먼저 페치 조인을 수행하면서 우측의 PersistentBag.get 이 좌측에서는 없어진 것을 볼 수 있습니다.

하지만 createRow() 자체는 전후 소요 시간이 비슷합니다.

메서드 별 실행 시간 차이 분석하기

아까 전에 스프링은 프록시 기술을 사용하기 때문에 하나의 플레임 그래프로 합쳐서 보기는 어렵다고 했었죠. 하지만 두 결과의 실행 시간 diff 값을 확인할 수 있는 방법이 있습니다.

바로 인텔리제이의 Method Merged Callees 를 사용하면 됩니다. 이는 이전 글에서 소개했던 인텔리제이 프로파일러 기능 중 3) 메서드 리스트에 해당합니다.

프록시 호출이 더 이상 발생하지 않는 createBookExcel 을 우클릭 선택 후 클릭합니다.

그러면 위와 같이 깔끔한 Diff 값을 크기 순서대로 정렬하여 볼 수 있습니다.

실제로 값을 가져와서 시트에 값을 쓰는 작업을 하는 populateSheets 를 봅시다. -5,984ms로, 약 6초정도 더 빠르게 시트에 데이터를 썼다는 것을 알 수 있습니다. 이는 기존 대비 4.4% 빠른 값이라는 것도 알 수 있습니다.

다른 메서드도 확인해봅시다.

페이징 쿼리를 수행하는 searchBookWithTasksForExcel 의 시간은 67,510ms 증가했습니다.

반면 기존에 페치 조인 미적용으로 인해 병목 지점으로 판단했었던 addTaskInfoRow 의 소요 시간은 74,574ms 감소했습니다.

이 결과가 시사하는 바는 무엇일까요?

먼저 우리가 가져와야 하는 데이터의 크기는 동일합니다. 단, 지연 로딩 후 각 작업에서 작업항목이 필요해질 때 추가 쿼리를 통해 작업항목 컬렉션을 가져오느냐, 아니면 페치 조인을 통해서 한번에 가져오느냐의 차이인 것이죠.

searchBookWithTasksForExcel 은, 지연 로딩 때 작업 엔티티만 가져오다가 페치 조인을 통해 작업항목까지 같이 조회해오기 때문에 더 긴 시간이 소요됩니다.

addTaskInfoRow 의 경우, 내부적으로 지연로딩된 컬렉션에 접근하여 추가 쿼리를 발생시키고 (이로 인해 일전의 PersistentBag.get 이 호출됩니다), 페치 조인을 통해 이 추가 쿼리가 더 이상 발생하지 않기 때문에 더 짧은 시간이 소요됩니다.

즉, 실제 메서드 실행 시간의 차이를 분석한 결과, 지연 로딩 방식보다 페치 조인 방식이 67,510 - 74,574 = 6,074ms 만큼 더 빠르다는 것을 알 수 있습니다.

중간 정리

이전 글에서 프로파일링을 수행했을 때는 5,075ms의 시간만 감소했고, 힙 메모리는 457MB가 추가로 증가했다고 했었습니다.

앞 섹션에서 우리는 지연 로딩으로 인한 추가 쿼리를 페치 조인으로 제거함으로써 6,074ms 만큼의 시간이 단축되었음을 알 수 있습니다.

그렇다면 6,074 - 5,075 = 999ms의 행방이 궁금하지 않나요? 이는 페치 조인을 하게 되면서 발생한 비용이라고 할 수 있겠습니다. 페치 조인을 하게 되면 실제로 사용하지 않는 작업항목 컬렉션까지 페치 조인을 통해 가져오게 되고, 이를 일대다 컬렉션으로 초기화하는 과정에서 추가적인 시간과 공간이 소요됩니다.

힙 메모리가 457MB만큼 추가로 사용된 것도 비슷한 맥락이라 할 수 있겠습니다.

그건 그렇고, 지연 로딩 → 페치 조인이 큰 효과를 보지 못했다는 사실은 변하지 않습니다. 고작해야 6초 개선하고 끝이거든요. 여전히 느리고, 여전히 근본적인 해결책이 아닙니다. 더 개선할 수 있는 방법을 찾아봅시다.

일대다 필드의 원소가 항상 1개로 조회되는 문제 트러블슈팅

마감이 중요

그 전에…

개선보다 중요한 건 마감입니다.

사실, 이 문제가 아예 해결할 수 없는 건 아닙니다. 페치 사이즈를 극한으로 줄이고 스펙을 증설하는 방식으로 해결할 수 있긴 하죠. 이게 근본적인 해결책이 아니긴 하지만, 데드라인을 맞춰야 하고, 원인도 파악하기 어렵다면 어쩔 수 없이 이 방법을 택할 수는 있겠습니다.

마감을 맞추기 위해서는 성능 개선에 대한 고민은 일단 제쳐놓고, 이 기능이 우리의 예상대로 동작하는지 검증해야 합니다. 역시 QA 과정에서 한 가지 문제가 발생했습니다.

문제 상황

현재 정책에 따르면 Task 가 가지는 일대다 필드인 List<TaskItem> 은 항상 10개여야 합니다. 하지만 해당 컬렉션의 원소 개수가 항상 1개로 조회되는 문제가 발생했고, 쿼리 시점부터 1개만 가져온다는 것을 알게 되었습니다. 아래는 문제의 코드입니다.

해결 방법

중간에 많은 일들이 있었지만… 결론은 꽤 허무했습니다. 아래와 같이 수정하면 됩니다.

fetch() 를 누락한 겁니다. 그러고 보니 이전 글에서도 fetchJoin() 누락했었죠. 제 QueryDSL 숙련도 이슈였습니다.

근데 왜 1개?

그런데 fetch() 를 호출하면 아예 조회를 안해야 하지 않나? 라는 궁금증이 생길 수도 있습니다. 아예 일대다 컬렉션이 비어있었으면 모를까, 딱 1개만 있으니 저도 트러블슈팅 과정에서 꽤나 어려움을 겪었습니다.

이유는 fetch() 를 호출하기 전 리턴 타입에 있습니다. JPA 2.2부터, fetch() 를 호출하지 않으면, 조회 결과를 Stream<Task> 와 같이 스트림 타입으로 받을 수 있는 기능이 추가되었습니다. 자세한 내용은 이 레퍼런스(링크)를 확인해주세요.

스트림 조회과 페치 조인의 관계

일대다 관계를 페치 조인하게 되면, 다 쪽의 개수만큼 일 쪽의 중복 레코드가 생긴다는 사실은 알고 계실 겁니다. 즉 task 를 기준으로 조회하되 task_item 을 조인하기 때문에 중복된 Task 가 조회되는 것이죠.

fetch join를 사용하게 되면, 이러한 중복 레코드를 하나로 transform하여, 하나의 Task 엔티티에 딸려있는 List<TaskItem> 컬렉션으로 초기화하는 작업을 수행합니다.

하지만 스트림 방식으로 조회하게 되면 어떤 문제가 발생할까요? task 그리고 조인된 task_item 한 건만이 조회되어, 하나의 Task 엔티티로 변환됩니다. 이후에 들어오는 중복된 Task 는, 이미 Task 엔티티가 초기화된 상태이기 때문에, 무시됩니다.

결론적으로 일대다 관계에 대하여 페치 조인을 수행하면서, 스트림 조회 기능을 같이 사용하게 되면, 컬렉션에 항상 하나의 아이템만 들어가게 됩니다.

진짜 병목 발견: `fetch()`

조회가 문제

위에서 fetch() 를 추가한 후 라인 프로파일러를 통해서 조회 로직을 분석해보니, 진짜 문제점을 발견할 수 있었습니다.

네. fetch() 를 호출하는 데 94,444ms(= 94.4초)가 걸립니다. 전체 시간이 120초 ~ 140초 가량 걸렸던 것을 생각해보면, 전체 실행 시간에 대하여 거의 80%를 차지하고 있다는 것을 알 수 있습니다.

왜 `fetch()` 는 오래 걸릴까

fetch() 의 내부를 분석하면, 크게 두 단게로 이루어집니다. 먼저 DB로부터 데이터를 가져온 후, 엔티티 객체에 해당 값들을 매핑하여 초기화하는 것입니다. 저는 후자로 인해 대부분의 오버헤드가 발생하고 있는 것으로 예측했습니다.

실제 쿼리 실행 시간은?

이를 위해서는, ‘DB로부터 데이터를 가져오는’, 즉 쿼리의 실행 시간이 위 94.4초의 극히 일부분만을 차지하고 있다는 것을 보이면 됩니다.

MySQL EXPLAIN ANALYZE로 확인한 결과, 쿼리 실행에는 2초 미만이 소요된다는 것을 확인할 수 있었습니다. 즉, 문제의 원인은 Task - TaskItem 일대다 관계를 초기화하는 과정에서 대부분의 오버헤드가 발생하고 있었던 것입니다.

해결 방법: 엔티티 프로젝션에서 DTO 프로젝션으로

Hibernate는 조회 결과를 두 가지 형태로 가져올 수 있습니다. 하나는 엔티티고, 하나는 DTO입니다. 우리는 이걸 엔티티 프로젝션과 DTO 프로젝션이라고 부릅니다.

DTO 프로젝션을 사용하면, 거의 모든 경우에서 조회 성능 상 이점을 얻을 수 있습니다. 이유는 두 가지인데요, DTO 프로젝션은 엔티티 일부 컬럼만 조회하기 때문이며, 다른 하나는 영속성 컨텍스트 1차 캐시에 의해 이러한 값들을 관리하는 오버헤드를 회피할 수 있기 때문입니다 (이게 핵심입니다).

DTO 프로젝션 후 실험 결과

DTO 프로젝션으로 로직을 변경한 후 실행 시간 및 최대 힙 사용량을 테스트해보았습니다.

실행 시간 : 140초 → 60초

최대 힙 메모리 : 2500MB → 700MB

확실히 개선된 모습을 볼 수 있습니다.

정리

이번 시리즈에서는 엑셀 로직을 개선하면서, 1) SXSSF 방식 + 페이징 쿼리에서의 페치 사이즈 최적 지점을 분석하고 2) 일대다 관계와 스트림 조회를 같이 사용할 때 발생하는 문제를 트러블슈팅했으며 3) 최대 병목 지점이 엔티티 프로젝션이라는 사실을 인지하고 DTO 프로젝션으로 전환하여 성능을 획기적으로 개선했습니다.

제 경험이 도움이 되셨기를 바라며 이번 글은 여기서 마무리하도록 하겠습니다.

읽어주셔서 감사합니다.