디버깅에서 가장 비싼 건 틀린 가설을 붙들고 있는 시간이다

테넌트에 줄 앱을 토글로 하나 껐더니 손대지 않은 다른 앱의 Pod가 재시작됐다. 나는 ArgoCD를 의심했다. ApplicationSet 갱신 방식을 바꿔 보고, 항목만 patch해 보고, 그래도 안 되자 ApplicationSet을 버리고 앱마다 Application을 따로 두는 구조로 쪼갰다. 그래도 재시작됐다. 마지막으로 ArgoCD를 아예 손에서 놓고 git에서 디렉터리를 지운 뒤 kubectl delete만 했다. 그래도 재시작됐다.

원인은 Karpenter의 노드 정리였고, 고친 건 PDB 한 줄이었다. 그 한 줄에 닿기까지 며칠이 걸렸고, 그 며칠은 대부분 엉뚱한 계층을 파는 데 들어갔다.

서비스 하나를 여러 고객사가 각자 쓰도록 바꾸는 멀티 테넌트 SaaS 전환 프로젝트를 몇 달 하면서 이런 일이 여러 번 있었다. 틀린 가설을 세운 것 자체는 문제가 아니었다. 대부분 그럴듯했고 몇몇은 절반쯤 맞았다. 비쌌던 건 틀렸다는 증거가 나온 뒤에도 그 가설을 놓지 않은 시간, 그리고 그 위에 쌓아 올린 변경이었다.

이 글에서는 그 시간을 줄이려고 사건마다 다시 꺼내 쓰게 된 습관 네 가지와, 틀린 가설이 남긴 것을 치우는 일을 적는다. 자세한 경위는 사건별 글로 넘긴다.

증상이 보이면 먼저 계층을 가른다

앱 하나를 껐는데 옆 앱이 재시작된 사건에서 나는 배포 계층만 팠다. 앱 목록을 바꾼 곳이 ArgoCD였고 그 직후 다른 앱이 흔들렸으니 자연스러운 선택이었다. ArgoCD 화면을 내려놓고 클러스터 이벤트를 시간순으로 뽑은 건 네 번째 시도가 끝난 뒤였다. 노드 이벤트에는 처음부터 Disrupting Node: Underutilized가 찍혀 있었다. 내가 지운 건 Pod였는데, Karpenter는 노드를 지우고 있었다.

Terminating에서 멈춘 Pod 사건은 계층이 더 깊었다. 눈에 보인 건 테넌트 삭제 파이프라인의 실패였다. 따라 내려가면 대기 루프가 있고, ArgoCD Application의 finalizer와 Rollout·ReplicaSet의 finalizer를 지나 Pod 하나에 닿는다. 그 Pod 안에서는 java 스레드가 커널의 종료 경로에서 NFS flush를 기다리고 있었다. 증상은 파이프라인에서 보였는데 원인은 다섯 계층 아래에 있었다.

계층을 가른다는 건 “앱인가, 배포 도구인가, 노드인가, 네트워크인가”를 먼저 묻는 일이다. David Agans는 디버깅 규칙을 아홉 개로 정리한 책에서 이를 “Divide and Conquer”라고 불렀다.

가설을 부정하는 증거가 나오면 그 자리에서 멈춘다

ArgoCD를 아예 빼고도 같은 증상이 나왔다면, 그 순간부터 ArgoCD를 의심할 이유는 없다. 사실 신호는 그 전에도 있었다. 갱신 방식을 바꾼 첫 두 번이 실패했을 때 나는 ArgoCD 바깥을 보지 않고 ArgoCD 안에서 더 큰 변경, 즉 구조를 쪼개는 쪽으로 갔다. 가설을 부정하는 결과를 “아직 덜 바꿨다”로 읽기 시작하면, 그다음부터 쓰는 시간은 디버깅이 아니라 가설을 지키는 일이 된다.

부하테스트에서도 같은 일이 있었다. nginx Pod를 3개에서 6개로 늘리고, Pod CPU limit과 사이드카 concurrency를 올리고, Gateway 노드를 네 배 사양으로 바꿔도 처리량은 5,300 RPS 근처에서 한 번도 움직이지 않았다. 그동안 Pod는 CPU와 메모리를 한도의 5~25%만 썼다. 사이드카 하나는 limit을 올려도 990m 근처에서 멈춰 있었고, 나는 그걸 근거로 “Envoy의 한 경로가 1코어 부근에서 직렬화된다”는 가설까지 갔다. 결국 부하를 주는 서버를 한 대 더 붙이자 합산 처리량이 8,823 RPS로 65% 올랐고, 990m에서 막힌다던 사이드카는 1,267m까지 썼다.

서버 쪽을 키워도 그대로라는 결과 하나하나가 서버 가설을 부정하는 증거였다. 자원이 남는데 처리량이 멈추면 서버보다 측정을 먼저 의심해야 한다. 나는 일주일 가까이 서버 쪽만 키운 뒤에야 그걸 알았다.

정상인 것과 비교한다

Terminating Pod 사건의 첫 가설은 “다른 가용 영역의 EFS에 고정 IP로 붙는 구조”였다. 재발했을 때 모든 것이 이 가설에 들어맞았다. 멈춘 Pod의 노드는 2a 존인데 마운트 타깃은 2c 존이었고, 그 IP를 쓰는 앱은 정확히 멈춘 두 앱이었다. dmesg에는 not responding이 8,800건 넘게 쌓여 있었다.

가설을 무너뜨린 건 멀쩡한 노드들이었다. 같은 날 cross-AZ로 마운트한 앱이 여러 노드에 흩어져 있었는데, 좀비 노드를 뺀 나머지 7대는 이틀 동안 NFS 오류가 0건이었다. cross-AZ가 원인이었다면 이 7대에서도 오류가 났어야 한다. 들어맞는 증거는 아픈 곳에서만 모은 것이라, 같은 조건인데 멀쩡한 쪽을 봐야 가설이 갈린다. 진짜 원인은 NFS 트래픽을 가로채던 Istio 사이드카가 앱보다 먼저 종료된 것이었다.

비교는 반대 방향으로도 쓴다. 앱 Pod 하나가 826 RPS에서 멈췄을 때 같은 클러스터의 nginx는 5,000 가까이 처리하고 있었다. JVM 앱이 빈 컨테이너보다 느린 건 당연해 보였다. 그런데 앱에 걸려 있던 DestinationRule을 nginx에 그대로 걸자 nginx도 850에서 막혔다. 멀쩡한 쪽에 아픈 쪽의 조건을 옮겨 심어 같은 증상이 나오면, 원인은 옮겨 심은 그 조건이다. 범인은 maxRequestsPerConnection: 1 한 줄이었다.

의심되는 기능은 끄고 재 보되, 끈 채로 두지 않는다

새 테넌트를 온보딩하면 Pod 60개가 안정되기까지 40분이 걸렸다. 의심 가는 건 이중 배포, 느린 기동, 노드 정리 셋이었다. 팀원이 정리 대기 시간을 늘려 봤지만 효과가 없었다고 했다. 추측을 더 쌓는 대신 NodePool의 disruption budget을 0으로 두고 같은 배포를 다시 했다. 7분에 끝났다. 40분 중 33분이 어디서 왔는지 그 한 번으로 정해졌다.

정리를 끄면 40분은 바로 사라진다. 하지만 노드 37개가 28개로 줄던 비용 절감도 같이 사라진다. 끄는 대신 정리가 왜 아팠는지를 다시 봤다. 40분을 만든 건 정리가 배포 도중에 끼어드는 타이밍이었다. 정리 대기 시간을 한 번의 배포보다 길게 잡자 배포 중에는 정리가 시작되지 않았다. 그 뒤 실험에서는 같은 앱의 Pod가 노드 몇 개에 몰려 있으면 정리 한 번에 한꺼번에 쓸려 간다는 것도 확인했다. 정리는 켜 둔 채 타이밍을 늦추고 몰림을 막았다.

틀린 가설로 바꾼 구조는 되돌린다

ArgoCD 사건이 끝났을 때 테넌트 앱들은 여전히 ApplicationSet 하나가 아니라 Application 수십 개로 나뉘어 있었다. 쪼갠 근거였던 “ApplicationSet이 전체를 다시 훑는다”는 이미 틀린 것으로 밝혀진 뒤였다. ApplicationSet 하나로 되돌렸다. 그대로 두었다면 몇 달 뒤 누군가 “왜 이렇게 돼 있지”라고 물었을 것이고, 답은 “예전에 잘못 짚었는데 안 되돌려서”였을 것이다.

되돌리는 게 늘 답은 아니다. Terminating Pod 사건의 cross-AZ 가설은 완전히 틀렸다기보다 같은 메커니즘의 다른 입구를 본 것이었다. 그 가설을 따라 만든 존별 EFS 마운트 개선은 dev에서 8번 중 8번 의도대로 동작했고, EFS 통신이 정말 끊기는 경우의 확률을 줄인다. 다만 그 작업을 남길지는 작업 자체의 근거로 다시 정해야 한다. 그 개선은 운영 반영 협의 때문에 revert해 둔 상태였는데, 재발했을 때 나는 “개선이 미적용이라 재발했다”고 결론을 내고 재적용을 대책으로 적었다. 틀린 근거를 단 채 남아 있던 작업이 다음 판단까지 끌고 갔다. 쓸모 있는 변경이라면 맞는 이유를 새로 붙여서 남기면 된다.

틀린 근거로 들어간 변경이 늘 큰 구조인 건 아니다. 특정 테넌트만 다른 프로파일을 써야 했을 때 온보딩 스크립트에 테넌트 이름으로 분기하는 한 줄을 급하게 넣었다. 동작은 했다. 그런데 ENV가 제대로 들어온다면 왜 강제로 넣어야만 동작하는가. 파이프라인을 끝에서부터 거꾸로 따라가 보니 환경변수는 DynamoDB 레코드의 키가 그대로 올라온 것이었고, 테넌트 레코드에는 env 필드가 아예 없었다. 그 한 줄짜리 예외가 구조적 구멍을 가리고 있었다. 이 분기는 ENV를 테넌트 레코드까지 내리는 일을 보류하면서 아직 남아 있다. 다만 이제는 왜 있는지, 무엇이 끝나야 지울 수 있는지가 적혀 있다.

틀린 가설은 문서에도 남는다. 프론트엔드 롤백에서 403이 난 사건을 나는 산출물 문서에 “index.html이 건너뛰어져 옛 화면이 새 파일을 찾다 403이 났다”고 적었다. 나중에 글로 옮기면서 당시 작업 기록을 다시 보니, 그때 확인한 S3 객체의 ETag는 반대를 말하고 있었다. 롤백되지 않고 남은 건 새 버전의 index.html이었고, 그 파일이 --delete로 이미 지워진 자기 js를 찾다가 403이 났다. 해법(sync 대신 cp)은 같았지만 원인 설명은 거꾸로였다. 롤백 때 index.html을 건너뛰는 aws s3 sync는 기록 쪽을 따라 다시 썼다. 사건이 끝난 뒤에 쓴 설명도 하나의 가설이다. 정리한 사람이 나라도 그렇다.

예상되는 반론들

“가설 없이 처음부터 전부 보면 되지 않나?”

비판: 틀린 가설이 문제라면 가설을 세우지 말고 처음부터 모든 계층의 로그와 지표를 다 보면 된다.

내 생각: 가설이 없으면 어디를 볼지도 정할 수 없다. 노드 이벤트, Pod 안의 iptables 규칙, 커널 스택, S3 객체의 ETag는 무엇을 의심하느냐에 따라 펼쳐 보게 되는 자료다. ArgoCD를 의심한 것도, cross-AZ를 의심한 것도 그때 보이던 사실로는 합리적이었다.

“비교나 격리 테스트를 할 여유가 늘 있는 건 아니다”

비판: 운영 중에 기능을 끄거나 서버를 늘려 가며 비교할 수는 없다. 급할 때는 가장 그럴듯한 가설로 먼저 막는 게 맞다.

내 생각: 급할 때 먼저 막는 건 맞다. 테넌트 이름 분기 한 줄도 그렇게 들어갔다. 막은 뒤에는 그 한 줄이 왜 필요했는지 한 번 따져야 한다. 이 글에 나온 비교와 격리는 대부분 비싸지 않았다. 정리를 막은 격리 테스트는 7분짜리 배포 한 번이었고, 측정을 바로잡는 데는 부하 서버 한 대면 됐다. cross-AZ 가설은 다른 노드 7대의 dmesg로 무너졌다. 그 한 번을 미룬 대가는 며칠, 길게는 일주일이었다.

정리

가설은 세우는 시점보다 버리는 시점이 중요하다. 다음에 무언가를 의심하기 시작하면 그 옆에 “이게 나오면 버린다”를 한 줄 적어 두자. 멈출 시점이 미리 정해진다.