새벽 3시, etcd db size 알람이 울렸다

새벽 3시 7분에 진동이 왔다

새벽 3시 7분. 폰이 진동했다. etcd_mvcc_db_total_size_in_bytes 가 6GiB를 넘었다는 알람이었다. 우리 클러스터는 컨트롤플레인이 EKS가 아니라 자체 운영이고, etcd quota를 8GiB로 잡아놨다. 8GiB를 넘기는 순간 클러스터가 read-only로 떨어진다. 일어났다.

평소에는 etcd db size가 1.2~1.5GiB 사이를 왔다 갔다 한다. 그게 6GiB라는 건 어딘가가 단단히 잘못됐다는 뜻이다. 처음엔 그냥 defrag 한번 돌리면 되겠지 했는데, 이게 그렇게 단순한 얘기가 아니었다.

일단 무슨 일이 일어났는지부터 봤다

ssh로 컨트롤플레인 노드 3대에 붙어서 etcdctl로 상태를 봤다.

ETCDCTL_API=3 etcdctl \
  --endpoints=https://127.0.0.1:2379 \
  --cacert=/etc/kubernetes/pki/etcd/ca.crt \
  --cert=/etc/kubernetes/pki/etcd/server.crt \
  --key=/etc/kubernetes/pki/etcd/server.key \
  endpoint status --write-out=table

세 멤버 모두 db size가 6.1~6.3GiB. 근데 DB SIZE IN USE(실제 사용량)는 1.4GiB. 즉, 실제 데이터는 1.4GiB인데 디스크 점유는 6GiB. compaction은 됐지만 defrag이 안 된 전형적인 모양이다.

여기서 잠깐. 두 개를 헷갈리면 안 된다.

• compaction: 오래된 리비전을 논리적으로 지운다. 데이터는 "안 보이게" 되지만 디스크 공간은 그대로다.
• defrag: 디스크 공간을 실제로 회수한다. 단, 해당 멤버의 쓰기를 잠시 막는다.

compaction은 5분마다 자동으로 돌고 있었는데, defrag은 우리 환경에서 cron으로 매주 일요일 새벽에만 돌렸다. 이번 주 일요일에는 정상으로 돌았다. 그러면 왜 갑자기 4.5GiB가 더 쌓였을까.

범인을 찾는 과정

처음엔 그냥 누군가 컨피그맵을 미친듯이 업데이트했나 싶었다. kubectl get --raw 로 etcd에 직접 들어있는 키들을 사이즈순으로 뽑아봤다.

ETCDCTL_API=3 etcdctl \
  --endpoints=https://127.0.0.1:2379 \
  --cacert=... --cert=... --key=... \
  get / --prefix --keys-only | \
  awk -F'/' '{print "/"$2"/"$3"/"$4}' | sort | uniq -c | sort -rn | head -20

비슷하게 키 prefix별 byte 사이즈도 계산해봤다 (스크립트로 키별 size 합산). 결과는 좀 황당했다.

/registry/events/default          ~480 MiB
/registry/leases/kube-node-lease  ~210 MiB
/registry/services/endpoints      ~95 MiB
...

Events가 480MiB? Events는 기본적으로 1시간 TTL이 걸려있다. 보존 정책상 이렇게 누적될 수가 없다. 그런데 우리 클러스터는 그렇게 쌓여 있었다.

apiserver 로그를 봤다. --event-ttl 플래그를 확인하니… 누군가 한 달 전에 디버깅한답시고 --event-ttl=240h (10일)로 바꿔놨다. 그리고 그 PR이 머지된 채로 돌아가고 있었다. 지난 일요일 defrag 후로 새로 쌓인 events가 그대로 etcd에 남아있던 것이다.

심지어 끝이 아니었다. leases가 210MiB라는 것도 비정상이었다. 확인해보니 어떤 컨트롤러가 leader election lease를 매번 새로 만들고 안 지우는 버그가 있었다 (사내 컨트롤러였고, 이 부분은 다음 분기 작업으로 넘겼다).

응급 처치

새벽 3시 반. 일단 클러스터를 살려야 했다. 순서는 이렇게 잡았다.

1. event-ttl을 원복 (1h)하는 PR을 긁어서 emergency 머지. apiserver 롤링 재시작.
2. compaction을 수동으로 한번 더 명시적으로 돌린다.
3. defrag을 follower → leader 순으로 한 멤버씩 돌린다.

2번이 약간 미묘했다. 자동 compaction이 돌고 있긴 한데 "이미 한 revision"을 또 compact하라고 시키는 거라 큰 효과는 없을 거라고 봤다. 실제로 별 차이 없었다.

3번은 신중하게 갔다. etcd 공식 권장 사항은 한 번에 한 멤버씩, leader는 마지막, 사이에 cluster health 확인.

# follower부터
ETCDCTL_API=3 etcdctl --endpoints=https://node-2:2379 ... defrag
# 끝나면 health 확인
ETCDCTL_API=3 etcdctl --endpoints=https://node-2:2379 ... endpoint health
# 다음 follower
...
# leader는 마지막

각 멤버 defrag에 약 8~12초 걸렸다. 그동안 그 멤버는 쓰기가 막히는데, raft가 알아서 라우팅해주니까 사용자 트래픽 영향은 없다. 단, 그 시점에 leader가 잠깐 바뀔 수 있어서 컨트롤러 매니저나 스케줄러가 잠깐 흔들릴 수는 있다. 우리는 이때 약 200ms 정도 elect 지연이 있었다.

3시 52분. db size 1.4GiB로 떨어졌다. 알람도 해제됐다.

끝나고 정리한 것들

다음 날 회고를 하면서 몇 가지를 바꿨다.

defrag을 주1회에서 일1회로 변경. "주 1회면 충분하다"는 게 어디서 나온 얘기인지 모르겠다. 우리 환경에서는 일1회가 적절했다. 단, leader 마지막 + 사이에 health check 하는 패턴은 그대로 유지.

etcd-defrag 도구 도입. 직접 짠 셸 스크립트는 health check 누락이나 leader 판정 실수 가능성이 있었다. etcd 공식에서 추천하는 etcd-defrag을 CronJob으로 올렸다. 멤버 순회와 leader-last를 알아서 해준다.

db size에 대한 알람을 3단계로 분리.

• WARN: 2.5GiB (평시 대비 1.5x)
• HIGH: 4GiB (조사 필요)
• CRITICAL: 6GiB (즉시 대응)

이전에는 CRITICAL 하나만 있어서 새벽에 깼다. WARN을 봤더라면 영업시간에 대응할 수 있었을 거다.

event-ttl 같은 운영용 플래그는 PR 머지 시 코드오너 추가. 컨트롤플레인 컴포넌트 매니페스트는 SRE 팀이 코드오너로 들어가게 했다. 누가 디버깅용으로 잠깐 바꿨다가 그대로 머지되는 상황을 막는 가장 단순한 방법이었다.

그리고 한 가지 더

이번에 검색하면서 알게 됐는데, Kubernetes 공식 문서에서도 cron으로 도는 defrag 대신 점검 윈도우에서 사람이 모니터링하면서 도는 방식을 권장한다. 우리는 일1회 자동으로 가긴 했지만, 알람이 떨어지는 임계를 충분히 낮춰서 사람이 한 번씩 들여다보는 식으로 둘 다 챙기는 중이다.

새벽에 일어나서 한 회고치고는 꽤 많이 얻었다. 가장 큰 교훈은 etcd db size 그래프는 매일 한 번씩 봐야 한다는 거. 그리고 compaction과 defrag을 헷갈리지 말 것.

다음에는 etcd snapshot 복구를 staging에서 실제로 한번 돌려보려고 한다. 그건 그것대로 또 한참 걸릴 것 같다.