Antithesis 초기 시절에 겪었던, 쉽게 잡히지 않는 기묘한 버그를 추적하고 해결해 나간 여정과 그 과정에서 얻은 인사이트를 기술합니다.
FreeBSD/EC2 관리인
2024년 5월 21일
Antithesis 초기 시절, 우리는 한 가지 문제를 안고 있었습니다: 머신이 계속해서 크래시가 발생하는 것이었습니다. 그 버그는 드물었습니다. 참을 수 없을 만큼 드물었습니다. 예를 들어, 수천 시간의 머신 사용 중 한 번 정도 발생하는 정도로요. 그래서 이 버그를 고칠 가치가 있는지에 대한 내부 논쟁이 거세게 일었습니다.
어떤 사람들은 그냥 이 버그를 감수해야 한다고 주장했습니다. 결국, 소프트웨어 테스트 회사라는 아이러니는 우리가 보통 다른 누구의 중요한 경로에 있지 않기 때문에, 우리 소프트웨어가 완벽하게 신뢰할 만할 필요는 없다는 것이지요. 1 재시도를 추가하고, 스케줄링 및 오케스트레이션 시스템을 머신 오류에도 견딜 수 있게 하고, 고객은 때때로 테스트 결과가 약간 늦게 나오는 것조차도 눈치채지 못할지도 모릅니다.
다른 쪽에서는, 이 특정 버그가 중요하지 않더라도, 존재 자체가 앞으로 우리가 하는 모든 일에 보이지 않는 세금을 부과할 거라고 주장했습니다.
이 시기는 초창기 사업 단계였으며, Antithesis의 가장 낮은 레벨까지 활발하게 개발 중이었습니다. 우리는 아직 Antithesis를 Antithesis로 테스트할 수도 없는 상황이었고, 실제로 머신 크래시로 나타날 수 있는 진짜 버그도 종종 도입하고 있었습니다.
여러분 팀이 할 수 있는 가장 생산적인 일 중 하나는 “이상한” 버그가 전혀 없는 상태를 유지하는 것입니다. 그래야 새로운 증상이 나타나는 즉시 눈에 띌 수 있고, 그 증상을 만들어낸 코드 변경이 머릿속에 신선할 때 바로 조사할 수 있습니다.
드물고, 확률적이며, 제대로 이해되지 않은 머신 크래시는 이상한 버그 근절 노력을 완전히 망칠 것입니다. 머신이 크래시 날 때마다 “아, 그 이상하게 드문 이슈겠지”라며 대수롭지 않게 넘길 유혹이 생깁니다. 결국 우리는 모든 머신 실패를 철저히 파헤치는 습관을 유지할 수 없다고 결론 내리고 말았습니다. 이후에는 이런 이슈들이 점점 더 많이 작업에 침투해 시스템의 품질이 서서히 저하될 것입니다.2
이제 버그를 조사할 때였습니다. 그러나 문제가 하나 있었습니다: 극히 드물고, 완전히 비결정적이며, Antithesis를 아직 Antithesis로 돌릴 수도 없었죠. 그래서 모두가 하는 일을 했습니다 — 문제 주변에 생각할 수 있는 모든 로깅을 추가하고, 다시 이 버그가 나타나기를 기다렸죠…
Antithesis 하이퍼바이저는 FreeBSD에서 구동되는 타입2 하이퍼바이저로, 자체 개발한 TCP 기반 프로토콜을 통해 나머지 플랫폼과 통신합니다. 하이퍼바이저 인스턴스(고성능 CPU가 많은 대형 머신)의 작업이 항상 꽉 차 있어야 회사 입장에서 경제성에 중요하므로, 프로토콜은 딥 파이프라이닝과 여러 동시 작업 큐를 처리할 수 있어야 했어요. 게다가, 하이퍼바이저와 반대편 프로토콜을 담당하는 컴포넌트를 막 리라이트한 시점이었기에, 첫 번째 가설은 논리 버그나 비동기화로 하이퍼바이저가 말도 안되는 명령을 받게 되었을 가능성이었습니다.3 그로 인해 커널 패닉이 나서 머신이 죽을 수 있었죠.
그래서 탐지 및 계측의 집중 지점을 하이퍼바이저의 네트워킹 컴포넌트 주변에 두고, 또 수천 시간 동안 버그가 다시 나타나기를 기다렸습니다. 마침내 발생했을 때, 로그를 열어보니… 아무것도 발견되지 않았습니다. 하이퍼바이저가 받은 메시지에는 손상, 비동기화 등 아무런 문제가 보이지 않았어요. 방금 전까지 작업을 잘하다가 갑자기 죽어버린 겁니다. 대체, 무슨 일이 일어난 거죠?
하이퍼바이저는 커널 안팎에서 부분적으로 동작하는 대형 C 프로그램이며, 불법적이거나 예기치 않은 동작이 감지되면 지체 없이 셧다운하는 전략을 사용합니다. crash-only 소프트웨어만큼 극단적이지는 않은데, 하이퍼바이저에 손상 발생해도 치명적이지 않고 보안 경계에 걸리지 않기 때문입니다.4 하지만 임의의 하이퍼바이저 손상을 디버깅하는 것은 크래시를 디버깅하는 것보다 훨씬 더 어렵습니다. 그래서 우리는 여러 상황을 의도적으로 크래시로 에스컬레이션합니다. 혹시 이 코드 일부가 문제였을까요?
혹시나 해서, 모든 오류 체크나 크래시 동작을 비활성화한 스페셜 빌드를 만들어 또다시 몇 천 시간 기다려 보았습니다. 드디어 버그가 다시 발생했을 때, 우리가 계측하지 않은 네트워크 코드 한 줄에서 오류가 나타났습니다.
실제로 프로토콜 버그가 있다고 가정하고 (상당히 복잡한) 네트워크에서 메시지를 읽고 해독하는 전체 코드에 로깅을 넣었지만, 유일하게 신경 쓰지 않은 한 줄, 바로 메시지 송신 관련 한 줄에서였죠:
send() at 160 returned 19
이 에러는 여러 면에서 이상합니다. 우선, 에러 코드 19는 처음 보는 것이었습니다. 구글링을 해보니 이런 결과가 나왔죠:
19 ENODEV Operation not supported by device.
장치에 적합하지 않은 기능을 적용하려고 할 때,
예를 들어 프린터 같은 쓰기 전용 장치에서 읽으려고 할 때.
ENODEV? 흥미롭네요. 그런데 FreeBSD에서 man send 결과에는 이 errno가 나온다는 설명이 없습니다! 더 이상한 점: 실험해 보니 이 에러는 _일시적_이었습니다. 이후 send는 제대로 동작합니다. 어떻게 일시적으로 장치가 없어질 수 있죠? 심지어 이건 스트림 소켓입니다! 스트림 소켓에서 send()가 일시적으로 실패할 거라 기대한 적 있으신가요? 저도 없습니다. 마지막으로, 어떻게 우리가 무언가를 잘못해서 머신이 이런 ENODEV를 띄우게 만들었을까요? 참고로 이 현상에 관해 인터넷 어디에도 아무도 불평하지 않았습니다.
그래서, 합리적으로 FreeBSD 커널 전체에서 ENODEV를 grep해보았습니다. 그러다 여기서 다음과 같은 코드를 발견했습니다:
if(unlikely((if_getdrvflags(adapter->ifp) & IFF_DRV_RUNNING) == 0))
return (ENODEV);
즉, 문서가 틀렸거나 최신이 아니었던 것이죠. 실제로 send()가 ENODEV를 반환할 경우가 있었던 겁니다. 더 흥미로운 것은, "ENA"라는 것이 Amazon Elastic Network Adapter를 의미하고, 크래시 나는 하이퍼바이저 인스턴스들이 Amazon 베어메탈 머신에서 돌아가고 있었다는 사실입니다. 하지만 여전히 많은 의문이 남았습니다. IFF_DRV_RUNNING이 false라는 건 뭘 의미하는가? 드라이버가 어떻게 이 에러 상태에 들어가고 이게 우리에게까지 전달되는가?
디버깅은 인생과 사랑처럼, 때론 받을 자격 없는 무언가를 얻게 되는 일입니다. 영감이 떠오르기도 하고, 로또에 당첨된 것처럼, 어떤 게 우연히 눈에 들어오기도 합니다. 이 현상들은 미리 계획하거나 예측할 수 없습니다. 다만 그런 일이 일어날 여지를 두고, 감사하는 수밖에요.
우리의 경우, 이 버그가 언제 발생했는지를 모두 비교한 표를 보다가 이런 일이 있었습니다. 누군가(기적, 우연, 친근한 유령)가 스프레드시트에 관련 없어 보이는 열, 즉 버그 발생 당시의 머신 업타임을 포함시켰죠. 더욱 기적적으로, 그 업타임이 분 단위로 변환되어 있었고, 이 열은 68, 158, 98, 278, 98, 758... 이런 식이었습니다. 맞습니다. 버그는 8분 오프셋을 두고 정확히 30분의 배수에만 발생했던 겁니다. 이건 명백히 이상했습니다 — 우리 시스템에는 현실 세계의 시간에 신경 쓸 만한 부분이 없었고, 30분은 컴퓨터에서 딱 떨어지는 숫자도 아니죠.
이런 깜짝 발견과 FreeBSD 커널 소스의 의미심장한 코드 한 줄 덕분에, 우리는 이제 구원자를 소환할 때라고 판단했습니다. 맞아요, Colin Percival에게 연락할 때였습니다.
Colin은 전설적인 FreeBSD 해커이자 공식적으로 지원되는 FreeBSD AMI 관리인입니다. 그래서 우리는 이메일로 사정을 설명했고, 좋은 소식을 기대했습니다. Colin은 2010년 이래로 FreeBSD가 EC2에서 잘 동작하도록 일을 해왔고, 만약 EC2에서 FreeBSD로 문제가 생긴다면 Colin이 해답을 가지고 있을 확률이 높습니다 — 혹은 아무리 못 해도 이 문제를 알기를 강력히 바랄 겁니다.5
“send() 시스템 콜에서 때때로 오류가 난다”라고 Colin에게 말했더니, 그는 바로 답장을 보내왔습니다: “/var/log/messages에서 30분마다 ENA가 내려갔다 다시 올라온다는 메시지가 있는지 확인해줄 수 있나?” 오류 발생 시점 얘기는 Colin에게 언급한 적도 없는데, 그가 “30분마다”를 얘기한 것은 그가 뭔가 알고 있다는 신호였습니다. 정말로, Colin이 기대한 바로 그 메시지가 로그에 있었습니다.
알고 보니 이건 Colin이 2017년 Xen netfront 드라이버에서 처음 고쳤던 버그였습니다: SIOCSIFMTU ioctl을 사용해 인터페이스 MTU를 설정하면, 새 MTU가 예전 MTU와 동일하더라도 드라이버가 리셋되곤 했습니다! MTU가 바뀔 때 드라이버를 리셋하는 것은 어느 정도 합리적입니다(가령 내부 버퍼는 처리해야 하는 최대 패킷 크기에 따라 할당됨). 그러나, 실제로 변경이 없는 상황에도 굳이 리셋할 필요는 없겠죠.6
그런데 왜 30분마다 MTU가 세팅되죠? EC2는 DHCP 임대 시간으로 1시간을 설정하고, 임대 시작 30분 뒤에 DHCP 클라이언트가 다시 깨어나 새 임대를 요청합니다. 이때 IP 주소가 변하지 않았다는 알림과 함께 EC2 네트워크가 점보그램을 지원한다는 메시지를 받게 되고, 이에 따라 인터페이스 MTU가… 30분마다 세팅되는 겁니다.
여기서 합리적으로 궁금할 수 있습니다: 네트워크 인터페이스가 자기 자신을 리셋하는 게 어떻게 이런 에러를 만드는가? 여기서 Robert Watson의 한 관찰을 되짚어보죠: 동시성 시스템은 적극적으로 악의적이다. 네트워크 인터페이스가 리셋되는 과정은 두 단계로 나뉩니다: 먼저 인터페이스가 내려가고 드라이버가 모든 리소스를 정리한 뒤, 인터페이스가 다시 올라오면서 드라이버가 재초기화됩니다. 이 모든 건 SIOCSIFMTU ioctl이 리턴하기 전이지만, 그 사이 수십 마이크로초 동안 인터페이스가 다운돼 있습니다 — 그러니까 네트워크 드라이버 용어로는 IFF_DRV_RUNNING 플래그가 설정되어 있지 않죠.
보통은 다운된 인터페이스에 트래픽을 보내려 하진 않지만, 여기서는 두 번째 악의적 상황이 발생합니다: 네트워크 스택은 성능상 비동기적으로 작동해서, IP 패킷을 어디로 보낼지 결정하는 과정과 실제로 보내는 과정이 분리돼 있습니다. 즉, send()를 호출할 땐 네트워크 인터페이스가 "업" 상태라 커널이 목적지를 ENA 네트워크 인터페이스로 선택해놓지만… 실제 패킷을 보내려고 할 땐 인터페이스가 다운 상태일 수 있습니다. 그러면 커널은 다운된 인터페이스로 보내려 한다는 걸 깨닫고, ENODEV를 애플리케이션까지 반환하는 일이 벌어집니다. 모든 게 1밀리초도 안 돼서 벌어지지만, 좋은 도구가 없었다면 문제 원인을 파악하는 데 몇 달은 걸렸을 겁니다.
이 디버깅 여정에서 우리가 얻은 교훈은? 첫 번째는 명확합니다: 잡기 힘들고 비결정적인 버그를 디버깅하는 건 정말 처참한 고통입니다. 추측을 하고, 버그가 또 발생할 때까지 엄청 오래 기다리며, 그 사이에 추가한 로깅이나 계측이 버그를 감쪽같이 사라지게 만들지 않기만 바랄 뿐입니다. 만약 우리가 Antithesis 자체를 써서 이 문제에 도전했다면, 훨씬 짧은 시간에 찾아내 고칠 수 있었을 겁니다. 이런 고통 때문에 Antithesis를 만든 것이기도 하죠!
하지만 더 미묘한 교훈도 있습니다. 이 버그를 코드베이스에 그대로 두면 시스템 전반에 서서히 악영향을 줄 거라는 주장이 완전히 옳았다는 사실입니다! 그 근거는, 우리가 이 버그를 찾고 고치자마자, 아주 비슷한 증상을 내는 다른 희귀 버그들이 한꺼번에 드러나기 시작했다는 점입니다.
이 버그가 아니었다면, 그런 이슈들이 처음 도입된 순간 바로 눈치채고 코드를 롤백하거나 수정했을 겁니다. 하지만 이 버그가 코드베이스와 모두의 뇌리에 핑계거리로 남아 있던 덕분에, 새 버그가 생겨도 똑같은 문제일 거라 치부하며 넘기기 너무 쉬웠습니다.
소프트웨어 업계에서는 품질과 개발 속도를 이분법적으로 생각하는 경향이 있습니다. 그러나 버그가 나타나자마자 신속히 고치는 게 쌓이는 걸 막고, 결과적으로 새 버그를 더 싸고 빠르게 파악할 수 있게 해 생산성을 극대화합니다.
이 버그의 또 다른 장기적 효과는 Antithesis 자체가 "셀프-호스팅"되어 스스로를 테스트할 수 있어야 한다는 결심을 더욱 굳게 해주었습니다. 운영 체제와 상호작용하고 타이밍에 민감한 이슈처럼 이상하고 잡기 힘든 버그야말로 우리가 가장 잘 찾아내는 것들이니까요. 그래서 우리 스스로에게 까다로운 고객이었음에도 불구하고, 내부 테스트를 모두 Antithesis로 교체하는 대대적 프로젝트를 시작했습니다. 이 노력에 대해선 Systems Distributed '24!에서 동료들이 발표할 예정입니다.
디버깅은 어렵지만, 친구의 도움을 받으면 좀 나아질 수 있습니다. Antithesis가 여러분을 위해 할 수 있는 것을 확인해보세요.