이번주 목요일에 있었던 장애로 업무일기(?) 를 남긴다.
어찌보면 너무나 당연한 Title이다. 장애가 발생했으니 가장 최초 원인이 된 트리거를 찾아야한다.
마이크로 서비스 환경이 깔끔하게 분리가 되어있고, 각 fail 이 발생했을 때 대비가 잘 되어있으면 좋겠지만 그렇지 못한 상황이거나 큰 규모의 장애가 발생했을 때는, 여기 저기서 알림이 오고 메트릭들도 여기 저기서 이상 징후를 보여준다.
이번 주 목요일이었다. 사무실이 갑자기 웅성웅성 하길래 이어폰을 뺐더니 각 중요 고객사들 앱에서 전부 광고 할당이 안되는 상황이라고 한다. 슬랙을 봤더니 여기저기서 얼럿이 울리고 장애가 선포되어있다. 두 개의 서버는 파드들이 다운되고, DB 커넥션이나 로드가 걸려서 다양한 API 에서 에러가 발생하고 있었다.
알림 오는 채널도 다양하고, API나 서버들도 여러 곳에서 문제가 발생하고 있으니 최초 이상 현상을 보이는 API를 DataDog 에서 찾았다. 그리고 해당 API 에서 최초로 발생하는 에러 trace를 찾았다.
해당 API에서 발생하는 query 에서 DB 장애를 유발했겠구나 싶어 해당 API에서 사용하는 DB의 Performance insights 를 확인했다.
트리거
wait/io/table/sql/handler 와 Lock wait가 걸린게 보인다.
모든 query를 보여주는건아니고 샘플링 되는 query를 보여주지만 특정 테이블에, 동일한 레코드에만 update가 발생하는걸 확인할 수 있었다.
CREATE TABLE `abc` (
`id` int unsigned NOT NULL AUTO_INCREMENT,
`col1` bigint NOT NULL,
`col2` varchar(255) NOT NULL,
`col3` varchar(100) NOT NULL,
...
PRIMARY KEY (`id`),
UNIQUE KEY `UNIQ_col2_col1` (`col2`,`col1`),
UNIQUE KEY `UNIQ_col3_col1` (`col3`,`col1`)
) ENGINE=InnoDB AUTO_INCREMENT=123123123 DEFAULT CHARSET=utf8mb3;해당 테이블에 update 요청인데 각 요청별로 unique 한 값으로 들어와야할 요청이 SAMPLE.. 이라는 비정상적인 동일 값으로 모든 요청이 들어오고 있었다.
특별히 요청이 평소에 비해 많이 들어온 것은 아니지만 unique 값으로 개별 record에 update 되어야할 query들이 하나의 record에 update가 집중되면서 문제가 발생했다.
외부 고객사의 연동 실수로 보여서 우선 해당 고객사 요청을 처리하지 않도록 처리하면서 담당자 분께 해당 고객사에 확인 요청을 드려놨다.
대응 끝난 이후에 slow query log도 한번 봤는데 해당 쿼리로 인한 문제임을 다시 한번 확인할 수 있었다.
대응
상황이 급박해서 우선 Controller에서 if 문으로 해당 요청에 500으로 처리하지 않도록 배포했다. SLA 기준을 6분 남겨두고 정상화되었다. 고객사들에 손해배상 지급을 해야했던 상황을 6분을 남겨두고 피할 수 있었다.
개선
rate limit
외부 연동 실수로 인한 동일 레코드에 update 요청이 DB 까지 발생하지 않도록 sliding window 방식의 rate limit을 적용했다. 배포 후 이번 장애와는 별개로 의도치 않은 side effect 이 발생했는데, 이건 별도로 다뤄보겠다.
table
# table, column 명을 임의로 변경하였음
CREATE TABLE `abcde` (
`id` int(11) NOT NULL AUTO_INCREMENT,
`something_a` varchar(255) NOT NULL,
`something_b` varchar(100) NOT NULL,
`something_b` bigint(20) NOT NULL,
...
PRIMARY KEY (`id`),
UNIQUE KEY `device_unit_device_token_731a8f96_uniq` (`something_a`,`something_c`),
UNIQUE KEY `device_ifa_91f9270e_uniq` (`something_b`,`something_c`)
) ENGINE=InnoDB AUTO_INCREMENT=274633169 DEFAULT CHARSET=utf8- 동일한 row에 update 요청이 발생하여 Lock 경합이 발생하고, 인덱스도 두개가 걸려있으나 데이터 사이즈도 작지 않다보니 부하 및 장애가 유발되었다.
장애를 유발했던 쿼리의 explain 실행 시,something_a가 키로 잡히고utf8mb3이다보니key_len이 765로 잡혀있다. 실제 데이터들 조사해보면, 비정상적인 문자열들 값만 utf8이 필요하고 정상적인 값들은ascii값으로 들어온다.key_len을 510으로 줄일 수 있다. 사실 something_b는 별도 테이블로 분리하고 해당 id 를 mapping하도록 개선이 필요하다.
- utf8 값 들어오는 비정상 트래픽의 valdiation 로직 추가가 필요하다.
something_b의 경우 something_b 의 경우에는varchar가 아닌char사용
