얼마전 Backoffice에서 Page단위로 데이터를 조회할 때 꽤 느리다는 이야기를 전달 받았습니다.
또한, 몇 천개의 데이터를 Excel로 다운받는 과정에서, 약 40s가 걸리며 과도하게 느린 이슈가 발생하고 있었습니다.
이 기능을 운영에 배포하기 전까지 개선하는 작업을 맡게 되었고, 우선 어디서 문제가 발생했는지 파악이 필요했습니다.
또한, 데이터는 꽤 가파르게 증가 할 예정이라, 병목 지점을 확인 및 데이터 증가에 따라서도 대응 가능하도록 처리가 필요했습니다.
상황
보통의 경우 사내에 표준 모니터링 Tool인 Datadog을 통해 병목 지점을 확인하고 있었고, 이를 통해 성능 개선을 한 사례도 있었습니다.
다만, Backoffice 또는 Datadog Tracing 설정 때문인지는 정확히 파악하지 못 했지만,
API는 Trace 기록이 매우 적게 남아있었습니다.
API Call 횟수는 남아있음에도, 어디서 얼마나 걸렸는지 정확한 Trace 정보가 없다보니 문제 파악이 어려웠습니다.
문제 : Datadog에 Trace 정보가 아주 적게 Sampling 되고 있었음. 약 일주일 전에 호출한 건만 남아있었으며, 이로 파악이 어려운 상태
재현하기
이 문제를 해결하기 위해 개발 DB에 Mock 데이터를 놓고 테스트를 진행했는데, 단순 데이터 조회임에도 약 2s가 걸리며 생각한 성능이 나오지 않고 있었습니다.
또한, 팀 특성 상 Gateway 역할을 하는 서버에서 Internal 서버로 호출해서 데이터를 가져오고 있었는데, 이를 모두 로컬에 띄워서 테스트를 완료 했습니다.
외부로 열려있는 Backoffice Gw 서버와 Internal 서버를 로컬에 띄워서 확인.
문제파악
Gateway 서버에서 Excel 데이터를 생성할 때 Page 단위로 조회한 데이터를 가공해서 만들고 있었습니다.
다만, 여기서 문제는 하나의 요청을 Blocking 호출로 하나씩 처리하고 있었습니다.
이로 인해, 약 3000개의 데이터를 가져올 때 100개씩 Page 단위로 호출하고, 약 1~2초 씩 걸리는 API를 순서대로 처리하니 병목 현상이 발생하고 있었습니다.
그러면 여기서 2가지 선택을 할 수 있었습니다.
1. Page 요청 단위를 늘린다.
2. 병렬로 API를 호출하여 데이터를 가공한다.여기서 Page 단위를 늘리는 방법은 요청하는 데이터가 많아질수록, Response의 데이터가 커지는 문제가 있을 수 있었습니다.
또한, Gateway 서버에서는 이미 Page 단위로 가져온 데이터를 Excel에 저장하고, 메모리에서 버려서 메모리 최적화를 해 둔 상태였습니다. (내부적으로 데이터를 저장소에 flush하고, 메모리를 최적화함)
단순히 Page 크기를 늘리는 방법은 위의 최적화를 버리는 선택으로 보였으며, 언제든지 Page 단위를 조절해야 한다는게 좋은 해결법은 아닌 것 같았습니다.
즉, 저는 비동기로 처리 하기 위한 Thread Pool을 새로 생성하고, 이를 통해 비동기로 여러번 호출하도록 처리 했습니다.
전역으로 설정한 Thread Pool을 주입받을 수 있도록 하였으며, Page 단위나 병렬로 호출하고 싶은 함수를 전달받아서 비동기로 처리하는 확장함수를 추가 했습니다.
위와 같이 처리하면서 Gw서버에서 여러번 호출하여 가공하는 API들을 같이 최적화 할 수 있었습니다.
기존 메모리 최적화를 지키고, 세밀한 Control을 위해 API 호출을 병렬로 호출하여 데이터를 가공하도록 변경. (단, Excel 을 생성하기 위한 Page Count도 물론 1000으로 올림)
끝..?
위와 같이 개선하여 약 몇천건의 데이터를 5s 내로 Excel 다운로드 할 수 있도록 개선했습니다.
다만, 적은 데이터를 조회함에도 1~2s가 걸리는 Page 호출이 마음에 걸렸습니다.
여기서도 개선이 필요해 보였으며, Page 요청 단위가 커질수록 느려지는게 마치 시한폭탄을 넘기는 기분이 들었습니다.
이를 최종적으로 확인하기 위해 고민하던 중, 예전에 성능 개선을 위해 이것저것 건드리면서 알게 된 Intellij Profile 기능이 기억 났습니다.
이걸로 Local 환경에서도 비슷하게 Trace를 확인했던 것 같아서, 얼른 셋팅을 하고 처리해보기로 마음 먹었습니다.
Page 요청 API가 아직 느리므로, Intellij Profile 기능을 통해 Trace를 확인해보기로 함.
- 참고 링크: Intellij 공식 링크
Profile을 통한 세밀한 Trace 확인
Intellij에서 제공하는 Run With profile을 통해 서버를 실행합니다.
그럼 서버 구동부터 Profile을 시작하고, 초기 Profile 데이터는 필요 없기 때문에 종료합니다.
API 호출 전에 다시 Profile을 시작하고, 응답을 받은 뒤 Profile 된 데이터를 확인합니다.
여기서 우리는 Memory, CPU 사용량을 확인할 수 있으며, Thread 단위로 세세하게 데이터를 확인할 수 있습니다.
- Total Time으로 Thread 단위 시간 확인
Internal 서버에서는 Coroutine이나 비동기로 처리하고 있지 않았기 때문에 비교적 쉽게 Trace를 확인할 수 있었습니다.
Datadog과 유사하게 실제로 어느 부분에서 느린지 확인할 수 있습니다.
심지어 Flame Graph 뿐만 아니라 Method List를 통해 Call Tree처럼 볼 수 있어서, 디테일한 내용들을 확인할 수 있습니다.
여기서 확인해보니, 우리가 호출한 API를 처리하는 Thread에서 유독 Mysql DB를 조회하는 부분이 느린 것을 확인 했습니다.
가져온 데이터를 가공하는 과정에서 느릴 것이라 생각했었지만, 예상 외로 DB 조회 부분에서 병목이 생긴다는 것을 알고 충격을 받았습니다.
Intellij Profile을 통해 DB 조회 지점이 병목 지점이라는 것을 파악.
진짜 문제 파악
DB 데이터 조회 시 느려진다는 점을 확인 했습니다.
여기서 DB 조회 시 Index를 타지 않는다고 생각하였고, DB Index 및 Explain 명령어를 통해 쿼리 실행 계획을 확인했습니다.
다만, 쿼리 실행 계획을 보니 Index Scan을 하며, DB로 직접 호출 시 빠르게 응답하는 것을 확인할 수 있었습니다.
이상하다 싶어, 실제 Query 문 요청을 보기 위해 SQL 문 확인 옵션을 켠 순간, N+1이 발생하고 있다는 점을 확인했습니다.
Entity Mapping으로 처리하고 있었는데, OneToOne Mapping으로 처리된 곳이 문제였습니다. 비주인 관계인 예약 데이터를 가져올 때 다른 Entity를 FetchType = Lazy로 가져오도록 처리되어 있었지만, 실제로는 조회하지 않음에도 모두 가져오고 있었습니다.
이건 확인해보니 OneToOne 관계에서 Lazy 설정이 먹히지 않는다고 관련 글이 꽤 있었습니다.
(이건 DB상에서 주인 Entity에 대한 Meta 데이터를 가지고 있지 못해서, Proxy로 생성하지 못하고 미리 만든다? 라는 글을 확인했는데, 정확한 이유는 아직 찾지 못했는데 추후 정리하고자 합니다.)
관련 글
Entity Mapping으로 가져오는 데이터가 N+1 문제가 발생하고 있다는 사실 발견.
해결
내부에서 예약 정보를 추상화해서 필요한 함수들을 공통화하여 사용하고 있었습니다.
여기에 예약 정보에서 연관관계로 걸려있던 데이터를 가져오기 위해 공통 함수로 처리하고 있었습니다.
이 부분은 추상화되어 있는 부분을 모두 수정하기 보다는 Repository를 한번 더 감싸서 사용하도록 변경하고, 연관관계에서 N+1이 발생하는 관계를 끊고 데이터를 각각 가져와서 가공하는 방법으로 처리 했습니다.
위와 같이 처리하여, 공통된 추상화 레벨의 코드는 살려두고 연관관계로부터 발생하는 문제를 해결했습니다.
이 개선을 통해 API는 약 200ms 로 줄였으며, Excel 다운 속도도 2s 내외로 처리되었습니다.
추상화된 공통 함수를 제거하지 않기 위해, 내부 필드로 선언된 주인관계 Entity의 연관관계를 끊음. Repository를 한번 더 감싸서 필요한 데이터는 각각 가져와서 가공하도록 변경.
느낀점
Datadog에서 Trace가 되지 않는 상황에서 병목 지점을 파악하는데 꽤 중요한 역할을 했던 것 같습니다.
실제로 우리가 관리하는 코드레벨에서는 모니터링 Tool을 이용해 병목 지점을 파악하기 쉽지만, 내부 라이브러리에서 발생하는 병목 지점은 파악하기 어려울 것 같은데요.
Intellij Profile을 통해 오픈소스 코드에서 발생하는 병목지점을 파악하고 컨트리뷰트를 했다는 경험도 들었었는데, 다음에는 그런 경험을 해볼 수 있다면 재밌을 것 같습니다.
이상으로 Profile 을 통해 API 병목 지점을 개선한 글을 마무리 하겠습니다.
긴 글 읽어주셔서 감사합니다.
