가용성/2026년 9월 23일 사고
9월 23일 22시 30분부터 24일 8시 47분까지 크롤러가 몰고 온 부하와 그것을 막으려던 조치가 차례로 이용자에게 닿았습니다. 앞의 67분 동안에는 로그인과 편집, 특수 문서처럼 PHP가 직접 만드는 요청이 자주 실패했습니다. 그 가운데 36분 동안 특수:빈문서 상태 검사가 실패했고, 서버는 502와 503을 2,689건 냈습니다. 같은 동안 200 응답도 33,552건 나갔고 페미위키:대문 검사는 한 번도 실패하지 않았으므로 비 로그인 요청은 대개 성공했습니다. 23시 52분 배포로 5xx는 멎었지만, 그때 넣은 속도 제한이 크롤러와 함께 로그인하지 않은 사람도 막았습니다. 이 상태는 24일 8시 47분에 상한을 올릴 때까지 이어졌습니다. 비 로그인 검색, 차이, 옛 판, 역사 요청을 사이트 전체에서 한데 세고, 상태 검사를 통과한 서버가 없어도 읽기 요청은 응답하는 서버로 보내게 고쳤습니다. 사람까지 막던 상한은 24일 8시 47분에 10분에 1,500건으로 올렸습니다.
| 시각 | 일어난 일 |
|---|---|
| 13:00 무렵 | 비 로그인 검색, 차이, 역사 요청이 평소의 두 배로 늘고, 워커가 최대치에 닿았다는 경고가 나오기 시작 |
| 17:00 무렵 | 같은 요청이 평소의 여섯 배쯤으로 늘어남 |
| 22:30 | autoheal이 앱 컨테이너를 처음 재시작. 상태 검사가 실패하기 시작 |
| 22:53 | 22시 57분까지 세 번 재시작 |
| 22:59 | 디스코드 알림 첫 번째 |
| 23:13 | 23시 34분까지 여섯 번 재시작. 23시 18분과 32분에 디스코드 알림 |
| 23:37 | 마지막 상태 검사 실패 |
| 23:50 | 속도 제한을 고친 이미지 배포 시작. 23시 52분에 끝남.[1] 5xx는 멎고, 대신 로그인하지 않은 이용자가 429를 받기 시작 |
| 24일 08:47 | 상한을 올린 이미지 배포.[2] 사람에게 붙던 429가 멎음 |
원인
비 로그인 상태의 검색, 차이, 옛 판, 역사 요청은 평소 시간당 1,300건 안팎인데 이날은 13시 무렵 두 배가 되고 17시부터는 8,000건 안팎이 됐습니다. 대부분 크롤러였고, 154.197.16.0/20과 154.193.16.0/20이 가장 많았지만 나머지도 수십 개 /16에 고르게 퍼져 있었습니다.
캐시를 거치지 않고 PHP로 가는 요청에는 이미 속도 제한이 있었는데 쿠키가 없는 요청을 /24마다 묶어 10분에 300건까지만 받았습니다.[3] 그러나 이 크롤러는 /24마다 10분에 수십 건씩만 보냈기 때문에 한 번도 걸리지 않았고, 이날 429를 받은 것은 따로 들어온 두 /24뿐이었습니다. 또 이 제한은 이름에 femiwiki가 든 쿠키만 있으면 면제였는데, 로그인 페이지는 처음 연 누구에게나 세션 쿠키를 주고 크롤러 요청의 5분의 1쯤은 특수:로그인에서 받은 이 쿠키를 달고 왔기에 제한에서 빠졌습니다.
앱 서버의 워커는 10개까지 뜨는데,[4] 비싼 요청이 이만큼 들어오자 워커는 내내 모자랐습니다. CPU 사용량은 2코어 가운데 0.8코어에서 1.7코어로 올랐고(이것은 바쁠 때 쓰려고 크레딧을 모아 둔 결과이므로 문제는 아닙니다), 데이터베이스도 한가했습니다. 모자란 것은 워커뿐이었습니다. 응답이 밀리자 컨테이너 상태 검사도 실패했고, 30초 간격으로 세 번 실패하면[5] autoheal이 컨테이너를 재시작했습니다. 22시 30분부터 23시 34분까지 열 번 재시작했고, 그때마다 처리 중이던 요청과 새로 들어온 요청이 502가 됐습니다. 재시작이 없던 10분 동안에는 502도 없었습니다. 503은 153건이었고, 살펴본 것은 모두 Caddy가 상태 검사를 통과한 서버를 찾지 못해 5초를 기다린 끝에 낸 것이었습니다.
대응이 만든 문제
23시 52분에 넣은 제한은 사이트 전체에서 10분에 600건이었는데,[6] 이 통 하나를 크롤러와 로그인하지 않은 이용자가 함께 씁니다. 로그인하지 않은 사람들이 이 경로에 보내는 요청은 10분에 900건에서 1,500건이니, 상한은 평소 수요보다도 낮았습니다. 크롤러가 통을 비우고 나면 그다음에 역사나 차이를 누른 사람이 그대로 429를 받았습니다.
배포부터 24일 8시 10분까지 이 제한이 거부한 요청은 35,113건으로, 같은 동안 /24별 제한이 거부한 2,376건보다 훨씬 많았습니다. 30분을 들여다보니 아이폰과 안드로이드 사용자의 서로 다른 주소 103개가 거부당했습니다. 5xx는 멎은 뒤였으므로 경보는 울리지 않았고, 이 8시간 반 동안 사이트는 정상으로 보였습니다.
알림
Route 53의 특수:빈문서 검사가 22시 59분, 23시 18분, 23시 32분에 경보로 바뀌어 디스코드로 알렸고, 그 사이사이 잠깐씩 정상으로 돌아왔습니다. Grafana의 사이트 다운 경보는 울리지 않았습니다. 5분 동안 성공한 응답이 100건에 못 미치면 울리는 경보인데,[7] 읽기 요청은 계속 성공했기 때문입니다.
고친 것
- 비 로그인 검색, 차이, 옛 판, 역사 요청을
/24별이 아니라 사이트 전체에서 한데 셉니다. 면제는 로그인한 사용자의 쿠키가 있을 때만 줍니다. docker-mediawiki#1109에서 고쳤습니다. - 상태 검사를 통과한 서버가 하나도 없으면 읽기 요청은 503 대신 응답하는 서버로 보냅니다.[8] docker-mediawiki#1108에서 고쳤습니다.
- 둘은 23시 52분에 infra#600으로 배포됐습니다. 그 뒤로 5xx와 상태 검사 실패는 없었습니다.
- 그 상한을 1,500건으로 올리고, 두 제한의 상한과 창 길이를 환경 변수로 빼서 이미지를 새로 굽지 않고도 고칠 수 있게 했습니다.[9] docker-mediawiki#1112에서 고쳐 24일 8시 47분에 infra#608로 배포했습니다. 배포 뒤 10분 동안 이 제한이 거부한 요청은 없었고, 같은 경로의 요청 1,090건이 그대로 처리됐습니다.
남은 문제
상태 검사는 PHP가 응답해야 통과하므로, 워커가 모자라면 서버가 살아 있어도 실패합니다. 이 사고에서 autoheal이 컨테이너를 열 번 재시작한 것은 서버가 죽어서가 아니라 느려서였고, 재시작이 요청을 502로 끊어 느림을 사고로 바꿨습니다. 검사가 워커를 두고 요청과 경쟁하지 않게 하거나, 느린 것과 죽은 것을 갈라 보는 방법이 필요합니다. femiwiki#561에 적어 두었습니다.
출처
- ↑ https://github.com/femiwiki/infra/pull/600
- ↑ https://github.com/femiwiki/infra/pull/608
- ↑ https://github.com/femiwiki/docker-mediawiki/blob/4b0a06bb18e0cd32db3c511487f8787c21889e9e/dockers/femiwiki/Caddyfile#L29-L40
- ↑ https://github.com/femiwiki/infra/blob/0bee714c955ab49cf9f3acd5e003dc0f961e097d/docker/container.tf#L95
- ↑ https://github.com/femiwiki/infra/blob/0bee714c955ab49cf9f3acd5e003dc0f961e097d/docker/container.tf#L125-L130
- ↑ https://github.com/femiwiki/docker-mediawiki/blob/bf16c29e0ffd829df734d5a920defd4902da77ea/dockers/femiwiki/Caddyfile#L41-L56
- ↑ https://github.com/femiwiki/infra/blob/665ed7dfc95a940ae7d2d7112a96b8c03669f0b7/grafana/alerts.tf#L134-L188
- ↑ https://github.com/femiwiki/docker-mediawiki/blob/bf16c29e0ffd829df734d5a920defd4902da77ea/dockers/femiwiki/Caddyfile#L80-L106
- ↑ https://github.com/femiwiki/docker-mediawiki/blob/ec57eae2979b4c94e769097e9bd8639efddb7dc8/dockers/femiwiki/Caddyfile#L41-L61