[Error #2] 연말은 에러와 함께~ (Rabbit MQ)

 

---

모니터링이 필요한 곳이 있다면
모니터링 방안을 구상하자

---

 

---

약 6개월 만의 작성해보는 게시글이네요. 벌써 입사 1년이 되어간다니 감회가 새로운데요...ㅎㅎ
소중히 아껴온 2022년 마지막 연차가 에러와 함께 불타오르는 것을 보니 서버 개발자가 된 것이 실감이 났습니다 (*ˊᵕˋ*)ﾉ
사실 1년차가 되면 일정량 업무가 반복 업무처럼 되어갈 줄 알았는데 매일매일이 새롭네요. 이 쯤 되니 경이롭습니다.
(하지만 거의 12시간 동안 서버 장애가 해결 안된 건 너무 새로운 이벤트가 아닌지...)

---

목차

1. 발생한 오류

2. 자세한 타임라인 (장애 인지부터 장애 대응 완료까지)

3. 장애 인지 및 대응 개선

4. 결론

---

▶ 발생한 오류

이번에 마주하게된 에러는 Rabbit MQ 과부하 (DISK FULL) 입니다.
챌린지 2차 프로젝트를 진행하며 동료와 함께 설계를 일부 변경한 부분이 문제가 되었습니다.
콘텐츠 재생 서비스와 Rabbit MQ 가 맞닿아 있어 결국 서버 자체에 영향이 갔고,
이로인해 모든 서비스가 불능 상태가 된 사건입니다. (MQ 문제와 별개로 인프라 구성에도 문제가 있는 것 같은...)

▶ 타임라인

[!] 유저 별로 콘텐츠 재생 시 30초 또는 1분 마다 재생 기록 API 가 호출되며,
유저의 콘텐츠 누적 재생 시간에 따라 주마다 Weekly 챌린지를 달성 처리 한다.

1. [2022-12-xx 챌린지 구현 중] 이 때, 체크포인트 변곡점에서만 이벤트를 발생시키던 A 방식에서 체크포인트 이후에 이벤트가 달성 처리되어 있지 않으면 이벤트를 계속 발생시키는 B 방식으로 변경

• Why? - A 방식의 경우 변곡점 이벤트가 누락되면 영원히 달성 처리가 누락되기에 B 방식으로 챌린지 달성을 보장하고자 함
• C 방식 (후보) - 체크포인트 변곡점 ± 5분 오차 허용

2. [2022-12-xx 챌린지 구현 중] 하지만 기획상 Weekly 챌린지는 그 다음주부터 시작되는 챌린지 -> 챌린지 오픈 전까지는 계속 미달성 상태
3. [2022-12-23 금요일 오전 11시 경] 이 상태에서 해당 기능 서버 배포
4. [2022-12-26 월요일 오후 6시 경] 이로인해 지속적으로 이벤트 발생 -> Rabbit MQ 큐에 과도한 메세지가 쌓이면서 DISK Full
5. [2022-12-26 월요일 오후 6시 경] 서버에서는 Celery 를 통해 이벤트 메세지를 Rabbit MQ 에 넣는 요청을 넣음 -> 현재 큐에 메세지를 넣을 수 없는 상태 -> (추측) 큐에 메세지를 넣기 위해 대기 상태 -> OSError / 502 Timeout -> 모든 서비스 접근 불가 / 불능 상태
6. [2022-12-26 월요일 오후 6시 경] 백엔드 개발자 4명 모두 당일 연차 -> Sentry 오류로 장애 인지했으나 원인 불명 -> 인프라 의심 (리더 개발자님 대응 중)
7. [2022-12-26 월요일 오후 8시 경] 서비스 여전히 접근 불가 / 집 도착
8. [2022-12-26 월요일 오후 11시 경] Rabbit MQ 에 대한 의심 -> 하지만 재택에서 모니터링 페이지 접근 불가 / EC2 인스턴스 자체에는 이상 無 -> 크게 의심하지 않고 다른 원인 물색 / 배포 자체는 3일 전 금요일에 진행했기에 챌린지에 문제 있을 거라고 생각 못 함
9. [2022-12-26 화요일 오전 6시 경] 임시 조치를 통한 서비스 정상화 + 금요일 배포한 챌린지에 문제가 있는 것 같다는 공지 (=리더 개발자님)

10. [2022-12-26 화요일 오전 7시 경] 공지 확인 -> 깨달음 -> 원인 파악 -> 동료에게 수정 요청 -> 보고
11. [2022-12-26 화요일 오전 9시 경] 출근 -> Rabbit MQ 모니터링 페이지 확인 -> 원인 확실시 -> 보고 -> 대응

약 1800만 개의 메세지가 쌓여 있다 (약 32G - DISK Full)

메세지 생성 속도가 소비 속도보다 월등히 높은 상태 (3일째 터져버린 시한 폭탄)

12. [2022-12-26 화요일 오전 9시 반 경] 모니터링 페이지에서 미러링 중단 버튼 클릭 -> 페이지 down -> MQ EC2 인스턴스 (master, slave) 중단 후 재실행 -> slave 클러스터 노드 죽어 있음 + master 클러스터 노드는 살아 있으나 큐에 durable 속성 적용되어 디스크에 저장된 메세지 복구 중 -> 또다시 Disk Full 상태를 향해 달려가는 중

약 40G 중 4.9 메가 남은 상태 -> 점점 줄어든다 (지옥의 카운트다운)

13. [2022-12-26 화요일 오전 10시 반 경] EC2 인스턴스 터미널 접속 -> 구글링 -> 메세지 데이터 삭제 방법 알아냄 -> master, slave queue 내의 .idx 파일 삭제 (각 28G+)

• https://www.rabbitmq.com/backup.html

메시지 데이터는 위에서 언급한 노드의 데이터 디렉토리 에 저장됩니다.

3.7.0부터 시작하는 RabbitMQ 버전에서 모든 메시지 데이터는 msg_stores/vhosts 디렉터리에 결합되고 가상 호스트당 하위 디렉터리에 저장됩니다. 각 가상 호스트 디렉토리는 해시로 이름이 지정되고 가상 호스트 이름이 있는 .vhost 파일을 포함하므로 특정 가상 호스트의 메시지 세트를 별도로 백업할 수 있습니다.

3.7.0 이전의 RabbitMQ 버전에서 메시지는 노드 데이터 디렉터리 아래의 여러 디렉터리( queues , msg_store_persistent 및 msg_store_transient )에 저장 됩니다. 또한 노드가 정상적으로 중지된 경우 복구 메타데이터를 포함 하는 recovery.dets 파일이 있습니다.

14. [2022-12-26 화요일 오후 2시 경] Slave 클러스터 노드 여전히 죽어 있음 (disk 데이터는 모두 정리된 상태) -> 구글링 -> 몇 가지 복구 방법 알아냄 -> 실행

목표 : node 살려내기

1. https://serverfault.com/questions/783607/rabbitmq-epmd-reports-node-rabbit-not-running-at-all
2. https://seungdols.tistory.com/762

rabbitmq 서버 터트리고 살리기 (akka. file discriptor가 문제다.)

방법 1. 효과 없음

So after removing sudo rm -rf /var/log/rabbitmq/* , I started sudo service rabbitmq-server start and rabbitmqctl start_app. It worked, thanks!

방법 2. 효과 있음

그러던 중 rabbitmq-server fails to start on Red Hat Openstack Platform 7 의 문서에서 Resolution 을 따라보기로...
rm -rf /var/lib/rabbitmq/mnesia/*, systemctl start rabbitmq-server...

15. [2022-12-26 화요일 오후 3시 경] 노드 재설정 하였으나 서버와 연결되지 않음 -> 리더 개발자님이 추가 조사 -> 이 과정에서 master cluster 노드도 재설정되어 버려서 slave cluster 만 살려서 연결 / 복구 -> sentry alert 드디어 더이상 안옴
16. [2022-12-26 화요일 오후 4시 경] 큐 정상화 / Celery worker 다시 활성화
17. [2022-12-26 화요일 오후 4시 경] 뒷 수습 중... (날아간 메세지 관련 후속 처리, 마이그레이션 일부 진행) / 프로덕트팀에 상황 공유
18. [2022-12-26 화요일 오후 6시 경] 퇴근

---

 

▶ 장애 인지 및 대응 개선

 

[1] Rabbit MQ 에 대한 모니터링 미흡 → 경보 시스템이 필요하다

• Rabbit MQ - celery queue 에 메세지가 과도하게 쌓이면서 disk full 상태에 이르렀지만, EC2 인스턴스 및 Celery Worker 상태는 초록불.
  • Rabbit MQ 모니터링 페이지 보면 큐에 이상이 있는게 확실한데 왜 EC2 인스턴스, Celery worker 는 계속 초록불이었는지 의아하다.
• 큐 상태에 대한 경보 시스템이 필요하다.

 

2022년 12월 26일 월요일

- 14:25 - QA 팀 → 챌린지 미달성 현상 제보

월요일 오후 5시 50분 경 전으로 QA 팀에서 챌린지 이상 현상을 캐치하였으나 당일 연차로 확인하지 못함

• QA 티켓 주셨을 때 Rabbit MQ 페이지 확인했다면 전체 서비스 장애까지는 안 가도록 조치 가능했을지도…

 

[2] 모니터링 페이지 관련해서는 재택에서도 접근 가능하도록 환경 미리 세팅 필요

[3] 터미널을 통해 EC2 인스턴스에 접근, 로그 확인 / 파일 CRUD 등 기본 명령어 연습 필요

• 12/27 (화) 장애 대응 시, 다른 동료한테 EC2 터미널 접속 방법 강의 받음

 

장애 대응 시 고민되었던 지점 = 대응 시 병목 지점이 된 심리 상태
[4] 장애 상황에서는 빠른 결단이 필요하다 (선 조치 후 보고 방식을 고려하자)

• 버튼을 함부로 누르지 말자 <-> 뭐라도 해보자
  
  • 결국 MQ 모니터링 페이지의 미러링 중지 버튼을 눌렀는데 바로 페이지 다운됨 (EC2 인스턴스 재실행으로 페이지 일단 살림;;;;) - 그리고 이렇게 slave cluster 의 node 가 죽었다. (=not running)
• disk 를 살리기 위한 disk 내 메세지 삭제 명령어를 실행시키는 과정에서 1시간 병목
  • 삭제해도 되는가? 되지 않을까? (챌린지 프로젝트와 무관한 동료와 상의 30분....) - 터미널 명령어만 확인 부탁.. 문제가 생기면 범인은 나인 걸로 해... - 일단 GO - disk 문제는 해결됨
  • 어차피 즉시 판단을 내릴 수 있는 사람이 나밖에 없었다는 점에서 좀 더 빠르게 결단을 내리고 실행했으면 좋았을 것 같다. 어떻게 회사에 리더가 아무도 없어... (휴가간 챌린지 프로젝트 동료와 리더 개발자님을 슬랙에서 소환해서 논의할 수도 있었겠지만... 그러면 이렇게 판단하게 된 배경부터 근거, 이유 + 답변 기다리는 시간까지 한 3시간은 걸리지 않았을까 / 아닌가 전화라도 해서 상의해보는게 나았을까? 리더 개발자님도 celery, mq 쪽은 안 다루셔서 주석처리로 새벽에 서비스만 살려두고 휴가 가버리셨는데 ㅎㅎㅠ?)
    • 다음날 리더 개발자님이 장애 상황에서는 선 조치 후 보고 해도 된다고 말씀하셨다.
    • 다음날 휴가간 챌린지 프로젝트 동료가 차라리 EC2 볼륨을 높여보는게 낫지 않았겠냐는 의견을 냈다. (disk 용량을 높이면 추가 비용 청구되지 않나. 이 방식은 리더 개발자님의 허가가 필요했을 듯.) 비용이 드는 결정은 판단이 어렵다.
      
• slave cluster 의 node 를 살리기 위한 명령어 (특정 로그 파일 삭제, 특정 경로 파일 삭제) 를 실행시키는 과정에서 2시간 병목
  • 위와 동일. 삭제해도 되는가? 되지 않을까? (동료와 상의...를 시도했으나 결제 관련 이슈로 떠나버려서 혼자 남음) - 삭제 명령어가 잘못되었을 때의 상황 시뮬레이션 상상 1시간... 근데 어차피 node 죽어있어서 아무것도 못하느니 뭐라도 해보는게... - 삭제할 파일 복제해두고 일단 GO - node 는 정상적으로 재설정 됨
  • 어차피... 모두 바쁘다면... 선 조치 후 보고 해도 되었을 것 같다. 그래도 node 재설정 후 서버와 연결 작업은 슬랙에 다시 나타난 리더 개발자님이 조치해주셨다.
    • 어떻게 하신건지 매우 궁금하다. 1월 첫째 주에 장애 리뷰할 때 여쭤보자.

 

▶ 결론

모니터링 자동화 - 경보 시스템 필요 (근데 왜 celery, mq 부분은 제 담당이 되어 있는거죠?)
경보 시스템 어떻게 추가할 수 있을까 - 고민 필요
챌린지 관련 고객 문의는 마음이 아프다 - 후속 조치 리스트업 필요

[+] MEMO
가용성을 높이는 조치가 덫이 되다
디스크에 저장된 메세지 어떻게 비우지에 대한 고민도 하나의 병목 지점