{"id":"IL-0294","org":"CircleCI","date":"2021-05-21","docs":[],"title":{"en":"CircleCI Docker and machine jobs stalled for nearly 12 hours after a VM cleanup queue lost all its RabbitMQ consumers","ko":"CircleCI 의 VM 정리 대기열에서 컨슈머가 사라져 Docker 와 machine 작업이 12시간 가까이 늦어지거나 막혔다"},"domain":["database","gcp","aws"],"impact":{"scope":"Docker, Machine executor (Windows, Mac, Arm, GPU) and remote Docker jobs delayed or blocked; macOS jobs slow","users":"CircleCI customers running these job types","region":"unknown"},"review":{"written_by":"session","reviewed_at":null,"reviewed_by":null},"lessons":null,"related":[],"sources":[{"url":"https://status.circleci.com/incidents/qxkj1832wf9l","kind":"official-status","archived":"https://web.archive.org/web/20221226060927/https://status.circleci.com/incidents/qxkj1832wf9l"}],"summary":{"en":"At 08:37 UTC on 20 May CircleCI upgraded its RabbitMQ cluster from 3.8.9 to 3.8.16 as routine maintenance, after checking the changelog for breaking changes. The changelog described a new 15 minute acknowledgement timeout for consumers that take messages without acknowledging them, but only for quorum queues, which CircleCI does not use. In fact the change, introduced in RabbitMQ 3.8.15, applied to all queue types. Messages that hit the timeout made RabbitMQ close the channel of the consumer, and on the queues that need a timeout that long, consumers dropped and did not come back. The queue that asynchronously cleans up VMs in one region lost consumers over time until it had none, and old VMs stopped being deleted.\n\nCircleCI then hit its GCP CPU quotas, and automated retries kept the quotas exhausted, so new VMs could not be started; because the Docker executor fleet was coupled to the VM service, Docker jobs slowed too. Engineers blocked Linux machine jobs from the work queue at 14:13, GCP raised the quotas at 14:37, and engineers deleted old VMs by hand and cancelled some workflows at 17:22. At 16:25 they found the VM destroy queues had no consumers and reset the VM services deployment, and the queues drained. That load used up the Burst Balance of the RDS-based databases at about 18:05; a reboot did not help, so an RDS instance was scaled up at 18:20 and again at 19:15, while VM provisioning was turned down and remote-docker jobs were blocked to shed load.\n\nThe system was stuck in a cycle of creating VMs and being unable to remove them because of the GCP quotas. At 21:00 engineers scaled down all pods that created and destroyed VMs, at 21:57 deployed a revised distribution backend that kept remote-docker jobs out of the provisioning queues, and from 22:36 brought provisioning and distribution back one component at a time. By 00:39 everything was back online and the code changes made during the outage were reversed, and the incident was resolved at 01:18 UTC on 22 May. On 24 May graphs showing RabbitMQ consumers disconnected after 15 minutes revealed the leading cause, and RabbitMQ confirmed that the timeout affects all queue types and said its next release would apply a larger timeout and document the setting.","ko":"CircleCI 는 2021-05-20 정기 유지보수로 RabbitMQ 를 3.8.9 에서 3.8.16 으로 올렸다. 팀은 변경 기록에서 호환되지 않는 변경을 확인했다. 변경 기록에는 메시지를 받고 ack 하지 않는 컨슈머에 기본 15분 ack 타임아웃을 거는 변경이 CircleCI 가 쓰지 않는 quorum queue 에만 해당한다고 적혀 있었다. 실제로 이 변경은 모든 큐 종류에 적용됐다. 일부 메시지가 ack 타임아웃에 걸리면서 그 컨슈머의 RabbitMQ 채널이 닫혔다. 특정 리전의 VM 을 비동기로 정리하는 대기열의 컨슈머는 이렇게 시간이 지나며 줄어 결국 0 이 됐다. 그래서 VM 이 지워지지 않았다. 이 원인은 5월 24일에야 밝혀졌다.\n\n5월 21일 02:31 에 VM destroyer 대기열에 컨슈머가 없다는 알림을 받고 파드를 재시작해 정상으로 돌렸다. 그러나 03:10 에 다시 컨슈머가 빠지기 시작한 것은 알아채지 못했다. 10:11 의 대기열 적체 알림은 한 번만 울리고 온콜을 호출하지 않았다. 13:00 에 작업 시작 지연 호출이 왔고, 시스템은 GCP CPU 쿼터에 걸려 VM 을 띄우지 못했다. 13:23 에 장애를 선언하고 13:26 에 Google Cloud 에 쿼터 증설 티켓을 열었다. 크립토마이닝 남용을 원인으로 보고 마이닝 작업을 지웠지만 효과가 없었고, 자동 재시도가 쿼터를 바닥낸 주된 원인으로 드러났다. 14:13 에 Linux machine 작업이 작업 대기열에 들어오지 못하게 막았고, Docker executor 와 VM 서비스가 묶여 있어 Docker 작업도 느려졌다. 14:37 에 GCP 가 쿼터를 늘렸지만 시스템은 스스로 회복하지 못했다. 엔지니어는 오래된 VM 을 손으로 지우기 시작했다. 16:25 에 VM 을 지우는 대기열에 컨슈머가 없음을 확인해 VM 서비스 배포를 리셋했고, 17:22 에 일부 워크플로를 취소해 자원을 비웠다.\n\n대기열이 빠지던 18:05 무렵 RDS 데이터베이스의 Burst Balance 가 바닥나 IO 가 크게 줄고 연결이 타임아웃됐다. 재부팅은 효과가 없었고, 18:20 에 RDS 인스턴스를 키우며 VM 프로비저닝 서비스를 줄여 연결이 몰리지 않게 했다. GP2 크레딧이 다시 바닥나자 remote-docker 작업을 막았다. 18:50 에 다시 GCP API 쿼터에 걸렸고, 19:00 에 프로비저닝 서비스를 줄였지만 burst balance 는 계속 빠르게 줄었다. 19:15 에 데이터베이스를 한 번 더 키워 19:45 에 안정됐지만 VM 프로비저닝 시간이 다시 늘었다. 시스템은 VM 을 만들고 쿼터 때문에 지우지 못하는 순환에 빠졌다. 21:00 에 엔지니어는 VM 을 만들고 지우는 파드를 모두 줄였다. 21:57 에 remote-docker 작업을 프로비저닝 대기열에 넣지 않는 새 분배 백엔드를 배포했고, 22:21 에 프로비저닝 시스템을 줄여 대기열이 빠질 여유를 만들었다. 22:36 부터 두 시간 동안 구성 요소를 하나씩 다시 올렸고, 00:39 에 모두 돌아오며 완화용 코드 변경을 되돌렸다. 장애는 5월 22일 01:18 에 해결됐다. 대응에는 EMEA 와 NA 의 인력이 참여했고 APAC 인력까지 부를 뻔했다. 이후 RabbitMQ 쪽은 이 타임아웃이 모든 큐 종류에 적용된다고 확인했고, 다음 릴리스에서 타임아웃을 늘리고 설정 문서를 보강하겠다고 답했다."},"trigger":{"en":"The upgrade of the RabbitMQ cluster from 3.8.9 to 3.8.16 on 20 May 2021, which brought in a 15 minute consumer acknowledgement timeout for all queue types.","ko":"2021-05-20 08:37 UTC 에 RabbitMQ 를 3.8.9 에서 3.8.16 으로 올렸다. 3.8.15 에서 들어온 변경으로, 메시지를 받고 ack 하지 않는 컨슈머에 기본 15분 ack 타임아웃이 걸렸다. 변경 기록에는 quorum queue 에만 해당한다고 적혀 있었지만 실제로는 모든 큐 종류에 적용됐다."},"severity":"unknown","symptoms":["throughput-degraded","cloud-api-rate-limited","database-overloaded"],"timeline":{"detected_after":null,"resolved_after":"11h 48m"},"date_kind":"incident","detection":{"en":"Engineers were paged at 13:00 UTC on 21 May for excessive delays in starting jobs. Earlier, a 02:31 notification that a VM destroyer queue had no consumers was handled by restarting pods, and a 10:11 alert that a VM destroy queue was backing up notified once at its threshold and did not page.","ko":"02:31 UTC 에 VM destroyer 서비스 대기열 하나에 컨슈머가 없다는 알림이 왔고, 파드를 재시작해 정상으로 돌렸다. 그 뒤 03:10 에 다시 컨슈머가 빠지기 시작한 것은 알아채지 못했다. 10:11 에 VM 을 지우는 대기열이 쌓인다는 알림이 울렸다. 이 알림은 임계값에 닿을 때 한 번만 알리게 잘못 설정돼 있었고 온콜을 호출하지 않았다. 엔지니어들은 13:00 에 작업 시작 지연 호출을 받고서야 본격적으로 조사를 시작했다."},"components":["message-broker","database"],"root_cause":"upgrade-breaking-change","remediation":[{"text":{"en":"Blocked Linux machine jobs from entering the work queue","ko":"14:13 에 Linux machine 작업이 작업 대기열에 아예 들어오지 못하게 손으로 막았다."}},{"text":{"en":"Had GCP raise the CPU quotas","ko":"13:26 에 Google Cloud 에 쿼터 증설 티켓을 열었고 14:37 에 GCP 가 쿼터를 늘렸다. 시스템은 그 뒤에도 스스로 회복하지 못했다."}},{"text":{"en":"Deleted old VMs by hand","ko":"오래된 VM 을 손으로 지우는 계획을 세우고 지우기 시작했다."}},{"text":{"en":"Cancelled some workflows to free resources","ko":"17:22 에 자원을 비우고 멈춘 플랫폼을 다시 움직이려고 일부 워크플로를 취소했다."}},{"text":{"en":"Reset the VM services deployment so the VM destroy queues had consumers again","ko":"16:25 에 VM 을 지우는 대기열에 컨슈머가 없음을 확인하고 대기열과의 연결을 되살리려고 VM 서비스 배포를 리셋했다. 대기열이 빠지기 시작했다."}},{"text":{"en":"Scaled up the RDS database instance, at 18:20 and again at 19:15","ko":"Burst Balance 가 바닥난 RDS 데이터베이스를 재부팅해도 효과가 없자 18:20 에 인스턴스를 키워 메모리와 CPU, burst balance 를 늘렸다. 데이터베이스가 돌아오는 동안 VM 프로비저닝 서비스를 줄여 연결이 몰리지 않게 했고, 19:15 에 한 번 더 키웠다."}},{"text":{"en":"Turned down VM provisioning and blocked remote-docker jobs to shed load","ko":"VM 프로비저닝 서비스를 줄이고, vm-create 대기열을 키우던 remote-docker 작업이 실행되지 않게 막아 부하를 덜었다."}},{"text":{"en":"Scaled down all pods that created and destroyed VMs","ko":"21:00 에 새 VM 을 만들고 오래된 VM 을 지우는 파드를 모두 줄여 VM 을 만들고 지우지 못하는 순환을 끊었다."}},{"text":{"en":"Deployed a revised distribution backend that kept remote-docker jobs out of the provisioning queues","ko":"21:57 에 remote-docker 작업을 프로비저닝 대기열에 넣지 않는 새 분배 백엔드를 배포했고, 22:21 에 프로비저닝 시스템을 줄여 대기열이 빠질 여유를 만들었다."}},{"text":{"en":"Brought provisioning and distribution back one component at a time and reversed the mitigation code changes","ko":"22:36 부터 두 시간 동안 프로비저닝과 분배 시스템의 구성 요소를 하나씩 안정성을 확인하며 다시 올렸고, 00:39 에 모두 돌아오자 완화용 코드 변경을 되돌렸다."}}],"action_items":[{"text":{"en":"Make VM provisioning more robust to changes in load so it can recover from thundering herds","ko":"VM 프로비저닝이 부하 변화에 더 잘 버티고 thundering herd 에서 회복하도록 고친다."}},{"text":{"en":"Make VM provisioning independent so its failure does not affect Docker jobs","ko":"VM 프로비저닝을 분리해 그 실패가 Docker 작업에 영향을 주지 않게 한다."}},{"text":{"en":"Review and improve observability of RabbitMQ and the production queues","ko":"RabbitMQ 와 운영 대기열들의 관측성을 점검하고 보강한다."}},{"text":{"en":"Batch requests to avoid hitting GCP API rate limits","ko":"요청을 묶어 보내 GCP API 요청 한도에 걸리지 않게 한다."}},{"text":{"en":"Improve incident response for long-running incidents","ko":"오래 이어지는 장애에 맞게 장애 대응 방식을 보강한다."}}],"contributing":["delayed-effect-change","early-signal-ignored","retry-storm","blast-radius-too-wide","overlapping-failures"],"recurrence_of":null,"symptoms_text":{"en":"From 13:30 UTC on 21 May 2021, CircleCI jobs on Docker, the Machine executor (including Windows, Mac, Arm and GPU) and remote Docker were delayed or blocked. Engineers had been paged at 13:00 for excessive delays in starting jobs, and the alerts showed CircleCI could not provision some types and classes of VM because it was hitting its CPU quotas in GCP.\n\nThere had been signs earlier that day. At 02:31 engineers were told that a VM destroyer service queue had no consumers, and restarted the VM service Kubernetes pods. From 03:10 the queue lost consumers again without anyone noticing, and at 10:11 an alert reported that a queue used to destroy VMs was backing up, but it was set to notify only once at a threshold and did not page anyone.\n\nA rise in cryptomining abuse of the platform looked like the cause, so engineers first removed the mining jobs, and the status page blamed platform abuse; this did not visibly reduce the impact. Meanwhile automated retries kept the GCP quotas exhausted, and when GCP raised the quotas at 14:37 the system still did not recover on its own.\n\nAfter the VM destroy queues were reconnected at 16:25 and began to drain, the RDS-based databases used up their Burst Balance at about 18:05: IO dropped sharply and connections to the database timed out and dropped. Rebooting the database did not help, and later the GP2 credits ran out as well. Customers saw Machine Executor and Remote Docker jobs queued, in permanent not run status or canceled, and macOS jobs could be slow.","ko":"2021-05-21 13:00 UTC 에 CircleCI 엔지니어가 작업 시작이 지나치게 늦어진다는 첫 호출을 받았다. Docker, Machine executor, remote Docker 작업이 늦어지거나 막혔고, 시스템이 GCP 의 CPU 쿼터에 걸려 VM 을 띄우지 못하고 있었다.\n\n상태 페이지는 Machine executor 와 Remote Docker 작업이 queued 나 permanent not run 상태로 남거나 canceled 된다고 알렸다. macOS 작업은 느려질 수 있었다. 영향은 주로 Linux executor 에 있었고, Windows executor 는 간헐적으로 문제를 겪을 수 있었다. 일부 작업은 취소돼 사용자가 손으로 다시 돌려야 했고, 상태 페이지는 queued 에 멈춘 작업을 취소하고 다시 돌리라고 안내했다.\n\n앞선 신호가 있었다. 02:31 에 VM destroyer 서비스 대기열 하나에 컨슈머가 없다는 알림이 와서 VM 서비스 Kubernetes 파드를 재시작했고 모두 정상으로 돌아왔다. 03:10 에 VM destroyer 서비스가 다시 대기열에서 컨슈머를 잃기 시작했지만 아무도 알아채지 못했다. 10:11 에 VM 을 지우는 대기열이 쌓인다는 알림이 울렸다. 그러나 이 알림은 임계값에 닿을 때 한 번만 알리고 대기열이 계속 늘어도 다시 알리지 않게 잘못 설정돼 있었고, 온콜도 호출하지 않았다.\n\n엔지니어는 처음에 크립토마이닝 관련 플랫폼 남용이 늘어난 것을 원인으로 보고 마이닝 작업을 지우는 데 힘을 쏟았다. 고객 영향은 눈에 띄게 줄지 않았고 GCP 쿼터에 계속 걸리며 복구가 막혔다. 더 조사해 보니 자동 재시도가 GCP 쿼터를 바닥낸 주된 원인이었다.\n\n대기열이 빠지기 시작한 뒤에는 RDS 데이터베이스가 버티지 못했다. 18:05 에 할당된 Burst Balance 를 모두 써서 IO 가 크게 줄었고 데이터베이스 연결이 타임아웃되며 끊겼다. 데이터베이스를 키운 뒤에도 GP2 크레딧이 바닥났다. 18:50 에는 다시 GCP API 쿼터에 걸렸고, 19:00 에 프로비저닝 서비스를 줄인 뒤에도 데이터베이스는 15분 만에 burst balance 의 약 30% 를 썼다.\n\n결국 시스템은 VM 을 만들고 GCP 쿼터 때문에 지우지 못하는 순환에 빠졌고, 19:45 에 데이터베이스가 안정된 뒤에도 VM 프로비저닝 시간이 다시 늘었다."},"updated_at":"2026-11-14T12:33:54.911415Z","url":"https://benchlet.com/incidentlib/app/cases/IL-0294","org_slug":"circleci"}