버그리포트 이후 72시간
Abstract
이 문서는 특정 프로젝트를 진행하면서 발생했던 일련의 사건을 정리합니다.
Bug Report
버그는 어디서나 발생합니다. 버그를 찾는 가장 좋은 케이스는 그것을 코드를 짜는 도중 발견하는 것입니다. 예를 들면 변수에 오타가 있다거나, 논리가 헛바퀴를 돌고 있다거나 하는 것을 코드를 타이핑하면서 발견하는 것입니다. 커피를 든 동료가 내 모니터를 건너 보게 하는 것은 버그를 찾을 수 있는 좋은 방법입니다. 그들은 여유가 있어서 고정관념을 깬(Out of the box) 채 당신의 코드를 바라봅니다. 이들은 로직에 영혼을 저당 잡힌 당신보다 더욱 쉽게 버그를 찾습니다. 만약 버그 신고자가 잘난척하기 좋아하는 인물일 경우, 버그를 찾는 비용보다 동료의 자찬을 듣는 비용이 더 클지도 모릅니다. 그러나 이것은 실제 서비스에서 문제가 발생하는 것보다는 낫습니다.
샌드박스(sandbox, 테스트 코드)에서 프로젝트를 조합하는 행동은 버그를 찾는 좋은 습관입니다. 만일 이 단계에서 버그가 발생할 경우, 며칠 밤을 고민할 정도의 작은 인내심과 출력 코드, 디버깅 툴이 그것을 해결해 줄 것입니다. 몇몇 큰 규모 회사는 매니저가 MAIC(Measurement, Analysis, Improvement, Control)를 하는 경우도 있습니다. 그들은 말도 안 되는 숫자, 부하(overhead), 논리를 조합하여 문제를 짜 냅니다. 당신은 "이건 억지야!"라며 소리를 지를 수도 있습니다. 그러나 코딩 과정에 판사는 없습니다. 당신은 이것을 고치거나 매니저와 협상해야 합니다. 일반적으로 (책임감 있는) 프로그래머는 말도 안 되는 로직마저 소화하는 코드를 작성합니다. 그러나 아무리 촘촘하게 로직을 채워도 버그는 발생합니다. 그 이유는 프로그램이란, 결국 로직에, 로직에, 로직을 올린 것이기 때문입니다. 자신의 주장을 검증하기 위해서 여러 프레임을 끌어다 쓰는 사람은 자기의 논리에 갇히기 쉽습니다. 과거 자기주장이 현재 자기주장을 반박하는 식이죠. 마찬가지로 고차원(high-level) 서비스는 여러 가지 논리를 사용하여 사용자 행동을 완성합니다. 로직 위에 로직을 쌓거나 옆으로 로직 두 개를 높이를 맞춰 올린 다음, 그 위에 로직을 올립니다. 필연적으로 모순이 발생합니다. 여기서 모순의 다른 이름은 버그입니다.
진짜 문제는 버그가 있는 코드가 서비스에 올라가는 것입니다. 자칫하면 기존 고객을 잃어버릴 수 있습니다. 고객 한 명을 유치하는데 드는 비용을 생각해보세요. 라이브 버그는 사용자의 신뢰와 열성 사용자 비율을 떨어뜨립니다. 이것은 누구도 원치 않지만 언제든 발생할 수 있는 일입니다.
1.1. 버그 발생 30일 전
월간 신규 사용자가 30만 명 정도인 웹 서비스가 있습니다. 이것은 충분히 크고 좋은 서비스지만 만든 지 너무 오래됐기 때문에 사용성이 떨어집니다. 만든 지 3년 2개월 된 디자인 역시 사용성을 떨어뜨립니다. 기술적으로도 이 서비스는 검색 크롤러가 웹 서비스를 긁어가기에 적절한 형태가 아닙니다. 확실히 개선이 필요합니다.
먼저 유관 부서들끼리 모여서 회의를 합니다. 서비스 문제를 자유롭게 토론합니다. 많은 문제점이 나오고, 각자가 생각하는 서비스 비전이 드러납니다. 타임라인에서 고양이를 볼 수 있게 해달라는 요청도 있네요. 프로젝트 관리자는 이번 업데이트가 커버할 수 있는 안건을 고릅니다.
이번 업데이트가 커버해야 할 리스트가 나왔습니다. 이제 프로젝트 관리자는 이 리스트를 가지고 관리자와 함께 해당 목표에 관리자가 원하는 것이 있는지 조율합니다. 요구사항 몇 개가 빠지고, 새로운 요구사항이 추가됩니다. 아쉽게도 고양이-타임라인 프로젝트는 우선순위가 밀린 것 같네요.
프로젝트는 두 사람이 함께 진행하게 됐습니다. 시니어 웹 퍼블리셔 한 명과 주니어 프론트앤드 프로그래머입니다. 시니어 퍼블리셔는 이 프로젝트의 기존 관리자로, 이 프로젝트가 끝나면 주니어 프로그래머에게 이것을 양도할 것입니다.
1.2. 버그 발생 사흘 전
한 달 여의 코딩-테스트-결합 과정이 끝났습니다. 매니저는 문서상의 목표와 실제 서비스 반영이 제대로 되어 있는지 마지막으로 확인합니다. 그동안 시니어 프로그래머는 구글에 인덱싱을 요청합니다. 주니어 프로그래머는 나머지 인수인계를 마치고 본인 부서로 돌아갑니다. 주니어는 곧 새로운 프로젝트에 투입될 것이므로 유관 동료들과 커피타임을 갖습니다. 프로젝트 오버뷰를 하고, 자유롭게 다음 서비스의 청사진을 그립니다.
업데이트한 모바일 웹을 확인합니다. 배너부터 필터, 스크롤까지 정상 작동합니다. 이전 서비스와 비교했을 때 좋아진 사용성에 감탄합니다. 자찬이지만 자신이 만든 산물이 자랑스럽지 않은 창조자는 없을 것입니다.
2.1. 버그 발생
9월 21일, 전체 메시지로 긴급 리포트가 올라옵니다. 해당 서비스가 503 에러 (Service Unavailable)를 낸다는 보고입니다. 503 에러는 서버에 접속자가 많을 때, 서버가 응답을 하지 않을 때, 혹은 서버 내 애플리케이션 문제로 요청한 서비스가 정상 작동하지 않을 때 발생합니다. 커피타임은 끝입니다. 주니어 프로그래머는 노트북을 들고 회사로 돌아갑니다.
서비스 도메인을 들어갑니다. 실제로 503 에러가 발생합니다. 주니어는 가장 먼저 시니어에게 찾아갑니다. 사흘 동안 자신이 모르는 업데이트가 발생했는지 확인하기 위함입니다. 만약 시니어가 그렇다고 한다면, 가장 가까운 커밋부터 의심을 시작할 것입니다.
"16일부터 20일 사이에 릴리즈 하신 게 있나요?" 주니어가 물어봅니다.
"아뇨. 없는데요." 시니어 퍼블리셔가 말합니다.
"그래요? 그런데 서비스가 죽었어요."
"네. 그냥 구글에 인덱싱 한다고 사이트맵 제출한 거. 그게 문제인 것 같아요." 퍼블리셔가 말합니다.
"구글이 해커도 아니고, 악의적 공격(malicious attack)을 할 리가 없잖아요. 정말로 그렇게 생각하세요?"
(대답 없음)
이제 주니어는 퍼블리셔의 모니터를 봅니다. 모니터에는 해당 에러와 관련 있는 페이지가 아니라 다른 프로젝트 페이지가 띄워져 있습니다. 주니어가 말합니다.
"신중하게 말씀하셔야 할 것 같아요. 어디가 잘못됐는지 함부로 추측하면 장애 해결에 시간이 더 걸릴 수 있어요."
그제야 시니어 퍼블리셔는 주니어의 얼굴을 봅니다. 시니어가 말합니다.
"아뇨, 그냥 이건 제 추측일 뿐이에요. 그리고 엔지니어님이야말로 저한테 지금 신중하게 말씀하셔야 할 것 같은데요?"
"지금 잘잘못을 따지자는 게 아니잖아요. 장애 해결해야죠."
"그럼 장애 해결하고, 이 일에 대해서 더 이야기하고 싶으세요?" 주니어 퍼블리셔는 다시 자기 모니터를 봅니다.
"아뇨. 더 말할 것도 없을 것 같네요. 장애 해결하러 갑니다."
시니어 퍼블리셔는 이미 프로젝트에 마음이 떴습니다. 주니어 프로그래머는 자리로 돌아갑니다. 문제를 해결할 사람은 자신밖에 없습니다. 그는 시니어 퍼블리셔의 무책임함을 따져 묻고 싶지만 문제 해결이 우선입니다. 만일 그가 말한 대로 구글이 사이트맵을 인덱싱 하면서 문제가 발생한 것인지, 그게 아니면 어느 곳에서 문제가 발생했는지 찾아야 할 것입니다.
주니어 엔지니어는 찬 물을 한 잔 마십니다. 버그에 집중합니다. 503 에러, 그러니까 서버 쪽에서 서비스가 죽었다면 서비스가 뻗기 전, CPU나 메모리, 혹은 로그단에서 문제를 발견할 수도 있습니다. 그는 물컵을 들고 엔지니어링팀 팀장에게 협조를 구합니다.
엔지니어링 팀장은 서비스가 언제 죽었는지 시점을 파악합니다. 서비스는 9월 21일 AM 11:13부터 15분 간 죽었습니다. 일단 급한 대로 서비스를 다시 시작합니다. 서비스가 다시 돌아갑니다. 엔지니어링 팀장은 URL 리퀘스트를 모두 체크하고, CPU와 메모리 그래프가 언제 튀었는지 체크합니다. 그동안 주니어 프로그래머는 해당 서버의 메모리 그래프의 평소 상태를 체크합니다. 서버는 4 GB의 여유가 있고, 평소에는 1~1.5 GB의 메모리를 사용하여 사용자 요청을 처리하는 것을 확인합니다.
이제 엔지니어링 팀장은 시스템 활동 기록(Activity Monitor)을 확인합니다. 9월 10일 이후부터 주기적으로 메모리와 CPU가 튀고 있는 그래프를 확인합니다. 이것은 외부에서 악의적 공격이 발생할 때 일어날 수 있는 패턴입니다. 이제 주니어는 nginx 로그를 열어봅니다. CPU가 주기적으로 튀는 시간의 URL을 해당 시간 전 후로 30분씩, 약 1시간의 URL 로그를 수집합니다. 이 한 시간 동안 들어온 리퀘스트는 약 7천 건입니다. 우선 시간이 늦었기 때문에 이 리스트를 이메일로 전송합니다. 메모리가 튀는 시점과 그래프도 스크린샷으로 받아옵니다.
이때 시간은 저녁 7시, 우선 서비스가 정상 작동하기에 다음 날 문제를 해결하기로 합니다.
CPU / 메모리가 한 달 동안 세 번 정도 튀었으며, 그때마다 서버가 재시작됐음
집으로 돌아온 주니어 프로그래머는 코드와 메일을 열어봅니다. 간단하게 할 수 있는 일부터 처리해봅니다. 먼저 악의적 공격. 의심 가는 URL을 리스트로 정리합니다. URL 요청 간격이 촘촘한 것부터, 요청 후 처리가 많은 로직까지 정리합니다. 이것을 라이브 서버에 던져봅니다. 에러가 나지 않습니다. 동료 엔지니어가 무슨 일이 있었는지 물어봅니다. 주니어 프로그래머는 상황을 설명하고, 문제를 추리고 있다고 설명합니다.
동료 역시 커밋 로그를 볼 수 있기 때문에 두 사람은 디플로이 시간과 코드를 비교하면서 의심 가는 부분을 골라줍니다. 주니어 프로그래머는 동료의 말을 옮겨 적습니다. 출근하자마자 할 일을 요약합니다.
3.1. 버그 발생 8시간 후
아침이 되고 주니어 프로그래머는 일어나자마자 서비스 상태를 확인합니다. 다행히 서비스는 잘 작동합니다. 출근길 지하철, 그는 평소라면 눈을 감고 있었을 것입니다. 그러나 주니어 프로그래머는 어제 동료와 했던 대화 내용을 복기하고, 할 일들이 서로 간섭하고 있지 않은지, 에러 재현에 왜 실패했는지를 돌아봅니다. 로직상 자잘한 버그도 함께 찾았습니다.
휴대폰으로 코드 커밋 리스트를 봅니다. 메모리는 9월 14일에 한 번, 21일에 한 번 크게 상승했고, 디플로이는 9월 13일, 20일에 했습니다. 만약 오늘도 에러 재현에 실패하면 한 달 전 코드로 롤백을 해야 할지도 모릅니다. 장애가 나는 서비스보다는 불편한 서비스가 나을 것입니다. 그러나 그것은 자존심이 허락지 않습니다. 회사 입장에서도, 개인적 성취로도 일어나선 안 될 일입니다. 휴대폰을 스크롤하는 엄지 손가락이 바빠집니다. 주니어는 출근을 하자마자 개인 메모장에 적어 두었던 의심 가는 항목과 코드 위치, 커밋을 리스트로 만듭니다. 항목은 총 5개 정도로, 근무 중에 모두 수행하고 검증해볼 수 있을 것입니다.
문제는 이렇게 만든 다섯 개의 리스트가 추정일 뿐이고, 결정적으로 어떤 추정과 공격으로도 503 에러를 재현하지 못했다는 것입니다. 서비스는 주니어 프로그래머의 공격에 꿈쩍없이 작동합니다. 주니어는 초조해졌습니다. 손톱을 물어뜯으며 다시 한번 로그 기록과 활동 기록을 살펴봅니다. 이상한 부분을 찾을 수 없습니다.
3.2. 버그 발생 12시간 후
주니어 프로그래머는 출근하고 지금까지 에러 재현을 시도하고, 의심 가는 부분을 수정합니다. DB 요청이 많은 쿼리를 날려봤지만 장애가 발생할 정도로 문제가 되진 않았습니다. 테스트 환경에선 전혀 문제를 찾을 수 없던 것이었습니다. 주니어의 TODO 리스트는 모두 지워져 있었습니다. 실 서비스도 재시작 이후 에러 없이 잘 돌고 있었습니다. 그때였습니다.
"어, 503 에러예요."
주니어 엔지니어는 엔지니어링팀 자리로 뛰어갑니다. 엔지니어링 팀장은 이미 활동 모니터를 띄워놓고 있었습니다. 주니어가 말합니다.
"CPU나 메모리, 그때랑 똑같은 패턴이에요?"
"네, 똑같아요." 엔지니어링 팀장이 말합니다.
에러가 재현됐습니다.
3.3. 버그 발생 13시간 후
주니어 프로그래머는 nginx 로그와 URL 요청을 확인합니다. 기존에 그가 가지고 있던 것과 다릅니다. 이제 다른 동료들도 이 문제에 관심을 갖기 시작합니다.
동료 한 분이 자초지종을 천천히 듣고 말합니다.
"DB 문제는 아닌 것 같아요."
"왜 그렇게 생각해요?" 주니어 프로그래머가 묻습니다.
"만약에 DB가 문제가 있었다면, 503 서버 에러보다 DB 쪽이 먼저 뻗었을 거예요."
맞는 말입니다. 그리고 주니어 프로그래머가 실제로 SQL에서 해당 명령을 헤비 하게 실행했을 때 명령은 제대로 들어갔습니다. 이것은 서비스 트래픽이 특별히 몰렸거나 DB 요청 때문에 생긴 문제가 아니라는 뜻입니다.
점심은 시켜먹기로 합니다. 주니어 프로그래머는 외부 공격에 의한 버그 검증을 제하고, 커밋 로그를 뜯기 시작합니다. 14일에 한 번, 21일에 한 번씩 튄 메모리. 그리고 9월 13일 디플로이 이후로 꾸준히 높은 수치를 차지하는 메모리 볼륨. 주니어 프로그래머는 의심 가는 부분을 체크합니다.
구글의 사이트맵 크롤링은 죄가 없습니다. 주니어 프로그래머의 머릿속엔 퍼블리셔의 얼굴이 스쳤습니다. 그는 버그 발생 후 지금까지 아무런 관심을 두지 않고 있습니다. 그는 자신이 돋보일 수 있는 신규 사업을 발견해서 기분이 아주 좋은 상태였고, 그것을 발전시키는데 정신을 집중하고 있었습니다. 주니어 프로그래머는 여전히 그의 책임감 없는 태도가 마음에 들지 않았지만, 여전히 문제를 해결이 우선입니다.
간단하게 점심을 해결하고 추가/삭제한 코드를 분석합니다. 디플로이와 디플로이 사이에 커밋한 코드는 10개가량입니다. 한 동료가 테스트 코드 몇 개를 작성합니다. 곧 주니어 프로그래머를 부릅니다.
"이 코드요, 좀 이상한 거 같아요."
주니어 프로그래머는 동료가 손가락으로 가리키는 곳을 봅니다. 그가 지적한 부분은 다음 부분입니다.
문제되는 부분(A)과 결과 해당 부분이 데코레이터로 사용될 때 출력값(Output)"13번째 줄 self는 클래스를 재할당 되는 거라 의미 없을 거고요, 클래스의 self.items()는 사이즈가 4가 돼서 계속 variable이 늘어날 거예요. 그러니까 이 데코레이터 사용 용도를 모르겠어요."
"아마도 메모리 캐시를 쓰고 싶은 것 같아요. 여기 비슷한 코드가 있어요." 다른 동료가 말합니다.
"이렇게 쓰면 메모리 누수(Out of Memory, OOM)로 죽을 거예요."
"일단 실험해 볼까요?"
옆에 앉아있던 다른 동료가 말합니다.
"서버에서 이 내용으로 스레드를 몇 개 써요?" 그가 말합니다.
"8개요."
그는 시스템 활동 기록 창을 켜고 프로세스를 8개 실행합니다.
"지금 보여요? 1분 지났는데 메모리가 4 MB 올라갔어요."
"네, 보여요. 잠깐만요."
주니어 프로그래머는 메모장과 계산기를 켜고 계산을 시작합니다. 코드 릴리즈 날짜는 20일, 장애 날짜는 21일 오전 11시. 시작부터 장애 발생까지 걸린 시간은 28시간입니다. 이것을 분으로 치환하면 1680분. 여기에 분당 메모리 증가량 약 4 MB를 곱하면
"6.5 GB" 주니어 프로그래머가 말했다.
"시스템이 죽기 딱 좋은 메모리네요." 동료 프로그래머가 말합니다.
버그를 찾았습니다.
3.4. 버그 발생 48시간 후
버그 수정후(A) 의도대로 작동하는 모습로직에서 문제가 발생하던 부분(A)을 수정합니다. clear 메서드는 클래스 내부에 있는 모든 변수와 속성을 지웁니다. 카멜 케이스(Camel Case)와 슈퍼클래스 상속 같은 간단한 문제도 해결(B)합니다.
테스트 프로그램을 만들고 돌려봅니다. 메모리는 딕셔너리를 세 개까지 가지고 있다가 동일한 URL이 들어오면 캐시 된 페이지를 리턴합니다. 이것을 일곱 글자로 줄이면, '정상 작동합니다'.
주니어 프로그래머는 이제 전체 공지로 버그가 수정됐음을 알립니다. 혼자 해결하려 들었다면 발견하지 못했을 버그였습니다. 모두 동료들 덕분입니다. 퍼블리셔를 제하고 말이죠.
4.1. 버그 발생 54시간 후
주니어 프로그래머는 이것을 문서로 정리합니다. 그리고 이 문제가 시니어 퍼블리셔의 코드에서 나왔음을 최종 확인합니다. 그는 여전히 새로운 프로젝트에 몰두하고 있습니다. 직접 대화할 여지는 없습니다. 이제 책임 소재를 밝힐 시간입니다. 프로젝트 매니저를 만납니다.
주니어 프로그래머가 말합니다.
"결국 코드는 고쳤고, 이것은 저쪽(퍼블리셔) 파트의 문제로 밝혀졌습니다. 그런데 시니어 퍼블리셔는 아무것도 하지 않았습니다. 아마, 그는 프로젝트 종료가 손을 떼는 것과 같은 것이라고 생각하고 있는 것 같습니다." 주니어 프로그래머가 말합니다.
"어떻게 하길 원하세요?" 프로젝트 매니저가 말합니다.
"성장을 추구하는 사람 중 신사업을 싫어하는 사람은 없을 겁니다. 그런데 이렇게 하면, 누군가는 레거시 코드만 고치고 앉아 있고, 어떤 사람은 계속 대충대충 신사업만 만들 거예요."
"공감합니다. 그런데 이 문제가 그렇게 책임소재를 딱딱 나눌 수 있는 건가요?" 프로젝트 매니저가 다시 묻습니다.
"아니요. 그런데 함께 문제를 해결하려고 노력할 수는 있겠죠." 주니어 프로그래머가 말합니다.
"그렇네요. 그런데 문제는 그(퍼블리셔)가 이것을 문제라고 생각하지 않을 거라는 거예요." 프로젝트 매니저가 말합니다.
"저는 이 프로젝트를 하면서 감정이 많이 상했습니다. 그러나 감정적 이유와 업무적 이유를 따로 떼어놓고 이야기하고 싶습니다. 감정을 차치하고라도, 그가 보여준 무책임함에 저는 실망했습니다. 사과도 필요 없고, 앞으로 그와 일을 하지 않길 바랍니다." 주니어 프로그래머는 자신의 뜻을 밝힙니다.
"알겠습니다. 운영진과 논의해 보겠습니다."
4.2. 버그 리포트 이후 72시간
사이다 같은 결말은 없습니다. 드라마 같은 결말도 없습니다. 팀 프로젝트가 끝나면 몇몇은 철천지 원수가 됩니다. 룸메이트를 잘못 만나면 생고생을 하기도 합니다. 그러나 고통은 그때뿐입니다. 회사는 다음날도, 그다음 날에도 출근해야 합니다.
만화: 숲속친구들어려분은 한쪽 말만 들었습니다. 주니어 프로그래머의 말입니다. 시니어 퍼블리셔의 말을 듣고 싶은 분도 있을 것입니다. 진짜 공정한 사람은 양쪽 말을 들어야 합니다. 아쉽게도 상대편 입장은 없습니다. 그러나 여기서 이야기를 끝낼 순 없습니다. 주니어 프로그래머는 이것을 교훈 삼고 싶었습니다. 이제 사건에서 대상을 지웁니다. 그리고 이것을 일반화합니다. 인류는 앞으로 나가는 존재입니다. 모 연예인의 인터넷 밈을 찾아봅니다.
Analysis
주니어 프로그래머는 먼저 사실 관계로만 얻을 수 있는 결론을 요약합니다. 어쩌면 이것은 당신이 세상에서 쉽게 찾을 수 있는 일반적인 겪언일지도 모릅니다.
프로젝트엔 책임의식이 중요하다
계란을 한 바구니에 담지 마라
운영하는 사람과 성장하는 사람이 다르면 소진된다
그는 여기까지 적고 자신의 행동에 문제가 된 부분은 없는지 고민합니다. 친한 동료에게 자신의 행동거지를 묻습니다. 그가 말합니다.
"그런데, 그렇게 프로젝트 매니저랑 이야기하면 상대편이랑은 다시는 일 못할 것 같아요."
Conclusion
주니어 프로그래머는 절차적이었습니다. 모름지기 시스템이란 효율성을 떨어뜨리지만 이렇게 문제가 생겼을 때 책임 소재를 명백하게 밝힐 수 있게 합니다. 그것이 상대편의 침묵일지라도 말이죠. 그러나 이것은 정서적 관계를 멀리 합니다. 인과 관계를 객관적으로 서술하는 것은 언제나 고통스럽습니다. 가족에 비유하자면 자녀 둘이 싸우다가 부모에게 달려간 꼴입니다. 부모는 판결을 내릴 테지만 기분이 좋진 않습니다. 세상에 자신의 자녀들이 싸우는 모습을 보고 싶어 하는 부모가 어딨겠어요. 주니어 프로그래머는 이것은 인간관계에선 몹쓸 짓이라고 생각합니다.
여기까지 적고 세상에 얼마나 가족 같은 기업이 많은가 생각해봅니다. 고개를 흔듭니다. 차라리 절차가 낫겠다 싶습니다. 물론 가장 좋은 일은 이럴 일이 없는 것이겠죠.
Fin.
