Scouter APM 소소한 시리즈 #3 - Active Service와 XLog

Scouter is an APM optimized for developers.

APM이 다른 모니터링 도구와의 차이점 중 하나는 발생한 문제의 결과가 아닌 원인에 접근할 수 있다는 것입니다.

이를 위해 Scouter에서는 어플리케이션이 지금 어떤 코드를 실행하고 어디서 지연되고 있는지를 파악할 수 있는 "Active Server 모니터링"과 이미 응답한 요청에 대해 상세 분석할 수 있는 Scatter 형식의 차트인 "XLog"를 제공합니다.

1. Active Service 모니터링

"Active service"란 현재 시점에 어플리케이션에서 수행되고 있는 요청을 나타냅니다.

이에 대한 모니터링은 주로 "Active Service EQ" 차트로 하게되는데, 서비스 지연으로 인한 장애를 가장 먼저 발견할 수 있는 차트이기도 합니다.

<그림. Active Service EQ>

위 그림은 다섯개의 인스턴스를 모니터링하고 있으며 숫자는 현재 동시에 실행중인 서비스의 개수를 의미합니다. 지연되는 서비스는 3초 이후에는 노란색, 7초 이후에는 빨간색으로 표시가 됩니다.

여기서 실행중인 서비스의 정보를 알고 싶다면 상세히 보고싶은 인스턴스를 더블클릭하면 "Active Service List" 화면이 열리게 됩니다.

<그림. Active Service List>

여기서는 호출된 서비스명과 현재까지 수행중인 시간(ms), 요청자 IP, 쿼리나 다른 서비스를 호출하고 대기중이라면 해당 쿼리나 서비스의 이름, Thread의 상태와 이름등이 보여집니다. 

• Service - 요청한 서비스의 이름
• Elapsed - 현재 시점까지 수행중인 시간
• Note - 현재 수행중인 쿼리 혹은 원격 호출하고 대기중인 다른 서비스
• CPU - Thread가 생성된 후 현재까지 사용한 CPU
• IP - 요청자 IP
• State / Name - Thread의 상태와 이름

여기서 상세하게 보고 싶은 서비스가 있다면 해당 서비스를 더블클릭하면 아래와 같은 상세화면이 열립니다.

위 예에서는 HttpClient가 서비스 요청하였고 응답을 대기하고 있다는 것을 StackTrace를 통해 알 수 있습니다.

이와 같이 "Activer Service" 모니터링을 통해서는 현재 시스템의 응답이 지연되고 있는지를 바로 파악할 우 있으며 상세 정보를 통해 어디서 지연되는지를 코드 레벨에서 정확히 파악할 수 있습니다.

모니터링 시점에 지연되는 부분이 있다면 여기서 원인을 파악하는 것이 가장 좋은 방법입니다. 하지만 많은 경우에 지나간 이슈에 대해 원인을 파악해야 할 필요가 있으며 이런 경우에 활용하는 것이 XLog 차트입니다.

2. XLog 차트 모니터링

XLog 차트는 모든 요청에 대해 하나의 점으로 표현하는 일종의 scatter 차트로서 x축에는 요청이 종료된 시간을, y축에는 (주로) 해당 요청의 응답시간을 표현합니다.
각 점의 색은 각 object 마다 다르며 빨간색은 에러를, 회색은 비동기 thread를 나타냅니다.
(scouter는 비동기 thread에 대한 연결 추적을 지원합니다.)

<그림. XLog 화면 조작>

위 그림에서 보이듯이 XLog의 각 점들을 마우스로 드래그하면 선택한 점들의 목록을 확인 할 수 있으며 각 XLog들은 하나의 서비스 요청에 대한 메타 정보를 가지고 있습니다.

이 메타 정보를 통해 선택한 점들이 어떤 서비스인지 응답시간은 얼마나 걸렸는지, SQL문이나 API 호출시의 응답시간은 얼마였는지 등의 1차적인 정보를 확인할 수 있습니다.

• XLog의 주요 메타 정보
• service : service명
• elapsed : 응답시간
• endtime : 요청의 종료시간
• ipaddr: 요청자의 ip
• userAgent
• sqlCallCount, sqlCallTime : 실행한 SQL 개수와 수행시간
• apiCallCount, apiCallTime : 외부로 http call을 수행한 개수와 시간
• cpu: 해당 요청을 처리하는 동안 사용한 cpu time
• kbytes: 해당 요청을 처리하는 동안 사용한 heap memory
• thread: 처리한 thread명
• country, city : geoip 정보(서버에 geoip_data_city_file 옵션 설정시)
• queuing time : proxy 서버로 부터 인입까지 걸린 시간(설정시)
• login, desc, text1~5 : agent plugin을 통해 사용자가 설정한 정보

XLog의 목록을 통해 기본적인 정보를 파악하였다면 상세 프로파일 정보를 통해 보다 더 정확한 정보를 확인할 수 있습니다. 상세 프로파일은 기본적으로 SQL 및 Socket 연결, http call및 redis call, aync thread call 등과 같은 연계에 대한 정보를 보여주며, 추가적인 설정을 통해 특정한 패턴의 메소드를 프로파일하게 할 수도 있습니다.

<그림. 프로파일에서 보여지는 메소드 및 SQL>

<그림. 프로파일에서 보여지는 외부 API 호출 정보 및 Socket 연결 정보>

만약 호출되는 API의 서버에도 Scouter가 설치되어있다면, Scouter는 spanid를 발행하여 각 서비스들(혹은 분기된 비동시 thread들)을 연결하여 추적할 수 있게 합니다.
위 그림에서 call 링크로 표현된 부분을 클릭하게되면 호출한 서비스의 profile을 보여주게 됩니다.
또한 위 그림에서 gxid 링크를 클릭하게 되면 서비스의 시작점부터 호출된 서비스 및 각 서비스가 사용한 테이블의 CURD 현황을 하나의 다이어그램으로 보여주게 됩니다.

<그림. XLog Service flow view>

• Scouter의 프로파일에선 비동기 thread 호출에 대해 외부 API 호출과 동일한 방식인 외부 링크 형식으로 보여줍니다.
  이를 하나의 화면에 tree 형식으로 보여주지 않는 이유는 (API 호출도 마찬가지이지만) thread 호출이 완료되기를 blocking하여 기다리지 않는 경우나 여러개의 thread 호출이 동시에 발생하고 이중 일부 호출에 대해서는 bloking 한후 또 다른 thread 호출이 발생하는 등 선후 관계가 서로 뒤바뀌거나 시간 순서대로 표현하기가 모호한 부분등을 나타내는데에는 링크 방식이 더 이해하기 편하다고 판단하였기 때문입니다.