elasticsearch 이슈 대응 (1)

2019-10-24 23:34:08

사건의 개요

19년 10월 24일 오후 즈음…
언제나 그렇듯이 바쁜 일상 속에서 업무 중요도에 따라 잠시 미뤄뒀던 task 로 인해 ~~오늘도~~ 작은 이슈가 발생하였다.

아래 이미지와 같이 elasticsearch 에서 로그가 쌓이지 않는 이슈가 발생하였고 그에 따라 업무에 필요한 로그 확인이 어려운 상황이었다. ~~심지어 로그가 쌓이지 않고 있다는 것도 너무 늦게 알았네~~

로그 수집에 대한 flow 는 어렵지 않으므로 kafka 와 elasticsearch 사이에서 이슈 구간이 어디인지 알 수만 있다면, 문제 해결 자체는 어렵지 않을 것이라 생각하고 ~~늦게나마~~ 확인 작업을 시작하였다.

logback -> kafka 구간 확인

우선 was 의 logback 에서 kafka 로의 메시지 전달에 문제가 없는지 확인하기 위해, kafka 의 kafka-console-producer.sh 을 실행하여 로그용 topic 에 메시지가 쌓이고 있는지를 확인하였다.

1
2
3

$ /usr/local/kafka/kafka-console-consumer.sh 
--bootstrap-server kafka-server1:9092,kafka-server2:9092,kafka-server3:9092 \
--topic log-v1

--from-beginning 옵션을 제거하면 kafka-console-consumer.sh 실행 이후의 시점부터 전달되는 메시지를 console 에 출력하게 된다.

실행결과 was 의 logback -> kafka 구간에서는 이슈 없이 메시지 전달이 정상적으로 이루어지고 있는 것을 확인하였다.

kafka -> logstash 구간 확인

다음으로 kafka 에서 logstash 구간을 확인하였다. kafka 자체의 동작에는 이슈가 없음을 확인하였기에, logstash 의 process 상태와 로그를 통하여 logstash 의 정상 동작 여부를 확인하고자 하였다.
logstash 의 로그 위치는 /etc/logstash/logstash.yml 에서의 path.logs 에 따라 /var/log/logstash 에 남고 있었고, 이를 tail -f 하여 실시간으로 로그를 확인하였다.

1 2	$ cat /etc/logstash/logstash.yml \| grep path.logs $ tail -f /var/log/logstash/logstash-plain.log

그 때의 로그 상황은 다음과 같다.

FORBIDDEN 이라는 ~~기분 나쁜~~ 문구와 함께 뭔가의 에러로그가 찍히고 있음을 확인하였다.

해당 문구를 구글링했을 때 비교적 많은 검색 결과를 얻을 수 있었고, 이슈 발생 원인은 elasticsearch 가 사용하는 disk space 가 부족할 때 elasticsearch 의 down 을 막기 위해서, 문제 시점 이후로는 index 의 읽기와 삭제만 허용하도록 자동적으로 설정이 바뀌기 때문임을 알게 되었다 (elasticsearch 에서 해당 설정값은 read_only_allow_delete=true 이다)

정리하면

elasticsearch 의 저장공간이 부족한 상황에서 추가적인 저장을 실행하면 elasticsearch 를 포함한 서버의 모든 프로세스가 영향을 받을 수 있기 때문에
elasticsearch 가 자체적으로 저장 operation 을 차단시키는 설정으로 변경되었고
이 후 kafka 에서 메시지를 읽어서 elasticsearch 에 저장하고자 했던 logstash 쪽에서 에러가 발생하는 것이었다.

이 때, 필자는 elasticsearch 가 되게 스마트하다는 것에 감탄했었고, 이는 마치 MSA 에서 과도한 트래픽으로 인해 시스템이 다운되기전에 트래픽을 차단시키는 circuit breaker 와 맥락이 비슷하다는 것을 느꼈다.

더 상세한 설명은 다음의 링크를 참고한다

어쨌든 문제 상황의 원인은 알았으니 빠르게 해결하는 일만 남았다.

해결!

단기 해결책

elasticsearch 의 용량이 부족한 상황을 알았으니 우선 용량을 확보하는 것이 급선무였다.

이를 위해

elasticsearch 에서 오래된 index 삭제
elasticsearch 의 설정값 read_only_allow_delete 를 false 로 변경

을 진행하였고, read_only_allow_delete 를 false 로 바꾸자마자 로그가 다시 들어오는 것을 확인하였다.

read_only_allow_delete 를 false 로 바꿀 때에는 kibana 의 Dev_tools 메뉴를 이용하면 편리하다.

read_only_allow_delete=false 를 실행하는 즉시 logstash 를 통하여 elasticsearch 에 데이터가 저장되기 시작한다.

logstash 에서 elasticsearch 로의 output 이 성공하기 시작

순식간에 로그가 복구됨

보통 elasticsearch 에 데이터를 저장할 때는 timestamp 를 기본 값으로 포함시키고, index 도 날짜를 기준으로 생성하는 것을 권장한다. 날짜별로 index 를 생성한다면 특정 기간이 지난 index 를 찾아서 삭제하기 쉽고, 날짜별 index 의 크기 및 특징을 확인하기에 편리한 장점이 있기 때문이다.

또한, kibana 를 통해 로그를 검색할 때에는 topic-* 같은 패턴으로 kibana index pattern 을 생성하면 날짜와 상관없이 topic 별로 데이터 검색도 가능하다. (즉, elasticsearch 의 index 저장 시에 날짜별로 구분해도 문제가 없다는 뜻이다)

참고로 필자가 근무하는 시스템의 logstash 에서는 elasticsearch 에 데이터를 저장할 때 아래와 같은 설정으로 저장하고 있다. -%{+YYYY.MM.dd}" 를 선언하여 날짜별로 index 를 생성하는 것을 확인할 수 있다.

-- 설정 일부 
output {
  elasticsearch {
       hosts => ["elasticsearch1","elasticsearch2","elasticsearch3","elasticsearch4"]
       index => "%{es_index}-%{+YYYY.MM.dd}"
       manage_template => false
     }
}

근본 해결책

근본적인 해결 방법은 elasticsearch 의 disk space 가 부족한 상황이 되지 않도록 환경을 만드는 것이다.

이를 위해

elasticsearch 가 사용하기에 충분한 disk space 를 할당하고
주기적으로 오래된 index 를 제거하는 것
disk 와 같은 리소스 부족 시 자동으로 notification 이루어지는 체계 구축

이 필요하다.

1번의 경우, elasticsearch.yml 의 path.data 와 path.logs 를 변경한 후에 elasticsearch cluster 를 재시작하면 데이터 및 로그 저장 경로를 변경할 수 있다. 자세한 처리 방법은 다음의 링크를 참고한다 (elasticsearch data 및 log 저장경로 변경)

2번의 경우, kibana 의 메뉴에서 management > Index Lifecycle Policies 에서 특정 topic 에 대한 삭제 주기를 설정하면, 삭제 없이 index 가 무한정으로 증가하는 것을 막을 수 있다.

아래 이미지는 kibana 의 Index Lifecycle Policies 의 상세 화면의 일부이다. Maximum index size 와 Maximum age 등을 통해서 용량별 / 기간별로 index 삭제 주기를 설정할 수 있다.

3번의 경우, 서비스가 동작하는 서버와 서비스에 대한 메트릭을 수집하는 다양한 방법이 존재하므로, 현재의 상황에 맞게 찾아서 적용하면 될 것이다. 핵심은 문제 상황 시 이를 자동으로 notification 하는 시스템을 구축하는 것이 중요하다는 것이다. (~~집중해서 개발도 해야 하잖아~~)