Open Distro for Elasticsearch — 로그를 활용한 장애 탐지

Gaeul Kim
29CM TEAM
Published in
22 min readMar 8, 2021

29CM에서는 ELK 스택을 통해 로그 데이터를 수집하고 평균 응답시간, 주문량과 같이 서비스 품질과 관련 있는 요소들을 분석하여 모니터링에 활용하고 있습니다.

이미 많은 곳에서 비슷한 용도로 ELK를 사용하고 계실 텐데요. 이번 글에서는 Open Distro for Elasticsearch의 Alerting을 활용하여 장애를 탐지하는 방법과 이를 구현하는 과정에서 경험한 것들을 공유하고자 합니다.

장애상황

지난해 12월 30일 새벽, 29CM의 결제 서비스가 외부 협력사의 서버 문제로 중단된 적이 있었습니다. 장애는 자정부터 시작되어 약 3시간 40분가량 지속되었으며 해당 시간 동안 사용자가 요청한 모든 결제가 실패했습니다.

사실 29CM 의 결제 서비스 중단 원인은 외부 협력사의 서비스 장애가 근본 원인이었기 때문에 이슈 해결을 위해 저희가 할 수 있는 것은 거의 없었습니다. 하지만 해당 시간대에 결제를 시도하는 유저들에게 현재 결제 서비스가 장애임을 인지시켜줄 수 있었다면, 고객 경험 측면에서는 그나마 피해를 최소화할 수 있지 않았을까 싶었습니다. 또한 장애 발생과는 별개로 장애 발생 인지 시점이 너무 늦었다는 것과 그것도 외부 지인의 제보를 통해 장애를 알 수 있었다는 점은 정말 뼈아픈 상황이었습니다. 만약 저희가 장애를 즉각 알아차렸다면 그만큼 그 상황 안에서 최선의 대응을 할 수 있었을 테니까요.

모니터링 시스템

29CM 백엔드 팀은 Sentry, Grafana, Kibana 같은 도구를 사용하여 서비스 상태를 모니터링하고 로그 레벨에 따라서 슬랙 메세지를 보내도록 구성되어 있습니다. 이 방법은 코드에서 발생하는 오류나 하드웨어에 걸리는 부하를 쉽게 탐지할 순 있지만, 서비스 지표에 어떤 이상이 있는지 파악하긴 어려웠습니다.

만약 기존의 시스템에서 발생하는 오류를 확인하고 조치하는 방법에 덧붙여서 서비스 지표를 보고 장애를 의심하거나 미리 준비할 수 있다면 좀 더 유연하게 장애에 대처할 수 있을 거라 생각했습니다. 사실 이미 Kibana 를 통해 대부분의 서비스 지표는 시각화해놓은 상태였는데, 즉각적인 알람 시스템이 갖춰지지 않아서 일부 장애 상황은 빠르게 파악하기 어려운 상황이었습니다.

그래서 코드를 보완하는 것과는 별개로 빠르게 장애를 탐지할 수 있는 알람 시스템을 만들어보기로 했습니다. 그리고 여러 서비스 지표 중 가장 중요하다고 볼 수 있는 주문완료 건수를 기반으로 확장된 모니터링을 우선 구축하기로 하였습니다.

서비스 지표를 통해서 장애를 탐지

구현 방법

가장 먼저 논의된 방법은 다음과 같습니다.

  1. 최근 30일의 주문데이터를 수집하고
  2. 구간별로 주문 건수 평균을 계산하여(00:00 ~ 00:10 평균주문 50, 00:10 ~ 00:20 평균주문 45 ···)
  3. 데이터베이스에 저장한다
  4. 일정 간격으로 현재 주문 건수와 데이터베이스에 저장된 값을 비교하고
  5. 평소보다 현저히 차이 날 경우 알람을 보낸다

사실 이 의견은 백엔드 리드 분께서 제안하셨는데 필요 이상의 데이터가 날마다 적재되고 각종 이벤트에 따라 주문량이 달라지는 29CM의 특성을 반영하기에는 어렵지 않을까 하는 의견이 있어서 잠시 보류하기로 했습니다.

그러던 중 다른 동료가 “이동평균을 주문량과 비교하면 가능하지 않을까요?” 하고 의견을 주셔서 좀 더 얘기해보니 아래와 같은 방법으로 해결이 가능했습니다.

  1. (주문 완료 시 찍히는 로그를 이용한) 이동평균 값과 주문량을 수집하고
  2. 이동평균 대비 주문의 비율을 계산해서
  3. 임계치 미만인 경우 알람을 보낸다
존버는 승리한다

이동평균이란 과거 수치를 바탕으로 일련의 평균을 만들어 분석하는 계산입니다. 거기에 점을 찍고 그 점들을 선으로 이어서 만든 그래프는 이동평균선이라고 합니다. 아마 주식이나 가상화폐 거래를 하는 분들은 이미 알고 있고 적절하게 활용하고 계실 겁니다.

만약 주문도 같은 방식으로 계산이 가능하다면 주문완료 로그를 바탕으로 이동평균 값과 주문량의 차이를 구한 후 그 값이 크다면 장애 여부를 탐지할 수 있겠죠.

이동평균선을 바탕으로 한 모니터링 구축을 진행하기에 앞서 이동평균이 신뢰할 수 있는 데이터인지 확인이 필요했습니다. 간단하게 엘라스틱서치에서 제공하는 이동평균 함수(moving_fn)와 키바나의 Visualizations(TSVB)으로 그래프를 그려보기로 합니다.

29CM은 주문 완료 시 웹훅으로 메세지를 받고 있기 때문에 웹훅 URL 로 요청이 들어오고 서버가 정상적으로 응답했을 경우 주문 성공이라고 가정했습니다. 최근 3시간의 주문 성공 개수를 15분 간격으로 그룹화시켜 추이를 본다면 아래 그래프와 같습니다.

그래프를 보면 서버가 정상 상태일 때 주문량(Count)과 이동평균 값(Moving Average)의 괴리가 크지 않은 걸 확인할 수 있습니다. 그래서 같은 조건으로 몇 주간의 데이터를 대입해보니 평균적으로 이동평균 대비 주문의 비율이 40% 미만으로 떨어지지 않는 걸 볼 수 있었습니다. 여기까지 확인하고 본격적으로 구현을 시작합니다.

Open Distro for Elasticsearch

기존에는 엘라스틱서치와 함께 설치되는 X-Pack 플러그인을 무료로 사용할 수 있었지만 6.3 버전을 기점으로 라이센스가 변경되었기 때문에 Alert을 비롯한 대부분의 쓸만한 기능은 라이센스 비용을 지불해야 합니다.

29CM은 Basic 플랜을 사용하고 있기 때문에 X-Pack 대신 AWS에서 공개한 엘라스틱서치용 오픈소스 플러그인인 Open Distro를 사용하기로 했습니다. 여기엔 Alerting을 포함한 여러 가지 플러그인들이 있으며 각각 단독으로 설치 할 수 있기 때문에 입맛에 맞는 기능들을 골라서 사용할 수 있습니다.

추가로 Elasticsearch를 둘러싼 AWS와 Elastic의 대립이란 글이 꽤 재미있으니 한 번쯤 읽어보시길 추천해 드립니다.

구현 과정

Alerting 플러그인은 크게 Monitor, Trigger, Destination으로 구성되어 있습니다. 모니터를 통해 대상이 되는 도큐먼트를 조회하고 코드로 작성된 로직에 의해 트리거가 발동되면 목적지로 메세지를 전송하는 방식입니다. 필요한 순서대로 구축 과정을 간단하게 설명하겠습니다.

먼저 알람을 받을 목적지를 설정합니다. 아쉬운 점이라면 슬랙의 채널별 라우팅이 지원되지 않습니다. 그렇기 때문에 채널별로 메세지를 전송하고 싶다면 웹훅을 추가하던가, 서버를 별도로 구현해야 하는 불편함이 다소 있습니다. (관련 이슈)

그다음 서비스 지표를 파악하기 위한 쿼리를 작성합니다. 만약 쿼리 작성이 익숙하지 않다면 키바나의 Visualize → Line에서 그래프를 먼저 만들고 Inspect 메뉴를 통해 현재 쿼리를 확인하는 방법으로 참고하여 작성할 수 있습니다.

저는 date range 범위는 3시간 이전부터 현재까지, date histogram 간격은 15분으로 설정했습니다. date histogram의 간격을 짧게 할 수록 장애를 인지하는 시간이 짧아지지만 조회되는 도큐먼트가 많지 않을경우(새벽 시간대) 계산되는 데이터가 쓸모없어지기도 합니다. 서비스, 인프라 상황에 맞춰서 적당히 조절하면 될 것으로 보입니다.

{
"aggregations": {
"histogram": {
"date_histogram": {
"field": "@timestamp",
"time_zone": "Asia/Seoul",
"fixed_interval": "15m",
"offset": 0,
"order": {
"_key": "asc"
},
"keyed": false,
"min_doc_count": 0
},
"aggregations": {
"moving_average": {
"moving_fn": {
"buckets_path": "_count",
"script": {
"source": "MovingFunctions.unweightedAvg(values)",
"lang": "painless"
},
"gap_policy": "skip",
"window": 3,
"shift": 0
}
}
}
}
}
}

마지막으로 트리거를 작성합니다. 위에서 작성한 쿼리로 조회되는 도큐먼트를 읽고 메세지 전송 여부를 판단합니다. 트리거에 작성된 코드가 true를 반환할 때 메세지가 전송됩니다.

코드 작성은 Painless 라는 엘라스틱서치 전용 스크립트 언어를 사용하는데 Groovy, Java와 비슷한 문법을 가지고 있으며 몇몇 API도 동일하게 사용할 수 있습니다. 저는 처음에 트리거 메뉴에서 코드를 실행해가며 문법을 익혔는데 알고 보니 Dev Tools에 Painless Lab이라는 플레이그라운드가 있었습니다. 이곳에서 로직을 작성하시면 좀 더 편하게 테스트해 볼수 있습니다.

🙂

트리거 코드를 작성하면서 유의할 점은 반드시 마지막 요소의 부분 데이터를 버려야 한다는 것입니다. 만약 15분 간격으로 date histogram을 설정했는데 17분에 쿼리가 실행된다면 이동평균값은 0분~15분 사이의 값으로 계산될 테고 현재 주문량은 15분~17분 구간만 합산되겠죠. 이렇게 되면 조회하는 시점에 따라 결과가 달라집니다.

그래서 저는 마지막 데이터의 시작 구간에 date histogram 값을 더한 뒤 현재 시각과 비교하는 방법으로 해결했습니다.

def MONITORING_INTERVAL = 15;
...
def isPartialData = startTimeOfLatestStat.plusMinutes(MONITORING_INTERVAL).isAfter(now);
if(isPartialData) latestStat = histogramBuckets[index-1];

전송될 메세지에 필요한 수치들을 표시하기 위해 템플릿에서 사용되는 값들을 할당해줍니다. 이렇게 하면 템플릿에서 동일한 변수로 접근 가능합니다.

ctx.results[0].thresholds = THRESHOLDS;
ctx.results[0].orderCount = orderCount;
ctx.results[0].orderCountRatio = Math.round(orderCountRatio);
ctx.results[0].movingAverage = Math.round(movingAverage);

완성된 트리거 코드입니다. (일부분은 생략했습니다)

def THRESHOLDS = 40;
def MONITORING_INTERVAL = 15;
...
def isPartialData = startTimeOfLatestStat.plusMinutes(MONITORING_INTERVAL).isAfter(now);
...
ctx.results[0].thresholds = THRESHOLDS;
ctx.results[0].orderCount = orderCount;
ctx.results[0].orderCountRatio = Math.round(orderCountRatio);
ctx.results[0].movingAverage = Math.round(movingAverage);
...
if(orderCount == 0) return true;
if(movingAverage == 0) return false;
if(orderCount >= movingAverage) return false;
def orderCountRatio = orderCount / movingAverage * 100;
return orderCountRatio < THRESHOLDS;

메세지 템플릿을 작성하고 테스트를 해봅니다. 메세지는 Mustache 문법으로 작성 가능하며 딱히 어려운 부분은 없었습니다.

짜잔! 테스트해보니 원하는 대로 메세지가 잘 옵니다. 가능한 많은 지표를 함께 알려준다면 한눈에 파악하기가 수월하겠죠? 임계값들은 라이브 환경에서 모니터링하며 조금씩 조절하기로 하고 기능 구현은 여기에서 마무리했습니다.

구현 이후

생각하지 못한 케이스가 많았기 때문에 구현 이후에도 계속해서 로직을 보완해 나갔습니다. 실제 장애를 감지한 경우도 있었고, 엉뚱한 알람을 보내는 경우도 있었죠. 그리고 주문과 전혀 관계없는 문제를 찾기도 했습니다. 하지만 동료들의 지속적인 피드백으로 알람은 점점 더 신뢰할 수 있을 만큼 개선되었고 현재는 아주 유용하게 사용중입니다.

신뢰 구간을 확장하여 알람의 정확성을 높힘
DB 부하로 일어난 장애 감지
비슷한 방법으로 에러 모니터링
특별한 케이스긴 하지만 로그 롤링 문제 확인

마무리

API 문서가 잘 정리되어 있고 참고할 수 있는 글이나 레퍼런스가 많아서 큰 어려움 없이 작업을 완료했습니다. 특히 여러 가지 의견을 제시하고 함께 고민했던 동료들 덕분에 공부도 많이 되었고요.

처음엔 단순히 장애 모니터링을 하기 위해 개발을 시작했지만, 작업을 진행할수록 비즈니스를 성공시키기 위해선 어떤 관점에서 제품(서비스)과 기능(개발)을 연관 지어 볼 것인지를 생각하는 계기가 되었습니다.

제가 준비한 글은 여기까지입니다. 작업 난이도도 높지 않고 생각보다 유용한 모니터링을 구축할 수 있는 가성비 좋은 기능이니 한 번쯤 사용해 보시는 걸 추천해 드립니다.

긴 글 읽어주셔서 감사합니다.

실습

ELK 설치

ELK를 로컬에 생성합니다. 도커가 설치되지 않았다면 먼저 설치해주세요.

ELK on Docker 프로젝트를 클론합니다.

$ git clone <https://github.com/deviantony/docker-elk.git>

프로젝트 폴더로 이동해서 도커를 실행시킵니다.

$ cd docker-elk
$ docker-compose up

실행이 완료되었다면 브라우져를 열고 키바나로 접속합니다. 정상적으로 접속되는 걸 확인했다면 도커를 종료합니다.

# 초기 비밀번호
# username:elastic
# password:changeme

<http://localhost:5601>

Open Distro 플러그인 설치

현재 기준으로 Open Distro Alerting 최신 버전에 대응되는 엘라스틱서치 버전은 7.10.2 버전입니다. 앞서 클론한 프로젝트의 ELK 버전을 동일하게 맞춰줍니다. 만약 새롭게 대응되는 버전이 있다면 그것으로 설치하셔도 무방합니다.

elk-docker 폴더로 이동하여 아래와 같이 수정합니다.

$ vi /.env
ELK_VERSION=7.10.2

엘라스틱서치와 키바나에 Open Distro Alerting을 설치하기 위해 Dockerfile 을 수정합니다.

$ vi elasticsearch/Dockerfile
# Add your elasticsearch plugins setup here
# Example: RUN elasticsearch-plugin install analysis-icu
FROM docker.elastic.co/elasticsearch/elasticsearch:${ELK_VERSION}
RUN elasticsearch-plugin install https://d3g5vo6xdbdb9a.cloudfront.net/downloads/elasticsearch-plugins/opendistro-alerting/opendistro-alerting-1.13.0.0.zip

$ vi kibana/Dockerfile
# Add your kibana plugins setup here
# Example: RUN kibana-plugin install <name|url>
FROM docker.elastic.co/kibana/kibana:${ELK_VERSION}
RUN kibana-plugin install https://d3g5vo6xdbdb9a.cloudfront.net/downloads/kibana-plugins/opendistro-alerting/opendistroAlertingKibana-1.13.0.0.zip

X-Pack 관련 설정을 비활성화시킵니다.

$ vi elasticsearch/config/elasticsearch.yml
xpack.security.enabled: false
xpack.monitoring.collection.enabled: false

이미지를 새롭게 빌드해준뒤 다시 실행합니다.

$ docker-compose build
$ docker-compose down -v #볼륨까지 초기화(필요시)
$ docker-compose up

사이드메뉴에서 Alerting 플러그인이 설치된 것을 확인할 수 있습니다.

샘플 데이터 생성

메인화면에서 Try our sample data → eCommerce orders 순서로 이동하여 샘플 데이터를 생성합니다.

Alert 만들기

  1. Deistination

알람을 받을 수단을 선택합니다. 여기에선 슬랙을 사용하기 때문에 아래처럼 타입과 웹훅URL을 작성하겠습니다.

2. Monitor

Document를 조회하기 위한 쿼리 작성을 합니다.

먼저 Define monitor에서 Define using extraction query를 선택합니다. Index는 처음에 만들어 두었던 샘플 데이터(kibana_sample_data_ecommerce)를 사용하겠습니다.

아래와 같이 쿼리를 작성하고 RUN으로 결과를 확인합니다.
* 샘플 데이터가 많지 않기 때문에 fixed interval과 date range를 길게 설정했습니다.

{
"size": 0,
"query": {
"bool": {
"must": [],
"filter": [
{
"bool": {
"should": [
{
"match_phrase": {
"type": "order"
}
}
],
"minimum_should_match": 1
}
}
],
"should": [],
"must_not": []
}
},
"aggregations": {
"range": {
"date_range": {
"field": "order_date",
"ranges": [
{
"from": "now-10h",
"to": "now"
}
],
"keyed": false
},
"aggregations": {
"histogram": {
"date_histogram": {
"field": "order_date",
"time_zone": "Asia/Seoul",
"fixed_interval": "1h",
"offset": 0,
"order": {
"_key": "asc"
},
"keyed": false,
"min_doc_count": 0
},
"aggregations": {
"moving_average": {
"moving_fn": {
"buckets_path": "_count",
"script": {
"source": "MovingFunctions.unweightedAvg(values)",
"lang": "painless"
},
"gap_policy": "skip",
"window": 3,
"shift": 0
}
}
}
}
}
}
}
}

3. Trigger

해석이 필요한 부분은 주석을 달아놨습니다. 테스트가 끝나면 임계값은 상황에 맞게 조절하면 되고 monitoring_interval은 date histogram 주기와 동일하게 맞춰주면 됩니다.

def THRESHOLDS = 100;         // 임계값: 테스트를 위해 100퍼센트로 설정
def MONITORING_INTERVAL = 60; // date histogram의 간격: 부분데이터를 삭제하기 위함

def histogramBuckets = ctx.results[0].aggregations.range.buckets[0].histogram.buckets;
def index = histogramBuckets.length - 1;
def latestStat = histogramBuckets[index];

def startTimeOfLatestStat = Instant.ofEpochMilli(latestStat.key).atZone(ZoneId.of("UTC"));
def now = Instant.ofEpochMilli(new Date().getTime()).atZone(ZoneId.of("UTC"));
def isPartialData = startTimeOfLatestStat.plusMinutes(MONITORING_INTERVAL).isAfter(now);

if(isPartialData) latestStat = histogramBuckets[index-1]; // 현재 조회된 데이터에 부분데이터가 있을경우 lastIndex-1 요소를 사용

def orderCount = latestStat.doc_count != null ? latestStat.doc_count : 0;
def movingAverage = latestStat.moving_average.value != null ? latestStat.moving_average.value : 0;
def startTimeOfhistogram = Instant.ofEpochMilli(latestStat.key).atZone(ZoneId.of("Asia/Seoul"));

// 조기 반환 조건들
if(orderCount == 0) return true;
if(movingAverage == 0) return false;
if(orderCount >= movingAverage) return false;

// 예상 대비 주문의 퍼센트
def orderCountRatio = orderCount / movingAverage * 100;

// 메세지 템플릿에 사용할 변수 할당
ctx.results[0].thresholds = THRESHOLDS;
ctx.results[0].orderCount = orderCount;
ctx.results[0].orderCountRatio = Math.round(orderCountRatio);
ctx.results[0].movingAverage = Math.round(movingAverage);
ctx.results[0].startTimeAsString = startTimeOfhistogram.format(DateTimeFormatter.ofPattern("MM월 dd일 HH:mm:ss"));
ctx.results[0].endTimeAsString = startTimeOfhistogram.plusMinutes(MONITORING_INTERVAL).format(DateTimeFormatter.ofPattern("MM월 dd일 HH:mm:ss"));

return orderCountRatio < THRESHOLDS;

메세지 템플릿은 Mustache 문법을 사용합니다. {{ 변수이름 }} 형식으로 손쉽게 접근이 가능합니다.

측정 구간 : {{ctx.results.0.startTimeAsString }} ~ {{ctx.results.0.endTimeAsString}}
알림 조건 : {{ctx.results.0.thresholds}}% 미만
예상 주문 : {{ctx.results.0.movingAverage}} 건
실제 주문 : {{ctx.results.0.orderCount}} 건
{{#ctx.results.0.orderCountRatio}}
주문 비율 : {{ctx.results.0.orderCountRatio}}%
{{/ctx.results.0.orderCountRatio}}

테스트 했을때 아래와 같이 메세지가 나온다면 성공입니다. 이제부턴 입맛에 맞게 적절하게 코드와 템플릿을 수정해 주시면 됩니다.

고생하셨습니다🎉

함께 성장할 동료를 찾습니다

29CM (무신사) 는 3년 연속 거래액 2배의 성장을 이루었습니다.

이제 더 큰 성장을 위해 기존 모놀리틱 서비스 구조를 마이크로서비스 구조로 전환하고, 앵귤러 기반 프론트엔드 코드를 리엑트로 전환하는 등의 기술적인 시도를 진행하고 있습니다.

함께 성장하고 유저 가치를 만들어낼 동료 개발자분들을 찾습니다
많은 지원 부탁합니다!

🚀 29CM 채용 페이지 : https://www.29cmcareers.co.kr/

--

--