게시 직후 크래시하는 앱을 잡아내기

9월 25일, 세 번의 게시가 성공으로 표시되었지만 앱의 API는 부팅할 때마다 몇 초 만에 크래시하고 있었습니다. 게시가 "성공"했으므로 롤백이 실행되지 않았고, 몇 분 뒤 백그라운드 점검이 이들을 실패로 처리하면서 사이트 전체가 404가 되었습니다. 헬스 체크는 호스팅 플랫폼의 이벤트 목록에서 크래시를 세고 있었는데, 이 목록은 머신마다 마지막 다섯 개 이벤트만 보관합니다. 크래시가 반복되면 목록이 계속 가득 차 있어서 개수가 늘어나지 않았습니다. 이제 헬스 체크는 가장 최근 크래시의 시각을 비교하며, 크래시가 반복되는 게시는 실패하고 이전 버전을 복원합니다.

게시가 기다리는 것

백엔드가 있는 앱을 Mythex에 게시하면, 새 버전이 호스팅 플랫폼의 머신에 올라가고, 헬스 체크가 게시가 라이브가 되었는지 실패했는지 결정합니다. 실패하면 롤백이 이전 버전을 되돌립니다.

어려운 점은 "시작됨"과 "서비스 중"이 같지 않다는 것입니다. 플랫폼은 머신이 올라오자마자 시작됨으로 보고합니다. 부팅 후 1초 만에 크래시하는 앱은 즉시 재시작되고, 잠시 뒤에 다시 시작됨으로 보입니다. 그래서 헬스 체크에는 시간이 지나면서 몇 겹의 검사가 쌓였습니다.

1. 두 번 확인합니다. 머신이 시작됨으로 보이면 잠시 기다렸다가 다시 확인합니다. 부팅 시 크래시는 두 번째 확인에서 자주 드러납니다.
2. 크래시 반복을 감시합니다. 플랫폼이 머신이 계속 크래시해서 재시작을 포기했다고 보고하면 실패 처리합니다.
3. 게시가 시작된 이후의 크래시를 셉니다. 두 번의 "시작됨" 확인 사이에 재시작이 끼어들 수 있습니다. 그래서 이 게시가 시작된 이후 크래시가 하나라도 있었다면 세 번째로 확인합니다. 세 번째 확인에서 크래시가 두 번째 확인 때보다 많으면 앱이 계속 실행되지 못하고 있는 것입니다.

이번에 실패한 것은 세 번째 검사입니다.

개수가 계속 같았던 이유

크래시 정보는 각 머신의 이벤트 목록에서 옵니다. 시작, 종료, 재시작 같은 이벤트입니다. 플랫폼은 머신마다 마지막 다섯 개 이벤트만 보관합니다.

9월 25일 실제로 있었던 것처럼, 부팅 후 2.5초 만에 매번 크래시하는 앱을 생각해 보세요. 주기마다 크래시 하나와 시작 하나가 추가됩니다. 몇 번 주기가 돌면 목록이 가득 찹니다. 그 뒤로는 새 이벤트가 하나 들어올 때마다 오래된 이벤트 하나가 밀려 나갑니다. 목록은 앞으로 흘러가지만, 항상 비슷한 구성을 유지합니다. 크래시 두어 개와 시작 두어 개입니다.

그래서 "게시가 시작된 이후 크래시가 몇 번인가"는 매번 확인할 때마다 같은 숫자를 반환했습니다. 두 번째 확인은 크래시가 두 번 있었다고 보았고, 세 번째 확인도 두 번이라고 보았습니다. 다른 크래시이긴 했지만 개수는 같았습니다. 검사는 크래시가 멈췄다고 결론 내렸고, 게시를 통과시켰습니다.

9월 25일 두 앱에서 이런 일이 세 번 있었습니다. 매번 다음과 같았습니다.

• 게시는 라이브로 표시되었습니다.
• 아무것도 실패하지 않았으므로 롤백이 실행되지 않았습니다.
• 사후에 배포를 점검하는 백그라운드 작업인 조정기(reconciler)가 몇 분 뒤 배포를 실패로 처리했습니다.
• 사이트 전체가 404를 반환했습니다.

제때 실패하는 게시는 복구할 수 있습니다. 롤백이 이전 버전을 복원하기 때문입니다. 하지만 성공으로 선언된 뒤 몇 분 뒤에 실패하는 게시는 이미 롤백을 건너뛴 것입니다.

원인을 찾은 과정

로컬에서 재현했습니다. 정상 동작하는 API를 가져다가 잠들게 한 뒤, 부팅할 때 크래시하는 변경으로 재게시했습니다. 헬스 체크는 라이브로 표시했습니다.

이는 운영 환경과 같았습니다. 세 번의 게시 모두에서 앱은 부팅 후 몇 초 만에 죽었지만, 비교 대상이었던 크래시 개수는 확인과 확인 사이에 증가하지 않았습니다.

해결책: 개수가 아니라 가장 최근 크래시를 비교

이제 헬스 체크는 크래시 개수를 세지 않고, 게시가 시작된 이후 가장 최근 크래시의 시각을 봅니다.

두 번째 확인에서 게시가 시작된 이후의 크래시가 하나라도 보이면, 검사는 기다렸다가 세 번째로 확인합니다. 세 번째 확인에서 가장 최근 크래시의 시각이 두 번째 확인의 가장 최근 크래시보다 늦다면, 그 사이에 머신이 다시 크래시한 것입니다. 머신은 계속 실행되지 못하고 있으며, 게시는 "게시 이후 머신이 반복해서 크래시하고 있으며 여전히 재시작 중"이라는 메시지와 함께 실패합니다.

이 방식은 이벤트 목록이 얼마나 짧든 상관없이 작동합니다. 다섯 개짜리 슬라이딩 윈도우는 크래시가 몇 번 있었는지는 숨길 수 있어도, 새로운 크래시가 방금 일어났다는 사실은 숨기지 못합니다. 가장 최근 이벤트는 항상 남아 있기 때문입니다.

이 변경을 적용한 뒤 로컬 재현은 올바르게 동작했습니다. 게시가 실패했고, 이전 이미지가 복원되었습니다. 또한 플랫폼의 동작을 흉내 내는 테스트가 있습니다. 매 확인마다 크래시와 시작을 하나씩 추가하고 목록을 다섯 개로 잘라내는데, 판정이 통과가 아니라 실패인지를 검증합니다.

얻은 교훈

• 세고 있는 데이터의 형태를 알아야 합니다. 상한이 있는 목록에 대한 개수는 목록이 가득 차면 의미를 잃습니다. 그 상한이 숨겨져 있던 것은 아닙니다. 우리가 검사를 그것을 고려해서 설계하지 않았을 뿐입니다.
• "몇 번 일어났나?"보다 "새로운 일이 일어났나?"를 물으세요. 가장 최근 타임스탬프는 잘려 나가도 살아남지만, 총개수는 그렇지 않습니다.
• 늦은 실패는 이른 실패보다 나쁩니다. 같은 망가진 빌드도, 게시가 실패하고 롤백되면 해롭지 않지만, 먼저 성공으로 선언되면 사이트를 내립니다.
• 실제 조건으로 재현하세요. 이 버그는 이벤트 목록을 채울 만큼 이미 여러 번 크래시한 머신이 필요했습니다. 테스트에서 한 번 빠르게 크래시하는 것으로는 드러나지 않았을 것입니다.

이 수정은 같은 날 나온 다른 수정과 짝을 이룹니다. 그 수정은 롤백이 이전 버전을 삭제하지 않고 복원하도록 보장합니다. 자세한 내용은 실패한 재배포가 작동 중인 백엔드를 삭제하지 않는 이유를 참고하세요. 앱이 시작될 때 크래시해서 게시에 실패한다면, 배포 문제 해결 문서와 AI로 만든 앱 디버깅 방법 가이드가 좋은 출발점입니다.