2022.11
## 회고
토요일 아침에 비몽사몽 일어났는데 슬랙 알림에서 얼핏 502가 발생한다는 메시지가 보였다. 여전히 눈은 반쯤 감은 상태였지만 최대한 빠르게 노트북을 켜고 온콜 개발자가 있는 디스코드에 들어갔다. 아미 많은 사람들이 모여있었고 데이터베이스는 한 번 죽었다가 failover된 상태였다.
장애 타임라인을 들어보니, 웹서버 ECS task의 CPU가 높아져서 자동으로 스케일아웃이 되었는데도 CPU 부하가 없어지지 않아 스케일아웃이 반복되었고 결국 데이터베이스에 너무 많은 커넥션이 연결되어 죽은 것이었다. 갑자기 웹서버에 CPU 부하가 높아진 원인을 찾기 어려웠지만 한 가지 의심되는 점은 이 날 사용한 인공지능 감독 기능이었다. 인공지능 감독은 S3에 업로드되는 녹화 파일에서 이상이 감지되면 웹서버에 HTTP로 이상 징후 정보를 보내고, 웹서버는 감독실에 있는 사용자에게 웹소켓으로 해당 정보를 전달하는 프로세스이다. 그래서 일단 인공지능 감독 서버를 종료했더니 CPU가 높아지는 현상이 재발하지 않았다.
상황이 어느정도 정리되어서 제대로 원인을 파악해보려고 했는데 이상한 점이 보였다. 웹서버가 자동으로 스케일아웃이 되었을 때 평균 CPU과 최소 CPU는 줄어들었는데 최대 CPU는 계속 100%로 유지되고 있었다. CloudWatch container insight로 보니 task 4대는 CPU가 아주 높았고 나머지는 낮은 상태였다. 일부 task의 CPU만 높은 현상에 대해서 의견이 분분했는데 평일 업무 시간에 자세한 원인을 찾아보기로 하고 마무리했다.
월요일이 되었지만 여전히 원인은 오리무중이었다. 시험 당일에 의심을 받은 인공지능 감독의 경우에는, 웹서버에 부하를 줄 만한 작업이 아니기도 하고 이전에 사용할 때는 이상이 없었어서 용의선상에서 빠졌다. DDoS를 잠깐 의심하기도 했지만 일부 task만 CPU가 높아지는 것이 불가능하다고 보여서 기각되었다. 또한 어떤 개발자가 task에 접속해서 무거운 작업을 돌린 것이 아닌가 하는 의견도 있었지만 해당 시간에 접근 기록이 전혀 없어서 역시 기각되었다. 그나마 가장 유력한 용의자는 ECS 관련 인프라 설정이었는데, 웹서버를 EC2에서 ECS로 옮긴지 얼마 안 됐을 때여서 설정에 무언가 실수가 있을 것이라는 의견이었다. 이 의견이 맞다고 생각하는 사람들은 ECS 설정을 살펴보기로 했고 나는 다른 원인을 찾아보기로 했다.
나는 무작정 원인을 찾는 것은 불가능에 가깝다고 생각해서 귀납적으로 원인을 찾아보려고 했었다. 그래서 먼저 CPU가 높았던 task들의 로그를 찾아보려고 다시 해당 task를 찾아보았는데, 이미 CloudWatch container insight 기록의 보관기간이 끝나서 아무런 흔적도 찾을 수 없었다. AWS에 기록을 살려달라고 읍소해볼까하는 생각이 잠깐 스쳐지나갔지만, 곧 내가 장애 당일에 CPU가 높은 task의 id를 복사했었다는 사실을 기억해내고 클립보드 히스토리에서 task id를 찾을 수 있었다. 그러나 해당 task의 로그를 찾아보아도 특이한 점이 보이지 않았다.
그래서 다시 연역적 방법으로 돌아가서 지금까지 나온 가설들을 다시 검토해보았다. 다른 원인들은 ECS task 중 일부만 CPU가 높아지는 것과 스케일아웃을 해도 CPU 부하가 유지되는 이유를 설명하지 못했는데, 인공지능 감독 기능에서는 가능한 장애 시나리오가 보였다. 웹소켓은 연결을 유지하고 있기 때문에 웹서버가 스케일아웃되어도 커넥션이 유지되기 때문에 만약 일부 서버에 웹소켓 연결이 집중된다면 장애가 발생할 수 있었다. 그 다음부터는 일부 웹서버에만 웹소켓 연결이 집중된 이유를 찾아보았는데 비교적 쉽게 알아낼 수 있었다. 시험 응시자 숫자에 맞추어서 시험 한 시간 전부터 서버가 늘어나도록 자동화되어있었는데, 감독관들이 시험 한 시간 전보다 더 일찍 접속했다는 사실을 시험 운영 일지에서 확인했다.
이 가설을 증명하기 위해 웹소켓 로그를 찾아봐서 CPU가 높은 task의 웹소켓 전송 로그가 다른 task들의 그것에 비해 월등히 많았다는 사실을 알아냈다. 웹소켓 전송 로그가 30초에 백만 건 정도 였으니 task 한대가 1초에 3만 건 넘게 전송한 셈이었다. 여기서 웹소켓이 원인이라는 것을 99% 확신했지만 좀 더 확실히 하기 위해 스테이징 환경에서 장애를 재현해보기로 했다.
먼저 웹서버 1대를 띄워놓은 상태에서 감독관 사용자가 감독실에 접속해서 웹소켓에 연결했다. 그런 다음 웹서버를 10대로 늘리고 웹소켓으로 인공지능 감지 데이터를 계속 전송했다. 그러자 장애 당시 메트릭과 유사한 형태로 웹서버 1대만 CPU가 높아지고 나머지는 CPU가 낮았다. 이렇게 하여 웹소켓 연결이 집중된 것이 장애의 원인아라는 것을 증명할 수 있었다.
원래는 데이터베이스가 죽을 정도로 큰 장애는 원인을 찾기 쉽다고 생각하고 있었는데 이번에 생각이 바뀌었다. 힘들게 원인을 찾았으니 반드시 개선해서 다시는 같은 장애가 발생하지 않도록 할 것이다.