퇴근 무렵, 윤아가 실시간 검색어가 업데이트가 안된다고 한다. 마지막 갱신시간을 봤더니 오전 7시 몇분. 헉… 순간 땀이 삐질. 모니터링 쉘은 계속 돌고 있는데 이상하게 데이터를 생성해주는 프로그램의 프로세스가 안보인다. 일단 오늘자 쿼리 로그 파일을 열어봤다. 아… 양이 너무 많다. 이래서는 알 수가 없다. 의심가는 부분에 디버깅 메시지를 집어넣고 하나씩 따라가 봤다.
query-20060830.log : 181930, 211.45.66.200, 이런n 182031, 211.45.66.200, 젠장n :
로그 파일의 포맷은 대충 저러하다. 시간, 아이피, 쿼리가 각 라인을 구성하고 있으며, 프로그램은 한줄씩 로그를 읽어서 쿼리의 빈도수를 카운트 후, 정렬해서 높은 순위부터 출력하는 비교적 간단한 프로그램이다.
char szBuff[1024] = {0x00, };
:
while(fgets(szBuff, 1023, pFile)) <== 첫번째 실수
{
ST_LOG stItem;
:
memset(&stItem;, 0, sizeof(ST_LOG));
iReturn = get_info(szBuff, &stItem;);
if (iReturn)
{
memset(szBuff, 0x00, 1024);
continue;
}
:
memset(szBuff, 0x00, 1024);
}
한줄씩 읽는 부분이다. 버퍼 사이즈가 1024 바이트인데 1023 바이트 까지만 읽기 때문에 문제가 될 게 없다. 그렇게 로그파일에서 읽은 로그는 파싱 함수에게 넘겨져 정보를 구조체에 집어넣게된다.
int get_info(char* pszBuff, ST_LOG* pstLog)
{
char szDate[20] = {0x00, };
char* pszToken = NULL;
:
pszToken = strtok(pszBuff, LOG_SEPARATOR));
if (pszToken == NULL)
return 1;
strcpy(szDate, pszToken); <== 두번째 실수
:
}
그런데 이따위 쓰레기 쿼리가 들어오면?
: 182209, 222.14.10.100, 네이버n 182210, 65.200.31.250, 0000000000000000000000000000000000000000000000000000000000000000 0000000000000000000000000000000000000000000000000000000000000000 0000000000000000000000000000000000000000000000000000000000000000 0000000000000000000000000000000000000000000000000000000000000000 0000000000000000000000000000000000000000000000000000000000000000 0000000000000000000000000000000000000000000000000000000000000000 0000000000000000000000000000000000000000000000000000000000000000 0000000000000000000000000000000000000000000000000000000000000000 0000000000000000000000000000000000000000000000000000000000000000 0000000000000000000000000000000000000000000000000000000000000000 0000000000000000000000000000000000000000000000000000000000000000 0000n 182312, 222.14.10.100, 다음n :
fgets 함수는 현재 파일 오프셋부터 개행문자를 만날때까지 최대 지정한 바이트만큼 읽어서 버퍼에 저장한다. 만약 최대 지정 바이트를 읽을때까지 줄바꿈 문자가 들어 있지 않으면 어떻게 되는가? 난 개행문자 다음 바이트부터 읽을 거라 착각을 했다. 왜 그런 착각을 했을까. fgets 함수는 단순히 라인 단위로 읽어온다는 직관이 작용했나 보다. 최대 지정 바이트를 다 채울때까지 개행문자를 만나지 못하면 다음 fgets 호출때는 마지막 읽은 파일 오프셋 다음 바이트 부터 읽게 된다.
따라서 저 라인의 경우 두번째로 fgets 가 호출될때, 버퍼에는 000000000000… 가 들어 있게 된다. 그렇게 되면 파싱함수는 20바이트짜리 szDate 에 200 바이트를 복사해 넣는다. 메모리가 오염되는 순간이다. 건드려서는 안될 영역을 건드린 바보같은 나의 실시간 검색어 생성 프로그램은 얼마못가 OS에게 처절한 응징을 당하고 장렬히 전사한다.
fgets 함수가 단순히 라인 단위로 동작한다고 착각한 것이 첫번째 실수요, strncpy 를 사용하지 않고 strcpy 를 사용한 것이 두번째 실수다.
쯥… 코딩을 할때는 항상 방어 자세를 취해야 하는데 너무 느슨했다.
구시렁 구시렁 