사고뭉치를 위한 디버깅 방법 #02

안녕하세요~
오랜만에 다시 찾아뵙는 엘키입니다. 개인적으로 몸이 너무 좋지 않아 몸조리를 하고 다시 복귀했습니다. 이어지는 포스팅은 늦지 않도록 노력하겠습니다. (__) 꾸벅~

지난 포스팅에서도 이야기 했다시피 일반적으로 버그에 대한 보고는 자신이 겪은 증상에 대한 보고 입니다.

아주 행복한 시나리오는 보고 받은 대로 시도하면 100% 재현 되는 버그입니다.
이런 종류의 버그는 너무나 해결하기 쉬워 “훗~ 어떻게 고쳐줄까?” 라고 고민하는 것만 집중하면 되지요.

하지만 대다수의 잡기 힘들었던 버그는

1. “그냥 뜬금 없이 프로그램이 종료”
2. “같은 방법으로 재현하려 해도 매번 다른 동작을 보여주는 버그”
3. “보고 받은 대로 해도 재현 되지 않는 버그”

위와 같은 버그들입니다.

이번 포스팅에서는 이런 버그들을 잡는 법에 대해 알아보겠습니다.

기본적으로 제가 생각하는 디버깅은 추리입니다.

이를테면 이 녀석이랑 우리는 비슷한 일은 한다는 거죠~

버그를 잡는 과정은 다음과 같습니다.

1. A라는 오류가 생겼다.
2. 그로 인한 원인은 B이다. (로그 혹은 재현)
3. 해결책은 C다.

여기서 가장 중요한 것은 B를 증명하는 과정입니다.

B를 증명하지 못한다면 그저 우연에 맡기는 프로그래밍(실용주의 프로그래머에서 인용)으로 서비스를 하는 것일테죠.

명확히 로그로 A라는 오류가 생겼다는 로그가 발견됐다면? 별거 아닐겁니다. 아마 그럴겁니다.

물론 실수는 누구나 할 수 있기에 단순 실수였다니 다행이군~ 하고 넘어갑시다.

하지만 대부분의 버그는 부주의에서 나오고, 그런 부주의의 원인이 무엇인지를 알려주는 로그 따위는 기대하지 맙시다.

대부분의 디버깅 상황은 명확한 증상과 원인을 알려주는 로그 따위는 없는 경우가 많습니다. 주로 한정된 로그와 로직의 흐름을 통해서 이루어지는 것이 일반적입니다.

그래서 제한된 정보를 바탕으로 재앙의 원인을 찾아내는 과정을 거치게 되는데 이 과정을 추리라고 보시면 됩니다.

명탐정 코난 보셨죠? 아주 작은 실마리 하나를 놓치지 않고 범인을 찾아내는 명석한 두뇌!!
아, 물론 우리는 그 정도로 똑똑할 필요는 없습니다.

하지만 종종 그에 못지않은 추리와 상상력이 필요할 때가 있습니다.

대부분의 경우 힌트는 조각나있습니다. 조각난 힌트들을 퍼즐 맞추듯 하나 하나 끼워 맞추는 과정이 우리에겐 필요합니다.

예를 들어 볼까요?

게임하다 갑자기 클라이언트가 종료됐다는 보고가 왔습니다. 그런데 전체 유저도 아니고 소수 유저라고 하는군요. (10명 내외)

아! 덤프 서버!! 덤프 분석 페이지를 가 봅시다. 어라? 덤프가 안남았다니...최악이군요.

여기서 보통 2가지 반응을 보입니다.
1. “어? 뭐야? 보고가 잘못된거 아냐??”
2. “헐....뭐지 덤프 안남고 죽는 상황들에는 뭐가 있더라...뭐 여하튼 힌트가 될만한건?”

물론, 우리는 2번 반응을 보여야 합니다. 유저의 보고가 잘못됐다는 것 마저도 우리는 증명해야 합니다. 우리는 엔지니어니까요. ^-^

기술자(技術者, technician)는 어떤 분야에 공학적인 일에 숙련된 사람을 말한다. 반면 공학자(工學者, engineer)는 공학의 일에 자연과학적인 지식과 기술적인 지식을 가지고 과학자와 기술자 사이에 매개체가 되는 사람을 가리킨다. 공학자는 기술, 수학, 과학 지식을 사용하여 실용적인 문제를 해결한다. 공학자로 일하는 사람들은 보통 공학 분야에서 학위를 가지고 있다. 공학자는 자연과학적 지식에 기초하고 있기 때문에 기술자와 구분된다. 15-16세기에는 엔지니어란 군사 분야의 기술을 맡거나, 건축가, 수력학자, 조각가, 화가로서 재능을 빌려주는 사람이었다. ^[1]

출처 : http://ko.wikipedia.org/wiki/%EA%B8%B0%EC%88%A0%EC%9E%90

자~ 그럼 뭐라도 힌트를 얻어볼까요? 에러 로그 먼저 살펴보죠.

에러 로그를 봐도 별다른게 없습니다. 쳇...쉽지 않네요.

그렇다면...추가적인 보고되는 상황도 뭔가 조금씩 다릅니다. 대부분 유저의 보고는 감정적으로 이루어지는 경우가 많아, 고의적이 아니더라도 현상을 다르게 보고하는 경향이 있습니다. (상대적으로 이성적으로 판단해주시는 QA 분들 마저 현상을 착각하는 경우도 종종 있습니다.)

이런 경우 공통점을 찾기 시작해야 합니다. 대부분 로그에서 결정적인 힌트는 없더라도 비슷한 점이 발견되는 경우가 종종 있습니다.

문제가 발생한 모든 유저의 로그에서, 유저가 크래시 발생전에 했던 행동중 우편함을 열어보았다는 로그를 발견했습니다. (저의 경우에는 Disconnect 시점에서 최근 10개 패킷 번호를 로그로 남기는 구현을 했던 적이 있는데, 이 로그가 디버깅에 아주 큰 도움이 되곤했습니다.)

우편함을 뒤져볼까요?

아...뭔가 조금 이상하군요. C++ 구조체에 정의된 최대 크기는 64바이트, DB에서 기록 가능한 최대 메시지가 128바이트였군요.

DB에서 실제 사용된 메시지 크기를 기준으로 검색해봅시다.

아...53명이군요. 53명중 10명만 오류에 대한 보고를 한 것이고요.

아마 버퍼 오버플로우가 났었겠지요?

어라? 어쨰서 유저들의 보고에서는 우편함을 클릭했었다 라는 보고가 없었던 걸까요?

그리고 어째서 서버는 크래시 되지 않았던걸까요?

서버 코드는 다음과 같습니다.

typedef DWORD MAIL_IDX;

typedef DWORD USER_IDX;

class Mail : public ISyncroized
{
public:
   Mail (const MAIL_IDX Idx, const char* szMessage, const USER_IDX UserIdx)
   {
       m_Idx = Idx;
       m_szMessage = szMessage;
       m_UserIdx = UserIdx;
   }

   virtual bool Encode()
   {
       // 인코딩 작업 구현
   }

private:

   MAIL_IDX m_Idx;

   USER_IDX m_UserIdx;

   std::string m_strMessage;
};

Mail mail(Idx, szMessage, UserIdx);
pSession->Send(mail); // Send 함수 내부에서 ISyncroized 형 참조자를 통해 Encode된 정보를 유저에게 전달함.

자 그렇다면 클라이언트 코드를 볼까요?

const int MAX_MAIL_MESSAGE = 64;

typedef DWORD MAIL_IDX;
typedef DWORD USER_IDX;

class Mail
{
public:
   Mail(const MAIL_IDX Idx, std::string strMessage, const USER_IDX UserIdx)
   {
       m_Idx = Idx;
       strcpy(m_szMessage, strMessage.c_str());
       m_UserIdx = UserIdx;
   }

private:
   MAIL_IDX m_Idx;

   USER_IDX m_UserIdx;

   char m_szMessage[MAX_MAIL_MESSAGE];

private:
   IUIForm* m_pForm;

private:
   MailBox* m_pMailBox;
};

MAIL_IDX Idx = packet.Decode();

std::string strMessage = packet.Decode();

USER_IDX UserIdx = packet.Decode();

Mail mail(Idx, strMessage, UserIdx);

변수 배치상 우편함을 열자마자 오류가 생긴 것이 아니고, 그로 인한 2차 감염으로 문제가 생겼네요.

자! 찾았습니다.
신난다~~ 신난다~~~


그렇지만 좋아만 할때가 아니죠잉?

자. 어떠한 실수가 이런 문제를 만든 걸까요?
1. DB와 C++ 코드와 텍스트 길이 오차
-> 64 <-> 128
2. non-safe 한 c 표준 함수 사용. (strcpy)
-> 버퍼 길이를 지정하는 함수로 변경. (strncpy)

직접적인 원인은 위 두가지겠지만, 실제론 더 있다고 볼 수 있습니다.
1. 패킷에서 사용하기로한 자료형은 std::string에 Decode되는 자료 구조형과 달리 NULL-Terminated 문자열 사용.
-> 패킷을 데이터로 변환하는 함수에서 std::string을 지원한다면 굳이 NULL-terminated형을 사용할 필요가 없었음.

2. UI에서 제대로 표기가능한 문자열은 실제로 128byte였음.
-> 무언가 기획서의 반영이 안된것인가 찾아보았더니, 최초 UI폼은 64byte만큼 표시가 가능했으나, 이후 UI폼에선 128byte만큼 표기 가능하게 변경됨. C++ 코드에서의 UI변화 코드 수정 누락으로 인한 문제 발생.

이렇듯, 문제가 왜 발생했는가의 경위를 알아내는 것이 매우 중요합니다.
이런 실수들은 꽤나 큰 문제를 일으키곤하는데요, 방금전 버퍼 오버 플로우 관려련 코드가 로그인 시에 매번 수행되는 코드에서 사용되었다면 유저 대부분이 떨어져 나가버려 서비스는 엉망이 될 것이고, 덤프도 안남는 상황에서 (혹은 엉터리 같은 덤프가 남는 상황에서) 그 많은 유저 사이에서의 공통점을 찾기란 서울에서 김서방 찾기만큼 힘들었을겁니다.

“찾았다~~ 문제생긴 코드만 후딱 수정해서 패치하면 되지 뭐~.”

이렇게 대처해서는 안됩니다.

생각보다 많은 팀에서 버그나 크래시가 발생했을 때 이를 너무 크게다뤄 지나치게 혼을 낸다거나, “뭐 이런일도 있는거지” 하며 쉽게 넘어가죠.

실제로 필요한 대처는 버그가 발생한 코드 조각이 아니라, 진짜 단순 실수였는가, 개발자의 무지에서 온 것은 아닌가, 시스템으로 커버 불가능한 오류였는가, 개발 과정에서 캐치 할 순 없었는가 등을 다 고민해보아야 합니다.

이런 과정은 “좋은 서비스”를 하고 있는 개발 팀일 수록 체계화 되어있으며, 개개인의 실수가 팀 차원에서 커버되는 경우가 많습니다.

여하튼 버그를 찾았다면 그런 버그가 “다시는” 나오지 않게 하기 위한 여러가지 고민을 할 차례입니다.

이런 고민에 대한 이야기를 다음 글에서 이어서 하겠습니다.