2024. 11. 24. 16:41ㆍ카테고리 없음
> 이 글은 Elastic APM이 Kibana에 수집하는 데이터를 바탕으로, transaction 및 span 같은 주요 이벤트의 종류와 의미를 분석하며, 이를 통해 성능 병목 문제를 어떻게 확인하고 해결할 수 있는지에 대해 설명합니다.
또한, 실제 사례를 통해 문제가 발생한 원인을 추적하는 과정을 공유합니다.
배경
최근에 회사에서 검색을 개선하기 위해 저는 Elasticsearch 를 도입했었습니다.
그래서 매번 Elasticsearch 관련 이슈가 생길때마다 항상 제가 도맡아 작업을 하게 됐는데,
이러다 보니 팀원들에게 이제 Elastic? —> 채훈님? 이라는 인식이 강하게 박혀있던 찰나, 일이 생겼습니다.
금주 개발 서버가 갑자기 원인 모를 이유로 매우 아파하는 이슈가 있었습니다.
그리고 그럴때마다 항상 다음과 같은 로그가 남아있었습니다.
Max spans (200) for transaction has been reached. For this transaction and possibly others, further spans will be dropped. See config param ‘transaction_max_spans*
팀원들에게 있어 Elastic 이라는 단어는 그저 침 분비샘 자극제 일 뿐입니다.
그러기에 저 Elastic 단어 하나 때문에항상 온갖 음해와 음모론에 시달렸습니다.
하필 저런 버그가 뜰 때마다 왜 저 Elastic APM 이라는 애가 저렇게 아파하는 걸까…
저는 이런 의심의 눈초리에 개탄하지 아니할 수 없어 해명을 해야함을 결심, 이 글을 작성하고 팀에게 공유하게 되었습니다.
APM & Elastic APM & Transaction ?
먼저 APM 이라는 개념에 대해서 일반적인 정의를 보면 다음과 같습니다.
애플리케이션 성능 모니터링(APM)은 소프트웨어 도구와 원격 측정 데이터를 사용하여
애플리케이션의 성능을 모니터링하는 프로세스입니다. APM 도구를 사용하여
애플리케이션의 성능에 대한 실시간 데이터와 인사이트를 제공합니다.
출처 : https://aws.amazon.com/ko/what-is/application-performance-monitoring/
이런 APM 은 다음과 같은 지표들을 추적합니다.
- CPU 사용량
- 응답 시간
- 오류율
- 트랜잭션 추적
- 인스턴스
- 요청
- 가동 시간
📖 트랜잭션 추적이란?
1. 요청의 시작부터 끝까지 시간을 측정하고,
2. 각 단계에서의 시간 소모, 오류 여부, 리소스 사용량(CPU, 메모리 등)을 분석하여 전체 성능을 최적화
하는 프로세스
APM 의 일반적인 정의와 비슷하게, Elastic APM 의 정의도 다음과 같습니다.
💡 Elastic APM은 Elastic Stack에 구축된 애플리케이션 성능 모니터링(APM) 시스템입니다.
수신 요청, 데이터베이스 쿼리, 캐시 호출, 외부 HTTP 요청 등에 대한 응답 시간에 대한 자세한 성능 정보를 수집하여
소프트웨어 서비스와 애플리케이션을 실시간으로 모니터링할 수 있습니다.
출처 :https://www.elastic.co/guide/en/observability/current/apm.html
즉 Elastic APM 은 APM 시스템인데, Elastic Stack 에서’만’ 의미가 있다는 뜻.
여기서 제가 이해가 가지 않았던 구분이 있는데, 바로 "Elastic Stack 에 구축된" 이라는 키워드입니다.
이에 대한 설명은 다음과 같습니다
📖 "Elastic Stack에 구축된"의 의미
Elastic APM이 Elastic Stack 구성 요소(Elasticsearch, Kibana) 와 함께 동작하며, 이들의 기능을 활용해 성능 모니터링을 제공한다는 뜻입니다. Elastic APM만으로는 데이터 수집과 전달까지만 가능하며, Elasticsearch(적재 장소)와 Kibana(시각화)가 없으면 데이터를 저장하거나 시각화할 수 없습니다.
그렇다면 transaction, span 이란?
항상 개발 서버가 느려지면, 동시에
For this transaction and possibly others, further spans will be dropped. See config param 'transaction_max_spans'.
와 같은 문구가 나옵니다.
사실 transaction, span 이런 키워드들은 Elastic APM 이 수집하는 이벤트의 형태입니다.
Elastic APM 이 수집하는 Event 종류
⚠️ 텍스트 산더미 주의 ⚠️
이 목차 보다가 텍스트가 너무 많아 못 보겠으면,
다음 목차에서 실제 예시를 먼저 보고 오셔도 좋습니다!!!!
- 스팬(Span)
- 특정 코드 경로의 실행에 대한 정보를 담고 있음
- Transaction과 Trace를 구성하는 기본 요소입니다.
- 트랜잭션(Transaction)
- Elastic APM 에이전트가 서비스에서 포착한 이벤트를 나타냅니다.
- 기술적으로는 추가 속성을 가진 스팬의 한 유형으로, 일반적으로 여러 자식 스팬을 포함합니다.
- 서비스 내에서 측정하는 가장 높은 수준의 작업 단위로 생각할 수 있습니다.
- 트레이스(Trace)
- 공통 루트를 공유하는 transaction 과 span 그룹입니다.
- 단일 요청의 전체 과정을 추적합니다.
- 트레이스가 여러 서비스를 거치면 이를 **분산 트레이스(Distributed Trace)**라고 합니다.
- 에러(Error)
- 애플리케이션 요청 중 문제가 발생하면 생성됩니다.
- Error event는 문제가 발생한 위치와 이유를 파악할 수 있는 정보를 포함하며, 종종 발생한 트랜잭션 정보도 함께 제공됩니다.
- 메트릭(Metric)
- 시스템 상태를 정기적으로 측정한 정보를 제공합니다.
실제 예시 한번 보기
먼저 kibana에 접속하게 되면 다음과 같은 화면을 볼 수 있습니다.
해당 페이지에서 POST /flight/list/itinerary 의 Trace 를 한번 확인해보겠습니다.
POST /flight/list/itinerary 의 Trace 전체 캡쳐본입니다.
구체적으로 볼 필요는 없고, 대략 하나의 API 호출 안에서 일어나는
서브 호출(?)등이 이렇게 분석, 트래킹이이 되는 구나~ 라는 전반적인 그림을 알 수 있습니다.
그렇다면 이제 위 전체 Trace 에서 일부분을 통해 어떻게 분석이 되는지, 다음 화면에서 확인할 수 있습니다.
- 전체 요청 처리 시간
- 가장 상단의 초록색 막대는 전체 요청에 소요된 시간을 나타냅니다.
- span 별 실행 시간
- 하위 스팬들은 요청 처리 과정에서 실행된 개별 작업입니다.
- 각 스팬의 실행 시간을 확인하여 비정상적으로 긴 시간이 소요된 작업이 있는지 파악하세요. 특히 빨간색 막대는 상대적으로 시간이 오래 걸린 작업을 나타냅니다.
- Database(MySQL, Redis) 관련 작업
- SELECT, INSERT, UPDATE와 같은 SQL 쿼리가 여러 번 실행
- 이떄 SQL 쿼리 실행 시간이 비정상적으로 길다?
- 인덱스가 적절히 설정되어 있는지 확인
- 불필요한 쿼리 반복 실행 여부 점검
- 배치 작업 또는 캐싱으로 최적화 가능성 고려
- HTTP 요청
- POST, GET 등 외부 서비스 호출과 관련된 span.
- 외부 서비스 호출 시간이 지연되었거나 실패한 경우:
- 네트워크 상태 점검
- 호출 대상 서비스의 상태 모니터링
er,,,error 도 맛있습니다(?)
위에서는 각 span 으로부터 어떤 작업이 있고, 각 작업의 latency 등의 정보를 확인 및
해당 정보로 추론할 수 있는 정보들을 알아봤지만, 사실 그것보다 맛있는 건(?) error도 확인할 수 있다는 겁니다.
사진에 표시된 초록 박스들을 보면 Error 가 있었다는 Notification 과 함께,
우측 초록 박스안 어떤 에러였는지 클릭해서 볼 수 있는 div 상자 하나가 나오게 됩니다.
해당 상자안 링크를 누르게 되면 다음 화면으로 넘어가게 됩니다.
상자 안 링크를 누르고 넘어온 화면에선
- 어느 시점에,
- 어느 Endpoint 에서,
- 어떤 error stack 을 콘솔창에 찍으며 exception 을 던졌나
에 대해서 알 수 있습니다.
(중요) 그렇다면 다시, 왜 내가 범인이 아닌가?
다시 돌아가 개발 서버가 매우 힘들어할 때 나오던 추궁 slack 을 다시 보겠습니다.
WARN co.elastic.apm.agent. impl.transaction.Span - Max spans (200) for transaction has been reached. For this transaction and possibly others, further spans will be dropped. See config param ‘transaction_max_spans*
이 에러 로그를 해석하면 다음과 같은 의미로 해석할 수 있습니다.
해당 transaction 에 대해서 span 을 여러개 만들다 보니 너무 많아!
너가 세팅한 transaction 당 기록, 수집할 span 의 개수는 200개야.
이걸 더 늘리고 싶다면, transaction_max_spans 라는 파라미터를 설정에서 수정해!
즉 원인 모를 이유로 에러가 날 당시에 너무 많은 span 이 찍히게 되어,
Elastic Apm 은 설정된 200개 이상의 span 들은 수집하지 않고 버린다는 걸
사용자에게 notify 하기 위한 경고문을 남긴 겁니다.
그렇다면 왜 Elastic APM 은 span 의 개수에 제한을 두었을까? 라는 의문을 가질 수 있는데,
이에 대한 해답은 Elastic 의 공식 문서에서 확인할 수 있습니다.
📖 Dropped spans
성능상의 이유로 APM 에이전트는 스팬을 샘플링하거나 의도적으로 생략(드롭)할 수 있습니다. 이는 100개 이상의 스팬을 포함한 장기 실행 트랜잭션과 같은 에지 케이스로 인해 APM 에이전트와 APM 서버가 과부하되는 것을 방지하는 데 유용합니다. 이러한 상황이 발생하면, 애플리케이션 UI에는 드롭된 스팬의 개수가 표시됩니다.
즉, Elastic APM 에서 에러가 난 게 아니라,
수집하는 span 이 설정한 transaction_max_spans 숫자보다 많아서 생기는 경고문이였지, 에러는 아니였습니다!
파묘 및 부검 후, 진범 묻어드리기
여기까지만 글을 작성했다면 아름다운 정보성 글로 끝났을 수도 있습니다만,
온갖 음해에 시달리며 마음에서 피어난 기쁜 마음(?), 영광(?)들의 올바른 주인을 찾아주겠다는 결심과 함께 부검을 시작했습니다.
그래서 서버가 아파하던 시점에 호출된, Latency가 높은 API 를 찾아나서기 시작합니다.
그래서 로그의 시간대를 서버가 아파하던 시간대로 옮기고 나니, 평소에 보이지 않던 비정상적인 Latency 의 API 를 하나 찾게 됩니다.
그렇게 해당 Endpoint 에 대한 Trace 를 타고 상세 정보를 확인하게 되니,
다소충격적인 transaction + span 을 확인할 수 있었습니다.
회사의 테이블명이 나와 있어 제대로 공개할 수는 없지만,
계속해서 똑같은 내용의 INSERT, SELECT 쿼리의 반복이 엄청나게 있어 병목이라는 것을 확인할 수 있었습니다.
또한 이 부분에서 아까 얘기했던
⚠️ Max spans (200) for transaction ... has been reached.
이 span 이 너무 많아서 못 찍겠다는 경고문이 해당 API 호출에서 알림이 떴다는 것을 확인할 수 있었습니다.
위 로그를 기반으로 해서 코드를 보니, bulk insert 로 실행됐어야 할 쿼리들이
for 문 안에서 단 건 by 단 건으로 되어있어 생기는 문제들이었습니다.
그래서 해당 자료 근거를 가지고 코드 파묘(?) 후 이전 담당자에게 잘 전달해줬습니다.
(해당 업무의 담당자인 사수에게 알림 후, 일에 파묻혀 죽으려는 사수를 보며 개운한 속을 가질 수 있었습니다 ㅎㅎ)
정리
눈에는 눈, 이에는 이 가 아니고, 다음과 같이 정리해볼 수 있겠습니다
- Elastic APM의 역할 : Elastic APM은 애플리케이션의 트랜잭션 및 스팬을 추적하여 성능 문제를 식별하고 개선점을 도출할 수 있도록 돕습니다.
- 트랜잭션 및 스팬 관리의 중요성 : 지나치게 많은 스팬은 성능에 부정적인 영향을 미칠 수 있으므로 적절한 설정(transaction_max_spans)과 코드 최적화가 필요합니다.
- Kibana의 유용성 : Kibana는 Elastic APM이 수집한 데이터를 시각적으로 제공하며, 병목 현상과 에러를 효율적으로 분석할 수 있습니다.
- 문제 원인 추적 : 반복적인 쿼리 실행과 같은 비효율적인 코드 구조는 병목 현상의 주요 원인이며, 이를 로그 및 트레이스를 통해 파악할 수 있습니다.
- 파묘 및 부검 이후 잠에 잘 들수 있었다 (?)